Commit fffedc77442cbea2ebf633ce2907b2be795800cb
Committed by
Christian Herdtweck
1 parent
26b43390
add log helper
Adds a log helper module that can be used by all modules and handles logging in general, avoiding code duplication. It also handles JSON output formatting by logging all messages in JSON format, thus making it easy for modules to support the `-j` flag. The module works by overwriting the default logging class to extend its behavior (adding a function to always log, useful for banners and other stuff). The JSON format uses a special formatter that will output JSON from a string or a dictionary.
Showing
7 changed files
with
281 additions
and
0 deletions
oletools/util/__init__.py
0 → 100644
oletools/util/log_helper/__init__.py
0 → 100644
oletools/util/log_helper/_json_formatter.py
0 → 100644
| 1 | +import logging | |
| 2 | +import json | |
| 3 | + | |
| 4 | + | |
| 5 | +class JsonFormatter(logging.Formatter): | |
| 6 | + def __init__(self, fmt=None, datefmt=None): | |
| 7 | + super(JsonFormatter, self).__init__(fmt, datefmt) | |
| 8 | + self._is_first_line = True | |
| 9 | + | |
| 10 | + def format(self, record): | |
| 11 | + """ | |
| 12 | + We accept messages that are either dictionaries or not. | |
| 13 | + When we have dictionaries we can just serialize it as JSON right away. | |
| 14 | + """ | |
| 15 | + trailing_comma = ',' | |
| 16 | + | |
| 17 | + if self._is_first_line: | |
| 18 | + trailing_comma = '' | |
| 19 | + self._is_first_line = False | |
| 20 | + | |
| 21 | + json_dict = record.msg \ | |
| 22 | + if type(record.msg) is dict \ | |
| 23 | + else dict(msg=record.msg) | |
| 24 | + json_dict['level'] = record.levelname | |
| 25 | + | |
| 26 | + return trailing_comma + ' ' + json.dumps(json_dict) | ... | ... |
oletools/util/log_helper/_logger_class.py
0 → 100644
| 1 | +import logging | |
| 2 | +from . import _root_logger_wrapper | |
| 3 | + | |
| 4 | + | |
| 5 | +class OletoolsLogger(logging.Logger): | |
| 6 | + """ | |
| 7 | + Default class for all loggers returned by the logging module. | |
| 8 | + """ | |
| 9 | + def __init__(self, name, level=logging.NOTSET): | |
| 10 | + super(self.__class__, self).__init__(name, level) | |
| 11 | + | |
| 12 | + def log_at_current_level(self, message): | |
| 13 | + """ | |
| 14 | + Logs the message using the current level. | |
| 15 | + This is useful for messages that should always appear, | |
| 16 | + such as banners. | |
| 17 | + """ | |
| 18 | + | |
| 19 | + level = _root_logger_wrapper.get_root_logger_level() \ | |
| 20 | + if _root_logger_wrapper.is_logging_initialized() \ | |
| 21 | + else self.level | |
| 22 | + | |
| 23 | + self.log(level, message) | ... | ... |
oletools/util/log_helper/_null_handler.py
0 → 100644
oletools/util/log_helper/_root_logger_wrapper.py
0 → 100644
| 1 | +import logging | |
| 2 | + | |
| 3 | + | |
| 4 | +def is_logging_initialized(): | |
| 5 | + """ | |
| 6 | + We use the same strategy as the logging module | |
| 7 | + when checking if the logging was initialized - | |
| 8 | + look for handlers in the root logger | |
| 9 | + """ | |
| 10 | + return len(logging.root.handlers) > 0 | |
| 11 | + | |
| 12 | + | |
| 13 | +def get_root_logger_level(): | |
| 14 | + return logging.root.level | ... | ... |
oletools/util/log_helper/log_helper.py
0 → 100644
| 1 | +""" | |
| 2 | +log_helper.py | |
| 3 | + | |
| 4 | +General logging helpers | |
| 5 | + | |
| 6 | +.. codeauthor:: Intra2net AG <info@intra2net> | |
| 7 | +""" | |
| 8 | + | |
| 9 | +# === LICENSE ================================================================= | |
| 10 | +# | |
| 11 | +# Redistribution and use in source and binary forms, with or without | |
| 12 | +# modification, are permitted provided that the following conditions are met: | |
| 13 | +# | |
| 14 | +# * Redistributions of source code must retain the above copyright notice, | |
| 15 | +# this list of conditions and the following disclaimer. | |
| 16 | +# * Redistributions in binary form must reproduce the above copyright notice, | |
| 17 | +# this list of conditions and the following disclaimer in the documentation | |
| 18 | +# and/or other materials provided with the distribution. | |
| 19 | +# | |
| 20 | +# THIS SOFTWARE IS PROVIDED BY THE COPYRIGHT HOLDERS AND CONTRIBUTORS "AS IS" | |
| 21 | +# AND ANY EXPRESS OR IMPLIED WARRANTIES, INCLUDING, BUT NOT LIMITED TO, THE | |
| 22 | +# IMPLIED WARRANTIES OF MERCHANTABILITY AND FITNESS FOR A PARTICULAR PURPOSE | |
| 23 | +# ARE DISCLAIMED. IN NO EVENT SHALL THE COPYRIGHT HOLDER OR CONTRIBUTORS BE | |
| 24 | +# LIABLE FOR ANY DIRECT, INDIRECT, INCIDENTAL, SPECIAL, EXEMPLARY, OR | |
| 25 | +# CONSEQUENTIAL DAMAGES (INCLUDING, BUT NOT LIMITED TO, PROCUREMENT OF | |
| 26 | +# SUBSTITUTE GOODS OR SERVICES; LOSS OF USE, DATA, OR PROFITS; OR BUSINESS | |
| 27 | +# INTERRUPTION) HOWEVER CAUSED AND ON ANY THEORY OF LIABILITY, WHETHER IN | |
| 28 | +# CONTRACT, STRICT LIABILITY, OR TORT (INCLUDING NEGLIGENCE OR OTHERWISE) | |
| 29 | +# ARISING IN ANY WAY OUT OF THE USE OF THIS SOFTWARE, EVEN IF ADVISED OF THE | |
| 30 | +# POSSIBILITY OF SUCH DAMAGE. | |
| 31 | + | |
| 32 | +# ----------------------------------------------------------------------------- | |
| 33 | +# CHANGELOG: | |
| 34 | +# 2017-12-07 v0.01 CH: - first version | |
| 35 | +# 2018-02-05 v0.02 SA: - fixed log level selection and reformatted code | |
| 36 | +# 2018-02-06 v0.03 SA: - refactored code to deal with NullHandlers | |
| 37 | +# 2018-02-07 v0.04 SA: - fixed control of handlers propagation | |
| 38 | +# 2018-04-23 v0.05 SA: - refactored the whole logger to use an OOP approach | |
| 39 | + | |
| 40 | +# ----------------------------------------------------------------------------- | |
| 41 | +# TODO: | |
| 42 | + | |
| 43 | + | |
| 44 | +from __future__ import print_function | |
| 45 | +from ._json_formatter import JsonFormatter | |
| 46 | +from ._null_handler import NullHandler | |
| 47 | +from ._logger_class import OletoolsLogger | |
| 48 | +from . import _root_logger_wrapper | |
| 49 | +import logging | |
| 50 | +import sys | |
| 51 | + | |
| 52 | + | |
| 53 | +LOG_LEVELS = { | |
| 54 | + 'debug': logging.DEBUG, | |
| 55 | + 'info': logging.INFO, | |
| 56 | + 'warning': logging.WARNING, | |
| 57 | + 'error': logging.ERROR, | |
| 58 | + 'critical': logging.CRITICAL | |
| 59 | +} | |
| 60 | + | |
| 61 | +DEFAULT_LOGGER_NAME = 'oletools' | |
| 62 | +DEFAULT_MESSAGE_FORMAT = '%(levelname)-8s %(message)s' | |
| 63 | + | |
| 64 | + | |
| 65 | +class LogHelper: | |
| 66 | + def __init__(self): | |
| 67 | + self._all_names = set() # set so we do not have duplicates | |
| 68 | + self._use_json = False | |
| 69 | + self._is_enabled = False | |
| 70 | + self._json_formatter = JsonFormatter() | |
| 71 | + logging.setLoggerClass(OletoolsLogger) | |
| 72 | + | |
| 73 | + def get_or_create_logger(self, name=DEFAULT_LOGGER_NAME, level=logging.WARNING): | |
| 74 | + """ | |
| 75 | + Get a logger or create one if it doesn't exist. | |
| 76 | + To keep the same behavior as `logging.getLogger`, we add a StreamHandler | |
| 77 | + that logs by default to stderr | |
| 78 | + """ | |
| 79 | + return self._get_or_create_logger(name, level, logging.StreamHandler()) | |
| 80 | + | |
| 81 | + def get_or_create_silent_logger(self, name=DEFAULT_LOGGER_NAME, level=logging.CRITICAL + 1): | |
| 82 | + """ | |
| 83 | + Get a logger or create one if it doesn't exist, setting a NullHandler | |
| 84 | + (to avoid printing to the console) as the handler if that's the case. | |
| 85 | + By default we also use a higher logging level so every message will | |
| 86 | + be ignored. | |
| 87 | + This is useful when we don't want to print anything when the logger | |
| 88 | + is not configured by the main application. | |
| 89 | + | |
| 90 | + Python 2.7 has logging.NullHandler, but this is necessary for 2.6: | |
| 91 | + git pus https://docs.python.org/2.6/library/logging.html#configuring-logging-for-a-library | |
| 92 | + """ | |
| 93 | + if sys.version_info >= (2, 6): | |
| 94 | + handler = logging.NullHandler | |
| 95 | + else: | |
| 96 | + handler = NullHandler | |
| 97 | + | |
| 98 | + return self._get_or_create_logger(name, level, handler()) | |
| 99 | + | |
| 100 | + def enable_logging(self, use_json, level, log_format=DEFAULT_MESSAGE_FORMAT, stream=None): | |
| 101 | + """ called from main after parsing arguments """ | |
| 102 | + if self._is_enabled: | |
| 103 | + raise ValueError('re-enabling logging. Not sure whether that is ok...') | |
| 104 | + | |
| 105 | + log_level = LOG_LEVELS[level] | |
| 106 | + logging.basicConfig(level=log_level, format=log_format, stream=stream) | |
| 107 | + self._is_enabled = True | |
| 108 | + | |
| 109 | + self._use_json = use_json | |
| 110 | + | |
| 111 | + sys.excepthook = self._log_except_hook | |
| 112 | + | |
| 113 | + # since there could be loggers already created we go through all of them | |
| 114 | + # and set their formatters to our custom Json formatter | |
| 115 | + # also set their levels so they respect what the main module wants logged | |
| 116 | + for name in self._all_names: | |
| 117 | + logger = self.get_or_create_logger(name) | |
| 118 | + logger.setLevel(log_level) | |
| 119 | + | |
| 120 | + if self._use_json: | |
| 121 | + self._make_json(logger) | |
| 122 | + | |
| 123 | + # print the start of the logging message list | |
| 124 | + if self._use_json: | |
| 125 | + print('[') | |
| 126 | + | |
| 127 | + def end_logging(self): | |
| 128 | + """ called at end of main """ | |
| 129 | + if not self._is_enabled: | |
| 130 | + return | |
| 131 | + self._is_enabled = False | |
| 132 | + | |
| 133 | + # end logging | |
| 134 | + self._all_names = set() | |
| 135 | + logging.shutdown() | |
| 136 | + | |
| 137 | + # end json list | |
| 138 | + if self._use_json: | |
| 139 | + print(']') | |
| 140 | + self._use_json = False | |
| 141 | + | |
| 142 | + def _log_except_hook(self, exctype, value, traceback): | |
| 143 | + """ | |
| 144 | + Global hook for exceptions so we can always end logging | |
| 145 | + """ | |
| 146 | + self.end_logging() | |
| 147 | + sys.__excepthook__(exctype, value, traceback) | |
| 148 | + | |
| 149 | + def _get_or_create_logger(self, name, level, handler=None): | |
| 150 | + """ | |
| 151 | + If a logger doesn't exist, we create it and set the handler, | |
| 152 | + if it given. This avoids messing with existing loggers. | |
| 153 | + If we are using json then we also skip adding a handler, | |
| 154 | + since it would be removed afterwards | |
| 155 | + """ | |
| 156 | + | |
| 157 | + # logging.getLogger creates a logger if it doesn't exist, | |
| 158 | + # so we need to check before calling it | |
| 159 | + if handler and not self._use_json and not self._log_exists(name): | |
| 160 | + logger = logging.getLogger(name) | |
| 161 | + logger.addHandler(handler) | |
| 162 | + else: | |
| 163 | + logger = logging.getLogger(name) | |
| 164 | + | |
| 165 | + self._set_logger_level(logger, level) | |
| 166 | + self._all_names.add(name) | |
| 167 | + | |
| 168 | + if self._use_json: | |
| 169 | + self._make_json(logger) | |
| 170 | + | |
| 171 | + return logger | |
| 172 | + | |
| 173 | + def _make_json(self, logger): | |
| 174 | + # remove handlers (sometimes there are multiple by default) | |
| 175 | + for handler in logger.handlers: | |
| 176 | + logger.removeHandler(handler) | |
| 177 | + new_handler = logging.StreamHandler(sys.stdout) | |
| 178 | + new_handler.setFormatter(self._json_formatter) | |
| 179 | + logger.addHandler(new_handler) | |
| 180 | + | |
| 181 | + # Don't let it propagate to parent loggers, otherwise we might get | |
| 182 | + # duplicated messages from the root logger | |
| 183 | + logger.propagate = False | |
| 184 | + | |
| 185 | + @staticmethod | |
| 186 | + def _set_logger_level(logger, level): | |
| 187 | + """ | |
| 188 | + If the logging is already initialized, we use the same level that | |
| 189 | + was set to the root logger. This prevents imported modules' loggers | |
| 190 | + from messing with the main module logging. | |
| 191 | + """ | |
| 192 | + if _root_logger_wrapper.is_logging_initialized(): | |
| 193 | + logger.setLevel(_root_logger_wrapper.get_root_logger_level()) | |
| 194 | + else: | |
| 195 | + logger.setLevel(level) | |
| 196 | + | |
| 197 | + @staticmethod | |
| 198 | + def _log_exists(name): | |
| 199 | + """ | |
| 200 | + We check the log manager instead of our global _all_names variable | |
| 201 | + since the logger could have been created outside of the helper | |
| 202 | + """ | |
| 203 | + return name in logging.Logger.manager.loggerDict | ... | ... |