diff --git a/src/basic/time-util.h b/src/basic/time-util.h index ebcdc41118..b28ab8242f 100644 --- 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/journal/journald-audit.c b/src/journal/journald-audit.c index bddfe76c1a..d49283d225 100644 --- a/src/journal/journald-audit.c +++ b/src/journal/journald-audit.c @@ -335,10 +335,9 @@ void process_audit_string(Server *s, int type, const char *data, size_t size) { size_t n = 0, z; uint64_t seconds, msec, id; const char *p, *type_name; - char id_field[sizeof("_AUDIT_ID=") + DECIMAL_STR_MAX(uint64_t)], - type_field[sizeof("_AUDIT_TYPE=") + DECIMAL_STR_MAX(int)], - source_time_field[sizeof("_SOURCE_REALTIME_TIMESTAMP=") + DECIMAL_STR_MAX(usec_t)]; - struct iovec iovec[N_IOVEC_META_FIELDS + 8 + N_IOVEC_AUDIT_FIELDS]; + char id_field[STRLEN("_AUDIT_ID=") + DECIMAL_STR_MAX(uint64_t)], + type_field[STRLEN("_AUDIT_TYPE=") + DECIMAL_STR_MAX(int)]; + struct iovec iovec[N_IOVEC_META_FIELDS + 7 + N_IOVEC_AUDIT_FIELDS]; char *m, *type_field_name; int k; @@ -375,14 +374,10 @@ void process_audit_string(Server *s, int type, const char *data, size_t size) { iovec[n++] = IOVEC_MAKE_STRING("_TRANSPORT=audit"); - sprintf(source_time_field, "_SOURCE_REALTIME_TIMESTAMP=%" PRIu64, - (usec_t) seconds * USEC_PER_SEC + (usec_t) msec * USEC_PER_MSEC); - iovec[n++] = IOVEC_MAKE_STRING(source_time_field); - - sprintf(type_field, "_AUDIT_TYPE=%i", type); + xsprintf(type_field, "_AUDIT_TYPE=%i", type); iovec[n++] = IOVEC_MAKE_STRING(type_field); - sprintf(id_field, "_AUDIT_ID=%" PRIu64, id); + xsprintf(id_field, "_AUDIT_ID=%" PRIu64, id); iovec[n++] = IOVEC_MAKE_STRING(id_field); assert_cc(4 == LOG_FAC(LOG_AUTH)); @@ -401,7 +396,9 @@ void process_audit_string(Server *s, int type, const char *data, size_t size) { map_all_fields(p, map_fields_kernel, "_AUDIT_FIELD_", true, iovec, &n, n + N_IOVEC_AUDIT_FIELDS); - server_dispatch_message(s, iovec, n, ELEMENTSOF(iovec), NULL, NULL, LOG_NOTICE, 0); + server_dispatch_message(s, iovec, n, ELEMENTSOF(iovec), NULL, + TIMEVAL_STORE((usec_t) seconds * USEC_PER_SEC + (usec_t) msec * USEC_PER_MSEC), + LOG_NOTICE, 0); /* free() all entries that map_all_fields() added. All others * are allocated on the stack or are constant. */ diff --git a/src/journal/journald-kmsg.c b/src/journal/journald-kmsg.c index 28d48808d0..a5e1715b13 100644 --- a/src/journal/journald-kmsg.c +++ b/src/journal/journald-kmsg.c @@ -98,7 +98,7 @@ static bool is_us(const char *identifier, const char *pid) { void dev_kmsg_record(Server *s, char *p, size_t l) { - _cleanup_free_ char *message = NULL, *syslog_priority = NULL, *syslog_pid = NULL, *syslog_facility = NULL, *syslog_identifier = NULL, *source_time = NULL, *identifier = NULL, *pid = NULL; + _cleanup_free_ char *message = NULL, *syslog_pid = NULL, *syslog_identifier = NULL, *identifier = NULL, *pid = NULL; struct iovec iovec[N_IOVEC_META_FIELDS + 7 + N_IOVEC_KERNEL_FIELDS + 2 + N_IOVEC_UDEV_FIELDS]; char *kernel_device = NULL; unsigned long long usec; @@ -253,16 +253,19 @@ void dev_kmsg_record(Server *s, char *p, size_t l) { } } - if (asprintf(&source_time, "_SOURCE_MONOTONIC_TIMESTAMP=%llu", usec) >= 0) - iovec[n++] = IOVEC_MAKE_STRING(source_time); + char source_time[STRLEN("_SOURCE_MONOTONIC_TIMESTAMP=") + DECIMAL_STR_MAX(unsigned long long)]; + xsprintf(source_time, "_SOURCE_MONOTONIC_TIMESTAMP=%llu", usec); + iovec[n++] = IOVEC_MAKE_STRING(source_time); iovec[n++] = IOVEC_MAKE_STRING("_TRANSPORT=kernel"); - if (asprintf(&syslog_priority, "PRIORITY=%i", priority & LOG_PRIMASK) >= 0) - iovec[n++] = IOVEC_MAKE_STRING(syslog_priority); + char syslog_priority[STRLEN("PRIORITY=") + DECIMAL_STR_MAX(int)]; + xsprintf(syslog_priority, "PRIORITY=%i", priority & LOG_PRIMASK); + iovec[n++] = IOVEC_MAKE_STRING(syslog_priority); - if (asprintf(&syslog_facility, "SYSLOG_FACILITY=%i", LOG_FAC(priority)) >= 0) - iovec[n++] = IOVEC_MAKE_STRING(syslog_facility); + char syslog_facility[STRLEN("SYSLOG_FACILITY=") + DECIMAL_STR_MAX(int)]; + xsprintf(syslog_facility, "SYSLOG_FACILITY=%i", LOG_FAC(priority)); + iovec[n++] = IOVEC_MAKE_STRING(syslog_facility); if (LOG_FAC(priority) == LOG_KERN) iovec[n++] = IOVEC_MAKE_STRING("SYSLOG_IDENTIFIER=kernel"); diff --git a/src/journal/journald-server.c b/src/journal/journald-server.c index 2fa014a89c..a52aef5986 100644 --- a/src/journal/journald-server.c +++ b/src/journal/journald-server.c @@ -1073,7 +1073,7 @@ static void server_dispatch_message_real( int priority, pid_t object_pid) { - char source_time[sizeof("_SOURCE_REALTIME_TIMESTAMP=") + DECIMAL_STR_MAX(usec_t)]; + char source_time[STRLEN("_SOURCE_REALTIME_TIMESTAMP=") + DECIMAL_STR_MAX(usec_t)]; _unused_ _cleanup_free_ char *cmdline1 = NULL, *cmdline2 = NULL; uid_t journal_uid; ClientContext *o; @@ -1153,7 +1153,7 @@ static void server_dispatch_message_real( assert(n <= m); if (tv) { - sprintf(source_time, "_SOURCE_REALTIME_TIMESTAMP=" USEC_FMT, timeval_load(tv)); + xsprintf(source_time, "_SOURCE_REALTIME_TIMESTAMP=" USEC_FMT, timeval_load(tv)); iovec[n++] = IOVEC_MAKE_STRING(source_time); } diff --git a/src/journal/journald-server.h b/src/journal/journald-server.h index a7939029ca..3878061d09 100644 --- a/src/journal/journald-server.h +++ b/src/journal/journald-server.h @@ -162,8 +162,8 @@ struct Server { bool sent_notify_ready:1; bool sync_scheduled:1; - char machine_id_field[sizeof("_MACHINE_ID=") + 32]; - char boot_id_field[sizeof("_BOOT_ID=") + 32]; + char machine_id_field[STRLEN("_MACHINE_ID=") + SD_ID128_STRING_MAX]; + char boot_id_field[STRLEN("_BOOT_ID=") + SD_ID128_STRING_MAX]; char *hostname_field; char *namespace_field; char *runtime_directory; diff --git a/src/journal/journald-socket.c b/src/journal/journald-socket.c index 24c8f05d45..25e56de6f3 100644 --- a/src/journal/journald-socket.c +++ b/src/journal/journald-socket.c @@ -141,7 +141,7 @@ int server_forward_socket( /* Synthesise __REALTIME_TIMESTAMP as the last argument so systemd-journal-upload can receive these * export messages. */ - char buf[sizeof("__REALTIME_TIMESTAMP=") + DECIMAL_STR_MAX(usec_t) + 2]; + char buf[STRLEN("__REALTIME_TIMESTAMP=") + DECIMAL_STR_MAX(usec_t) + 2]; xsprintf(buf, "__REALTIME_TIMESTAMP="USEC_FMT"\n\n", now(CLOCK_REALTIME)); iov[iov_idx++] = IOVEC_MAKE_STRING(buf); diff --git a/src/journal/journald-syslog.c b/src/journal/journald-syslog.c index f6accb5b44..4539722b20 100644 --- a/src/journal/journald-syslog.c +++ b/src/journal/journald-syslog.c @@ -314,8 +314,8 @@ void server_process_syslog_message( const char *label, size_t label_len) { - char *t, syslog_priority[sizeof("PRIORITY=") + DECIMAL_STR_MAX(int)], - syslog_facility[sizeof("SYSLOG_FACILITY=") + DECIMAL_STR_MAX(int)]; + char *t, syslog_priority[STRLEN("PRIORITY=") + DECIMAL_STR_MAX(int)], + syslog_facility[STRLEN("SYSLOG_FACILITY=") + DECIMAL_STR_MAX(int)]; const char *msg, *syslog_ts, *a; _cleanup_free_ char *identifier = NULL, *pid = NULL, *dummy = NULL, *msg_msg = NULL, *msg_raw = NULL; diff --git a/src/libsystemd/sd-journal/sd-journal.c b/src/libsystemd/sd-journal/sd-journal.c index 713cdcc0ec..0aa37260b6 100644 --- a/src/libsystemd/sd-journal/sd-journal.c +++ b/src/libsystemd/sd-journal/sd-journal.c @@ -2656,9 +2656,7 @@ _public_ int sd_journal_get_monotonic_usec(sd_journal *j, uint64_t *ret, sd_id12 if (r < 0) return r; - if (ret_boot_id) - *ret_boot_id = o->entry.boot_id; - else { + if (!ret_boot_id) { sd_id128_t id; r = sd_id128_get_boot(&id); @@ -2675,6 +2673,8 @@ _public_ int sd_journal_get_monotonic_usec(sd_journal *j, uint64_t *ret, sd_id12 if (ret) *ret = t; + if (ret_boot_id) + *ret_boot_id = o->entry.boot_id; return 0; } diff --git a/src/shared/logs-show.c b/src/shared/logs-show.c index e63be5002c..d5b131a187 100644 --- a/src/shared/logs-show.c +++ b/src/shared/logs-show.c @@ -364,39 +364,37 @@ static int output_timestamp_realtime( sd_journal *j, OutputMode mode, OutputFlags flags, - const dual_timestamp *display_ts) { + usec_t usec) { char buf[CONST_MAX(FORMAT_TIMESTAMP_MAX, 64U)]; - int r; assert(f); assert(j); - assert(display_ts); - if (!VALID_REALTIME(display_ts->realtime)) - return log_error_errno(SYNTHETIC_ERRNO(EINVAL), "No valid realtime timestamp available"); + if (!VALID_REALTIME(usec)) + 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), display_ts->realtime, TIMESTAMP_UTC); + k = format_timestamp_style(buf, sizeof(buf), usec, TIMESTAMP_UTC); else - k = format_timestamp(buf, sizeof(buf), display_ts->realtime); + k = format_timestamp(buf, sizeof(buf), usec); if (!k) return log_error_errno(SYNTHETIC_ERRNO(EINVAL), - "Failed to format timestamp: %" PRIu64, display_ts->realtime); + "Failed to format timestamp: %" PRIu64, usec); } else { struct tm tm; time_t t; - t = (time_t) (display_ts->realtime / USEC_PER_SEC); + t = (time_t) (usec / USEC_PER_SEC); switch (mode) { case OUTPUT_SHORT_UNIX: - xsprintf(buf, "%10"PRI_TIME".%06"PRIu64, t, display_ts->realtime % USEC_PER_SEC); + xsprintf(buf, "%10"PRI_TIME".%06"PRIu64, t, usec % USEC_PER_SEC); break; case OUTPUT_SHORT_ISO: @@ -404,13 +402,11 @@ static int output_timestamp_realtime( size_t tail = strftime(buf, sizeof(buf), "%Y-%m-%dT%H:%M:%S", localtime_or_gmtime_r(&t, &tm, flags & OUTPUT_UTC)); if (tail == 0) - return log_error_errno(SYNTHETIC_ERRNO(EINVAL), - "Failed to format ISO time"); + return log_error_errno(SYNTHETIC_ERRNO(EINVAL), "Failed to format ISO time."); /* No usec in strftime, need to append */ if (mode == OUTPUT_SHORT_ISO_PRECISE) { - assert(ELEMENTSOF(buf) - tail >= 7); - snprintf(buf + tail, ELEMENTSOF(buf) - tail, ".%06"PRI_USEC, display_ts->realtime % USEC_PER_SEC); + assert_se(snprintf_ok(buf + tail, ELEMENTSOF(buf) - tail, ".%06"PRI_USEC, usec % USEC_PER_SEC)); tail += 7; } @@ -425,19 +421,12 @@ static int output_timestamp_realtime( if (strftime(buf, sizeof(buf), "%b %d %H:%M:%S", localtime_or_gmtime_r(&t, &tm, flags & OUTPUT_UTC)) <= 0) - return log_error_errno(SYNTHETIC_ERRNO(EINVAL), - "Failed to format syslog time"); + return log_error_errno(SYNTHETIC_ERRNO(EINVAL), "Failed to format syslog time."); if (mode == OUTPUT_SHORT_PRECISE) { - size_t k; - assert(sizeof(buf) > strlen(buf)); - k = sizeof(buf) - strlen(buf); - - r = snprintf(buf + strlen(buf), k, ".%06"PRIu64, display_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"); + if (!snprintf_ok(buf + strlen(buf), sizeof(buf) - strlen(buf), ".%06"PRIu64, usec % USEC_PER_SEC)) + return log_error_errno(SYNTHETIC_ERRNO(EINVAL), "Failed to format precise time."); } break; @@ -450,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 (source_realtime && safe_atou64(source_realtime, &t) >= 0 && VALID_REALTIME(t)) + source_ts.realtime = t; - 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 (source_monotonic && safe_atou64(source_monotonic, &t) >= 0 && VALID_MONOTONIC(t)) + source_ts.monotonic = t; - 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; + (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( @@ -491,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; @@ -557,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); @@ -570,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); + } 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; @@ -694,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; @@ -715,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)); @@ -729,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); @@ -754,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); @@ -764,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; @@ -772,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 : "",