mirror of
https://gitlab.com/libvirt/libvirt.git
synced 2024-08-28 11:31:16 +00:00
The log filters have supported the use of a "+" before the source match
string to request that a stack trace be emitted for every log message:
commit 548563956e
Author: Daniel P. Berrange <berrange@redhat.com>
Date: Wed May 9 15:18:56 2012 +0100
Allow stack traces to be included with log messages
Sometimes it is useful to see the callpath for log messages.
This change enhances the log filter syntax so that stack traces
can be show by setting '1:+NAME' instead of '1:NAME'.
With the huge & ever increasing number of logging statements per file,
this will be incredibly verbose and have a major performance penalty.
This makes the feature impractical to use widely and as such it is not
worth the code maint cost.
Removing this seldom used feature allows us to drop the 'execinfo'
module in gnulib which provides the backtrace() function which doesn't
exist on non-Linux.
Users who want to get stack traces of parts of libvirt can use GDB,
or systemtap for live tracing with minimal perf impact.
Reviewed-by: Ján Tomko <jtomko@redhat.com>
Signed-off-by: Daniel P. Berrangé <berrange@redhat.com>
244 lines
11 KiB
XML
244 lines
11 KiB
XML
<?xml version="1.0" encoding="UTF-8"?>
|
|
<!DOCTYPE html>
|
|
<html xmlns="http://www.w3.org/1999/xhtml">
|
|
<body>
|
|
<h1 >Logging in the library and the daemon</h1>
|
|
|
|
<p>Libvirt includes logging facilities starting from version 0.6.0,
|
|
this complements the <a href="errors.html">error handling</a>
|
|
mechanism and APIs to allow tracing through the execution of the
|
|
library as well as in the libvirtd daemon.</p>
|
|
|
|
<ul id="toc"/>
|
|
|
|
<h2>
|
|
<a id="log_library">Logging in the library</a>
|
|
</h2>
|
|
<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>
|
|
<li><b>log messages</b>: they are information generated at runtime by
|
|
the libvirt code. Each message 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 beginning of the message</li>
|
|
<li><b>log filters</b>: a set of patterns and priorities to accept
|
|
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, for example, capturing all
|
|
debug messages for the QEMU driver, but otherwise only allowing
|
|
errors to show up from other parts.</li>
|
|
<li><b>log outputs</b>: once a message has gone through 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 through syslog.</li>
|
|
</ul>
|
|
|
|
<h2>
|
|
<a id="log_config">Configuring logging in the library</a>
|
|
</h2>
|
|
<p>The library configuration of logging is through 3 environment variables
|
|
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>
|
|
<li>2 or "info": log all non-debugging information</li>
|
|
<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>
|
|
<li>LIBVIRT_LOG_FILTERS: defines logging filters</li>
|
|
<li>LIBVIRT_LOG_OUTPUTS: defines logging outputs</li>
|
|
</ul>
|
|
<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>
|
|
<h2>
|
|
<a id="log_daemon">Logging in the daemon</a>
|
|
</h2>
|
|
<p>Similarly the daemon logging behaviour can be tuned using 3 config
|
|
variables, stored in the configuration file:</p>
|
|
<ul>
|
|
<li>log_level: accepts the following values:
|
|
<ul>
|
|
<li>4: only errors</li>
|
|
<li>3: warnings and errors</li>
|
|
<li>2: information, warnings and errors</li>
|
|
<li>1: debug and everything</li>
|
|
</ul></li>
|
|
<li>log_filters: defines logging filters</li>
|
|
<li>log_outputs: defines logging outputs</li>
|
|
</ul>
|
|
<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
|
|
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>
|
|
<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>
|
|
<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>
|
|
<h2>
|
|
<a id="log_syntax">Syntax for filters and output values</a>
|
|
</h2>
|
|
<p>The syntax for filters and outputs is the same for both types of
|
|
variables.</p>
|
|
<p>The format for a filter is:</p>
|
|
<pre>
|
|
x:name</pre>
|
|
<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
|
|
similar categories), and <code>x</code> is the minimal
|
|
level where matching messages should be logged:</p>
|
|
<ul>
|
|
<li>1: DEBUG</li>
|
|
<li>2: INFO</li>
|
|
<li>3: WARNING</li>
|
|
<li>4: ERROR</li>
|
|
</ul>
|
|
<p>Multiple filters can be defined in a single string, they just need to be
|
|
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
|
|
layer.</p>
|
|
<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>
|
|
<p>The format for an output can be one of those 3 forms:</p>
|
|
<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>
|
|
<li><code>x:file:file_path</code> output to a file, with the given
|
|
filepath</li>
|
|
<li><code>x:journald</code> output goes to systemd journal</li>
|
|
</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>
|
|
<p>Multiple output can be defined, they just need to be separated by
|
|
spaces, e.g.: <code>"3:syslog:libvirtd 1:file:/tmp/libvirt.log"</code>
|
|
will log all warnings and errors to syslog under the libvirtd ident
|
|
but also log all debug and information included in the
|
|
file <code>/tmp/libvirt.log</code></p>
|
|
|
|
<h2><a id="journald">Systemd journal fields</a></h2>
|
|
|
|
<p>
|
|
When logging to the systemd journal, the following fields
|
|
are defined, in addition to any automatically recorded
|
|
<a href="http://www.freedesktop.org/software/systemd/man/systemd.journal-fields.html">standard fields</a>:
|
|
</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>
|
|
<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>
|
|
</dl>
|
|
|
|
<h3><a id="journaldids">Well known message ID values</a></h3>
|
|
|
|
<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>
|
|
$ 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" }
|
|
</pre>
|
|
|
|
<h2>
|
|
<a id="log_examples">Examples</a>
|
|
</h2>
|
|
<p>For example setting up the following:</p>
|
|
<pre>export LIBVIRT_DEBUG=1
|
|
export LIBVIRT_LOG_OUTPUTS="1:file:virsh.log"</pre>
|
|
<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>
|
|
<p>To activate full debug of the libvirt entry points, utility
|
|
functions and the QEMU/KVM driver, set:</p>
|
|
<pre>log_filters="1:libvirt 1:util 1:qemu"
|
|
log_outputs="1:file:/var/log/libvirt/libvirtd.log"</pre>
|
|
<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>
|
|
</body>
|
|
</html>
|