[libvirt] [PATCH] Imprint all logs with version + package build information

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 --- configure.ac | 19 +++++++++++ libvirt.spec.in | 9 +++++ src/util/logging.c | 91 +++++++++++++++++++++++++++++++++++++++++++-------- 3 files changed, 104 insertions(+), 15 deletions(-) diff --git a/configure.ac b/configure.ac index 8a4083f..3cd824a 100644 --- a/configure.ac +++ b/configure.ac @@ -29,6 +29,25 @@ AC_SUBST([LIBVIRT_VERSION]) AC_SUBST([LIBVIRT_VERSION_INFO]) AC_SUBST([LIBVIRT_VERSION_NUMBER]) +AC_ARG_WITH([packager], + [AS_HELP_STRING([--with-packager], + [Extra packager name])], + [],[]) +AC_ARG_WITH([packager-version], + [AS_HELP_STRING([--with-packager-version], + [Extra packager version])], + [],[]) +if test "x$with_packager" != "xno" +then + AC_DEFINE_UNQUOTED([PACKAGER], ["$with_packager"], + [Extra package name]) +fi +if test "x$with_packager_version" != "xno" +then + AC_DEFINE_UNQUOTED([PACKAGER_VERSION], ["$with_packager_version"], + [Extra package version]) +fi + dnl Required minimum versions of all libs we depend on LIBXML_REQUIRED="2.6.0" GNUTLS_REQUIRED="1.0.25" diff --git a/libvirt.spec.in b/libvirt.spec.in index 0a2d10e..da1fe4a 100644 --- a/libvirt.spec.in +++ b/libvirt.spec.in @@ -592,6 +592,13 @@ of recent versions of Linux (and other OSes). %define _without_dtrace --without-dtrace %endif +%define when %(date +"%%m-%%d-%%Y-%%H:%%M:%%S") +%define where %(hostname) +%define who %{?packager}%{!?packager:Unknown} +%define with_packager --with-packager="%{who}, %{when}, %{where}" +%define with_packager_version --with-packager-version="%{release}" + + %configure %{?_without_xen} \ %{?_without_qemu} \ %{?_without_openvz} \ @@ -626,6 +633,8 @@ of recent versions of Linux (and other OSes). %{?_without_macvtap} \ %{?_without_audit} \ %{?_without_dtrace} \ + %{with_packager} \ + %{with_packager_version} \ --with-qemu-user=%{qemu_user} \ --with-qemu-group=%{qemu_group} \ --with-init-script=redhat \ diff --git a/src/util/logging.c b/src/util/logging.c index a80c3e3..85406bf 100644 --- a/src/util/logging.c +++ b/src/util/logging.c @@ -108,6 +108,7 @@ static int virLogNbFilters = 0; * after filtering, multiple output can be used simultaneously */ struct _virLogOutput { + bool logVersion; void *data; virLogOutputFunc f; virLogCloseFunc c; @@ -490,6 +491,7 @@ int virLogDefineOutput(virLogOutputFunc f, virLogCloseFunc c, void *data, goto cleanup; } ret = virLogNbOutputs++; + virLogOutputs[ret].logVersion = true; virLogOutputs[ret].f = f; virLogOutputs[ret].c = c; virLogOutputs[ret].data = data; @@ -501,6 +503,55 @@ cleanup: return ret; } +static int +virLogFormatString(char **msg, + const char *funcname, + long long linenr, + struct tm *time_info, + struct timeval *cur_time, + int priority, + const char *str) +{ + int ret; + if ((funcname != NULL)) { + ret = virAsprintf(msg, "%02d:%02d:%02d.%03d: %d: %s : %s:%lld : %s\n", + time_info->tm_hour, time_info->tm_min, + time_info->tm_sec, (int) cur_time->tv_usec / 1000, + virThreadSelfID(), + virLogPriorityString(priority), funcname, linenr, str); + } else { + ret = virAsprintf(msg, "%02d:%02d:%02d.%03d: %d: %s : %s\n", + time_info->tm_hour, time_info->tm_min, + time_info->tm_sec, (int) cur_time->tv_usec / 1000, + virThreadSelfID(), + virLogPriorityString(priority), str); + } + return ret; +} + +static int +virLogVersionString(char **msg, + struct tm *time_info, + struct timeval *cur_time) +{ +#ifdef PACKAGER_VERSION +# ifdef PACKAGER +# define LOG_VERSION_STRING \ + "libvirt version: " VERSION ", package: " PACKAGER_VERSION " (" PACKAGER ")" +# else +# define LOG_VERSION_STRING \ + "libvirt version: " VERSION ", package: " PACKAGER_VERSION +# endif +#else +# define LOG_VERSION_STRING \ + "libvirt version: " VERSION +#endif + + return virLogFormatString(msg, NULL, 0, + time_info, cur_time, + VIR_LOG_INFO, LOG_VERSION_STRING); +} + /** * virLogMessage: * @category: where is that message coming from @@ -516,6 +567,7 @@ cleanup: */ void virLogMessage(const char *category, int priority, const char *funcname, long long linenr, int flags, const char *fmt, ...) { + static bool logVersionStderr = true; char *str = NULL; char *msg; struct timeval cur_time; @@ -547,19 +599,9 @@ void virLogMessage(const char *category, int priority, const char *funcname, gettimeofday(&cur_time, NULL); localtime_r(&cur_time.tv_sec, &time_info); - if ((funcname != NULL)) { - ret = virAsprintf(&msg, "%02d:%02d:%02d.%03d: %d: %s : %s:%lld : %s\n", - time_info.tm_hour, time_info.tm_min, - time_info.tm_sec, (int) cur_time.tv_usec / 1000, - virThreadSelfID(), - virLogPriorityString(priority), funcname, linenr, str); - } else { - ret = virAsprintf(&msg, "%02d:%02d:%02d.%03d: %d: %s : %s\n", - time_info.tm_hour, time_info.tm_min, - time_info.tm_sec, (int) cur_time.tv_usec / 1000, - virThreadSelfID(), - virLogPriorityString(priority), str); - } + ret = virLogFormatString(&msg, funcname, linenr, + &time_info, &cur_time, + priority, str); VIR_FREE(str); if (ret < 0) { /* apparently we're running out of memory */ @@ -578,12 +620,31 @@ void virLogMessage(const char *category, int priority, const char *funcname, virLogStr(msg, len); virLogLock(); for (i = 0; i < virLogNbOutputs;i++) { - if (priority >= virLogOutputs[i].priority) + if (priority >= virLogOutputs[i].priority) { + if (virLogOutputs[i].logVersion) { + char *ver = NULL; + if (virLogVersionString(&ver, &time_info, &cur_time) >= 0) + virLogOutputs[i].f(category, priority, __func__, __LINE__, + ver, strlen(ver), + virLogOutputs[i].data); + VIR_FREE(ver); + virLogOutputs[i].logVersion = false; + } virLogOutputs[i].f(category, priority, funcname, linenr, msg, len, virLogOutputs[i].data); + } } - if ((virLogNbOutputs == 0) && (flags != 1)) + if ((virLogNbOutputs == 0) && (flags != 1)) { + if (logVersionStderr) { + char *ver = NULL; + if (virLogVersionString(&ver, &time_info, &cur_time) >= 0) + ignore_value (safewrite(STDERR_FILENO, + ver, strlen(ver))); + VIR_FREE(ver); + logVersionStderr = false; + } ignore_value (safewrite(STDERR_FILENO, msg, len)); + } virLogUnlock(); VIR_FREE(msg); -- 1.7.3.5

On 02/02/2011 05:18 AM, Daniel P. Berrange wrote:
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.
git send-email --subject-prefix=PATCHv2 is a neat trick, as is summarizing the difference from v1. I don't have the gnulib version-etc module licensing issue sorted yet, but now that your ./configure options match those of gnulib, I'm happier with it; and I'd rather see this go in sooner than later (we can tweak it later to take advantage of gnulib, if gnulib improves).
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"
Confirm that this matches coreutils' ./configure option.
+++ b/libvirt.spec.in @@ -592,6 +592,13 @@ of recent versions of Linux (and other OSes). %define _without_dtrace --without-dtrace %endif
+%define when %(date +"%%m-%%d-%%Y-%%H:%%M:%%S")
That's US-centric. Can't we instead go with ISO format of year first, to avoid the ambiguities of US vs Europe on the first 12 days of a given month? And, since the .spec file runs on a system where we are guaranteed that date is POSIX-compliant, we can use the shorter: %(date +"%%F-%%T")
@@ -578,12 +620,31 @@ void virLogMessage(const char *category, int priority, const char *funcname, virLogStr(msg, len); virLogLock(); for (i = 0; i < virLogNbOutputs;i++) { - if (priority >= virLogOutputs[i].priority) + if (priority >= virLogOutputs[i].priority) { + if (virLogOutputs[i].logVersion) { + char *ver = NULL; + if (virLogVersionString(&ver, &time_info, &cur_time) >= 0) + virLogOutputs[i].f(category, priority, __func__, __LINE__, + ver, strlen(ver), + virLogOutputs[i].data);
This says the version string is logged at the same priority as the first call to virLogMessage; shouldn't it instead be a fixed priority?
+ VIR_FREE(ver); + virLogOutputs[i].logVersion = false;
And if you switch to a fixed priority, should setting virLogOutputs[i].logVersion to false be dependent on whether the callback function virLogOutputs[i].f() actually output the version string? ACK with those nits addressed. -- Eric Blake eblake@redhat.com +1-801-349-2682 Libvirt virtualization library http://libvirt.org

On Wed, Feb 02, 2011 at 09:43:28AM -0700, Eric Blake wrote:
On 02/02/2011 05:18 AM, Daniel P. Berrange wrote:
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.
git send-email --subject-prefix=PATCHv2 is a neat trick, as is summarizing the difference from v1. I don't have the gnulib version-etc module licensing issue sorted yet, but now that your ./configure options match those of gnulib, I'm happier with it; and I'd rather see this go in sooner than later (we can tweak it later to take advantage of gnulib, if gnulib improves).
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"
Confirm that this matches coreutils' ./configure option.
+++ b/libvirt.spec.in @@ -592,6 +592,13 @@ of recent versions of Linux (and other OSes). %define _without_dtrace --without-dtrace %endif
+%define when %(date +"%%m-%%d-%%Y-%%H:%%M:%%S")
That's US-centric. Can't we instead go with ISO format of year first, to avoid the ambiguities of US vs Europe on the first 12 days of a given month? And, since the .spec file runs on a system where we are guaranteed that date is POSIX-compliant, we can use the shorter:
%(date +"%%F-%%T")
Opps, US date format was not intentional. I wanted the international format.
@@ -578,12 +620,31 @@ void virLogMessage(const char *category, int priority, const char *funcname, virLogStr(msg, len); virLogLock(); for (i = 0; i < virLogNbOutputs;i++) { - if (priority >= virLogOutputs[i].priority) + if (priority >= virLogOutputs[i].priority) { + if (virLogOutputs[i].logVersion) { + char *ver = NULL; + if (virLogVersionString(&ver, &time_info, &cur_time) >= 0) + virLogOutputs[i].f(category, priority, __func__, __LINE__, + ver, strlen(ver), + virLogOutputs[i].data);
This says the version string is logged at the same priority as the first call to virLogMessage; shouldn't it instead be a fixed priority?
Good point, we should log at 'info' really.
+ VIR_FREE(ver); + virLogOutputs[i].logVersion = false;
And if you switch to a fixed priority, should setting virLogOutputs[i].logVersion to false be dependent on whether the callback function virLogOutputs[i].f() actually output the version string?
I guess so Daniel -- |: http://berrange.com -o- http://www.flickr.com/photos/dberrange/ :| |: http://libvirt.org -o- http://virt-manager.org :| |: http://autobuild.org -o- http://search.cpan.org/~danberr/ :| |: http://entangle-photo.org -o- http://live.gnome.org/gtk-vnc :|

On Wed, Feb 02, 2011 at 04:50:21PM +0000, Daniel P. Berrange wrote:
On Wed, Feb 02, 2011 at 09:43:28AM -0700, Eric Blake wrote:
On 02/02/2011 05:18 AM, Daniel P. Berrange wrote:
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.
git send-email --subject-prefix=PATCHv2 is a neat trick, as is summarizing the difference from v1. I don't have the gnulib version-etc module licensing issue sorted yet, but now that your ./configure options match those of gnulib, I'm happier with it; and I'd rather see this go in sooner than later (we can tweak it later to take advantage of gnulib, if gnulib improves).
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"
Confirm that this matches coreutils' ./configure option.
+++ b/libvirt.spec.in @@ -592,6 +592,13 @@ of recent versions of Linux (and other OSes). %define _without_dtrace --without-dtrace %endif
+%define when %(date +"%%m-%%d-%%Y-%%H:%%M:%%S")
That's US-centric. Can't we instead go with ISO format of year first, to avoid the ambiguities of US vs Europe on the first 12 days of a given month? And, since the .spec file runs on a system where we are guaranteed that date is POSIX-compliant, we can use the shorter:
%(date +"%%F-%%T")
Opps, US date format was not intentional. I wanted the international format.
@@ -578,12 +620,31 @@ void virLogMessage(const char *category, int priority, const char *funcname, virLogStr(msg, len); virLogLock(); for (i = 0; i < virLogNbOutputs;i++) { - if (priority >= virLogOutputs[i].priority) + if (priority >= virLogOutputs[i].priority) { + if (virLogOutputs[i].logVersion) { + char *ver = NULL; + if (virLogVersionString(&ver, &time_info, &cur_time) >= 0) + virLogOutputs[i].f(category, priority, __func__, __LINE__, + ver, strlen(ver), + virLogOutputs[i].data);
This says the version string is logged at the same priority as the first call to virLogMessage; shouldn't it instead be a fixed priority?
Good point, we should log at 'info' really.
I pushed this with the change to VIR_LOG_INFO
+ VIR_FREE(ver); + virLogOutputs[i].logVersion = false;
And if you switch to a fixed priority, should setting virLogOutputs[i].logVersion to false be dependent on whether the callback function virLogOutputs[i].f() actually output the version string?
I guess so
Actually this wasn't needed, because the 'output' functions don't do any filtering of their own. Daniel -- |: http://berrange.com -o- http://www.flickr.com/photos/dberrange/ :| |: http://libvirt.org -o- http://virt-manager.org :| |: http://autobuild.org -o- http://search.cpan.org/~danberr/ :| |: http://entangle-photo.org -o- http://live.gnome.org/gtk-vnc :|
participants (2)
-
Daniel P. Berrange
-
Eric Blake