]> git.ipfire.org Git - thirdparty/systemd.git/commitdiff
core: Add wall clock duration to CPU usage logging
authorgvenugo3 <gvenugo3@asu.edu>
Wed, 16 Jul 2025 05:31:46 +0000 (05:31 +0000)
committerZbigniew Jędrzejewski-Szmek <zbyszek@in.waw.pl>
Wed, 17 Sep 2025 13:07:11 +0000 (15:07 +0200)
Enhance CPU time logging to include wall clock duration alongside
CPU consumption. When a unit transitions to inactive/failed state,
the log message now shows both CPU time consumed and the total wall
clock time since activation.

Changes:
- Calculate wall clock duration using active_enter_timestamp
- Update log format: "Consumed Xs CPU time over Ys wall clock time"
- Fallback to original format if no activation timestamp available
- Use monotonic clock for accurate duration calculation

This addresses issue #35738 by providing administrators better context
about service performance and resource efficiency.

Example output:
- With wall clock: "service: Consumed 30s CPU time over 5min wall clock time"
- Without timestamp: "service: Consumed 30s CPU time"

src/core/unit.c

index 7d9e24c5de893a0d6072f30b511acf51b3f5f9d5..a6c3fd8bda588ae9fbddced353bfa7ca62055246 100644 (file)
@@ -2411,10 +2411,20 @@ static int unit_log_resources(Unit *u) {
                 iovec[n_iovec++] = IOVEC_MAKE_STRING(TAKE_PTR(t));
 
                 /* Format the CPU time for inclusion in the human language message string */
-                if (strextendf_with_separator(&message, ", ",
-                                              "Consumed %s CPU time",
-                                              FORMAT_TIMESPAN(cpu_nsec / NSEC_PER_USEC, USEC_PER_MSEC)) < 0)
-                        return log_oom();
+                if (dual_timestamp_is_set(&u->inactive_exit_timestamp) &&
+                    dual_timestamp_is_set(&u->inactive_enter_timestamp)) {
+                        usec_t wall_clock_usec = usec_sub_unsigned(u->inactive_enter_timestamp.monotonic, u->inactive_exit_timestamp.monotonic);
+                        if (strextendf_with_separator(&message, ", ",
+                                                      "Consumed %s CPU time over %s wall clock time",
+                                                      FORMAT_TIMESPAN(cpu_nsec / NSEC_PER_USEC, USEC_PER_MSEC),
+                                                      FORMAT_TIMESPAN(wall_clock_usec, USEC_PER_MSEC)) < 0)
+                                return log_oom();
+                } else {
+                        if (strextendf_with_separator(&message, ", ",
+                                                      "Consumed %s CPU time",
+                                                      FORMAT_TIMESPAN(cpu_nsec / NSEC_PER_USEC, USEC_PER_MSEC)) < 0)
+                                return log_oom();
+                }
 
                 log_level = raise_level(log_level,
                                         cpu_nsec > MENTIONWORTHY_CPU_NSEC,