Looking at the performance of the libvirtd event loop when used with libvirt sandbox and apps which do lots of I/O I discovered that a huge amount of time was being spent in our logging APIs making the event loop quite poor at dealing with frequently firing poll events for small data sizes. To track this down I created the following short demo program which simulates a libvirtd event loop thread, watching 500 FDs (eg 500 QEMU or LXC console or monitor FDs). In the test no logging outputs are enabled, so ideally the log overhead would be near zero. Running the demo for 51200 iterations initially took 1 minute 40 seconds. oprofile traces show that in this test run the logging APIs were totally dominant in CPU time, over the work done in the event loop. Note the demo program's FD handler doesn't actually do any work, so this is showing the worst case behaviour, but it is none-the-less a good illustration of the loggin overhead. After refactoring the logging code, the overhead of logging calls when no outputs are enabled is reduced to a single function call which does 2 integer comparisons without any mutex locks. The demo program now completes in 3.3 seconds. IOW, 97% of the original CPU time for the demo was consumed by the logging APIs ! The main feature we loose in this series is the global logging buffer. This ring buffer currently collects all log mesages regardless of log filter settings, and dumps them to stderr upon crash of libvirtd. As the amount of logging code in libvirt has grown, the signal/noise ratio of data in the global log buffer has gone down significantly. Whenever libvirtd crashes, my first reaction to ask the reporter to reproduce with a specifically tailored set of log filters set. Thus, IMHO, the global log buffer is no longer a compelling enough feature to justify its significant performance overhead. Rather than remove it entirely though, I've changed it in two parts. The first patch removes the overhead of it, but leaves a more tailored verson of it still present. This removes the contribution it makes to performance overheads. The last patch, which is not performance relevant, simply deletes the rest of the global log buffer entirely. I'm mostly ambivalent on whether to apply patch 7 or not. IMHO the global log buffer is mostly useless once patch 1 is applied, but if people think it is worth keeping it, patch 7 can be dropped and I won't mind. The demo program used is $ cat demo.c #include <libvirt/libvirt.h> #include <unistd.h> #include <stdio.h> static void ignore(int handle, int fd, int events, void *opaque) { // nada } #define STEPS (1024 * 5) #define ITERATIONS (STEPS * 10) #define NFILES 500 int main(int argc, char **argv) { int fds[NFILES][2]; int i; virEventRegisterDefaultImpl(); for (i = 0 ; i < NFILES ; i++) { char c = '0'; if (pipe(fds[i]) < 0) { perror("pipe"); return -1; } if (write(fds[i][1], &c, 1) < 0) return -1; virEventAddHandle(fds[i][0], VIR_EVENT_HANDLE_READABLE, ignore, NULL, NULL); } for (i = 0 ; i < ITERATIONS ; i++) { if (!(i % STEPS)) fprintf(stderr, "."); virEventRunDefaultImpl(); } return 0; } Simply compile & run it with no args $ gcc -Wall `pkg-config --cflags --libs libvirt` -o demo demo.c $ time ./demo .......... real 1m39.981s user 1m34.894s sys 0m4.851s Now make it use the newly compiled libvirt version $ export LD_LIBRARY_PATH=`pwd`/src/.libs $ time ./demo .......... real 0m3.316s user 0m2.896s sys 0m0.412s 97% execution time removed ! Daniel P. Berrange (7): Reduce performance overhead of the global log buffer Refactor code that skips logging of error messages Move dtrace probe macros into separate header file Turn virLogSource into a struct instead of an enum Add virLogSource variables to all source files Switch to filtering based on log source name instead of filename Remove global log buffer feature entirely daemon/libvirtd-config.c | 5 +- daemon/libvirtd-config.h | 1 - daemon/libvirtd.aug | 1 - daemon/libvirtd.c | 5 +- daemon/libvirtd.conf | 7 - daemon/libvirtd.h | 1 - daemon/remote.c | 3 + daemon/stream.c | 2 + daemon/test_libvirtd.aug.in | 1 - docs/apibuild.py | 30 +++ docs/logging.html.in | 10 - src/access/viraccessdriverpolkit.c | 3 + src/access/viraccessmanager.c | 3 + src/bhyve/bhyve_command.c | 2 + src/bhyve/bhyve_driver.c | 2 + src/bhyve/bhyve_process.c | 2 + src/conf/domain_audit.c | 2 + src/conf/domain_conf.c | 2 + src/conf/domain_event.c | 1 + src/conf/network_event.c | 2 + src/conf/nwfilter_params.c | 2 + src/conf/object_event.c | 2 + src/conf/secret_conf.c | 2 + src/conf/snapshot_conf.c | 2 + src/conf/storage_conf.c | 1 - src/conf/virchrdev.c | 2 + src/cpu/cpu.c | 2 + src/cpu/cpu_powerpc.c | 2 + src/cpu/cpu_x86.c | 2 + src/datatypes.c | 2 + src/driver.c | 2 + src/esx/esx_device_monitor.c | 1 - src/esx/esx_driver.c | 2 + src/esx/esx_interface_driver.c | 2 - src/esx/esx_network_driver.c | 2 - src/esx/esx_nwfilter_driver.c | 2 - src/esx/esx_secret_driver.c | 2 - src/esx/esx_storage_backend_iscsi.c | 2 - src/esx/esx_storage_backend_vmfs.c | 2 + src/esx/esx_util.c | 2 +- src/esx/esx_vi.c | 2 +- src/esx/esx_vi_methods.c | 1 - src/esx/esx_vi_types.c | 2 +- src/fdstream.c | 2 + src/hyperv/hyperv_device_monitor.c | 2 - src/hyperv/hyperv_driver.c | 3 +- src/hyperv/hyperv_interface_driver.c | 2 - src/hyperv/hyperv_network_driver.c | 2 - src/hyperv/hyperv_nwfilter_driver.c | 2 - src/hyperv/hyperv_secret_driver.c | 2 - src/hyperv/hyperv_storage_driver.c | 2 - src/hyperv/hyperv_util.c | 2 +- src/hyperv/hyperv_wmi.c | 2 - src/interface/interface_backend_netcf.c | 2 + src/internal.h | 74 ------ src/libvirt-lxc.c | 2 + src/libvirt-qemu.c | 2 + src/libvirt.c | 2 + src/libxl/libxl_conf.c | 2 + src/libxl/libxl_domain.c | 1 + src/libxl/libxl_driver.c | 2 + src/locking/domain_lock.c | 2 + src/locking/lock_daemon.c | 4 +- src/locking/lock_daemon_config.c | 4 +- src/locking/lock_daemon_config.h | 1 - src/locking/lock_daemon_dispatch.c | 5 +- src/locking/lock_driver_lockd.c | 2 + src/locking/lock_driver_nop.c | 2 + src/locking/lock_driver_sanlock.c | 2 + src/locking/lock_manager.c | 2 + src/locking/test_virtlockd.aug.in | 2 - src/locking/virtlockd.aug | 1 - src/locking/virtlockd.conf | 7 - src/lxc/lxc_cgroup.c | 2 + src/lxc/lxc_conf.c | 2 + src/lxc/lxc_container.c | 2 + src/lxc/lxc_controller.c | 2 + src/lxc/lxc_domain.c | 2 + src/lxc/lxc_driver.c | 1 + src/lxc/lxc_fuse.c | 1 - src/lxc/lxc_hostdev.c | 2 + src/lxc/lxc_monitor.c | 2 + src/lxc/lxc_native.c | 1 + src/lxc/lxc_process.c | 2 + src/network/bridge_driver.c | 2 + src/network/bridge_driver_linux.c | 3 + src/network/bridge_driver_platform.h | 1 - src/node_device/node_device_driver.c | 2 - src/node_device/node_device_hal.c | 2 + src/node_device/node_device_linux_sysfs.c | 2 + src/node_device/node_device_udev.c | 4 +- src/nodeinfo.c | 1 - src/nwfilter/nwfilter_dhcpsnoop.c | 2 + src/nwfilter/nwfilter_driver.c | 2 + src/nwfilter/nwfilter_ebiptables_driver.c | 2 + src/nwfilter/nwfilter_gentech_driver.c | 1 + src/nwfilter/nwfilter_learnipaddr.c | 2 + src/openvz/openvz_driver.c | 2 + src/parallels/parallels_driver.c | 2 + src/phyp/phyp_driver.c | 3 + src/qemu/qemu_agent.c | 2 + src/qemu/qemu_bridge_filter.c | 1 - src/qemu/qemu_capabilities.c | 4 +- src/qemu/qemu_cgroup.c | 2 + src/qemu/qemu_command.c | 2 + src/qemu/qemu_conf.c | 2 + src/qemu/qemu_domain.c | 2 + src/qemu/qemu_driver.c | 2 + src/qemu/qemu_hostdev.c | 2 + src/qemu/qemu_hotplug.c | 3 + src/qemu/qemu_migration.c | 2 + src/qemu/qemu_monitor.c | 3 + src/qemu/qemu_monitor_json.c | 3 + src/qemu/qemu_monitor_text.c | 3 + src/qemu/qemu_process.c | 2 + src/remote/remote_driver.c | 2 + src/rpc/virkeepalive.c | 3 + src/rpc/virnetclient.c | 3 + src/rpc/virnetclientprogram.c | 2 + src/rpc/virnetclientstream.c | 2 + src/rpc/virnetmessage.c | 2 + src/rpc/virnetsaslcontext.c | 2 + src/rpc/virnetserver.c | 47 +--- src/rpc/virnetserverclient.c | 3 + src/rpc/virnetservermdns.c | 2 + src/rpc/virnetserverprogram.c | 2 + src/rpc/virnetsocket.c | 2 + src/rpc/virnetsshsession.c | 2 + src/rpc/virnettlscontext.c | 3 + src/secret/secret_driver.c | 2 + src/security/security_apparmor.c | 3 + src/security/security_dac.c | 3 + src/security/security_driver.c | 2 + src/security/security_manager.c | 1 + src/security/security_selinux.c | 2 + src/storage/storage_backend.c | 2 + src/storage/storage_backend_disk.c | 2 + src/storage/storage_backend_fs.c | 2 + src/storage/storage_backend_gluster.c | 2 + src/storage/storage_backend_iscsi.c | 2 + src/storage/storage_backend_logical.c | 2 + src/storage/storage_backend_mpath.c | 2 + src/storage/storage_backend_rbd.c | 2 + src/storage/storage_backend_scsi.c | 2 + src/storage/storage_backend_sheepdog.c | 1 - src/storage/storage_driver.c | 2 + src/test/test_driver.c | 2 + src/uml/uml_conf.c | 1 + src/uml/uml_driver.c | 2 + src/util/viralloc.c | 2 + src/util/virarch.c | 2 + src/util/viraudit.c | 9 +- src/util/viraudit.h | 10 +- src/util/virauth.c | 2 + src/util/virauthconfig.c | 1 + src/util/vircgroup.c | 2 + src/util/virclosecallbacks.c | 2 + src/util/vircommand.c | 2 + src/util/virconf.c | 2 + src/util/virdbus.c | 2 + src/util/virdnsmasq.c | 3 + src/util/virebtables.c | 2 + src/util/virerror.c | 16 +- src/util/virevent.c | 2 + src/util/vireventpoll.c | 3 + src/util/virfile.c | 2 + src/util/virhash.c | 2 + src/util/virhook.c | 2 + src/util/viridentity.c | 1 + src/util/viriptables.c | 2 + src/util/virjson.c | 1 + src/util/virkeyfile.c | 2 + src/util/virlockspace.c | 2 + src/util/virlog.c | 379 ++++-------------------------- src/util/virlog.h | 49 ++-- src/util/virnetdev.c | 2 + src/util/virnetdevmacvlan.c | 1 + src/util/virnetdevtap.c | 2 + src/util/virnetdevveth.c | 2 + src/util/virnetdevvportprofile.c | 2 + src/util/virnetlink.c | 2 + src/util/virnodesuspend.c | 2 + src/util/virnuma.c | 2 + src/util/virobject.c | 3 + src/util/virpci.c | 2 + src/util/virpidfile.c | 2 + src/util/virprobe.h | 100 ++++++++ src/util/virprocess.c | 2 + src/util/virrandom.c | 2 + src/util/virscsi.c | 1 - src/util/virstoragefile.c | 2 + src/util/virstring.c | 2 + src/util/virsysinfo.c | 1 - src/util/virsystemd.c | 1 + src/util/virusb.c | 2 + src/util/virutil.c | 2 + src/util/viruuid.c | 2 + src/vbox/vbox_MSCOMGlue.c | 2 + src/vbox/vbox_XPCOMCGlue.c | 1 + src/vbox/vbox_driver.c | 1 + src/vbox/vbox_tmpl.c | 3 + src/vmx/vmx.c | 2 + src/xen/xen_driver.c | 3 + src/xen/xen_hypervisor.c | 2 + src/xen/xen_inotify.c | 2 + src/xen/xend_internal.c | 2 + src/xen/xm_internal.c | 2 + src/xen/xs_internal.c | 2 + src/xenapi/xenapi_utils.c | 2 + src/xenxs/xen_sxpr.c | 2 + tests/domainconftest.c | 2 + tests/eventtest.c | 2 + tests/fdstreamtest.c | 2 + tests/libvirtdconftest.c | 2 + tests/qemumonitortestutils.c | 2 + tests/securityselinuxlabeltest.c | 2 + tests/securityselinuxtest.c | 2 + tests/sockettest.c | 2 + tests/testutils.c | 4 +- tests/virauthconfigtest.c | 2 + tests/vircgrouptest.c | 2 + tests/virdbustest.c | 2 + tests/virdrivermoduletest.c | 2 + tests/virhashtest.c | 2 + tests/viridentitytest.c | 1 + tests/virkeycodetest.c | 1 + tests/virkeyfiletest.c | 1 + tests/virlockspacetest.c | 2 + tests/virnetmessagetest.c | 2 + tests/virnetsockettest.c | 2 + tests/virnettlscontexttest.c | 2 + tests/virnettlshelpers.c | 2 + tests/virnettlssessiontest.c | 2 + tests/virportallocatortest.c | 1 + tests/virstoragetest.c | 2 + tests/virstringtest.c | 2 + tests/virsystemdtest.c | 2 + tests/virtimetest.c | 2 + tests/viruritest.c | 2 + tools/virsh-console.c | 2 + 240 files changed, 637 insertions(+), 563 deletions(-) create mode 100644 src/util/virprobe.h -- 1.8.5.3 -- libvir-list mailing list libvir-list@xxxxxxxxxx https://www.redhat.com/mailman/listinfo/libvir-list