Re: [libvirt] [PATCH] dynamic debug patch

On Wed, Nov 05, 2008 at 04:26:15PM +0100, Daniel Veillard wrote: Hardcoding a file in /tmp is not very good practice - it'll certainly not play nicely with SELinux. We should make the logfile name be configurable via /etc/libvirt/libvirtd.conf. I think use virBufferPtr is rather too cumbersome for the calling program. The internal API for logging currently just takes void qemudLog(int priority, const char *fmt, ...) Either we can pass variable args out to the app, or format the error message and then pass it out. The calling app can write this straight to a file, send to syslog, or anything else it wants, without having the intermediate step of potentially uneccessary buffering. I think it'll also be desirable to include a 'category' string to allow applications to filter the messages it uses. In the Java world, with log4j, the typical pattern is that each class registers a logging category matching its classname, eg you might have org.libvirt.Connect, org.libvirt.Domain, etc. The application using the class can configure the log4j infrastructure to turn on/off log messages per-category. We need a similar capability in libvirt - the existing logging in the daemon is already non-scalable because the 'EVENT' messages are soo frequent they typically drown out the more interesting stuff from the daemon. In parallel with debugging / logging of functional aspects of the daemon / library, it is also desirable to get the ability to record a log of operations invoked on objects. eg, I want to record all operation invoked against a particular driver, so as a support person I can ask a bug-reporter to send me the log of the operations they did leading upto the problem. As an application using libvirt API, I'd expect to have ability to register a callback to receive debug info, and APIs to control the logging level enum { VIR_LOG_DEBUG, VIR_LOG_INFO, VIR_LOG_WARN, VIR_LOG_ERROR, }; typedef void (*virLogHandler)(const char *category, int priority, const char *msg); virLogAddHandler(virLogHandler callback); virLogSetDefaultPriority(int priority); virLogSetPriority(const char *category, int priority); And a semi-public internal API (ie for use by libvirt.so and libvirtd) virLogMessage(const char *category, int priority, const char *fmt, ....); I'd be inclined to say that categories are named to match the filename, so if you wanted to log messasges from the event.c file, at a level of 'INFO' or higher, you'd do void mylogger(const char *cat, int prior, const char *msg) { fprintf(stderr, "%s", msg); } virLogAddHandler(mylogger); virLogSetPriority("file.events", VIR_INFO) The default priority would be 'WARN', unless explicitly set for a category. In the context of libvirtd daemon, if you passed '--verbose' we'd set virLogDefaultPriority(VIR_LOG_INFO) and if you passed --debug we'd set it to VIR_LOG_DEBUG. So the same public API would be useful both for libvirtd, and other apps linking to libvirt.so in just the same way - we'd merely need to expose virLogMessage() to the daemon so its own log messages can flow through the same channels as those inside the library. Currently we toggle between using stderr, and syslog according to whether the --deamon flag is passed. This isn't particularly great. We should be configurable independantly of thise. I'd expect /etc/libvirt/libvirtd.conf to allow you to set # Choice of 'null', 'syslog', 'stderr', 'file' log.backend = "syslog" # If 'file' was chosen, then also allow log.file = "/var/log/libvirtd.log" # or if 'syslog' was chosen, then allow admin to set the # syslog facility name for openlog() call. log.syslog = "libvirtd" # One of VIR_LOG_XXX constants log.priority = "WARN" # And per category overrides log.category.events = "DEBUG" log.category.mdns = "INFO" We already have SIGUSR1 hooked up to make it re-read the domain XML files, so we could extend this to also re-read the master config file. So if someone wanted to temporarily debug the system they could just edit 'log.backend' from 'null' to 'file', and send the 'SIGUSR1'. Or if they already have it logging to a file by default and just wanted to increase verbosity, they'd edit 'log.priority' and send SIGUSR1. At any time, they can also send SIGUSR2 as per your patch, and get a dump listing all active sockets, sent to whatever log.backend they currently have configured - either syslog, or file, or whateve else we implement. This comprehensive logging solution is rather alot of work, so for immediate use I'd suggest just adding the config for 'log.file' and 'log.backend' choice, and ignore the per-category debug levels for 0.5.0 release. I think debug messages are potentially important not to localize. They are not typically intended for end users, but for developers & vendor support people, where having everything in english may make it easier to search for similar problems. This path needs to be configurable from the /etc/libvirt/libvirtd.conf file, and default to /var/log to be selinux compliant. Since this is inside the daemon, we already know that no other SIGUSR2 handler is present, so can ignore that check. IMHO, toggle of log level should be done with SIGUSR1 and libvirtd.conf reload, and SIGUSR2 should just be doing the 'state dump' of active sockets, clients & other interesting info, to whatever logging target is active, be it syslog or a file, or stderr. This qemudLog() function is really flawed - if toggles between the use of syslog() vs stderr, based on whether you pass --daemon flag. It needs to be configurable by the config file, independantly of --daemon. As this patch stands, nothing will ever be logged because 99% of libvirtd instances run with --daemon flag set, and thus are using the syslog() code branch THis pile of (mostly useless) EVENT log messages is why we need to ultimately have 'category' filters per file :-) Regards, Daniel -- |: Red Hat, Engineering, London -o- http://people.redhat.com/berrange/ :| |: http://libvirt.org -o- http://virt-manager.org -o- http://ovirt.org :| |: http://autobuild.org -o- http://search.cpan.org/~danberr/ :| |: GnuPG: 7D3B9505 -o- F3C9 553F A1DA 4AC2 5648 23C1 B3DF F742 7D3B 9505 :|