[libvirt] [PATCH] libxl: Create per-domain log file
Currently, only one log file is created by the libxl driver, with all output from libxl for all domains going to this one file. Create a per-domain log file based on domain name, making sifting through the logs a bit easier. This required deferring libxl_ctx allocation until starting the domain, which is fine since the ctx is not used when the domain is inactive. --- src/libxl/libxl_conf.h | 5 +-- src/libxl/libxl_driver.c | 88 +++++++++++++++++++++++++++++------------------- 2 files changed, 57 insertions(+), 36 deletions(-) diff --git a/src/libxl/libxl_conf.h b/src/libxl/libxl_conf.h index aa57710..78133b9 100644 --- a/src/libxl/libxl_conf.h +++ b/src/libxl/libxl_conf.h @@ -57,8 +57,6 @@ struct _libxlDriverPrivate { virDomainXMLOptionPtr xmlopt; unsigned int version; - FILE *logger_file; - xentoollog_logger *logger; /* libxl ctx for driver wide ops; getVersion, getNodeInfo, ... */ libxl_ctx *ctx; @@ -93,6 +91,9 @@ typedef libxlDomainObjPrivate *libxlDomainObjPrivatePtr; struct _libxlDomainObjPrivate { virObjectLockable parent; + /* per domain log stream for libxl messages */ + FILE *logger_file; + xentoollog_logger *logger; /* per domain libxl ctx */ libxl_ctx *ctx; /* console */ diff --git a/src/libxl/libxl_driver.c b/src/libxl/libxl_driver.c index 9e9bc89..8e9a3d0 100644 --- a/src/libxl/libxl_driver.c +++ b/src/libxl/libxl_driver.c @@ -398,6 +398,51 @@ static const libxl_osevent_hooks libxl_event_callbacks = { .timeout_deregister = libxlTimeoutDeregisterEventHook, }; +static int +libxlDomainObjPrivateInitCtx(virDomainObjPtr vm) +{ + libxlDomainObjPrivatePtr priv = vm->privateData; + char *log_file; + int ret = -1; + + if (priv->ctx) + return 0; + + if (virAsprintf(&log_file, "%s/%s.log", LIBXL_LOG_DIR, vm->def->name) < 0) + return -1; + + if ((priv->logger_file = fopen(log_file, "a")) == NULL) { + virReportSystemError(errno, + _("failed to open logfile %s"), + log_file); + goto cleanup; + } + + priv->logger = + (xentoollog_logger *)xtl_createlogger_stdiostream(priv->logger_file, + XTL_DEBUG, 0); + if (!priv->logger) { + virReportError(VIR_ERR_INTERNAL_ERROR, + _("cannot create libxenlight logger for domain %s"), + vm->def->name); + goto cleanup; + } + + if (libxl_ctx_alloc(&priv->ctx, LIBXL_VERSION, 0, priv->logger)) { + virReportError(VIR_ERR_INTERNAL_ERROR, "%s", + _("Failed libxl context initialization")); + goto cleanup; + } + + libxl_osevent_register_hooks(priv->ctx, &libxl_event_callbacks, priv); + + ret = 0; + +cleanup: + VIR_FREE(log_file); + return ret; +} + static void * libxlDomainObjPrivateAlloc(void) { @@ -409,14 +454,6 @@ libxlDomainObjPrivateAlloc(void) if (!(priv = virObjectLockableNew(libxlDomainObjPrivateClass))) return NULL; - if (libxl_ctx_alloc(&priv->ctx, LIBXL_VERSION, 0, libxl_driver->logger)) { - VIR_ERROR(_("Failed libxl context initialization")); - virObjectUnref(priv); - return NULL; - } - - libxl_osevent_register_hooks(priv->ctx, &libxl_event_callbacks, priv); - if (!(priv->devs = virChrdevAlloc())) return NULL; @@ -432,6 +469,11 @@ libxlDomainObjPrivateDispose(void *obj) libxl_evdisable_domain_death(priv->ctx, priv->deathW); virChrdevFree(priv->devs); + + xtl_logger_destroy(priv->logger); + if (priv->logger_file) + VIR_FORCE_FCLOSE(priv->logger_file); + libxl_ctx_free(priv->ctx); } @@ -929,6 +971,9 @@ libxlVmStart(libxlDriverPrivatePtr driver, virDomainObjPtr vm, int managed_save_fd = -1; libxlDomainObjPrivatePtr priv = vm->privateData; + if (libxlDomainObjPrivateInitCtx(vm) < 0) + goto error; + /* If there is a managed saved state restore it instead of starting * from scratch. The old state is removed once the restoring succeeded. */ if (restore_fd < 0) { @@ -1135,9 +1180,6 @@ libxlStateCleanup(void) virObjectUnref(libxl_driver->xmlopt); virObjectUnref(libxl_driver->domains); libxl_ctx_free(libxl_driver->ctx); - xtl_logger_destroy(libxl_driver->logger); - if (libxl_driver->logger_file) - VIR_FORCE_FCLOSE(libxl_driver->logger_file); virObjectUnref(libxl_driver->reservedVNCPorts); @@ -1187,7 +1229,6 @@ libxlStateInitialize(bool privileged, void *opaque ATTRIBUTE_UNUSED) { const libxl_version_info *ver_info; - char *log_file = NULL; virCommandPtr cmd; int status, ret = 0; unsigned int free_mem; @@ -1267,17 +1308,6 @@ libxlStateInitialize(bool privileged, goto error; } - if (virAsprintf(&log_file, "%s/libxl.log", libxl_driver->logDir) < 0) - goto error; - - if ((libxl_driver->logger_file = fopen(log_file, "a")) == NULL) { - virReportSystemError(errno, - _("failed to create logfile %s"), - log_file); - goto error; - } - VIR_FREE(log_file); - /* read the host sysinfo */ if (privileged) libxl_driver->hostsysinfo = virSysinfoRead(); @@ -1286,16 +1316,7 @@ libxlStateInitialize(bool privileged, if (!libxl_driver->domainEventState) goto error; - libxl_driver->logger = - (xentoollog_logger *)xtl_createlogger_stdiostream(libxl_driver->logger_file, XTL_DEBUG, 0); - if (!libxl_driver->logger) { - VIR_INFO("cannot create logger for libxenlight, disabling driver"); - goto fail; - } - - if (libxl_ctx_alloc(&libxl_driver->ctx, - LIBXL_VERSION, 0, - libxl_driver->logger)) { + if (libxl_ctx_alloc(&libxl_driver->ctx, LIBXL_VERSION, 0, NULL)) { VIR_INFO("cannot initialize libxenlight context, probably not running in a Xen Dom0, disabling driver"); goto fail; } @@ -1362,7 +1383,6 @@ libxlStateInitialize(bool privileged, error: ret = -1; fail: - VIR_FREE(log_file); if (libxl_driver) libxlDriverUnlock(libxl_driver); libxlStateCleanup(); -- 1.8.1.4
On gio, 2013-08-08 at 17:41 -0600, Jim Fehlig wrote:
Currently, only one log file is created by the libxl driver, with all output from libxl for all domains going to this one file.
Create a per-domain log file based on domain name, making sifting through the logs a bit easier.
That is actually a really nice idea. I gave it a quick spin, and it worked well, so I think you can add (if you want, and if it is customary here in libvir) something like the below: Tested-by: Dario Faggioli <dario.faggioli@citrix.com> Regards, Dario -- <<This happens because I choose it to happen!>> (Raistlin Majere) ----------------------------------------------------------------- Dario Faggioli, Ph.D, http://about.me/dario.faggioli Senior Software Engineer, Citrix Systems R&D Ltd., Cambridge (UK)
Dario Faggioli wrote:
On gio, 2013-08-08 at 17:41 -0600, Jim Fehlig wrote:
Currently, only one log file is created by the libxl driver, with all output from libxl for all domains going to this one file.
Create a per-domain log file based on domain name, making sifting through the logs a bit easier.
That is actually a really nice idea.
I gave it a quick spin, and it worked well, so I think you can add (if you want, and if it is customary here in libvir) something like the below:
Tested-by: Dario Faggioli <dario.faggioli@citrix.com>
Ok. Thanks for testing Dario! Regards, Jim
On 09.08.2013 01:41, Jim Fehlig wrote:
Currently, only one log file is created by the libxl driver, with all output from libxl for all domains going to this one file.
Create a per-domain log file based on domain name, making sifting through the logs a bit easier. This required deferring libxl_ctx allocation until starting the domain, which is fine since the ctx is not used when the domain is inactive. --- src/libxl/libxl_conf.h | 5 +-- src/libxl/libxl_driver.c | 88 +++++++++++++++++++++++++++++------------------- 2 files changed, 57 insertions(+), 36 deletions(-)
ACK Michal
Michal Privoznik wrote:
On 09.08.2013 01:41, Jim Fehlig wrote:
Currently, only one log file is created by the libxl driver, with all output from libxl for all domains going to this one file.
Create a per-domain log file based on domain name, making sifting through the logs a bit easier. This required deferring libxl_ctx allocation until starting the domain, which is fine since the ctx is not used when the domain is inactive. --- src/libxl/libxl_conf.h | 5 +-- src/libxl/libxl_driver.c | 88 +++++++++++++++++++++++++++++------------------- 2 files changed, 57 insertions(+), 36 deletions(-)
ACK
Thanks Michal. Pushed now. Regards, Jim
On Thu, Aug 08, 2013 at 05:41:26PM -0600, Jim Fehlig wrote:
Currently, only one log file is created by the libxl driver, with all output from libxl for all domains going to this one file.
Create a per-domain log file based on domain name, making sifting through the logs a bit easier. This required deferring libxl_ctx allocation until starting the domain, which is fine since the ctx is not used when the domain is inactive. --- src/libxl/libxl_conf.h | 5 +-- src/libxl/libxl_driver.c | 88 +++++++++++++++++++++++++++++------------------- 2 files changed, 57 insertions(+), 36 deletions(-)
Startup of libvirtd SEGVs with this change in GIT ==4706== For counts of detected and suppressed errors, rerun with: -v ==4706== ERROR SUMMARY: 0 errors from 0 contexts (suppressed: 2 from 2) ==4601== Thread 12: ==4601== Invalid read of size 8 ==4601== at 0x1E57964F: xtl_logv (in /usr/lib64/libxenctrl.so.4.2.0) ==4601== by 0x1E5796D3: xtl_log (in /usr/lib64/libxenctrl.so.4.2.0) ==4601== by 0x1E33258A: ??? (in /usr/lib64/libxenlight.so.2.0.0) ==4601== by 0x1E332641: ??? (in /usr/lib64/libxenlight.so.2.0.0) ==4601== by 0x1E317CD7: libxl_ctx_alloc (in /usr/lib64/libxenlight.so.2.0.0) ==4601== by 0x1E0E3016: libxlStateInitialize.part.12 (libxl_driver.c:1319) ==4601== by 0x514AA29: virStateInitialize (libvirt.c:832) ==4601== by 0x11C42A: daemonRunStateInit (libvirtd.c:906) ==4601== by 0x50C273D: virThreadHelper (virthreadpthread.c:161) ==4601== by 0x82D0C52: start_thread (pthread_create.c:308) ==4601== by 0x89E213C: clone (clone.S:113) ==4601== Address 0x0 is not stack'd, malloc'd or (recently) free'd ==4601== Caught Segmentation violation dumping internal log buffer: 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 :|
Daniel P. Berrange wrote:
On Thu, Aug 08, 2013 at 05:41:26PM -0600, Jim Fehlig wrote:
Currently, only one log file is created by the libxl driver, with all output from libxl for all domains going to this one file.
Create a per-domain log file based on domain name, making sifting through the logs a bit easier. This required deferring libxl_ctx allocation until starting the domain, which is fine since the ctx is not used when the domain is inactive. --- src/libxl/libxl_conf.h | 5 +-- src/libxl/libxl_driver.c | 88 +++++++++++++++++++++++++++++------------------- 2 files changed, 57 insertions(+), 36 deletions(-)
Startup of libvirtd SEGVs with this change in GIT
==4706== For counts of detected and suppressed errors, rerun with: -v ==4706== ERROR SUMMARY: 0 errors from 0 contexts (suppressed: 2 from 2) ==4601== Thread 12: ==4601== Invalid read of size 8 ==4601== at 0x1E57964F: xtl_logv (in /usr/lib64/libxenctrl.so.4.2.0) ==4601== by 0x1E5796D3: xtl_log (in /usr/lib64/libxenctrl.so.4.2.0) ==4601== by 0x1E33258A: ??? (in /usr/lib64/libxenlight.so.2.0.0) ==4601== by 0x1E332641: ??? (in /usr/lib64/libxenlight.so.2.0.0) ==4601== by 0x1E317CD7: libxl_ctx_alloc (in /usr/lib64/libxenlight.so.2.0.0)
I should have looked at the xen code closer. Seems libxl doesn't cope well with a NULL logger :(. Hmm, should the logger for this driver-wide ctx (used for getting libxl version and the like, no domain ops) just dump messages to /dev/null or should they go to a driver-wide log file? Regards, Jim
On Fri, Aug 09, 2013 at 10:48:52AM -0600, Jim Fehlig wrote:
Daniel P. Berrange wrote:
On Thu, Aug 08, 2013 at 05:41:26PM -0600, Jim Fehlig wrote:
Currently, only one log file is created by the libxl driver, with all output from libxl for all domains going to this one file.
Create a per-domain log file based on domain name, making sifting through the logs a bit easier. This required deferring libxl_ctx allocation until starting the domain, which is fine since the ctx is not used when the domain is inactive. --- src/libxl/libxl_conf.h | 5 +-- src/libxl/libxl_driver.c | 88 +++++++++++++++++++++++++++++------------------- 2 files changed, 57 insertions(+), 36 deletions(-)
Startup of libvirtd SEGVs with this change in GIT
==4706== For counts of detected and suppressed errors, rerun with: -v ==4706== ERROR SUMMARY: 0 errors from 0 contexts (suppressed: 2 from 2) ==4601== Thread 12: ==4601== Invalid read of size 8 ==4601== at 0x1E57964F: xtl_logv (in /usr/lib64/libxenctrl.so.4.2.0) ==4601== by 0x1E5796D3: xtl_log (in /usr/lib64/libxenctrl.so.4.2.0) ==4601== by 0x1E33258A: ??? (in /usr/lib64/libxenlight.so.2.0.0) ==4601== by 0x1E332641: ??? (in /usr/lib64/libxenlight.so.2.0.0) ==4601== by 0x1E317CD7: libxl_ctx_alloc (in /usr/lib64/libxenlight.so.2.0.0)
I should have looked at the xen code closer. Seems libxl doesn't cope well with a NULL logger :(.
Hmm, should the logger for this driver-wide ctx (used for getting libxl version and the like, no domain ops) just dump messages to /dev/null or should they go to a driver-wide log file?
Depends if you think there's any useful info to be had from the driver wide context object ? If so, then probably best to have a driver-wide log file for those messages 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 08/09/2013 10:50 AM, Daniel P. Berrange wrote:
I should have looked at the xen code closer. Seems libxl doesn't cope well with a NULL logger :(.
Hmm, should the logger for this driver-wide ctx (used for getting libxl version and the like, no domain ops) just dump messages to /dev/null or should they go to a driver-wide log file?
Depends if you think there's any useful info to be had from the driver wide context object ? If so, then probably best to have a driver-wide log file for those messages
Or even just reply the data into the main libvirtd.log (ie. use existing virLog functionality, rather than creating a new file), since ideally the log will be relatively sparse: in my case, it would be just one message stating that libxl is not available, at which point the libxl driver no longer does anything else during the life of libvirtd. -- Eric Blake eblake redhat com +1-919-301-3266 Libvirt virtualization library http://libvirt.org
On Fri, Aug 09, 2013 at 10:56:41AM -0600, Eric Blake wrote:
On 08/09/2013 10:50 AM, Daniel P. Berrange wrote:
I should have looked at the xen code closer. Seems libxl doesn't cope well with a NULL logger :(.
Hmm, should the logger for this driver-wide ctx (used for getting libxl version and the like, no domain ops) just dump messages to /dev/null or should they go to a driver-wide log file?
Depends if you think there's any useful info to be had from the driver wide context object ? If so, then probably best to have a driver-wide log file for those messages
Or even just reply the data into the main libvirtd.log (ie. use existing virLog functionality, rather than creating a new file), since ideally the log will be relatively sparse: in my case, it would be just one message stating that libxl is not available, at which point the libxl driver no longer does anything else during the life of libvirtd.
I was going to suggest that, but IIUC, the libxl logger API requires you to give it a FILE * instance to which it writes directly. To feed it into our normal logs, we'd want it to let us give it a callback for writing log messages. 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 :|
Daniel P. Berrange wrote:
On Fri, Aug 09, 2013 at 10:56:41AM -0600, Eric Blake wrote:
On 08/09/2013 10:50 AM, Daniel P. Berrange wrote:
I should have looked at the xen code closer. Seems libxl doesn't cope well with a NULL logger :(.
Hmm, should the logger for this driver-wide ctx (used for getting libxl version and the like, no domain ops) just dump messages to /dev/null or should they go to a driver-wide log file?
Depends if you think there's any useful info to be had from the driver wide context object ? If so, then probably best to have a driver-wide log file for those messages
Or even just reply the data into the main libvirtd.log (ie. use existing virLog functionality, rather than creating a new file), since ideally the log will be relatively sparse: in my case, it would be just one message stating that libxl is not available, at which point the libxl driver no longer does anything else during the life of libvirtd.
I was going to suggest that, but IIUC, the libxl logger API requires you to give it a FILE * instance to which it writes directly.
Right.
To feed it into our normal logs, we'd want it to let us give it a callback for writing log messages.
I was going to pass the logger create function 'stderr' for the driver-wide ctx. Would that be safe? Regards, Jim
On 08/09/2013 11:04 AM, Daniel P. Berrange wrote:
On Fri, Aug 09, 2013 at 10:56:41AM -0600, Eric Blake wrote:
On 08/09/2013 10:50 AM, Daniel P. Berrange wrote:
I should have looked at the xen code closer. Seems libxl doesn't cope well with a NULL logger :(.
Hmm, should the logger for this driver-wide ctx (used for getting libxl version and the like, no domain ops) just dump messages to /dev/null or should they go to a driver-wide log file?
Depends if you think there's any useful info to be had from the driver wide context object ? If so, then probably best to have a driver-wide log file for those messages
Or even just reply the data into the main libvirtd.log (ie. use existing virLog functionality, rather than creating a new file), since ideally the log will be relatively sparse: in my case, it would be just one message stating that libxl is not available, at which point the libxl driver no longer does anything else during the life of libvirtd.
I was going to suggest that, but IIUC, the libxl logger API requires you to give it a FILE * instance to which it writes directly. To feed it into our normal logs, we'd want it to let us give it a callback for writing log messages.
Can we rely on open_memstream() being present on any platform with libxl? If so, that would give us a FILE* interface to libxl, while still giving us access to the strings it prints which we can then turn around and hand to our logger. -- Eric Blake eblake redhat com +1-919-301-3266 Libvirt virtualization library http://libvirt.org
Daniel P. Berrange wrote:
On Thu, Aug 08, 2013 at 05:41:26PM -0600, Jim Fehlig wrote:
Currently, only one log file is created by the libxl driver, with all output from libxl for all domains going to this one file.
Create a per-domain log file based on domain name, making sifting through the logs a bit easier. This required deferring libxl_ctx allocation until starting the domain, which is fine since the ctx is not used when the domain is inactive. --- src/libxl/libxl_conf.h | 5 +-- src/libxl/libxl_driver.c | 88 +++++++++++++++++++++++++++++------------------- 2 files changed, 57 insertions(+), 36 deletions(-)
Startup of libvirtd SEGVs with this change in GIT
I should have tested this change on a system with libxl, but not booted to Xen. libxl would have then complained, and I would have seen the crash. Lesson learned... I've sent a patch to fix the issue https://www.redhat.com/archives/libvir-list/2013-August/msg00484.html Regards, Jim
==4706== For counts of detected and suppressed errors, rerun with: -v ==4706== ERROR SUMMARY: 0 errors from 0 contexts (suppressed: 2 from 2) ==4601== Thread 12: ==4601== Invalid read of size 8 ==4601== at 0x1E57964F: xtl_logv (in /usr/lib64/libxenctrl.so.4.2.0) ==4601== by 0x1E5796D3: xtl_log (in /usr/lib64/libxenctrl.so.4.2.0) ==4601== by 0x1E33258A: ??? (in /usr/lib64/libxenlight.so.2.0.0) ==4601== by 0x1E332641: ??? (in /usr/lib64/libxenlight.so.2.0.0) ==4601== by 0x1E317CD7: libxl_ctx_alloc (in /usr/lib64/libxenlight.so.2.0.0) ==4601== by 0x1E0E3016: libxlStateInitialize.part.12 (libxl_driver.c:1319) ==4601== by 0x514AA29: virStateInitialize (libvirt.c:832) ==4601== by 0x11C42A: daemonRunStateInit (libvirtd.c:906) ==4601== by 0x50C273D: virThreadHelper (virthreadpthread.c:161) ==4601== by 0x82D0C52: start_thread (pthread_create.c:308) ==4601== by 0x89E213C: clone (clone.S:113) ==4601== Address 0x0 is not stack'd, malloc'd or (recently) free'd ==4601== Caught Segmentation violation dumping internal log buffer:
Daniel
On ven, 2013-08-09 at 18:24 -0600, Jim Fehlig wrote:
I should have tested this change on a system with libxl, but not booted to Xen. libxl would have then complained, and I would have seen the crash. Lesson learned...
Ups! I was wondering how that could happen, since I tested this too and it worked, but yes, I tested it on Xen too... Did not think about doing the above, although, yes, it definitely sounds like a reasonable thing to do! :-P Note taken for next time. :-) Dario -- <<This happens because I choose it to happen!>> (Raistlin Majere) ----------------------------------------------------------------- Dario Faggioli, Ph.D, http://about.me/dario.faggioli Senior Software Engineer, Citrix Systems R&D Ltd., Cambridge (UK)
participants (5)
-
Daniel P. Berrange -
Dario Faggioli -
Eric Blake -
Jim Fehlig -
Michal Privoznik