Differences between revisions 19 and 20
Revision 19 as of 2009-09-22 16:50:31
Size: 7697
Editor: VinaySajip
Comment:
Revision 20 as of 2010-02-02 22:25:18
Size: 9420
Editor: c-66-31-170-102
Comment:
Deletions are marked like this. Additions are marked like this.
Line 87: Line 87:



== The appropriate roles for args and kwargs in loggerAdapter are ambiguous. ==

I'm finding the paradigms for augmenting log arguments with relevant context info confusing. The docs and general web info are helpful but slim on the topic so far. Adding contextual info via the 'extra' parameter with loggingAdapter(. . . ,extra=myClassObj | extra=my.__dict__ ) is slick for some use cases, not so much for others. It seems that the extra= is set in stone when the loggerAdapter object is instantiated, then passed to the individual LogRecords as needed (true?/false?). Context specific to the location of the log() call is superseded by the context of the loggerAdapter instantiation. Any kwargs['extra'] in the log() calls are overwritten silently. Perhaps that's a feature, and context info specific to the log() call location should be incorporated using log(... args) and having Formatters manage and replace the the actual args? At present, the use of the kw extra is handled by logging in the reverse behavior of most inherited object properties, where lower level objects supercede the higher level class values. Fortunately, the logging mechanisms are so flexible that it's not difficult to use args in place of kwargs (even for class arguments), or to alter the default behavior of logging for the extra kw. Still, it's confusing as is when the use case is not to pass down the context of the logger instantiation to all subsequent log() calls. I have code for both solutions if there is interest. (This comment seems long and detailed relative to the intended context of this page. Is there another place for similar discussion? Also: where to post demo code that is neither patch nor bug?)

This page should cover pros and cons of current stdlib logging package.

Pros

  • Almost every feature you could want from a logging package is there

Cons

I have made sections of each of the points in the original bulleted list to facilitate further discussion. -- VinaySajip

Docs are not complete

According to some people, docs are never complete. Please add below here areas where you think the docs are not complete. Feel free to post patches on bugs.python.org, but even if not, please be specific. It's hard to work from e.g. "the docs need to be clearer." -- VinaySajip

Config files are a little bit hard to comprehend

An alternate configuration mechanism is provided by the ZConfig package (PyPI). (Note ZConfig is not a small package to pull in.)

Another alternative is provided by the config package, which is a single module and easy to incorporate into logging. However, what say people to the question of backward compatibility? -- VinaySajip

If you want to suggest an alternative mechanism which uses ConfigParser, please suggest alternatives to the format. -- VinaySajip

API uses camelCase (goes against PEP8 recommendation and most of the stdlib)

There's no objection on my part to changing the library to use PEP8 naming while retaining camelCase aliases for backward compatibility. Comments on this below here, please: -- VinaySajip

Rather slow considering the large number of function calls performed internally to check which handler to use

Is this a subjective measurement? See Knuth on premature optimisation. While a package for general use like logging can be too slow in some specialised scenarios, can people provide some more objective metrics than "what a lot of function calls!"? See below for (very simple) timing test results. -- VinaySajip

Doesn't have runtime scoping (i.e., log messages handled based on the call stack)

Please give some more details on what you mean here. How exactly would you want to log messages based on the call stack? -- VinaySajip

Difficult to extend log records

LogRecords need to be pickleable to be sent across the wire. You can add arbitrary attributes to LogRecords by using the "extra" keyword parameter to logging calls. Exactly how would you like to extend LogRecords in a way which is difficult at the moment, and why? -- VinaySajip

Difficult to add general context to log messages (e.g., add the request URL to all logging messages during the request)

There's information on this very topic at Adding contextual information to your logging output. Can you provide more details on how the mechanism provided fails to meet your needs? -- VinaySajip

By default it does nothing; basicConfig makes it do something but makes it hard to tweak logging.

How would you want to tweak logging in a way which basicConfig doesn't make easy? Suggest improvements which can be made to basicConfig, I'm receptive. Remember to consider backward compatibility. -- VinaySajip

filters are an abstract class instead of callables

Filter is not an abstract class - it's a concrete class with a reasonable default implementation. Is this really a major design flaw? It would be easy to modify the package to add callables to the filter list, and the system could expect either a Filter instance or a callable. -- VinaySajip

Thread-local handlers aren't easy to setup

Please suggest how you would like these to work, and why you need thread-local handlers? You already have the ability to insert thread-local context information into messages using non-thread-local handlers. -- VinaySajip

Nothing like keywords or tags for doing multi-dimensional categorization or grouping of messages

How many use cases need this? How would you see this being implemented? Buffering of messages is already possible. Talk is cheap, so please describe your use cases in more detail and how you think an "ideal" API for "multi-dimensional categorization" or "grouping" would look. -- VinaySajip

No clear way to introduce HTML-formatted messages (or an HTML formatting option)

You can post messages to web sites, and present messages in HTML format in numerous ways; is this a common use case and would we get common agreement on how this would work (i.e. a specific HTML representation) ? -- VinaySajip

Not fast enough to do pervasive logging in libraries (we've encountered this with Paste/Pylons, where we'd like to put lots of logging in that people could turn on, but it becomes a notable performance hit).

Please clarify - how much of a performance hit is it if logging is turned off for particular modules? When you encountered performance issues, what mitigating strategies did you try? (e.g. isEnabledFor) -- VinaySajip

I set up a very simple script to time logging calls, available here. Output looks like this (Python 2.6 on Windows, Core Duo E8400):

log_noop              0.13 microseconds
log_simple           57.36 microseconds
log_filtered          4.19 microseconds
log_mitigated         3.78 microseconds
log_disabled          0.98 microseconds
No caller, thread, process info...
log_simple           49.89 microseconds
log_filtered          4.19 microseconds
log_mitigated         3.79 microseconds

which means that a simple logging call takes around 57 microseconds, reduced to around 50 microseconds if you opt to not collect caller, thread or process info. That's for logging to a file. So what are your expectations for performance? These numbers don't look too shabby to me. Of course, it's a simplistic test, but at least there are some actual numbers there. --VinaySajip

Too complicated, with logging levels, namespaces, handlers, and other things -- they took all the terrible things from java.util.logging and log4j, which are incredibly slow (but powerful) in python

Good ideas don't only come from Python people, folks. These ideas were proven in log4j and other packages and they are based on the ideas of "what happened? where did it happen? how important is it? who wants to know?" and if you think about it, these ideas are hardly Java-specific. OTOH, they are pretty central to the problem domain addressed by logging. So - "what happened?" is the details of the logging call, "where did it happen?" is the namespace, "how important is it?" is the level, and "who wants to know?" is the handler. Hardly that complicated, and AFAICT pretty much a minimum requirement for any logging package that aspires to the name.

And, "incredibly slow" is pretty emotive. Care to back that up with some hard data? See the numbers above for some ideas. Also, anyone who bothers to look at log4j in detail will see that Python logging is not a mindless translation - it's fairly Pythonic. Beyond the basic abstractions of "What? Where? How Important? Who Needs To Know?", there's no real correspondence between the Java artifacts and the Python ones. Using David A. Wheeler's SLOCCount, log4j 1.2.15 = 168 source files, around 16K SLOC; Python 2.6 logging = 3 source files, < 1.5K SLOC. To me the Java connection and inferences that people draw from the "Java heritage" is bordering on FUD a lot of the time, I have to say. But feel free to put me right with specific comments rather than vague arm-waving, and you'll find me receptive. -- VinaySajip

The appropriate roles for args and kwargs in loggerAdapter are ambiguous.

I'm finding the paradigms for augmenting log arguments with relevant context info confusing. The docs and general web info are helpful but slim on the topic so far. Adding contextual info via the 'extra' parameter with loggingAdapter(. . . ,extra=myClassObj | extra=my.dict ) is slick for some use cases, not so much for others. It seems that the extra= is set in stone when the loggerAdapter object is instantiated, then passed to the individual LogRecords as needed (true?/false?). Context specific to the location of the log() call is superseded by the context of the loggerAdapter instantiation. Any kwargs['extra'] in the log() calls are overwritten silently. Perhaps that's a feature, and context info specific to the log() call location should be incorporated using log(... args) and having Formatters manage and replace the the actual args? At present, the use of the kw extra is handled by logging in the reverse behavior of most inherited object properties, where lower level objects supercede the higher level class values. Fortunately, the logging mechanisms are so flexible that it's not difficult to use args in place of kwargs (even for class arguments), or to alter the default behavior of logging for the extra kw. Still, it's confusing as is when the use case is not to pass down the context of the logger instantiation to all subsequent log() calls. I have code for both solutions if there is interest. (This comment seems long and detailed relative to the intended context of this page. Is there another place for similar discussion? Also: where to post demo code that is neither patch nor bug?)

LoggingPackage (last edited 2012-03-15 12:46:11 by VinaySajip)

Unable to edit the page? See the FrontPage for instructions.