Re: Log message format in KVM-Autotest

[Lucas Meneghel Rodrigues <lmr@redhat.com>]

On Mon, 2009-06-08 at 06:35 -0400, Michael Goldish wrote: 
> Hi Lucas,
> 
> Before the merge with Autotest we used kvm_log.py to log formatted messages.
> Each message contained the current test's 'shortname' (e.g. Fedora.8.32.install), the current date and time (down to a 1 sec resolution) and the message itself. In addition, debug messages contained the name of the calling function, e.g.
> remote_login: Trying to login...
> 
> What is the preferred way of obtaining this functionality using the new logging system inside Autotest? Should we define our own logging Handler for the KVM test in kvm.py, along with our own Formatter, or should we use logging.config.fileConfig(), or is there another preferred way?
> I'm particularly interested in printing the name of the caller in debug messages. This feature makes debugging easier and improves overall readability of the logs. (Obviously we can manually hardcode the name of the current function into every debug message, but that doesn't seem like a good solution.)

The logging system can be configured to display several LogRecord
attributes, they are documented under

http://docs.python.org/library/logging.html#formatter-objects

%(funcName)s is the name of the function issuing the logging call, so
that's what we are looking to mirror the wanted functionality.

Creating a logging Handler with a formatter on its own is a possibility,
although we can propose adding the name of the function to the file
format being used by autotest. There's allways the concern that an
excess of information may clutter the logs. 

Right now, for files we use the following format:

http://autotest.kernel.org/browser/trunk/client/debug_client.ini

[formatter_file_formatter]
format=[%(asctime)s %(levelname)-5.5s %(module)s] %(message)s
datefmt=%m/%d %H:%M:%S

The formatter we're using for the logs contain a timestamp, the debug
level name and the module (source file except the .py extension). I
believe this makes debugging easy enough without cluttering too much the
logs. Do you think the caller name would be an interesting addition even
considering the above?


> Thanks,
> Michael
-- 
Lucas Meneghel Rodrigues
Software Engineer (QE)
Red Hat - Emerging Technologies