+
+ def process(self, msg, kwargs):
+ return f'{msg}{self.extra.get("suffix", "")}', kwargs
+
+ @staticmethod
+ def wrap_logger(suffix: str, logger: logging.Logger) -> logging.LoggerAdapter:
+ """Helper method around the creation of a LoggerAdapter that appends
+ a given string to every log message produced.
+
+ Args:
+ suffix: the message to prepend to every log message.
+ logger: the logger whose messages to modify.
+
+ Returns:
+ A new logger wrapping the old one with the given behavior.
+ The old logger will continue to behave as usual; simply drop
+ the reference to this wrapper when it's no longer needed.
+ """
+ assert suffix
+ return AppendingLogAdapter(logger, {"suffix": suffix})
+
+
+class LoggingContext(contextlib.ContextDecorator):
+ def __init__(
+ self,
+ logger: logging.Logger,
+ *,
+ level: Optional[int] = None,
+ handlers: Optional[List[logging.Handler]] = None,
+ prefix: Optional[str] = None,
+ suffix: Optional[str] = None,
+ ):
+ """This is a logging context that can be used to temporarily change the
+ way we are logging within its scope. Logging changes may include:
+
+ - Changing the logging level (e.g. from INFO to DEBUG)
+ - Adding a prefix or suffix to every log message produced
+ - Adding temporary Handlers to direct the logging output elsewhere
+
+ Setup for doctest / examples. This will normally be taken care of
+ by code in :meth:`initialize_logging` so you don't have to worry
+ about it.
+
+ >>> logging_format = "%(prefix)s%(message)s%(suffix)s"
+ >>> logger = logging.getLogger(__name__ + ".LoggingContext")
+ >>> logger.setLevel(logging.INFO)
+ >>> handler = logging.StreamHandler(sys.stdout)
+ >>> handler.setFormatter(
+ ... MillisecondAwareFormatter(
+ ... fmt=logging_format,
+ ... datefmt='',
+ ... )
+ ... )
+ >>> logger.addHandler(handler)
+ >>> logger.addFilter(PrefixAddingFilter(None))
+ >>> logger.addFilter(SuffixAddingFilter(None))
+
+ First, this logger should be currently be configured to send
+ INFO+ messages to sys.stdout. Let's see it in action:
+
+ >>> logger.info("Hello world!")
+ Hello world!
+ >>> logger.debug("You should not see this")
+
+ The first example is to simply change the level of the logger.
+ Here we temporarily change it to DEBUG within the body of the
+ :class:`LoggingContext`:
+
+ >>> with LoggingContext(logger, level=logging.DEBUG):
+ ... logger.debug("You should see this now")
+ ... logger.info("Of course you should still see this too")
+ You should see this now
+ Of course you should still see this too
+
+ >>> logger.debug("Outside of the context we are at INFO again")
+ >>> logger.debug("(which is why you don't see these)")
+ >>> logger.info("But you should see this at INFO level")
+ But you should see this at INFO level
+
+ The prefix and suffix argument prepend or append a message to
+ all log output. To do this, you need %(prefix)s and
+ %(suffix)s placeholders in your logger format string
+ indicating where to insert the data. This is useful, for
+ example, to add an active request identifier to the set of log
+ messages produced while processing it.
+
+ >>> logger.info("About to work on a new request")
+ About to work on a new request
+
+ >>> with LoggingContext(logger, prefix='10.0.0.13> '):
+ ... logger.info("Working on it now")
+ 10.0.0.13> Working on it now
+
+ >>> logger.info("Done with that request")
+ Done with that request
+
+ LoggingContext can also be used to add temporary handler(s).
+ This code temporarily uses two stdout handlers to double the
+ output for testing purporses but you could also temporarily,
+ e.g., add a RotatingFileHandler or SysLogHandler etc...
+
+ >>> with LoggingContext(logger, handlers=[logging.StreamHandler(sys.stdout)]):
+ ... logger.info("TEST")
+ TEST
+ TEST
+
+ Once leaving the context, logger's behavior is restored. In
+ this case, the extra handler is removed so output will not
+ longer be doubled.
+
+ >>> logger.info("OUTSIDE")
+ OUTSIDE
+
+ LoggingContext can also be used as a decorator if that is more
+ convenient:
+
+ >>> @LoggingContext(logger, level=logging.DEBUG)
+ ... def log_stuff(logger):
+ ... logger.debug("But inside, the decorator has changed us to DEBUG")
+
+ >>> logger.debug("Outside, we're at INFO level and you don't see this")
+ >>> log_stuff(logger)
+ But inside, the decorator has changed us to DEBUG
+ >>> logger.debug("And, of course, out here we're still at INFO afterwards")
+
+ Args:
+ logger: the logger on which to operate
+ level: the new level to set for the duration of the context
+ handlers: additional handlers to add for the duration of the context
+ prefix: the prefix string to set for the duration of the context
+ suffix: the suffix string to set for the duration of the context
+
+ Returns:
+ The modified logger.
+
+ """
+ self.logger = logger
+ self.level = level
+ self.old_level: Optional[int] = None
+ self.handlers = handlers
+ if prefix:
+ self.prefix: Optional[logging.Filter] = PrefixAddingFilter(prefix, True)
+ else:
+ self.prefix = None
+ if suffix:
+ self.suffix: Optional[logging.Filter] = SuffixAddingFilter(suffix, True)
+ else:
+ self.suffix = None
+
+ def __enter__(self) -> Union[logging.Logger, logging.LoggerAdapter]:
+ assert self.logger
+ if self.level:
+ self.old_level = self.logger.level
+ self.logger.setLevel(self.level)
+
+ if self.handlers:
+ for handler in self.handlers:
+ self.logger.addHandler(handler)
+
+ if self.prefix:
+ self.logger.addFilter(self.prefix)
+
+ if self.suffix:
+ self.logger.addFilter(self.suffix)
+ return self.logger
+
+ def __exit__(self, et, ev, tb) -> None:
+ if self.suffix:
+ self.logger.removeFilter(self.suffix)
+
+ if self.prefix:
+ self.logger.removeFilter(self.prefix)
+
+ if self.handlers:
+ for handler in self.handlers:
+ self.logger.removeHandler(handler)
+ handler.close()
+
+ if self.old_level:
+ self.logger.setLevel(self.old_level)
+ return None # propagate exceptions out
+
+
+class MillisecondAwareFormatter(logging.Formatter):
+ """A formatter for adding milliseconds to log messages which, for