Python logging in Azure: adding application-wide custom dimensions

Integrating Azure App Insights into Python for logging purposes can be quite tricky, in praticular if you want to add custom properties to the log entries in Azure Log Monitor. This post gives a short outline on this topic.

Personally, I think Python grew so much that it cannot hold up to the PEP-20 statement anymore: »There should be one– and preferably only one –obvious way to do it.« Similar to the Lego bricks above, Python provides you with many logging pieces: adapters, functions, handlers, formatters, etc. And once you realise you want to have your code in production and that you need to adapt your logging approach to your favourite cloud provider, things can get messy. The use case that really got me thinking was running Flask (or Plotly Dash) on Azure App Service. Microsoft suggests to use App Insights with OpenCensus to collect the log information of your Python app.

Looking at basic Lego bricks

How does this work in practice? Actually quite straight forward, until you want to supply extra information as part of the custom_dimensions. Adding extra information to custom_dimensions enables you to quickly filter log entries in Azure Monitor Log Analytics. They use the Kusto query language to query log information. If you supply extra custom_dimensions, you can query them directly (app_name in this case):

traces
| extend appName = tostring(customDimensions.app_name)
| where appName == "myapp"
| limit 50

This will give you 50 entries where the app_name is myapp. To be able to access this information, you need to supply it during the logging call. Before we tackle the custom dimensions, let’s have a look at the basic setup for using OpenCensus in Azure:

import logging
from opencensus.ext.azure.log_exporter import AzureLogHandler

instrumentation_key = os.environ.get(
    "INSTRUMENTATION_KEY", "00000000-0000-0000-0000-000000000000"
)

log_dfmt = '%Y-%m-%d %H:%M:%S'
log_fmt = '%(asctime)s - %(levelname)-8s - %(name)s.%(funcName)s: %(message)s'
formatter = logging.Formatter(log_fmt, log_dfmt)

default_properties = {'app_name': 'myapp'}
# or supply the default_properties as environment variables and add them here

handler = AzureLogHandler(connection_string=f'InstrumentationKey={instrumentation_key}')
handler.setFormatter(formatter)

# get the root logger and add the handler
logging.getLogger().addHandler(handler)

This is more or less what Microsoft also describes in their documentation. Microsoft already allows logging custom_dimensions as part of the extra field in the log call itself:

logger = logging.getLogger(__name__)

extra = {"custom_dimensions": {"app_name": "myapp"}}
logger.warning("take care!", extra=extra)

If you want to log app-wide or default properties, such as the deployment environment, adding this info to every log call is not an option. Luckily you can (mis-)use logging.Filter in Python.

class CustomDimensionsFilter(logging.Filter):
    """Add application-wide properties to AzureLogHandler records"""

    def __init__(self, custom_dimensions=None):
        self.custom_dimensions = custom_dimensions or {}

    def filter(self, record):
        """Adds the default custom_dimensions into the current log record"""
        cdim = self.custom_dimensions.copy()
        cdim.update(getattr(record, 'custom_dimensions', {}))
        record.custom_dimensions = cdim

        return True

This CustomDimensionsFilter adds custom_dimensions to every log record. The properties can still be overwritten by the extra argument in the logging calls themselves. The CustomDimensionsFilter you can supply as filter to the AzureLogHandler:

#...
handler = AzureLogHandler(connection_string=f'InstrumentationKey={instrumentation_key}')
handler.addFilter(CustomDimensionsFilter(default_properties))
logging.getLogger().addHandler(handler)
#...

The reason for (mis-)using filters and not taking a different approach lies in the architecture of Flask. It is hard to manipulate the underlying logging mechanism, in particular when dealing with exceptions. This makes it difficult to use a custom adapter, as advocated in the Python logging cookbook.

With the basics set up, we can put everything together. Let’s assume you have a Flask app that is comprised many different modules. My approach is to initialize the logging system in a separate module and use this module consistently throughout all other modules and also supply it to the Flask app. The Flask documentation suggests to configure the logging system as early as possible:

When you want to configure logging for your project, you should do it as soon as possible when the program starts. If app.logger is accessed before logging is configured, it will add a default handler. If possible, configure logging before creating the application object.

Let’s start with logging.py:

import logging
import os
from logging import getLogger
from opencensus.ext.azure.log_exporter import AzureLogHandler


class CustomDimensionsFilter(logging.Filter):
    """Add application-wide properties to AzureLogHandler records"""

    def __init__(self, custom_dimensions=None):
        self.custom_dimensions = custom_dimensions or {}

    def filter(self, record):
        """Adds the default custom_dimensions into the current log record"""
        cdim = self.custom_dimensions.copy()
        cdim.update(getattr(record, 'custom_dimensions', {}))
        record.custom_dimensions = cdim

        return True


def build_azure_handler():
    instrumentation_key = os.environ.get(
        "INSTRUMENTATION_KEY", "00000000-0000-0000-0000-000000000000"
    )

    log_dfmt = '%Y-%m-%d %H:%M:%S'
    log_fmt = '%(asctime)s - %(levelname)-8s - %(name)s.%(funcName)s: %(message)s'
    formatter = logging.Formatter(log_fmt, log_dfmt)

    default_properties = {'app_name': 'myapp'}
    # or supply the default_properties as environment variables and add them here

    handler = AzureLogHandler(connection_string=f'InstrumentationKey={instrumentation_key}')
    handler.addFilter(CustomDimensionsFilter(default_properties))
    handler.setFormatter(formatter)
    return handler


def init():
    handler = build_azure_handler()
    logging.basicConfig(handlers=[handler])


init()

Now you can import the logging module in other modules.

import myapp.logging

logger = myapp.logging.getLogger(__name__)


def blah():
    logger.info("called")
    # ...

You may have noticed that I use the getLogger from myapp.logging and not from logging directly. Enables easy wrapping of the logging.getLogger method in myapp.logging, e.g. you could add an adapter:

class CustomDimensionsAdapter(logging.LoggerAdapter):
    def __init__(self, custom_dimensions=None):
        self.custom_dimensions = custom_dimensions or {}

    def process(self, msg, kwargs):
        cdim = self.custom_dimensions.copy()

        if 'extra' not in kwargs:
          kwargs['extra'] = {}

        if 'custom_dimensions' in kwargs['extra']:
            cdim.update(kwargs['extra']['custom_dimensions'])

        kwargs['extra']['custom_dimensions'] = cdim
        return msg, kwargs


def getLogger(name):
    logger = logging.getLogger(name)
    # add adapters or change stuff
    return CustomDimensionsAdapter(logger, {'app': 'myapp'})

This construction works fine for standard logging, but injecting the adapter into Flask’s logging mechanism is challenging. Therefore the solution with the CustomDimensionsFilter is in this case more appropriate.

With the CustomDimensionsFilter, logging for Flask happens behind the scenes, there are no changes necessary, the app.logger instance can be used right away:

import myapp.logging

from flask import Flask

app = Flask(__name__)


@app.route("/")
def hello_world():
    app.logger.info("somebody called hello world")
    return "Hello, World!"

Flask will inherit the handler of the root logger, but in case you want to do custom stuff, you can also configure a handler for the wsgi namespace yourself:

import myapp.logging
from flask import Flask

logger = myapp.logging.getLogger("wsgi")
logger.addHandler(myapp.logging.build_azure_handler())

app = Flask(__name__)


@app.route("/")
def hello_world():
    app.logger.info("somebody called hello world")
    return "Hello, World!"

Conclusion

This article should give you an idea on how to tackle application-wide custom dimensions/properties in Azure App Insights/Monitor. This article silently assumes that the Flask app is already in an installable state as suggested by the Flask documentation (if you want to write larger Flask applications). Nowadays I would probably initialize new Flask projects with e.g. Python poetry first, before writing any Flask-related code.

Have fun!