5

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

2 Answers 2

2

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()).

Sign up to request clarification or add additional context in comments.

3 Comments

Can you provide an example please?
Add ExtraAdder() as a processor to your pre_chain. The example at structlog.org/en/stable/… does that.
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.
0

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": []}

Comments

Your Answer

By clicking “Post Your Answer”, you agree to our terms of service and acknowledge you have read our privacy policy.

Start asking to get answers

Find the answer to your question by asking.

Ask question

Explore related questions

See similar questions with these tags.