Is it possible for metadata to be associated with loggers out side of my application?

[jws]

Is it possible for metadata to be associated with loggers out side of my application? For example, 3rd party packages or django's.

I'm seeing logs from django.request which don't have a request_id, ideally all logs associated with a single request could be associated with the same request_id

[jrobichaud]

3rd party packages logs called within the request should work but with appropriate configuration. See below for django.request and other django loggers.

For the metadata to be associated with loggers outside of the application they must fulfill some conditions.

The metadata have to be accessible

tmp_local vs global

The current implementation of django-structlog for the metadata to be bound, the log calls have to be done within structlog's context manager. In this case, inside a request. The code where the binding is done:

django-structlog/django_structlog/middlewares/request.py

Lines 44 to 69 in 105acd5

	with structlog.threadlocal.tmp_bind(logger):
	logger.bind(request_id=request_id)
	if hasattr(request, "user"):
	logger.bind(user_id=request.user.pk)
	if correlation_id:
	logger.bind(correlation_id=correlation_id)
	ip, _ = get_client_ip(request)
	logger.bind(ip=ip)
	signals.bind_extra_request_metadata.send(
	sender=self.__class__, request=request, logger=logger
	)
	logger.info(
	"request_started",
	request=request,
	user_agent=request.META.get("HTTP_USER_AGENT"),
	)
	self._raised_exception = False
	response = self.get_response(request)
	if not self._raised_exception:
	logger.info(
	"request_finished", code=response.status_code, request=request
	)

django.request logger is called after django-structlog's middleware so it does not have access to the context.

It may be possible to add optional functionality in django-structlog to bind globally instead of using the tmp_local. However it has the caveat that every binds have to be unbound or they are permanent. We could implement a global binding middleware and proper documentation.

Threads

It may have limitations if the calls are done in other threads, I never experimented with this.

Configuration

The loggers have to be configured to use structlog.

See: http://www.structlog.org/en/stable/standard-library.html
See maybe this as well: http://www.structlog.org/en/stable/twisted.html

I experimented that each django logger has its particularities (custom formatter, called outside of scope, etc.), I never really took the time to configure any of them completely. But I would like to add how to do it in the documentation.

Conclusion

You will have to experiment yourself for now. I am really looking forward anything that would help improve this library (Pull requests (of feature or documentation), comments, etc.).

I will leave this issue open until there is appropriate documentation about this or any feature that could help resolve this.

[debfx]

This has been working for me to make the django-structlog context variables available to events from the stdlib logging library:

In the LOGGING configuration I added a custom function to the formatter foreign_pre_chain (the other processors are optional for this).

    "formatters": {
        "json_formatter": {
            "()": structlog.stdlib.ProcessorFormatter,
            "processor": structlog.processors.JSONRenderer(),
            "foreign_pre_chain": [
                inject_context_dict,
                structlog.processors.TimeStamper(fmt="iso"),
                structlog.stdlib.add_logger_name,
                structlog.stdlib.add_log_level,
                structlog.stdlib.PositionalArgumentsFormatter(),
            ],
        },
    },

With inject_context_dict() defined as:

def inject_context_dict(test, level, event_dict):
    """
    Add the structlog context dict to log events generated by the stdlib logging library.
    """
    context_class = structlog.get_config().get('context_class')

    if context_class:
        for key, value in context_class().items():
            if key not in event_dict:
                event_dict[key] = value

    return event_dict

With this configuration code like

import logging
logging.getLogger('test').info('foo bar')

generates

{"event": "foo bar", "request_id": "d8974577-7fbf-42e8-9c55-2e65787b2d2b", "user_id": null, "ip": "127.0.0.1", "timestamp": "2020-11-12T07:42:50.164204Z", "logger": "test", "level": "info"}

[jrobichaud]

@debfx I just tested your inject_context_dict and it appears to work pretty well.

Do you mind if I integrate this in the library in a processors module?

[debfx]

Not at all, in fact that would be great 👍

[jrobichaud]

Fixed in 2.1.0. Thanks again @debfx.