shared/logs-show: add new --output= format "short-delta"

This new output formatting option is similar to "short-monotonic" but
also shows the time delta between two messages.

This fixes #24641.

12 files changed, 109 insertions, 24 deletions

diff --git a/NEWS b/NEWS
index fe91391627..1281964b21 100644
--- a/NEWS
+++ b/NEWS
@@ -165,6 +165,10 @@ CHANGES WITH 252 in spe:
         * openssl is the default crypto backend for systemd-resolved. (gnutls
           is still supported.)
 
+        * journalctl -o (and similar commands) now understands a new output mode
+          "short-delta". It is similar to "short-monotonic" but also shows the
+          time delta between two messages.
+
         Experimental features:
 
         * BPF programs can now be compiled with bpf-gcc.
diff --git a/man/journalctl.xml b/man/journalctl.xml
index fb7da5446e..75427bc632 100644
--- a/man/journalctl.xml
+++ b/man/journalctl.xml
@@ -420,6 +420,13 @@
           </varlistentry>
 
           <varlistentry>
+            <term><option>short-delta</option></term>
+            <listitem><para>as for <option>short-monotonic</option> but includes the time difference
+            to the previous entry.
+            Maybe unreliable time differences are marked by a <literal>*</literal>.</para></listitem>
+          </varlistentry>
+
+          <varlistentry>
             <term><option>short-unix</option></term>
             <listitem><para>is very similar, but shows seconds passed since January 1st 1970 UTC instead of
             wallclock timestamps ("UNIX time"). The time is shown with microsecond accuracy.</para></listitem>
diff --git a/shell-completion/zsh/_sd_outputmodes b/shell-completion/zsh/_sd_outputmodes
index 267a2e7bd3..68b11871f2 100644
--- a/shell-completion/zsh/_sd_outputmodes
+++ b/shell-completion/zsh/_sd_outputmodes
@@ -2,5 +2,5 @@
 # SPDX-License-Identifier: LGPL-2.1-or-later
 
 local -a _output_opts
-_output_opts=(short short-full short-iso short-iso-precise short-precise short-monotonic short-unix verbose export json json-pretty json-sse json-seq cat with-unit)
+_output_opts=(short short-full short-iso short-iso-precise short-precise short-monotonic short-unix short-delta verbose export json json-pretty json-sse json-seq cat with-unit)
 _describe -t output 'output mode' _output_opts || compadd "$@"
diff --git a/src/journal-remote/journal-gatewayd.c b/src/journal-remote/journal-gatewayd.c
index cdfeb1fc80..3e2a85ce29 100644
--- a/src/journal-remote/journal-gatewayd.c
+++ b/src/journal-remote/journal-gatewayd.c
@@ -148,6 +148,8 @@ static ssize_t request_reader_entries(
                 size_t max) {
 
         RequestMeta *m = ASSERT_PTR(cls);
+        dual_timestamp previous_ts = DUAL_TIMESTAMP_NULL;
+        sd_id128_t previous_boot_id = SD_ID128_NULL;
         int r;
         size_t n, k;
 
@@ -222,7 +224,7 @@ static ssize_t request_reader_entries(
                 }
 
                 r = show_journal_entry(m->tmp, m->journal, m->mode, 0, OUTPUT_FULL_WIDTH,
-                                   NULL, NULL, NULL);
+                                   NULL, NULL, NULL, &previous_ts, &previous_boot_id);
                 if (r < 0) {
                         log_error_errno(r, "Failed to serialize item: %m");
                         return MHD_CONTENT_READER_END_WITH_ERROR;
diff --git a/src/journal/journalctl.c b/src/journal/journalctl.c
index 5e25ed9bfd..f9d2334459 100644
--- a/src/journal/journalctl.c
+++ b/src/journal/journalctl.c
@@ -2097,7 +2097,8 @@ int main(int argc, char *argv[]) {
         bool previous_boot_id_valid = false, first_line = true, ellipsized = false, need_seek = false;
         bool use_cursor = false, after_cursor = false;
         _cleanup_(sd_journal_closep) sd_journal *j = NULL;
-        sd_id128_t previous_boot_id = {};  /* Unnecessary initialization to appease gcc */
+        sd_id128_t previous_boot_id = SD_ID128_NULL, previous_boot_id_output = SD_ID128_NULL;
+        dual_timestamp previous_ts_output = DUAL_TIMESTAMP_NULL;
         int n_shown = 0, r, poll_fd = -1;
 
         setlocale(LC_ALL, "");
@@ -2672,7 +2673,8 @@ int main(int argc, char *argv[]) {
                                 arg_no_hostname * OUTPUT_NO_HOSTNAME;
 
                         r = show_journal_entry(stdout, j, arg_output, 0, flags,
-                                               arg_output_fields, highlight, &ellipsized);
+                                               arg_output_fields, highlight, &ellipsized,
+                                               &previous_ts_output, &previous_boot_id_output);
                         need_seek = true;
                         if (r == -EADDRNOTAVAIL)
                                 break;
diff --git a/src/login/loginctl.c b/src/login/loginctl.c
index ed24473baa..4dbfa0db44 100644
--- a/src/login/loginctl.c
+++ b/src/login/loginctl.c
@@ -1267,9 +1267,9 @@ static int help(int argc, char *argv[], void *userdata) {
                "  -n --lines=INTEGER       Number of journal entries to show\n"
                "  -o --output=STRING       Change journal output mode (short, short-precise,\n"
                "                             short-iso, short-iso-precise, short-full,\n"
-               "                             short-monotonic, short-unix, verbose, export,\n"
+               "                             short-monotonic, short-unix, short-delta,\n"
                "                             json, json-pretty, json-sse, json-seq, cat,\n"
-               "                             with-unit)\n"
+               "                             verbose, export, with-unit)\n"
                "\nSee the %s for details.\n",
                program_invocation_short_name,
                ansi_highlight(),
diff --git a/src/machine/machinectl.c b/src/machine/machinectl.c
index d05b4101cc..a93425e97b 100644
--- a/src/machine/machinectl.c
+++ b/src/machine/machinectl.c
@@ -2462,9 +2462,9 @@ static int help(int argc, char *argv[], void *userdata) {
                "     --max-addresses=INTEGER  Number of internet addresses to show at most\n"
                "  -o --output=STRING          Change journal output mode (short, short-precise,\n"
                "                               short-iso, short-iso-precise, short-full,\n"
-               "                               short-monotonic, short-unix, verbose, export,\n"
+               "                               short-monotonic, short-unix, short-delta,\n"
                "                               json, json-pretty, json-sse, json-seq, cat,\n"
-               "                               with-unit)\n"
+               "                               verbose, export, with-unit)\n"
                "     --verify=MODE            Verification mode for downloaded images (no,\n"
                "                              checksum, signature)\n"
                "     --force                  Download image even if already exists\n"
diff --git a/src/shared/logs-show.c b/src/shared/logs-show.c
index 23de0f456e..0ebc66597d 100644
--- a/src/shared/logs-show.c
+++ b/src/shared/logs-show.c
@@ -317,15 +317,47 @@ static bool print_multiline(
         return ellipsized;
 }
 
-static int output_timestamp_monotonic(FILE *f, const dual_timestamp *ts) {
+static int output_timestamp_monotonic(
+                FILE *f, OutputMode mode,
+                const dual_timestamp *ts,
+                const sd_id128_t *boot_id,
+                const dual_timestamp *previous_ts,
+                const sd_id128_t *previous_boot_id) {
+
+        int written_chars = 0;
+
         assert(f);
         assert(ts);
+        assert(boot_id);
+        assert(previous_ts);
+        assert(previous_boot_id);
 
         if (!VALID_MONOTONIC(ts->monotonic))
                 return log_error_errno(SYNTHETIC_ERRNO(EINVAL), "No valid monotonic timestamp available");
 
-        fprintf(f, "[%5"PRI_USEC".%06"PRI_USEC"]", ts->monotonic / USEC_PER_SEC, ts->monotonic % USEC_PER_SEC);
-        return 1 + 5 + 1 + 6 + 1;
+        written_chars += fprintf(f, "[%5"PRI_USEC".%06"PRI_USEC, ts->monotonic / USEC_PER_SEC, ts->monotonic % USEC_PER_SEC);
+
+        if (mode == OUTPUT_SHORT_DELTA) {
+                uint64_t delta;
+                bool reliable_ts = true;
+
+                if (VALID_MONOTONIC(previous_ts->monotonic) && sd_id128_equal(*boot_id, *previous_boot_id))
+                        delta = usec_sub_unsigned(ts->monotonic, previous_ts->monotonic);
+                else if (VALID_REALTIME(ts->realtime) && VALID_REALTIME(previous_ts->realtime)) {
+                        delta = usec_sub_unsigned(ts->realtime, previous_ts->realtime);
+                        reliable_ts = false;
+                } else {
+                        written_chars += fprintf(f, "%16s", "");
+                        goto finish;
+                }
+
+                written_chars += fprintf(f, " <%5"PRI_USEC".%06"PRI_USEC"%s>", delta / USEC_PER_SEC, delta % USEC_PER_SEC, reliable_ts ? " " : "*");
+        }
+
+finish:
+        written_chars += fprintf(f, "%s", "]");
+
+        return written_chars;
 }
 
 static int output_timestamp_realtime(
@@ -426,7 +458,9 @@ static int output_short(
                 const Set *output_fields,
                 const size_t highlight[2],
                 const dual_timestamp *ts,
-                const sd_id128_t *boot_id) {
+                const sd_id128_t *boot_id,
+                const dual_timestamp *previous_ts,
+                const sd_id128_t *previous_boot_id) {
 
         int r;
         const void *data;
@@ -459,6 +493,8 @@ static int output_short(
         assert(j);
         assert(ts);
         assert(boot_id);
+        assert(previous_ts);
+        assert(previous_boot_id);
 
         /* Set the threshold to one bigger than the actual print
          * threshold, so that if the line is actually longer than what
@@ -493,8 +529,8 @@ static int output_short(
 
         audit = streq_ptr(transport, "audit");
 
-        if (mode == OUTPUT_SHORT_MONOTONIC)
-                r = output_timestamp_monotonic(f, ts);
+        if (IN_SET(mode, OUTPUT_SHORT_MONOTONIC, OUTPUT_SHORT_DELTA))
+                r = output_timestamp_monotonic(f, mode, ts, boot_id, previous_ts, previous_boot_id);
         else
                 r = output_timestamp_realtime(f, j, mode, flags, ts);
         if (r < 0)
@@ -629,7 +665,9 @@ static int output_verbose(
                 const Set *output_fields,
                 const size_t highlight[2],
                 const dual_timestamp *ts,
-                const sd_id128_t *boot_id) {
+                const sd_id128_t *boot_id,
+                const dual_timestamp *previous_ts,
+                const sd_id128_t *previous_boot_id) {
 
         const void *data;
         size_t length;
@@ -642,6 +680,8 @@ static int output_verbose(
         assert(j);
         assert(ts);
         assert(boot_id);
+        assert(previous_ts);
+        assert(previous_boot_id);
 
         sd_journal_set_data_threshold(j, 0);
 
@@ -727,7 +767,9 @@ static int output_export(
                 const Set *output_fields,
                 const size_t highlight[2],
                 const dual_timestamp *ts,
-                const sd_id128_t *boot_id) {
+                const sd_id128_t *boot_id,
+                const dual_timestamp *previous_ts,
+                const sd_id128_t *previous_boot_id) {
 
         _cleanup_free_ char *cursor = NULL;
         const void *data;
@@ -737,6 +779,8 @@ static int output_export(
         assert(j);
         assert(ts);
         assert(boot_id);
+        assert(previous_ts);
+        assert(previous_boot_id);
 
         sd_journal_set_data_threshold(j, 0);
 
@@ -962,7 +1006,9 @@ static int output_json(
                 const Set *output_fields,
                 const size_t highlight[2],
                 const dual_timestamp *ts,
-                const sd_id128_t *boot_id) {
+                const sd_id128_t *boot_id,
+                const dual_timestamp *previous_ts,
+                const sd_id128_t *previous_boot_id) {
 
         char sid[SD_ID128_STRING_MAX], usecbuf[DECIMAL_STR_MAX(usec_t)];
         _cleanup_(json_variant_unrefp) JsonVariant *object = NULL;
@@ -976,6 +1022,8 @@ static int output_json(
         assert(j);
         assert(ts);
         assert(boot_id);
+        assert(previous_ts);
+        assert(previous_boot_id);
 
         (void) sd_journal_set_data_threshold(j, flags & OUTPUT_SHOW_ALL ? 0 : JSON_THRESHOLD);
 
@@ -1158,7 +1206,9 @@ static int output_cat(
                 const Set *output_fields,
                 const size_t highlight[2],
                 const dual_timestamp *ts,
-                const sd_id128_t *boot_id) {
+                const sd_id128_t *boot_id,
+                const dual_timestamp *previous_ts,
+                const sd_id128_t *previous_boot_id) {
 
         int r, prio = LOG_INFO;
         const char *field;
@@ -1167,6 +1217,8 @@ static int output_cat(
         assert(f);
         assert(ts);
         assert(boot_id);
+        assert(previous_ts);
+        assert(previous_boot_id);
 
         (void) sd_journal_set_data_threshold(j, 0);
 
@@ -1259,13 +1311,16 @@ static int (*output_funcs[_OUTPUT_MODE_MAX])(
                 const Set *output_fields,
                 const size_t highlight[2],
                 const dual_timestamp *ts,
-                const sd_id128_t *boot_id) = {
+                const sd_id128_t *boot_id,
+                const dual_timestamp *previous_ts,
+                const sd_id128_t *previous_boot_id) = {
 
         [OUTPUT_SHORT]             = output_short,
         [OUTPUT_SHORT_ISO]         = output_short,
         [OUTPUT_SHORT_ISO_PRECISE] = output_short,
         [OUTPUT_SHORT_PRECISE]     = output_short,
         [OUTPUT_SHORT_MONOTONIC]   = output_short,
+        [OUTPUT_SHORT_DELTA]       = output_short,
         [OUTPUT_SHORT_UNIX]        = output_short,
         [OUTPUT_SHORT_FULL]        = output_short,
         [OUTPUT_VERBOSE]           = output_verbose,
@@ -1286,7 +1341,9 @@ int show_journal_entry(
                 OutputFlags flags,
                 char **output_fields,
                 const size_t highlight[2],
-                bool *ellipsized) {
+                bool *ellipsized,
+                dual_timestamp *previous_ts,
+                sd_id128_t *previous_boot_id) {
 
         _cleanup_set_free_ Set *fields = NULL;
         dual_timestamp ts = DUAL_TIMESTAMP_NULL;
@@ -1295,6 +1352,8 @@ int show_journal_entry(
 
         assert(mode >= 0);
         assert(mode < _OUTPUT_MODE_MAX);
+        assert(previous_ts);
+        assert(previous_boot_id);
 
         if (n_columns <= 0)
                 n_columns = columns();
@@ -1311,7 +1370,11 @@ int show_journal_entry(
         if (r < 0)
                 return log_error_errno(r, "Failed to get journal fields: %m");
 
-        r = output_funcs[mode](f, j, mode, n_columns, flags, fields, highlight, &ts, &boot_id);
+        r = output_funcs[mode](f, j, mode, n_columns, flags, fields, highlight, &ts, &boot_id, previous_ts, previous_boot_id);
+
+        /* Store timestamp and boot ID for next iteration */
+        *previous_ts = ts;
+        *previous_boot_id = boot_id;
 
         if (ellipsized && r > 0)
                 *ellipsized = true;
@@ -1348,6 +1411,8 @@ int show_journal(
         unsigned line = 0;
         bool need_seek = false;
         int warn_cutoff = flags & OUTPUT_WARN_CUTOFF;
+        dual_timestamp previous_ts = DUAL_TIMESTAMP_NULL;
+        sd_id128_t previous_boot_id = SD_ID128_NULL;
 
         assert(j);
         assert(mode >= 0);
@@ -1396,7 +1461,8 @@ int show_journal(
                 line++;
                 maybe_print_begin_newline(f, &flags);
 
-                r = show_journal_entry(f, j, mode, n_columns, flags, NULL, NULL, ellipsized);
+                r = show_journal_entry(f, j, mode, n_columns, flags, NULL, NULL, ellipsized,
+                                       &previous_ts, &previous_boot_id);
                 if (r < 0)
                         return r;
         }
diff --git a/src/shared/logs-show.h b/src/shared/logs-show.h
index 71ebe13573..71e39ebb1f 100644
--- a/src/shared/logs-show.h
+++ b/src/shared/logs-show.h
@@ -21,7 +21,9 @@ int show_journal_entry(
                 OutputFlags flags,
                 char **output_fields,
                 const size_t highlight[2],
-                bool *ellipsized);
+                bool *ellipsized,
+                dual_timestamp *previous_ts,
+                sd_id128_t *previous_boot_id);
 int show_journal(
                 FILE *f,
                 sd_journal *j,
diff --git a/src/shared/output-mode.c b/src/shared/output-mode.c
index 1645b756df..026bf19a59 100644
--- a/src/shared/output-mode.c
+++ b/src/shared/output-mode.c
@@ -28,6 +28,7 @@ static const char *const output_mode_table[_OUTPUT_MODE_MAX] = {
         [OUTPUT_SHORT_ISO_PRECISE] = "short-iso-precise",
         [OUTPUT_SHORT_PRECISE] = "short-precise",
         [OUTPUT_SHORT_MONOTONIC] = "short-monotonic",
+        [OUTPUT_SHORT_DELTA] = "short-delta",
         [OUTPUT_SHORT_UNIX] = "short-unix",
         [OUTPUT_VERBOSE] = "verbose",
         [OUTPUT_EXPORT] = "export",
diff --git a/src/shared/output-mode.h b/src/shared/output-mode.h
index 4b4abfe75f..26351c9fdb 100644
--- a/src/shared/output-mode.h
+++ b/src/shared/output-mode.h
@@ -11,6 +11,7 @@ typedef enum OutputMode {
         OUTPUT_SHORT_ISO_PRECISE,
         OUTPUT_SHORT_PRECISE,
         OUTPUT_SHORT_MONOTONIC,
+        OUTPUT_SHORT_DELTA,
         OUTPUT_SHORT_UNIX,
         OUTPUT_VERBOSE,
         OUTPUT_EXPORT,
diff --git a/src/systemctl/systemctl.c b/src/systemctl/systemctl.c
index ae046e73a3..56d26c43a0 100644
--- a/src/systemctl/systemctl.c
+++ b/src/systemctl/systemctl.c
@@ -291,7 +291,7 @@ static int systemctl_help(void) {
                "  -n --lines=INTEGER     Number of journal entries to show\n"
                "  -o --output=STRING     Change journal output mode (short, short-precise,\n"
                "                             short-iso, short-iso-precise, short-full,\n"
-               "                             short-monotonic, short-unix,\n"
+               "                             short-monotonic, short-unix, short-delta,\n"
                "                             verbose, export, json, json-pretty, json-sse, cat)\n"
                "     --firmware-setup    Tell the firmware to show the setup menu on next boot\n"
                "     --boot-loader-menu=TIME\n"