Skip to content

Commit 03237c0

Browse files
committed
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.
1 parent c058412 commit 03237c0

File tree

1 file changed

+80
-43
lines changed

1 file changed

+80
-43
lines changed

src/shared/logs-show.c

Lines changed: 80 additions & 43 deletions
Original file line numberDiff line numberDiff line change
@@ -446,37 +446,76 @@ static int output_timestamp_realtime(
446446
return (int) strlen(buf);
447447
}
448448

449+
static void parse_display_realtime(
450+
sd_journal *j,
451+
const char *source_realtime,
452+
const char *source_monotonic,
453+
usec_t *ret) {
454+
455+
usec_t t, s, u;
456+
457+
assert(j);
458+
459+
/* First, try _SOURCE_REALTIME_TIMESTAMP. */
460+
if (source_realtime && safe_atou64(source_realtime, &t) >= 0 && VALID_REALTIME(t)) {
461+
*ret = t;
462+
return;
463+
}
464+
465+
/* Read realtime timestamp in the entry header. */
466+
if (sd_journal_get_realtime_usec(j, &t) < 0) {
467+
*ret = USEC_INFINITY;
468+
return;
469+
}
470+
471+
/* If _SOURCE_MONOTONIC_TIMESTAMP is provided, adjust the header timestamp. */
472+
if (source_monotonic && safe_atou64(source_monotonic, &s) >= 0 && VALID_MONOTONIC(s) &&
473+
sd_journal_get_monotonic_usec(j, &u, &(sd_id128_t) {}) >= 0) {
474+
*ret = map_clock_usec_raw(t, u, s);
475+
return;
476+
}
477+
478+
/* Otherwise, use the header timestamp as is. */
479+
*ret = t;
480+
}
481+
449482
static void parse_display_timestamp(
450483
sd_journal *j,
451-
const char *realtime,
452-
const char *monotonic,
484+
const char *source_realtime,
485+
const char *source_monotonic,
453486
dual_timestamp *ret_display_ts,
454487
sd_id128_t *ret_boot_id) {
455488

456-
bool realtime_good = false, monotonic_good = false, boot_id_good = false;
489+
dual_timestamp
490+
header_ts = { USEC_INFINITY, USEC_INFINITY },
491+
source_ts = { USEC_INFINITY, USEC_INFINITY };
492+
sd_id128_t boot_id = SD_ID128_NULL;
493+
usec_t t;
457494

458495
assert(j);
459496
assert(ret_display_ts);
460497
assert(ret_boot_id);
461498

462-
if (realtime)
463-
realtime_good = safe_atou64(realtime, &ret_display_ts->realtime) >= 0;
464-
if (!realtime_good || !VALID_REALTIME(ret_display_ts->realtime))
465-
realtime_good = sd_journal_get_realtime_usec(j, &ret_display_ts->realtime) >= 0;
466-
if (!realtime_good)
467-
ret_display_ts->realtime = USEC_INFINITY;
468-
469-
if (monotonic)
470-
monotonic_good = safe_atou64(monotonic, &ret_display_ts->monotonic) >= 0;
471-
if (!monotonic_good || !VALID_MONOTONIC(ret_display_ts->monotonic))
472-
monotonic_good = boot_id_good = sd_journal_get_monotonic_usec(j, &ret_display_ts->monotonic, ret_boot_id) >= 0;
473-
if (!monotonic_good)
474-
ret_display_ts->monotonic = USEC_INFINITY;
475-
476-
if (!boot_id_good)
477-
boot_id_good = sd_journal_get_monotonic_usec(j, NULL, ret_boot_id) >= 0;
478-
if (!boot_id_good)
479-
*ret_boot_id = SD_ID128_NULL;
499+
if (source_realtime && safe_atou64(source_realtime, &t) >= 0 && VALID_REALTIME(t))
500+
source_ts.realtime = t;
501+
502+
if (source_monotonic && safe_atou64(source_monotonic, &t) >= 0 && VALID_MONOTONIC(t))
503+
source_ts.monotonic = t;
504+
505+
(void) sd_journal_get_realtime_usec(j, &header_ts.realtime);
506+
(void) sd_journal_get_monotonic_usec(j, &header_ts.monotonic, &boot_id);
507+
508+
/* Adjust timestamp if possible. */
509+
if (header_ts.realtime != USEC_INFINITY && header_ts.monotonic != USEC_INFINITY) {
510+
if (source_ts.realtime == USEC_INFINITY && source_ts.monotonic != USEC_INFINITY)
511+
source_ts.realtime = map_clock_usec_raw(header_ts.realtime, header_ts.monotonic, source_ts.monotonic);
512+
else if (source_ts.realtime != USEC_INFINITY && source_ts.monotonic == USEC_INFINITY)
513+
source_ts.monotonic = map_clock_usec_raw(header_ts.monotonic, header_ts.realtime, source_ts.realtime);
514+
}
515+
516+
ret_display_ts->realtime = source_ts.realtime != USEC_INFINITY ? source_ts.realtime : header_ts.realtime;
517+
ret_display_ts->monotonic = source_ts.monotonic != USEC_INFINITY ? source_ts.monotonic : header_ts.monotonic;
518+
*ret_boot_id = boot_id;
480519
}
481520

482521
static int output_short(
@@ -487,8 +526,8 @@ static int output_short(
487526
OutputFlags flags,
488527
const Set *output_fields,
489528
const size_t highlight[2],
490-
dual_timestamp *previous_display_ts, /* in and out */
491-
sd_id128_t *previous_boot_id) { /* in and out */
529+
dual_timestamp *previous_display_ts, /* in and out, used only when mode is OUTPUT_SHORT_MONOTONIC, OUTPUT_SHORT_DELTA. */
530+
sd_id128_t *previous_boot_id) { /* in and out, used only when mode is OUTPUT_SHORT_MONOTONIC, OUTPUT_SHORT_DELTA. */
492531

493532
int r;
494533
const void *data;
@@ -553,8 +592,6 @@ static int output_short(
553592
if (identifier && set_contains(j->exclude_syslog_identifiers, identifier))
554593
return 0;
555594

556-
parse_display_timestamp(j, realtime, monotonic, &display_ts, &boot_id);
557-
558595
if (!(flags & OUTPUT_SHOW_ALL))
559596
strip_tab_ansi(&message, &message_len, highlight_shifted);
560597

@@ -566,10 +603,14 @@ static int output_short(
566603

567604
audit = streq_ptr(transport, "audit");
568605

569-
if (IN_SET(mode, OUTPUT_SHORT_MONOTONIC, OUTPUT_SHORT_DELTA))
606+
if (IN_SET(mode, OUTPUT_SHORT_MONOTONIC, OUTPUT_SHORT_DELTA)) {
607+
parse_display_timestamp(j, realtime, monotonic, &display_ts, &boot_id);
570608
r = output_timestamp_monotonic(f, mode, &display_ts, &boot_id, previous_display_ts, previous_boot_id);
571-
else
572-
r = output_timestamp_realtime(f, j, mode, flags, display_ts.realtime);
609+
} else {
610+
usec_t usec;
611+
parse_display_realtime(j, realtime, monotonic, &usec);
612+
r = output_timestamp_realtime(f, j, mode, flags, usec);
613+
}
573614
if (r < 0)
574615
return r;
575616
n += r;
@@ -690,17 +731,15 @@ static int output_short(
690731
if (flags & OUTPUT_CATALOG)
691732
(void) print_catalog(f, j);
692733

693-
*previous_display_ts = display_ts;
694-
*previous_boot_id = boot_id;
734+
if (IN_SET(mode, OUTPUT_SHORT_MONOTONIC, OUTPUT_SHORT_DELTA)) {
735+
*previous_display_ts = display_ts;
736+
*previous_boot_id = boot_id;
737+
}
695738

696739
return ellipsized;
697740
}
698741

699-
static int get_display_timestamp(
700-
sd_journal *j,
701-
dual_timestamp *ret_display_ts,
702-
sd_id128_t *ret_boot_id) {
703-
742+
static int get_display_realtime(sd_journal *j, usec_t *ret) {
704743
const void *data;
705744
_cleanup_free_ char *realtime = NULL, *monotonic = NULL;
706745
size_t length;
@@ -711,8 +750,7 @@ static int get_display_timestamp(
711750
int r;
712751

713752
assert(j);
714-
assert(ret_display_ts);
715-
assert(ret_boot_id);
753+
assert(ret);
716754

717755
JOURNAL_FOREACH_DATA_RETVAL(j, data, length, r) {
718756
r = parse_fieldv(data, length, message_fields, ELEMENTSOF(message_fields));
@@ -725,7 +763,7 @@ static int get_display_timestamp(
725763
if (r < 0)
726764
return r;
727765

728-
(void) parse_display_timestamp(j, realtime, monotonic, ret_display_ts, ret_boot_id);
766+
(void) parse_display_realtime(j, realtime, monotonic, ret);
729767

730768
/* Restart all data before */
731769
sd_journal_restart_data(j);
@@ -750,32 +788,31 @@ static int output_verbose(
750788
size_t length;
751789
_cleanup_free_ char *cursor = NULL;
752790
char buf[FORMAT_TIMESTAMP_MAX + 7];
753-
dual_timestamp display_ts;
754-
sd_id128_t boot_id;
755791
const char *timestamp;
792+
usec_t usec;
756793
int r;
757794

758795
assert(f);
759796
assert(j);
760797

761798
(void) sd_journal_set_data_threshold(j, 0);
762799

763-
r = get_display_timestamp(j, &display_ts, &boot_id);
800+
r = get_display_realtime(j, &usec);
764801
if (IN_SET(r, -EBADMSG, -EADDRNOTAVAIL)) {
765802
log_debug_errno(r, "Skipping message we can't read: %m");
766803
return 0;
767804
}
768805
if (r < 0)
769806
return log_error_errno(r, "Failed to get journal fields: %m");
770807

771-
if (!VALID_REALTIME(display_ts.realtime))
808+
if (!VALID_REALTIME(usec))
772809
return log_error_errno(SYNTHETIC_ERRNO(EINVAL), "No valid realtime timestamp available");
773810

774811
r = sd_journal_get_cursor(j, &cursor);
775812
if (r < 0)
776813
return log_error_errno(r, "Failed to get cursor: %m");
777814

778-
timestamp = format_timestamp_style(buf, sizeof buf, display_ts.realtime,
815+
timestamp = format_timestamp_style(buf, sizeof buf, usec,
779816
flags & OUTPUT_UTC ? TIMESTAMP_US_UTC : TIMESTAMP_US);
780817
fprintf(f, "%s%s%s %s[%s]%s\n",
781818
timestamp && (flags & OUTPUT_COLOR) ? ANSI_UNDERLINE : "",

0 commit comments

Comments
 (0)