[libvirt] [PATCH 0/2] Log enhancement

Hi, Following patches improve logging feature of libvirt. Please see individual patches for more details. [PATCH 1/2] extend logging to record configuration-related events on host machine [PATCH 2/2] qemu: extend logging to record guest configuration events Thanks, Naoya Horiguchi

Currently libvirt's logging is so poor that it's difficult to determine what was happening when a proglem occurred (especially on someone's machines you don't know the detail.) This patch helps us to do that by making additional logging available for the following events: creating/defining/undefining domains creating/defining/undefining/starting/stopping networks creating/defining/undefining/starting/stopping storage pools creating/defining/undefining/starting/stopping storage volumes. Signed-off-by: Naoya Horiguchi <n-horiguchi@ah.jp.nec.com> --- src/network/bridge_driver.c | 4 ++++ src/qemu/qemu_driver.c | 5 ++++- src/storage/storage_driver.c | 12 ++++++++++++ 3 files changed, 20 insertions(+), 1 deletions(-) diff --git v0.8.8/src/network/bridge_driver.c v0.8.8/src/network/bridge_driver.c index c4ee1e8..097e83a 100644 --- v0.8.8/src/network/bridge_driver.c +++ v0.8.8/src/network/bridge_driver.c @@ -1656,6 +1656,7 @@ networkStartNetworkDaemon(struct network_driver *driver, goto err5; } + VIR_INFO(_("Starting up network '%s'"), network->def->name); network->active = 1; return 0; @@ -2000,6 +2001,7 @@ static virNetworkPtr networkCreate(virConnectPtr conn, const char *xml) { goto cleanup; } + VIR_INFO(_("Creating network '%s'"), network->def->name); ret = virGetNetwork(conn, network->def->name, network->def->uuid); cleanup: @@ -2069,6 +2071,7 @@ static virNetworkPtr networkDefine(virConnectPtr conn, const char *xml) { dnsmasqContextFree(dctx); } + VIR_INFO(_("Defining network '%s'"), network->def->name); ret = virGetNetwork(conn, network->def->name, network->def->uuid); cleanup: @@ -2148,6 +2151,7 @@ static int networkUndefine(virNetworkPtr net) { } + VIR_INFO(_("Undefining network '%s'"), network->def->name); virNetworkRemoveInactive(&driver->networks, network); network = NULL; diff --git v0.8.8/src/qemu/qemu_driver.c v0.8.8/src/qemu/qemu_driver.c index ab664a0..3b30d0f 100644 --- v0.8.8/src/qemu/qemu_driver.c +++ v0.8.8/src/qemu/qemu_driver.c @@ -3642,6 +3642,7 @@ static virDomainPtr qemudDomainCreate(virConnectPtr conn, const char *xml, VIR_DOMAIN_EVENT_STARTED_BOOTED); qemuDomainStartAudit(vm, "booted", true); + VIR_INFO(_("Creating domain '%s'"), vm->def->name); dom = virGetDomain(conn, vm->def->name, vm->def->uuid); if (dom) dom->id = vm->def->id; @@ -4711,7 +4712,7 @@ qemuDomainManagedSave(virDomainPtr dom, unsigned int flags) if (name == NULL) goto cleanup; - VIR_DEBUG("Saving state to %s", name); + VIR_INFO("Saving state to %s", name); compressed = QEMUD_SAVE_FORMAT_RAW; ret = qemudDomainSaveFlag(driver, dom, vm, name, compressed); @@ -6438,6 +6439,7 @@ static virDomainPtr qemudDomainDefine(virConnectPtr conn, const char *xml) { if (virDomainSaveConfig(driver->configDir, vm->newDef ? vm->newDef : vm->def) < 0) { + VIR_INFO(_("Defining domain '%s'"), vm->def->name); virDomainRemoveInactive(&driver->domains, vm); vm = NULL; @@ -6499,6 +6501,7 @@ static int qemudDomainUndefine(virDomainPtr dom) { VIR_DOMAIN_EVENT_UNDEFINED, VIR_DOMAIN_EVENT_UNDEFINED_REMOVED); + VIR_INFO(_("Undefining domain '%s'"), vm->def->name); virDomainRemoveInactive(&driver->domains, vm); vm = NULL; diff --git v0.8.8/src/storage/storage_driver.c v0.8.8/src/storage/storage_driver.c index 5373025..162ef7f 100644 --- v0.8.8/src/storage/storage_driver.c +++ v0.8.8/src/storage/storage_driver.c @@ -550,6 +550,7 @@ storagePoolCreate(virConnectPtr conn, pool = NULL; goto cleanup; } + VIR_INFO(_("Creating storage pool '%s'"), pool->def->name); pool->active = 1; ret = virGetStoragePool(conn, pool->def->name, pool->def->uuid); @@ -591,6 +592,7 @@ storagePoolDefine(virConnectPtr conn, } def = NULL; + VIR_INFO(_("Defining storage pool '%s'"), pool->def->name); ret = virGetStoragePool(conn, pool->def->name, pool->def->uuid); cleanup: @@ -640,6 +642,7 @@ storagePoolUndefine(virStoragePoolPtr obj) { VIR_FREE(pool->configFile); VIR_FREE(pool->autostartLink); + VIR_INFO(_("Undefining storage pool '%s'"), pool->def->name); virStoragePoolObjRemove(&driver->pools, pool); pool = NULL; ret = 0; @@ -687,6 +690,7 @@ storagePoolStart(virStoragePoolPtr obj, goto cleanup; } + VIR_INFO(_("Starting up storage pool '%s'"), pool->def->name); pool->active = 1; ret = 0; @@ -774,6 +778,7 @@ storagePoolDestroy(virStoragePoolPtr obj) { virStoragePoolObjClearVols(pool); pool->active = 0; + VIR_INFO(_("Shutting down storage pool '%s'"), pool->def->name); if (pool->configFile == NULL) { virStoragePoolObjRemove(&driver->pools, pool); @@ -830,6 +835,7 @@ storagePoolDelete(virStoragePoolPtr obj, } if (backend->deletePool(obj->conn, pool, flags) < 0) goto cleanup; + VIR_INFO(_("Deleting storage pool '%s'"), pool->def->name); ret = 0; cleanup: @@ -1355,6 +1361,8 @@ storageVolumeCreateXML(virStoragePoolPtr obj, } + VIR_INFO(_("Creating volume '%s' in storage pool '%s'"), + volobj->name, pool->def->name); ret = volobj; volobj = NULL; voldef = NULL; @@ -1513,6 +1521,8 @@ storageVolumeCreateXMLFrom(virStoragePoolPtr obj, goto cleanup; } + VIR_INFO(_("Creating volume '%s' in storage pool '%s'"), + volobj->name, pool->def->name); ret = volobj; volobj = NULL; @@ -1790,6 +1800,8 @@ storageVolumeDelete(virStorageVolPtr obj, for (i = 0 ; i < pool->volumes.count ; i++) { if (pool->volumes.objs[i] == vol) { + VIR_INFO(_("Deleting volume '%s' from storage pool '%s'"), + vol->name, pool->def->name); virStorageVolDefFree(vol); vol = NULL; -- 1.7.3.4

[ OOPs actually I wrote this reply wednesday last week but forgot to send it, sorry , Daniel ] On Mon, Mar 28, 2011 at 05:13:46PM +0900, Naoya Horiguchi wrote:
Currently libvirt's logging is so poor that it's difficult to determine what was happening when a proglem occurred (especially on someone's
Actually libvirt logging is fairly complete, but the default logging at the INFO level is not complete, which can be a problem for a prosteriori analysis. http://libvirt.org/logging.html I tried to fix this for serious problems like crashes https://www.redhat.com/archives/libvir-list/2011-March/msg00072.html but for continuous default logging, yeah we could be a bit more verbose
machines you don't know the detail.) This patch helps us to do that by making additional logging available for the following events:
creating/defining/undefining domains creating/defining/undefining/starting/stopping networks creating/defining/undefining/starting/stopping storage pools creating/defining/undefining/starting/stopping storage volumes.
Okay, makes sense to me. ACK,
Signed-off-by: Naoya Horiguchi <n-horiguchi@ah.jp.nec.com> --- src/network/bridge_driver.c | 4 ++++ src/qemu/qemu_driver.c | 5 ++++- src/storage/storage_driver.c | 12 ++++++++++++ 3 files changed, 20 insertions(+), 1 deletions(-)
diff --git v0.8.8/src/network/bridge_driver.c v0.8.8/src/network/bridge_driver.c
Note: your patch didn't applied cleanly because you developped it against a released versions, it's better to do this against libvirt git head. I rebased it solving the couple of conflict, it was easy, thanks ! Daniel -- Daniel Veillard | libxml Gnome XML XSLT toolkit http://xmlsoft.org/ daniel@veillard.com | Rpmfind RPM search engine http://rpmfind.net/ http://veillard.com/ | virtualization library http://libvirt.org/

The following events can be logged onto /var/log/libvirt/qemu/<domain>.log: starting/shutting down/suspending/resuming/migrating domains changing the amount of memory changing the number of VCPUs inserting/ejecting a media into/from CDROM/Floppy devices attaching/detaching PCI/SCSI/USB devices (including NICs and disks.) This patch generalizes qemudLog*() introduced in commit 93bc093ac to handle the whole range of qemu driver's events. This is useful for the same reason as explainged in the previous patch. Signed-off-by: Naoya Horiguchi <n-horiguchi@ah.jp.nec.com> --- src/qemu/qemu_driver.c | 110 +++++++++++++++++++++++++++++------------------ src/qemu/qemu_driver.h | 8 +++ src/qemu/qemu_hotplug.c | 66 +++++++++++++++++++++++++++- 3 files changed, 140 insertions(+), 44 deletions(-) diff --git v0.8.8/src/qemu/qemu_driver.c v0.8.8/src/qemu/qemu_driver.c index 3b30d0f..7df0023 100644 --- v0.8.8/src/qemu/qemu_driver.c +++ v0.8.8/src/qemu/qemu_driver.c @@ -247,6 +247,62 @@ qemudLogReadFD(const char* logDir, const char* name, off_t pos) } +static int +qemudLogWriteFD(int logfd, struct qemud_driver *driver, + virDomainObjPtr vm, bool append, const char *logstr) +{ + bool openfile = logfd < 0; + char *timestamp; + char ebuf[1024]; + + if (openfile && + (logfd = qemudLogFD(driver, vm->def->name, append)) < 0) { + /* To not break the normal domain shutdown process, skip the + * timestamp log writing if failed on opening log file. */ + VIR_WARN("Unable to open logfile: %s", + virStrerror(errno, ebuf, sizeof ebuf)); + return -1; + } + + if ((timestamp = virTimestamp()) == NULL) { + virReportOOMError(); + return -1; + } + + if (safewrite(logfd, timestamp, strlen(timestamp)) < 0 || + safewrite(logfd, logstr, strlen(logstr)) < 0) { + VIR_WARN("Unable to write timestamp to logfile: %s", + virStrerror(errno, ebuf, sizeof ebuf)); + } + VIR_FREE(timestamp); + + if (openfile && VIR_CLOSE(logfd) < 0) { + VIR_WARN("Unable to close logfile: %s", + virStrerror(errno, ebuf, sizeof ebuf)); + } + + return 0; +} + + +void qemudLogWrite(struct qemud_driver *driver, virDomainObjPtr vm, + bool append, const char *fmt, ...) +{ + char *buf; + va_list args; + + va_start(args, fmt); + if (virVasprintf(&buf, fmt, args) < 0) { + VIR_WARN0("Out of memory while formatting log message"); + buf = NULL; + } + va_end(args); + + if (buf) + qemudLogWriteFD(-1, driver, vm, append, buf); +} + + struct qemuAutostartData { struct qemud_driver *driver; virConnectPtr conn; @@ -2610,9 +2666,6 @@ static int qemuDomainSnapshotSetCurrentInactive(virDomainObjPtr vm, char *snapshotDir); -#define START_POSTFIX ": starting up\n" -#define SHUTDOWN_POSTFIX ": shutting down\n" - static int qemudStartVMDaemon(virConnectPtr conn, struct qemud_driver *driver, virDomainObjPtr vm, @@ -2627,7 +2680,6 @@ static int qemudStartVMDaemon(virConnectPtr conn, char ebuf[1024]; char *pidfile = NULL; int logfile = -1; - char *timestamp; qemuDomainObjPrivatePtr priv = vm->privateData; virCommandPtr cmd = NULL; @@ -2845,18 +2897,7 @@ static int qemudStartVMDaemon(virConnectPtr conn, goto cleanup; } - if ((timestamp = virTimestamp()) == NULL) { - virReportOOMError(); - goto cleanup; - } else { - if (safewrite(logfile, timestamp, strlen(timestamp)) < 0 || - safewrite(logfile, START_POSTFIX, strlen(START_POSTFIX)) < 0) { - VIR_WARN("Unable to write timestamp to logfile: %s", - virStrerror(errno, ebuf, sizeof ebuf)); - } - - VIR_FREE(timestamp); - } + qemudLogWriteFD(logfile, driver, vm, false, START_POSTFIX); virCommandWriteArgLog(cmd, logfile); @@ -2985,9 +3026,6 @@ static void qemudShutdownVMDaemon(struct qemud_driver *driver, virErrorPtr orig_err; virDomainDefPtr def; int i; - int logfile = -1; - char *timestamp; - char ebuf[1024]; VIR_DEBUG("Shutting down VM '%s' pid=%d migrated=%d", vm->def->name, vm->pid, migrated); @@ -2997,29 +3035,7 @@ static void qemudShutdownVMDaemon(struct qemud_driver *driver, return; } - if ((logfile = qemudLogFD(driver, vm->def->name, true)) < 0) { - /* To not break the normal domain shutdown process, skip the - * timestamp log writing if failed on opening log file. */ - VIR_WARN("Unable to open logfile: %s", - virStrerror(errno, ebuf, sizeof ebuf)); - } else { - if ((timestamp = virTimestamp()) == NULL) { - virReportOOMError(); - } else { - if (safewrite(logfile, timestamp, strlen(timestamp)) < 0 || - safewrite(logfile, SHUTDOWN_POSTFIX, - strlen(SHUTDOWN_POSTFIX)) < 0) { - VIR_WARN("Unable to write timestamp to logfile: %s", - virStrerror(errno, ebuf, sizeof ebuf)); - } - - VIR_FREE(timestamp); - } - - if (VIR_CLOSE(logfile) < 0) - VIR_WARN("Unable to close logfile: %s", - virStrerror(errno, ebuf, sizeof ebuf)); - } + qemudLogWrite(driver, vm, true, SHUTDOWN_POSTFIX); /* This method is routinely used in clean up paths. Disable error * reporting so we don't squash a legit error. */ @@ -3713,6 +3729,7 @@ static int qemudDomainSuspend(virDomainPtr dom) { } if (virDomainSaveStatus(driver->caps, driver->stateDir, vm) < 0) goto endjob; + qemudLogWrite(driver, vm, true, ": suspending\n"); ret = 0; } @@ -3769,6 +3786,7 @@ static int qemudDomainResume(virDomainPtr dom) { } if (virDomainSaveStatus(driver->caps, driver->stateDir, vm) < 0) goto endjob; + qemudLogWrite(driver, vm, true, ": resuming\n"); ret = 0; endjob: @@ -3978,6 +3996,8 @@ static int qemudDomainSetMemory(virDomainPtr dom, unsigned long newmem) { goto endjob; } + qemudLogWrite(driver, vm, true, ": setting memory to %lu kB\n", newmem); + ret = 0; endjob: if (qemuDomainObjEndJob(vm) == 0) @@ -5198,6 +5218,9 @@ qemudDomainSetVcpusFlags(virDomainPtr dom, unsigned int nvcpus, break; } + if (!ret) + qemudLogWrite(driver, vm, true, ": setting Num of VCPUs to %u\n", nvcpus); + /* Save the persistent config to disk */ if (flags & VIR_DOMAIN_VCPU_CONFIG) ret = virDomainSaveConfig(driver->configDir, persistentDef); @@ -8963,6 +8986,9 @@ qemudDomainMigratePerform (virDomainPtr dom, virDomainRemoveInactive(&driver->domains, vm); vm = NULL; } + + qemudLogWrite(driver, vm, true, ": migrating to %s\n", dname); + ret = 0; endjob: diff --git v0.8.8/src/qemu/qemu_driver.h v0.8.8/src/qemu/qemu_driver.h index dac0935..bdd8072 100644 --- v0.8.8/src/qemu/qemu_driver.h +++ v0.8.8/src/qemu/qemu_driver.h @@ -30,6 +30,7 @@ # include <libxml/xpath.h> # include "internal.h" +# include "qemu_conf.h" # if HAVE_LINUX_KVM_H # include <linux/kvm.h> @@ -51,4 +52,11 @@ int qemuRegister(void); +# define START_POSTFIX ": starting up\n" +# define SHUTDOWN_POSTFIX ": shutting down\n" + +void qemudLogWrite(struct qemud_driver *driver, virDomainObjPtr vm, + bool append, const char *fmt, ...) + ATTRIBUTE_FMT_PRINTF(4, 5); + #endif /* QEMUD_DRIVER_H */ diff --git v0.8.8/src/qemu/qemu_hotplug.c v0.8.8/src/qemu/qemu_hotplug.c index fb9db5a..edeeeb7 100644 --- v0.8.8/src/qemu/qemu_hotplug.c +++ v0.8.8/src/qemu/qemu_hotplug.c @@ -28,6 +28,7 @@ #include "qemu_capabilities.h" #include "qemu_domain.h" #include "qemu_command.h" +#include "qemu_driver.h" #include "qemu_bridge_filter.h" #include "qemu_audit.h" #include "qemu_hostdev.h" @@ -113,6 +114,14 @@ int qemuDomainChangeEjectableMedia(struct qemud_driver *driver, if (ret < 0) goto error; + if (disk->src) { + qemudLogWrite(driver, vm, true, ": inserting '%s' to %s device\n", + disk->src, virDomainDiskDeviceTypeToString(disk->device)); + } else { + qemudLogWrite(driver, vm, true, ": ejecting media from %s device\n", + virDomainDiskDeviceTypeToString(disk->device)); + } + if (virSecurityManagerRestoreImageLabel(driver->securityManager, vm, origdisk) < 0) VIR_WARN("Unable to restore security label on ejected image %s", origdisk->src); @@ -208,6 +217,9 @@ int qemuDomainAttachPciDiskDevice(struct qemud_driver *driver, if (ret < 0) goto error; + qemudLogWrite(driver, vm, true, ": attach PCI disk %s %s (%s)\n", + type, drivestr, devstr); + virDomainDiskInsertPreAlloced(vm->def, disk); VIR_FREE(devstr); @@ -282,6 +294,9 @@ int qemuDomainAttachPciControllerDevice(struct qemud_driver *driver, if (ret == 0) { controller->info.type = VIR_DOMAIN_DEVICE_ADDRESS_TYPE_PCI; virDomainControllerInsertPreAlloced(vm->def, controller); + qemudLogWrite(driver, vm, true, + ": attaching PCI controller device %s:%d\n", + type, controller->idx); } cleanup: @@ -440,6 +455,10 @@ int qemuDomainAttachSCSIDisk(struct qemud_driver *driver, if (ret < 0) goto error; + qemudLogWrite(driver, vm, true, ": attaching SCSI disk %s %s (%s)\n", + virDomainDeviceAddressTypeToString(disk->info.type), + drivestr, devstr); + virDomainDiskInsertPreAlloced(vm->def, disk); VIR_FREE(devstr); @@ -523,6 +542,9 @@ int qemuDomainAttachUsbMassstorageDevice(struct qemud_driver *driver, if (ret < 0) goto error; + qemudLogWrite(driver, vm, true, ": attaching USB storage %s %s (%s)\n", + disk->dst, drivestr, devstr); + virDomainDiskInsertPreAlloced(vm->def, disk); VIR_FREE(devstr); @@ -702,6 +724,11 @@ int qemuDomainAttachNetDevice(virConnectPtr conn, qemuDomainNetAudit(vm, NULL, net, "attach", true); + qemudLogWrite(driver, vm, true, + ": attaching network device %s, %s, %s, %s %s\n", + nicstr, netstr, virDomainNetTypeToString(net->type), + net->ifname, net->mac); + ret = 0; vm->def->nets[vm->def->nnets++] = net; @@ -847,6 +874,8 @@ int qemuDomainAttachHostPciDevice(struct qemud_driver *driver, vm->def->hostdevs[vm->def->nhostdevs++] = hostdev; + qemudLogWrite(driver, vm, true, ": attaching host PCI device\n"); + VIR_FREE(devstr); VIR_FREE(configfd_name); VIR_FORCE_CLOSE(configfd); @@ -922,6 +951,8 @@ int qemuDomainAttachHostUsbDevice(struct qemud_driver *driver, vm->def->hostdevs[vm->def->nhostdevs++] = hostdev; + qemudLogWrite(driver, vm, true, ": attaching host USB device\n"); + VIR_FREE(devstr); return 0; @@ -985,6 +1016,8 @@ int qemuDomainAttachHostDevice(struct qemud_driver *driver, goto error; } + qemudLogWrite(driver, vm, true, ": attaching host device\n"); + return 0; error: @@ -1211,6 +1244,9 @@ int qemuDomainDetachPciDiskDevice(struct qemud_driver *driver, NULLSTR(dev->data.disk->src)); } + qemudLogWrite(driver, vm, true, ": detaching PCI disk %s %s\n", + NULLSTR(dev->data.disk->src), drivestr); + ret = 0; cleanup: @@ -1289,6 +1325,9 @@ int qemuDomainDetachSCSIDiskDevice(struct qemud_driver *driver, NULLSTR(dev->data.disk->src)); } + qemudLogWrite(driver, vm, true, ": detaching SCSI disk %s %s\n", + NULLSTR(dev->data.disk->src), drivestr); + ret = 0; cleanup: @@ -1369,6 +1408,11 @@ int qemuDomainDetachPciControllerDevice(struct qemud_driver *driver, virDomainControllerDefFree(detach); + qemudLogWrite(driver, vm, true, + ": detaching PCI controller device [%s:%d]\n", + virDomainControllerTypeToString(dev->data.controller->type), + dev->data.controller->idx); + ret = 0; cleanup: @@ -1456,6 +1500,13 @@ int qemuDomainDetachNetDevice(struct qemud_driver *driver, qemuDomainNetAudit(vm, detach, NULL, "detach", true); + qemudLogWrite(driver, vm, true, + ": detaching network device %s %s %02x:%02x:%02x:%02x:%02x:%02x \n", + virDomainNetTypeToString(detach->type), detach->model, + detach->mac[0], detach->mac[1], + detach->mac[2], detach->mac[3], + detach->mac[4], detach->mac[5]); + if ((qemuCmdFlags & QEMUD_CMD_FLAG_DEVICE) && qemuDomainPCIAddressReleaseAddr(priv->pciaddrs, &detach->info) < 0) VIR_WARN0("Unable to release PCI address on NIC"); @@ -1599,6 +1650,9 @@ int qemuDomainDetachHostPciDevice(struct qemud_driver *driver, } virDomainHostdevDefFree(detach); + if (ret == 0) + qemudLogWrite(driver, vm, true, ": detaching host PCI device\n"); + return ret; } @@ -1610,14 +1664,16 @@ int qemuDomainDetachHostUsbDevice(struct qemud_driver *driver, virDomainHostdevDefPtr detach = NULL; qemuDomainObjPrivatePtr priv = vm->privateData; int i, ret; + unsigned bus; + unsigned device; for (i = 0 ; i < vm->def->nhostdevs ; i++) { if (vm->def->hostdevs[i]->mode != VIR_DOMAIN_HOSTDEV_MODE_SUBSYS || vm->def->hostdevs[i]->source.subsys.type != VIR_DOMAIN_HOSTDEV_SUBSYS_TYPE_USB) continue; - unsigned bus = vm->def->hostdevs[i]->source.subsys.u.usb.bus; - unsigned device = vm->def->hostdevs[i]->source.subsys.u.usb.device; + bus = vm->def->hostdevs[i]->source.subsys.u.usb.bus; + device = vm->def->hostdevs[i]->source.subsys.u.usb.device; unsigned product = vm->def->hostdevs[i]->source.subsys.u.usb.product; unsigned vendor = vm->def->hostdevs[i]->source.subsys.u.usb.vendor; @@ -1666,6 +1722,9 @@ int qemuDomainDetachHostUsbDevice(struct qemud_driver *driver, ret = 0; + qemudLogWrite(driver, vm, true, ": detaching host USB device %03d%03d\n", + bus, device); + if (vm->def->nhostdevs > 1) { memmove(vm->def->hostdevs + i, vm->def->hostdevs + i + 1, @@ -1717,6 +1776,9 @@ int qemuDomainDetachHostDevice(struct qemud_driver *driver, vm, dev->data.hostdev) < 0) VIR_WARN0("Failed to restore host device labelling"); + if (ret == 0) + qemudLogWrite(driver, vm, true, ": detaching host device\n"); + return ret; } -- 1.7.3.4

On Mon, Mar 28, 2011 at 05:13:47PM +0900, Naoya Horiguchi wrote:
The following events can be logged onto /var/log/libvirt/qemu/<domain>.log:
starting/shutting down/suspending/resuming/migrating domains changing the amount of memory changing the number of VCPUs inserting/ejecting a media into/from CDROM/Floppy devices attaching/detaching PCI/SCSI/USB devices (including NICs and disks.)
This patch generalizes qemudLog*() introduced in commit 93bc093ac to handle the whole range of qemu driver's events.
This is useful for the same reason as explainged in the previous patch.
I think we need to think about the question of logging in a more thorough way. - libvirt.c: Logs invocation of every API call - qemu/driver.c/qemu_audit.c: Logs major lifecycle changes & any config change that is related host resources - virterror.c: Logs any API call that results in an error - qemu_driver.c: Logs a set of lifecycle/config changes (your previous patch 1/2) at VIR_INFO - qemu_driver.c: Logs a different set of lifecycle/config changes in /var/log/libvirt/qemu/<domain>.loog I don't think the latter two are particularly great because they are only cover a fraction of the API calls in the QEMU driver. libvirt.c has full logging cover, but it only covers API calls, it doesn't indicate whether it was successful or failed. For SystemTAP, we likely want to add probes to libvirt.c which will log initial parameters, and the return values. Our SystemTAP probe macros also generate log statements. A further complication is that /var/log/libvirt/qemu/$NAME.log is intended for QEMU's stderr output. The only time that libvirtd currently writes to it, is before QEMU starts and after it has shutdown. This new patch means that libvirtd writes to it while QEMU is running, which is not really safe because you can now end up with 2 proceses writing to the same file at once. The log messages may well get interleaved/corrupted by each other. I don't think that is good for something that wants to be used as a formal record of operations on a VM. I think that in each driver we only really want to have to insert one set of formal "operation logging" calls. Since we already have the audit APIs present, I think we could try to make use of that to generate a record of operations against a VM in some way. Regards, 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 :|

Hi, On Mon, Apr 04, 2011 at 03:55:26PM +0100, Daniel P. Berrange wrote:
On Mon, Mar 28, 2011 at 05:13:47PM +0900, Naoya Horiguchi wrote:
The following events can be logged onto /var/log/libvirt/qemu/<domain>.log:
starting/shutting down/suspending/resuming/migrating domains changing the amount of memory changing the number of VCPUs inserting/ejecting a media into/from CDROM/Floppy devices attaching/detaching PCI/SCSI/USB devices (including NICs and disks.)
This patch generalizes qemudLog*() introduced in commit 93bc093ac to handle the whole range of qemu driver's events.
This is useful for the same reason as explainged in the previous patch.
I think we need to think about the question of logging in a more thorough way.
- libvirt.c: Logs invocation of every API call - qemu/driver.c/qemu_audit.c: Logs major lifecycle changes & any config change that is related host resources - virterror.c: Logs any API call that results in an error - qemu_driver.c: Logs a set of lifecycle/config changes (your previous patch 1/2) at VIR_INFO - qemu_driver.c: Logs a different set of lifecycle/config changes in /var/log/libvirt/qemu/<domain>.loog
Thank you for detailed explanation.
I don't think the latter two are particularly great because they are only cover a fraction of the API calls in the QEMU driver. libvirt.c has full logging cover, but it only covers API calls, it doesn't indicate whether it was successful or failed.
I see.
For SystemTAP, we likely want to add probes to libvirt.c which will log initial parameters, and the return values. Our SystemTAP probe macros also generate log statements.
A further complication is that /var/log/libvirt/qemu/$NAME.log is intended for QEMU's stderr output. The only time that libvirtd currently writes to it, is before QEMU starts and after it has shutdown.
OK.
This new patch means that libvirtd writes to it while QEMU is running, which is not really safe because you can now end up with 2 proceses writing to the same file at once. The log messages may well get interleaved/corrupted by each other. I don't think that is good for something that wants to be used as a formal record of operations on a VM.
I think that in each driver we only really want to have to insert one set of formal "operation logging" calls. Since we already have the audit APIs present, I think we could try to make use of that to generate a record of operations against a VM in some way.
I didn't care about audit logging because it's not used in RHEL6.0. I tried this logging mechanism and made sure that this logging recorded enough information about operational events in /var/log/libvirt/libvirtd.log. This feature meets our demand, so I'll drop this patch. Thanks, Naoya
participants (3)
-
Daniel P. Berrange
-
Daniel Veillard
-
Naoya Horiguchi