diff --git a/cli-messaging/src/main/java/com/salesforce/messaging/CliMessager.java b/cli-messaging/src/main/java/com/salesforce/messaging/CliMessager.java index bf0a0a34f..b96a53aec 100644 --- a/cli-messaging/src/main/java/com/salesforce/messaging/CliMessager.java +++ b/cli-messaging/src/main/java/com/salesforce/messaging/CliMessager.java @@ -4,6 +4,7 @@ import java.util.Arrays; import java.util.List; +import com.google.common.collect.Lists; import com.google.gson.Gson; public class CliMessager { @@ -12,8 +13,17 @@ public class CliMessager { // The END string lets us know when a message stops, which should prevent bugs involving multi-line output. private static final String END = "SFDX-END"; + private static final String REALTIME_START = "SFCA-REALTIME-START"; + private static final String REALTIME_END = "SFCA-REALTIME-END"; + + /* Deprecated: Don't maintain state in a class that's essentially used as a utility.*/ + @Deprecated private static final List MESSAGES = new ArrayList<>(); + /** + * Deprecated - switch to static invocation of {@link #postMessage(String, EventKey, String...)} + */ + @Deprecated public static CliMessager getInstance() { return LazyHolder.INSTANCE; } @@ -26,6 +36,7 @@ public static CliMessager getInstance() { * * @param exception to send to Typescript layer */ + @Deprecated public void addMessage(MessagePassableException exception) { final EventKey eventKey = exception.getEventKey(); addMessage( @@ -43,34 +54,59 @@ public void addMessage(MessagePassableException exception) { * @param eventKey EventKey to display to user * @param args String args passed to the EventKey to make the displayed message meaningful */ + @Deprecated public void addMessage(String internalLog, EventKey eventKey, String... args) { - // Developer error if eventKey was not added to exception and we'll get a bunch of NPEs - assert (eventKey != null); - // Confirm that the correct number of arguments for the message has been provided - // If this fails, this would be a developer error - assert (eventKey.getArgCount() == args.length); - - final Message message = new Message( - eventKey.getMessageKey(), - Arrays.asList(args), - internalLog, - eventKey.getMessageType(), - eventKey.getMessageHandler(), - eventKey.isVerbose()); - MESSAGES.add(message); + final Message message = createMessage(internalLog, eventKey, args); + MESSAGES.add(message); } - /** + /** + * Publish formatted stdout message to pass onto Typescript layer. + * Make sure EventKey is updated with messages/EventKeyTemplates.json + * and has correct properties in the enum. + * + * @param internalLog Information for internal use. Will be logged but not displayed to user + * @param eventKey EventKey to display to user + * @param args String args passed to the EventKey to make the displayed message meaningful + */ + public static void postMessage(String internalLog, EventKey eventKey, String... args) { + final Message message = createMessage(internalLog, eventKey, args); + final List messages = Lists.newArrayList(message); + + final String messageAsJson = new Gson().toJson(messages); + System.out.println(REALTIME_START + messageAsJson + REALTIME_END); + } + + private static Message createMessage(String internalLog, EventKey eventKey, String[] args) { + // Developer error if eventKey was not added to exception and we'll get a bunch of NPEs + assert (eventKey != null); + // Confirm that the correct number of arguments for the message has been provided + // If this fails, this would be a developer error + assert (eventKey.getArgCount() == args.length); + + final Message message = new Message( + eventKey.getMessageKey(), + Arrays.asList(args), + internalLog, + eventKey.getMessageType(), + eventKey.getMessageHandler(), + eventKey.isVerbose()); + return message; + } + + /** * Convert all messages stored by the instance into a JSON-formatted string, enclosed in the start and end strings. * Java code can use this method to log the messages to console, and TypeScript code can seek the start and stop * strings to get an array of messages that can be deserialized. * @return */ + @Deprecated public String getAllMessagesWithFormatting() { final String messagesAsJson = getMessagesAsJson(); return START + messagesAsJson + END; } + @Deprecated private String getMessagesAsJson() { return new Gson().toJson(MESSAGES); } diff --git a/cli-messaging/src/main/java/com/salesforce/messaging/EventKey.java b/cli-messaging/src/main/java/com/salesforce/messaging/EventKey.java index a09f07269..2b3c77685 100644 --- a/cli-messaging/src/main/java/com/salesforce/messaging/EventKey.java +++ b/cli-messaging/src/main/java/com/salesforce/messaging/EventKey.java @@ -3,6 +3,8 @@ public enum EventKey { // MAKE SURE `messageKey` OF EVERY VALUE ADDED HERE HAS AN ENTRY IN 'messages/EventKeyTemplates.js'! + + /** PMD-CATALOGER RELATED **/ INFO_GENERAL_INTERNAL_LOG("info.generalInternalLog", 1, MessageType.INFO, MessageHandler.INTERNAL, true), WARNING_INVALID_CAT_SKIPPED("warning.invalidCategorySkipped", 1, MessageType.WARNING, MessageHandler.UX, true), WARNING_INVALID_RULESET_SKIPPED("warning.invalidRulesetSkipped", 1, MessageType.WARNING, MessageHandler.UX, true), @@ -20,8 +22,23 @@ public enum EventKey { ERROR_EXTERNAL_RECURSION_LIMIT("error.external.recursionLimitReached", 2, MessageType.ERROR, MessageHandler.UX, false), ERROR_EXTERNAL_XML_NOT_READABLE("error.external.xmlNotReadable", 2, MessageType.ERROR, MessageHandler.UX, false), ERROR_EXTERNAL_XML_NOT_PARSABLE("error.external.xmlNotParsable", 2, MessageType.ERROR, MessageHandler.UX, false), + + + + + /** SFGE RELATED **/ + INFO_GENERAL("info.sfgeInfoLog", 1, MessageType.INFO, MessageHandler.UX, true), + INFO_META_INFO_COLLECTED("info.sfgeMetaInfoCollected", 2, MessageType.INFO, MessageHandler.UX, true), + INFO_COMPLETED_FILE_COMPILATION("info.sfgeFinishedCompilingFiles", 1, MessageType.INFO, MessageHandler.UX_SPINNER, false), + INFO_STARTED_BUILDING_GRAPH("info.sfgeStartedBuildingGraph", 0, MessageType.INFO, MessageHandler.UX_SPINNER, false), + INFO_COMPLETED_BUILDING_GRAPH("info.sfgeFinishedBuildingGraph", 0, MessageType.INFO, MessageHandler.UX_SPINNER, false), + INFO_PATH_ENTRY_POINTS_IDENTIFIED("info.sfgePathEntryPointsIdentified", 1, MessageType.INFO, MessageHandler.UX_SPINNER, false), + INFO_PATH_ANALYSIS_PROGRESS("info.sfgeViolationsInPathProgress", 4, MessageType.INFO, MessageHandler.UX_SPINNER, false), + INFO_COMPLETED_PATH_ANALYSIS("info.sfgeCompletedPathAnalysis", 3, MessageType.INFO, MessageHandler.UX_SPINNER, false), + WARNING_GENERAL("warning.sfgeWarnLog", 1, MessageType.WARNING, MessageHandler.UX, true), WARNING_MULTIPLE_METHOD_TARGET_MATCHES("warning.multipleMethodTargetMatches", 3, MessageType.WARNING, MessageHandler.UX, false), - WARNING_NO_METHOD_TARGET_MATCHES("warning.noMethodTargetMatches", 2, MessageType.WARNING, MessageHandler.UX, false); + WARNING_NO_METHOD_TARGET_MATCHES("warning.noMethodTargetMatches", 2, MessageType.WARNING, MessageHandler.UX, false), + ERROR_GENERAL("error.internal.sfgeErrorLog", 1, MessageType.ERROR, MessageHandler.UX, false); final String messageKey; final int argCount; diff --git a/cli-messaging/src/main/java/com/salesforce/messaging/Message.java b/cli-messaging/src/main/java/com/salesforce/messaging/Message.java index 20ba93ae0..b5df0e39e 100644 --- a/cli-messaging/src/main/java/com/salesforce/messaging/Message.java +++ b/cli-messaging/src/main/java/com/salesforce/messaging/Message.java @@ -6,7 +6,7 @@ public class Message { final private String messageKey; final private List args; - final private String internalLog; + final private String internalLog; final private MessageType type; final private MessageHandler handler; final private boolean verbose; @@ -34,8 +34,25 @@ public String getInternalLog() { return internalLog; } + public MessageType getType() { + return type; + } + + public MessageHandler getHandler() { + return handler; + } + + public boolean isVerbose() { + return verbose; + } + + public long getTime() { + return time; + } + enum MessageHandler { UX, + UX_SPINNER, INTERNAL } diff --git a/messages/EventKeyTemplates.js b/messages/EventKeyTemplates.js index a5d0f3a48..5206ccc06 100644 --- a/messages/EventKeyTemplates.js +++ b/messages/EventKeyTemplates.js @@ -7,7 +7,15 @@ module.exports = { "customEslintHeadsUp": "About to run Eslint with custom config in %s. Please make sure your current directory has all the required NPM dependencies.", "customPmdHeadsUp": "About to run PMD with custom config in %s. Please make sure that any custom rule references have already been added to the plugin through scanner:rule:add command.", "pmdRuleSkipped": "Omitting results for PMD rule \"%s\". Reason: %s.", - "unmatchedPathExtensionCpd": "Path extensions for the following files will not be processed by CPD: %s" + "unmatchedPathExtensionCpd": "Path extensions for the following files will not be processed by CPD: %s", + "sfgeInfoLog": "%s", + "sfgeMetaInfoCollected": "Loaded %s: [ %s ]", + "sfgeFinishedCompilingFiles": "Compiled %s files.", + "sfgeStartedBuildingGraph": "Building graph.", + "sfgeFinishedBuildingGraph": "Added all compilation units to graph.", + "sfgePathEntryPointsIdentified": "Identified %s path entry point(s).", + "sfgeViolationsInPathProgress": "Detected %s violation(s) from %s path(s) on %s/%s entry point(s).", + "sfgeCompletedPathAnalysis": "Overall, analyzed %s path(s) from %s entry point(s). Detected %s violation(s)." }, "warning": { "invalidCategorySkipped": "Cataloger skipped invalid PMD Category file '%s'.", @@ -20,7 +28,8 @@ module.exports = { "unexpectedPmdNodeType": "Encountered unexpected PMD node of type '%s'", "multipleMethodTargetMatches": "Total of %s methods in file %s matched name #%s", "noMethodTargetMatches": "No methods in file %s matched name #%s()", - "pmdConfigError": "PMD failed to evaluate rule '%s'. Message: %s" + "pmdConfigError": "PMD failed to evaluate rule '%s'. Message: %s", + "sfgeWarnLog": "%s" }, "error": { "internal": { @@ -28,7 +37,8 @@ module.exports = { "mainInvalidArgument": "INTERNAL ERROR: Invalid arguments passed to Main. Details: %s. Please log an issue with us at github.com/forcedotcom/sfdx-scanner.", "jsonWriteFailed": "INTERNAL ERROR: Failed to write JSON to file: %s. Please log an issue with us at github.com/forcedotcom/sfdx-scanner.", "classpathDoesNotExist": "INTERNAL ERROR: Path does not exist: %s. Please log an issue with us at github.com/forcedotcom/sfdx-scanner.", - "xmlMissingInClasspath": "INTERNAL ERROR: XML resource [%s] found in jar, but not in Classpath. Please log an issue with us at github.com/forcedotcom/sfdx-scanner." + "xmlMissingInClasspath": "INTERNAL ERROR: XML resource [%s] found in jar, but not in Classpath. Please log an issue with us at github.com/forcedotcom/sfdx-scanner.", + "sfgeErrorLog": "%s" }, "external": { "errorMessageAbove": "Please see error details displayed above.", diff --git a/sfge/src/main/java/com/salesforce/CliMessagerAppender.java b/sfge/src/main/java/com/salesforce/CliMessagerAppender.java new file mode 100644 index 000000000..9fe793a34 --- /dev/null +++ b/sfge/src/main/java/com/salesforce/CliMessagerAppender.java @@ -0,0 +1,86 @@ +package com.salesforce; + +import com.salesforce.config.SfgeConfigProvider; +import com.salesforce.messaging.CliMessager; +import com.salesforce.messaging.EventKey; +import java.io.Serializable; +import org.apache.logging.log4j.Level; +import org.apache.logging.log4j.core.Appender; +import org.apache.logging.log4j.core.Core; +import org.apache.logging.log4j.core.Filter; +import org.apache.logging.log4j.core.Layout; +import org.apache.logging.log4j.core.LogEvent; +import org.apache.logging.log4j.core.appender.AbstractAppender; +import org.apache.logging.log4j.core.config.plugins.Plugin; +import org.apache.logging.log4j.core.config.plugins.PluginAttribute; +import org.apache.logging.log4j.core.config.plugins.PluginElement; +import org.apache.logging.log4j.core.config.plugins.PluginFactory; +import org.apache.logging.log4j.core.layout.PatternLayout; + +/** + * Custom log4j2 appender to send logs as realtime events through {@link CliMessager}. This helps + * streamline logs displayed to commandline users. Invoked from log4j.xml. + */ +@Plugin( + name = "CliMessagerAppender", + category = Core.CATEGORY_NAME, + elementType = Appender.ELEMENT_TYPE) +public class CliMessagerAppender extends AbstractAppender { + + private final boolean shouldLogWarningsOnVerbose; + + @PluginFactory + public static CliMessagerAppender createAppender( + @PluginAttribute("name") String name, + @PluginElement("Layout") Layout layout, + @PluginElement("Filter") final Filter filter) { + if (name == null) { + // Assign default name to avoid complaining + name = "CliMessagerAppender"; + } + if (layout == null) { + layout = PatternLayout.createDefaultLayout(); + } + return new CliMessagerAppender(name, filter, layout, true); + } + + protected CliMessagerAppender( + String name, + Filter filter, + Layout layout, + final boolean ignoreExceptions) { + super(name, filter, layout, ignoreExceptions, null); + this.shouldLogWarningsOnVerbose = SfgeConfigProvider.get().shouldLogWarningsOnVerbose(); + } + + /** + * {@link CliMessagerAppender} decrements the log level while publishing to CLI. Warning is + * reduced to Info, Error is reduced to Warning, Fatal is reduced to Error. + * + * @param event that was published from code + */ + @Override + public void append(LogEvent event) { + Level level = event.getLevel(); + if (Level.WARN.equals(level) && this.shouldLogWarningsOnVerbose) { + CliMessager.postMessage( + "SFGE Warning as Info", EventKey.INFO_GENERAL, getEventMessage(event)); + } else if (Level.ERROR.equals(level)) { + CliMessager.postMessage( + "SFGE Error as Warning", EventKey.WARNING_GENERAL, getEventMessage(event)); + } else if (Level.FATAL.equals(level)) { + CliMessager.postMessage( + "SFGE Fatal as Error", EventKey.ERROR_GENERAL, getEventMessage(event)); + } else { + error( + String.format( + "Unable to log less than WARN level [{}]: {}", + event.getLevel(), + getEventMessage(event))); + } + } + + private String getEventMessage(LogEvent event) { + return event.getMessage().getFormattedMessage(); + } +} diff --git a/sfge/src/main/java/com/salesforce/Main.java b/sfge/src/main/java/com/salesforce/Main.java index 3b850f895..4634f88d7 100644 --- a/sfge/src/main/java/com/salesforce/Main.java +++ b/sfge/src/main/java/com/salesforce/Main.java @@ -14,6 +14,7 @@ import com.salesforce.rules.RuleRunner; import com.salesforce.rules.RuleUtil; import com.salesforce.rules.Violation; +import com.salesforce.rules.ops.ProgressListenerProvider; import java.util.Arrays; import java.util.Collection; import java.util.List; @@ -146,6 +147,7 @@ private int execute(String... args) { List allViolations; try { allViolations = new RuleRunner(g).runRules(eap.getSelectedRules(), eap.getTargets()); + ProgressListenerProvider.get().completedAnalysis(); } catch (SfgeRuntimeException ex) { LOGGER.error("Error while running rules", ex); System.err.println(formatError(ex)); @@ -172,6 +174,11 @@ private void collectMetaInfo(CliArgParser.ExecuteArgParser eap) { for (MetaInfoCollector collector : allCollectors) { collector.loadProjectFiles(eap.getProjectDirs()); + + // Let progress listener know about the meta information collected + ProgressListenerProvider.get() + .collectedMetaInfo( + collector.getMetaInfoTypeName(), collector.getMetaInfoCollected()); } } diff --git a/sfge/src/main/java/com/salesforce/config/EnvUtil.java b/sfge/src/main/java/com/salesforce/config/EnvUtil.java index b2b913675..afe45194f 100644 --- a/sfge/src/main/java/com/salesforce/config/EnvUtil.java +++ b/sfge/src/main/java/com/salesforce/config/EnvUtil.java @@ -9,6 +9,8 @@ public final class EnvUtil { private static final String ENV_RULE_ENABLE_WARNING_VIOLATION = "SFGE_RULE_ENABLE_WARNING_VIOLATION"; private static final String ENV_IGNORE_PARSE_ERRORS = "SFGE_IGNORE_PARSE_ERRORS"; + private static final String ENV_LOG_WARNINGS_ON_VERBOSE = "SFGE_LOG_WARNINGS_ON_VERBOSE"; + private static final String ENV_PROGRESS_INCREMENTS = "SFGE_PROGRESS_INCREMENTS"; // TODO: These should move to SfgeConfigImpl and this class should return Optionals @VisibleForTesting @@ -21,6 +23,8 @@ public final class EnvUtil { @VisibleForTesting static final boolean DEFAULT_RULE_ENABLE_WARNING_VIOLATION = true; @VisibleForTesting static final boolean DEFAULT_IGNORE_PARSE_ERRORS = false; + @VisibleForTesting static final boolean DEFAULT_LOG_WARNINGS_ON_VERBOSE = false; + @VisibleForTesting static final int DEFAULT_PROGRESS_INCREMENTS = 10; /** * Returns the value of the {@link #ENV_RULE_THREAD_COUNT} environment variable if set, else @@ -61,6 +65,27 @@ static boolean shouldIgnoreParseErrors() { return getBoolOrDefault(ENV_IGNORE_PARSE_ERRORS, DEFAULT_IGNORE_PARSE_ERRORS); } + /** + * Indicates if SFGE should log internal warnings on --verbose + * + * @return value of {@link #ENV_LOG_WARNINGS_ON_VERBOSE} env variable. If it is not set, {@link + * #DEFAULT_LOG_WARNINGS_ON_VERBOSE} + */ + static boolean shouldLogWarningsOnVerbose() { + return getBoolOrDefault(ENV_LOG_WARNINGS_ON_VERBOSE, DEFAULT_LOG_WARNINGS_ON_VERBOSE); + } + + /** + * Gets the level of increments at which path analysis progress update is provided. Applicable + * only with --verbose. + * + * @return value of {@link #ENV_PROGRESS_INCREMENTS} environment variable if set, else {@link + * #DEFAULT_PROGRESS_INCREMENTS} + */ + static int getProgressIncrements() { + return getIntOrDefault(ENV_PROGRESS_INCREMENTS, DEFAULT_PROGRESS_INCREMENTS); + } + private static int getIntOrDefault(String name, int defaultValue) { String strVal = System.getProperty(name); return strVal == null ? defaultValue : Integer.parseInt(strVal); diff --git a/sfge/src/main/java/com/salesforce/config/SfgeConfig.java b/sfge/src/main/java/com/salesforce/config/SfgeConfig.java index 1503614e9..9cbc3da47 100644 --- a/sfge/src/main/java/com/salesforce/config/SfgeConfig.java +++ b/sfge/src/main/java/com/salesforce/config/SfgeConfig.java @@ -16,4 +16,16 @@ public interface SfgeConfig { /** Indicates if a Jorje parse error causes the entire process to stop. */ boolean shouldIgnoreParseErrors(); + + /** + * Indicates if Warn level logs to log4j should be forwarded to CLI as well when verbose is + * enabled + */ + boolean shouldLogWarningsOnVerbose(); + + /** + * Should be used to set the level of increments at which path analysis progress update is + * provided + */ + int getProgressIncrements(); } diff --git a/sfge/src/main/java/com/salesforce/config/SfgeConfigImpl.java b/sfge/src/main/java/com/salesforce/config/SfgeConfigImpl.java index fd45a735e..fad94991f 100644 --- a/sfge/src/main/java/com/salesforce/config/SfgeConfigImpl.java +++ b/sfge/src/main/java/com/salesforce/config/SfgeConfigImpl.java @@ -25,6 +25,16 @@ public boolean shouldIgnoreParseErrors() { return EnvUtil.shouldIgnoreParseErrors(); } + @Override + public boolean shouldLogWarningsOnVerbose() { + return EnvUtil.shouldLogWarningsOnVerbose(); + } + + @Override + public int getProgressIncrements() { + return EnvUtil.getProgressIncrements(); + } + static SfgeConfigImpl getInstance() { return SfgeConfigImpl.LazyHolder.INSTANCE; } diff --git a/sfge/src/main/java/com/salesforce/graph/ops/GraphUtil.java b/sfge/src/main/java/com/salesforce/graph/ops/GraphUtil.java index b6385ddfe..c414eb199 100644 --- a/sfge/src/main/java/com/salesforce/graph/ops/GraphUtil.java +++ b/sfge/src/main/java/com/salesforce/graph/ops/GraphUtil.java @@ -20,6 +20,8 @@ import com.salesforce.graph.vertex.BaseSFVertex; import com.salesforce.graph.vertex.SFVertexFactory; import com.salesforce.io.FileHandler; +import com.salesforce.rules.ops.ProgressListener; +import com.salesforce.rules.ops.ProgressListenerProvider; import java.io.File; import java.io.IOException; import java.nio.file.FileVisitResult; @@ -154,8 +156,17 @@ public static void loadSourceFolders(GraphTraversalSource g, List source } } + final ProgressListener progressListener = ProgressListenerProvider.get(); + + // Let progress listener know that we've finished compiling all the files in project + progressListener.finishedFileCompilation(); + Util.Config config = Util.Config.Builder.get(g, comps).build(); + + // Let progress listener know what we are doing + progressListener.startedBuildingGraph(); Util.buildGraph(config); + progressListener.completedBuildingGraph(); } private static List buildFolderComps(String sourceFolder) @@ -182,6 +193,8 @@ private static List buildFolderComps(String sourceFo private static Optional loadFile(Path path) throws IOException { String pathString = path.toString(); + final ProgressListener progressListener = ProgressListenerProvider.get(); + if (!pathString.toLowerCase(Locale.ROOT).endsWith(".cls")) { if (LOGGER.isDebugEnabled()) { LOGGER.debug("Skipping file. path=" + pathString); @@ -194,6 +207,8 @@ private static Optional loadFile(Path path) throws I } String sourceCode = FileHandler.getInstance().readTargetFile(pathString); AstNodeWrapper astNodeWrapper = JorjeUtil.compileApexFromString(sourceCode); + // Let progress listener know that we've compiled another file + progressListener.compiledAnotherFile(); return Optional.of(new Util.CompilationDescriptor(pathString, astNodeWrapper)); } catch (JorjeUtil.JorjeCompilationException ex) { if (SfgeConfigProvider.get().shouldIgnoreParseErrors()) { diff --git a/sfge/src/main/java/com/salesforce/graph/symbols/PathScopeVisitor.java b/sfge/src/main/java/com/salesforce/graph/symbols/PathScopeVisitor.java index 00e3d8b2e..15007bf5e 100644 --- a/sfge/src/main/java/com/salesforce/graph/symbols/PathScopeVisitor.java +++ b/sfge/src/main/java/com/salesforce/graph/symbols/PathScopeVisitor.java @@ -388,7 +388,7 @@ public Optional> getApexValue(VariableExpressionVertex var) { if (LOGGER.isWarnEnabled()) { LOGGER.warn( "TODO: PathScopeVisitor.getApexValue() can currently only support chains of length 2 or lower. keySequence=" - + keys); + + Arrays.toString(keys)); } return Optional.empty(); } @@ -600,7 +600,7 @@ public Optional getImplementingScope( if (LOGGER.isWarnEnabled()) { LOGGER.warn( "TODO: PathScopeVisitor.getApexValue() can currently only support chains of length 2 or lower. keySequence=" - + keys); + + Arrays.toString(keys)); } return Optional.empty(); } diff --git a/sfge/src/main/java/com/salesforce/graph/symbols/ScopeUtil.java b/sfge/src/main/java/com/salesforce/graph/symbols/ScopeUtil.java index 42a8cef79..f48c204a1 100644 --- a/sfge/src/main/java/com/salesforce/graph/symbols/ScopeUtil.java +++ b/sfge/src/main/java/com/salesforce/graph/symbols/ScopeUtil.java @@ -11,6 +11,7 @@ import com.salesforce.graph.vertex.LiteralExpressionVertex; import com.salesforce.graph.vertex.PrefixExpressionVertex; import com.salesforce.graph.vertex.VariableExpressionVertex; +import java.util.Arrays; import java.util.Optional; import org.apache.logging.log4j.LogManager; import org.apache.logging.log4j.Logger; @@ -151,8 +152,8 @@ public static Optional> getDefaultPropertyValue( if (keys.length > 2) { if (LOGGER.isWarnEnabled()) { LOGGER.warn( - "TODO: PathScopeVisitor.getApexValue() can currently only support chains of length 2 or lower. keySequence=" - + keys); + "PathScopeVisitor.getApexValue() can currently only support chains of length 2 or lower. keySequence=" + + Arrays.toString(keys)); } } else if (result instanceof ObjectProperties) { final ObjectProperties objectProperties = (ObjectProperties) result; diff --git a/sfge/src/main/java/com/salesforce/metainfo/CustomSettingInfoCollector.java b/sfge/src/main/java/com/salesforce/metainfo/CustomSettingInfoCollector.java index 8231716c9..342e2a6f4 100644 --- a/sfge/src/main/java/com/salesforce/metainfo/CustomSettingInfoCollector.java +++ b/sfge/src/main/java/com/salesforce/metainfo/CustomSettingInfoCollector.java @@ -24,6 +24,7 @@ public class CustomSettingInfoCollector extends XmlMetaInfoCollector { private static final String CUSTOM_SETTING_PATTERN_STRING = "(.*)" + OBJECT_FILE_NAME_PATTERN; private static final Pattern CUSTOM_SETTING_PATTERN = Pattern.compile(CUSTOM_SETTING_PATTERN_STRING, Pattern.CASE_INSENSITIVE); + private static final String META_INFO_TYPE_NAME = "Custom Settings"; @Override HashSet getPathPatterns() { @@ -88,6 +89,11 @@ private Optional getCustomSettingName(Path path) { return Optional.empty(); } + @Override + public String getMetaInfoTypeName() { + return META_INFO_TYPE_NAME; + } + protected static final class LazyHolder { // Postpone initialization until first use. protected static final CustomSettingInfoCollector INSTANCE = diff --git a/sfge/src/main/java/com/salesforce/metainfo/MetaInfoCollector.java b/sfge/src/main/java/com/salesforce/metainfo/MetaInfoCollector.java index 5b214c2bc..7038087aa 100644 --- a/sfge/src/main/java/com/salesforce/metainfo/MetaInfoCollector.java +++ b/sfge/src/main/java/com/salesforce/metainfo/MetaInfoCollector.java @@ -19,6 +19,8 @@ public interface MetaInfoCollector { */ TreeSet getMetaInfoCollected(); + String getMetaInfoTypeName(); + /** Thrown when project files cannot be properly loaded/processed. */ final class MetaInfoLoadException extends SfgeRuntimeException { MetaInfoLoadException(String msg) { diff --git a/sfge/src/main/java/com/salesforce/metainfo/VisualForceHandlerImpl.java b/sfge/src/main/java/com/salesforce/metainfo/VisualForceHandlerImpl.java index 53def4dba..85c6b5e14 100644 --- a/sfge/src/main/java/com/salesforce/metainfo/VisualForceHandlerImpl.java +++ b/sfge/src/main/java/com/salesforce/metainfo/VisualForceHandlerImpl.java @@ -15,6 +15,7 @@ public class VisualForceHandlerImpl extends AbstractMetaInfoCollector { private static final Logger LOGGER = LogManager.getLogger(VisualForceHandlerImpl.class); + private static final String META_INFO_TYPE_NAME = "Apex Controllers"; @Override protected TreeSet getAcceptedExtensions() { @@ -213,6 +214,11 @@ private void addReferencedNames(String concatenatedNames) { } } + @Override + public String getMetaInfoTypeName() { + return META_INFO_TYPE_NAME; + } + protected static final class LazyHolder { // Postpone initialization until first use. protected static final VisualForceHandlerImpl INSTANCE = new VisualForceHandlerImpl(); diff --git a/sfge/src/main/java/com/salesforce/rules/AbstractRuleRunner.java b/sfge/src/main/java/com/salesforce/rules/AbstractRuleRunner.java index b97595a82..f1b773db9 100644 --- a/sfge/src/main/java/com/salesforce/rules/AbstractRuleRunner.java +++ b/sfge/src/main/java/com/salesforce/rules/AbstractRuleRunner.java @@ -6,6 +6,7 @@ import com.salesforce.graph.Schema; import com.salesforce.graph.build.CaseSafePropertyUtil.H; import com.salesforce.graph.vertex.MethodVertex; +import com.salesforce.rules.ops.ProgressListenerProvider; import java.util.ArrayList; import java.util.HashSet; import java.util.List; @@ -87,6 +88,9 @@ private Set runPathBasedRules( return new HashSet<>(); } + // Let listener know that we have finished identifying entry points in target + ProgressListenerProvider.get().pathEntryPointsIdentified(pathEntryPoints.size()); + // For each entry point, generate a submission object. List submissions = new ArrayList<>(); for (MethodVertex pathEntryPoint : pathEntryPoints) { diff --git a/sfge/src/main/java/com/salesforce/rules/PathBasedRuleRunner.java b/sfge/src/main/java/com/salesforce/rules/PathBasedRuleRunner.java index 816f3ada0..0aa527108 100644 --- a/sfge/src/main/java/com/salesforce/rules/PathBasedRuleRunner.java +++ b/sfge/src/main/java/com/salesforce/rules/PathBasedRuleRunner.java @@ -10,6 +10,8 @@ import com.salesforce.graph.vertex.SFVertex; import com.salesforce.rules.fls.apex.operations.FlsViolationInfo; import com.salesforce.rules.fls.apex.operations.FlsViolationMessageUtil; +import com.salesforce.rules.ops.ProgressListener; +import com.salesforce.rules.ops.ProgressListenerProvider; import java.util.HashSet; import java.util.List; import java.util.Optional; @@ -28,12 +30,15 @@ public class PathBasedRuleRunner { /** Set that holds the violations found by this rule execution. */ private final Set violations; + private final ProgressListener progressListener; + public PathBasedRuleRunner( GraphTraversalSource g, List rules, MethodVertex methodVertex) { this.g = g; this.rules = rules; this.methodVertex = methodVertex; this.violations = new HashSet<>(); + this.progressListener = ProgressListenerProvider.get(); } /** @@ -65,6 +70,8 @@ public Set runRules() { } } + progressListener.finishedAnalyzingEntryPoint(paths, violations); + return violations; } diff --git a/sfge/src/main/java/com/salesforce/rules/ThreadableRuleExecutor.java b/sfge/src/main/java/com/salesforce/rules/ThreadableRuleExecutor.java index 0ff506365..72724e1d5 100644 --- a/sfge/src/main/java/com/salesforce/rules/ThreadableRuleExecutor.java +++ b/sfge/src/main/java/com/salesforce/rules/ThreadableRuleExecutor.java @@ -5,6 +5,8 @@ import com.salesforce.graph.JustInTimeGraphProvider; import com.salesforce.graph.ops.LogUtil; import com.salesforce.graph.vertex.MethodVertex; +import com.salesforce.rules.ops.ProgressListener; +import com.salesforce.rules.ops.ProgressListenerProvider; import java.util.List; import java.util.Set; import java.util.Timer; @@ -78,8 +80,9 @@ private static int submitRunners( CompletionService> completionService, List submissions) { int submissionCount = 0; + final ProgressListener progressListener = ProgressListenerProvider.get(); for (ThreadableRuleSubmission submission : submissions) { - completionService.submit(new CallableExecutor(submission)); + completionService.submit(new CallableExecutor(submission, progressListener)); submissionCount += 1; } if (LOGGER.isInfoEnabled()) { @@ -113,7 +116,8 @@ private static class CallableExecutor implements Callable> { private final ThreadableRuleSubmission submission; private boolean timedOut; - public CallableExecutor(ThreadableRuleSubmission submission) { + public CallableExecutor( + ThreadableRuleSubmission submission, ProgressListener progressListener) { this.submission = submission; } diff --git a/sfge/src/main/java/com/salesforce/rules/ops/ProgressListener.java b/sfge/src/main/java/com/salesforce/rules/ops/ProgressListener.java new file mode 100644 index 000000000..2cfbd727a --- /dev/null +++ b/sfge/src/main/java/com/salesforce/rules/ops/ProgressListener.java @@ -0,0 +1,48 @@ +package com.salesforce.rules.ops; + +import com.salesforce.graph.ApexPath; +import com.salesforce.rules.Violation; +import java.util.List; +import java.util.Set; +import java.util.TreeSet; + +/** Observer that listens to activities happening in SFGE while analyzing source code. */ +public interface ProgressListener { + /** + * Invoked when meta information about source code is collected + * + * @param metaInfoType type of information + * @param itemsCollected items that were collected + */ + void collectedMetaInfo(String metaInfoType, TreeSet itemsCollected); + + /** Invoked when a file is compiled by Jorje. */ + void compiledAnotherFile(); + + /** Invoked when compilation is completed for all files. */ + void finishedFileCompilation(); + + /** Invoked when SFGE starts building the graph with information found during compilation. */ + void startedBuildingGraph(); + + /** Invoked when SFGE completes building graph. */ + void completedBuildingGraph(); + + /** + * Invoked when entry points to analysis are identified. + * + * @param pathEntryPointsCount number of entry points identified. + */ + void pathEntryPointsIdentified(int pathEntryPointsCount); + + /** + * Invoked when all the paths originating from an entry point are analyzed. + * + * @param paths number of paths that originated from an entry point. + * @param violations number of violations detected while walking the identified paths. + */ + void finishedAnalyzingEntryPoint(List paths, Set violations); + + /** Invoked when analysis is finished. */ + void completedAnalysis(); +} diff --git a/sfge/src/main/java/com/salesforce/rules/ops/ProgressListenerImpl.java b/sfge/src/main/java/com/salesforce/rules/ops/ProgressListenerImpl.java new file mode 100644 index 000000000..a695113d1 --- /dev/null +++ b/sfge/src/main/java/com/salesforce/rules/ops/ProgressListenerImpl.java @@ -0,0 +1,153 @@ +package com.salesforce.rules.ops; + +import com.google.common.annotations.VisibleForTesting; +import com.google.common.base.Joiner; +import com.salesforce.config.SfgeConfigProvider; +import com.salesforce.graph.ApexPath; +import com.salesforce.messaging.CliMessager; +import com.salesforce.messaging.EventKey; +import com.salesforce.rules.Violation; +import java.util.Collection; +import java.util.List; +import java.util.Set; +import java.util.TreeSet; + +/** Publishes realtime information to CLI on the progress of analysis. */ +public class ProgressListenerImpl implements ProgressListener { + + @VisibleForTesting static final String NONE_FOUND = "none found"; + + private int filesCompiled = 0; + private int pathsDetected = 0; + private int lastPathCountReported = 0; + private int violationsDetected = 0; + private int entryPointsAnalyzed = 0; + private int totalEntryPoints = 0; + + private final int progressIncrements; + + static ProgressListener getInstance() { + return ProgressListenerImpl.LazyHolder.INSTANCE; + } + + private static final class LazyHolder { + private static final ProgressListenerImpl INSTANCE = new ProgressListenerImpl(); + } + + @VisibleForTesting + ProgressListenerImpl() { + progressIncrements = SfgeConfigProvider.get().getProgressIncrements(); + } + + @Override + public void collectedMetaInfo(String metaInfoType, TreeSet itemsCollected) { + final String items = stringify(itemsCollected); + CliMessager.postMessage( + "Meta information collected", + EventKey.INFO_META_INFO_COLLECTED, + metaInfoType, + items); + } + + @Override + public void compiledAnotherFile() { + filesCompiled++; + } + + @Override + public void finishedFileCompilation() { + CliMessager.postMessage( + "Finished compiling files", + EventKey.INFO_COMPLETED_FILE_COMPILATION, + String.valueOf(filesCompiled)); + } + + @Override + public void startedBuildingGraph() { + CliMessager.postMessage("Started building graph", EventKey.INFO_STARTED_BUILDING_GRAPH); + } + + @Override + public void completedBuildingGraph() { + CliMessager.postMessage("Finished building graph", EventKey.INFO_COMPLETED_BUILDING_GRAPH); + } + + @Override + public void pathEntryPointsIdentified(int pathEntryPointsCount) { + totalEntryPoints = pathEntryPointsCount; + CliMessager.postMessage( + "Path entry points identified", + EventKey.INFO_PATH_ENTRY_POINTS_IDENTIFIED, + String.valueOf(totalEntryPoints)); + } + + @Override + public void finishedAnalyzingEntryPoint(List paths, Set violations) { + pathsDetected += paths.size(); + violationsDetected += violations.size(); + entryPointsAnalyzed++; + + // Make a post only if we have more paths detected than the progress increments + // since the last time we posted. + if (pathsDetected - lastPathCountReported >= progressIncrements) { + CliMessager.postMessage( + "Count of violations in paths, entry points", + EventKey.INFO_PATH_ANALYSIS_PROGRESS, + String.valueOf(violationsDetected), + String.valueOf(pathsDetected), + String.valueOf(entryPointsAnalyzed), + String.valueOf(totalEntryPoints)); + + lastPathCountReported = pathsDetected; + } + } + + @Override + public void completedAnalysis() { + CliMessager.postMessage( + "Completed analysis stats", + EventKey.INFO_COMPLETED_PATH_ANALYSIS, + String.valueOf(pathsDetected), + String.valueOf(entryPointsAnalyzed), + String.valueOf(violationsDetected)); + } + + @VisibleForTesting + String stringify(Collection items) { + return (items.isEmpty()) ? NONE_FOUND : Joiner.on(',').join(items); + } + + @VisibleForTesting + void reset() { + filesCompiled = 0; + pathsDetected = 0; + lastPathCountReported = 0; + violationsDetected = 0; + entryPointsAnalyzed = 0; + } + + @VisibleForTesting + int getFilesCompiled() { + return filesCompiled; + } + + @VisibleForTesting + int getPathsDetected() { + return pathsDetected; + } + + @VisibleForTesting + int getLastPathCountReported() { + return lastPathCountReported; + } + + @VisibleForTesting + int getViolationsDetected() { + return violationsDetected; + } + + @VisibleForTesting + int getEntryPointsAnalyzed() { + return entryPointsAnalyzed; + } +} diff --git a/sfge/src/main/java/com/salesforce/rules/ops/ProgressListenerProvider.java b/sfge/src/main/java/com/salesforce/rules/ops/ProgressListenerProvider.java new file mode 100644 index 000000000..e50cd0868 --- /dev/null +++ b/sfge/src/main/java/com/salesforce/rules/ops/ProgressListenerProvider.java @@ -0,0 +1,17 @@ +package com.salesforce.rules.ops; + +import com.google.common.annotations.VisibleForTesting; + +/** Provides the singleton instance of {@link ProgressListener} in a thread-safe way. */ +public class ProgressListenerProvider { + @VisibleForTesting + static final ThreadLocal PROGRESS_LISTENER = + ThreadLocal.withInitial(() -> ProgressListenerImpl.getInstance()); + + /** Get the ProgressListener for the current thread */ + public static ProgressListener get() { + return PROGRESS_LISTENER.get(); + } + + private ProgressListenerProvider() {} +} diff --git a/sfge/src/main/resources/log4j2.xml b/sfge/src/main/resources/log4j2.xml index cd26f44bb..f69d0b0f7 100644 --- a/sfge/src/main/resources/log4j2.xml +++ b/sfge/src/main/resources/log4j2.xml @@ -1,7 +1,10 @@ - + + + + @@ -16,38 +19,33 @@ - + - + - - - - - - + diff --git a/sfge/src/test/java/com/salesforce/SfgeTestExtension.java b/sfge/src/test/java/com/salesforce/SfgeTestExtension.java index 36cf3450c..de875ad2a 100644 --- a/sfge/src/test/java/com/salesforce/SfgeTestExtension.java +++ b/sfge/src/test/java/com/salesforce/SfgeTestExtension.java @@ -4,6 +4,7 @@ import com.salesforce.graph.TestMetadataInfo; import com.salesforce.graph.cache.VertexCacheTestProvider; import com.salesforce.metainfo.MetaInfoCollectorTestProvider; +import com.salesforce.rules.ops.ProgressListenerTestProvider; import org.apache.logging.log4j.LogManager; import org.apache.logging.log4j.Logger; import org.junit.jupiter.api.extension.BeforeTestExecutionCallback; @@ -31,6 +32,7 @@ public void beforeTestExecution(ExtensionContext context) { MetadataInfoTestProvider.initializeForTest(); VertexCacheTestProvider.initializeForTest(); MetaInfoCollectorTestProvider.initializeForTest(); + ProgressListenerTestProvider.initializeForTest(); } /** @@ -45,5 +47,6 @@ public void preDestroyTestInstance(ExtensionContext context) { MetadataInfoTestProvider.remove(); VertexCacheTestProvider.remove(); MetaInfoCollectorTestProvider.remove(); + ProgressListenerTestProvider.remove(); } } diff --git a/sfge/src/test/java/com/salesforce/config/SfgeConfigProviderTest.java b/sfge/src/test/java/com/salesforce/config/SfgeConfigProviderTest.java index 0afed7b93..189d20a92 100644 --- a/sfge/src/test/java/com/salesforce/config/SfgeConfigProviderTest.java +++ b/sfge/src/test/java/com/salesforce/config/SfgeConfigProviderTest.java @@ -41,6 +41,16 @@ public boolean isWarningViolationEnabled() { public boolean shouldIgnoreParseErrors() { return !EnvUtil.DEFAULT_IGNORE_PARSE_ERRORS; } + + @Override + public boolean shouldLogWarningsOnVerbose() { + return !EnvUtil.DEFAULT_LOG_WARNINGS_ON_VERBOSE; + } + + @Override + public int getProgressIncrements() { + return -1 * EnvUtil.DEFAULT_PROGRESS_INCREMENTS; + } }); final SfgeConfig sfgeConfig = SfgeConfigProvider.get(); @@ -57,6 +67,12 @@ public boolean shouldIgnoreParseErrors() { MatcherAssert.assertThat( sfgeConfig.shouldIgnoreParseErrors(), equalTo(!EnvUtil.DEFAULT_IGNORE_PARSE_ERRORS)); + MatcherAssert.assertThat( + sfgeConfig.shouldLogWarningsOnVerbose(), + equalTo(!EnvUtil.DEFAULT_LOG_WARNINGS_ON_VERBOSE)); + MatcherAssert.assertThat( + sfgeConfig.getProgressIncrements(), + equalTo(-1 * EnvUtil.getProgressIncrements())); } finally { SfgeConfigTestProvider.remove(); } @@ -80,5 +96,10 @@ private void assertDefaultImplementation(SfgeConfig sfgeConfig) { equalTo(EnvUtil.DEFAULT_RULE_ENABLE_WARNING_VIOLATION)); MatcherAssert.assertThat( sfgeConfig.shouldIgnoreParseErrors(), equalTo(EnvUtil.DEFAULT_IGNORE_PARSE_ERRORS)); + MatcherAssert.assertThat( + sfgeConfig.shouldLogWarningsOnVerbose(), + equalTo(EnvUtil.DEFAULT_LOG_WARNINGS_ON_VERBOSE)); + MatcherAssert.assertThat( + sfgeConfig.getProgressIncrements(), equalTo(EnvUtil.DEFAULT_PROGRESS_INCREMENTS)); } } diff --git a/sfge/src/test/java/com/salesforce/config/TestSfgeConfig.java b/sfge/src/test/java/com/salesforce/config/TestSfgeConfig.java index 13fe0adeb..c6eecb136 100644 --- a/sfge/src/test/java/com/salesforce/config/TestSfgeConfig.java +++ b/sfge/src/test/java/com/salesforce/config/TestSfgeConfig.java @@ -24,4 +24,14 @@ public boolean isWarningViolationEnabled() { public boolean shouldIgnoreParseErrors() { return SfgeConfigImpl.getInstance().shouldIgnoreParseErrors(); } + + @Override + public boolean shouldLogWarningsOnVerbose() { + return SfgeConfigImpl.getInstance().shouldLogWarningsOnVerbose(); + } + + @Override + public int getProgressIncrements() { + return SfgeConfigImpl.getInstance().getProgressIncrements(); + } } diff --git a/sfge/src/test/java/com/salesforce/rules/ops/ProgressListenerImplTest.java b/sfge/src/test/java/com/salesforce/rules/ops/ProgressListenerImplTest.java new file mode 100644 index 000000000..5f5dff5e9 --- /dev/null +++ b/sfge/src/test/java/com/salesforce/rules/ops/ProgressListenerImplTest.java @@ -0,0 +1,92 @@ +package com.salesforce.rules.ops; + +import static org.hamcrest.MatcherAssert.assertThat; +import static org.hamcrest.Matchers.equalTo; + +import com.google.common.collect.Lists; +import com.google.common.collect.Sets; +import com.salesforce.config.SfgeConfigTestProvider; +import com.salesforce.config.TestSfgeConfig; +import com.salesforce.graph.ApexPath; +import com.salesforce.rules.Violation; +import com.salesforce.testutils.DummyVertex; +import java.util.ArrayList; +import java.util.List; +import java.util.Set; +import org.junit.jupiter.api.BeforeEach; +import org.junit.jupiter.api.Test; + +public class ProgressListenerImplTest { + + final ProgressListenerImpl progressListener; + + public ProgressListenerImplTest() { + SfgeConfigTestProvider.set( + new TestSfgeConfig() { + @Override + public int getProgressIncrements() { + return 3; + } + }); + + // Creating an instance directly to avoid conflicts with other tests + progressListener = new ProgressListenerImpl(); + } + + @BeforeEach + public void beforeEach() { + progressListener.reset(); + } + + @Test + public void testCompiledAnotherFile() { + progressListener.compiledAnotherFile(); + assertThat(progressListener.getFilesCompiled(), equalTo(1)); + } + + @Test + public void testFinishedAnalyzingEntryPoint() { + List paths = Lists.newArrayList(new ApexPath(null), new ApexPath(null)); + Set violations = + Sets.newHashSet( + new Violation.InternalErrorViolation("details", new DummyVertex("label"))); + + progressListener.finishedAnalyzingEntryPoint(paths, violations); + assertThat(progressListener.getPathsDetected(), equalTo(2)); + assertThat(progressListener.getViolationsDetected(), equalTo(1)); + assertThat(progressListener.getEntryPointsAnalyzed(), equalTo(1)); + assertThat(progressListener.getLastPathCountReported(), equalTo(0)); + } + + @Test + public void testFinishedAnalyzingEntryPoint_progressIncrement() { + List paths = Lists.newArrayList(new ApexPath(null), new ApexPath(null)); + Set violations = + Sets.newHashSet( + new Violation.InternalErrorViolation("details", new DummyVertex("label"))); + + progressListener.finishedAnalyzingEntryPoint(paths, violations); + assertThat(progressListener.getPathsDetected(), equalTo(2)); + assertThat(progressListener.getViolationsDetected(), equalTo(1)); + assertThat(progressListener.getEntryPointsAnalyzed(), equalTo(1)); + assertThat(progressListener.getLastPathCountReported(), equalTo(0)); + + progressListener.finishedAnalyzingEntryPoint(paths, violations); + assertThat(progressListener.getPathsDetected(), equalTo(4)); + assertThat(progressListener.getViolationsDetected(), equalTo(2)); + assertThat(progressListener.getEntryPointsAnalyzed(), equalTo(2)); + assertThat(progressListener.getLastPathCountReported(), equalTo(4)); + } + + @Test + public void testStringify() { + final List items = Lists.newArrayList("one", "two"); + assertThat(progressListener.stringify(items), equalTo("one,two")); + } + + @Test + public void testStringifyEmpty() { + final List items = new ArrayList<>(); + assertThat(progressListener.stringify(items), equalTo(ProgressListenerImpl.NONE_FOUND)); + } +} diff --git a/sfge/src/test/java/com/salesforce/rules/ops/ProgressListenerTestProvider.java b/sfge/src/test/java/com/salesforce/rules/ops/ProgressListenerTestProvider.java new file mode 100644 index 000000000..c378e58c3 --- /dev/null +++ b/sfge/src/test/java/com/salesforce/rules/ops/ProgressListenerTestProvider.java @@ -0,0 +1,26 @@ +package com.salesforce.rules.ops; + +import com.salesforce.SfgeTestExtension; +import org.junit.jupiter.api.extension.ExtensionContext; + +/** + * Test implementation that overrides behavior of {@link ProgressListenerProvider}. Initializes a + * test with a unique {@link ProgressListener} implementation for the current thread. + */ +public class ProgressListenerTestProvider { + /** + * Create a new ProgressListenerImpl for the current thread. This is invoked from {@link + * SfgeTestExtension#beforeTestExecution(ExtensionContext)} for all tests. + */ + public static void initializeForTest() { + ProgressListenerProvider.PROGRESS_LISTENER.set(new TestProgressListenerImpl()); + } + + /** + * Remove the ProgressListener from the current thread. This is invoked from {@link + * SfgeTestExtension#preDestroyTestInstance(ExtensionContext)} for all tests. + */ + public static void remove() { + ProgressListenerProvider.PROGRESS_LISTENER.remove(); + } +} diff --git a/sfge/src/test/java/com/salesforce/rules/ops/TestProgressListenerImpl.java b/sfge/src/test/java/com/salesforce/rules/ops/TestProgressListenerImpl.java new file mode 100644 index 000000000..b0ca29ca5 --- /dev/null +++ b/sfge/src/test/java/com/salesforce/rules/ops/TestProgressListenerImpl.java @@ -0,0 +1,50 @@ +package com.salesforce.rules.ops; + +import com.salesforce.graph.ApexPath; +import com.salesforce.rules.Violation; +import java.util.List; +import java.util.Set; +import java.util.TreeSet; + +/** Test implementation of {@link ProgressListener} to use as a non-singleton with tests */ +public class TestProgressListenerImpl implements ProgressListener { + @Override + public void collectedMetaInfo(String metaInfoType, TreeSet itemsCollected) { + // do nothing + } + + @Override + public void compiledAnotherFile() { + // do nothing + } + + @Override + public void finishedFileCompilation() { + // do nothing + } + + @Override + public void startedBuildingGraph() { + // do nothing + } + + @Override + public void completedBuildingGraph() { + // do nothing + } + + @Override + public void pathEntryPointsIdentified(int pathEntryPointsCount) { + // do nothing + } + + @Override + public void finishedAnalyzingEntryPoint(List paths, Set violations) { + // do nothing + } + + @Override + public void completedAnalysis() { + // do nothing + } +} diff --git a/src/lib/ScannerCommand.ts b/src/lib/ScannerCommand.ts index 1697ca0c0..73008d17f 100644 --- a/src/lib/ScannerCommand.ts +++ b/src/lib/ScannerCommand.ts @@ -86,6 +86,13 @@ export abstract class ScannerCommand extends SfdxCommand { this.ux.setSpinnerStatus(msg); } + /* eslint-disable-next-line @typescript-eslint/no-unused-vars */ + protected waitOnSpinner(msg: string): void { + // msg variable is thrown away - please don't send anything here. + const currentStatus = this.ux.getSpinnerStatus(); + this.ux.setSpinnerStatus(currentStatus + ' .'); + } + protected stopSpinner(msg: string): void { this.ux.stopSpinner(msg); } @@ -104,6 +111,7 @@ export abstract class ScannerCommand extends SfdxCommand { uxEvents.on(EVENTS.ERROR_VERBOSE, (msg: string) => this.displayError(msg)); uxEvents.on(EVENTS.START_SPINNER, (msg: string, status: string) => this.startSpinner(msg, status)); uxEvents.on(EVENTS.UPDATE_SPINNER, (msg: string) => this.updateSpinner(msg)); + uxEvents.on(EVENTS.WAIT_ON_SPINNER, (msg: string) => this.waitOnSpinner(msg)); uxEvents.on(EVENTS.STOP_SPINNER, (msg: string) => this.stopSpinner(msg)); } } diff --git a/src/lib/ScannerEvents.ts b/src/lib/ScannerEvents.ts index 1ddb1355f..4d5bbd36d 100644 --- a/src/lib/ScannerEvents.ts +++ b/src/lib/ScannerEvents.ts @@ -14,5 +14,6 @@ export enum EVENTS { // and `ux.stopSpinner()`, which are both no-ops if there's not an active spinner. START_SPINNER = 'start-spinner', UPDATE_SPINNER = 'update-spinner', + WAIT_ON_SPINNER = 'wait-on-spinner', STOP_SPINNER = 'stop-spinner' } diff --git a/src/lib/services/CommandLineSupport.ts b/src/lib/services/CommandLineSupport.ts index 4ad203958..63a912f71 100644 --- a/src/lib/services/CommandLineSupport.ts +++ b/src/lib/services/CommandLineSupport.ts @@ -77,9 +77,11 @@ export abstract class CommandLineSupport extends AsyncCreatable { // When data is passed back up to us, pop it onto the appropriate string. cp.stdout.on('data', data => { + this.outputProcessor.processRealtimeOutput(String(data)); stdout += data; }); cp.stderr.on('data', data => { + this.outputProcessor.processRealtimeOutput(String(data)); stderr += data; }); diff --git a/src/lib/services/OutputProcessor.ts b/src/lib/services/OutputProcessor.ts index bde7eba52..cf13229c2 100644 --- a/src/lib/services/OutputProcessor.ts +++ b/src/lib/services/OutputProcessor.ts @@ -1,13 +1,18 @@ import {Logger, LoggerLevel, Messages} from '@salesforce/core'; import {AsyncCreatable} from '@salesforce/kit'; import {RuleEvent} from '../../types'; -import {uxEvents} from '../ScannerEvents'; +import {EVENTS, uxEvents} from '../ScannerEvents'; Messages.importMessagesDirectory(__dirname); const messages = Messages.loadMessages('@salesforce/sfdx-scanner', 'EventKeyTemplates'); const genericMessageKey = 'error.external.genericErrorMessage'; +const MESSAGE_START_TAG = 'SFDX-START'; +const MESSAGE_END_TAG = 'SFDX-END'; +const REALTIME_MESSAGE_START_TAG = 'SFCA-REALTIME-START'; +const REALTIME_MESSAGE_END_TAG = 'SFCA-REALTIME-END'; + /** * Helps with processing output from PmdCatalog java module and converting messages into usable events */ @@ -30,42 +35,64 @@ export class OutputProcessor extends AsyncCreatable { this.initialized = true; } + public isRealtimeOutput(out: string): boolean { + return out.startsWith(REALTIME_MESSAGE_START_TAG); + } + + public processOutput(out: string): boolean { + return this.processAllOutput(out, MESSAGE_START_TAG, MESSAGE_END_TAG); + } + + public processRealtimeOutput(out: string): boolean { + return this.processAllOutput(out, REALTIME_MESSAGE_START_TAG, REALTIME_MESSAGE_END_TAG); + } + // We want to find any events that were dumped into stdout or stderr and turn them back into events that can be thrown. // As per the convention outlined in SfdxMessager.java, SFDX-relevant messages will be stored in the outputs as JSONs - // sandwiched between 'SFDX-START' and 'SFDX-END'. So we'll find all instances of that. - public processOutput(out: string): void { + // sandwiched between a given start tag and end tag. So we'll find all instances of that. + private processAllOutput(out: string, startTag: string, endTag: string): boolean { this.logger.trace(`stdout: ${out}`); if (!out) { // Nothing to do here - return; + return false; } - const outEvents: RuleEvent[] = this.getEventsFromString(out); + const outEvents: RuleEvent[] = this.getEventsFromString(out, startTag, endTag); this.logger.trace(`Total count of events found: ${outEvents.length}`); - this.emitEvents(outEvents); + return this.emitEvents(outEvents); } // TODO: consider moving all message creation logic to a separate place and making this method private - public emitEvents(outEvents: RuleEvent[]): void { + public emitEvents(outEvents: RuleEvent[]): boolean { this.logger.trace('About to order and emit'); // If list is empty, we can just be done now. if (outEvents.length == 0) { - return; + return false; } // Iterate over all of the events and throw them as appropriate. outEvents.forEach((event) => { this.logEvent(event); - if (event.handler === 'UX' || (event.handler === 'INTERNAL' && event.type === 'ERROR')) { - const eventType = `${event.type.toLowerCase()}-${event.verbose ? 'verbose' : 'always'}`; - this.emitUxEvent(eventType, event.messageKey, event.args); + let eventType = ''; + if (event.handler === 'UX_SPINNER') { + eventType = EVENTS.UPDATE_SPINNER.toString(); + } else if (event.handler === 'UX' || (event.handler === 'INTERNAL' && event.type === 'ERROR')) { + eventType = `${event.type.toLowerCase()}-${event.verbose ? 'verbose' : 'always'}`; } + this.emitUxEvent(eventType, event.messageKey, event.args); }); + return true; } private emitUxEvent(eventType: string, messageKey: string, args: string[]): void { + if (eventType === '') { + this.logger.trace(`No event type requested for message ${messageKey}`); + return; + } + + this.logger.trace(`Sending new event of type ${eventType} and message ${messageKey}`); let constructedMessage: string = null; try { @@ -79,12 +106,12 @@ export class OutputProcessor extends AsyncCreatable { uxEvents.emit(eventType, constructedMessage); } - private getEventsFromString(str: string): RuleEvent[] { + private getEventsFromString(str: string, startTag: string, endTag: string): RuleEvent[] { const events: RuleEvent[] = []; - const regex = /SFDX-START(.*)SFDX-END/g; - const headerLength = 'SFDX-START'.length; - const tailLength = 'SFDX-END'.length; + const regex = new RegExp(`^${startTag}(.*)${endTag}`, 'g'); + const headerLength = startTag.length; + const tailLength = endTag.length; const regexMatch = str.match(regex); if (!regexMatch || regexMatch.length < 1) { this.logger.trace(`No events to log`); diff --git a/src/lib/sfge/SfgeWrapper.ts b/src/lib/sfge/SfgeWrapper.ts index 723516852..bf488d97c 100644 --- a/src/lib/sfge/SfgeWrapper.ts +++ b/src/lib/sfge/SfgeWrapper.ts @@ -63,12 +63,11 @@ class SfgeSpinnerManager extends AsyncCreatable implements SpinnerManager { } public startSpinner(): void { - uxEvents.emit(EVENTS.START_SPINNER, `Evaluating SFGE rules. See ${this.logFilePath} for logs`, "Please wait"); + uxEvents.emit(EVENTS.START_SPINNER, `Analyzing with SFGE. See ${this.logFilePath} for details.`, "Please wait"); - let intervalCount = 0; + // TODO: This timer logic should ideally live inside waitOnSpinner() this.intervalId = setInterval(() => { - uxEvents.emit(EVENTS.UPDATE_SPINNER, "Please wait." + ".".repeat(intervalCount)); - intervalCount += 1; + uxEvents.emit(EVENTS.WAIT_ON_SPINNER, 'message is unused'); }, 30000); } diff --git a/test/commands/scanner/run.dfa.test.ts b/test/commands/scanner/run.dfa.test.ts new file mode 100644 index 000000000..e51826c8c --- /dev/null +++ b/test/commands/scanner/run.dfa.test.ts @@ -0,0 +1,95 @@ +import {expect} from '@salesforce/command/lib/test'; +import {setupCommandTest} from '../../TestUtils'; +import {Messages} from '@salesforce/core'; +import * as path from 'path'; +import Dfa from '../../../src/commands/scanner/run/dfa'; +import * as sinon from 'sinon'; + + +Messages.importMessagesDirectory(__dirname); +const sfgeMessages = Messages.loadMessages('@salesforce/sfdx-scanner', 'EventKeyTemplates'); + +const dfaTarget = path.join('test', 'code-fixtures', 'projects', 'sfge-smoke-app', 'src'); +const projectdir = path.join('test', 'code-fixtures', 'projects', 'sfge-smoke-app', 'src'); + +const apexControllerStr = 'UnsafeVfController'; +const customSettingsStr = 'none found'; +const fileCount = '7'; +const entryPointCount = '5'; +const pathCount = '6'; +const violationCount = '2'; + +const customSettingsMessage = sfgeMessages.getMessage('info.sfgeMetaInfoCollected', ['Custom Settings', customSettingsStr]); +const apexControllerMessage = sfgeMessages.getMessage('info.sfgeMetaInfoCollected', ['Apex Controllers', apexControllerStr]); +const compiledMessage = sfgeMessages.getMessage('info.sfgeFinishedCompilingFiles', [fileCount]); +const startGraphBuildMessage = sfgeMessages.getMessage('info.sfgeStartedBuildingGraph'); +const endGraphBuildMessage = sfgeMessages.getMessage('info.sfgeFinishedBuildingGraph'); +const identifiedEntryMessage = sfgeMessages.getMessage('info.sfgePathEntryPointsIdentified', [entryPointCount]); +const completedAnalysisMessage = sfgeMessages.getMessage('info.sfgeCompletedPathAnalysis', [pathCount, entryPointCount, violationCount]); + +function isSubstr(output: string, substring: string): boolean { + const updatedSubstr = substring.replace('[', '\\['); + const regex = new RegExp(`^${updatedSubstr}`, 'gm'); + const regexMatch = output.match(regex); + return regexMatch != null && regexMatch.length >= 1; +} + + +function verifyNotContains(output: string, substring: string): void { + expect(isSubstr(output, substring), `Output "${output}" should not contain substring "${substring}"`).is.false; +} + +describe('scanner:run:dfa', function () { + this.timeout(20000); // TODO why do we get timeouts at the default of 5000? What is so expensive here? + + describe('End to end', () => { + + describe('Output consistency', () => { + describe('run with --format json', () => { + setupCommandTest + .command(['scanner:run:dfa', + '--target', dfaTarget, + '--projectdir', projectdir, + '--format', 'json' + ]) + .it('provides only json in stdout', ctx => { + try { + JSON.parse(ctx.stdout); + } catch (error) { + expect.fail("dummy", "another dummy", "Invalid JSON output from --format json: " + ctx.stdout + ", error = " + error); + } + + }); + }); + }); + + describe('Progress output', () => { + let sandbox; + let spy: sinon.SinonSpy; + before(() => { + sandbox = sinon.createSandbox(); + spy = sandbox.spy(Dfa.prototype, "updateSpinner"); + }); + + after(() => { + spy.restore(); + sinon.restore(); + }); + + setupCommandTest + .command(['scanner:run:dfa', + '--target', dfaTarget, + '--projectdir', projectdir, + '--format', 'json' + ]) + .it('contains valid information when --verbose is not used', ctx => { + const output = ctx.stdout; + verifyNotContains(output, customSettingsMessage); + verifyNotContains(output, apexControllerMessage); + expect(spy.calledWith(compiledMessage, startGraphBuildMessage, endGraphBuildMessage, identifiedEntryMessage, completedAnalysisMessage)); + }); + + }); + + }); +}); \ No newline at end of file