From f35e9b101d80c05d5a5eaece6e62e8eeb5743691 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Zbigniew=20J=C4=99drzejewski-Szmek?= Date: Tue, 1 Jun 2021 09:55:09 +0200 Subject: [PATCH 1/6] varlink: say "varlink:" instead of "n/a:" when no description is available For new connections, we log something like this: systemd[1]: n/a: New incoming connection. systemd[1]: n/a: Connections of user 997: 0 (of 1024 max) systemd[1]: varlink-22: varlink: setting state idle-server systemd[1]: varlink-22: New incoming message: ... This "n/a" is not very pretty, and without context it would be hard to even figure out this is a varlink connection. --- src/shared/varlink.c | 4 ++-- 1 file changed, 2 insertions(+), 2 deletions(-) diff --git a/src/shared/varlink.c b/src/shared/varlink.c index e77b144779..2542d90668 100644 --- a/src/shared/varlink.c +++ b/src/shared/varlink.c @@ -221,11 +221,11 @@ DEFINE_PRIVATE_STRING_TABLE_LOOKUP_TO_STRING(varlink_state, VarlinkState); log_debug("%s: " fmt, varlink_server_description(s), ##__VA_ARGS__) static inline const char *varlink_description(Varlink *v) { - return strna(v ? v->description : NULL); + return (v ? v->description : NULL) ?: "varlink"; } static inline const char *varlink_server_description(VarlinkServer *s) { - return strna(s ? s->description : NULL); + return (s ? s->description : NULL) ?: "varlink"; } static void varlink_set_state(Varlink *v, VarlinkState state) { From 953394e3bb1f1ead3c1d80237b97b71835b0755a Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Zbigniew=20J=C4=99drzejewski-Szmek?= Date: Tue, 1 Jun 2021 10:00:01 +0200 Subject: [PATCH 2/6] varlink: remove duplicated "varlink:" prefix MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit We had: systemd[1]: varlink-36: New incoming message: {"method":"io.systemd.UserDatabase.GetMemberships","parameters":{"userName":"gdm","service":"io.systemd.DynamicUser"},"more":true} systemd[1]: varlink-36: varlink: changing state idle-server → processing-method-more systemd[1]: varlink-36: Sending message: {"error":"io.systemd.UserDatabase.NoRecordFound","parameters":{}} systemd[1]: varlink-36: varlink: changing state processing-method-more → processed-method systemd[1]: varlink-36: varlink: changing state processed-method → idle-server systemd[1]: varlink-36: Got POLLHUP from socket. systemd[1]: varlink-36: varlink: changing state idle-server → pending-disconnect systemd[1]: varlink-36: varlink: changing state pending-disconnect → processing-disconnect systemd[1]: varlink-36: varlink: changing state processing-disconnect → disconnected So let's drop the "varlink:" prefix and use capitalized sentences like in other messages. --- src/shared/varlink.c | 4 ++-- 1 file changed, 2 insertions(+), 2 deletions(-) diff --git a/src/shared/varlink.c b/src/shared/varlink.c index 2542d90668..6b0b343ae9 100644 --- a/src/shared/varlink.c +++ b/src/shared/varlink.c @@ -233,10 +233,10 @@ static void varlink_set_state(Varlink *v, VarlinkState state) { assert(state >= 0 && state < _VARLINK_STATE_MAX); if (v->state < 0) - varlink_log(v, "varlink: setting state %s", + varlink_log(v, "Setting state %s", varlink_state_to_string(state)); else - varlink_log(v, "varlink: changing state %s → %s", + varlink_log(v, "Changing state %s → %s", varlink_state_to_string(v->state), varlink_state_to_string(state)); From 5b326dee29d6bc8a331a1d72293a3c6acee10879 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Zbigniew=20J=C4=99drzejewski-Szmek?= Date: Tue, 1 Jun 2021 12:56:33 +0200 Subject: [PATCH 3/6] TODO: add entry about alias logging --- TODO | 4 ++++ 1 file changed, 4 insertions(+) diff --git a/TODO b/TODO index 084a8540b3..739c29f07b 100644 --- a/TODO +++ b/TODO @@ -9,6 +9,10 @@ Bugfixes: * Get rid of nftw(). We should refuse to use such useless APIs on principle. +* Jun 01 09:43:02 krowka systemd[1]: Unit user@1000.service has alias user@.service. + Jun 01 09:43:02 krowka systemd[1]: Unit user@6.service has alias user@.service. + Jun 01 09:43:02 krowka systemd[1]: Unit user-runtime-dir@6.service has alias user-runtime-dir@.service. + External: * Fedora: add an rpmlint check that verifies that all unit files in the RPM are listed in %systemd_post macros. From 2a341bb9d2a3cd28115e88291414fa67ca7035c3 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Zbigniew=20J=C4=99drzejewski-Szmek?= Date: Tue, 1 Jun 2021 15:25:44 +0200 Subject: [PATCH 4/6] core: split out core/manager-dump.[ch] This is a fairly specialized topic, let's create a separate file for it. --- src/core/dbus-manager.c | 1 + src/core/execute.c | 1 + src/core/fuzz-unit-file.c | 1 + src/core/main.c | 13 +----- src/core/manager-dump.c | 85 +++++++++++++++++++++++++++++++++++++++ src/core/manager-dump.h | 12 ++++++ src/core/manager.c | 69 +------------------------------ src/core/manager.h | 5 --- src/core/meson.build | 2 + src/test/test-engine.c | 1 + 10 files changed, 106 insertions(+), 84 deletions(-) create mode 100644 src/core/manager-dump.c create mode 100644 src/core/manager-dump.h diff --git a/src/core/dbus-manager.c b/src/core/dbus-manager.c index 128d7778f5..68a108742a 100644 --- a/src/core/dbus-manager.c +++ b/src/core/dbus-manager.c @@ -26,6 +26,7 @@ #include "fs-util.h" #include "install.h" #include "log.h" +#include "manager-dump.h" #include "os-util.h" #include "parse-util.h" #include "path-util.h" diff --git a/src/core/execute.c b/src/core/execute.c index 3d750ee06e..5c30d0bcbe 100644 --- a/src/core/execute.c +++ b/src/core/execute.c @@ -64,6 +64,7 @@ #include "log.h" #include "macro.h" #include "manager.h" +#include "manager-dump.h" #include "memory-util.h" #include "missing_fs.h" #include "mkdir.h" diff --git a/src/core/fuzz-unit-file.c b/src/core/fuzz-unit-file.c index 311ffcecc1..aef29f4cf7 100644 --- a/src/core/fuzz-unit-file.c +++ b/src/core/fuzz-unit-file.c @@ -6,6 +6,7 @@ #include "fuzz.h" #include "install.h" #include "load-fragment.h" +#include "manager-dump.h" #include "string-util.h" #include "unit-serialize.h" #include "utf8.h" diff --git a/src/core/main.c b/src/core/main.c index 1336be494a..906c1482d7 100644 --- a/src/core/main.c +++ b/src/core/main.c @@ -54,6 +54,7 @@ #include "loopback-setup.h" #include "machine-id-setup.h" #include "manager.h" +#include "manager-dump.h" #include "mkdir.h" #include "mount-setup.h" #include "os-util.h" @@ -2500,16 +2501,6 @@ static int initialize_security( return 0; } -static void test_summary(Manager *m) { - assert(m); - - printf("-> By units:\n"); - manager_dump_units(m, stdout, "\t"); - - printf("-> By jobs:\n"); - manager_dump_jobs(m, stdout, "\t"); -} - static int collect_fds(FDSet **ret_fds, const char **ret_error_message) { int r; @@ -2882,7 +2873,7 @@ int main(int argc, char *argv[]) { format_timespan(timespan, sizeof(timespan), after_startup - before_startup, 100 * USEC_PER_MSEC)); if (arg_action == ACTION_TEST) { - test_summary(m); + manager_test_summary(m); retval = EXIT_SUCCESS; goto finish; } diff --git a/src/core/manager-dump.c b/src/core/manager-dump.c new file mode 100644 index 0000000000..850ee36523 --- /dev/null +++ b/src/core/manager-dump.c @@ -0,0 +1,85 @@ +/* SPDX-License-Identifier: LGPL-2.1-or-later */ + +#include "fd-util.h" +#include "fileio.h" +#include "hashmap.h" +#include "manager-dump.h" +#include "unit-serialize.h" + +void manager_dump_jobs(Manager *s, FILE *f, const char *prefix) { + Job *j; + + assert(s); + assert(f); + + HASHMAP_FOREACH(j, s->jobs) + job_dump(j, f, prefix); +} + +void manager_dump_units(Manager *s, FILE *f, const char *prefix) { + Unit *u; + const char *t; + + assert(s); + assert(f); + + HASHMAP_FOREACH_KEY(u, t, s->units) + if (u->id == t) + unit_dump(u, f, prefix); +} + +void manager_dump(Manager *m, FILE *f, const char *prefix) { + assert(m); + assert(f); + + for (ManagerTimestamp q = 0; q < _MANAGER_TIMESTAMP_MAX; q++) { + const dual_timestamp *t = m->timestamps + q; + char buf[CONST_MAX(FORMAT_TIMESPAN_MAX, FORMAT_TIMESTAMP_MAX)]; + + if (dual_timestamp_is_set(t)) + fprintf(f, "%sTimestamp %s: %s\n", + strempty(prefix), + manager_timestamp_to_string(q), + timestamp_is_set(t->realtime) ? format_timestamp(buf, sizeof buf, t->realtime) : + format_timespan(buf, sizeof buf, t->monotonic, 1)); + } + + manager_dump_units(m, f, prefix); + manager_dump_jobs(m, f, prefix); +} + +int manager_get_dump_string(Manager *m, char **ret) { + _cleanup_free_ char *dump = NULL; + _cleanup_fclose_ FILE *f = NULL; + size_t size; + int r; + + assert(m); + assert(ret); + + f = open_memstream_unlocked(&dump, &size); + if (!f) + return -errno; + + manager_dump(m, f, NULL); + + r = fflush_and_check(f); + if (r < 0) + return r; + + f = safe_fclose(f); + + *ret = TAKE_PTR(dump); + + return 0; +} + +void manager_test_summary(Manager *m) { + assert(m); + + printf("-> By units:\n"); + manager_dump_units(m, stdout, "\t"); + + printf("-> By jobs:\n"); + manager_dump_jobs(m, stdout, "\t"); +} diff --git a/src/core/manager-dump.h b/src/core/manager-dump.h new file mode 100644 index 0000000000..317a4b641c --- /dev/null +++ b/src/core/manager-dump.h @@ -0,0 +1,12 @@ +/* SPDX-License-Identifier: LGPL-2.1-or-later */ +#pragma once + +#include + +#include "manager.h" + +void manager_dump_jobs(Manager *s, FILE *f, const char *prefix); +void manager_dump_units(Manager *s, FILE *f, const char *prefix); +void manager_dump(Manager *s, FILE *f, const char *prefix); +int manager_get_dump_string(Manager *m, char **ret); +void manager_test_summary(Manager *m); diff --git a/src/core/manager.c b/src/core/manager.c index d96280667a..dd6e7693d0 100644 --- a/src/core/manager.c +++ b/src/core/manager.c @@ -55,6 +55,7 @@ #include "log.h" #include "macro.h" #include "manager.h" +#include "manager-dump.h" #include "memory-util.h" #include "mkdir.h" #include "parse-util.h" @@ -2154,74 +2155,6 @@ int manager_load_startable_unit_or_warn( return 0; } -void manager_dump_jobs(Manager *s, FILE *f, const char *prefix) { - Job *j; - - assert(s); - assert(f); - - HASHMAP_FOREACH(j, s->jobs) - job_dump(j, f, prefix); -} - -void manager_dump_units(Manager *s, FILE *f, const char *prefix) { - Unit *u; - const char *t; - - assert(s); - assert(f); - - HASHMAP_FOREACH_KEY(u, t, s->units) - if (u->id == t) - unit_dump(u, f, prefix); -} - -void manager_dump(Manager *m, FILE *f, const char *prefix) { - assert(m); - assert(f); - - for (ManagerTimestamp q = 0; q < _MANAGER_TIMESTAMP_MAX; q++) { - const dual_timestamp *t = m->timestamps + q; - char buf[CONST_MAX(FORMAT_TIMESPAN_MAX, FORMAT_TIMESTAMP_MAX)]; - - if (dual_timestamp_is_set(t)) - fprintf(f, "%sTimestamp %s: %s\n", - strempty(prefix), - manager_timestamp_to_string(q), - timestamp_is_set(t->realtime) ? format_timestamp(buf, sizeof buf, t->realtime) : - format_timespan(buf, sizeof buf, t->monotonic, 1)); - } - - manager_dump_units(m, f, prefix); - manager_dump_jobs(m, f, prefix); -} - -int manager_get_dump_string(Manager *m, char **ret) { - _cleanup_free_ char *dump = NULL; - _cleanup_fclose_ FILE *f = NULL; - size_t size; - int r; - - assert(m); - assert(ret); - - f = open_memstream_unlocked(&dump, &size); - if (!f) - return -errno; - - manager_dump(m, f, NULL); - - r = fflush_and_check(f); - if (r < 0) - return r; - - f = safe_fclose(f); - - *ret = TAKE_PTR(dump); - - return 0; -} - void manager_clear_jobs(Manager *m) { Job *j; diff --git a/src/core/manager.h b/src/core/manager.h index c4d4b2c375..b3e7c68e6d 100644 --- a/src/core/manager.h +++ b/src/core/manager.h @@ -485,11 +485,6 @@ int manager_add_job_by_name(Manager *m, JobType type, const char *name, JobMode int manager_add_job_by_name_and_warn(Manager *m, JobType type, const char *name, JobMode mode, Set *affected_jobs, Job **ret); int manager_propagate_reload(Manager *m, Unit *unit, JobMode mode, sd_bus_error *e); -void manager_dump_units(Manager *s, FILE *f, const char *prefix); -void manager_dump_jobs(Manager *s, FILE *f, const char *prefix); -void manager_dump(Manager *s, FILE *f, const char *prefix); -int manager_get_dump_string(Manager *m, char **ret); - void manager_clear_jobs(Manager *m); void manager_unwatch_pid(Manager *m, pid_t pid); diff --git a/src/core/meson.build b/src/core/meson.build index 06f0e8b5db..e696d27727 100644 --- a/src/core/meson.build +++ b/src/core/meson.build @@ -85,6 +85,8 @@ libcore_sources = ''' locale-setup.h manager.c manager.h + manager-dump.c + manager-dump.h mount.c mount.h namespace.c diff --git a/src/test/test-engine.c b/src/test/test-engine.c index 1039709b89..6dc16193d3 100644 --- a/src/test/test-engine.c +++ b/src/test/test-engine.c @@ -5,6 +5,7 @@ #include "bus-util.h" #include "manager.h" +#include "manager-dump.h" #include "rm-rf.h" #include "service.h" #include "special.h" From 0517ececff1d56694f07543a1707f1f061e9e9e8 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Zbigniew=20J=C4=99drzejewski-Szmek?= Date: Tue, 1 Jun 2021 16:46:53 +0200 Subject: [PATCH 5/6] core: show manager version in dump This makes it easier to not get lost which one is which when comparing two dumps. --- src/core/manager-dump.c | 4 ++++ 1 file changed, 4 insertions(+) diff --git a/src/core/manager-dump.c b/src/core/manager-dump.c index 850ee36523..dba32464e2 100644 --- a/src/core/manager-dump.c +++ b/src/core/manager-dump.c @@ -1,5 +1,6 @@ /* SPDX-License-Identifier: LGPL-2.1-or-later */ +#include "build.h" #include "fd-util.h" #include "fileio.h" #include "hashmap.h" @@ -32,6 +33,9 @@ void manager_dump(Manager *m, FILE *f, const char *prefix) { assert(m); assert(f); + fprintf(f, "%sManager: systemd " STRINGIFY(PROJECT_VERSION) " (" GIT_VERSION ")\n", strempty(prefix)); + fprintf(f, "%sFeatures: %s\n", strempty(prefix), systemd_features); + for (ManagerTimestamp q = 0; q < _MANAGER_TIMESTAMP_MAX; q++) { const dual_timestamp *t = m->timestamps + q; char buf[CONST_MAX(FORMAT_TIMESPAN_MAX, FORMAT_TIMESTAMP_MAX)]; From 0d5a24beaedb161d4f7fe07361d2a5abdbd6e736 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Zbigniew=20J=C4=99drzejewski-Szmek?= Date: Tue, 1 Jun 2021 17:40:51 +0200 Subject: [PATCH 6/6] various: don't say that the timestamp 'changed' on initial load I always found this a bit annoying. With the patch: $ SYSTEMD_LOG_LEVEL=debug build/udevadm test /sys/class/block/dm-1 ... Loaded timestamp for '/etc/systemd/network'. Loaded timestamp for '/usr/lib/systemd/network'. Parsed configuration file /usr/lib/systemd/network/99-default.link Parsed configuration file /etc/systemd/network/10-eth0.link Created link configuration context. Loaded timestamp for '/etc/udev/rules.d'. Loaded timestamp for '/usr/lib/udev/rules.d'. ... --- src/basic/path-util.c | 8 +++++--- 1 file changed, 5 insertions(+), 3 deletions(-) diff --git a/src/basic/path-util.c b/src/basic/path-util.c index 82f3709042..eb547e7467 100644 --- a/src/basic/path-util.c +++ b/src/basic/path-util.c @@ -713,7 +713,7 @@ int find_executable_full(const char *name, bool use_path_envvar, char **ret_file } bool paths_check_timestamp(const char* const* paths, usec_t *timestamp, bool update) { - bool changed = false; + bool changed = false, originally_unset; const char* const* i; assert(timestamp); @@ -721,6 +721,8 @@ bool paths_check_timestamp(const char* const* paths, usec_t *timestamp, bool upd if (!paths) return false; + originally_unset = *timestamp == 0; + STRV_FOREACH(i, paths) { struct stat stats; usec_t u; @@ -730,11 +732,11 @@ bool paths_check_timestamp(const char* const* paths, usec_t *timestamp, bool upd u = timespec_load(&stats.st_mtim); - /* first check */ + /* check first */ if (*timestamp >= u) continue; - log_debug("timestamp of '%s' changed", *i); + log_debug(originally_unset ? "Loaded timestamp for '%s'." : "Timestamp of '%s' changed.", *i); /* update timestamp */ if (update) {