[PATCH] Use full module name and component classname in logging calls

[ethan.jucovy@…]

Currently Trac logging output has access to %(module)s. This variable isn't actually a Python module identifier; it's the filename, sans extension, of the source file from which the logging call was issued.

This means that logging calls from trac/ticket/web_ui.py, trac/timeline/web_ui.py and my_random_plugin/web_ui.py will all be logged against the same %(module)s; Trac's default log format will display "Trac[web_ui] …." for all of them.

Likewise, a plugin that puts its code in my_random_plugin/__init__.py and then uses the logging system will display "Trac[init]" in its log calls.

Providing the full Python module string (trac.ticket.web_ui vs trac.timeline.web_ui vs my_random_plugin.web_ui; my_random_plugin for code in an __init__.py) would provide more useful logging information.

Even nicer would be to append the classname of the component that issued the call to self.log, e.g. trac.ticket.web_ui:TicketModule

The attached patch implements a ​logging Filter that walks up the call stack to find a calling Component, and makes that component's module + classname available to the logger as %(component)s.

Because of potential performance implications (which I haven't tried to measure) the filter is only configured if the log format string contains "%(component)s (which it does not by default). So an end user could enable this feature by setting trac.ini's [logging] format to include $(component)s, e.g. log_format = Trac[$(component)s] $(levelname)s: $(message)s

[ethan.jucovy@…]

This is a pretty ugly approach, and I'm not convinced that it's worth it, especially if it's not even going to be on by default. Maybe best to just apply the patch manually if you're in a debugging situation where you need that info.

(I also toyed with plugging in arbitrary logging.Filter implementations so that a Trac administrator could provide additional context info for the format, e.g. values from the request environment — related to #7286 and #9625. That seems much too messy to consider, especially since Environment.setup_log has to happen before components are loaded and initialized.)

[Ryan J Ollos]

Might be a duplicate of #10413. You might want to take a look at the approach in that ticket.

[ethan.jucovy@…]

Replying to rjollos:

Might be a duplicate of #10413. You might want to take a look at the approach in that ticket.

Whoops — yes, it is a duplicate of #10413, sorry.