Use log helper

oletools/common/log_helper/_json_formatter.py

@@ -8,6 +8,10 @@ class JsonFormatter(logging.Formatter):
     """
     _is_first_line = True
 
+    def __init__(self, other_logger_has_first_line=False):
+        if other_logger_has_first_line:
+            self._is_first_line = False
+
     def format(self, record):
         """
         Since we don't buffer messages, we always prepend messages with a comma to make

oletools/common/log_helper/_logger_adapter.py

@@ -54,4 +54,9 @@ def set_json_enabled_function(self, json_enabled):
         self._json_enabled = json_enabled
 
     def level(self):
+        """Return current level of logger."""
         return self.logger.level
+
+    def setLevel(self, new_level):
+        """Set level of underlying logger. Required only for python < 3.2."""
+        return self.logger.setLevel(new_level)

oletools/common/log_helper/log_helper.py

@@ -3,6 +3,26 @@
 
 General logging helpers
 
+Use as follows:
+
+    # at the start of your file:
+    # import logging   <-- replace this with next line
+    from oletools.common.log_helper import log_helper
+
+    logger = log_helper.get_or_create_silent_logger("module_name")
+    def enable_logging():
+        '''Enable logging in this module; for use by importing scripts'''
+        logger.setLevel(log_helper.NOTSET)
+        imported_oletool_module.enable_logging()
+        other_imported_oletool_module.enable_logging()
+
+    # ... your code; use logger instead of logging ...
+
+    def main():
+        log_helper.enable_logging(level=...)   # instead of logging.basicConfig
+        # ... your main code ...
+        log_helper.end_logging()
+
 .. codeauthor:: Intra2net AG <info@intra2net>, Philippe Lagadec
 """
 
@@ -45,6 +65,7 @@
 # TODO:
 
 
+from __future__ import print_function
 from ._json_formatter import JsonFormatter
 from ._logger_adapter import OletoolsLoggerAdapter
 from . import _root_logger_wrapper
@@ -61,15 +82,27 @@
     'critical': logging.CRITICAL
 }
 
+#: provide this constant to modules, so they do not have to import
+#: :py:mod:`logging` for themselves just for this one constant.
+NOTSET = logging.NOTSET
+
 DEFAULT_LOGGER_NAME = 'oletools'
 DEFAULT_MESSAGE_FORMAT = '%(levelname)-8s %(message)s'
 
 
 class LogHelper:
+    """
+    Single helper class that creates and remembers loggers.
+    """
+
+    #: for convenience: here again (see also :py:data:`log_helper.NOTSET`)
+    NOTSET = logging.NOTSET
+
     def __init__(self):
         self._all_names = set()  # set so we do not have duplicates
         self._use_json = False
         self._is_enabled = False
+        self._target_stream = None
 
     def get_or_create_silent_logger(self, name=DEFAULT_LOGGER_NAME, level=logging.CRITICAL + 1):
         """
@@ -82,7 +115,8 @@ def get_or_create_silent_logger(self, name=DEFAULT_LOGGER_NAME, level=logging.CR
         """
         return self._get_or_create_logger(name, level, logging.NullHandler())
 
-    def enable_logging(self, use_json=False, level='warning', log_format=DEFAULT_MESSAGE_FORMAT, stream=None):
+    def enable_logging(self, use_json=False, level='warning', log_format=DEFAULT_MESSAGE_FORMAT, stream=None,
+                       other_logger_has_first_line=False):
         """
         This function initializes the root logger and enables logging.
         We set the level of the root logger to the one passed by calling logging.basicConfig.
@@ -93,15 +127,26 @@ def enable_logging(self, use_json=False, level='warning', log_format=DEFAULT_MES
         which in turn will log to the stream set in this function.
         Since the root logger is the one doing the work, when using JSON we set its formatter
         so that every message logged is JSON-compatible.
+
+        If other code also creates json output, all items should be pre-pended
+        with a comma like the `JsonFormatter` does. Except the first; use param
+        `other_logger_has_first_line` to clarify whether our logger or the
+        other code will produce the first json item.
         """
         if self._is_enabled:
             raise ValueError('re-enabling logging. Not sure whether that is ok...')
 
-        if stream in (None, sys.stdout):
+        if stream is None:
+            self.target_stream = sys.stdout
+        else:
+            self.target_stream = stream
+
+        if self.target_stream == sys.stdout:
             ensure_stdout_handles_unicode()
 
         log_level = LOG_LEVELS[level]
-        logging.basicConfig(level=log_level, format=log_format, stream=stream)
+        logging.basicConfig(level=log_level, format=log_format,
+                            stream=self.target_stream)
         self._is_enabled = True
 
         self._use_json = use_json
@@ -115,8 +160,8 @@ def enable_logging(self, use_json=False, level='warning', log_format=DEFAULT_MES
 
         # add a JSON formatter to the root logger, which will be used by every logger
         if self._use_json:
-            _root_logger_wrapper.set_formatter(JsonFormatter())
-            print('[')
+            _root_logger_wrapper.set_formatter(JsonFormatter(other_logger_has_first_line))
+            print('[', file=self.target_stream)
 
     def end_logging(self):
         """
@@ -133,7 +178,7 @@ def end_logging(self):
 
         # end json list
         if self._use_json:
-            print(']')
+            print(']', file=self.target_stream)
         self._use_json = False
 
     def _get_except_hook(self, old_hook):

oletools/crypto.py

@@ -95,6 +95,7 @@ def script_main_function(input_file, passwords, crypto_nesting=0, args):
 # 2019-05-23       PL: - added DEFAULT_PASSWORDS list
 # 2021-05-22 v0.60 PL: - added PowerPoint transparent password
 #                        '/01Hannes Ruescher/01' (issue #627)
+# 2019-05-24       CH: - use log_helper
 
 __version__ = '0.60'
 
@@ -104,7 +105,6 @@ def script_main_function(input_file, passwords, crypto_nesting=0, args):
 from os.path import splitext, isfile
 from tempfile import mkstemp
 import zipfile
-import logging
 
 from olefile import OleFileIO
 
@@ -134,44 +134,20 @@ def script_main_function(input_file, passwords, crypto_nesting=0, args):
 
 # === LOGGING =================================================================
 
-# TODO: use log_helper instead
-
-def get_logger(name, level=logging.CRITICAL+1):
-    """
-    Create a suitable logger object for this module.
-    The goal is not to change settings of the root logger, to avoid getting
-    other modules' logs on the screen.
-    If a logger exists with same name, reuse it. (Else it would have duplicate
-    handlers and messages would be doubled.)
-    The level is set to CRITICAL+1 by default, to avoid any logging.
-    """
-    # First, test if there is already a logger with the same name, else it
-    # will generate duplicate messages (due to duplicate handlers):
-    if name in logging.Logger.manager.loggerDict:
-        # NOTE: another less intrusive but more "hackish" solution would be to
-        # use getLogger then test if its effective level is not default.
-        logger = logging.getLogger(name)
-        # make sure level is OK:
-        logger.setLevel(level)
-        return logger
-    # get a new logger:
-    logger = logging.getLogger(name)
-    # only add a NullHandler for this logger, it is up to the application
-    # to configure its own logging:
-    logger.addHandler(logging.NullHandler())
-    logger.setLevel(level)
-    return logger
-
 # a global logger object used for debugging:
-log = get_logger('crypto')
+log = log_helper.get_or_create_silent_logger('crypto')
+
 
 def enable_logging():
     """
     Enable logging for this module (disabled by default).
+
+    For use by third-party libraries that import `crypto` as module.
+
     This will set the module-specific logger level to NOTSET, which
     means the main application controls the actual logging level.
     """
-    log.setLevel(logging.NOTSET)
+    log.setLevel(log_helper.NOTSET)
 
 
 def is_encrypted(some_file):

oletools/mraptor.py

@@ -71,7 +71,7 @@
 
 #--- IMPORTS ------------------------------------------------------------------
 
-import sys, logging, optparse, re, os
+import sys, optparse, re, os
 
 # IMPORTANT: it should be possible to run oletools directly as scripts
 # in any directory without installing them with pip or setup.py.
@@ -90,11 +90,12 @@
 
 from oletools import olevba
 from oletools.olevba import TYPE2TAG
+from oletools.common.log_helper import log_helper
 
 # === LOGGING =================================================================
 
 # a global logger object used for debugging:
-log = olevba.get_logger('mraptor')
+log = log_helper.get_or_create_silent_logger('mraptor')
 
 
 #--- CONSTANTS ----------------------------------------------------------------
@@ -230,15 +231,7 @@ def main():
     """
     Main function, called when olevba is run from the command line
     """
-    global log
     DEFAULT_LOG_LEVEL = "warning" # Default log level
-    LOG_LEVELS = {
-        'debug':    logging.DEBUG,
-        'info':     logging.INFO,
-        'warning':  logging.WARNING,
-        'error':    logging.ERROR,
-        'critical': logging.CRITICAL
-        }
 
     usage = 'usage: mraptor [options] <filename> [filename2 ...]'
     parser = optparse.OptionParser(usage=usage)
@@ -272,9 +265,9 @@ def main():
     print('MacroRaptor %s - http://decalage.info/python/oletools' % __version__)
     print('This is work in progress, please report issues at %s' % URL_ISSUES)
 
-    logging.basicConfig(level=LOG_LEVELS[options.loglevel], format='%(levelname)-8s %(message)s')
+    log_helper.enable_logging(level=options.loglevel)
     # enable logging in the modules:
-    log.setLevel(logging.NOTSET)
+    olevba.enable_logging()
 
     t = tablestream.TableStream(style=tablestream.TableStyleSlim,
             header_row=['Result', 'Flags', 'Type', 'File'],
@@ -346,6 +339,7 @@ def main():
             global_result = result
             exitcode = result.exit_code
 
+    log_helper.end_logging()
     print('')
     print('Flags: A=AutoExec, W=Write, X=Execute')
     print('Exit code: %d - %s' % (exitcode, global_result.name))