[py-dev] Logging in the py library

[holger krekel]

Hi Grig, 

On Tue, Jun 07, 2005 at 07:59 -0700, Grig Gheorghiu wrote:
> --- holger krekel <hpk at trillke.net> wrote:
> > ... 
> > Basically we could associate
> > with each logging message/object [*] a set of keywords.
> > severity categorizations would just be a keyword in that idea. 
> > 
> > Let me try an example for e.g. tracing in py/execnet/gateway.py: 
> > ... 
> >             trace("initializing gateway ...")
> >             ... 
> > 'trace' may by default add a 'debug' keyword if called like this. 
> > If we want to print some warning, then we could do something like: 
> > 
> >     trace.warn("remote gateway side could not be destroyed") 
> > 
> > which would add the keyword 'warning' to that particular message.  
> 
> So is this association static or dynamic? If I understand correctly,
> you'd want it to be dynamic, right?

No, the association of keywords with messages can be static. 

> So for example trace.foo would add
> 'foo' to the message. But the severity levels need to be statically
> defined, at least if we want to mimic what the logging module does. 

Yes, 'trace.debug' would return a tracer that has the same keywords 
as 'trace' + the keyword 'debug'.  Any message this tracer then 
produces would have all the latter keywords associated with it. 

> In the logging module, you can set a default severity level,
> so that the logger will output only those messages that have
> greater or equal severity levels. 

This refers to output filters and such.  I think it makes 
sense to differentiate between a 'producing' API (basically something 
very simple like above - just one 'tracer' factory function) 
and a consuming API dealing with how to redirect messages based 
on keywords to specific backends/formatters.  

IMO the connection between producing and consuming objects should 
be runtime re-configurable.  So it's really a small event system 
and may even be generalized into that at some point.  The logging 
module would only come into play on the consuming side an internal 
backend and we would expose as few details about this as feasible. 

> > By default, everything would probably go to stdout but an
> > application should be able to redirect by keyword to specific
> > formatting/output backends (much like the logging module).  I
> > think it's important to allow this redirection to happen
> > _after_ the above example is already imported, so
> > redirections-by-keyword should be re-configurable at runtime. 
> 
> Yes, it would be nice to have the possibility of sending the messages
> to a variety of handlers (stdout, files, sockets, HTTP servers, etc.)
> One reservation I have about stdout being the default is that it might
> interfere with py.test's own catching of stdout/stderr. I think it
> would be better to trace to a file by default (I think that's what the
> twisted.log module does too, although I haven't looked at it, I only
> saw it mentioned somewhere).

don't worry, py.test could reconfigure the tracing accordingly. 
The idea above is really about an application-independent 
general mechanism.  I believe that the basic tracer should 
be as close to a mere 'print' statement as possible. 

Hum, to keep things really minimal we might consider: 

    import py  
    py.trace.debug('hello', 'world') 

which would by default print something like: 

    [debug] hello world 

Or, to make it even more obvious: 

    print >>py.trace.debug, "hello", "world" 

No API is the best API, remember? :-) 

(the disadvantage is that the str()s are always computed 
but that is a somewhat unfortunate language implementation 
detail that could be changed at some point :-). 

The nice property of the above that it is a really simple 
idiom which makes it obvious that the tracing statement 
does not mutate the program state but only has a tracing 
side effect.  

> > What do you think of this basic keyword idea?  (which cold
> > still use the logging module underneath for accessing all 
> > the backends if it makes sense). 
> > 
> > And sorry, but the py lib really aims at exploring
> > improvements over current ways of doing things :-) 
> > 
> 
> I think it's a very good idea. In my opinion, it would still be worth
> using the logging module underneath, since all the grunt work is
> already done there. I hate reinventing wheels.

Agreed.  However, before worrying about output handlers (where 
the logging module could really help) i'd like to have a nice
pythonic tracing model that allows to connect e.g. print-statements 
to tracer functions (and we can offer some default set of 
tracer functions which itself use the logging module). 

Hum.  Here is a thought example of how a _consuming_ tracer  
function could look like: 

    def mytracer(message): 
        if 'error' in message.keywords: 
            print >>somefile, "error:", str(message) 
        elif ... 

    py.trace[...] = mytracer 
             ^^^ literally :-) 

or to associate the consuming tracer function more directly: 

    def myerrortracer(message): 
        print >>errorfile, str(message)  

    py.trace['error'] = myerrortracer 

Wouldn't the meaning of this API be obvious? 
(I am not explaining it on purpose here :-) 

Providing adapter-consuming-tracer-functions for using the 
logging-module's backends should then becomes an orthogonal 
disconnected issue. 

> But polishing and simplifying the interface to the logging
> module is certainly something to be aimed for -- and your
> keyword idea goes a long way towards that goal.

great to hear!  

I have to admit i have thought about the 'tracing problem'
quite a bit already and i had some discussion with Vinay at
the time (the author of the logging module).  Your bringing
up of the topic forced me to try express my train of thoughts 
more clearly.  

cheers, 

    holger