diff --git a/.github/workflows/testing.yml b/.github/workflows/testing.yml index a15f9ef..cb7a043 100644 --- a/.github/workflows/testing.yml +++ b/.github/workflows/testing.yml @@ -19,7 +19,7 @@ jobs: - name: Install python uses: actions/setup-python@v2.2.2 with: - python-version: 3.9 + python-version: "3.x" - name: Install dependencies run: | python -m pip install --upgrade pip setuptools @@ -37,7 +37,7 @@ jobs: runs-on: ubuntu-latest strategy: matrix: - python-version: [2.7, 3.7, 3.8, 3.9] + python-version: [2.7, 3.7, 3.8, 3.9, "3.10"] steps: - uses: actions/checkout@v2 - name: Install python ${{matrix.python-version}} @@ -70,7 +70,7 @@ jobs: - name: Install python uses: actions/setup-python@v2.2.2 with: - python-version: 3.9 + python-version: "3.7" # matches readthedocs.yml - name: Install dependencies run: | python -m pip install --upgrade pip setuptools twine diff --git a/README.rst b/README.rst index bb8d360..37b6c47 100644 --- a/README.rst +++ b/README.rst @@ -13,71 +13,36 @@ Usage Configuration ^^^^^^^^^^^^^ +The expectation is that you are using the ``logging.config.dictConfig`` function +somewhere to configure the Python logging module. This library exposes two functions +that return configuration dictionaries appropriate to services and command-line +applications: -.. code-block:: json +:get_cli_configuration: + Returns a configuration that generates human-readable logs - { - "version": 1, - "filters": { - "defaultsetter": { - "()": "jsonscribe.AttributeSetter", - "add_fields": { - "correlation_id": "ext://UUID" - } - } - }, - "formatters": { - "jsonlines": { - "()": "jsonscribe.JSONFormatter", - "include_fields": [ - "name", - "levelname", - "asctime", - "message", - "module", - "correlation_id", - "exc_info" - ], - } - }, - "handlers": { - "loggly": { - "class": "logging.StreamHandler", - "formatter": "jsonlines", - "filters": ["defaultsetter"], - "stream": "ext://sys.stdout" - } - }, - "loggers": { - "somepackage": { - "level": "DEBUG", - } - }, - "root": { - "level": "INFO", - "handlers": ["jsonlines"] - } - } +:get_service_configuration: + Returns a configuration that generates machine-readable logs Logging ^^^^^^^ The following snippet is the simplest usage. It is nothing more than the -textbook usage of the logging module. It uses the logging configuration from -above and generates a JSON blob. +textbook usage of the logging module. It uses the logging configuration for +a service and generates a JSON blob. .. code-block:: python import logging.config - import json + + import jsonscribe if __name__ == '__main__': - config = json.load(open('config.json')) - logging.config.dictConfig(config) + logging.config.dictConfig(jsonscribe.get_service_configuration()) logger = logging.getLogger(__package__).getChild('main') logger.info('processing request') -The JSON message looks something like the following. It is reformatted to -make it readable. The default is to render it as compact JSON. +The JSON message looks something like the following (reformatted to +make it readable). The default is to render it as compact JSON. .. code-block:: json diff --git a/docs/api.rst b/docs/api.rst index d7e7ef3..43adf36 100644 --- a/docs/api.rst +++ b/docs/api.rst @@ -1,16 +1,50 @@ Developer Interface =================== +Logging configuration +--------------------- +The ``jsonscribe.config`` module contains functions that generate sane :func:`logging.config.dictConfig` +values for difference scenarios. Each of the configuration functions uses a template that you can modify before +calling the function (see :data:`~jsonscribe.config.CONFIGURATION_DEFAULTS`). The configuration functions +also obey the following environment variables if they are present. + +.. envvar:: DEBUG + + If this environment variable is set and it can be parsed as a boolean value and the result is *truthy*, + then the root log level will be :data:`logging.DEBUG` instead of the default value. See + :func:`~jsonscribe.utils.parse_boolean` for the list of acceptable values. + +.. envvar:: LOG_FORMAT + + If this environment variable is set, then it overrides the default formatter used by the configuration + functions. This can be useful if you want to run a service from a shell and want human-readable logs. + + .. warning:: + + If ``LOG_FORMAT`` is set to a value that is not a configured formatter, then the configuration functions + will raise a :exc:`ValueError`. + +.. autofunction:: jsonscribe.config.get_service_configuration + +.. autofunction:: jsonscribe.config.get_cli_configuration + +.. autodata:: jsonscribe.config.CONFIGURATION_DEFAULTS + :no-value: + +Implementation classes +---------------------- .. autoclass:: jsonscribe.AttributeSetter :members: - .. autoclass:: jsonscribe.JSONFormatter :members: :private-members: +Helpers +------- +.. autofunction:: jsonscribe.utils.parse_boolean + .. autoclass:: jsonscribe.utils.UTCZone :members: .. autodata:: jsonscribe.utils.utc - diff --git a/docs/conf.py b/docs/conf.py index cae79d3..899dd18 100644 --- a/docs/conf.py +++ b/docs/conf.py @@ -7,10 +7,8 @@ source_suffix = '.rst' master_doc = 'index' html_extra_path = ['../CODE_OF_CONDUCT.md'] -html_static_path = ['.'] -html_theme = 'alabaster' -html_sidebars = {'**': ['about.html', 'navigation.html', 'searchbox.html']} -extensions = [] +html_theme = 'sphinx_rtd_theme' +extensions = ['sphinx_rtd_theme'] # see https://www.sphinx-doc.org/en/master/usage/extensions/intersphinx.html extensions.append('sphinx.ext.intersphinx') diff --git a/docs/examples.rst b/docs/examples.rst index 224dcc8..5d30c38 100644 --- a/docs/examples.rst +++ b/docs/examples.rst @@ -4,5 +4,8 @@ Examples .. literalinclude:: ../examples/simple.py :linenos: +.. literalinclude:: ../examples/attributes.py + :linenos: + .. literalinclude:: ../examples/adapter.py :linenos: diff --git a/docs/history.rst b/docs/history.rst index 1a01787..5a776de 100644 --- a/docs/history.rst +++ b/docs/history.rst @@ -7,6 +7,8 @@ Release History - Integrate with readthedocs.org. - Integrate with codecov.io. - Adopt the Contributor Covenant. +- Add ``jsonscribe.config`` module. +- Advertise support for 3.10 2.0.0 (11-May-2021) ------------------- diff --git a/examples/adapter.py b/examples/adapter.py index cf0dd03..fb00814 100644 --- a/examples/adapter.py +++ b/examples/adapter.py @@ -14,7 +14,7 @@ since it is simply a usage of :class:`logging.LoggerAdapter`. """ -import logging +import logging.config import uuid import jsonscribe @@ -36,15 +36,18 @@ def process(self, message): if __name__ == '__main__': - logging.basicConfig( - level=logging.INFO, - format=('%(levelname)1.1s %(name)s: %(message)s' - '\t{correlation_id=%(correlation_id)s}')) - root_logger = logging.getLogger() - handler = root_logger.handlers[0] - handler.addFilter( - jsonscribe.AttributeSetter( - add_fields={'correlation_id': 'ext://UUID'})) + config = jsonscribe.get_cli_configuration() + config['filters']['attr-setter'] = { + '()': 'jsonscribe.AttributeSetter', + 'add_fields': { + 'correlation_id': 'ext://UUID' + } + } + config['handlers']['console']['filters'].append('attr-setter') + config['formatters']['plain']['format'] = ( + '%(levelname)1.1s %(name)s: %(message)s' + '\t{correlation_id=%(correlation_id)s}') + logging.config.dictConfig(config) processor = Processor() for i in range(0, 10): diff --git a/examples/attributes.py b/examples/attributes.py new file mode 100644 index 0000000..51c1b23 --- /dev/null +++ b/examples/attributes.py @@ -0,0 +1,36 @@ +""" +Example of logging JSON lines with custom attributes. + +This example uses :class:`jsonscribe.AttributeSetter` to create +custom attributes on log records and updates the configuration +to pass the new attribute along in the JSON log bodies. + +""" +import logging.config + +import jsonscribe + + +def failure(): + logger = logging.getLogger('simple.failure') + try: + raise RuntimeError('failed') + except Exception: + logger.exception('something failed') + + +if __name__ == '__main__': + config = jsonscribe.get_service_configuration() + config['filters']['attr-setter'] = { + '()': 'jsonscribe.AttributeSetter', + 'add_fields': { + 'correlation_id': 'ext://UUID' + } + } + config['formatters']['json']['include_fields'].append('correlation_id') + config['handlers']['console']['filters'].append('attr-setter') + + logging.config.dictConfig(config) + logger = logging.getLogger('simple') + logger.info('hi there') + failure() diff --git a/examples/simple.py b/examples/simple.py index 9f7ab3a..f823b12 100644 --- a/examples/simple.py +++ b/examples/simple.py @@ -1,11 +1,5 @@ -""" -Example of logging JSON lines. - -This example uses :class:`jsonscribe.AttributeSetter` and -:class:`jsonscribe.JSONFormatter` to emit log lines as JSON objects. - -""" -import logging +"""Example of logging JSON lines.""" +import logging.config import jsonscribe @@ -19,18 +13,7 @@ def failure(): if __name__ == '__main__': - logging.basicConfig(level=logging.INFO) - root_logger = logging.getLogger() - handler = root_logger.handlers[0] - handler.addFilter( - jsonscribe.AttributeSetter( - add_fields={'correlation_id': 'ext://UUID'})) - handler.setFormatter( - jsonscribe.JSONFormatter(include_fields=[ - 'name', 'levelname', 'asctime', 'message', 'module', - 'correlation_id', 'exc_info' - ])) - + logging.config.dictConfig(jsonscribe.get_service_configuration()) logger = logging.getLogger('simple') logger.info('hi there') failure() diff --git a/jsonscribe/__init__.py b/jsonscribe/__init__.py index cc8babd..e44de82 100644 --- a/jsonscribe/__init__.py +++ b/jsonscribe/__init__.py @@ -1,3 +1,4 @@ +from jsonscribe.config import get_cli_configuration, get_service_configuration from jsonscribe.filters import AttributeSetter from jsonscribe.formatters import JSONFormatter @@ -7,6 +8,8 @@ __all__ = [ 'AttributeSetter', 'JSONFormatter', + 'get_cli_configuration', + 'get_service_configuration', 'version', 'version_info', ] diff --git a/jsonscribe/config.py b/jsonscribe/config.py new file mode 100644 index 0000000..cd77500 --- /dev/null +++ b/jsonscribe/config.py @@ -0,0 +1,120 @@ +import copy +import os + +from jsonscribe import utils + +CONFIGURATION_DEFAULTS = { + 'version': 1, + 'disable_existing_loggers': False, + 'incremental': False, + 'filters': {}, + 'formatters': { + 'json': { + '()': 'jsonscribe.JSONFormatter', + 'include_fields': [ + 'asctime', 'exc_info', 'levelname', 'message', 'module', 'name' + ], + }, + 'plain': { + 'format': ' '.join([ + '%(asctime)s', + '%(levelname)-8s', + '%(name)s:', + '%(message)s', + ]) + }, + }, + 'handlers': { + 'console': { + 'class': 'logging.StreamHandler', + 'filters': [], + 'stream': 'ext://sys.stdout', + } + }, + 'root': { + 'level': 'INFO', + 'handlers': ['console'] + }, +} +"""Template used to generate configurations. + +You may modify this template as you see fit. The next call to +:func:`get_service_configuration` or :func:`get_cli_configuration` +will reflect modifications. + +""" + + +def get_service_configuration(**kwargs): + """Retrieve configuration suitable for a service. + + :param bool force_debug: should the root log level be + ``logging.DEBUG``? + :param str force_formatter: optional formatter to use + + The default configuration for a "service" is to emit lines + as minimized JSON objects and to only emit records at the + info, warning, and error levels. If the `force_debug` + parameter is specified and *truthy*, then debug-level records + are also emitted. + + :returns: :class:`dict` instance suitable for passing to + :func:`logging.config.dictConfig` + :raises: :exc:`ValueError` if either the ``force_formatter`` or + :envvar:`LOG_FORMAT` refers to an unknown formatter + + """ + config = copy.deepcopy(CONFIGURATION_DEFAULTS) + config['handlers']['console']['formatter'] = 'json' + _update_configuration(config, **kwargs) + + return config + + +def get_cli_configuration(**kwargs): + """Retrieve configuration suitable for a command-line application. + + :param bool force_debug: should the root log level be + ``logging.DEBUG``? + :param str force_formatter: optional formatter to use + + The default configuration for a "command-line applicatoin" is + to emit human-readable log lines and to only emit records at the + info, warning, and error levels. If the `force_debug` + parameter is specified and *truthy*, then debug-level records + are also emitted. + + :returns: :class:`dict` instance suitable for passing to + :func:`logging.config.dictConfig` + :raises: :exc:`ValueError` if either the ``force_formatter`` or + :envvar:`LOG_FORMAT` refers to an unknown formatter + + """ + config = copy.deepcopy(CONFIGURATION_DEFAULTS) + config['handlers']['console']['formatter'] = 'plain' + _update_configuration(config, **kwargs) + + return config + + +def _update_configuration(config, **kwargs): + """Update the configuration based on the environment.""" + debug = kwargs.get('force_debug', False) + if not debug: + try: + debug = utils.parse_boolean(os.environ.get('DEBUG', None)) + except ValueError: + pass # ignored since we don't "own" $DEBUG + + if debug: + config['root']['level'] = 'DEBUG' + + selected_format = kwargs.get('force_format', + os.environ.get('LOG_FORMAT', None)) + if selected_format: + if selected_format in config['formatters']: + config['handlers']['console']['formatter'] = selected_format + else: + raise ValueError( + 'invalid LOG_FORMAT value %r is not in %r' % + (selected_format, list(config['formatters'].keys()))) diff --git a/jsonscribe/utils.py b/jsonscribe/utils.py index 46b9349..c4782e0 100644 --- a/jsonscribe/utils.py +++ b/jsonscribe/utils.py @@ -42,3 +42,31 @@ def utcnow(): """ return datetime.datetime.now(tz=utc) + + +def parse_boolean(s): + """Parse a string as a boolean value. + + :returns: boolean value that `s` matches + :raises: :exc:`ValueError` if `s` does not match a known value + + Acceptable values are 1, y, yes, t, or true for *truthiness* and + 0, n, no, f, or false for *falsiness*. + + """ + if isinstance(s, (int, float)): + return bool(s) + if s is None: + return False + + try: + value = s.strip().lower() + except AttributeError: + pass # unexpected type, raise a ValueError + else: + if value in ('0', 'n', 'no', 'f', 'false'): + return False + if value in ('1', 'y', 'yes', 't', 'true'): + return True + + raise ValueError('cannot determine Boolean value: %r' % (s, )) diff --git a/setup.py b/setup.py index 24f0c54..a7824d2 100755 --- a/setup.py +++ b/setup.py @@ -20,6 +20,7 @@ "Sphinx==1.8.5; python_version < '3'", "Sphinx==4.0.1; python_version >= '3.7'", 'readme-renderer==21.0', + 'sphinx-rtd-theme==1.0.0', 'wheel==0.36.2', 'yapf==0.22.0', ], @@ -37,5 +38,6 @@ 'Programming Language :: Python :: 3.7', 'Programming Language :: Python :: 3.8', 'Programming Language :: Python :: 3.9', + 'Programming Language :: Python :: 3.10', ], ) diff --git a/tests/test_config.py b/tests/test_config.py new file mode 100644 index 0000000..06f573f --- /dev/null +++ b/tests/test_config.py @@ -0,0 +1,96 @@ +import logging +import os +import uuid + +try: + import unittest2 as unittest +except ImportError: + import unittest + +import jsonscribe.config + + +class ConfigurationTestMixin(object): + default_format = 'UNSET' + + def setUp(self): + super(ConfigurationTestMixin, self).setUp() + self._env_vars = { + 'DEBUG': os.environ.pop('DEBUG', None), + 'LOG_FORMAT': os.environ.pop('LOG_FORMAT', None), + } + + def tearDown(self): + for name, value in self._env_vars.items(): + os.environ.pop(name, None) + if value is not None: + os.environ[name] = value + + def get_configuration(self, **kwargs): + raise NotImplementedError() + + def test_config_defaults(self): + config = self.get_configuration() + self.assertEqual(self.default_format, + config['handlers']['console']['formatter']) + self.assertEqual( + jsonscribe.config.CONFIGURATION_DEFAULTS['root']['level'], + config['root']['level']) + + def test_that_debug_envvar_overrides_log_level(self): + os.environ['DEBUG'] = '1' + config = self.get_configuration() + self.assertEqual( + logging.getLevelName(logging.DEBUG), config['root']['level']) + + def test_that_force_debug_overrides_everything(self): + os.environ['DEBUG'] = '0' + config = self.get_configuration(force_debug=True) + self.assertEqual( + logging.getLevelName(logging.DEBUG), config['root']['level']) + + def test_that_unexpected_debug_value_is_ignored(self): + os.environ['DEBUG'] = 'not-a-boolean-value' + config = self.get_configuration() + self.assertEqual( + jsonscribe.config.CONFIGURATION_DEFAULTS['root']['level'], + config['root']['level']) + + def test_that_log_format_envvar_overrides_format(self): + fmts = set(jsonscribe.config.CONFIGURATION_DEFAULTS['formatters']) + fmts.discard(self.default_format) + force_format = next(iter(fmts)) + + os.environ['LOG_FORMAT'] = force_format + config = self.get_configuration() + self.assertEqual(force_format, + config['handlers']['console']['formatter']) + + def test_that_force_log_format_overrides_everything(self): + fmts = set(jsonscribe.config.CONFIGURATION_DEFAULTS['formatters']) + fmts.discard(self.default_format) + force_format = next(iter(fmts)) + + os.environ['LOG_FORMAT'] = 'not-used-and-would-fail' + config = self.get_configuration(force_format=force_format) + self.assertEqual(force_format, + config['handlers']['console']['formatter']) + + def test_that_unknown_log_format_fails(self): + os.environ['LOG_FORMAT'] = str(uuid.uuid4()) + with self.assertRaises(ValueError): + self.get_configuration() + + +class ServiceConfigurationTests(ConfigurationTestMixin, unittest.TestCase): + default_format = 'json' + + def get_configuration(self, **kwargs): + return jsonscribe.get_service_configuration(**kwargs) + + +class CLIConfigurationTests(ConfigurationTestMixin, unittest.TestCase): + default_format = 'plain' + + def get_configuration(self, **kwargs): + return jsonscribe.get_cli_configuration(**kwargs) diff --git a/tests/test_utils.py b/tests/test_utils.py new file mode 100644 index 0000000..7d4d3f6 --- /dev/null +++ b/tests/test_utils.py @@ -0,0 +1,50 @@ +import uuid + +try: + import unittest2 as unittest +except ImportError: + import unittest + +from jsonscribe import utils + + +class ParseBooleanTests(unittest.TestCase): + def assert_parsed_as_false(self, expr): + self.assertIs( + utils.parse_boolean(expr), False, + repr(expr) + ' not parsed as false') + + def assert_parsed_as_true(self, expr): + self.assertIs( + utils.parse_boolean(expr), True, + repr(expr) + ' not parsed as true') + + def test_falsy_values(self): + self.assert_parsed_as_false(None) + for value in ('0', 'n', 'no', 'f', 'false'): + self.assert_parsed_as_false(value.lower()) + self.assert_parsed_as_false(value.upper()) + self.assert_parsed_as_false(value.title()) + self.assert_parsed_as_false(' ' + value + '\t') + + def test_truthy_values(self): + for value in ('1', 'y', 'yes', 't', 'true'): + self.assert_parsed_as_true(value.lower()) + self.assert_parsed_as_true(value.upper()) + self.assert_parsed_as_true(value.title()) + self.assert_parsed_as_true(' ' + value + '\t') + + def test_that_unexpected_values_raises(self): + for unexpected in (str(uuid.uuid4()), dict(), list()): + with self.assertRaises(ValueError) as context: + utils.parse_boolean(unexpected) + self.assertEqual( + 'cannot determine Boolean value: ' + repr(unexpected), + str(context.exception)) + + def test_booleans_and_integers(self): + for value in (1, 10, True, 1.0): + self.assert_parsed_as_true(value) + + for value in (0, False, 0.0, None): + self.assert_parsed_as_false(value) diff --git a/tox.ini b/tox.ini index 1a09af5..63dfbb3 100644 --- a/tox.ini +++ b/tox.ini @@ -1,5 +1,5 @@ [tox] -envlist = lint,py27,py37,py39 +envlist = lint,py27,py37,py39,py310 toxworkdir = ./build/tox [testenv]