Python add extra fields to structlog-based formatters within logging

Question

I'm trying to add the extra fields of my logs as a key-value while keep using standard logging library along with structlog ProcessorFormatter.

Here is an example:

If we use JsonFormatter, extra fields are added as a key-value to the log.

With python-json-logger:

formatter = jsonlogger.JsonFormatter()
handler = logging.StreamHandler()
handler.setFormatter(formatter)

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

logger = logging.getLogger('testnameloger1')
logger.debug('testmsg2', extra={'extra2': 2})

console:

{"message": "testmsg2", "extra2": 2}

With rendering using structlog-based formatters within logging:

shared_processors = [
    structlog.stdlib.add_logger_name,
    structlog.stdlib.add_log_level,
    structlog.processors.TimeStamper(fmt='iso'),
]

formatter = structlog.stdlib.ProcessorFormatter(
    processor=structlog.processors.JSONRenderer(),
    foreign_pre_chain=shared_processors,
)
handler = logging.StreamHandler()
handler.setFormatter(formatter)

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

logger = logging.getLogger('testnameloger1')
logger.debug('testmsg1', extra={'extra1': 1})

console:

{"event": "testmsg1", "logger": "testnameloger1", "level": "debug", "timestamp": "2020-06-16T13:33:50.881221Z"}

How can I add the extra fields in the log output ?

Logs I would want would be formatted like:

{"event": "testmsg1", "extra1": 1, "logger": "testnameloger1", "level": "debug", "timestamp": "2020-06-16T13:33:50.881221Z"}

Thank you for your insight

hynek · Answer 1 · 2022-01-26T13:15:33.383

1

This works as of structlog 21.5.0!

Check out the structlog.stdlib.ExtraAdder processor that allows you to pick and choose what to add (adding all if added just as ExtraAdder()).

edited Jan 26 '22 at 13:15

answered Jun 25 '20 at 15:31

hynek

3,647
1
18
26

Can you provide an example please? – Omega Mar 28 '23 at 14:32
Add `ExtraAdder()` as a processor to your `pre_chain`. The example at https://www.structlog.org/en/stable/standard-library.html#rendering-using-structlog-based-formatters-within-logging does that. – hynek Mar 30 '23 at 08:25
The example is quite complex and covers a number of other things as well. Would be helpful if the documentation was broken down into smaller parts. – Omega Apr 06 '23 at 09:47

score 0 · Answer 2 · answered Jun 17 '20 at 08:19

Here is an answer. Something else might work better.

LOG_RECORD_ATTRIBUTES = {
    'args', 'asctime', 'created', 'exc_info', 'exc_text', 'filename',
    'funcName', 'levelname', 'levelno', 'lineno', 'message', 'module',
    'msecs', 'msg', 'name', 'pathname', 'process', 'processName',
    'relativeCreated', 'stack_info', 'thread', 'threadName',
}

def extract_stdlib_extra(logger, method_name, event_dict):
    """
    Extract the `extra` key-values from the standard logger record
    and populate the `event_dict` with them.
    """
    record_extra = {k: v for k, v in vars(event_dict['_record']).items()
                    if k not in LOG_RECORD_ATTRIBUTES}
    event_dict.update(record_extra)
    return event_dict

processors = [
    structlog.stdlib.add_logger_name,
    structlog.stdlib.add_log_level,
    structlog.processors.TimeStamper(fmt='iso'),
    extract_stdlib_extra,
]

formatter = structlog.stdlib.ProcessorFormatter(
    processor=structlog.processors.JSONRenderer(),
    foreign_pre_chain=processors,
)
handler = logging.StreamHandler()
handler.setFormatter(formatter)

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

logger = logging.getLogger('testnameloger1')
logger.debug('testmsg1', extra={'t': 1, 'z': {'r': 2}, 'k': []})

Console:

{"event": "testmsg1", "logger": "testnameloger1", "level": "debug", "timestamp": "2020-06-17T08:14:56.465786Z", "t": 1, "z": {"r": 2}, "k": []}

Python add extra fields to structlog-based formatters within logging

2 Answers2

Linked