[SEBA-314] Refactoring multistructlog
- Redid the way loggers are created to use vanilla structlog
- This fixes the incorrect line numbering and similar in SEBA-314
- Fix/rewrite unit tests
- Apply pep8 formatting
- Make compatible with Python 3.x, enable multi-version testing with tox
- Removed XOS specific code
Change-Id: I615bc6f32ba2592475e3a8cf22850c563001a3d4
diff --git a/.gitignore b/.gitignore
new file mode 100644
index 0000000..036ac49
--- /dev/null
+++ b/.gitignore
@@ -0,0 +1,11 @@
+*.pyc
+dist
+.tox
+__pycache__
+*.egg-info
+MANIFEST
+.coverage
+coverage.xml
+nose2-junit.xml
+msl_test_scratch
+
diff --git a/.gitreview b/.gitreview
new file mode 100644
index 0000000..bb5325a
--- /dev/null
+++ b/.gitreview
@@ -0,0 +1,5 @@
+[gerrit]
+host=gerrit.opencord.org
+port=29418
+project=multistructlog.git
+defaultremote=origin
diff --git a/README.rst b/README.rst
new file mode 100644
index 0000000..2339a25
--- /dev/null
+++ b/README.rst
@@ -0,0 +1,59 @@
+multistructlog
+==============
+
+This module is a thin wrapper around Structlog that sets and provides defaults
+for sending logs to one or more logging destinations with individual formatting
+per destination.
+
+The API consists of a single function: ``create_logger()``.
+
+Args:
+ logging_config (dict): Input to logging.config.dictConfig
+ level(logging.loglevel): Overrides logging level for all loggers (not handlers!)
+
+Returns:
+ log: structlog logger object
+
+It can be invoked as follows:
+
+ logging_config = ...
+
+ log = multistructlog.create_logger(config, level=logging.INFO)
+ log.info('Entered function', foo='bar')
+
+To create a ``logging_config`` dictionary, see these docs:
+
+ https://docs.python.org/2.7/library/logging.config.html#logging.config.dictConfig
+ http://www.structlog.org/en/stable/standard-library.html#rendering-using-structlog-based-formatters-within-logging
+
+There are no required arguments to `create_logger()` - any missing parts of the
+config will be filled in with defaults that print structured logs to the
+console.
+
+If you don't specify a ``formatters`` section in your config, three will be
+created which can be used in handlers:
+
+ - ``json``: renders one JSON dictionary per message
+ - ``structured``: prints structured logs with the ``structlog.dev.ConsoleRenderer``
+ - ``structured-color``: same as ``structured`` but in color
+
+If you don't specify a ``handlers`` section, a handler will be added that logs
+to console with ``logging.StreamHandler`` with format ``structured`` at level
+``DEBUG``.
+
+If you don't specify a ``loggers`` section, a default logger (empty string)
+will be created with all items in ``handlers`` added to it, with a level of
+``NOTSET`` (every level printed).
+
+When setting log level, the higher of ``logging_config['loggers'][*]['level']``
+and ``logging_config['handlers'][*]['level']`` is used. The ``level`` parameter
+overrides the ``loggers`` value of level, not the ``handlers`` one.
+
+If the handler's level is set to ``DEBUG`` but the logger's level is set to
+``ERROR``, the handler will only log ``ERROR`` level messages.
+
+Multistructlog also adds a ``TRACE`` log level (integer level 5) that is below
+"DEBUG" to both standard library ``Logger`` and Structlog ``BoundLogger``.
+
+List of standard logging levels:
+ https://docs.python.org/2.7/library/logging.html#logging-levels
diff --git a/VERSION b/VERSION
new file mode 100644
index 0000000..227cea2
--- /dev/null
+++ b/VERSION
@@ -0,0 +1 @@
+2.0.0
diff --git a/multistructlog.py b/multistructlog.py
index ecfd499..49338d0 100644
--- a/multistructlog.py
+++ b/multistructlog.py
@@ -12,168 +12,163 @@
# See the License for the specific language governing permissions and
# limitations under the License.
-"""
-multistructlog logging module
-
-This module enables structured data to be logged to a single destination, or to
-multiple destinations simulataneously. The API consists of a single function:
-create_logger, which returns a structlog object. You can invoke it as follows:
-
- log = logger.create_logger(xos_config, level=logging.INFO)
- log.info('Entered function', name = '%s' % fn_name)
-
-The default handlers in XOS are the console and Logstash. You can override the
-handlers, structlog's processors, or anything else by adding keyword arguments
-to create_logger:
-
- log = logger.create_logger(xos_config, level=logging.INFO,
- handlers=[logging.StreamHandler(sys.stdout),
- logstash.LogstashHandler('somehost', 5617, version=1)])
-
-Each handler depends on a specific renderer (e.g. Logstash needs JSON and
-stdout needs ConsoleRenderer) but a structlog instance can enchain only one
-renderer. For this reason, we apply renderers at the logging layer, as
-logging formatters.
-"""
-
+from six import iteritems
+import copy
import logging
import logging.config
-import logstash
import structlog
-import sys
-import copy
-import inspect
-PROCESSOR_MAP = {
- 'StreamHandler': structlog.dev.ConsoleRenderer(colors=True, force_colors=True),
- 'LogstashHandler': structlog.processors.JSONRenderer(),
- 'RotatingFileHandler': structlog.processors.JSONRenderer()
-}
+"""
+We expose the Structlog logging interface directly.
+This should allow callers to bind contexts incrementally and configure and use
+other features of structlog directly.
-class FormatterFactory:
- def __init__(self, handler_name):
- self.handler_name = handler_name
+To create a logging_config dictionary see these docs:
- def __call__(self):
- try:
- processor = PROCESSOR_MAP[self.handler_name]
- except KeyError:
- processor = structlog.processors.KeyValueRenderer()
+ https://docs.python.org/2.7/library/logging.config.html#logging.config.dictConfig
+ http://www.structlog.org/en/stable/standard-library.html#rendering-using-structlog-based-formatters-within-logging
- formatter = structlog.stdlib.ProcessorFormatter(processor)
+When setting log level, the higher of logging_config['logger'][*]['level'] and
+logging_config['handler'][*]['level'] is used.
- return formatter
+If the handler's level is set to "DEBUG" but the handler's is set to "ERROR",
+the handler will only log "ERROR" level messages.
+List of logging levels:
+ https://docs.python.org/2.7/library/logging.html#logging-levels
-class XOSLoggerFactory:
- def __init__(self, handlers):
- self.handlers = handlers
-
- def __call__(self):
- base_logger = logging.getLogger("multistructlog")
- base_logger.handlers = []
- for h in self.handlers:
- formatter = FormatterFactory(h.__class__.__name__)()
- h.setFormatter(formatter)
- base_logger.addHandler(h)
-
- self.logger = base_logger
- return self.logger
-
-
-""" We expose the Structlog logging interface directly. This should allow callers to
- bind contexts incrementally and configure and use other features of structlog directly
-
- The use of structlog in Chameleon was used for reference when writing this code.
"""
+# Add a TRACE log level to both structlog and normal python logger
+
+# new level is 5, per these locations:
+# https://github.com/python/cpython/blob/2.7/Lib/logging/__init__.py#L132
+# https://github.com/hynek/structlog/blob/18.2.0/src/structlog/stdlib.py#L296
+structlog.stdlib.TRACE = TRACE_LOGLVL = 5
+structlog.stdlib._NAME_TO_LEVEL['trace'] = TRACE_LOGLVL
+logging.addLevelName(TRACE_LOGLVL, "TRACE")
+
+
+# Create structlog TRACE level and add to BoundLogger object
+# https://github.com/hynek/structlog/blob/18.2.0/src/structlog/stdlib.py#L59
+def trace_structlog(self, event=None, *args, **kw):
+ ''' enable TRACE for structlog '''
+ return self._proxy_to_logger("trace", event, *args, **kw)
+
+
+structlog.stdlib.BoundLogger.trace = trace_structlog
+
+
+# create standard logger TRACE level and add to Logger object
+# https://github.com/python/cpython/blob/2.7/Lib/logging/__init__.py#L1152
+def trace_loglevel(self, message, *args, **kws):
+ ''' enable TRACE for standard logger'''
+ if self.isEnabledFor(TRACE_LOGLVL):
+ self._log(TRACE_LOGLVL, message, args, **kws)
+
+
+logging.Logger.trace = trace_loglevel
+
+# used to return same logger on multiple calls without reconfiguring it
+# may be somewhat redundant with "cache_logger_on_first_use" in structlog
CURRENT_LOGGER = None
-CURRENT_LOGGER_PARMS = None
+CURRENT_LOGGER_PARAMS = None
-def create_logger(_config=None, extra_processors=[],
- force_create=False, level=None):
+def create_logger(logging_config=None, level=None):
"""
Args:
- _config (dict): The standard config for Python's logging module
- extra_processors(dict): Custom structlog processors
- force_create(bool): Forces creation of the logger
- level(logging.loglevel): Overrides logging level
+ logging_config (dict): Input to logging.config.dictConfig
+ level(logging.loglevel): Overrides logging level for all loggers
Returns:
log: structlog logger
"""
- first_entry_elts = ['Starting']
-
- """Inherit base options from config"""
- if _config:
- logging_config = copy.deepcopy(_config)
- else:
- first_entry_elts.append('Config is empty')
- logging_config = {'version': 1}
-
- """Check if a logger with this configuration has already been created, if so, return that logger
- instead of creating a new one"""
global CURRENT_LOGGER
- global CURRENT_LOGGER_PARMS
- if CURRENT_LOGGER and CURRENT_LOGGER_PARMS == (
- logging_config, extra_processors, level) and not force_create:
+ global CURRENT_LOGGER_PARAMS
+
+ if CURRENT_LOGGER and CURRENT_LOGGER_PARAMS == (logging_config, level):
return CURRENT_LOGGER
- if level:
- try:
- for k, v in logging_config['loggers'].iteritems():
- v['level'] = level
- except KeyError:
- first_entry_elts.append('Level override failed')
+ # store unmodified config, which is changed later
+ CURRENT_LOGGER_PARAMS = (copy.deepcopy(logging_config), level)
+ # set bare minimum config if not set
+ if not logging_config:
+ logging_config = {'version': 1}
+
+ # check if formatters exists in logging_config, set defaults if not set
+ if "formatters" not in logging_config:
+
+ logging_config['formatters'] = {
+ 'json': {
+ '()': structlog.stdlib.ProcessorFormatter,
+ "processor": structlog.processors.JSONRenderer(),
+ },
+ 'structured-color': {
+ '()': structlog.stdlib.ProcessorFormatter,
+ 'processor': structlog.dev.ConsoleRenderer(colors=True),
+ },
+ 'structured': {
+ '()': structlog.stdlib.ProcessorFormatter,
+ 'processor': structlog.dev.ConsoleRenderer(colors=False),
+ },
+ }
+
+ # set a default colored output to console handler if none are set
+ if "handlers" not in logging_config:
+
+ logging_config['handlers'] = {
+ 'default': {
+ 'class': 'logging.StreamHandler',
+ 'level': 'DEBUG',
+ },
+ }
+
+ # if a formatter isn't set in a handler, use structured formatter
+ for k, v in iteritems(logging_config['handlers']):
+ if 'formatter' not in v:
+ v['formatter'] = 'structured'
+
+ # add loggers if they don't exist or default '' logger is missing
+ if "loggers" not in logging_config or '' not in logging_config['loggers']:
+
+ # By default, include all handlers in default '' logger
+ handler_l = logging_config['handlers'].keys()
+
+ logging_config['loggers'] = {
+ '': {
+ 'handlers': handler_l,
+ 'level': 'NOTSET', # don't filter on level in logger
+ 'propagate': True
+ },
+ }
+
+ # If level is set, override log level of base loggers
+ if level:
+ for k, v in iteritems(logging_config['loggers']):
+ v['level'] = level
+
+ # configure standard logger
logging.config.dictConfig(logging_config)
- processors = copy.copy(extra_processors)
- processors.extend([
- structlog.processors.StackInfoRenderer(),
- structlog.processors.format_exc_info,
- structlog.stdlib.ProcessorFormatter.wrap_for_formatter
- ])
-
-
- handlers = logging.getLogger('multistructlog').handlers
-
- if not handlers:
- caller = inspect.stack()[1]
-
- try:
- filename = inspect.getmodule(caller[0]).__name__
- except AttributeError:
- filename = '/tmp/multistructlog'
-
- handlers = [
- logging.StreamHandler(sys.stdout),
- logging.handlers.RotatingFileHandler(
- filename=filename,
- maxBytes=10485760,
- backupCount=1)
- ]
-
- factory = XOSLoggerFactory(handlers)
-
+ # configure structlog
structlog.configure(
- processors=processors,
- logger_factory=factory,
+ processors=[
+ structlog.processors.StackInfoRenderer(),
+ structlog.processors.format_exc_info,
+ structlog.stdlib.ProcessorFormatter.wrap_for_formatter,
+ ],
+ context_class=dict,
+ logger_factory=structlog.stdlib.LoggerFactory(),
+ wrapper_class=structlog.stdlib.BoundLogger,
+ cache_logger_on_first_use=True,
)
log = structlog.get_logger()
- first_entry = '. '.join(first_entry_elts)
- log.info(first_entry, level_override=level, **logging_config)
CURRENT_LOGGER = log
- CURRENT_LOGGER_PARMS = (logging_config, extra_processors, level)
+
return log
-
-
-if __name__ == '__main__':
- l = create_logger(
- {'version': 2, 'loggers': {'': {'level': 'INFO'}}}, level="INFO")
- l.info("Test OK")
diff --git a/requirements.txt b/requirements.txt
new file mode 100644
index 0000000..8e48f43
--- /dev/null
+++ b/requirements.txt
@@ -0,0 +1,3 @@
+structlog
+colorama
+six
diff --git a/setup.py b/setup.py
index 4e69f55..9337274 100644
--- a/setup.py
+++ b/setup.py
@@ -16,23 +16,44 @@
from setuptools import setup
-setup(name='multistructlog',
- version='1.5',
- description='structlog with multiple simultaneous logging backends',
- author='Varun Belur, Sapan Bhatia',
- author_email='varun@opennetworking.org,sapan@opennetworking.org',
- py_modules=['multistructlog'],
- license='Apache 2',
- classifiers=[
- 'Development Status :: 5 - Production/Stable',
- 'Intended Audience :: Developers',
- 'Topic :: System :: Logging',
- 'License :: OSI Approved :: Apache Software License',
- 'Programming Language :: Python :: 2.7'
- ],
- copyright='Open Networking Foundation',
- include_package_data=True,
- install_requires=['structlog', 'python-logstash', 'colorama'],
- keywords=['multistructlog', 'structlog',
- 'multiple backends', 'xos logging']
- )
+
+def readme():
+ with open('README.rst') as f:
+ return f.read()
+
+
+def version():
+ with open('VERSION') as f:
+ return f.read()
+
+
+def parse_requirements(filename):
+ lineiter = (line.strip() for line in open(filename))
+ return [line for line in lineiter if line and not line.startswith("#")]
+
+
+setup(
+ name='multistructlog',
+ version=version(),
+ description='structlog with multiple simultaneous logging backends',
+ long_description=readme(),
+ author='Varun Belur, Sapan Bhatia, Zack Williams',
+ author_email='''
+ varun@opennetworking.org,sapan@opennetworking.org,zdw@opennetworking.org
+ ''',
+ py_modules=['multistructlog'],
+ license='Apache v2',
+ classifiers=[
+ 'Development Status :: 5 - Production/Stable',
+ 'Intended Audience :: Developers',
+ 'Topic :: System :: Logging',
+ 'License :: OSI Approved :: Apache Software License',
+ 'Programming Language :: Python :: 2.7',
+ 'Programming Language :: Python :: 3',
+ ],
+ copyright='Open Networking Foundation',
+ include_package_data=True,
+ install_requires=parse_requirements('requirements.txt'),
+ keywords=['multistructlog', 'structlog', 'multiple backends'],
+ data_files=[('', ['VERSION', 'requirements.txt', 'README.rst'])],
+)
diff --git a/tests/test_logger.py b/tests/test_logger.py
deleted file mode 100644
index 9e40ca7..0000000
--- a/tests/test_logger.py
+++ /dev/null
@@ -1,79 +0,0 @@
-
-# Copyright 2017-present Open Networking Foundation
-#
-# Licensed under the Apache License, Version 2.0 (the "License");
-# you may not use this file except in compliance with the License.
-# You may obtain a copy of the License at
-#
-# http://www.apache.org/licenses/LICENSE-2.0
-#
-# Unless required by applicable law or agreed to in writing, software
-# distributed under the License is distributed on an "AS IS" BASIS,
-# WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
-# See the License for the specific language governing permissions and
-# limitations under the License.
-
-
-import unittest
-import mock
-import pdb
-import os, sys
-import multistructlog
-import logging
-
-class MockLogging:
- def debug(self, str):
- return str
-
-class TestMultiStructLog(unittest.TestCase):
- def setUp(self):
- self.logging_config= {
- 'version': 1,
- 'handlers': {
- 'default': {
- 'class': 'logging.StreamHandler',
- },
- },
-
- 'loggers': {
- '': {
- 'handlers': ['default'],
- 'level': 'INFO',
- 'propagate': True
- },
- }
- }
-
- self.config = self.logging_config
-
- @mock.patch('multistructlog.logging')
- def test_reload(self, mock_logging):
- logger = multistructlog.create_logger({'version':1, 'foo':'bar'})
- logger0 = multistructlog.create_logger({'version':1, 'foo':'bar'})
- logger2 = multistructlog.create_logger({'version':1, 'foo':'notbar'})
- self.assertEqual(logger, logger0)
- self.assertNotEqual(logger,logger2)
-
- # "Starting" is only printed once
- self.assertEqual(mock_logging.StreamHandler.call_count, 2)
-
- @mock.patch('multistructlog.logging')
- def test_level(self, mock_logging):
- logger = multistructlog.create_logger({'version':1, 'foo':'x'})
- logger.info('Test 1')
- logger.debug('Test 2')
-
- # Default level is INFO
- self.assertEqual(mock_logging.StreamHandler.call_count, 1)
-
- @mock.patch('multistructlog.logging')
- def test_override_level(self, mock_logging):
- logger = multistructlog.create_logger(self.config, level='DEBUG')
-
- logger.info('Test 1')
- logger.debug('Test 2')
-
- self.assertEqual(mock_logging.StreamHandler.call_count, 2)
-
-if __name__ == '__main__':
- unittest.main()
diff --git a/tests/test_multistructlog.py b/tests/test_multistructlog.py
new file mode 100644
index 0000000..2e7171a
--- /dev/null
+++ b/tests/test_multistructlog.py
@@ -0,0 +1,133 @@
+# Copyright 2017-present Open Networking Foundation
+#
+# Licensed under the Apache License, Version 2.0 (the "License");
+# you may not use this file except in compliance with the License.
+# You may obtain a copy of the License at
+#
+# http://www.apache.org/licenses/LICENSE-2.0
+#
+# Unless required by applicable law or agreed to in writing, software
+# distributed under the License is distributed on an "AS IS" BASIS,
+# WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
+# See the License for the specific language governing permissions and
+# limitations under the License.
+
+import multistructlog
+import os
+import logging
+import logging.config
+import shutil
+import json
+import unittest
+import structlog
+
+# test directory, cleared and left around after testing
+test_scratch = "msl_test_scratch"
+
+
+class TestMultiStructLog(unittest.TestCase):
+
+ @classmethod
+ def setUpClass(clsG):
+ # delete and recreate test_scratch directory if it exists
+ if os.path.isdir(test_scratch):
+ shutil.rmtree(test_scratch)
+
+ os.mkdir(test_scratch)
+
+ def tearDown(self):
+ structlog.reset_defaults()
+
+ def test_reload(self):
+ '''
+ Test that creating creatinging multiple identical loggers will reuse
+ existing loggers
+ '''
+
+ logger0 = multistructlog.create_logger({'version': 1, 'foo': 'bar'})
+ logger1 = multistructlog.create_logger({'version': 1, 'foo': 'bar'})
+ logger2 = multistructlog.create_logger()
+
+ self.assertEqual(logger0, logger1)
+ self.assertNotEqual(logger0, logger2)
+
+ def test_different_formatters(self):
+ '''
+ Test different formattters and levels to different output streams
+ NOTE: Only one test as logger has global state that is hard to reset
+ between tests without breaking other things.
+ '''
+
+ f1 = os.path.join(test_scratch, 'different_formatters_test_file1')
+ f2 = os.path.join(test_scratch, 'different_formatters_test_file2.json')
+
+ logging_config = {
+ 'version': 1,
+ 'handlers': {
+ 'file1': {
+ 'class': 'logging.handlers.RotatingFileHandler',
+ 'level': 'WARNING',
+ 'formatter': 'structured',
+ 'filename': f1,
+ },
+ 'file2': {
+ 'class': 'logging.handlers.RotatingFileHandler',
+ 'level': 'INFO',
+ 'formatter': 'json',
+ 'filename': f2,
+ },
+ },
+ 'formatters': {
+ 'json': {
+ '()': structlog.stdlib.ProcessorFormatter,
+ "processor": structlog.processors.JSONRenderer(),
+ },
+ 'structured': {
+ '()': structlog.stdlib.ProcessorFormatter,
+ 'processor': structlog.dev.ConsoleRenderer(colors=False),
+ },
+ },
+ 'loggers': {
+ '': {
+ 'handlers': ['file1', 'file2'],
+ 'level': 'WARNING',
+ 'propagate': True
+ },
+ }
+ }
+
+ # reset level to debug, overriding 'loggers' directive above
+ logger = multistructlog.create_logger(logging_config,
+ level=logging.DEBUG)
+
+ extra_data = {'number': 42}
+
+ logger.warning("should be in both files", extra=extra_data)
+
+ # filtered by file1 handler
+ logger.info("should only be in file2")
+
+ # filtered by both handlers, but not by loggers
+ logger.debug("should not be in either file")
+
+ # test new trace level
+ logger.trace("testing trace, shouldn't be in either file")
+
+ # check contents of file1
+ with open(f1) as f1fh:
+ f1_desired = '''should be in both files extra={'number': 42}
+'''
+ self.assertEqual(f1fh.read(), f1_desired)
+
+ # check contents of file2
+ f2_read = []
+ f2_desired = [
+ {"event": "should be in both files", "extra": {"number": 42}},
+ {"event": "should only be in file2"},
+ ]
+
+ with open(f2) as f2fh:
+ for line in f2fh:
+ f2_read.append(json.loads(line))
+
+ self.assertEqual(f2_read, f2_desired)
diff --git a/tox.ini b/tox.ini
new file mode 100644
index 0000000..bd840cf
--- /dev/null
+++ b/tox.ini
@@ -0,0 +1,28 @@
+; Copyright 2018-present Open Networking Foundation
+;
+; Licensed under the Apache License, Version 2.0 (the "License");
+; you may not use this file except in compliance with the License.
+; You may obtain a copy of the License at
+;
+; http://www.apache.org/licenses/LICENSE-2.0
+;
+; Unless required by applicable law or agreed to in writing, software
+; distributed under the License is distributed on an "AS IS" BASIS,
+; WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
+; See the License for the specific language governing permissions and
+; limitations under the License.
+
+[tox]
+envlist = py27,py35,py36
+skip_missing_interpreters = true
+
+[testenv]
+deps =
+ nose2
+ structlog
+ six
+ flake8
+commands =
+ nose2 --verbose --junit-xml
+ flake8
+
diff --git a/unittest.cfg b/unittest.cfg
new file mode 100644
index 0000000..544a816
--- /dev/null
+++ b/unittest.cfg
@@ -0,0 +1,8 @@
+[unittest]
+plugins=nose2.plugins.junitxml
+
+[coverage]
+always-on=True
+coverage=
+ multistructlog
+coverage-report=xml