mysql-proxy-discuss team mailing list archive

[Kay Röpke <Kay.Roepke@xxxxxxx>]

Hi!

Last weekend, I started to work on the log4j-style logging blueprint,  
because I was sick of looking at megabytes of debug log output when  
working on a bugfix.
I just took the time to patch it into the current trunk (what will  
become 0.8 eventually), in order to get some feedback and testing in.

How does it work?
This implementation replaces the current log mechanism (in chassis- 
log.h|c) but mostly uses the same code when it comes to assembling the  
log message. We still use the g_log macros from glib2 to generate log  
output (although I might end up writing a couple of different ones,  
but that's another story).
Essentially we piggyback on a feature of the glib2 log system that we  
haven't been using so for: log domains.
A log domain is simply a string that gets passed on to the registered  
log handler. (Glib2 supports registering different handlers for  
different log domains, a feature this implementation doesn't use yet -  
maybe it never will, I need to do some experiments first.)

So, basically, in our log function we not only receive the requested  
log level, the message to print and a pointer to our log structure,  
but also a "domain".
For those of you that have used log4j or related systems, you are  
already familiar with the hierarchical nature of loggers. In that  
system you can request a logger with a name. The name describes a  
level in a tree structure, much like (internet) domain names do, often  
used in the reverse domain name format: "com.mysql.proxy" could be one  
of them.

Each of these loggers can be configured, by a configuration file for  
example, to be set on a certain log level and log file. The beauty of  
it is that because the loggers are arranged in a tree structure,  
"lower" level loggers will inherit the settings of the ones "above" it  
in the hierarchy, if no setting was configured for a specific logger.
For example: Setting "com.mysql" to log level "warning" will cause  
every logger starting with "com.mysql" to be set on that log level -  
unless you tell it that "com.mysql.proxy" should log on "debug". This  
is naturally applied recursively.

Ok, long story short, what we have here is a subset of log4j. It  
supports "logger targets" (which are places where the output gets  
written to, most often files) and "loggers". Loggers have a name, a  
minium log level (with the same meaning as the current --log-level  
option) and a target.
This way, you can direct different parts of your log output to certain  
files, or turn off parts you aren't interested in at all.

I suggest looking at the sample configurate file in my new branch to  
get a feel for what I'm babbling about here: http://bazaar.launchpad.net/%7Ekay-roepke/mysql-proxy/chassis-log-domains/annotate/head%3A/scripts/mysql-proxy-config.ini

There is one known bug right now, harmless but slighly annoying, that  
has to do with reporting a wrong log level and logger name when  
coalescing repeated messages, but that's non-critical.
The more important problem is that you cannot change log levels at  
runtime (though that's no change to the existing logging  
implementation) mostly because the code manipulating the log levels is  
not threadsafe yet. I will change that, however (probably by using  
glib2's log handler per log domain, because that already uses a global  
mutex internally). Should I find that being too slow, I might need to  
roll my own - we'll see.

cheers,
-k

P.S.: I'm really happy about the effect this has had. Being able to  
trim log output down to a manageable size is a huge benefit when  
trying to debug something :)
--
Kay Roepke
Software Engineer, MySQL Enterprise Tools

Sun Microsystems GmbH    Sonnenallee 1, DE-85551 Kirchheim-Heimstetten
Geschaeftsfuehrer:    Thomas Schroeder,  Wolfang Engels,  Wolf Frenkel
Vorsitz d. Aufs.rat.: Martin Haering                    HRB MUC 161028