Logging in the library and the daemon

Libvirt includes logging facilities starting from version 0.6.0, this complements the error handling mechanism and APIs to allow tracing though the execution of the library as well as in the libvirtd daemon.

The logging functionalities in libvirt are based on 3 key concepts, similar to the one present in other generic logging facilities like log4j:

log messages: they are information generated at runtime by the libvirt code, it includes a priority level (DEBUG = 1, INFO = 2, WARNING = 3, ERROR = 4), a category, function name and line number, indicating where it originated from, and finally a formatted message, in addition the library adds a timestamp at the begining of the message
log filters: it's a set of patter and priorities allowing to acept or reject a log message, if the message category matches a filter, the message priority is compared to the filter priority, if lower the message is discarded, if higher the message is output. If no filter matches, then a general priority level is applied to all remaining messages. This allows to capture for example all debug messages for the QEmu driver, but otherwise only allow errors to show up from other parts
log outputs: once a message has gone though filtering a set of output defines where to send the message, they can also filter based on the priority, for example it may be useful to output all messages to a debugging file but only allow errors to be logged though syslog.

The library configuration of logging is though 3 environment variables allowing to control the logging behaviour:

LIBVIRT_DEBUG: it can take the four following values:
- 1 or "debug": asking the library to log every message emitted, though the filters can be used to avoid filling up the output
- 2 or "info": log all non-debugging informations
- 3 or "warn": log warnings and errors, that's the default value
- 4 or "error": log only error messages
LIBVIRT_LOG_FILTERS: allow to define logging filters
LIBVIRT_LOG_OUTPUTS: allow to define logging outputs

Similary the daemon logging behaviour can be tuned using 3 config variables, stored in the configuration file:

log_level: accepts the following values:
- 0: no logging at all
- 4: only errors
- 3: warnings and errors
- 2: informations, warnings and errors
- 1: debug and everything
log_filters: allow to define logging filters
log_outputs: allow to define logging outputs

In both case the syntax for filters and outputs is similar.

The format for a filter is:

x:name

where name is a match string e.g. remote or qemu and the x is the minimal level where matching messages should be logged:

1: DEBUG
2: INFO
3: WARNING
4: ERROR

Multiple filter can be defined in a single string, they just need to be separated by spaces, e.g: "3:remote 4:event" to only get warning or errors from the remote layer and only errors from the event layer.

The format for an output can be one of those 3 forms:

x:stderr output goes to stderr
x:syslog:name use syslog for the output and use the given name as the ident
x:file:file_pathoutput to a file, with the given filepath

In all cases the x prefix is the minimal level, acting as a filter:

0: everything
1: DEBUG
2: INFO
3: WARNING
4: ERROR

Multiple output can be defined , they just need to be separated by spaces, e.g.: "3:syslog:libvirtd 0:file:/tmp/libvirt.log" will log all warnings and errors to syslog under the libvirtd ident but also log everything debugging and informations included in the file /tmp/libvirt.log

For example setting up the following:

export LIBVIRT_DEBUG=1
export LIBVIRT_LOG_OUTPUTS="0:file:virsh.log"

and then running virsh will accumulate the logs in the virsh.log file in a way similar to:

14:29:04.771: debug : virInitialize:278 : register drivers
14:29:04.771: debug : virRegisterDriver:618 : registering Test as driver 0

the messages are timestamped, there is also the level recorded, if debug the name of the function is also printed and then the formatted message. This should be sufficient to at least get a precise idea of what is happening and where things are going wrong, allowing to then put the correct breakpoints when running under a debugger.