Allow the logging APIs to be called with a va_list for format
args, instead of requiring var-args usage.
* src/util/logging.h, src/util/logging.c: Add virLogVMessage
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'.
This results in output like:
2012-05-09 14:18:45.136+0000: 13314: debug : virInitialize:414 : register drivers
/home/berrange/src/virt/libvirt/src/.libs/libvirt.so.0(virInitialize+0xd6)[0x7f89188ebe86]
/home/berrange/src/virt/libvirt/tools/.libs/lt-virsh[0x431921]
/lib64/libc.so.6(__libc_start_main+0xf5)[0x3a21e21735]
/home/berrange/src/virt/libvirt/tools/.libs/lt-virsh[0x40a279]
2012-05-09 14:18:45.136+0000: 13314: debug : virRegisterDriver:775 : driver=0x7f8918d02760 name=Test
/home/berrange/src/virt/libvirt/src/.libs/libvirt.so.0(virRegisterDriver+0x6b)[0x7f89188ec717]
/home/berrange/src/virt/libvirt/src/.libs/libvirt.so.0(+0x11b3ad)[0x7f891891e3ad]
/home/berrange/src/virt/libvirt/src/.libs/libvirt.so.0(virInitialize+0xf3)[0x7f89188ebea3]
/home/berrange/src/virt/libvirt/tools/.libs/lt-virsh[0x431921]
/lib64/libc.so.6(__libc_start_main+0xf5)[0x3a21e21735]
/home/berrange/src/virt/libvirt/tools/.libs/lt-virsh[0x40a279]
* docs/logging.html.in: Document new syntax
* configure.ac: Check for execinfo.h
* src/util/logging.c, src/util/logging.h: Add support for
stack traces
* tests/testutils.c: Adapt to API change
Signed-off-by: Daniel P. Berrange <berrange@redhat.com>
The field 'mon' in 'struct tm' gives months 0-11, where as
humans tend to expect months 1-12. Thus the month number
needing adjusting by 1
* src/util/logging.c: Use human friendly month number
We don't use the gnulib vsnprintf replacement, which means that
on mingw, vsnprintf doesn't support %zn or %lln.
And as it turns out, VIR_GET_VAR_STR was a rather inefficient
reimplementation of virVasprintf logic.
* src/util/logging.c (VIR_GET_VAR_STR): Drop.
(virLogMessage): Inline a simpler version here.
* src/util/virterror.c (VIR_GET_VAR_STR, virRaiseErrorFull):
Likewise.
Reported by Matthias Bolte.
These VIR_XXXX0 APIs make us confused, use the non-0-suffix APIs instead.
How do these coversions works? The magic is using the gcc extension of ##.
When __VA_ARGS__ is empty, "##" will swallow the "," in "fmt," to
avoid compile error.
example: origin after CPP
high_level_api("%d", a_int) low_level_api("%d", a_int)
high_level_api("a string") low_level_api("a string")
About 400 conversions.
8 special conversions:
VIR_XXXX0("") -> VIR_XXXX("msg") (avoid empty format) 2 conversions
VIR_XXXX0(string_literal_with_%) -> VIR_XXXX(%->%%) 0 conversions
VIR_XXXX0(non_string_literal) -> VIR_XXXX("%s", non_string_literal)
(for security) 6 conversions
Signed-off-by: Lai Jiangshan <laijs@cn.fujitsu.com>
We already have virAsprintf, so picking a similar name helps for
seeing a similar purpose. Furthermore, the prefix V before printf
generally implies 'va_list', even though this variant was '...', and
the old name got in the way of adding a new va_list version.
global rename performed with:
$ git grep -l virBufferVSprintf \
| xargs -L1 sed -i 's/virBufferVSprintf/virBufferAsprintf/g'
then revert the changes in ChangeLog-old.
gcc 4.6 warns when a variable is initialized but isn't used afterwards:
vmware/vmware_driver.c:449:18: warning: variable 'vmxPath' set but not used [-Wunused-but-set-variable]
This patch fixes these warnings. There are still 2 offending files:
- vbox_tmpl.c: the variable is used inside an #ifdef and is assigned several
times outside of #ifdef. Fixing the warning would have required wrapping
all the assignment inside #ifdef which hurts readability.
vbox/vbox_tmpl.c: In function 'vboxAttachDrives':
vbox/vbox_tmpl.c:3918:22: warning: variable 'accessMode' set but not used [-Wunused-but-set-variable]
- esx_vi_types.generated.c: the name implies it's generated code and I
didn't want to dive into the code generator
esx/esx_vi_types.generated.c: In function 'esxVI_FileQueryFlags_Free':
esx/esx_vi_types.generated.c:1203:3: warning: variable 'item' set but not used [-Wunused-but-set-variable]
qemu driver uses a 4K buffer for reading qemu log file. This is enough
when only qemu's output is present in the log file. However, when
debugging messages are turned on, intermediate libvirt process fills the
log with a bunch of debugging messages before it executes qemu binary.
In such a case the buffer may become too small. However, we are not
really interested in libvirt messages so they can be filtered out from
the buffer.
* src/util/logging.c (virLogStartup, virLogSetBufferSize):
Over-allocate, so that a debugger can just print the circular
buffer. Suggested by Daniel Veillard.
Valgrind caught that our log wrap-around was going 1 past the end.
Regression introduced in commit b16f47a; previously the
buffer was static and size+1 bytes, but now it is dynamic and
exactly size bytes.
* src/util/logging.c (virLogStr): Don't write past end of log.
As pointed out, locking the buffer from the signal handler
cannot been guaranteed to be safe, so to avoid any hazard
we prefer the trade off of dumping logs possibly messed up
by concurrent logging activity rather than risk a daemon
crash.
* src/util/logging.c: change virLogEmergencyDumpAll() to not
take any lock on the log buffer but reset buffer content variables
to an empty set before starting the actual dump.
This is the part allowing to dynamically resize the debug log
buffer from it's default 64kB size. The buffer is now dynamically
allocated.
It adds a new API virLogSetBufferSize() which resizes the buffer
If passed a zero size, the buffer is deallocated and we do the small
optimization of not formatting messages which are not output anymore.
On the daemon side, it just adds a new option log_buffer_size to
libvirtd.conf and call virLogSetBufferSize() if needed
* src/util/logging.h src/util/logging.c src/libvirt_private.syms:
make buffer dynamic and add virLogSetBufferSize() internal API
* daemon/libvirtd.conf: document the new log_buffer_size option
* daemon/libvirtd.c: read and use the new log_buffer_size option
Apparently some signals found on Unix are not exposed, this led
to a compilation failure
* src/util/logging.c: make code related to each signal dependant
upon the definition of that signal
* src/util/logging.c: fix virLogDumpAllFD() to avoid snprintf, simplify
the code and provide more useful signal descriptions. Also remove an
unused variable.
virLogEmergencyDumpAll() allows to dump the content of the
debug buffer from within a signal handler. It saves to all
log file or stderr if none is found
* src/util/logging.h src/util/logging.c: add the new API
and cleanup the old virLogDump code
* src/libvirt_private.syms: exports it as a private symbol
Initially only the log actually written out by libvirt were
saved on the memory buffer, this patch forces all informations
including info and debug to be saved in memory too. This is
useful to get full data in case of crash.
Followup to commit 17e19add, and would have prevented the bug
independently fixed in commit 76c57a7c.
* src/util/logging.c (virLogMessage): Preserve errno, since
logging should be as unintrusive as possible.
The logging functions are enhanced so that immediately prior to
the first log message being printed to any output channel, the
libvirt package version will be printed.
eg
$ LIBVIRT_DEBUG=1 virsh
18:13:28.013: 17536: info : libvirt version: 0.8.7
18:13:28.013: 17536: debug : virInitialize:361 : register drivers
...
The 'configure' script gains two new arguments which can be
used as
--with-packager="Fedora Project, x86-01.phx2.fedoraproject.org, 01-27-2011-18:00:10"
--with-packager-version="1.fc14"
to allow distros to append a custom string with package specific
data.
The RPM specfile is modified so that it appends the RPM version,
the build host, the build date and the packager name.
eg
$ LIBVIRT_DEBUG=1 virsh
18:14:52.086: 17551: info : libvirt version: 0.8.7, package: 1.fc13 (Fedora Project, x86-01.phx2.fedoraproject.org, 01-27-2011-18:00:10)
18:14:52.086: 17551: debug : virInitialize:361 : register drivers
Thus when distro packagers receive bug reports they can clearly
see what version was in use, even if the bug reporter mistakenly
or intentionally lies about version/builds
* src/util/logging.c: Output version data prior to first log message
* libvirt.spec.in: Include RPM release, date, hostname & packager
* configure.ac: Add --with-packager & --with-packager-version args
To allow messages from different threads to be untangled,
include an integer thread identifier in log messages.
* src/util/logging.c: Include thread ID
* src/util/threads.h, src/util/threads.h, src/util/threads-pthread.c:
Add new virThreadSelfID() function
* configure.ac: Check for sys/syscall.h
Using automated replacement with sed and editing I have now replaced all
occurrences of close() with VIR_(FORCE_)CLOSE() except for one, of
course. Some replacements were straight forward, others I needed to pay
attention. I hope I payed attention in all the right places... Please
have a look. This should have at least solved one more double-close
error.
Approximately 60 messages were marked. Since these diagnostics are
intended solely for developers and maintainers, encouraging translation
is deemed to be counterproductive:
http://thread.gmane.org/gmane.comp.emulators.libvirt/25050/focus=25052
Run this command:
git grep -l VIR_WARN|xargs perl -pi -e \
's/(VIR_WARN0?)\s*\(_\((".*?")\)/$1($2/'
Ad pointed out by Dan Berrange:
So if some thread in libvirtd is currently executing a logging call,
while another thread calls virExec(), that other thread no longer
exists in the child, but its lock is never released. So when the
child then does virLogReset() it deadlocks.
The only way I see to address this, is for the parent process to call
virLogLock(), immediately before fork(), and then virLogUnlock()
afterwards in both parent & child. This will ensure that no other
thread
can be holding the lock across fork().
* src/util/logging.[ch] src/libvirt_private.syms: export virLogLock() and
virLogUnlock()
* src/util/util.c: lock just before forking and unlock just after - in
both parent and child.
* src/util/logging.c (virLogMessage): Include "ignore-value.h".
Use it to ignore the return value of safewrite.
Use STDERR_FILENO, rather than "2".
* bootstrap (modules): Add ignore-value.
* gnulib: Update to latest, for ignore-value that is now LGPLv2+.
Replace free(virBufferContentAndReset()) with virBufferFreeAndReset().
Update documentation and replace all remaining calls to free() with
calls to VIR_FREE(). Also add missing calls to virBufferFreeAndReset()
and virReportOOMError() in OOM error cases.
* src/libvirt.c src/lxc/lxc_conf.c src/lxc/lxc_container.c
src/lxc/lxc_controller.c src/node_device/node_device_hal.c
src/openvz/openvz_conf.c src/qemu/qemu_driver.c
src/qemu/qemu_monitor_text.c src/remote/remote_driver.c
src/storage/storage_backend_disk.c src/storage/storage_driver.c
src/util/logging.c src/xen/sexpr.c src/xen/xend_internal.c
src/xen/xm_internal.c: Steve Grubb <sgrubb@redhat.com> sent a code
review and those are the fixes correcting the problems
When configuring logging settings, keep more information about the
output destination. Add accessors to retrieve the filter and output
settings in the original string form; this to be used to set up
environment for a child process that also logs.
* src/util/logging.[ch]: add virLogGetFilters and virLogGetOutputs
accessors and modify the internals (including virLogDefineOutput())
to save the data needed for the accessors
