From: Vito Caputo Date: Tue, 27 Oct 2020 06:24:34 +0000 (-0700) Subject: logs-show: move show_journal_by_unit _BOOT_ID match X-Git-Tag: v248-rc1~85 X-Git-Url: http://git.ipfire.org/gitweb.cgi?a=commitdiff_plain;h=f82027042a6b4acb2aed8fa8010393df8fd12656;p=thirdparty%2Fsystemd.git logs-show: move show_journal_by_unit _BOOT_ID match In scrutinizing the journal overhead of `systemctl status $service` it became apparent that the matching engine was performing the unit matches on every journal in my system, even ones containing nothing relevant to the current boot. This seemed strange and likely suboptimal to me, since there's likely far more unit data to rifle through than boot IDs in any given journal. The _BOOT_ID match seemed like it should be serving as an early exit match on irrelevant journals, but that wasn't what seemed to be happening. As a quick experiment to see if I could get the _BOOT_ID match to be something along the lines of a higher priority when matching, and try early exit on these unrelated journals, I moved add_match_this_boot() to after the unit match adds, inserting a conjunction between them. The end result seems to be a very substantial performance gain in my simple uncached tests, and I still get the expected journal output from the `systemctl status $service` command: ---------------------------------------------------------------------- Unmodified systemctl times: root@localhost:/# echo 2 > /proc/sys/vm/drop_caches root@localhost:/# time systemctl --no-pager status dbus ● dbus.service - D-Bus System Message Bus Loaded: loaded (/lib/systemd/system/dbus.service; static; vendor preset: enabled) Active: active (running) since Sun 2020-10-25 17:03:05 PDT; 1 day 6h ago Docs: man:dbus-daemon(1) Main PID: 572 (dbus-daemon) Memory: 2.8M CPU: 110ms CGroup: /system.slice/dbus.service └─572 /usr/bin/dbus-daemon --system --address=systemd: --nofork --nopidfile --systemd-activation Oct 25 17:03:05 localhost systemd[1]: Started D-Bus System Message Bus. Oct 25 17:06:26 localhost dbus[572]: [system] Activating via systemd: service name='org.freedesktop.machine1' unit='dbus-org.freedesktop.machine1.service' Oct 25 17:06:26 localhost dbus[572]: [system] Successfully activated service 'org.freedesktop.machine1' real 0m0.695s user 0m0.005s sys 0m0.043s root@localhost:/# echo 2 > /proc/sys/vm/drop_caches root@localhost:/# time systemctl --no-pager status dbus ● dbus.service - D-Bus System Message Bus Loaded: loaded (/lib/systemd/system/dbus.service; static; vendor preset: enabled) Active: active (running) since Sun 2020-10-25 17:03:05 PDT; 1 day 6h ago Docs: man:dbus-daemon(1) Main PID: 572 (dbus-daemon) Memory: 2.8M CPU: 110ms CGroup: /system.slice/dbus.service └─572 /usr/bin/dbus-daemon --system --address=systemd: --nofork --nopidfile --systemd-activation Oct 25 17:03:05 localhost systemd[1]: Started D-Bus System Message Bus. Oct 25 17:06:26 localhost dbus[572]: [system] Activating via systemd: service name='org.freedesktop.machine1' unit='dbus-org.freedesktop.machine1.service' Oct 25 17:06:26 localhost dbus[572]: [system] Successfully activated service 'org.freedesktop.machine1' real 0m0.696s user 0m0.003s sys 0m0.046s root@localhost:/# echo 2 > /proc/sys/vm/drop_caches root@localhost:/# time systemctl --no-pager status dbus ● dbus.service - D-Bus System Message Bus Loaded: loaded (/lib/systemd/system/dbus.service; static; vendor preset: enabled) Active: active (running) since Sun 2020-10-25 17:03:05 PDT; 1 day 6h ago Docs: man:dbus-daemon(1) Main PID: 572 (dbus-daemon) Memory: 2.8M CPU: 110ms CGroup: /system.slice/dbus.service └─572 /usr/bin/dbus-daemon --system --address=systemd: --nofork --nopidfile --systemd-activation Oct 25 17:03:05 localhost systemd[1]: Started D-Bus System Message Bus. Oct 25 17:06:26 localhost dbus[572]: [system] Activating via systemd: service name='org.freedesktop.machine1' unit='dbus-org.freedesktop.machine1.service' Oct 25 17:06:26 localhost dbus[572]: [system] Successfully activated service 'org.freedesktop.machine1' real 0m0.694s user 0m0.006s sys 0m0.041s ---------------------------------------------------------------------- Modified systemctl including this commit: root@localhost:/home/vc/gh/systemd/build# echo 2 > /proc/sys/vm/drop_caches root@localhost:/home/vc/gh/systemd/build# time ./systemctl --no-pager status dbus ● dbus.service - D-Bus System Message Bus Loaded: loaded (/lib/systemd/system/dbus.service; static) Active: active (running) since Sun 2020-10-25 17:03:05 PDT; 1 day 6h ago TriggeredBy: ● dbus.socket Docs: man:dbus-daemon(1) Main PID: 572 (dbus-daemon) Memory: 2.8M CPU: 110ms CGroup: /system.slice/dbus.service └─572 /usr/bin/dbus-daemon --system --address=systemd: --nofork --nopidfile --systemd-activation Oct 25 17:03:05 localhost systemd[1]: Started D-Bus System Message Bus. Oct 25 17:06:26 localhost dbus[572]: [system] Activating via systemd: service name='org.freedesktop.machine1' unit='dbus-org.freedesktop.machine1.service' Oct 25 17:06:26 localhost dbus[572]: [system] Successfully activated service 'org.freedesktop.machine1' real 0m0.168s user 0m0.003s sys 0m0.016s root@localhost:/home/vc/gh/systemd/build# echo 2 > /proc/sys/vm/drop_caches root@localhost:/home/vc/gh/systemd/build# time ./systemctl --no-pager status dbus ● dbus.service - D-Bus System Message Bus Loaded: loaded (/lib/systemd/system/dbus.service; static) Active: active (running) since Sun 2020-10-25 17:03:05 PDT; 1 day 6h ago TriggeredBy: ● dbus.socket Docs: man:dbus-daemon(1) Main PID: 572 (dbus-daemon) Memory: 2.8M CPU: 110ms CGroup: /system.slice/dbus.service └─572 /usr/bin/dbus-daemon --system --address=systemd: --nofork --nopidfile --systemd-activation Oct 25 17:03:05 localhost systemd[1]: Started D-Bus System Message Bus. Oct 25 17:06:26 localhost dbus[572]: [system] Activating via systemd: service name='org.freedesktop.machine1' unit='dbus-org.freedesktop.machine1.service' Oct 25 17:06:26 localhost dbus[572]: [system] Successfully activated service 'org.freedesktop.machine1' real 0m0.167s user 0m0.005s sys 0m0.013s root@localhost:/home/vc/gh/systemd/build# echo 2 > /proc/sys/vm/drop_caches root@localhost:/home/vc/gh/systemd/build# time ./systemctl --no-pager status dbus ● dbus.service - D-Bus System Message Bus Loaded: loaded (/lib/systemd/system/dbus.service; static) Active: active (running) since Sun 2020-10-25 17:03:05 PDT; 1 day 6h ago TriggeredBy: ● dbus.socket Docs: man:dbus-daemon(1) Main PID: 572 (dbus-daemon) Memory: 2.8M CPU: 110ms CGroup: /system.slice/dbus.service └─572 /usr/bin/dbus-daemon --system --address=systemd: --nofork --nopidfile --systemd-activation Oct 25 17:03:05 localhost systemd[1]: Started D-Bus System Message Bus. Oct 25 17:06:26 localhost dbus[572]: [system] Activating via systemd: service name='org.freedesktop.machine1' unit='dbus-org.freedesktop.machine1.service' Oct 25 17:06:26 localhost dbus[572]: [system] Successfully activated service 'org.freedesktop.machine1' real 0m0.170s user 0m0.005s sys 0m0.014s --- diff --git a/src/shared/logs-show.c b/src/shared/logs-show.c index 948bdb5ce95..a217c1e0810 100644 --- a/src/shared/logs-show.c +++ b/src/shared/logs-show.c @@ -1635,10 +1635,6 @@ int show_journal_by_unit( if (r < 0) return log_error_errno(r, "Failed to open journal: %m"); - r = add_match_this_boot(j, NULL); - if (r < 0) - return r; - if (system_unit) r = add_matches_for_unit(j, unit); else @@ -1646,6 +1642,14 @@ int show_journal_by_unit( if (r < 0) return log_error_errno(r, "Failed to add unit matches: %m"); + r = sd_journal_add_conjunction(j); + if (r < 0) + return log_error_errno(r, "Failed to add conjunction: %m"); + + r = add_match_this_boot(j, NULL); + if (r < 0) + return r; + if (DEBUG_LOGGING) { _cleanup_free_ char *filter;