Opened 16 years ago
Closed 14 years ago
#7286 closed enhancement (wontfix)
Improve logging with "filters"
Reported by: | Owned by: | Remy Blank | |
---|---|---|---|
Priority: | normal | Milestone: | |
Component: | general | Version: | 0.12dev |
Severity: | normal | Keywords: | logging |
Cc: | Branch: | ||
Release Notes: | |||
API Changes: | |||
Internal Changes: |
Description
Here's a suggestion for an improvement on trac's logging.
First of all, this change is backwards compatible with the old way trac handled it's logging.
What I suggest is some more explicit module names, ie, full dotted module path, because, web_ui
ain't that explicit, right? trac itself has several of those; and the ability to filter what modules we really want logging from.
This will help debugging parts of trac and also plugin development.
This change introduces a new config variable under [logging]
, log_filters
and it's syntax is:
[logging] log_filters = trac:ERROR, my.plugin:DEBUG
What the above means is:
- all logging messages that come from a module that starts with
trac
(trac.web
,trac.ticket
,tracforge
, etc) and which it's level is higher thatERROR
are logged and shown to the user; - all logging messages that come from a module that starts with
my.plugin
and which it's level is higher thanDEBUG
are also logged. - all other messages that do not match the above "filters" and which their logging level is higher than what's defined on
log_level
will be shown to the user.
This will also simplify logging for plugin' development. Currently if our class is inheriting from Component
we have access to logging on self.log
. If our class is not inheriting from Component
we have to pass env
and access logging from env.log
. What this change introduces is the ability to do, from anywhere:
import logging log = logging.getLogger(__name__)
We're now able to log just by calling log
.
There's only one catch on the above code. At least the root logger must be configured to be able to log, ie, adding the above code to genshi/__init__.py
won't work because genshi is called prior to the logging has been setup, but that's it.
Note that regarding trac, there won't be any issues because, environment is the first thing being initialized and it calls the function to setup logging at an early stage.
Now you ask, why did he talked about genshi!?
Well, with this change, and how logging is configured, we can access logging from trac, it's plugins and packages trac uses, like genshi.
Hope the code is good enough.
Attachments (10)
Change History (29)
by , 16 years ago
Attachment: | enhanced_logging.patch added |
---|
comment:1 by , 16 years ago
comment:2 by , 16 years ago
The correct patch I just added, keeps the main logger object as it was, we won't be able to get logging from other packages, like the example I posted for genshi, but, it will work correctly for multiple environments running in a single interpreter.
comment:3 by , 16 years ago
This last patch is the one to consider, please anyone with ATTACHMENT_DELETE
, could you delete the corrected_enhanced_logging*.patch
patches except corrected_enhanced_logging.5.patch
.
This introduces a performance enhancement as per suggestion of coderanger
plus an addition to filter matching; trac:DEBUG
will now match for modules trac
, trac.web
, trac.whatever
but not tracforge
like it previously did.
by , 16 years ago
Attachment: | corrected_enhanced_logging.8.patch added |
---|
Removed extreme copyright on my behalf :)
by , 16 years ago
Attachment: | corrected_enhanced_logging.patch added |
---|
by , 16 years ago
Attachment: | corrected_enhanced_logging.2.patch added |
---|
comment:4 by , 16 years ago
With corrected_enhanced_logging.2.patch
fixed dynamic reloading not removing _trac_handler
correctly.
Fixed the filter implementation, if it does not match our criterea, let it log. Log warnings to user for wrong log levels.
by , 16 years ago
Attachment: | corrected_enhanced_logging.3.patch added |
---|
comment:5 by , 16 years ago
3rd version of the patch is the same as the 2nd plus corrections on classes which inherit from Component
yet, still log to self.env.log
meaning that they will show up as logging from trac.env
and not trac.mimeview.php
for example.
I also suggest that classes that do not inherit from Component
, yet are passed an env, get their own self.log
as, for example:
self.log = logging.getLogger("%s.%s" % (env.path, __name__))
The above would be applied for example on trac.web.session
which logs to env.log
apearing as trac.env
and not as a more suggestible name trac.web.session
.
by , 16 years ago
Attachment: | all-the-way_enhanced_logging.patch added |
---|
comment:6 by , 16 years ago
This last patch goes all the way, ie, no more calling env.log
even for classes that do not subclass Component
or functions which get passed an env. This will mean that all modules that log will have the correct full dotted module path as %(module)s
. For example, trac.mimeview.php
will be what's shown as %(module)s
when logging from there. Useful logging, from the useful place, with useful info.
With this patch, all tests pass, including functional, except "Admin create milestone with a space" which also fails on pristine trac [7184], so it's not a fail introduced by my patch.
As a note, for classes that do not subclass Component
or functions which get passed an env, to get the correct logger, simply use:
env.get_logger(__name__)
ie, one of:
self.log = env.get_logger(__name__) self.log = self.env.get_logger(__name__)
follow-up: 8 comment:7 by , 16 years ago
Milestone: | 0.13 → 0.12 |
---|
Any legacy systems that call env.log
directly will show up against trac.env
. I wonder if there is a decent way to fix this (and issue a deprecation warning)?
Also retargeting to 0.12 since the patch looks very good to me.
comment:8 by , 16 years ago
Replying to nkantrowitz:
Any legacy systems that call
env.log
directly will show up againsttrac.env
. I wonder if there is a decent way to fix this (and issue a deprecation warning)?
I'll try to see if we can do this cleanly.
Also retargeting to 0.12 since the patch looks very good to me.
Which of the versions of the patch? The regular patch or the all-the-way?
by , 16 years ago
Attachment: | all-the-way_enhanced_logging.2.patch added |
---|
This one also issues some warnings of bad env.log
deprecated usage.
comment:9 by , 16 years ago
Well, now the patch also issues some warnings through self.log
regarding some bad env.log
explaining how to port the old code.
The question left is, should we use the warnings.warn
instead?
by , 16 years ago
Attachment: | all-the-way_enhanced_logging.3.patch added |
---|
Removed a testing log line
by , 16 years ago
Attachment: | all-the-way_enhanced_logging.4.patch added |
---|
comment:11 by , 16 years ago
Interesting patch. Seems OK to target it to 0.12.
Did you measure any speed impact when no filters are defined?
comment:13 by , 15 years ago
Milestone: | 0.12 → 2.0 |
---|
Eventually at some later point.
What would be nice is to separate the s/self.env.log/self.log
fixes from the logging filter enhancement. A patch for the former will certainly get applied sooner.
comment:14 by , 15 years ago
Well, this work is complete and working for me. You decide if you want to apply it in 2.0, or better, re-do it since code will change. Actually, the latest patch is 8 months old, it probably has already changed enough for the patch to fail to apply. (No heart broken)
comment:16 by , 14 years ago
Milestone: | triaging → 0.13 |
---|---|
Owner: | changed from | to
comment:17 by , 14 years ago
Remy, I see you picked this up a while back. Do you still think we need this?
The parts in the patch doing s/self.env.log/self.log/
are good, though I suspect most of it is already done by now. The filter mechanism itself seems overkill to me, in retrospect. If you're debugging something, you can just live with the increased log size during the time you've enable DEBUG level, and you can easily search (or grep) for the lines you're interested in.
comment:18 by , 14 years ago
It does feel overkill, you're right. I'll go through the self.env.log -> self.log
changes and apply the missing ones, and then… close or unscheduled?
comment:19 by , 14 years ago
Milestone: | 0.13 |
---|---|
Resolution: | → wontfix |
Status: | new → closed |
Cleanup done in [10554]. As for the rest, the increase in complexity feels too high for the added benefit.
First glitch on the proposed change, this will for if running a trac env for a single interpreter. If running
tracd -e
which handles multiple environments the above won't work that great, the logging config from one env wins over the other. dam….