{"id":20566,"date":"2018-05-09T09:57:08","date_gmt":"2018-05-09T13:57:08","guid":{"rendered":"https:\/\/www.bloomberg.com\/company\/stories\/guide-logging-python\/"},"modified":"2022-02-16T12:35:51","modified_gmt":"2022-02-16T17:35:51","slug":"guide-logging-python","status":"publish","type":"post","link":"https:\/\/www.bloomberg.com\/company\/stories\/guide-logging-python\/","title":{"rendered":"A guide to logging in Python"},"content":{"rendered":"<div class='bbg-row bbg-bg--white  bbg-row--margin-top-none bbg-row--margin-bottom-none' data-anchor='row-6a0c2d9aa5358'>\n  \n\t\n\t\n\t<div class=\"bbg-row--content\">\n\t\t\n\t\t\t<div class='bbg-column bbg-column--width-8 bbg-column--offset-2'>\n\t<div class='bb-wysiwyg'>\n    \n    <p><em>Get a better understanding of logging in Python with this primer by Senior Software Developer Mario Corchero.<\/em><\/p>\n<p><em>This article was originally\u00a0<a class=\"\" href=\"https:\/\/opensource.com\/article\/17\/9\/python-logging\" target=\"_blank\" rel=\"noopener noreferrer\">published on Opensource.com<\/a><span class=\"Apple-converted-space\">\u00a0<\/span>under the<span class=\"Apple-converted-space\">\u00a0<\/span><a class=\"rte-from-internet\" href=\"https:\/\/creativecommons.org\/licenses\/by-sa\/4.0\/\" target=\"_blank\" rel=\"noopener noreferrer\">CC BY-SA 4.0<\/a><span class=\"Apple-converted-space\">\u00a0<\/span>license.<\/em><\/p>\n\n<\/div>\n<div class=\"bb-separator\" data-color=\"\">\n\t<hr class=\"bb-separator__rule\">\n<\/div>\n\n<\/div>\n\n\n\t\t\n\t<\/div>\n<\/div>\n<div class='bbg-row bbg-bg--white  bbg-row--margin-top-none' data-anchor='row-6a0c2d9aa6924'>\n  \n\t\n\t\n\t<div class=\"bbg-row--content\">\n\t\t\n\t\t\t<div class='bbg-column bbg-column--width-8 bbg-column--offset-2'>\n\t<div class='bb-wysiwyg'>\n    \n    <div class=\"wpb_text_column wpb_content_element \">\n<div class=\"wpb_wrapper\">\n<h2><img loading=\"lazy\" decoding=\"async\" class=\"image-full-size aligncenter\" title=\"A guide to logging in Python\" src=\"https:\/\/opensource.com\/sites\/default\/files\/styles\/image-full-size\/public\/lead-images\/log-wood-logging-road-tree.png?itok=snuAmRJa\" alt=\"A guide to logging in Python\" width=\"520\" height=\"292\" \/><\/h2>\n<h6>Image by:\u00a0<a title=\"Pixabay\" href=\"https:\/\/pixabay.com\/en\/forest-wood-nature-log-trees-2310309\/\" target=\"_blank\" rel=\"noopener noreferrer\">Pixabay<\/a>.\u00a0<a href=\"https:\/\/creativecommons.org\/publicdomain\/zero\/1.0\/deed.en\" target=\"_blank\" rel=\"nofollow noopener noreferrer\">CC0 1.0<\/a>.<\/h6>\n<\/div>\n<\/div>\n<div class=\"wpb_text_column wpb_content_element \">\n<div class=\"wpb_wrapper\"><\/div>\n<\/div>\n<p>There is little worse as a developer than trying to figure out why an application is not working if you don\u2019t know what is going on inside it. Sometimes you can\u2019t even tell whether the system is working as designed at all.<\/p>\n<p>When applications are running in production, they become black boxes that need to be traced and monitored. One of the simplest, yet most important ways to do so is by logging. Logging allows us\u2014at the time we develop our software\u2014to instruct the program to emit information while the system is running that will be useful for us and our sysadmins.<\/p>\n<p>The same way we document code for future developers, we should direct new software to generate adequate logs for developers and sysadmins. Logs are a critical part of the system documentation about an application\u2019s runtime status. When instrumenting your software with logs, think of it like writing documentation for developers and sysadmins who will maintain the system in the future.<\/p>\n<p>Some purists argue that a disciplined developer who uses logging and testing should hardly need an interactive debugger. If we cannot reason about our application during development with verbose logging, it will be even harder to do it when our code is running in production.<\/p>\n<p>This article looks at Python\u2019s\u00a0<strong>logging\u00a0<\/strong>module, its design, and ways to adapt it for more complex use cases. This is not intended as documentation for developers, rather as a guide to show how the Python\u00a0<strong>logging\u00a0<\/strong>module is built and to encourage the curious to delve deeper.<\/p>\n<h2>Why use the logging module?<\/h2>\n<p>A developer might argue, why aren\u2019t simple print statements sufficient? The\u00a0<b>logging<\/b>\u00a0module offers multiple benefits, including:<\/p>\n<ul>\n<li>Multi-threading support<\/li>\n<li>Categorization via different levels of logging<\/li>\n<li>Flexibility and configurability<\/li>\n<li>Separation of the\u00a0<i>how<\/i>\u00a0from the\u00a0<i>what<\/i><\/li>\n<\/ul>\n<p>This last point, the actual separation of the\u00a0<i>what<\/i>\u00a0we log from the\u00a0<i>how<\/i>\u00a0we log enables collaboration between different parts of the software. As an example, it allows the developer of a framework or library to add logs and let the sysadmin or person in charge of the runtime configuration decide what should be logged at a later point.<\/p>\n<h2>What\u2019s in the logging module<\/h2>\n<p>The\u00a0<b>logging<\/b>\u00a0module beautifully separates the responsibility of each of its parts (following the Apache\u00a0<a href=\"https:\/\/logging.apache.org\/log4j\/2.x\/\" target=\"_blank\" rel=\"noopener noreferrer\">Log4j<\/a>\u00a0API\u2019s approach). Let\u2019s look at how a log line travels around the module\u2019s code and explore its different parts.<\/p>\n<h3>Logger<\/h3>\n<p>Loggers are the objects a developer usually interacts with. They are the main APIs that indicate what we want to log.<\/p>\n<p>Given an instance of a\u00a0<b>logger<\/b>, we can categorize and ask for messages to be emitted without worrying about how or where they will be emitted.<\/p>\n<p>For example, when we write\u00a0<code>logger.info(\"Stock was sold at %s\", price)<\/code>\u00a0we have the following model in mind:<\/p>\n<div class=\"media media-element-container media-default media-wysiwyg-align-center\">\n<div id=\"file-369356\" class=\"file file-image file-image-jpeg\">\n<div class=\"content\">\n<p><img loading=\"lazy\" decoding=\"async\" class=\"media-element file-default aligncenter\" title=\"Python logging model diagram 1\" src=\"https:\/\/opensource.com\/sites\/default\/files\/u128651\/1-ikkitaj.jpg\" alt=\"Python logging model diagram 1\" width=\"216\" height=\"173\" \/><\/p>\n<div class=\"field field-name-field-file-image-caption field-type-text-long field-label-hidden\">We request a line and we assume some code is executed in the logger that makes that line appear in the console\/file. But what actually is happening inside?<\/div>\n<\/div>\n<\/div>\n<\/div>\n<h3>Log records<\/h3>\n<p>Log records are packages that the\u00a0<strong>logging\u00a0<\/strong>module uses to pass all required information around. They contain information about the function where the log was requested, the string that was passed, arguments, call stack information, etc.<\/p>\n<p>These are the objects that are being logged. Every time we invoke our loggers, we are creating instances of these objects. But how do objects like these get serialized into a stream? Via handlers!<\/p>\n<h3>Handlers<\/h3>\n<p>Handlers emit the log records into any output. They take log records and handle them in the function of what they were built for.<\/p>\n<p>As an example, a\u00a0<b>FileHandler<\/b>\u00a0will take a log record and append it to a file.<\/p>\n<p>The standard\u00a0<b>logging<\/b>\u00a0module already comes with multiple built-in handlers like:<\/p>\n<ul>\n<li>Multiple file handlers (<strong>TimeRotated<\/strong>,\u00a0<strong>SizeRotated<\/strong>,\u00a0<strong>Watched<\/strong>) that can write to files<\/li>\n<li><strong>StreamHandler<\/strong>\u00a0can target a stream like\u00a0<strong>stdout\u00a0<\/strong>or\u00a0<strong>stderr<\/strong><\/li>\n<li><strong>SMTPHandler<\/strong>\u00a0sends log records via email<\/li>\n<li><strong>SocketHandler<\/strong>\u00a0sends\u00a0<strong>LogRecords\u00a0<\/strong>to a streaming socket<\/li>\n<li><strong>SyslogHandler<\/strong>,\u00a0<strong>NTEventHandler<\/strong>,\u00a0<strong>HTTPHandler<\/strong>,\u00a0<strong>MemoryHandler<\/strong>, and others<\/li>\n<\/ul>\n<p>We have now a model that\u2019s closer to reality:<\/p>\n<div class=\"media media-element-container media-default media-wysiwyg-align-center\">\n<div id=\"file-369361\" class=\"file file-image file-image-jpeg\">\n<div class=\"content\">\n<p><img loading=\"lazy\" decoding=\"async\" class=\"media-element file-default aligncenter\" title=\"Python logging model diagram 2\" src=\"https:\/\/opensource.com\/sites\/default\/files\/u128651\/2-crmvrmf.jpg\" alt=\"Python logging model diagram 2\" width=\"228\" height=\"349\" \/><\/p>\n<div class=\"field field-name-field-file-image-caption field-type-text-long field-label-hidden\">But most handlers work with simple strings (SMTPHandler, FileHandler, etc.), so you may be wondering how those structured\u00a0<strong>LogRecords\u00a0<\/strong>are transformed into easy-to-serialize bytes\u2026<\/div>\n<\/div>\n<\/div>\n<\/div>\n<h3>Formatters<\/h3>\n<p>Let me present the Formatters. Formatters are in charge of serializing the metadata-rich\u00a0<strong>LogRecord\u00a0<\/strong>into a string. There is a default formatter if none is provided.<\/p>\n<p>The generic formatter class provided by the logging library takes a template and style as input. Then placeholders can be declared for all the attributes in a\u00a0<b>LogRecord<\/b>\u00a0object.<\/p>\n<p>As an example:\u00a0<code>'%(asctime)s %(levelname)s %(name)s: %(message)s'<\/code>\u00a0will generate logs like \u201c2017-07-19 15:31:13,942 INFO parent.child: Hello EuroPython.\u201d<\/p>\n<p>Note that the attribute\u00a0<b>message<\/b>\u00a0is the result of interpolating the log\u2019s original template with the arguments provided (e.g., for\u00a0<code>logger.info(\"Hello %s\", \"Laszlo\")<\/code>, the message will be \u201cHello Laszlo\u201d).<\/p>\n<p>All default attributes can be found in\u00a0<a href=\"https:\/\/docs.python.org\/3\/library\/logging.html#logrecord-attributes\" target=\"_blank\" rel=\"noopener noreferrer\">the logging documentation<\/a>.<\/p>\n<p>OK, now that we know about formatters, our model has changed again:<\/p>\n<div class=\"media media-element-container media-default media-wysiwyg-align-center\">\n<div id=\"file-369366\" class=\"file file-image file-image-jpeg\">\n<div class=\"content\">\n<p><img loading=\"lazy\" decoding=\"async\" class=\"media-element file-default aligncenter\" title=\"Python logging model diagram 3\" src=\"https:\/\/opensource.com\/sites\/default\/files\/u128651\/3-olzyr7p.jpg\" alt=\"Python logging model diagram 3\" width=\"506\" height=\"349\" \/><\/p>\n<\/div>\n<\/div>\n<\/div>\n<h3>Filters<\/h3>\n<p>The last objects in our logging toolkit are filters.<\/p>\n<p>Filters allow for finer-grained control of which logs should be emitted. Multiple filters can be attached to both loggers and handlers. For a log to be emitted, all filters should allow the record to pass.<\/p>\n<p>Users can declare their own filters as objects using a\u00a0<b>filter<\/b>\u00a0method that takes a record as input and returns\u00a0<b>True<\/b>\/<b>False<\/b>\u00a0as output.<\/p>\n<p>With this in mind, here is the current logging workflow:<\/p>\n<div class=\"media media-element-container media-default media-wysiwyg-align-center\">\n<div id=\"file-369371\" class=\"file file-image file-image-jpeg\">\n<div class=\"content\">\n<p><img loading=\"lazy\" decoding=\"async\" class=\"media-element file-default aligncenter\" title=\"Python logging model diagram 4\" src=\"https:\/\/opensource.com\/sites\/default\/files\/u128651\/4-nfjk7uc.jpg\" alt=\"Python logging model diagram 4\" width=\"497\" height=\"476\" \/><\/p>\n<\/div>\n<\/div>\n<\/div>\n<h3>The logger hierarchy<\/h3>\n<p>At this point, you might be impressed by the amount of complexity and configuration that the module is hiding so nicely for you, but there is even more to consider: the logger hierarchy.<\/p>\n<p>We can create a logger via\u00a0<code>logging.getLogger(&lt;logger_name&gt;)<\/code>. The string passed as an argument to\u00a0<b>getLogger<\/b>\u00a0can define a hierarchy by separating the elements using dots.<\/p>\n<p>As an example,\u00a0<code>logging.getLogger(\"parent.child\")<\/code>\u00a0will create a logger \u201cchild\u201d with a parent logger named \u201cparent.\u201d Loggers are global objects managed by the\u00a0<strong>logging\u00a0<\/strong>module, so they can be retrieved conveniently anywhere during our project.<\/p>\n<p>Logger instances are also known as channels. The hierarchy allows the developer to define the channels and their hierarchy.<\/p>\n<p>After the log record has been passed to all the handlers within the logger, the parents\u2019 handlers will be called recursively until we reach the top logger (defined as an empty string) or a logger has configured\u00a0<b>propagate = False<\/b>. We can see it in the updated diagram:<\/p>\n<div class=\"media media-element-container media-default media-wysiwyg-align-center\">\n<div id=\"file-369376\" class=\"file file-image file-image-jpeg\">\n<div class=\"content\">\n<p><img loading=\"lazy\" decoding=\"async\" class=\"media-element file-default aligncenter\" title=\"Python logging model diagram 5\" src=\"https:\/\/opensource.com\/sites\/default\/files\/u128651\/5-sjkrpt3.jpg\" alt=\"Python logging model diagram 5\" width=\"495\" height=\"600\" \/><\/p>\n<\/div>\n<\/div>\n<\/div>\n<p>Note that the parent logger is not called, only its handlers. This means that filters and other code in the logger class won\u2019t be executed on the parents. This is a common pitfall when adding filters to loggers.<\/p>\n<h3>Recapping the workflow<\/h3>\n<p>We\u2019ve examined the split in responsibility and how we can fine tune log filtering. But there are two other attributes we haven\u2019t mentioned yet:<\/p>\n<ol>\n<li>Loggers can be disabled, thereby not allowing any record to be emitted from them.<\/li>\n<li>An effective level can be configured in both loggers and handlers.<\/li>\n<\/ol>\n<p>As an example, when a logger has configured a level of\u00a0<b>INFO<\/b>, only\u00a0<b>INFO<\/b>\u00a0levels and above will be passed. The same rule applies to handlers.<\/p>\n<p>With all this in mind, the final flow diagram in the\u00a0<a href=\"https:\/\/docs.python.org\/3\/_images\/logging_flow.png\" target=\"_blank\" rel=\"noopener noreferrer\">logging documentation<\/a>\u00a0looks like this:<\/p>\n<div class=\"media media-element-container media-default media-wysiwyg-align-center\">\n<div id=\"file-369381\" class=\"file file-image file-image-jpeg\">\n<div class=\"content\">\n<p><img loading=\"lazy\" decoding=\"async\" class=\"media-element file-default aligncenter\" title=\"Python logging model diagram \" src=\"https:\/\/opensource.com\/sites\/default\/files\/u128651\/6-kd6eiyr.jpg\" alt=\"Python logging model diagram 6\" width=\"484\" height=\"600\" \/><\/p>\n<\/div>\n<\/div>\n<\/div>\n<h2>How to use logging<\/h2>\n<p>Now that we\u2019ve looked at the\u00a0<strong>logging\u00a0<\/strong>module\u2019s parts and design, it\u2019s time to examine how a developer interacts with it. Here is a code example:<\/p>\n<pre>import logging\r\n\r\ndef sample_function(secret_parameter):\r\n    logger = logging.getLogger(__name__)  # __name__=projectA.moduleB\r\n    logger.debug(\"Going to perform magic with '%s'\",  secret_parameter)\r\n    ...\r\n    try:\r\n        result = do_magic(secret_parameter)\r\n    except IndexError:\r\n        logger.exception(\"OMG it happened again, someone please tell Laszlo\")\r\n    except:\r\n        logger.info(\"Unexpected exception\", exc_info=True)\r\n        raise\r\n    else:\r\n        logger.info(\"Magic with '%s' resulted in '%s'\", secret_parameter, result, stack_info=True)\r\n<\/pre>\n<p>This creates a logger using the module\u00a0<b>__name__<\/b>. It will create channels and hierarchies based on the project structure, as Python modules are concatenated with dots.<\/p>\n<p>The logger variable references the logger \u201cmodule,\u201d having \u201cprojectA\u201d as a parent, which has \u201croot\u201d as its parent.<\/p>\n<p>On line 5, we see how to perform calls to emit logs. We can use one of the methods\u00a0<b>debug<\/b>,\u00a0<b>info<\/b>,\u00a0<b>error<\/b>, or\u00a0<b>critical<\/b>\u00a0to log using the appropriate level.<\/p>\n<p>When logging a message, in addition to the template arguments, we can pass keyword arguments with specific meaning. The most interesting are\u00a0<b>exc_info<\/b>\u00a0and\u00a0<b>stack_info<\/b>. These will add information about the current exception and the stack frame, respectively. For convenience, a method\u00a0<b>exception<\/b>\u00a0is available in the logger objects, which is the same as calling\u00a0<b>error<\/b>\u00a0with\u00a0<b>exc_info=True<\/b>.<\/p>\n<p>These are the basics of how to use the logger module. \u0298\u203f\u0298. But it is also worth mentioning some uses that are usually considered bad practices.<\/p>\n<h3>Greedy string formatting<\/h3>\n<p>Using\u00a0<code>logger.info(\"string template {}\".format(argument))<\/code>\u00a0should be avoided whenever possible in favor of\u00a0<code>logger.info(\"string template %s\", argument)<\/code>. This is a better practice, as the actual string interpolation will be used only if the log will be emitted. Not doing so can lead to wasted cycles when we are logging on a level over\u00a0<b>INFO<\/b>, as the interpolation will still occur.<\/p>\n<h3>Capturing and formatting exceptions<\/h3>\n<p>Quite often, we want to log information about the exception in a catch block, and it might feel intuitive to use:<\/p>\n<pre>try:\r\n    ...\r\nexcept Exception as error:\r\n    logger.info(\"Something bad happened: %s\", error)\r\n<\/pre>\n<p>But that code can give us log lines like\u00a0<strong>Something bad happened: \u201csecret_key.\u201d<\/strong>\u00a0This is not that useful. If we use\u00a0<b>exc_info<\/b>\u00a0as illustrated previously, it will produce the following:<\/p>\n<pre>try:\r\n    ...\r\nexcept Exception:\r\n    logger.info(\"Something bad happened\", exc_info=True)\r\n<\/pre>\n<pre>Something bad happened\r\nTraceback (most recent call last):\r\n  File \"sample_project.py\", line 10, in code\r\n    inner_code()\r\n  File \"sample_project.py\", line 6, in inner_code\r\n    x = data[\"secret_key\"]\r\nKeyError: 'secret_key'\r\n<\/pre>\n<p>This not only contains the exact source of the exception, but also the type.<\/p>\n<h2>Configuring our loggers<\/h2>\n<p>It\u2019s easy to instrument our software, and we need to configure the logging stack and specify how those records will be emitted.<\/p>\n<p>There are multiple ways to configure the logging stack.<\/p>\n<h3>BasicConfig<\/h3>\n<p>This is by far the simplest way to configure logging. Just doing\u00a0<code>logging.basicConfig(level=\"INFO\")<\/code>\u00a0sets up a basic\u00a0<b>StreamHandler<\/b>\u00a0that will log everything on the\u00a0<b>INFO<\/b>\u00a0and above levels to the console. There are arguments to customize this basic configuration. Some of them are:<\/p>\n<table border=\"1\" cellspacing=\"1\" cellpadding=\"1\" align=\"center\">\n<tbody>\n<tr>\n<td class=\"rtecenter\"><strong>Format<\/strong><\/td>\n<td class=\"rtecenter\"><strong>Description<\/strong><\/td>\n<td class=\"rtecenter\"><strong>Example<\/strong><\/td>\n<\/tr>\n<tr>\n<td><em>filename<\/em><\/td>\n<td>Specifies that a FileHandler should be created, using the specified filename, rather than a StreamHandler<\/td>\n<td>\/var\/logs\/logs.txt<\/td>\n<\/tr>\n<tr>\n<td><em>format<\/em><\/td>\n<td>Use the specified format string for the handler<\/td>\n<td>\u201c\u2018%(asctime)s %(message)s&#8217;\u201d<\/td>\n<\/tr>\n<tr>\n<td><em>datefmt<\/em><\/td>\n<td>Use the specified date\/time format<\/td>\n<td>\u201c%H:%M:%S\u201d<\/td>\n<\/tr>\n<tr>\n<td><em>level<\/em><\/td>\n<td>Set the root logger level to the specified level<\/td>\n<td>\u201cINFO\u201d<\/td>\n<\/tr>\n<\/tbody>\n<\/table>\n<p>This is a simple and practical way to configure small scripts.<\/p>\n<p>Note,\u00a0<strong>basicConfig<\/strong>\u00a0only works the first time it is called in a runtime. If you have already configured your root logger, calling\u00a0<strong>basicConfig<\/strong>\u00a0will have no effect.<\/p>\n<h3>DictConfig<\/h3>\n<p>The configuration for all elements and how to connect them can be specified as a dictionary. This dictionary should have different sections for loggers, handlers, formatters, and some basic global parameters.<\/p>\n<p>Here\u2019s an example:<\/p>\n<pre>config = {\r\n    'disable_existing_loggers': False,\r\n    'version': 1,\r\n    'formatters': {\r\n        'short': {\r\n            'format': '%(asctime)s %(levelname)s %(name)s: %(message)s'\r\n        },\r\n    },\r\n    'handlers': {\r\n        'console': {\r\n            'level': 'INFO',\r\n            'formatter': 'short',\r\n            'class': 'logging.StreamHandler',\r\n        },\r\n    },\r\n    'loggers': {\r\n        '': {\r\n            'handlers': ['console'],\r\n            'level': 'ERROR',\r\n        },\r\n        'plugins': {\r\n            'handlers': ['console'],\r\n            'level': 'INFO',\r\n            'propagate': False\r\n        }\r\n    },\r\n}\r\nimport logging.config\r\nlogging.config.dictConfig(config)\r\n<\/pre>\n<p>When invoked,\u00a0<b>dictConfig<\/b>\u00a0will disable all existing loggers, unless\u00a0<b>disable_existing_loggers<\/b>\u00a0is set to\u00a0<b>false<\/b>. This is usually desired, as many modules declare a global logger that will be instantiated at import time, before\u00a0<strong>dictConfig\u00a0<\/strong>is called.<\/p>\n<p>You can see the\u00a0<a href=\"https:\/\/docs.python.org\/3\/library\/logging.config.html?#configuration-dictionary%20schema\" target=\"_blank\" rel=\"noopener noreferrer\">schema that can be used for the\u00a0<strong>dictConfig<\/strong>\u00a0method<\/a>. Often, this configuration is stored in a YAML file and configured from there. Many developers often prefer this over using\u00a0<a href=\"https:\/\/docs.python.org\/3\/library\/logging.config.html#logging.config.fileConfig\" target=\"_blank\" rel=\"noopener noreferrer\">fileConfig<\/a>, as it offers better support for customization.<\/p>\n<h2>Extending logging<\/h2>\n<p>Thanks to the way it is designed, it is easy to extend the\u00a0<strong>logging\u00a0<\/strong>module. Let\u2019s see some examples:<\/p>\n<h3>Logging JSON<\/h3>\n<p>If we want, we can log JSON by creating a custom formatter that transforms the log records into a JSON-encoded string:<\/p>\n<pre>import logging\r\nimport logging.config\r\nimport json\r\nATTR_TO_JSON = ['created', 'filename', 'funcName', 'levelname', 'lineno', 'module', 'msecs', 'msg', 'name', 'pathname', 'process', 'processName', 'relativeCreated', 'thread', 'threadName']\r\nclass JsonFormatter:\r\n    def format(self, record):\r\n        obj = {attr: getattr(record, attr)\r\n                  for attr in ATTR_TO_JSON}\r\n        return json.dumps(obj, indent=4)\r\n\r\nhandler = logging.StreamHandler()\r\nhandler.formatter = JsonFormatter()\r\nlogger = logging.getLogger(__name__)\r\nlogger.addHandler(handler)\r\nlogger.error(\"Hello\")\r\n<\/pre>\n<h3>Adding further context<\/h3>\n<p>On the formatters, we can specify any log record attribute.<\/p>\n<p>We can inject attributes in multiple ways. In this example, we\u00a0<strong>abuse\u00a0<\/strong>filters to enrich the records.<\/p>\n<pre>import logging\r\nimport logging.config\r\nGLOBAL_STUFF = 1\r\n\r\nclass ContextFilter(logging.Filter):\r\n    def filter(self, record):\r\n        global GLOBAL_STUFF\r\n        GLOBAL_STUFF += 1\r\n        record.global_data = GLOBAL_STUFF\r\n        return True\r\n\r\nhandler = logging.StreamHandler()\r\nhandler.formatter = logging.Formatter(\"%(global_data)s %(message)s\")\r\nhandler.addFilter(ContextFilter())\r\nlogger = logging.getLogger(__name__)\r\nlogger.addHandler(handler)\r\n\r\nlogger.error(\"Hi1\")\r\nlogger.error(\"Hi2\")\r\n<\/pre>\n<p>This effectively adds an attribute to all the records that go through that logger. The formatter will then include it in the log line.<\/p>\n<p>Note that this impacts all log records in your application, including libraries or other frameworks that you might be using and for which you are emitting logs. It can be used to log things like a unique request ID on all log lines to track requests or to add extra contextual information.<\/p>\n<p>Starting with Python 3.2, you can use\u00a0<strong><a href=\"https:\/\/docs.python.org\/3\/library\/logging.html#logging.setLogRecordFactory\" target=\"_blank\" rel=\"noopener noreferrer\">setLogRecordFactory<\/a><\/strong>\u00a0to capture all log record creation and inject extra information. The\u00a0<a href=\"https:\/\/docs.python.org\/3\/library\/logging.html#logging.Logger.debug\" target=\"_blank\" rel=\"noopener noreferrer\">extra attribute<\/a>\u00a0and the\u00a0<a href=\"https:\/\/docs.python.org\/3\/library\/logging.html#loggeradapter-objects\" target=\"_blank\" rel=\"noopener noreferrer\"><strong>LoggerAdapter<\/strong>\u00a0class<\/a>\u00a0may also be of the interest.<\/p>\n<h3>Buffering logs<\/h3>\n<p>Sometimes we would like to have access to debug logs when an error happens. This is feasible by creating a buffered handler that will log the last debug messages after an error occurs. See the following code as a non-curated example:<\/p>\n<pre>import logging\r\nimport logging.handlers\r\n\r\nclass SmartBufferHandler(logging.handlers.MemoryHandler):\r\n    def __init__(self, num_buffered, *args, **kwargs):\r\n        kwargs[\"capacity\"] = num_buffered + 2  # +2 one for current, one for prepop\r\n        super().__init__(*args, **kwargs)\r\n\r\n    def emit(self, record):\r\n        if len(self.buffer) == self.capacity - 1:\r\n            self.buffer.pop(0)\r\n        super().emit(record)\r\n\r\nhandler = SmartBufferHandler(num_buffered=2, target=logging.StreamHandler(), flushLevel=logging.ERROR)\r\nlogger = logging.getLogger(__name__)\r\nlogger.setLevel(\"DEBUG\")\r\nlogger.addHandler(handler)\r\n\r\nlogger.error(\"Hello1\")\r\nlogger.debug(\"Hello2\")  # This line won't be logged\r\nlogger.debug(\"Hello3\")\r\nlogger.debug(\"Hello4\")\r\nlogger.error(\"Hello5\")  # As error will flush the buffered logs, the two last debugs will be logged\r\n<\/pre>\n<h2>For more information<\/h2>\n<p>This introduction to the logging library\u2019s flexibility and configurability aims to demonstrate the beauty of how its design splits concerns. It also offers a solid foundation for anyone interested in a deeper dive into the\u00a0<a href=\"https:\/\/docs.python.org\/3\/library\/logging.html\" target=\"_blank\" rel=\"noopener noreferrer\">logging documentation<\/a>\u00a0and the\u00a0<a href=\"https:\/\/docs.python.org\/3\/howto\/logging.html\" target=\"_blank\" rel=\"noopener noreferrer\">how-to guide<\/a>. Although this article isn\u2019t a comprehensive guide to Python logging, here are answers to a few frequently asked questions:<\/p>\n<p><em>My library emits a \u201cno logger configured\u201d warning?<\/em><\/p>\n<p>Check\u00a0<a href=\"https:\/\/docs.python-guide.org\/en\/latest\/writing\/logging\/#logging-in-a-library\" target=\"_blank\" rel=\"noopener noreferrer\">how to configure logging in a library<\/a>\u00a0from \u201cThe Hitchhiker\u2019s Guide to Python.\u201d<\/p>\n<p><em>What happens if a logger has no level configured?<\/em><\/p>\n<p>The effective level of the logger will then be defined recursively by its parents.<\/p>\n<p><em>All my logs are in local time. How do I log in UTC?<\/em><\/p>\n<p>Formatters are the answer! You need to set the\u00a0<b>converter<\/b>\u00a0attribute of your formatter to generate UTC times. Use\u00a0<code>converter = time.gmtime<\/code>.<\/p>\n\n<\/div>\n\n\n<\/div>\n\n\n\t\t\n\t<\/div>\n<\/div>\n","protected":false},"excerpt":{"rendered":"<p>Logging is a critical way to understand what&#8217;s going on inside a Python application.<\/p>\n","protected":false},"author":313,"featured_media":19347,"comment_status":"closed","ping_status":"closed","sticky":false,"template":"","format":"standard","meta":{"footnotes":""},"categories":[1466],"tags":[1515,1483,1514,1464,1481],"class_list":["post-20566","post","type-post","status-publish","format-standard","has-post-thumbnail","hentry","category-tech-at-bloomberg","tag-code","tag-coding","tag-logging","tag-open-source","tag-python"],"yoast_head":"<!-- This site is optimized with the Yoast SEO plugin v19.11 - https:\/\/yoast.com\/wordpress\/plugins\/seo\/ -->\n<title>A guide to logging in Python | Bloomberg LP<\/title>\n<meta name=\"description\" content=\"Logging is a critical way to understand what&#039;s going on inside a Python application.\" \/>\n<meta name=\"robots\" content=\"index, follow, max-snippet:-1, max-image-preview:large, max-video-preview:-1\" \/>\n<link rel=\"canonical\" href=\"https:\/\/www.bloomberg.com\/company\/stories\/guide-logging-python\/\" \/>\n<meta property=\"og:locale\" content=\"en_US\" \/>\n<meta property=\"og:type\" content=\"article\" \/>\n<meta property=\"og:title\" content=\"A guide to logging in Python | Bloomberg LP\" \/>\n<meta property=\"og:description\" content=\"Logging is a critical way to understand what&#039;s going on inside a Python application.\" \/>\n<meta property=\"og:url\" content=\"https:\/\/www.bloomberg.com\/company\/stories\/guide-logging-python\/\" \/>\n<meta property=\"og:site_name\" content=\"Bloomberg L.P.\" \/>\n<meta property=\"article:publisher\" content=\"https:\/\/www.facebook.com\/bloomberglp\/\" \/>\n<meta property=\"article:published_time\" content=\"2018-05-09T13:57:08+00:00\" \/>\n<meta property=\"article:modified_time\" content=\"2022-02-16T17:35:51+00:00\" \/>\n<meta property=\"og:image\" content=\"https:\/\/assets.bbhub.io\/company\/sites\/51\/2018\/05\/log-wood-logging-road-tree.png\" \/>\n\t<meta property=\"og:image:width\" content=\"520\" \/>\n\t<meta property=\"og:image:height\" content=\"292\" \/>\n\t<meta property=\"og:image:type\" content=\"image\/png\" \/>\n<meta name=\"author\" content=\"akelber5\" \/>\n<meta name=\"twitter:card\" content=\"summary_large_image\" \/>\n<meta name=\"twitter:image\" content=\"https:\/\/assets.bbhub.io\/company\/sites\/51\/2018\/05\/log-wood-logging-road-tree.png\" \/>\n<meta name=\"twitter:creator\" content=\"@bloomberg\" \/>\n<meta name=\"twitter:site\" content=\"@bloomberg\" \/>\n<meta name=\"twitter:label1\" content=\"Written by\" \/>\n\t<meta name=\"twitter:data1\" content=\"akelber5\" \/>\n\t<meta name=\"twitter:label2\" content=\"Est. reading time\" \/>\n\t<meta name=\"twitter:data2\" content=\"13 minutes\" \/>\n<script type=\"application\/ld+json\" class=\"yoast-schema-graph\">{\"@context\":\"https:\/\/schema.org\",\"@graph\":[{\"@type\":\"WebPage\",\"@id\":\"https:\/\/www.bloomberg.com\/company\/stories\/guide-logging-python\/\",\"url\":\"https:\/\/www.bloomberg.com\/company\/stories\/guide-logging-python\/\",\"name\":\"A guide to logging in Python | Bloomberg LP\",\"isPartOf\":{\"@id\":\"https:\/\/www.bloomberg.com\/company\/#website\"},\"datePublished\":\"2018-05-09T13:57:08+00:00\",\"dateModified\":\"2022-02-16T17:35:51+00:00\",\"author\":{\"@id\":\"https:\/\/www.bloomberg.com\/company\/#\/schema\/person\/09c9e1a38b7f345ce5c0b4bbde1656a6\"},\"description\":\"Logging is a critical way to understand what's going on inside a Python application.\",\"breadcrumb\":{\"@id\":\"https:\/\/www.bloomberg.com\/company\/stories\/guide-logging-python\/#breadcrumb\"},\"inLanguage\":\"en-US\",\"potentialAction\":[{\"@type\":\"ReadAction\",\"target\":[\"https:\/\/www.bloomberg.com\/company\/stories\/guide-logging-python\/\"]}]},{\"@type\":\"BreadcrumbList\",\"@id\":\"https:\/\/www.bloomberg.com\/company\/stories\/guide-logging-python\/#breadcrumb\",\"itemListElement\":[{\"@type\":\"ListItem\",\"position\":\"1\",\"name\":\"Home\",\"item\":\"https:\/\/www.bloomberg.com\/company\/\"},{\"@type\":\"ListItem\",\"position\":\"2\",\"name\":\"A guide to logging in Python\"}]},{\"@type\":\"WebSite\",\"@id\":\"https:\/\/www.bloomberg.com\/company\/#website\",\"url\":\"https:\/\/www.bloomberg.com\/company\/\",\"name\":\"Bloomberg L.P.\",\"description\":\"Bloomberg L.P. is the leader in global business and financial information, enabling customers to make smarter, faster, more informed business decisions.\",\"potentialAction\":[{\"@type\":\"SearchAction\",\"target\":{\"@type\":\"EntryPoint\",\"urlTemplate\":\"https:\/\/www.bloomberg.com\/company\/?s={search_term_string}\"},\"query-input\":\"required name=search_term_string\"}],\"inLanguage\":\"en-US\"},{\"@type\":\"Person\",\"@id\":\"https:\/\/www.bloomberg.com\/company\/#\/schema\/person\/09c9e1a38b7f345ce5c0b4bbde1656a6\",\"name\":\"Bloomberg L.P.\",\"url\":\"https:\/\/www.bloomberg.com\/company\"}]}<\/script>\n<!-- \/ Yoast SEO plugin. -->","yoast_head_json":{"title":"A guide to logging in Python | Bloomberg LP","description":"Logging is a critical way to understand what's going on inside a Python application.","robots":{"index":"index","follow":"follow","max-snippet":"max-snippet:-1","max-image-preview":"max-image-preview:large","max-video-preview":"max-video-preview:-1"},"canonical":"https:\/\/www.bloomberg.com\/company\/stories\/guide-logging-python\/","og_locale":"en_US","og_type":"article","og_title":"A guide to logging in Python | Bloomberg LP","og_description":"Logging is a critical way to understand what's going on inside a Python application.","og_url":"https:\/\/www.bloomberg.com\/company\/stories\/guide-logging-python\/","og_site_name":"Bloomberg L.P.","article_publisher":"https:\/\/www.facebook.com\/bloomberglp\/","article_published_time":"2018-05-09T13:57:08+00:00","article_modified_time":"2022-02-16T17:35:51+00:00","og_image":[{"width":520,"height":292,"url":"https:\/\/assets.bbhub.io\/company\/sites\/51\/2018\/05\/log-wood-logging-road-tree.png","type":"image\/png"}],"author":"akelber5","twitter_card":"summary_large_image","twitter_image":"https:\/\/assets.bbhub.io\/company\/sites\/51\/2018\/05\/log-wood-logging-road-tree.png","twitter_creator":"@bloomberg","twitter_site":"@bloomberg","twitter_misc":{"Written by":"akelber5","Est. reading time":"13 minutes"},"schema":{"@context":"https:\/\/schema.org","@graph":[{"@type":"WebPage","@id":"https:\/\/www.bloomberg.com\/company\/stories\/guide-logging-python\/","url":"https:\/\/www.bloomberg.com\/company\/stories\/guide-logging-python\/","name":"A guide to logging in Python | Bloomberg LP","isPartOf":{"@id":"https:\/\/www.bloomberg.com\/company\/#website"},"datePublished":"2018-05-09T13:57:08+00:00","dateModified":"2022-02-16T17:35:51+00:00","author":{"@id":"https:\/\/www.bloomberg.com\/company\/#\/schema\/person\/09c9e1a38b7f345ce5c0b4bbde1656a6"},"description":"Logging is a critical way to understand what's going on inside a Python application.","breadcrumb":{"@id":"https:\/\/www.bloomberg.com\/company\/stories\/guide-logging-python\/#breadcrumb"},"inLanguage":"en-US","potentialAction":[{"@type":"ReadAction","target":["https:\/\/www.bloomberg.com\/company\/stories\/guide-logging-python\/"]}]},{"@type":"BreadcrumbList","@id":"https:\/\/www.bloomberg.com\/company\/stories\/guide-logging-python\/#breadcrumb","itemListElement":[{"@type":"ListItem","position":"1","name":"Home","item":"https:\/\/www.bloomberg.com\/company\/"},{"@type":"ListItem","position":"2","name":"A guide to logging in Python"}]},{"@type":"WebSite","@id":"https:\/\/www.bloomberg.com\/company\/#website","url":"https:\/\/www.bloomberg.com\/company\/","name":"Bloomberg L.P.","description":"Bloomberg L.P. is the leader in global business and financial information, enabling customers to make smarter, faster, more informed business decisions.","potentialAction":[{"@type":"SearchAction","target":{"@type":"EntryPoint","urlTemplate":"https:\/\/www.bloomberg.com\/company\/?s={search_term_string}"},"query-input":"required name=search_term_string"}],"inLanguage":"en-US"},{"@type":"Person","@id":"https:\/\/www.bloomberg.com\/company\/#\/schema\/person\/09c9e1a38b7f345ce5c0b4bbde1656a6","name":"Bloomberg L.P.","url":"https:\/\/www.bloomberg.com\/company"}]}},"featured_image_rendered":"<img srcset='https:\/\/assets.bbhub.io\/image\/v1\/resize?width=auto&type=webp&url=https:\/\/assets.bbhub.io\/company\/sites\/51\/2018\/05\/log-wood-logging-road-tree.png 520w, https:\/\/assets.bbhub.io\/image\/v1\/resize?width=auto&type=webp&url=https:\/\/assets.bbhub.io\/company\/sites\/51\/2018\/05\/log-wood-logging-road-tree.png 300w, https:\/\/assets.bbhub.io\/image\/v1\/resize?width=auto&type=webp&url=https:\/\/assets.bbhub.io\/company\/sites\/51\/2018\/05\/log-wood-logging-road-tree.png 170w, https:\/\/assets.bbhub.io\/image\/v1\/resize?width=auto&type=webp&url=https:\/\/assets.bbhub.io\/company\/sites\/51\/2018\/05\/log-wood-logging-road-tree.png 140w' src='https:\/\/assets.bbhub.io\/image\/v1\/resize?width=auto&type=webp&url=https:\/\/assets.bbhub.io\/company\/sites\/51\/2018\/05\/log-wood-logging-road-tree.png' alt='Image by: Pixabay. CC0 1.0.' \/>","category_info":{"name":"Tech At Bloomberg","blog_landing_name":"Tech At Bloomberg"},"_links":{"self":[{"href":"https:\/\/www.bloomberg.com\/company\/wp-json\/wp\/v2\/posts\/20566","targetHints":{"allow":["GET"]}}],"collection":[{"href":"https:\/\/www.bloomberg.com\/company\/wp-json\/wp\/v2\/posts"}],"about":[{"href":"https:\/\/www.bloomberg.com\/company\/wp-json\/wp\/v2\/types\/post"}],"author":[{"embeddable":true,"href":"https:\/\/www.bloomberg.com\/company\/wp-json\/wp\/v2\/users\/313"}],"replies":[{"embeddable":true,"href":"https:\/\/www.bloomberg.com\/company\/wp-json\/wp\/v2\/comments?post=20566"}],"version-history":[{"count":3,"href":"https:\/\/www.bloomberg.com\/company\/wp-json\/wp\/v2\/posts\/20566\/revisions"}],"predecessor-version":[{"id":20846,"href":"https:\/\/www.bloomberg.com\/company\/wp-json\/wp\/v2\/posts\/20566\/revisions\/20846"}],"wp:featuredmedia":[{"embeddable":true,"href":"https:\/\/www.bloomberg.com\/company\/wp-json\/wp\/v2\/media\/19347"}],"wp:attachment":[{"href":"https:\/\/www.bloomberg.com\/company\/wp-json\/wp\/v2\/media?parent=20566"}],"wp:term":[{"taxonomy":"category","embeddable":true,"href":"https:\/\/www.bloomberg.com\/company\/wp-json\/wp\/v2\/categories?post=20566"},{"taxonomy":"post_tag","embeddable":true,"href":"https:\/\/www.bloomberg.com\/company\/wp-json\/wp\/v2\/tags?post=20566"}],"curies":[{"name":"wp","href":"https:\/\/api.w.org\/{rel}","templated":true}]}}