2013-05-03 14:25:37 +00:00
|
|
|
<?xml version="1.0" encoding="UTF-8"?>
|
2017-07-26 17:01:25 +00:00
|
|
|
<!DOCTYPE html>
|
2013-05-03 14:25:37 +00:00
|
|
|
<html xmlns="http://www.w3.org/1999/xhtml">
|
2008-12-23 13:47:10 +00:00
|
|
|
<body>
|
|
|
|
|
<h1 >Logging in the library and the daemon</h1>
|
2014-02-24 16:37:20 +00:00
|
|
|
|
2008-12-23 13:47:10 +00:00
|
|
|
<p>Libvirt includes logging facilities starting from version 0.6.0,
|
|
|
|
|
this complements the <a href="errors.html">error handling</a>
|
2010-09-22 21:34:17 +00:00
|
|
|
mechanism and APIs to allow tracing through the execution of the
|
2008-12-23 13:47:10 +00:00
|
|
|
library as well as in the libvirtd daemon.</p>
|
2014-02-24 16:37:20 +00:00
|
|
|
|
|
|
|
|
<ul id="toc"/>
|
|
|
|
|
|
2014-02-24 16:34:36 +00:00
|
|
|
<h2>
|
2017-07-26 14:52:42 +00:00
|
|
|
<a id="log_library">Logging in the library</a>
|
2014-02-24 16:34:36 +00:00
|
|
|
</h2>
|
2008-12-23 13:47:10 +00:00
|
|
|
<p>The logging functionalities in libvirt are based on 3 key concepts,
|
|
|
|
|
similar to the one present in other generic logging facilities like
|
|
|
|
|
log4j:</p>
|
|
|
|
|
<ul>
|
2011-03-17 07:30:49 +00:00
|
|
|
<li><b>log messages</b>: they are information generated at runtime by
|
2010-09-22 21:34:17 +00:00
|
|
|
the libvirt code. Each message includes a priority level (DEBUG = 1,
|
2008-12-23 13:47:10 +00:00
|
|
|
INFO = 2, WARNING = 3, ERROR = 4), a category, function name and
|
|
|
|
|
line number, indicating where it originated from, and finally
|
2010-09-22 21:34:17 +00:00
|
|
|
a formatted message. In addition the library adds a timestamp
|
2011-03-17 07:30:49 +00:00
|
|
|
at the beginning of the message</li>
|
|
|
|
|
<li><b>log filters</b>: a set of patterns and priorities to accept
|
2010-09-22 21:34:17 +00:00
|
|
|
or reject a log message. If the message category matches a filter,
|
2008-12-23 13:47:10 +00:00
|
|
|
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
|
2010-09-22 21:34:17 +00:00
|
|
|
all remaining messages. This allows, for example, capturing all
|
2018-03-31 14:51:14 +00:00
|
|
|
debug messages for the QEMU driver, but otherwise only allowing
|
2010-09-22 21:34:17 +00:00
|
|
|
errors to show up from other parts.</li>
|
2011-03-17 07:30:49 +00:00
|
|
|
<li><b>log outputs</b>: once a message has gone through filtering a set of
|
2008-12-23 13:47:10 +00:00
|
|
|
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
|
2010-09-22 21:34:17 +00:00
|
|
|
logged through syslog.</li>
|
2008-12-23 13:47:10 +00:00
|
|
|
</ul>
|
2011-03-17 07:30:49 +00:00
|
|
|
|
2014-02-24 16:34:36 +00:00
|
|
|
<h2>
|
2017-07-26 14:52:42 +00:00
|
|
|
<a id="log_config">Configuring logging in the library</a>
|
2014-02-24 16:34:36 +00:00
|
|
|
</h2>
|
2010-09-22 21:34:17 +00:00
|
|
|
<p>The library configuration of logging is through 3 environment variables
|
2008-12-23 13:47:10 +00:00
|
|
|
allowing to control the logging behaviour:</p>
|
|
|
|
|
<ul>
|
|
|
|
|
<li>LIBVIRT_DEBUG: it can take the four following values:
|
|
|
|
|
<ul>
|
|
|
|
|
<li>1 or "debug": asking the library to log every message emitted,
|
|
|
|
|
though the filters can be used to avoid filling up the output</li>
|
2013-10-22 03:02:43 +00:00
|
|
|
<li>2 or "info": log all non-debugging information</li>
|
2008-12-23 13:47:10 +00:00
|
|
|
<li>3 or "warn": log warnings and errors, that's the default value</li>
|
|
|
|
|
<li>4 or "error": log only error messages</li>
|
|
|
|
|
</ul></li>
|
2010-09-22 21:34:17 +00:00
|
|
|
<li>LIBVIRT_LOG_FILTERS: defines logging filters</li>
|
|
|
|
|
<li>LIBVIRT_LOG_OUTPUTS: defines logging outputs</li>
|
2008-12-23 13:47:10 +00:00
|
|
|
</ul>
|
2009-08-06 13:58:38 +00:00
|
|
|
<p>Note that, for example, setting LIBVIRT_DEBUG= is the same as unset. If
|
|
|
|
|
you specify an invalid value, it will be ignored with a warning. If you
|
|
|
|
|
have an error in a filter or output string, some of the settings may be
|
|
|
|
|
applied up to the point at which libvirt encountered the error.</p>
|
2014-02-24 16:34:36 +00:00
|
|
|
<h2>
|
2017-07-26 14:52:42 +00:00
|
|
|
<a id="log_daemon">Logging in the daemon</a>
|
2014-02-24 16:34:36 +00:00
|
|
|
</h2>
|
2010-09-22 21:34:17 +00:00
|
|
|
<p>Similarly the daemon logging behaviour can be tuned using 3 config
|
2011-04-01 22:02:10 +00:00
|
|
|
variables, stored in the configuration file:</p>
|
2008-12-23 13:47:10 +00:00
|
|
|
<ul>
|
|
|
|
|
<li>log_level: accepts the following values:
|
|
|
|
|
<ul>
|
|
|
|
|
<li>4: only errors</li>
|
|
|
|
|
<li>3: warnings and errors</li>
|
2013-10-22 03:02:43 +00:00
|
|
|
<li>2: information, warnings and errors</li>
|
2008-12-23 13:47:10 +00:00
|
|
|
<li>1: debug and everything</li>
|
|
|
|
|
</ul></li>
|
2010-09-22 21:34:17 +00:00
|
|
|
<li>log_filters: defines logging filters</li>
|
|
|
|
|
<li>log_outputs: defines logging outputs</li>
|
2008-12-23 13:47:10 +00:00
|
|
|
</ul>
|
2009-08-06 13:58:38 +00:00
|
|
|
<p>When starting the libvirt daemon, any logging environment variable
|
|
|
|
|
settings will override settings in the config file. Command line options
|
|
|
|
|
take precedence over all. If no outputs are defined for libvirtd, it
|
2014-02-24 16:22:51 +00:00
|
|
|
will try to use</p>
|
|
|
|
|
<ul>
|
|
|
|
|
<li>0.10.0 or later: systemd journal, if <code>/run/systemd/journal/socket</code> exists</li>
|
|
|
|
|
<li>0.9.0 or later: file <code>/var/log/libvirt/libvirtd.log</code> if running as a daemon</li>
|
|
|
|
|
<li>before 0.9.0: syslog if running as a daemon</li>
|
|
|
|
|
<li>all versions: to stderr stream if running in the foreground</li>
|
|
|
|
|
</ul>
|
2009-08-06 13:58:38 +00:00
|
|
|
<p>Libvirtd does not reload its logging configuration when issued a SIGHUP.
|
|
|
|
|
If you want to reload the configuration, you must do a <code>service
|
|
|
|
|
libvirtd restart</code> or manually stop and restart the daemon
|
|
|
|
|
yourself.</p>
|
2011-03-17 07:30:49 +00:00
|
|
|
<p>Starting from 0.9.0, the daemon can save all the content of the debug
|
|
|
|
|
buffer to the defined error channels (or /var/log/libvirt/libvirtd.log
|
|
|
|
|
by default) in case of crash, this can also be activated explicitly
|
|
|
|
|
for debugging purposes by sending the daemon a USR2 signal:</p>
|
|
|
|
|
<pre>killall -USR2 libvirtd</pre>
|
2014-02-24 16:34:36 +00:00
|
|
|
<h2>
|
2017-07-26 14:52:42 +00:00
|
|
|
<a id="log_syntax">Syntax for filters and output values</a>
|
2014-02-24 16:34:36 +00:00
|
|
|
</h2>
|
2009-08-06 13:58:38 +00:00
|
|
|
<p>The syntax for filters and outputs is the same for both types of
|
|
|
|
|
variables.</p>
|
2019-10-02 10:51:51 +00:00
|
|
|
<p>The format for a filter is:</p>
|
2012-05-09 14:18:56 +00:00
|
|
|
<pre>
|
2019-10-02 10:51:51 +00:00
|
|
|
x:name</pre>
|
2015-12-21 15:53:57 +00:00
|
|
|
<p>where <code>name</code> is a string which is matched against
|
|
|
|
|
the category given in the VIR_LOG_INIT() at the top of each
|
|
|
|
|
libvirt source file, e.g., <code>remote</code>, <code>qemu</code>,
|
|
|
|
|
or <code>util.json</code> (the name in the filter can be a
|
|
|
|
|
substring of the full category name, in order to match multiple
|
2019-10-02 10:51:51 +00:00
|
|
|
similar categories), and <code>x</code> is the minimal
|
2015-12-21 15:53:57 +00:00
|
|
|
level where matching messages should be logged:</p>
|
2008-12-23 13:47:10 +00:00
|
|
|
<ul>
|
|
|
|
|
<li>1: DEBUG</li>
|
|
|
|
|
<li>2: INFO</li>
|
|
|
|
|
<li>3: WARNING</li>
|
|
|
|
|
<li>4: ERROR</li>
|
|
|
|
|
</ul>
|
2009-08-06 13:58:38 +00:00
|
|
|
<p>Multiple filters can be defined in a single string, they just need to be
|
2008-12-23 13:47:10 +00:00
|
|
|
separated by spaces, e.g: <code>"3:remote 4:event"</code> to only get
|
|
|
|
|
warning or errors from the remote layer and only errors from the event
|
2011-04-01 22:02:10 +00:00
|
|
|
layer.</p>
|
2009-08-06 13:58:38 +00:00
|
|
|
<p>If you specify a log priority in a filter that is below the default log
|
|
|
|
|
priority level, messages that match that filter will still be logged,
|
|
|
|
|
while others will not. In order to see those messages, you must also have
|
|
|
|
|
an output defined that includes the priority level of your filter.</p>
|
2020-05-19 21:41:30 +00:00
|
|
|
<p>The format for an output can be one of the following forms:</p>
|
2008-12-23 13:47:10 +00:00
|
|
|
<ul>
|
|
|
|
|
<li><code>x:stderr</code> output goes to stderr</li>
|
|
|
|
|
<li><code>x:syslog:name</code> use syslog for the output and use the
|
|
|
|
|
given <code>name</code> as the ident</li>
|
2010-02-21 13:56:23 +00:00
|
|
|
<li><code>x:file:file_path</code> output to a file, with the given
|
2008-12-23 13:47:10 +00:00
|
|
|
filepath</li>
|
2014-02-24 16:22:51 +00:00
|
|
|
<li><code>x:journald</code> output goes to systemd journal</li>
|
2008-12-23 13:47:10 +00:00
|
|
|
</ul>
|
|
|
|
|
<p>In all cases the x prefix is the minimal level, acting as a filter:</p>
|
|
|
|
|
<ul>
|
|
|
|
|
<li>1: DEBUG</li>
|
|
|
|
|
<li>2: INFO</li>
|
|
|
|
|
<li>3: WARNING</li>
|
|
|
|
|
<li>4: ERROR</li>
|
|
|
|
|
</ul>
|
2010-09-22 21:34:17 +00:00
|
|
|
<p>Multiple output can be defined, they just need to be separated by
|
2009-07-01 11:21:15 +00:00
|
|
|
spaces, e.g.: <code>"3:syslog:libvirtd 1:file:/tmp/libvirt.log"</code>
|
2008-12-23 13:47:10 +00:00
|
|
|
will log all warnings and errors to syslog under the libvirtd ident
|
2011-03-17 07:30:49 +00:00
|
|
|
but also log all debug and information included in the
|
2008-12-23 13:47:10 +00:00
|
|
|
file <code>/tmp/libvirt.log</code></p>
|
2014-02-24 16:22:51 +00:00
|
|
|
|
2017-07-26 14:52:42 +00:00
|
|
|
<h2><a id="journald">Systemd journal fields</a></h2>
|
2014-02-24 16:22:51 +00:00
|
|
|
|
|
|
|
|
<p>
|
|
|
|
|
When logging to the systemd journal, the following fields
|
|
|
|
|
are defined, in addition to any automatically recorded
|
2020-08-25 22:44:00 +00:00
|
|
|
<a href="https://www.freedesktop.org/software/systemd/man/systemd.journal-fields.html">standard fields</a>:
|
2014-02-24 16:22:51 +00:00
|
|
|
</p>
|
|
|
|
|
|
|
|
|
|
<dl>
|
|
|
|
|
<dt><code>MESSAGE</code></dt>
|
|
|
|
|
<dd>The log message string</dd>
|
|
|
|
|
<dt><code>PRIORITY</code></dt>
|
|
|
|
|
<dd>The log priority value</dd>
|
|
|
|
|
<dt><code>LIBVIRT_SOURCE</code></dt>
|
|
|
|
|
<dd>The source type, one of "file", "error", "audit", "trace", "library"</dd>
|
|
|
|
|
<dt><code>CODE_FILE</code></dt>
|
|
|
|
|
<dd>The name of the file emitting the log record</dd>
|
|
|
|
|
<dt><code>CODE_LINE</code></dt>
|
|
|
|
|
<dd>The line number of the file emitting the log record</dd>
|
|
|
|
|
<dt><code>CODE_FUNC</code></dt>
|
|
|
|
|
<dd>The name of the function emitting the log record</dd>
|
2014-02-21 17:23:10 +00:00
|
|
|
<dt><code>LIBVIRT_DOMAIN</code></dt>
|
|
|
|
|
<dd>The libvirt error domain (values from virErrorDomain enum), if LIBVIRT_SOURCE="error"</dd>
|
|
|
|
|
<dt><code>LIBVIRT_CODE</code></dt>
|
|
|
|
|
<dd>The libvirt error code (values from virErrorCode enum), if LIBVIRT_SOURCE="error"</dd>
|
2014-02-24 16:22:51 +00:00
|
|
|
</dl>
|
|
|
|
|
|
2017-07-26 14:52:42 +00:00
|
|
|
<h3><a id="journaldids">Well known message ID values</a></h3>
|
2014-02-21 17:16:07 +00:00
|
|
|
|
|
|
|
|
<p>
|
|
|
|
|
Certain areas of the code will emit log records tagged with well known
|
|
|
|
|
unique id values, which are guaranteed never to change in the future.
|
|
|
|
|
This allows applications to identify critical log events without doing
|
|
|
|
|
string matching on the <code>MESSAGE</code> field.
|
|
|
|
|
</p>
|
|
|
|
|
|
|
|
|
|
<dl>
|
|
|
|
|
<dt><code>MESSAGE_ID=8ae2f3fb-2dbe-498e-8fbd-012d40afa361</code></dt>
|
|
|
|
|
<dd>Generated by the QEMU driver when it identifies a QEMU system
|
|
|
|
|
emulator binary, but is unable to extract information about its
|
|
|
|
|
capabilities. This is usually an indicator of a broken QEMU
|
|
|
|
|
build or installation. When this is emitted, the <code>LIBVIRT_QEMU_BINARY</code>
|
|
|
|
|
message field will provide the full path of the QEMU binary that failed.
|
|
|
|
|
</dd>
|
|
|
|
|
</dl>
|
|
|
|
|
|
|
|
|
|
<p>
|
|
|
|
|
The <code>journalctl</code> command can be used to search the journal
|
|
|
|
|
matching on specific message ID values
|
|
|
|
|
</p>
|
|
|
|
|
|
|
|
|
|
<pre>
|
2016-11-11 22:40:27 +00:00
|
|
|
$ journalctl MESSAGE_ID=8ae2f3fb-2dbe-498e-8fbd-012d40afa361 --output=json
|
|
|
|
|
{ ...snip...
|
|
|
|
|
"LIBVIRT_SOURCE" : "file",
|
|
|
|
|
"PRIORITY" : "3",
|
|
|
|
|
"CODE_FILE" : "qemu/qemu_capabilities.c",
|
|
|
|
|
"CODE_LINE" : "2770",
|
|
|
|
|
"CODE_FUNC" : "virQEMUCapsLogProbeFailure",
|
|
|
|
|
"MESSAGE_ID" : "8ae2f3fb-2dbe-498e-8fbd-012d40afa361",
|
|
|
|
|
"LIBVIRT_QEMU_BINARY" : "/bin/qemu-system-xtensa",
|
|
|
|
|
"MESSAGE" : "Failed to probe capabilities for /bin/qemu-system-xtensa:" \
|
|
|
|
|
"internal error: Child process (LC_ALL=C LD_LIBRARY_PATH=/home/berrange" \
|
|
|
|
|
"/src/virt/libvirt/src/.libs PATH=/usr/lib64/ccache:/usr/local/sbin:" \
|
|
|
|
|
"/usr/local/bin:/sbin:/bin:/usr/sbin:/usr/bin:/root/bin HOME=/root " \
|
|
|
|
|
"USER=root LOGNAME=root /bin/qemu-system-xtensa -help) unexpected " \
|
|
|
|
|
"exit status 127: /bin/qemu-system-xtensa: error while loading shared " \
|
|
|
|
|
"libraries: libglapi.so.0: cannot open shared object file: No such " \
|
|
|
|
|
"file or directory\n" }
|
2014-02-21 17:16:07 +00:00
|
|
|
</pre>
|
|
|
|
|
|
2014-02-24 16:34:36 +00:00
|
|
|
<h2>
|
2017-07-26 14:52:42 +00:00
|
|
|
<a id="log_examples">Examples</a>
|
2014-02-24 16:34:36 +00:00
|
|
|
</h2>
|
2008-12-23 13:47:10 +00:00
|
|
|
<p>For example setting up the following:</p>
|
|
|
|
|
<pre>export LIBVIRT_DEBUG=1
|
2009-07-01 11:21:15 +00:00
|
|
|
export LIBVIRT_LOG_OUTPUTS="1:file:virsh.log"</pre>
|
2008-12-23 13:47:10 +00:00
|
|
|
<p>and then running virsh will accumulate the logs in the
|
|
|
|
|
<code>virsh.log</code> file in a way similar to:</p>
|
|
|
|
|
<pre>14:29:04.771: debug : virInitialize:278 : register drivers
|
|
|
|
|
14:29:04.771: debug : virRegisterDriver:618 : registering Test as driver 0</pre>
|
|
|
|
|
<p>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.</p>
|
2011-03-17 07:30:49 +00:00
|
|
|
<p>To activate full debug of the libvirt entry points, utility
|
2018-03-31 14:51:14 +00:00
|
|
|
functions and the QEMU/KVM driver, set:</p>
|
2012-03-12 21:34:55 +00:00
|
|
|
<pre>log_filters="1:libvirt 1:util 1:qemu"
|
|
|
|
|
log_outputs="1:file:/var/log/libvirt/libvirtd.log"</pre>
|
2011-03-17 07:30:49 +00:00
|
|
|
<p>in libvirtd.conf and restart the daemon will allow to
|
|
|
|
|
gather a copious amount of debugging traces for the operations done
|
|
|
|
|
in those areas.</p>
|
2008-12-23 13:47:10 +00:00
|
|
|
</body>
|
|
|
|
|
</html>
|
