logs-show: adjust source timestamp with header timestamp

Previously, _SOURCE_REALTIME_TIMESTAMP was only used for realtime
timestamp, and _SOURCE_MONOTONIC_TIMESTAMP was for monotonic.

This make these journal field used more aggressively. If we need
realtime timestamp, but an entry has only _SOURCE_MONOTONIC_TIMESTAMP,
then now realtime timestamp is calculated based on
_SOURCE_MONOTONIC_TIMESTAMP and the header dual timestamp.
Similary, monotonic timestamp is obtained from
_SOURCE_REALTIME_TIMESTAMP and the header dual timestamp.

This should change shown timestamps not so much in most cases, but may
be improve the situation such as #32492.

diff --git a/src/basic/time-util.h b/src/basic/time-util.h
index ebcdc41118eacd4735e6b231e1be6239672cbe09..b28ab8242fb203f87f9ef4aa306a388521f1aa1d 100644 (file)
--- a/src/basic/time-util.h
+++ b/src/basic/time-util.h
@@ -72,6 +72,7 @@ typedef enum TimestampStyle {
 #define TIME_T_MAX (time_t)((UINTMAX_C(1) << ((sizeof(time_t) << 3) - 1)) - 1)
 
 #define DUAL_TIMESTAMP_NULL ((dual_timestamp) {})
+#define DUAL_TIMESTAMP_INFINITY ((dual_timestamp) { USEC_INFINITY, USEC_INFINITY })
 #define TRIPLE_TIMESTAMP_NULL ((triple_timestamp) {})
 
 usec_t now(clockid_t clock);

diff --git a/src/shared/logs-show.c b/src/shared/logs-show.c
index 1d9466f7a1f710d5a39d6f1ac22286f13834030d..d5b131a187f580cfd2256f90a6ab74ca483c246c 100644 (file)
--- a/src/shared/logs-show.c
+++ b/src/shared/logs-show.c
@@ -439,37 +439,75 @@ static int output_timestamp_realtime(
         return (int) strlen(buf);
 }
 
+static void parse_display_realtime(
+                sd_journal *j,
+                const char *source_realtime,
+                const char *source_monotonic,
+                usec_t *ret) {
+
+        usec_t t, s, u;
+
+        assert(j);
+        assert(ret);
+
+        /* First, try _SOURCE_REALTIME_TIMESTAMP. */
+        if (source_realtime && safe_atou64(source_realtime, &t) >= 0 && VALID_REALTIME(t)) {
+                *ret = t;
+                return;
+        }
+
+        /* Read realtime timestamp in the entry header. */
+        if (sd_journal_get_realtime_usec(j, &t) < 0) {
+                *ret = USEC_INFINITY;
+                return;
+        }
+
+        /* If _SOURCE_MONOTONIC_TIMESTAMP is provided, adjust the header timestamp. */
+        if (source_monotonic && safe_atou64(source_monotonic, &s) >= 0 && VALID_MONOTONIC(s) &&
+            sd_journal_get_monotonic_usec(j, &u, &(sd_id128_t) {}) >= 0) {
+                *ret = map_clock_usec_raw(t, u, s);
+                return;
+        }
+
+        /* Otherwise, use the header timestamp as is. */
+        *ret = t;
+}
+
 static void parse_display_timestamp(
                 sd_journal *j,
-                const char *realtime,
-                const char *monotonic,
+                const char *source_realtime,
+                const char *source_monotonic,
                 dual_timestamp *ret_display_ts,
                 sd_id128_t *ret_boot_id) {
 
-        bool realtime_good = false, monotonic_good = false, boot_id_good = false;
+        dual_timestamp header_ts = DUAL_TIMESTAMP_INFINITY, source_ts = DUAL_TIMESTAMP_INFINITY;
+        sd_id128_t boot_id = SD_ID128_NULL;
+        usec_t t;
 
         assert(j);
         assert(ret_display_ts);
         assert(ret_boot_id);
 
-        if (realtime)
-                realtime_good = safe_atou64(realtime, &ret_display_ts->realtime) >= 0;
-        if (!realtime_good || !VALID_REALTIME(ret_display_ts->realtime))
-                realtime_good = sd_journal_get_realtime_usec(j, &ret_display_ts->realtime) >= 0;
-        if (!realtime_good)
-                ret_display_ts->realtime = USEC_INFINITY;
-
-        if (monotonic)
-                monotonic_good = safe_atou64(monotonic, &ret_display_ts->monotonic) >= 0;
-        if (!monotonic_good || !VALID_MONOTONIC(ret_display_ts->monotonic))
-                monotonic_good = boot_id_good = sd_journal_get_monotonic_usec(j, &ret_display_ts->monotonic, ret_boot_id) >= 0;
-        if (!monotonic_good)
-                ret_display_ts->monotonic = USEC_INFINITY;
-
-        if (!boot_id_good)
-                boot_id_good = sd_journal_get_monotonic_usec(j, NULL, ret_boot_id) >= 0;
-        if (!boot_id_good)
-                *ret_boot_id = SD_ID128_NULL;
+        if (source_realtime && safe_atou64(source_realtime, &t) >= 0 && VALID_REALTIME(t))
+                source_ts.realtime = t;
+
+        if (source_monotonic && safe_atou64(source_monotonic, &t) >= 0 && VALID_MONOTONIC(t))
+                source_ts.monotonic = t;
+
+        (void) sd_journal_get_realtime_usec(j, &header_ts.realtime);
+        (void) sd_journal_get_monotonic_usec(j, &header_ts.monotonic, &boot_id);
+
+        /* Adjust timestamp if possible. */
+        if (header_ts.realtime != USEC_INFINITY && header_ts.monotonic != USEC_INFINITY) {
+                if (source_ts.realtime == USEC_INFINITY && source_ts.monotonic != USEC_INFINITY)
+                        source_ts.realtime = map_clock_usec_raw(header_ts.realtime, header_ts.monotonic, source_ts.monotonic);
+                else if (source_ts.realtime != USEC_INFINITY && source_ts.monotonic == USEC_INFINITY)
+                        source_ts.monotonic = map_clock_usec_raw(header_ts.monotonic, header_ts.realtime, source_ts.realtime);
+        }
+
+        ret_display_ts->realtime = source_ts.realtime != USEC_INFINITY ? source_ts.realtime : header_ts.realtime;
+        ret_display_ts->monotonic = source_ts.monotonic != USEC_INFINITY ? source_ts.monotonic : header_ts.monotonic;
+        *ret_boot_id = boot_id;
 }
 
 static int output_short(
@@ -480,8 +518,8 @@ static int output_short(
                 OutputFlags flags,
                 const Set *output_fields,
                 const size_t highlight[2],
-                dual_timestamp *previous_display_ts, /* in and out */
-                sd_id128_t *previous_boot_id) {      /* in and out */
+                dual_timestamp *previous_display_ts, /* in and out, used only when mode is OUTPUT_SHORT_MONOTONIC, OUTPUT_SHORT_DELTA. */
+                sd_id128_t *previous_boot_id) {      /* in and out, used only when mode is OUTPUT_SHORT_MONOTONIC, OUTPUT_SHORT_DELTA. */
 
         int r;
         const void *data;
@@ -546,8 +584,6 @@ static int output_short(
         if (identifier && set_contains(j->exclude_syslog_identifiers, identifier))
                 return 0;
 
-        parse_display_timestamp(j, realtime, monotonic, &display_ts, &boot_id);
-
         if (!(flags & OUTPUT_SHOW_ALL))
                 strip_tab_ansi(&message, &message_len, highlight_shifted);
 
@@ -559,10 +595,14 @@ static int output_short(
 
         audit = streq_ptr(transport, "audit");
 
-        if (IN_SET(mode, OUTPUT_SHORT_MONOTONIC, OUTPUT_SHORT_DELTA))
+        if (IN_SET(mode, OUTPUT_SHORT_MONOTONIC, OUTPUT_SHORT_DELTA)) {
+                parse_display_timestamp(j, realtime, monotonic, &display_ts, &boot_id);
                 r = output_timestamp_monotonic(f, mode, &display_ts, &boot_id, previous_display_ts, previous_boot_id);
-        else
-                r = output_timestamp_realtime(f, j, mode, flags, display_ts.realtime);
+        } else {
+                usec_t usec;
+                parse_display_realtime(j, realtime, monotonic, &usec);
+                r = output_timestamp_realtime(f, j, mode, flags, usec);
+        }
         if (r < 0)
                 return r;
         n += r;
@@ -683,17 +723,15 @@ static int output_short(
         if (flags & OUTPUT_CATALOG)
                 (void) print_catalog(f, j);
 
-        *previous_display_ts = display_ts;
-        *previous_boot_id = boot_id;
+        if (IN_SET(mode, OUTPUT_SHORT_MONOTONIC, OUTPUT_SHORT_DELTA)) {
+                *previous_display_ts = display_ts;
+                *previous_boot_id = boot_id;
+        }
 
         return ellipsized;
 }
 
-static int get_display_timestamp(
-                sd_journal *j,
-                dual_timestamp *ret_display_ts,
-                sd_id128_t *ret_boot_id) {
-
+static int get_display_realtime(sd_journal *j, usec_t *ret) {
         const void *data;
         _cleanup_free_ char *realtime = NULL, *monotonic = NULL;
         size_t length;
@@ -704,8 +742,7 @@ static int get_display_timestamp(
         int r;
 
         assert(j);
-        assert(ret_display_ts);
-        assert(ret_boot_id);
+        assert(ret);
 
         JOURNAL_FOREACH_DATA_RETVAL(j, data, length, r) {
                 r = parse_fieldv(data, length, message_fields, ELEMENTSOF(message_fields));
@@ -718,7 +755,7 @@ static int get_display_timestamp(
         if (r < 0)
                 return r;
 
-        (void) parse_display_timestamp(j, realtime, monotonic, ret_display_ts, ret_boot_id);
+        (void) parse_display_realtime(j, realtime, monotonic, ret);
 
         /* Restart all data before */
         sd_journal_restart_data(j);
@@ -743,9 +780,8 @@ static int output_verbose(
         size_t length;
         _cleanup_free_ char *cursor = NULL;
         char buf[FORMAT_TIMESTAMP_MAX + 7];
-        dual_timestamp display_ts;
-        sd_id128_t boot_id;
         const char *timestamp;
+        usec_t usec;
         int r;
 
         assert(f);
@@ -753,7 +789,7 @@ static int output_verbose(
 
         (void) sd_journal_set_data_threshold(j, 0);
 
-        r = get_display_timestamp(j, &display_ts, &boot_id);
+        r = get_display_realtime(j, &usec);
         if (IN_SET(r, -EBADMSG, -EADDRNOTAVAIL)) {
                 log_debug_errno(r, "Skipping message we can't read: %m");
                 return 0;
@@ -761,14 +797,14 @@ static int output_verbose(
         if (r < 0)
                 return log_error_errno(r, "Failed to get journal fields: %m");
 
-        if (!VALID_REALTIME(display_ts.realtime))
+        if (!VALID_REALTIME(usec))
                 return log_error_errno(SYNTHETIC_ERRNO(EINVAL), "No valid realtime timestamp available");
 
         r = sd_journal_get_cursor(j, &cursor);
         if (r < 0)
                 return log_error_errno(r, "Failed to get cursor: %m");
 
-        timestamp = format_timestamp_style(buf, sizeof buf, display_ts.realtime,
+        timestamp = format_timestamp_style(buf, sizeof buf, usec,
                                            flags & OUTPUT_UTC ? TIMESTAMP_US_UTC : TIMESTAMP_US);
         fprintf(f, "%s%s%s %s[%s]%s\n",
                 timestamp && (flags & OUTPUT_COLOR) ? ANSI_UNDERLINE : "",