logs-show: move timestamp reading into show_journal_entry()

1 files changed, 127 insertions, 92 deletions

diff --git a/src/shared/logs-show.c b/src/shared/logs-show.c
index 98219e14fa..23de0f456e 100644
--- a/src/shared/logs-show.c
+++ b/src/shared/logs-show.c
@@ -317,62 +317,55 @@ static bool print_multiline(
         return ellipsized;
 }
 
-static int output_timestamp_monotonic(FILE *f, sd_journal *j, const char *monotonic) {
-        sd_id128_t boot_id;
-        uint64_t t;
-        int r;
-
+static int output_timestamp_monotonic(FILE *f, const dual_timestamp *ts) {
         assert(f);
-        assert(j);
+        assert(ts);
 
-        r = -ENXIO;
-        if (monotonic)
-                r = safe_atou64(monotonic, &t);
-        if (r < 0)
-                r = sd_journal_get_monotonic_usec(j, &t, &boot_id);
-        if (r < 0)
-                return log_error_errno(r, "Failed to get monotonic timestamp: %m");
+        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"]", t / USEC_PER_SEC, t % USEC_PER_SEC);
+        fprintf(f, "[%5"PRI_USEC".%06"PRI_USEC"]", ts->monotonic / USEC_PER_SEC, ts->monotonic % USEC_PER_SEC);
         return 1 + 5 + 1 + 6 + 1;
 }
 
-static int output_timestamp_realtime(FILE *f, sd_journal *j, OutputMode mode, OutputFlags flags, const char *realtime) {
+static int output_timestamp_realtime(
+                FILE *f,
+                sd_journal *j,
+                OutputMode mode,
+                OutputFlags flags,
+                const dual_timestamp *ts) {
+
         char buf[CONST_MAX(FORMAT_TIMESTAMP_MAX, 64U)];
-        uint64_t x;
         int r;
 
         assert(f);
         assert(j);
+        assert(ts);
 
-        if (realtime)
-                r = safe_atou64(realtime, &x);
-        if (!realtime || r < 0 || !VALID_REALTIME(x))
-                r = sd_journal_get_realtime_usec(j, &x);
-        if (r < 0)
-                return log_error_errno(r, "Failed to get realtime timestamp: %m");
+        if (!VALID_REALTIME(ts->realtime))
+                return log_error_errno(SYNTHETIC_ERRNO(EINVAL), "No valid realtime timestamp available");
 
         if (IN_SET(mode, OUTPUT_SHORT_FULL, OUTPUT_WITH_UNIT)) {
                 const char *k;
 
                 if (flags & OUTPUT_UTC)
-                        k = format_timestamp_style(buf, sizeof(buf), x, TIMESTAMP_UTC);
+                        k = format_timestamp_style(buf, sizeof(buf), ts->realtime, TIMESTAMP_UTC);
                 else
-                        k = format_timestamp(buf, sizeof(buf), x);
+                        k = format_timestamp(buf, sizeof(buf), ts->realtime);
                 if (!k)
                         return log_error_errno(SYNTHETIC_ERRNO(EINVAL),
-                                               "Failed to format timestamp: %" PRIu64, x);
+                                               "Failed to format timestamp: %" PRIu64, ts->realtime);
 
         } else {
                 struct tm tm;
                 time_t t;
 
-                t = (time_t) (x / USEC_PER_SEC);
+                t = (time_t) (ts->realtime / USEC_PER_SEC);
 
                 switch (mode) {
 
                 case OUTPUT_SHORT_UNIX:
-                        xsprintf(buf, "%10"PRI_TIME".%06"PRIu64, t, x % USEC_PER_SEC);
+                        xsprintf(buf, "%10"PRI_TIME".%06"PRIu64, t, ts->realtime % USEC_PER_SEC);
                         break;
 
                 case OUTPUT_SHORT_ISO:
@@ -390,7 +383,7 @@ static int output_timestamp_realtime(FILE *f, sd_journal *j, OutputMode mode, Ou
                                      localtime_or_gmtime_r(&t, &tm, flags & OUTPUT_UTC)) <= 0)
                                 return log_error_errno(SYNTHETIC_ERRNO(EINVAL),
                                                        "Failed to format ISO-precise time");
-                        xsprintf(usec, "%06"PRI_USEC, x % USEC_PER_SEC);
+                        xsprintf(usec, "%06"PRI_USEC, ts->realtime % USEC_PER_SEC);
                         memcpy(buf + 20, usec, 6);
                         break;
                 }
@@ -408,7 +401,7 @@ static int output_timestamp_realtime(FILE *f, sd_journal *j, OutputMode mode, Ou
                                 assert(sizeof(buf) > strlen(buf));
                                 k = sizeof(buf) - strlen(buf);
 
-                                r = snprintf(buf + strlen(buf), k, ".%06"PRIu64, x % USEC_PER_SEC);
+                                r = snprintf(buf + strlen(buf), k, ".%06"PRIu64, ts->realtime % USEC_PER_SEC);
                                 if (r <= 0 || (size_t) r >= k) /* too long? */
                                         return log_error_errno(SYNTHETIC_ERRNO(EINVAL),
                                                                "Failed to format precise time");
@@ -431,16 +424,18 @@ static int output_short(
                 unsigned n_columns,
                 OutputFlags flags,
                 const Set *output_fields,
-                const size_t highlight[2]) {
+                const size_t highlight[2],
+                const dual_timestamp *ts,
+                const sd_id128_t *boot_id) {
 
         int r;
         const void *data;
         size_t length, n = 0;
         _cleanup_free_ char *hostname = NULL, *identifier = NULL, *comm = NULL, *pid = NULL, *fake_pid = NULL,
-                *message = NULL, *realtime = NULL, *monotonic = NULL, *priority = NULL, *transport = NULL,
+                *message = NULL, *priority = NULL, *transport = NULL,
                 *config_file = NULL, *unit = NULL, *user_unit = NULL, *documentation_url = NULL;
         size_t hostname_len = 0, identifier_len = 0, comm_len = 0, pid_len = 0, fake_pid_len = 0, message_len = 0,
-                realtime_len = 0, monotonic_len = 0, priority_len = 0, transport_len = 0, config_file_len = 0,
+                priority_len = 0, transport_len = 0, config_file_len = 0,
                 unit_len = 0, user_unit_len = 0, documentation_url_len = 0;
         int p = LOG_INFO;
         bool ellipsized = false, audit;
@@ -453,8 +448,6 @@ static int output_short(
                 PARSE_FIELD_VEC_ENTRY("_HOSTNAME=", &hostname, &hostname_len),
                 PARSE_FIELD_VEC_ENTRY("SYSLOG_PID=", &fake_pid, &fake_pid_len),
                 PARSE_FIELD_VEC_ENTRY("SYSLOG_IDENTIFIER=", &identifier, &identifier_len),
-                PARSE_FIELD_VEC_ENTRY("_SOURCE_REALTIME_TIMESTAMP=", &realtime, &realtime_len),
-                PARSE_FIELD_VEC_ENTRY("_SOURCE_MONOTONIC_TIMESTAMP=", &monotonic, &monotonic_len),
                 PARSE_FIELD_VEC_ENTRY("CONFIG_FILE=", &config_file, &config_file_len),
                 PARSE_FIELD_VEC_ENTRY("_SYSTEMD_UNIT=", &unit, &unit_len),
                 PARSE_FIELD_VEC_ENTRY("_SYSTEMD_USER_UNIT=", &user_unit, &user_unit_len),
@@ -464,6 +457,8 @@ static int output_short(
 
         assert(f);
         assert(j);
+        assert(ts);
+        assert(boot_id);
 
         /* Set the threshold to one bigger than the actual print
          * threshold, so that if the line is actually longer than what
@@ -499,9 +494,9 @@ static int output_short(
         audit = streq_ptr(transport, "audit");
 
         if (mode == OUTPUT_SHORT_MONOTONIC)
-                r = output_timestamp_monotonic(f, j, monotonic);
+                r = output_timestamp_monotonic(f, ts);
         else
-                r = output_timestamp_realtime(f, j, mode, flags, realtime);
+                r = output_timestamp_realtime(f, j, mode, flags, ts);
         if (r < 0)
                 return r;
         n += r;
@@ -632,52 +627,32 @@ static int output_verbose(
                 unsigned n_columns,
                 OutputFlags flags,
                 const Set *output_fields,
-                const size_t highlight[2]) {
+                const size_t highlight[2],
+                const dual_timestamp *ts,
+                const sd_id128_t *boot_id) {
 
         const void *data;
         size_t length;
         _cleanup_free_ char *cursor = NULL;
-        uint64_t realtime = 0;
-        char ts[FORMAT_TIMESTAMP_MAX + 7];
+        char buf[FORMAT_TIMESTAMP_MAX + 7];
         const char *timestamp;
         int r;
 
         assert(f);
         assert(j);
+        assert(ts);
+        assert(boot_id);
 
         sd_journal_set_data_threshold(j, 0);
 
-        r = sd_journal_get_data(j, "_SOURCE_REALTIME_TIMESTAMP", &data, &length);
-        if (r == -ENOENT)
-                log_debug("Source realtime timestamp not found");
-        else if (r < 0)
-                return log_full_errno(r == -EADDRNOTAVAIL ? LOG_DEBUG : LOG_ERR, r, "Failed to get source realtime timestamp: %m");
-        else {
-                _cleanup_free_ char *value = NULL;
-
-                r = parse_field(data, length, "_SOURCE_REALTIME_TIMESTAMP=",
-                                STRLEN("_SOURCE_REALTIME_TIMESTAMP="), &value,
-                                NULL);
-                if (r < 0)
-                        return r;
-                assert(r > 0);
-
-                r = safe_atou64(value, &realtime);
-                if (r < 0)
-                        log_debug_errno(r, "Failed to parse realtime timestamp: %m");
-        }
-
-        if (r < 0) {
-                r = sd_journal_get_realtime_usec(j, &realtime);
-                if (r < 0)
-                        return log_full_errno(r == -EADDRNOTAVAIL ? LOG_DEBUG : LOG_ERR, r, "Failed to get realtime timestamp: %m");
-        }
+        if (!VALID_REALTIME(ts->realtime))
+                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(ts, sizeof ts, realtime,
+        timestamp = format_timestamp_style(buf, sizeof buf, ts->realtime,
                                            flags & OUTPUT_UTC ? TIMESTAMP_US_UTC : TIMESTAMP_US);
         fprintf(f, "%s [%s]\n",
                 timestamp ?: "(no timestamp)",
@@ -750,26 +725,26 @@ static int output_export(
                 unsigned n_columns,
                 OutputFlags flags,
                 const Set *output_fields,
-                const size_t highlight[2]) {
+                const size_t highlight[2],
+                const dual_timestamp *ts,
+                const sd_id128_t *boot_id) {
 
         _cleanup_free_ char *cursor = NULL;
-        usec_t realtime, monotonic;
-        sd_id128_t boot_id;
         const void *data;
         size_t length;
         int r;
 
         assert(j);
+        assert(ts);
+        assert(boot_id);
 
         sd_journal_set_data_threshold(j, 0);
 
-        r = sd_journal_get_realtime_usec(j, &realtime);
-        if (r < 0)
-                return log_error_errno(r, "Failed to get realtime timestamp: %m");
+        if (!VALID_REALTIME(ts->realtime))
+                return log_error_errno(SYNTHETIC_ERRNO(EINVAL), "No valid realtime timestamp available");
 
-        r = sd_journal_get_monotonic_usec(j, &monotonic, &boot_id);
-        if (r < 0)
-                return log_error_errno(r, "Failed to get monotonic timestamp: %m");
+        if (!VALID_MONOTONIC(ts->monotonic))
+                return log_error_errno(SYNTHETIC_ERRNO(EINVAL), "No valid monotonic timestamp available");
 
         r = sd_journal_get_cursor(j, &cursor);
         if (r < 0)
@@ -781,9 +756,9 @@ static int output_export(
                 "__MONOTONIC_TIMESTAMP="USEC_FMT"\n"
                 "_BOOT_ID=%s\n",
                 cursor,
-                realtime,
-                monotonic,
-                SD_ID128_TO_STRING(boot_id));
+                ts->realtime,
+                ts->monotonic,
+                SD_ID128_TO_STRING(*boot_id));
 
         JOURNAL_FOREACH_DATA_RETVAL(j, data, length, r) {
                 size_t fieldlen;
@@ -985,30 +960,30 @@ static int output_json(
                 unsigned n_columns,
                 OutputFlags flags,
                 const Set *output_fields,
-                const size_t highlight[2]) {
+                const size_t highlight[2],
+                const dual_timestamp *ts,
+                const sd_id128_t *boot_id) {
 
         char sid[SD_ID128_STRING_MAX], usecbuf[DECIMAL_STR_MAX(usec_t)];
         _cleanup_(json_variant_unrefp) JsonVariant *object = NULL;
         _cleanup_free_ char *cursor = NULL;
-        uint64_t realtime, monotonic;
         JsonVariant **array = NULL;
         struct json_data *d;
-        sd_id128_t boot_id;
         Hashmap *h = NULL;
         size_t n = 0;
         int r;
 
         assert(j);
+        assert(ts);
+        assert(boot_id);
 
         (void) sd_journal_set_data_threshold(j, flags & OUTPUT_SHOW_ALL ? 0 : JSON_THRESHOLD);
 
-        r = sd_journal_get_realtime_usec(j, &realtime);
-        if (r < 0)
-                return log_error_errno(r, "Failed to get realtime timestamp: %m");
+        if (!VALID_REALTIME(ts->realtime))
+                return log_error_errno(SYNTHETIC_ERRNO(EINVAL), "No valid realtime timestamp available");
 
-        r = sd_journal_get_monotonic_usec(j, &monotonic, &boot_id);
-        if (r < 0)
-                return log_error_errno(r, "Failed to get monotonic timestamp: %m");
+        if (!VALID_MONOTONIC(ts->monotonic))
+                return log_error_errno(SYNTHETIC_ERRNO(EINVAL), "No valid monotonic timestamp available");
 
         r = sd_journal_get_cursor(j, &cursor);
         if (r < 0)
@@ -1022,17 +997,17 @@ static int output_json(
         if (r < 0)
                 goto finish;
 
-        xsprintf(usecbuf, USEC_FMT, realtime);
+        xsprintf(usecbuf, USEC_FMT, ts->realtime);
         r = update_json_data(h, flags, "__REALTIME_TIMESTAMP", usecbuf, strlen(usecbuf));
         if (r < 0)
                 goto finish;
 
-        xsprintf(usecbuf, USEC_FMT, monotonic);
+        xsprintf(usecbuf, USEC_FMT, ts->monotonic);
         r = update_json_data(h, flags, "__MONOTONIC_TIMESTAMP", usecbuf, strlen(usecbuf));
         if (r < 0)
                 goto finish;
 
-        sd_id128_to_string(boot_id, sid);
+        sd_id128_to_string(*boot_id, sid);
         r = update_json_data(h, flags, "_BOOT_ID", sid, strlen(sid));
         if (r < 0)
                 goto finish;
@@ -1181,13 +1156,17 @@ static int output_cat(
                 unsigned n_columns,
                 OutputFlags flags,
                 const Set *output_fields,
-                const size_t highlight[2]) {
+                const size_t highlight[2],
+                const dual_timestamp *ts,
+                const sd_id128_t *boot_id) {
 
         int r, prio = LOG_INFO;
         const char *field;
 
         assert(j);
         assert(f);
+        assert(ts);
+        assert(boot_id);
 
         (void) sd_journal_set_data_threshold(j, 0);
 
@@ -1227,6 +1206,50 @@ static int output_cat(
         return 0;
 }
 
+static int get_dual_timestamp(sd_journal *j, dual_timestamp *ret_ts, sd_id128_t *ret_boot_id) {
+        const void *data;
+        _cleanup_free_ char *realtime = NULL, *monotonic = NULL;
+        size_t length = 0, realtime_len = 0, monotonic_len = 0;
+        const ParseFieldVec message_fields[] = {
+                PARSE_FIELD_VEC_ENTRY("_SOURCE_REALTIME_TIMESTAMP=", &realtime, &realtime_len),
+                PARSE_FIELD_VEC_ENTRY("_SOURCE_MONOTONIC_TIMESTAMP=", &monotonic, &monotonic_len),
+        };
+        int r;
+
+        assert(j);
+        assert(ret_ts);
+        assert(ret_boot_id);
+
+        JOURNAL_FOREACH_DATA_RETVAL(j, data, length, r) {
+                r = parse_fieldv(data, length, message_fields, ELEMENTSOF(message_fields));
+                if (r < 0)
+                        return r;
+        }
+        if (r < 0)
+                return r;
+
+        if (realtime)
+                r = safe_atou64(realtime, &ret_ts->realtime);
+        if (!realtime || r < 0 || !VALID_REALTIME(ret_ts->realtime))
+                r = sd_journal_get_realtime_usec(j, &ret_ts->realtime);
+        if (r < 0)
+                ret_ts->realtime = USEC_INFINITY;
+
+        if (monotonic)
+                r = safe_atou64(monotonic, &ret_ts->monotonic);
+        if (!monotonic || r < 0 || !VALID_MONOTONIC(ret_ts->monotonic))
+                r = sd_journal_get_monotonic_usec(j, &ret_ts->monotonic, ret_boot_id);
+        if (r < 0)
+                ret_ts->monotonic = USEC_INFINITY;
+
+        /* Restart all data before */
+        sd_journal_restart_data(j);
+        sd_journal_restart_unique(j);
+        sd_journal_restart_fields(j);
+
+        return 0;
+}
+
 static int (*output_funcs[_OUTPUT_MODE_MAX])(
                 FILE *f,
                 sd_journal *j,
@@ -1234,7 +1257,9 @@ static int (*output_funcs[_OUTPUT_MODE_MAX])(
                 unsigned n_columns,
                 OutputFlags flags,
                 const Set *output_fields,
-                const size_t highlight[2]) = {
+                const size_t highlight[2],
+                const dual_timestamp *ts,
+                const sd_id128_t *boot_id) = {
 
         [OUTPUT_SHORT]             = output_short,
         [OUTPUT_SHORT_ISO]         = output_short,
@@ -1264,6 +1289,8 @@ int show_journal_entry(
                 bool *ellipsized) {
 
         _cleanup_set_free_ Set *fields = NULL;
+        dual_timestamp ts = DUAL_TIMESTAMP_NULL;
+        sd_id128_t boot_id = SD_ID128_NULL;
         int r;
 
         assert(mode >= 0);
@@ -1276,7 +1303,15 @@ int show_journal_entry(
         if (r < 0)
                 return r;
 
-        r = output_funcs[mode](f, j, mode, n_columns, flags, fields, highlight);
+        r = get_dual_timestamp(j, &ts, &boot_id);
+        if (r == -EBADMSG) {
+                log_debug_errno(r, "Skipping message we can't read: %m");
+                return 0;
+        }
+        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);
 
         if (ellipsized && r > 0)
                 *ellipsized = true;