[PATCH 0/7] Remove overhead of disabled logging calls

[Date Prev][Date Next][Thread Prev][Thread Next][Date Index][Thread Index]

 



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




[Index of Archives]     [Virt Tools]     [Libvirt Users]     [Lib OS Info]     [Fedora Users]     [Fedora Desktop]     [Fedora SELinux]     [Big List of Linux Books]     [Yosemite News]     [KDE Users]     [Fedora Tools]