Same as for outputs, introduce a new method, that is basically the same as
virLogParseAndDefineFilter with the difference that it does not define the
filter. It rather returns a newly created object that needs to be inserted into
a list and then defined separately.
Signed-off-by: NErik Skultety <eskultet@redhat.com>

Introduce a method to parse an individual logging output. The difference
compared to the virLogParseAndDefineOutput is that this method does not define
the output, instead it makes use of the virLogNewOutputTo* methods introduced
in the previous patch and just returns the virLogOutput object that has to be
added to a list of object which then can be defined as a whole via
virLogDefineOutputs. The idea remains still the same - split parsing and
defining of the logging primitives (outputs, filters).
Additionally, since virLogNewOutputTo* methods are now finally used,
ATTRIBUTE_UNUSED can be successfully removed from the methods' definitions,
since that was just to avoid compiler complaints about unused static functions.
Signed-off-by: NErik Skultety <eskultet@redhat.com>

Now that we're in the critical section, syslog connection can be re-opened
by issuing openlog, which is something that cannot be done beforehand, since
syslog keeps its file descriptor private and changing the tag earlier might
introduce a log inconsistency if something went wrong with preparing a new set
of logging outputs in order to replace the existing one.
Signed-off-by: NErik Skultety <eskultet@redhat.com>

Continuing with the effort to split output parsing and defining, these new
functions return a logging object reference instead of defining the output.
Eventually, these functions will replace the existing ones (virLogAddOutputTo*)
which will then be dropped.
Signed-off-by: NErik Skultety <eskultet@redhat.com>

Prepare a method that only defines a set of filters. It takes a list of
filters, preferably created by virLogParseFilters. The original set of filters
is reset and replaced by the new user-provided set of filters.
Signed-off-by: NErik Skultety <eskultet@redhat.com>

Prepare a method that only defines a set of outputs. It takes a list of
outputs, preferably created by virLogParseOutputs. The original set of outputs
is reset and replaced by the new user-provided set of outputs.
Signed-off-by: NErik Skultety <eskultet@redhat.com>

Outputs are a bit trickier than filters, since the user(config)-specified
set of outputs can contain duplicates. That would lead to logging the same
message twice. For compatibility reasons, we cannot just error out and forbid
the daemon to start if we find duplicate outputs which do not make sense.
Instead, we could silently take into account only the last occurrence of the
duplicate output and remove all the previous ones, so that the logger will not
try to use them when it is looping over all of its registered outputs.
Signed-off-by: NErik Skultety <eskultet@redhat.com>

This method allocates a new filter object which it then returns back to caller.
Signed-off-by: NErik Skultety <eskultet@redhat.com>

In order to later split output parsing and output defining, introduce a new
function which will create a new virLogOutput object which the parser will
insert into a list with the list being eventually defined.
Signed-off-by: NErik Skultety <eskultet@redhat.com>

There is really no reason why we could not keep journald's fd within the
journald output object the same way as we do for regular file-based outputs.
By doing this we later won't have to special case the journald-based output
(due to the fd being globally shared) when replacing the existing set of outputs
with a new one. Additionally, by making this change, we don't need the
virLogCloseJournald routine anymore, plain virLogCloseFd will suffice.
Signed-off-by: NErik Skultety <eskultet@redhat.com>

Right now virLogParse* functions are doing both parsing and defining of filters
and outputs which should be two separate operations. Since the naming is
apparently a bit poor this patch renames these functions to
virLogParseAndDefine* which eventually will be replaced by virLogSet*.
Additionally, virLogParse{Filter,Output} will be later (after the split) reused,
so that these functions do exactly what the their name suggests.
Signed-off-by: NErik Skultety <eskultet@redhat.com>

During first stage of virlog.c refactor, commit 0b231195 forgot to remove the
macro definition along with its usage.
Signed-off-by: NErik Skultety <eskultet@redhat.com>

When a new filter is being defined, the return code is not handled properly,
thus triggering OOM error reporting routine (bug introduced by 51b2606f).
Signed-off-by: NErik Skultety <eskultet@redhat.com>

This is just a convenience method for discarding a list of filters instead of
using a 'for' loop everywhere. It is safe to pass -1 as the number of elements
in the list as well as passing NULL as list reference.
Signed-off-by: NErik Skultety <eskultet@redhat.com>

Provide a separate method to free a logging filter object. This will come handy
once a method to create an individual logging filter object is introduced.
Signed-off-by: NErik Skultety <eskultet@redhat.com>

This is just a convenience method for discarding a list of outputs instead of
using a 'for' loop everywhere. It is safe to pass -1 as the number of elements
in the list as well as passing NULL as list reference.
Signed-off-by: NErik Skultety <eskultet@redhat.com>

Provide a separate method to free a logging output object. This will come handy
once a method to create an individual logging output object is introduced.
Signed-off-by: NErik Skultety <eskultet@redhat.com>

Same as with outputs; since the operations will be further divided into smaller
tasks, creating a filter will become a separate operation that will return
a reference to a newly created filter.
Signed-off-by: NErik Skultety <eskultet@redhat.com>

Right now, we define outputs one after another. However, the correct flow
should be to define a set of outputs as a whole unit. Therefore each output
should be first created, placed into an array/list and the list will be
defined. Output creation should be a separate operation, so an output will be
returned by a reference. From that perspective, it makes perfect sense to
only store pointers to actual outputs.
Signed-off-by: NErik Skultety <eskultet@redhat.com>

In this particular case, reset is meant as clearing the whole list of
outputs/filters, not resetting it to a predefined default setting. Looking at
it from that perspective, returning the number of records removed doesn't help
the caller in any way (not that any of the callers would actually check for
it). Well, callers could detect an error from the number of successfully
removed records, but the only thing that can fail in virLogReset is force
closing a file descriptor in which case the error isn't propagated back to
virLogReset anyway. Conclusion: there is no practical use for having a return
type of 'int' rather than 'void' in this case.
Signed-off-by: NErik Skultety <eskultet@redhat.com>

Patch 0b231195 refactored logging output parser to make it more readable.
This patch does similar thing to logging filter parser.

Refactor series 0b231195 worked with virLogDestination type which, depending
on the compiler, might be (and probably will be) an unsigned data type.
However, virEnumFromString may return -1 in case of an error. So, when enum
happens to be unsigned, some compilers will naturally complain about foo:
    'if (foo < 0)'

The problem with the original virLogParseOutputs method was that the way it
parsed the input, walking the string char by char and using absolute jumps
depending on the virLogDestination type, was rather complicated to read.
This patch utilizes virStringSplit method twice, first time to filter out any
spaces and split the input to individual log outputs and then for each
individual output to tokenize it by to the parts according to our
PRIORITY:DESTINATION?(:DATA) format. Also, to STREQLEN for matching destination
was replaced with virDestinationTypeFromString call.

In order to refactor the ugly virLogParseOutputs method, this is a neat way of
finding out whether the destination type (in the form of a string) user
provided is a valid one. As a bonus, if it turns out it is valid, we get the
actual enum which will later be passed to any of virLogAddOutput methods right
away.

Instead of misusing a const string to hold up runtime allocated
data, introduce new variable @hoststr and obey const correctness.

==6879== 15 bytes in 1 blocks are definitely lost in loss record 68 of 1,064
==6879==    at 0x4C29F80: malloc (in /usr/lib64/valgrind/vgpreload_memcheck-amd64-linux.so)
==6879==    by 0xA7DDF97: vasprintf (in /lib64/libc-2.21.so)
==6879==    by 0x552BBC6: virVasprintfInternal (virstring.c:493)
==6879==    by 0x552BCDB: virAsprintfInternal (virstring.c:514)
==6879==    by 0x54FA44C: virLogHostnameString (virlog.c:468)
==6879==    by 0x54FAB0F: virLogVMessage (virlog.c:645)
==6879==    by 0x54FA680: virLogMessage (virlog.c:531)
==6879==    by 0x54FBBF4: virLogParseOutputs (virlog.c:1130)
==6879==    by 0x11CB4F: daemonSetupLogging (libvirtd.c:685)
==6879==    by 0x11E137: main (libvirtd.c:1297)
Signed-off-by: NMichal Privoznik <mprivozn@redhat.com>

Once @hostname is printed into @hoststr we don't need it anymore.

==6879== 5 bytes in 1 blocks are definitely lost in loss record 10 of 1,064
==6879==    at 0x4C29F80: malloc (in /usr/lib64/valgrind/vgpreload_memcheck-amd64-linux.so)
==6879==    by 0xA7ED599: strdup (in /lib64/libc-2.21.so)
==6879==    by 0x552C126: virStrdup (virstring.c:726)
==6879==    by 0x553B13E: virGetHostnameImpl (virutil.c:720)
==6879==    by 0x553B1BF: virGetHostnameQuiet (virutil.c:741)
==6879==    by 0x54FA3FD: virLogHostnameString (virlog.c:462)
==6879==    by 0x54FAB0F: virLogVMessage (virlog.c:645)
==6879==    by 0x54FA680: virLogMessage (virlog.c:531)
==6879==    by 0x54FBBF4: virLogParseOutputs (virlog.c:1130)
==6879==    by 0x11CB4F: daemonSetupLogging (libvirtd.c:685)
==6879==    by 0x11E137: main (libvirtd.c:1297)
Signed-off-by: NMichal Privoznik <mprivozn@redhat.com>

On the very first log message we send to any output, we include
the libvirt version number and package string. In some bug reports
we have been given libvirtd.log files that came from a different
host than the corresponding /var/log/libvirt/qemu log files. So
extend the initial log message to include the hostname too.

eg on first log message we would now see:

 $ libvirtd
 2015-12-04 17:35:36.610+0000: 20917: info : libvirt version: 1.3.0
 2015-12-04 17:35:36.610+0000: 20917: info : hostname: dhcp-1-180.lcy.redhat.com
 2015-12-04 17:35:36.610+0000: 20917: error : qemuMonitorIO:687 : internal error: End of file from monitor
Signed-off-by: NDaniel P. Berrange <berrange@redhat.com>

otherwise messages end up in /var/log/kern.log if journald forwards to
syslog.

Reference: https://bugs.debian.org/cgi-bin/bugreport.cgi?bug=799633

It is often helpful to know which version of libvirt and QEMU
was present when a guest was first launched. Ensure this info
is written into the QEMU log file for each guest.

Signed-off-by: NMartin Kletzander <mkletzan@redhat.com>

C guarantees that static variables are zero-initialized.  Some older
compilers (and also gcc -fno-zero-initialized-in-bss) create larger
binaries if you explicitly zero-initialize a static variable.

* src/libvirt.c: Fix initialization.
* src/util/viralloc.c: Likewise.
* src/util/virdbus.c: Likewise.
* src/util/virevent.c: Likewise.
* src/util/virfile.c (safezero): Likewise.
* src/util/virlog.c: Likewise.
* src/util/virnetlink.c: Likewise.
* src/util/virthread.h (VIR_ONCE_GLOBAL_INIT): Likewise.
* src/util/virprocess.c (virProcessGetStartTime): Likewise.
Signed-off-by: NEric Blake <eblake@redhat.com>

Recent changes to the module seemed to have caused Coverity to find a new
issue regarding the failure to check the return from a sendmsg. The code
doesn't seem to care about the return status, so just added an ignore_value
to keep Coverity quiet.

virLogParseDefaultPriority's successful return value is the same as
virLogSetDefaultPriority's successful return value. So it should be 0
rather than the parsed log level.
Signed-off-by: NZhou Yimin <zhouyimin@huawei.com>

A earlier commit changed the global log buffer so that it only
records messages that are explicitly requested via the log
filters setting. This removes the performance burden, and
improves the signal/noise ratio for messages in the global
buffer. At the same time though, it is somewhat pointless, since
all the recorded log messages are already going to be sent to an
explicit log output like syslog, stderr or the journal. The
global log buffer is thus just duplicating this data on stderr
upon crash.

The log_buffer_size config parameter is left in the augeas
lens to prevent breakage for users on upgrade. It is however
completely ignored hereafter.
Signed-off-by: NDaniel P. Berrange <berrange@redhat.com>

Currently the log filter strings are used in a string comparison
against the source filename each time log message is emitted.
If no log filters at all are set, there's obviously no string
comparison to be done. If any single log filter is set though,
this imposes a compute burden on every logging call even if logs
from the file in question are disabled. This string comparison
must also be done while the logging mutex is held, which has
implications for concurrency when multiple threads are emitting
log messages.

This changes the log filtering to be done based on the virLogSource
object name. The virLogSource struct is extended to contain
'serial' and 'priority' fields. Any time the global log filter
rules are changed a global serial number is incremented. When a
log message is emitted, the serial in the virLogSource instance
is compared with the global serial number. If out of date, then
the 'priority' field in the virLogSource instance is updated based
on the new filter rules. The 'priority' field is checked to see
whether the log message should be sent to the log outputs.

The comparisons of the 'serial' and 'priority' fields are done
with no locks held. So in the common case each logging call has
an overhead of 2 integer comparisons, with no locks held. Only
if the decision is made to forward the message to the log output,
or if the 'serial' value is out of date do locks need to be
acquired.

Technically the comparisons of the 'serial' and 'priority' fields
should be done with locks held, or using atomic operations. Both
of these options have a notable performance impact, however, and
since all writes a protected by a global mutex, it is believed
that worst case behaviour where the fields are read concurrently
with being written would merely result in an mistaken emission
or dropping of the log message in question. This is an acceptable
tradeoff for the performance benefit of avoiding locking.

As a quick benchmark, a demo program that registers 500 file
descriptors with the event loop (eg equiv of 500 QEMU monitor
commands), creates pending read I/O on every FD, and then runs
virEventRunDefaultImpl() took 4.6 seconds to do 51200 iterations.
After this optimization it only takes 3.3 seconds, with the log
APIs no longer being a relevant factor in the running time.
Signed-off-by: NDaniel P. Berrange <berrange@redhat.com>

Any source file which calls the logging APIs now needs
to have a VIR_LOG_INIT("source.name") declaration at
the start of the file. This provides a static variable
of the virLogSource type.
Signed-off-by: NDaniel P. Berrange <berrange@redhat.com>

As part of the goal to get away from doing string matching on
filenames when deciding whether to emit a log message, turn
the virLogSource enum into a struct which contains a log
"name". There will eventually be one virLogSource instance
statically declared per source file. To minimise churn in this
commit though, a single global instance is used.
Signed-off-by: NDaniel P. Berrange <berrange@redhat.com>

The error reporting code will invoke a callback when any error
is raised and the default callback will print to stderr. The
virRaiseErrorFull method also sends all error messages on to the
logging code, which also prints to stderr by default. To avoid
duplicated data on stderr, the logging code has some logic to
skip emission when no log outputs are configured, which checks
whether the virLogSource == VIR_LOG_FROM_ERROR.

Meanwhile the libvirtd daemon can register another callback which
is used to reduce log message priority from error to a lower level.
When this is used we do want messages to end up on stderr, so the
error code will conditionally use either VIR_LOG_FROM_FILE or
VIR_LOG_FROM_ERROR depending on whether such a callback is provided.

This will all complicate later refactoring. By pushing the checks
for whether a log output is present up a level into the error code,
the special cases can be isolated in one place.
Signed-off-by: NDaniel P. Berrange <berrange@redhat.com>

With the vast number of log debug statements in the code, the
logging framework has a measurable performance impact on libvirt
code, particularly in the daemon event loop.

The global log buffer records every single log message triggered
whether anyone cares to see them or not. This makes it impossible
to eliminate the overhead of printf format expansions in any of
the logging code. It is possible to disable the global log buffer
in libvirtd itself, but this doesn't help client side library
code. Also even if disabled by the config file, the existence of
the feature makes other performance improvements in the logging
layer impossible.

Instead of logging every single message to the global buffer, only
log messages that pass the log filters. This if libvirtd is set
to have log_filters="1:libvirt 1:qemu" the global log buffer will
only get filled with those messages instead of everything. This
reduces the performance burden, as well as improving the signal
to noise ratio of the log buffer.

As a quick benchmark, a demo program that registers 500 file
descriptors with the event loop (eg equiv of 500 QEMU monitor
commands), creates pending read I/O on every FD, and then runs
virEventRunDefaultImpl() took 1 minute 40 seconds to do 51200
iterations with nearly all the time shown against the logging
code. After this optimization it only takes 4.6 seconds.
Signed-off-by: NDaniel P. Berrange <berrange@redhat.com>