Samuel Henrique <samuel...@debian.org> added the comment:

Hello Vinay Sajip,

I would like to kindly ask you to please reconsider and give your thoughts on 
my description of the issue here.

Let me try to work based on your last reply:
> ...has been around since Jan 2008, and it seems that no one in that time has 
> raised this as a must-have

This is a fair statement and it certainly shows that this is not a big enough 
issue for enough people to complain about. I believe it falls into the 
"papercut" category of issues and people just override the "process" method 
when they hit it.

> 1. If you want to pass different kwargs in every time, use a logger.
> 2. If you want to pass particular contextual information in which fits the 
> "extra" parameter approach, use a LoggerAdapter.
> 3. If that doesn't do it for you, subclass LoggerAdapter and implement what 
> you need.

We could improve the logging library by removing the limitation #1 with no 
apparent downsides, so please bear with me for my example below.

> You haven't really explained why you need this to work in this particular 
> way, so I suspect it could be an XY problem.

So Steffen Schuldenzucker already provided an use case, I have one which is 
very similar and hopefully easily recognizable as a common (or at least not 
rare) usage pattern of logging:

As a logging user, I would like to have a set of extra keys in the formatter, 
some required and some optional, such that I can make use of LoggerAdapter to 
set the constant extra values only once, and still pass the dynamic extra 
values on each "log" method.

Pseudo code:
# assume logger is a logger object with a formatter that allows for dynamic 
extra keys (dynamic = optional extra keys)
adapted_logger = logging.LoggerAdapter(logger, extra={"invocation_id": 
"invocation_id_value"})
adapted_logger.info("test", extra={"resource_owner": "resource_owner_value"})

In this example I expect the log entry to contain both extra keys: 
"invocation_id" and "resource_owner". invocation_id is reused in every log 
entry but resource_owner changes based on what's being processed.

For reference, this is an example of a Formatter which allows for dynamic extra 
keys and formats log entries to json serialized strings:

class ExtraFormatter(logging.Formatter):
    """
    Dynamically adds any extra key to a json-like output.
    """

    def format(self, record: logging.LogRecord) -> str:
        default_attrs = vars(
            logging.LogRecord(None, None, None, None, None, None, None)
        ).keys()
        extras = set(record.__dict__.keys()) - set(default_attrs)

        log_items = {"message": "%(message)s"}
        for attr in extras:
            log_items[attr] = f"%({attr})s"
        format_str = json.dumps(log_items)
        self._style._fmt = format_str

        return super().format(record)

The reason I believe this is a papercut type of issue is that I would expect 
the Formatter to control whether or not to show the extra key, not the 
LoggerAdapter. It is counter intuitive to me that the LoggerAdapter would 
silently drop any extra keys provided to the log methods, and I would expect 
that LoggerAdapter would at least not allow for the parameter to be passed then 
(I don't like this alternative either, but it removes the feeling of being 
tricked).

Again, this is a problem that can easily be workaround-ed by overriding the 
"process" method. But there seems to be a very good opportunity to improve the 
Adapter instead and avoid letting other people hit this issue. I'm curious 
about your opinion on any downsides to this change as I couldn't come up with 
anything.

There is also a problem with the current documentation, in which the 
LoggerAdapter doc led me (and other people, when we had to debug this issue) to 
believe the Adapter would not silently drop the extra parameters. The only 
place where this behavior is mentioned is in the logging-cookbook, in the 
following part:
"Of course, if you had passed an ‘extra’ keyword argument in the call to the 
adapter, it will be silently overwritten."

The "Of course" part is a little bit weird cause it implies it's an obvious 
behavior, whereas the sentence just before this one says: "The default 
implementation of this method leaves the message alone, but inserts an ‘extra’ 
key in the keyword argument whose value is the dict-like object passed to the 
constructor.". Note how it uses the word "inserts" instead of "overrides".

So the documentation has to be updated, either to mention this behavior in the 
LoggerAdapter documentation or to remove the part about extra being silently 
overwritten in the cookbook, the only place this is mentioned (if this gets 
changed).

I worked on a patch, with tests, before noticing this issue was open, so I'm 
gonna attach my patch to this message anyway. I also pushed the commit to my 
fork at 
https://github.com/samueloph/cpython/commit/a0c0e68db9adc405d65fd529a7e17c0c026a85af

To summarize, I would like you to consider what's the downside of performing 
such a change and the papercut factor of this issue.

Thank you.

----------
keywords: +patch
nosy: +samueloph
Added file: https://bugs.python.org/file50136/bpo-32732_logger_adapter.patch

_______________________________________
Python tracker <rep...@bugs.python.org>
<https://bugs.python.org/issue32732>
_______________________________________
_______________________________________________
Python-bugs-list mailing list
Unsubscribe: 
https://mail.python.org/mailman/options/python-bugs-list/archive%40mail-archive.com

Reply via email to