analyze: do not print timestamps before "start of userspace"

We have the following timestamp status:

  $ systemctl show systemd-fsck-root.service | grep InactiveExitTimestamp
  InactiveExitTimestamp=Thu 2023-11-02 12:27:24 CET
  InactiveExitTimestampMonotonic=15143158

  $ systemctl show | grep UserspaceTimestamp
  UserspaceTimestamp=Thu 2023-11-02 12:27:25 CET
  UserspaceTimestampMonotonic=15804273

i.e. UserspaceTimestamp is before InactiveExit of systemd-fsck-root.service.
This is fine, but on display, we'd subtract those values and print a huge
negative value bogusly:

  $ build/systemd-analyze critical-chain systemd-remount-fs.service
  The time when unit became active or started is printed after the "@" character.
  The time the unit took to start is printed after the "+" character.

  systemd-remount-fs.service +137ms
  └─systemd-fsck-root.service @584542y 2w 2d 20h 1min 48.890s +45ms
    └─systemd-journald.socket
      └─system.slice
        └─-.slice

In fact, list_dependencies_print() already had a branch where the check that
'times->activating > boot->userspace_time', but it didn't cover all cases. So
make it cover both branches, and also change to '>=', since it's fine if
something happened with the same timestamp.

With the patch:

  $ build/systemd-analyze critical-chain systemd-remount-fs.service
  The time when unit became active or started is printed after the "@" character.
  The time the unit took to start is printed after the "+" character.

  systemd-remount-fs.service +42ms
  └─systemd-fsck-root.service
    └─systemd-journald.socket
      └─system.slice
        └─-.slice

Fixes https://github.com/systemd/systemd/issues/17191.

diff --git a/src/analyze/analyze-critical-chain.c b/src/analyze/analyze-critical-chain.c
index 4a7f452eaf5f375da440b06e8a5baf539610b142..7d78de3d388d1fb36752104c4045bdb4236aa0d3 100644 (file)
--- a/src/analyze/analyze-critical-chain.c
+++ b/src/analyze/analyze-critical-chain.c
@@ -23,23 +23,20 @@ static int list_dependencies_print(
                 UnitTimes *times,
                 BootTimes *boot) {
 
-        for (unsigned i = level; i != 0; i--)
+        for (unsigned i = level; i > 0; i--)
                 printf("%s", special_glyph(branches & (1 << (i-1)) ? SPECIAL_GLYPH_TREE_VERTICAL : SPECIAL_GLYPH_TREE_SPACE));
 
         printf("%s", special_glyph(last ? SPECIAL_GLYPH_TREE_RIGHT : SPECIAL_GLYPH_TREE_BRANCH));
 
-        if (times) {
+        if (times && times->activating >= boot->userspace_time) {
                 if (timestamp_is_set(times->time))
-                        printf("%s%s @%s +%s%s", ansi_highlight_red(), name,
+                        printf("%s%s @%s +%s%s\n", ansi_highlight_red(), name,
                                FORMAT_TIMESPAN(times->activating - boot->userspace_time, USEC_PER_MSEC),
                                FORMAT_TIMESPAN(times->time, USEC_PER_MSEC), ansi_normal());
-                else if (times->activated > boot->userspace_time)
-                        printf("%s @%s", name, FORMAT_TIMESPAN(times->activated - boot->userspace_time, USEC_PER_MSEC));
                 else
-                        printf("%s", name);
+                        printf("%s @%s\n", name, FORMAT_TIMESPAN(times->activated - boot->userspace_time, USEC_PER_MSEC));
         } else
-                printf("%s", name);
-        printf("\n");
+                printf("%s\n", name);
 
         return 0;
 }