Fine logging (#49) (#84)

* Replace commented out output with "fine" logging.

* Use "fine" logging in Maven build.

* Split logging properties for CI.

Less logging on the CI. CI is complaining about too much logging.

* Centralize log config.

So that it applies to all tests.

* Fix CI.

* Define a custom logging config file property.

Co-authored-by: Manu Sridharan <[email protected]>

.github/workflows/continuous-integration.yml

@@ -40,4 +40,4 @@ jobs:
     - name: Check formatting with spotless.
       run: mvn spotless:check -B
     - name: Build with Maven
-      run: mvn clean verify -B
+      run: mvn -Dlogging.config.file=\${maven.multiModuleProjectDirectory}/logging.ci.properties clean verify -B

.travis.yml

@@ -17,7 +17,7 @@ install:
  - popd
 script:
  - mvn spotless:check -B
- - mvn clean verify -B
+ - mvn -Dlogging.config.file=\${maven.multiModuleProjectDirectory}/logging.ci.properties clean verify -B
 before_cache:
   - rm -f  $HOME/.gradle/caches/modules-2/modules-2.lock
   - rm -fr $HOME/.gradle/caches/*/plugin-resolution/

com.ibm.wala.cast.python.jython3/source/com/ibm/wala/cast/python/parser/PythonModuleParser.java

@@ -31,13 +31,16 @@
 import java.util.Optional;
 import java.util.Set;
 import java.util.function.Consumer;
+import java.util.logging.Logger;
 import java.util.stream.Collectors;
 import org.antlr.runtime.ANTLRInputStream;
 import org.antlr.runtime.CharStream;
 import org.python.antlr.ast.ImportFrom;
 
 public class PythonModuleParser extends PythonParser<ModuleEntry> {
 
+  private static final Logger logger = Logger.getLogger(PythonModuleParser.class.getName());
+
   private final Set<String> localModules = HashSetFactory.make();
 
   private final SourceModule fileName;
@@ -118,7 +121,7 @@ public void accept(ModuleEntry f) {
                                   accept(sm);
                                 });
                       } else {
-                        System.err.println("**CLS: " + scriptName((SourceModule) f));
+                        logger.fine(() -> "**CLS: " + scriptName((SourceModule) f));
                         localModules.add(scriptName((SourceModule) f));
                       }
                     }

com.ibm.wala.cast.python.ml/source/com/ibm/wala/cast/python/ml/types/TensorType.java

@@ -29,10 +29,13 @@
 import java.util.Arrays;
 import java.util.Iterator;
 import java.util.List;
+import java.util.logging.Logger;
 import java.util.stream.Collectors;
 
 public class TensorType implements Iterable<Dimension<?>> {
 
+  private static final Logger logger = Logger.getLogger(TensorType.class.getName());
+
   public enum Format {
     CString,
     MCString,
@@ -327,7 +330,7 @@ public static TensorType mnistInput() {
   }
 
   public static TensorType shapeArg(CGNode node, int literalVn) {
-    System.err.println(node.getIR());
+    logger.fine(() -> node.getIR().toString());
     ArrayList<Dimension<?>> r = new ArrayList<>();
     DefUse du = node.getDU();
     SymbolTable S = node.getIR().getSymbolTable();

com.ibm.wala.cast.python/source/com/ibm/wala/cast/python/ir/PythonCAstToIRTranslator.java

@@ -62,10 +62,13 @@
 import java.util.Map;
 import java.util.Set;
 import java.util.Stack;
+import java.util.logging.Logger;
 import java.util.stream.Collectors;
 
 public class PythonCAstToIRTranslator extends AstTranslator {
 
+  private static final Logger logger = Logger.getLogger(PythonCAstToIRTranslator.class.getName());
+
   private final Map<CAstType, TypeName> walaTypeNames = HashMapFactory.make();
   private final Set<Pair<Scope, String>> globalDeclSet = new HashSet<>();
   private static boolean signleFileAnalysis = true;
@@ -683,7 +686,7 @@ protected void doCall(
     ((CAstControlFlowRecorder) context.getControlFlow()).map(call, call);
 
     if (context.getControlFlow().getTargetLabels(call).isEmpty()) {
-      System.err.println("no exceptions for " + CAstPrinter.print(call));
+      logger.fine(() -> "no exceptions for " + CAstPrinter.print(call));
       context.cfg().addPreEdgeToExit(call, true);
     } else {
       context

logging.ci.properties

@@ -0,0 +1,60 @@
+############################################################
+#  	Default Logging Configuration File
+#
+# You can use a different file by specifying a filename
+# with the java.util.logging.config.file system property.
+# For example java -Djava.util.logging.config.file=myfile
+############################################################
+
+############################################################
+#  	Global properties
+############################################################
+
+# "handlers" specifies a comma separated list of log Handler
+# classes.  These handlers will be installed during VM startup.
+# Note that these classes must be on the system classpath.
+# By default we only configure a ConsoleHandler, which will only
+# show messages at the INFO and above levels.
+handlers= java.util.logging.ConsoleHandler
+
+# To also add the FileHandler, use the following line instead.
+#handlers= java.util.logging.FileHandler, java.util.logging.ConsoleHandler
+
+# Default global logging level.
+# This specifies which kinds of events are logged across
+# all loggers.  For any given facility this global level
+# can be overriden by a facility specific level
+# Note that the ConsoleHandler also has a separate level
+# setting to limit messages printed to the console.
+.level= INFO
+
+############################################################
+# Handler specific properties.
+# Describes specific configuration info for Handlers.
+############################################################
+
+# default file output is in user's home directory.
+#java.util.logging.FileHandler.pattern = %h/java%u.log
+#java.util.logging.FileHandler.limit = 50000
+#java.util.logging.FileHandler.count = 1
+#java.util.logging.FileHandler.formatter = java.util.logging.XMLFormatter
+
+# Limit the message that are printed on the console to INFO and above.
+java.util.logging.ConsoleHandler.level = INFO
+java.util.logging.ConsoleHandler.formatter = java.util.logging.SimpleFormatter
+
+# Example to customize the SimpleFormatter output format
+# to print one-line log message like this:
+#     <level>: <log message> [<date/time>]
+#
+# java.util.logging.SimpleFormatter.format=%4$s: %5$s [%1$tc]%n
+java.util.logging.SimpleFormatter.format=[%4$s] %5$s%n
+
+############################################################
+# Facility specific properties.
+# Provides extra control for each logger.
+############################################################
+
+# For example, set the com.xyz.foo logger to only log SEVERE
+# messages:
+#com.xyz.foo.level = SEVERE

logging.properties

@@ -0,0 +1,60 @@
+############################################################
+#  	Default Logging Configuration File
+#
+# You can use a different file by specifying a filename
+# with the java.util.logging.config.file system property.
+# For example java -Djava.util.logging.config.file=myfile
+############################################################
+
+############################################################
+#  	Global properties
+############################################################
+
+# "handlers" specifies a comma separated list of log Handler
+# classes.  These handlers will be installed during VM startup.
+# Note that these classes must be on the system classpath.
+# By default we only configure a ConsoleHandler, which will only
+# show messages at the INFO and above levels.
+handlers= java.util.logging.ConsoleHandler
+
+# To also add the FileHandler, use the following line instead.
+#handlers= java.util.logging.FileHandler, java.util.logging.ConsoleHandler
+
+# Default global logging level.
+# This specifies which kinds of events are logged across
+# all loggers.  For any given facility this global level
+# can be overriden by a facility specific level
+# Note that the ConsoleHandler also has a separate level
+# setting to limit messages printed to the console.
+.level= FINE
+
+############################################################
+# Handler specific properties.
+# Describes specific configuration info for Handlers.
+############################################################
+
+# default file output is in user's home directory.
+#java.util.logging.FileHandler.pattern = %h/java%u.log
+#java.util.logging.FileHandler.limit = 50000
+#java.util.logging.FileHandler.count = 1
+#java.util.logging.FileHandler.formatter = java.util.logging.XMLFormatter
+
+# Limit the message that are printed on the console to INFO and above.
+java.util.logging.ConsoleHandler.level = FINE
+java.util.logging.ConsoleHandler.formatter = java.util.logging.SimpleFormatter
+
+# Example to customize the SimpleFormatter output format
+# to print one-line log message like this:
+#     <level>: <log message> [<date/time>]
+#
+# java.util.logging.SimpleFormatter.format=%4$s: %5$s [%1$tc]%n
+java.util.logging.SimpleFormatter.format=[%4$s] %5$s%n
+
+############################################################
+# Facility specific properties.
+# Provides extra control for each logger.
+############################################################
+
+# For example, set the com.xyz.foo logger to only log SEVERE
+# messages:
+#com.xyz.foo.level = SEVERE

pom.xml

@@ -32,6 +32,7 @@
     <wala.version>1.6.0</wala.version>
     <spotless.version>2.37.0</spotless.version>
     <maven.surefire.version>3.0.0-M7</maven.surefire.version>
+    <logging.config.file>${maven.multiModuleProjectDirectory}/logging.properties</logging.config.file>
   </properties>
   <dependencyManagement>
     <dependencies>
@@ -135,7 +136,7 @@
             <threadCount>1</threadCount>
             <systemPropertyVariables>
               <!-- Set JUL Formatting -->
-              <java.util.logging.SimpleFormatter.format>[%4$s] %5$s%n</java.util.logging.SimpleFormatter.format>
+              <java.util.logging.config.file>${logging.config.file}</java.util.logging.config.file>
             </systemPropertyVariables>
             <forkMode>once</forkMode>
             <argLine>-Dpython.import.site=false</argLine>