[libvirt] [PATCH 0/4] Improve logging when QEMU caps fails
This improves the logging when we have a failure to probe QEMU capabilities for any binary. Daniel P. Berrange (4): Send virLogMetadata fields onto the journal Include error domain and code in log messages from errors Add comments describing the different log sources Generate a unique journald log for QEMU capabilities failure src/qemu/qemu_capabilities.c | 28 ++++++++++++++++++++++++++-- src/util/virerror.c | 8 +++++++- src/util/virlog.c | 18 ++++++++++++++++-- src/util/virlog.h | 10 +++++----- 4 files changed, 54 insertions(+), 10 deletions(-) -- 1.8.5.3
The systemd journal accepts arbitrary user specified log fields. These can be passed into virLogMessage via the virLogMetadata structure. Allow upto 5 custom fields to be reported by libvirt callers. Signed-off-by: Daniel P. Berrange <berrange@redhat.com> --- src/util/virlog.c | 18 ++++++++++++++++-- 1 file changed, 16 insertions(+), 2 deletions(-) diff --git a/src/util/virlog.c b/src/util/virlog.c index 32714ce..b8f539e 100644 --- a/src/util/virlog.c +++ b/src/util/virlog.c @@ -1153,7 +1153,7 @@ virLogOutputToJournald(virLogSource source, int linenr, const char *funcname, const char *timestamp ATTRIBUTE_UNUSED, - virLogMetadataPtr metadata ATTRIBUTE_UNUSED, + virLogMetadataPtr metadata, unsigned int flags, const char *rawstr, const char *str ATTRIBUTE_UNUSED, @@ -1172,8 +1172,11 @@ virLogOutputToJournald(virLogSource source, * be a tmpfs, and one that is available from early boot on * and where unprivileged users can create files. */ char path[] = "/dev/shm/journal.XXXXXX"; + size_t nmetadata = 0; -# define NUM_FIELDS 6 +# define NUM_FIELDS_CORE 6 +# define NUM_FIELDS_META 5 +# define NUM_FIELDS (NUM_FIELDS_CORE + NUM_FIELDS_META) struct iovec iov[NUM_FIELDS * 5]; char iov_bufs[NUM_FIELDS][JOURNAL_BUF_SIZE]; struct journalState state; @@ -1192,6 +1195,17 @@ virLogOutputToJournald(virLogSource source, journalAddInt(&state, "CODE_LINE", linenr); if (funcname) journalAddString(&state, "CODE_FUNC", funcname); + if (metadata != NULL) { + while (metadata->key != NULL && + nmetadata < NUM_FIELDS_META) { + if (metadata->s != NULL) + journalAddString(&state, metadata->key, metadata->s); + else + journalAddInt(&state, metadata->key, metadata->iv); + metadata++; + nmetadata++; + } + } memset(&sa, 0, sizeof(sa)); sa.sun_family = AF_UNIX; -- 1.8.5.3
On 02/21/2014 10:31 AM, Daniel P. Berrange wrote:
The systemd journal accepts arbitrary user specified log fields. These can be passed into virLogMessage via the virLogMetadata structure. Allow upto 5 custom fields to
s/upto/up to/
be reported by libvirt callers.
Signed-off-by: Daniel P. Berrange <berrange@redhat.com> --- src/util/virlog.c | 18 ++++++++++++++++-- 1 file changed, 16 insertions(+), 2 deletions(-)
ACK -- Eric Blake eblake redhat com +1-919-301-3266 Libvirt virtualization library http://libvirt.org
When a virError is raised, pass the error domain and code onto the systemd journald using metadata fields. This allows error messages to be queried by code eg $ journalctl LIBVIRT_CODE=43 Signed-off-by: Daniel P. Berrange <berrange@redhat.com> --- src/util/virerror.c | 8 +++++++- 1 file changed, 7 insertions(+), 1 deletion(-) diff --git a/src/util/virerror.c b/src/util/virerror.c index 74c6807..820e1ad 100644 --- a/src/util/virerror.c +++ b/src/util/virerror.c @@ -649,6 +649,11 @@ virRaiseErrorFull(const char *filename ATTRIBUTE_UNUSED, virErrorPtr to; char *str; int priority; + virLogMetadata meta[] = { + { .key = "LIBVIRT_DOMAIN", .s = NULL, .iv = domain }, + { .key = "LIBVIRT_CODE", .s = NULL, .iv = code }, + { .key = NULL }, + }; /* * All errors are recorded in thread local storage @@ -703,10 +708,11 @@ virRaiseErrorFull(const char *filename ATTRIBUTE_UNUSED, priority = virErrorLevelPriority(level); if (virErrorLogPriorityFilter) priority = virErrorLogPriorityFilter(to, priority); + virLogMessage(virErrorLogPriorityFilter ? VIR_LOG_FROM_FILE : VIR_LOG_FROM_ERROR, priority, filename, linenr, funcname, - NULL, "%s", str); + meta, "%s", str); errno = save_errno; } -- 1.8.5.3
Signed-off-by: Daniel P. Berrange <berrange@redhat.com> --- src/util/virlog.h | 10 +++++----- 1 file changed, 5 insertions(+), 5 deletions(-) diff --git a/src/util/virlog.h b/src/util/virlog.h index f400824..6ba2daa 100644 --- a/src/util/virlog.h +++ b/src/util/virlog.h @@ -45,11 +45,11 @@ typedef enum { } virLogDestination; typedef enum { - VIR_LOG_FROM_FILE, - VIR_LOG_FROM_ERROR, - VIR_LOG_FROM_AUDIT, - VIR_LOG_FROM_TRACE, - VIR_LOG_FROM_LIBRARY, + VIR_LOG_FROM_FILE, /* General debugging */ + VIR_LOG_FROM_ERROR, /* Errors reported */ + VIR_LOG_FROM_AUDIT, /* Audit operations */ + VIR_LOG_FROM_TRACE, /* DTrace probe pointers */ + VIR_LOG_FROM_LIBRARY, /* 3rd party libraries */ VIR_LOG_FROM_LAST, } virLogSource; -- 1.8.5.3
On 02/21/2014 10:31 AM, Daniel P. Berrange wrote:
Signed-off-by: Daniel P. Berrange <berrange@redhat.com> --- src/util/virlog.h | 10 +++++----- 1 file changed, 5 insertions(+), 5 deletions(-)
ACK
diff --git a/src/util/virlog.h b/src/util/virlog.h index f400824..6ba2daa 100644 --- a/src/util/virlog.h +++ b/src/util/virlog.h @@ -45,11 +45,11 @@ typedef enum { } virLogDestination;
typedef enum { - VIR_LOG_FROM_FILE, - VIR_LOG_FROM_ERROR, - VIR_LOG_FROM_AUDIT, - VIR_LOG_FROM_TRACE, - VIR_LOG_FROM_LIBRARY, + VIR_LOG_FROM_FILE, /* General debugging */ + VIR_LOG_FROM_ERROR, /* Errors reported */ + VIR_LOG_FROM_AUDIT, /* Audit operations */ + VIR_LOG_FROM_TRACE, /* DTrace probe pointers */ + VIR_LOG_FROM_LIBRARY, /* 3rd party libraries */
VIR_LOG_FROM_LAST, } virLogSource;
-- Eric Blake eblake redhat com +1-919-301-3266 Libvirt virtualization library http://libvirt.org
When probing QEMU capabilities fails for a binary generate a log message with MESSAGE_ID==8ae2f3fb-2dbe-498e-8fbd-012d40afa361. This can be directly queried from journald based on the UUID instead of needing string grep. This lets tools like libguestfs' bug reporting tool trivially do automated sanity tests on the host they're running on. $ journalctl MESSAGE_ID=8ae2f3fb-2dbe-498e-8fbd-012d40afa361 Feb 21 17:11:01 localhost.localdomain lt-libvirtd[9196]: Failed to probe capabilities for /bin/qemu-system-alpha: 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-alpha -help) unexpected exit status 127: /bin/qemu-system-alpha: error while loading shared libraries: libglapi.so.0: cannot open shared object file: No such file or directory $ 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" } Signed-off-by: Daniel P. Berrange <berrange@redhat.com> --- src/qemu/qemu_capabilities.c | 28 ++++++++++++++++++++++++++-- 1 file changed, 26 insertions(+), 2 deletions(-) diff --git a/src/qemu/qemu_capabilities.c b/src/qemu/qemu_capabilities.c index d618b3f..9d5f026 100644 --- a/src/qemu/qemu_capabilities.c +++ b/src/qemu/qemu_capabilities.c @@ -2754,6 +2754,26 @@ cleanup: } +#define MESSAGE_ID_CAPS_PROBE_FAILURE "8ae2f3fb-2dbe-498e-8fbd-012d40afa361" + +static void virQEMUCapsLogProbeFailure(const char *binary) +{ + virLogMetadata meta[] = { + { .key = "MESSAGE_ID", .s = MESSAGE_ID_CAPS_PROBE_FAILURE, .iv = 0 }, + { .key = "LIBVIRT_QEMU_BINARY", .s = binary, .iv = 0 }, + { .key = NULL }, + }; + virErrorPtr err = virGetLastError(); + + virLogMessage(VIR_LOG_FROM_FILE, + VIR_LOG_WARN, + __FILE__, __LINE__, __func__, + meta, + "Failed to probe capabilities for %s: %s", + binary, err && err->message ? err->message : "<unknown failure>"); +} + + virQEMUCapsPtr virQEMUCapsNewForBinary(const char *binary, const char *libDir, uid_t runUid, @@ -2785,12 +2805,16 @@ virQEMUCapsPtr virQEMUCapsNewForBinary(const char *binary, goto error; } - if ((rv = virQEMUCapsInitQMP(qemuCaps, libDir, runUid, runGid)) < 0) + if ((rv = virQEMUCapsInitQMP(qemuCaps, libDir, runUid, runGid)) < 0) { + virQEMUCapsLogProbeFailure(binary); goto error; + } if (!qemuCaps->usedQMP && - virQEMUCapsInitHelp(qemuCaps, runUid, runGid) < 0) + virQEMUCapsInitHelp(qemuCaps, runUid, runGid) < 0) { + virQEMUCapsLogProbeFailure(binary); goto error; + } return qemuCaps; -- 1.8.5.3
On 02/21/2014 10:31 AM, Daniel P. Berrange wrote:
When probing QEMU capabilities fails for a binary generate a log message with MESSAGE_ID==8ae2f3fb-2dbe-498e-8fbd-012d40afa361.
I'd expect this value to be documented somewhere in the html pages.
Signed-off-by: Daniel P. Berrange <berrange@redhat.com> --- src/qemu/qemu_capabilities.c | 28 ++++++++++++++++++++++++++-- 1 file changed, 26 insertions(+), 2 deletions(-)
diff --git a/src/qemu/qemu_capabilities.c b/src/qemu/qemu_capabilities.c index d618b3f..9d5f026 100644 --- a/src/qemu/qemu_capabilities.c +++ b/src/qemu/qemu_capabilities.c @@ -2754,6 +2754,26 @@ cleanup: }
+#define MESSAGE_ID_CAPS_PROBE_FAILURE "8ae2f3fb-2dbe-498e-8fbd-012d40afa361" + +static void virQEMUCapsLogProbeFailure(const char *binary)
Style - shouldn't this take two lines?
+ + virLogMessage(VIR_LOG_FROM_FILE, + VIR_LOG_WARN, + __FILE__, __LINE__, __func__, + meta, + "Failed to probe capabilities for %s: %s", + binary, err && err->message ? err->message : "<unknown failure>");
Should either of these strings be marked with _()? -- Eric Blake eblake redhat com +1-919-301-3266 Libvirt virtualization library http://libvirt.org
On 02/21/2014 10:31 AM, Daniel P. Berrange wrote:
This improves the logging when we have a failure to probe QEMU capabilities for any binary.
Daniel P. Berrange (4): Send virLogMetadata fields onto the journal Include error domain and code in log messages from errors Add comments describing the different log sources Generate a unique journald log for QEMU capabilities failure
Odd that 2/4 hasn't hit my inbox yet, but I reviewed it online. ACK. -- Eric Blake eblake redhat com +1-919-301-3266 Libvirt virtualization library http://libvirt.org
participants (2)
-
Daniel P. Berrange -
Eric Blake