Usage

Setup

`StructuredLogger`

No special setup is needed for StructuredLogger. Just call logstruct.getLogger to obtain it and use it.

All key logging.Logger methods exist in StructuredLogger. For the ones that don’t, use the public StructuredLogger.logger attribute to manage the stdlib logger.

`StructuredFormatter`

In order to format incoming log records as JSON, StructuredFormatter needs to be assigned to the log handler in use. Once this is done, log records will be output as JSON, regardless of where they come from - logging.Logger or StructuredLogger.

logging.basicConfig(level=logging.DEBUG)
logging.root.handlers[0].setFormatter(logstruct.StructuredFormatter())

logging.getLogger("stdlib-logger").info("hello world")

{"time": "...", "logger": "stdlib-logger", "level": "INFO", ..., "message": "hello world"}

StructuredFormatter supports the standard dictConfig method and the legacy fileConfig method of file configuration.

Structured data

StructuredLogger’s logging API is nearly identical to the standard library logging.Logger. The key difference is that additional keyword arguments provided to logging functions are automatically included in structured output.

logger = logstruct.getLogger(__name__)
logger.info("hello", request_id=1234, user="black_knight")

{..., "level": "INFO", ..., "message": "hello", "request_id": 1234, "user": "black_knight"}

This works for all logging levels.

logger.debug("good to know", request_id=1234)
logger.info("doing this and that", request_id=1234)
logger.warning("take a look", request_id=1234)
logger.error("uh-oh", request_id=1234)
logger.critical("abort", request_id=1234)

{..., "level": "DEBUG", ..., "message": "good to know", "request_id": 1234}
{..., "level": "INFO", ..., "message": "doing this and that", "request_id": 1234}
{..., "level": "WARNING", ..., "message": "take a look", "request_id": 1234}
{..., "level": "ERROR", ..., "message": "uh-oh", "request_id": 1234}
{..., "level": "CRITICAL", ..., "message": "abort", "request_id": 1234}

Alternatively, structured data can be passed as a dictionary in the extra parameter:

logger.info("hello", extra={"request_id": 1234, "user": "black_knight"})

{..., "message": "hello", "request_id": 1234, "user": "black_knight"}

Passing data in the extra parameter also works for standard library loggers:

standard_logger = logging.getLogger("stdlib-logger")
standard_logger.info("hello", extra={"request_id": 1234})

{..., "message": "hello", "request_id": 1234}

Exception logging

Similar to logging.Logger, you can include exception information using the exc_info parameter:

logger.error("uh-oh", exc_info=ValueError("wrong value"), request_id=1234)

{..., "message": "uh-oh", "exc_text": "ValueError: wrong value", "request_id": 1234}

The currently handled exception is automatically captured if exc_info is true or if logger.exception is called.

try:
    x = 1 / 0
except ZeroDivisionError:
    logger.debug("debug", exc_info=True, request_id=1234)
    logger.exception("error", request_id=1234)

{..., "level": "DEBUG",... "message": "debug", "exc_text": "Traceback ...ZeroDivisionError: division by zero", "request_id": 1234}
{..., "level": "ERROR",... "message": "error", "exc_text": "Traceback ...ZeroDivisionError: division by zero", "request_id": 1234}

exc_text includes the traceback of the exception relative to the logging call. You can customise exception formatting by subclassing StructuredFormatter and overriding logging.Formatter.formatException, just like you would do it with any other logging.Formatter.

Stack logging

Similar to logging.Logger, you can include stack information using the stack_info parameter:

logger.info("with stack", stack_info=True, stacklevel=0)

{..., "stack_info": "Stack (most recent call last):...", ...}

The stacklevel parameter controls the number of stack frames that are omitted from stack_info, relative to the frame from which the log method is called.

Context variables

Logstruct context variables are meant to contain data relevant to the current operation, like message ID, request path, user ID, job name, job ID, etc. Once set, they are shared by all subsequent logs until they are unset.

Context variables are automatically incorporated in produced structured logs but they can be overridden by keyword args directly passed to log calls. Context variables are implemented with contextvars.Context which makes them local to the current thread, asyncio task, or gevent task. Context variables are automatically inherited by child tasks but not by spawned threads.

You can use context_scope to add contextual information to all log records within the scope.

with logstruct.context_scope(request_id="1234"):
    logger.info("has context", user="abc")

logger.info("scope ended")

{..., "message": "has context", "request_id": "1234", "user": "abc"}
{..., "message": "scope ended"}

Contexts can be nested. Inner scopes shadow data from outer scopes.

with logstruct.context_scope(outer="outer", redefined="outer"):
    with logstruct.context_scope(inner="inner", redefined="inner"):
        logger.info("inner context")

{..., "message": "inner context", "inner": "inner", "redefined": "inner", "outer": "outer"}

You can modify the current context with add_context, remove_context, or clear_scope.

logstruct.add_context(request_id="1234", user="abc")
logger.info("has context")

logstruct.remove_context("user")
logger.info("only request_id")

logstruct.clear_scope()
logger.info("no context")

{..., "message": "has context", "request_id": "1234", "user": "abc"}
{..., "message": "only request_id", "request_id": "1234"}
{..., "message": "no context"}

Modifications only apply to the current scope. Once the scope ends, all modifications are lost.

with logstruct.context_scope(request_id="1234"):
  logstruct.add_context(user="abc")
  logger.info("modified")

logger.info("unmodified")

{..., "message": "modified", "request_id": "1234", "user": "abc"}
{..., "message": "unmodified"}

Configuration

Logger configuration

There is no configuration specific to StructuredLogger. Since each StructuredLogger is paired with a logging.Logger with the same name, that logger should be configured as in the official docs.

logging.config.fileConfig and logging.config.dictConfig configuration works just like it does in the standard library.

Formatter configuration

A StructuredFormatter is configured using StructuredFormatterConfig.

Logstruct provides two default configs: logstruct.CONFIG_FORMATTED_MESSAGE and logstruct.CONFIG_RAW_MESSAGE, which can be used directly or copied to derive custom configuration.

`StructuredFormatterConfig` attributes
Attribute	Default	Description
`format_message`	`True`	Controls whether log messages should be formatted with positional log call arguments (using `record.getMessage()`) or left unformatted (keeping `record.msg`).
`uses_time`	`True`	Determines if the current time should be assigned to `LogRecord.asctime`.
`log_fields`	`DEFAULT_LOG_FIELDS`	Defines how LogRecord attributes map to output key-value pairs. See Log field configuration below.
`get_context_fn`	`logstruct.get_context`	Function to retrieve context variables that get merged into the output.
`dumps_fn`	`json.dumps` with `default=repr`	Function used to serialise final structured into text for logging.

Log field configuration

The LogField struct allows you to map logging.LogRecord attributes to structured output keys. LogRecord is the piece of log data sent from the logger to the handler to be formatted by its formatter and written out. LogRecord attribute reference can be found in standard library docs.

`LogField` attributes
Attribute	Default?	Description
`LogField.source` (or legacy `log_record_attr`)	required	Source LogRecord attribute name or a callable that receives a LogRecord and returns a string.
`LogField.dest` (or legacy `struct_key`)	required	The output key in the structured log.
`LogField.condition`	`None`	An optional callable to determine if the field should be included. Always included if `None`.

For example, this LogField will try to pick up the taskName attribute from the LogRecord and include it as the "task" key in the produced log. If the attribute is missing, the key won’t be included.

LogField("taskName", "task", bool),

{"task": "Task-1234"}

If the condition is missing, the key will always be included even if the source LogRecord attribute is missing or evaluates to False.

LogField("taskName", "task"),

{"task": null}

Highly customised configuration example

The following example defines completely custom configuration, featuring:

disabling log message formatting
specifying own LogFields
custom serialisation function

The example configures Logstruct in Python - see Using configuration files for config file examples.

#!/usr/bin/env python3
"""Structured logging demo with customisation."""

import json
import logging
from functools import partial

import logstruct
from logstruct import LogField, StructuredFormatter, StructuredFormatterConfig

logging.basicConfig(level=logging.INFO)

custom_json_formatter = StructuredFormatter(
    datefmt="%Y-%m-%d %H:%M:%S",
    structured_formatter_config=StructuredFormatterConfig(
        format_message=False,
        log_fields=[
            LogField("asctime", "ts", bool),
            LogField("name", "name"),
            LogField("levelname", "level"),
            LogField("module", "module"),
            LogField("funcName", "func"),
            LogField("lineno", "line"),
            LogField("message", "event"),
            LogField("exc_text", "exc_text", bool),
            LogField("stack_info", "stack_info", bool),
            LogField("args", "positional_args", bool),
        ],
        # without `default=repr` it's very easy to cause serialisation errors
        dumps_fn=partial(json.dumps, indent=4, default=repr),
    ),
)
logging.root.handlers[0].setFormatter(custom_json_formatter)

log = logstruct.getLogger(__name__)

log.info("An info message")
log.info("An info message with stack info", stack_info=True)
log.info("An info message with data (traditional)", extra={"log": "struct", "unrepresentable": logging})
log.info("An info message with data (kwargs)", log="struct", unrepresentable=logging)

try:
    print(1 / 0)
except Exception:
    log.exception("Division error")

log output

{
    "ts": "2025-03-02 18:25:52",
    "name": "__main__",
    "level": "INFO",
    "module": "demo_custom",
    "func": "<module>",
    "line": 37,
    "event": "An info message"
}
{
    "ts": "2025-03-02 18:25:52",
    "name": "__main__",
    "level": "INFO",
    "module": "demo_custom",
    "func": "<module>",
    "line": 38,
    "event": "An info message with stack info",
    "stack_info": "Stack (most recent call last):\n  File \"/home/docs/checkouts/readthedocs.org/user_builds/logstruct/checkouts/0.2.0/docs/../demo_custom.py\", line 38, in <module>\n    log.info(\"An info message with stack info\", stack_info=True)"
}
{
    "ts": "2025-03-02 18:25:52",
    "name": "__main__",
    "level": "INFO",
    "module": "demo_custom",
    "func": "<module>",
    "line": 39,
    "event": "An info message with data (traditional)",
    "log": "struct",
    "unrepresentable": "<module 'logging' from '/home/docs/.asdf/installs/python/3.12.7/lib/python3.12/logging/__init__.py'>"
}
{
    "ts": "2025-03-02 18:25:52",
    "name": "__main__",
    "level": "INFO",
    "module": "demo_custom",
    "func": "<module>",
    "line": 40,
    "event": "An info message with data (kwargs)",
    "log": "struct",
    "unrepresentable": "<module 'logging' from '/home/docs/.asdf/installs/python/3.12.7/lib/python3.12/logging/__init__.py'>"
}
{
    "ts": "2025-03-02 18:25:52",
    "name": "__main__",
    "level": "ERROR",
    "module": "demo_custom",
    "func": "<module>",
    "line": 45,
    "event": "Division error",
    "exc_text": "Traceback (most recent call last):\n  File \"/home/docs/checkouts/readthedocs.org/user_builds/logstruct/checkouts/0.2.0/docs/../demo_custom.py\", line 43, in <module>\n    print(1 / 0)\n          ~~^~~\nZeroDivisionError: division by zero"
}

Using configuration files

File configuration of StructuredFormatter is fully supported, including configuring LogFields.

Basic `dictConfig`

You can configure logstruct with a data file by loading it and passing it to logging.config.dictConfig.

example_config.yaml

version: 1
disable_existing_loggers: false

handlers:
  stream:
    class: logging.StreamHandler
    formatter: structured
    level: INFO
    stream: ext://sys.stderr
formatters:
  structured:
    class: logstruct.StructuredFormatter
root:
  level: INFO
  handlers: [stream]

config = yaml.safe_load(Path("example_config.yaml").read_text())
logging.config.dictConfig(config)
logger = logstruct.getLogger(__name__)
logger.info("hello", request_id=1234)

{"time": "...", "level": "INFO", ..., "message": "hello", "request_id": 1234}

`StructuredFormatter` config in `dictConfig`

Formatter configuration is available thanks to the () feature in dictConfig, allowing to pass custom parameters to the formatter’s constructor.

example_config.yaml

formatters:
  structured:
    (): logstruct.StructuredFormatter
    structured_formatter_config:
      format_message: False
      uses_time: True

Refer to Advanced dictConfig example for complete code.

Callables in `dictConfig`

Some values, for example StructuredFormatterConfig.dumps_fn, are callables. While it isn’t possible to define functions in config files, config attributes can still reference Python functions. For example, if user_module.submodule.user_func is passed as a value of a callable config field, the user_module.submodule module will be imported and user_func will be retrieved from it.

example_config.yaml

formatters:
  structured:
    (): logstruct.StructuredFormatter
    structured_formatter_config:
      dumps_fn: logstruct.DEFAULT_DUMPS_FN  # This is the default but you can import anything

LogFields in `dictConfig`

It is also possible to configure LogFields via dictConfig.

example_config.yaml

formatters:
  structured:
    (): logstruct.StructuredFormatter
    structured_formatter_config:
      log_fields:
        - source: asctime
          dest: ts
          condition: bool
        - source: levelname
          dest: level
... etc ...

Note

LogField.source can be either a string or a callable and the two are distinguished by the presence of a dot in the value, so:

source: lineno will be the LogRecord.lineno attribute
source: my_module.get_line_no will be the get_line_no function in my_module.

If for whatever reason you want your source callable to be a built-in, you need to spell out the __builtins__ module explicitly, e.g. source: __builtins__.vars

Advanced `dictConfig` example

The following example uses a YAML file to define data passed to logging.config.dictConfig and specify custom StructuredFormatterConfig, including log fields. Callables are referenced from the dumps_fn and a number of condition keys. No Python code is used to specify configuration.

example_config.yaml

version: 1
disable_existing_loggers: false

handlers:
  stream:
    class: logging.StreamHandler
    formatter: structured
    level: INFO
    stream: ext://sys.stderr
formatters:
  structured:
    (): logstruct.StructuredFormatter
    structured_formatter_config:
      format_message: False
      uses_time: True
      log_fields:
        - source: asctime
          dest: ts
          condition: bool
        - source: levelname
          dest: level
        - source: name
          dest: logger
        - source: lineno
          dest: line
        - source: message
          dest: msg
        - source: args
          dest: msg_args
          condition: bool
        - source: exc_text
          dest: exc
          condition: bool
        - source: stack_info
          dest: stack_info
          condition: bool
      dumps_fn: logstruct.DEFAULT_DUMPS_FN  # This is the default but you can import anything
root:
  level: INFO
  handlers: [stream]

config = yaml.safe_load(Path("example_config_advanced.yaml").read_text())
logging.config.dictConfig(config)
logger = logstruct.getLogger(__name__)
logger.info("hello", request_id=1234)

{"ts": "...", "level": "INFO", "logger": "...", "line": ..., "msg": "hello", "request_id": 1234}

Note

Sadly, YAML sucks. It is used here only because Python uses it in its dictConfig documentation.

Legacy `fileConfig` (ini files)

logstruct can be configured with the standard library’s configuration file format and the fileConfig function. Unlike dictConfig, this method doesn’t allow for custom formatter configuration.

example_config.ini

[loggers]
keys=root

[handlers]
keys=stream

[formatters]
keys=structured

[handler_stream]
class=logging.StreamHandler
formatter=structured
level=INFO
stream=ext://sys.stderr

[formatter_structured]
class=logstruct.StructuredFormatter

[logger_root]
level=INFO
handlers = stream

logging.config.fileConfig("example_config.ini", disable_existing_loggers=False)
logger = getLogger(__name__)
logger.info("hello", request_id=1234)

{"time": "...", "level": "INFO", ..., "message": "hello", "request_id": 1234}

Development mode logging

In this demo the DEBUG env var set to a non-empty value makes logs formatted in a developer-friendly way, but unlike the default formatter, will include the extra dictionary, where our log call key-values go.

#!/usr/bin/env python3
"""Structured logging demo - dev-friendly console renderer."""

import logging
import os

import logstruct
from logstruct import (
    StructuredFormatter,
    StructuredFormatterConfig,
    make_friendly_dump_fn,
)

logging.basicConfig(level=logging.DEBUG)
handler = logging.root.handlers[0]

if os.environ.get("DEBUG"):
    handler.formatter = StructuredFormatter(
        structured_formatter_config=StructuredFormatterConfig(
            dumps_fn=make_friendly_dump_fn(
                # Enable colours only if the handler pointed to a teletype.
                colours=isinstance(handler, logging.StreamHandler) and handler.stream.isatty()
            ),
        )
    )
else:
    handler.formatter = StructuredFormatter()

log = logstruct.getLogger(__name__)

log.debug("A debug message")
log.info("An info message")
log.warning("A warning message with stack info", stack_info=True)
log.error("An error message with data (traditional)", extra={"log": "struct", "unrepresentable": logging})
log.critical("A critical message with data (kwargs)", log="struct", unrepresentable=logging)

try:
    print(1 / 0)
except Exception:
    log.exception("Division error")

DEBUG=1

2025-03-02 18:25:53,014 DEBUG    __main__:<module>:31 A debug message
2025-03-02 18:25:53,014 INFO     __main__:<module>:32 An info message
2025-03-02 18:25:53,014 WARNING  __main__:<module>:33 A warning message with stack info
Stack (most recent call last):
  File "/home/docs/checkouts/readthedocs.org/user_builds/logstruct/checkouts/0.2.0/docs/../demo_dev_mode.py", line 33, in <module>
    log.warning("A warning message with stack info", stack_info=True)
2025-03-02 18:25:53,014 ERROR    __main__:<module>:34 An error message with data (traditional) {"log": "struct", "unrepresentable": "<module 'logging' from '/home/docs/.asdf/installs/python/3.12.7/lib/python3.12/logging/__init__.py'>"}
2025-03-02 18:25:53,014 CRITICAL __main__:<module>:35 A critical message with data (kwargs) {"log": "struct", "unrepresentable": "<module 'logging' from '/home/docs/.asdf/installs/python/3.12.7/lib/python3.12/logging/__init__.py'>"}
2025-03-02 18:25:53,014 ERROR    __main__:<module>:40 Division error
Traceback (most recent call last):
  File "/home/docs/checkouts/readthedocs.org/user_builds/logstruct/checkouts/0.2.0/docs/../demo_dev_mode.py", line 38, in <module>
    print(1 / 0)
          ~~^~~
ZeroDivisionError: division by zero

DEBUG not set

{"time": "2025-03-02 18:25:53,064", "logger": "__main__", "level": "DEBUG", "func": "<module>", "line": 31, "message": "A debug message"}
{"time": "2025-03-02 18:25:53,064", "logger": "__main__", "level": "INFO", "func": "<module>", "line": 32, "message": "An info message"}
{"time": "2025-03-02 18:25:53,064", "logger": "__main__", "level": "WARNING", "func": "<module>", "line": 33, "message": "A warning message with stack info", "stack_info": "Stack (most recent call last):\n  File \"/home/docs/checkouts/readthedocs.org/user_builds/logstruct/checkouts/0.2.0/docs/../demo_dev_mode.py\", line 33, in <module>\n    log.warning(\"A warning message with stack info\", stack_info=True)"}
{"time": "2025-03-02 18:25:53,064", "logger": "__main__", "level": "ERROR", "func": "<module>", "line": 34, "message": "An error message with data (traditional)", "log": "struct", "unrepresentable": "<module 'logging' from '/home/docs/.asdf/installs/python/3.12.7/lib/python3.12/logging/__init__.py'>"}
{"time": "2025-03-02 18:25:53,064", "logger": "__main__", "level": "CRITICAL", "func": "<module>", "line": 35, "message": "A critical message with data (kwargs)", "log": "struct", "unrepresentable": "<module 'logging' from '/home/docs/.asdf/installs/python/3.12.7/lib/python3.12/logging/__init__.py'>"}
{"time": "2025-03-02 18:25:53,064", "logger": "__main__", "level": "ERROR", "func": "<module>", "line": 40, "message": "Division error", "exc_text": "Traceback (most recent call last):\n  File \"/home/docs/checkouts/readthedocs.org/user_builds/logstruct/checkouts/0.2.0/docs/../demo_dev_mode.py\", line 38, in <module>\n    print(1 / 0)\n          ~~^~~\nZeroDivisionError: division by zero"}

Usage

Setup

StructuredLogger

StructuredFormatter

Structured data

Exception logging

Stack logging

Context variables

Configuration

Logger configuration

Formatter configuration

Log field configuration

Highly customised configuration example

Using configuration files

Basic dictConfig

StructuredFormatter config in dictConfig

Callables in dictConfig

LogFields in dictConfig

Advanced dictConfig example

Legacy fileConfig (ini files)

Development mode logging

`StructuredLogger`

`StructuredFormatter`

Basic `dictConfig`

`StructuredFormatter` config in `dictConfig`

Callables in `dictConfig`

LogFields in `dictConfig`

Advanced `dictConfig` example

Legacy `fileConfig` (ini files)