logging: add a logging_config trait

* Closes ipython#688
* Allows fine configuration of logging via a `logging.config.dictConfig`.
* Changes the default log level from WARN to DEBUG and the default log
  handler level from undefined to WARN.

traitlets/config/application.py

@@ -9,6 +9,7 @@
 import functools
 import json
 import logging
+from logging.config import dictConfig
 import os
 import pprint
 import re
@@ -64,6 +65,20 @@
 #-----------------------------------------------------------------------------
 
 
+def nested_update(this, that):
+    for key, val in this.items():
+        if isinstance(val, dict):
+            if key in that and isinstance(that[key], dict):
+                nested_update(this[key], that[key])
+        elif key in that:
+            this[key] = that[key]
+
+    for key, val in that.items():
+        if key not in this:
+            this[key] = val
+
+    return this
+
 
 _envvar = os.environ.get('TRAITLETS_APPLICATION_RAISE_CONFIG_FILE_ERROR','')
 if _envvar.lower() in {'1','true'}:
@@ -176,16 +191,6 @@ def _classes_inc_parents(self, classes=None):
                     default_value=logging.WARN,
                     help="Set the log level by value or name.").tag(config=True)
 
-    @observe('log_level')
-    @observe_compat
-    def _log_level_changed(self, change):
-        """Adjust the log level when log_level is set."""
-        new = change.new
-        if isinstance(new, str):
-            new = getattr(logging, new)
-            self.log_level = new
-        self.log.setLevel(new)
-
     _log_formatter_cls = LevelFormatter
 
     log_datefmt = Unicode("%Y-%m-%d %H:%M:%S",
@@ -196,50 +201,137 @@ def _log_level_changed(self, change):
         help="The Logging format template",
     ).tag(config=True)
 
-    @observe('log_datefmt', 'log_format')
-    @observe_compat
-    def _log_format_changed(self, change):
-        """Change the log formatter when log_format is set."""
-        _log_handler = self._get_log_handler()
-        if not _log_handler:
-            warnings.warn(
-                f"No Handler found on {self.log}, setting log_format will have no effect",
-                RuntimeWarning,
-            )
-            return
-        _log_formatter = self._log_formatter_cls(fmt=self.log_format, datefmt=self.log_datefmt)
-        _log_handler.setFormatter(_log_formatter)
-
-    @default('log')
-    def _log_default(self):
-        """Start logging for this application.
+    def get_default_logging_config(self):
+        """Return the base logging configuration.
 
         The default is to log to stderr using a StreamHandler, if no default
-        handler already exists.  The log level starts at logging.WARN, but this
+        handler already exists.  The log handler level starts at logging.WARN, but this
         can be adjusted by setting the ``log_level`` attribute.
+
+        The ``logging_config`` trait is merged into this allowing for finer
+        control of logging.
+
         """
+        # convert log level strings to ints
+        log_level = self.log_level
+        if isinstance(log_level, str):
+            log_level = getattr(logging, log_level)
+
+        config = {
+            'version': 1,
+            'handlers': {
+                'console': {
+                    'class': 'logging.StreamHandler',
+                    'formatter': 'console',
+                    'level': logging.getLevelName(log_level),
+                    'stream': 'ext://sys.stderr',
+                },
+            },
+            'formatters': {
+                'console': {
+                    'class': (
+                        f'{self._log_formatter_cls.__module__}'
+                        f'.{self._log_formatter_cls.__name__}'
+                    ),
+                    'format': self.log_format,
+                    'datefmt': self.log_datefmt,
+                },
+            },
+            'loggers': {
+                self.__class__.__name__: {
+                    'level': 'DEBUG',
+                    'handlers': ['console'],
+                }
+            },
+            'disable_existing_loggers': False,
+        }
+
+        if sys.executable and sys.executable.endswith('pythonw.exe'):
+            # disable logging
+            # (this should really go to a file, but file-logging is only
+            # hooked up in parallel applications)
+            del config['handlers']['loggers']
+
+        return config
+
+    @observe('log_datefmt', 'log_format', 'log_level', 'logging_config')
+    def _observe_logging_change(self, change):
+        self._configure_logging()
+
+    @observe('log', type='default')
+    def _observe_logging_default(self, change):
+        self._configure_logging()
+
+    def _configure_logging(self):
+        config = self.get_default_logging_config()
+        nested_update(config, self.logging_config or {})
+        dictConfig(config)
+
+    @default('log')
+    def _log_default(self):
+        """Start logging for this application."""
         log = logging.getLogger(self.__class__.__name__)
-        log.setLevel(self.log_level)
         log.propagate = False
-        _log = log # copied from Logger.hasHandlers() (new in Python 3.2)
+        _log = log  # copied from Logger.hasHandlers() (new in Python 3.2)
         while _log:
             if _log.handlers:
                 return log
             if not _log.propagate:
                 break
             else:
                 _log = _log.parent
-        if sys.executable and sys.executable.endswith('pythonw.exe'):
-            # this should really go to a file, but file-logging is only
-            # hooked up in parallel applications
-            _log_handler = logging.StreamHandler(open(os.devnull, 'w'))
-        else:
-            _log_handler = logging.StreamHandler()
-        _log_formatter = self._log_formatter_cls(fmt=self.log_format, datefmt=self.log_datefmt)
-        _log_handler.setFormatter(_log_formatter)
-        log.addHandler(_log_handler)
         return log
 
+    logging_config = Dict(
+        help="""
+            Configure additional log handlers.
+
+            The default stderr logs handler is configured by the
+            log_level, log_datefmt and log_format settings.
+
+            This configuration can be used to configure additional handlers
+            (e.g. to output the log to a file) or for finer control over the
+            default handlers.
+
+            If provided this should be a logging configuration dictionary, for
+            more information see:
+            https://docs.python.org/3/library/logging.config.html#logging-config-dictschema
+
+            This dictionary is merged with the base logging configuration which
+            defines the following:
+
+            * A logging formatter intended for interactive use called
+              ``console``.
+            * A logging handler that writes to stderr called
+              ``console`` and uses the formatter called ``console``.
+            * A logger with the name of this application set to ``DEBUG``
+              level.
+
+            This example adds a new handler that writes to a file:
+
+            .. code-block:: python
+
+               c.Application.logging_configuration = {
+                   'handlers': {
+                       'file': {
+                           'class': 'logging.FileHandler',
+                           'level': 'DEBUG',
+                           'filename': '<path/to/file>',
+                       }
+                   },
+                   'loggers': {
+                       '<application-name>': {
+                           'level': 'DEBUG',
+                           # NOTE: if you don't list the default "console"
+                           # handler here then it will be disabled
+                           'handlers': ['console', 'file'],
+                       },
+                   }
+               }
+
+        """,
+    ).tag(config=True)
+
     #: the alias map for configurables
     #: Keys might strings or tuples for additional options; single-letter alias accessed like `-v`.
     #: Values might be like "Class.trait" strings of two-tuples: (Class.trait, help-text).

traitlets/config/configurable.py

@@ -462,6 +462,9 @@ def _get_log_handler(self):
         """Return the default Handler
 
         Returns None if none can be found
+
+        Deprecated, this now returns the first log handler which may or may
+        not be the default one.
         """
         logger = self.log
         if isinstance(logger, logging.LoggerAdapter):

traitlets/config/tests/test_application.py

@@ -762,6 +762,39 @@ def initialize(self, *args, **kwargs):
     assert len(list(app.emit_alias_help())) > 0
 
 
+def test_logging_config(tmp_path):
+    """We should be able to configure additional log handlers."""
+    log_file = tmp_path / 'log_file'
+    app = Application(
+        logging_config={
+            'version': 1,
+            'handlers': {
+                'file': {
+                    'class': 'logging.FileHandler',
+                    'level': 'DEBUG',
+                    'filename': str(log_file),
+                },
+            },
+            'loggers': {
+                'Application': {
+                    'level': 'DEBUG',
+                    'handlers': ['console', 'file'],
+                },
+            }
+        }
+    )
+    # the default "console" handler + our new "file" handler
+    assert len(app.log.handlers) == 2
+
+    # test that log messages get written to the file as configured
+    app.log.info('here')
+    for handler in app.log.handlers:
+        handler.close()
+    with open(log_file, 'r') as log_handle:
+        assert log_handle.read() == 'here\n'
+
+
+
 if __name__ == '__main__':
     # for test_help_output:
     MyApp.launch_instance()