logging fix and the long-awaited setting log-level by processor (#1458)

* put event number into logging messages

also convert the logging levels to human readable strings while we are working on a formatter anyways

* promote logging into its own Python configuration class

this will be more helpful as I attempt to add the additional features of
per-processor log filtering

* add custom logging rules allowing specific channels to be raised or
lowered

* only print event message on first tries

* just format-cpp

* move space to before label so colon always follows label

also use a const reference instead of a copy just because we can lmao

* lower the level of the Process channel to info if a logFrequency is set

this avoids tying together the event-status frequency from the overall
terminal log level

Framework/include/Framework/Logger.h

@@ -22,6 +22,8 @@
 #include <boost/log/sources/record_ostream.hpp>
 #include <boost/log/utility/setup/file.hpp>
 
+#include "Framework/Configure/Parameters.h"
+
 namespace framework {
 
 namespace logging {
@@ -37,37 +39,6 @@ enum level {
   fatal       ///> 4
 };
 
-/**
- * Convert an integer to the severity level enum
- *
- * Any integer below zero will be set to 0 (debug),
- * and any integer above four will be set to 4 (fatal).
- *
- * @param[in] iLvl integer level to be converted
- * @return converted enum level
- */
-level convertLevel(int& iLvl);
-
-/**
- * Severity level to human readable name map
- *
- * Human readable names are the same width in characters
- *
- * We could also add terminal color here if we wanted.
- *
- * @note Not in use right now. boost's extract returns some
- * weird templated type that cannot be implicitly converted to level.
- *
- * We _can_ stream the output to a string stream and use
- * that as the key in our map, but that is lame.
- */
-const std::unordered_map<level, std::string> humanReadableLevel = {
-    {debug, "debug"},
-    {info, "info "},
-    {warn, "warn "},
-    {error, "error"},
-    {fatal, "fatal"}};
-
 /**
  * Short names for boost namespaces
  */
@@ -99,23 +70,53 @@ logger makeLogger(const std::string& name);
  * This function setups up the terminal and file sinks.
  * Sets their format and filtering level for this run.
  *
- * @note Will not setup printing log messages to file if fileName is empty
+ * @note Will not setup printing log messages to file if filePath is empty
  * string.
  *
- * @param termLevel minimum level to print to terminal (everything above it is
- * also printed)
- * @param fileLevel minimum level to print to file log (everything above it is
- * also printed)
- * @param fileName name of file to print log to
+ * @param p parameters to configure the logging with
  */
-void open(const level termLevel, const level fileLevel,
-          const std::string& fileName);
+void open(const framework::config::Parameters& p);
 
 /**
  * Close up the logging
  */
 void close();
 
+/**
+ * Our logging formatter
+ *
+ * We use a singleton formatter so that it can hold the current event index
+ * as an attribute and include it within the logs. This is easier than
+ * attempting to update the event number in all of the different logging
+ * sources floating around ldmx-sw.
+ */
+class Formatter {
+  int event_number_{0};
+  Formatter() = default;
+
+ public:
+  /// delete the copy constructor
+  Formatter(Formatter const&) = delete;
+
+  /// delete the assignment operator
+  void operator=(Formatter const&) = delete;
+
+  /// get reference to the current single Formatter
+  static Formatter& get();
+
+  /// set the event number in the current Formatter
+  static void set(int n);
+
+  /**
+   * format the passed record view into the output stream
+   *
+   * The format is
+   *
+   *  [ channel ] severity : message
+   */
+  void operator()(const log::record_view& view, log::formatting_ostream& os);
+};
+
 }  // namespace logging
 
 }  // namespace framework

Framework/include/Framework/Process.h

@@ -136,14 +136,15 @@ class Process {
    * Process the input event through the sequence
    * of processors
    *
-   * The input counter for number of events processed is
+   * The input counters (for events and tries) are
    * only used to print the status.
    *
    * @param[in] n counter for number of events processed
+   * @param[in] n_tries counter for number of tries on current event
    * @param[in,out] event reference to event we are going to process
    * @returns true if event was full processed (false if aborted)
    */
-  bool process(int n, Event &event) const;
+  bool process(int n, int n_tries, Event &event) const;
 
   /**
    * Run through the processors and let them know
@@ -181,15 +182,6 @@ class Process {
   /** The frequency with which event info is printed. */
   int logFrequency_;
 
-  /** Integer form of logging level to print to terminal */
-  int termLevelInt_;
-
-  /** Integer form of logging level to print to file */
-  int fileLevelInt_;
-
-  /** Name of file to print logging to */
-  std::string logFileName_;
-
   /** Maximum number of attempts to make before giving up on an event */
   int maxTries_;
 

Framework/python/ldmxcfg.py

@@ -424,6 +424,81 @@ def external(self,seed) :
     def time(self) :
         """Set master random seed based off of time"""
         self.seedMode = 'time'
+
+
+class _LogRule:
+    """A single pair holding a channel name and the level it should be logged at
+
+    This class should not be used directly, use the helper functions
+    in Logger instead to define rule sets.
+    """
+    def __init__(self, name, level):
+        self.name = name
+        self.level = level
+
+
+class Logger:
+    """Configure the logging infrastructure of ldmx-sw
+
+    The "severity level" of messages correspond to the following integers.
+
+        - 0 : Debug
+        - 1 : Information
+        - 2 : Warning
+        - 3 : Error
+        - 4 : Fatal (reserved for program-ending exceptions)
+
+    Whenever a level is specified, messages for that level and any level above
+    it (corresponding to a larger integer) are including when printing out
+    the messages.
+
+    Paramters
+    ---------
+    termLevel: int
+        minimum severity level to print to the terminal
+    fileLevel: int
+        minimum severity level to print to the file
+    filePath: str
+        path to file to direct logging to (if not provided, don't open a file for logging)
+    logRules: List[_LogRule]
+        list of custom logging rules that override the default terminal and file levels
+    """
+
+    def __init__(self):
+        self.termLevel = 2 # warnings and above
+        self.fileLevel = 0 # everything
+        self.filePath  = '' # don't open file for logging
+        self.logRules = []
+
+
+    def custom(self, name, level):
+        """Add a new custom logging rule to the logger
+
+        We automatically get the event processor's instance name
+        if an instance of an event processor is passed.
+
+        Parameters
+        ----------
+        name: str|EventProcessor
+            identification of the logging channel to customize
+        level: int
+            level (and above) messages to print for that channel
+        """
+
+        if isinstance(name, EventProcessor):
+            name = name.instanceName
+        self.logRules.append(_LogRule(name, level))
+
+
+    def debug(self, name):
+        """drop the input channel to the debug level"""
+        self.custom(name, level = 0)
+
+
+    def silence(self, name):
+        """raise the input channel to the error-only level"""
+        self.custom(name, level = 3)
+
 
 class Process:
     """Process configuration object
@@ -471,12 +546,8 @@ class Process:
         List of skimming rules for which processors the process should listen to when deciding whether to keep an event
     logFrequency : int
         Print the event number whenever its modulus with this frequency is zero
-    termLogLevel : int
-        Minimum severity of log messages to print to terminal: 0 (debug) - 4 (fatal)
-    fileLogLevel : int
-        Minimum severity of log messages to print to file: 0 (debug) - 4 (fatal)
-    logFileName : str
-        File to print log messages to, won't setup file logging if this parameter is not set
+    logger : Logger
+        configuration for logging system in ldmx-sw
     conditionsGlobalTag : str
         Global tag for the current generation of conditions
     conditionsObjectProviders : list of ConditionsObjectProviders
@@ -509,9 +580,7 @@ def __init__(self, passName):
         self.skimDefaultIsKeep=True
         self.skimRules=[]
         self.logFrequency=-1
-        self.termLogLevel=2 #warnings and above
-        self.fileLogLevel=0 #print all messages
-        self.logFileName='' #won't setup log file
+        self.logger = Logger()
         self.compressionSetting=9
         self.histogramFile=''
         self.conditionsGlobalTag='Default'
@@ -522,6 +591,29 @@ def __init__(self, passName):
         # needs lastProcess defined to self-register
         self.randomNumberSeedService=RandomNumberSeedService()
 
+
+    def __setattr__(self, key, val):
+        logger_remap = {
+            'termLogLevel' : 'termLevel',
+            'fileLogLevel' : 'fileLevel',
+            'logFileName'  : 'filePath'
+        }
+        if key in logger_remap:
+            setattr(self.logger, logger_remap[key], val)
+            return
+        elif key == 'logFrequency' and val > 0:
+            # make sure the Process channel is lowered to info
+            # later log rules override earlier ones so we put this
+            # at the front of the list so the user could have overwritten
+            # this if need be
+            # 'Process' needs to match the name given in enableLogging
+            # in include/Framework/Process.h
+            self.logger.logRules.insert(0, _LogRule('Process', level=1))
+            # fall through to set the key=val
+
+        super().__setattr__(key, val)
+
+
     def addLibrary(lib) :
         """Add a library to the list of dynamically loaded libraries