1:18 p.m.
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