mirror of
https://github.com/systemd/systemd
synced 2024-10-01 13:55:20 +00:00
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.
This commit is contained in:
parent
6ed286d2cf
commit
affde1d7e7
|
@ -72,6 +72,7 @@ typedef enum TimestampStyle {
|
||||||
#define TIME_T_MAX (time_t)((UINTMAX_C(1) << ((sizeof(time_t) << 3) - 1)) - 1)
|
#define TIME_T_MAX (time_t)((UINTMAX_C(1) << ((sizeof(time_t) << 3) - 1)) - 1)
|
||||||
|
|
||||||
#define DUAL_TIMESTAMP_NULL ((dual_timestamp) {})
|
#define DUAL_TIMESTAMP_NULL ((dual_timestamp) {})
|
||||||
|
#define DUAL_TIMESTAMP_INFINITY ((dual_timestamp) { USEC_INFINITY, USEC_INFINITY })
|
||||||
#define TRIPLE_TIMESTAMP_NULL ((triple_timestamp) {})
|
#define TRIPLE_TIMESTAMP_NULL ((triple_timestamp) {})
|
||||||
|
|
||||||
usec_t now(clockid_t clock);
|
usec_t now(clockid_t clock);
|
||||||
|
|
|
@ -439,37 +439,75 @@ static int output_timestamp_realtime(
|
||||||
return (int) strlen(buf);
|
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(
|
static void parse_display_timestamp(
|
||||||
sd_journal *j,
|
sd_journal *j,
|
||||||
const char *realtime,
|
const char *source_realtime,
|
||||||
const char *monotonic,
|
const char *source_monotonic,
|
||||||
dual_timestamp *ret_display_ts,
|
dual_timestamp *ret_display_ts,
|
||||||
sd_id128_t *ret_boot_id) {
|
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(j);
|
||||||
assert(ret_display_ts);
|
assert(ret_display_ts);
|
||||||
assert(ret_boot_id);
|
assert(ret_boot_id);
|
||||||
|
|
||||||
if (realtime)
|
if (source_realtime && safe_atou64(source_realtime, &t) >= 0 && VALID_REALTIME(t))
|
||||||
realtime_good = safe_atou64(realtime, &ret_display_ts->realtime) >= 0;
|
source_ts.realtime = t;
|
||||||
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)
|
if (source_monotonic && safe_atou64(source_monotonic, &t) >= 0 && VALID_MONOTONIC(t))
|
||||||
monotonic_good = safe_atou64(monotonic, &ret_display_ts->monotonic) >= 0;
|
source_ts.monotonic = t;
|
||||||
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)
|
(void) sd_journal_get_realtime_usec(j, &header_ts.realtime);
|
||||||
boot_id_good = sd_journal_get_monotonic_usec(j, NULL, ret_boot_id) >= 0;
|
(void) sd_journal_get_monotonic_usec(j, &header_ts.monotonic, &boot_id);
|
||||||
if (!boot_id_good)
|
|
||||||
*ret_boot_id = SD_ID128_NULL;
|
/* 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(
|
static int output_short(
|
||||||
|
@ -480,8 +518,8 @@ static int output_short(
|
||||||
OutputFlags flags,
|
OutputFlags flags,
|
||||||
const Set *output_fields,
|
const Set *output_fields,
|
||||||
const size_t highlight[2],
|
const size_t highlight[2],
|
||||||
dual_timestamp *previous_display_ts, /* 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 */
|
sd_id128_t *previous_boot_id) { /* in and out, used only when mode is OUTPUT_SHORT_MONOTONIC, OUTPUT_SHORT_DELTA. */
|
||||||
|
|
||||||
int r;
|
int r;
|
||||||
const void *data;
|
const void *data;
|
||||||
|
@ -546,8 +584,6 @@ static int output_short(
|
||||||
if (identifier && set_contains(j->exclude_syslog_identifiers, identifier))
|
if (identifier && set_contains(j->exclude_syslog_identifiers, identifier))
|
||||||
return 0;
|
return 0;
|
||||||
|
|
||||||
parse_display_timestamp(j, realtime, monotonic, &display_ts, &boot_id);
|
|
||||||
|
|
||||||
if (!(flags & OUTPUT_SHOW_ALL))
|
if (!(flags & OUTPUT_SHOW_ALL))
|
||||||
strip_tab_ansi(&message, &message_len, highlight_shifted);
|
strip_tab_ansi(&message, &message_len, highlight_shifted);
|
||||||
|
|
||||||
|
@ -559,10 +595,14 @@ static int output_short(
|
||||||
|
|
||||||
audit = streq_ptr(transport, "audit");
|
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);
|
r = output_timestamp_monotonic(f, mode, &display_ts, &boot_id, previous_display_ts, previous_boot_id);
|
||||||
else
|
} else {
|
||||||
r = output_timestamp_realtime(f, j, mode, flags, display_ts.realtime);
|
usec_t usec;
|
||||||
|
parse_display_realtime(j, realtime, monotonic, &usec);
|
||||||
|
r = output_timestamp_realtime(f, j, mode, flags, usec);
|
||||||
|
}
|
||||||
if (r < 0)
|
if (r < 0)
|
||||||
return r;
|
return r;
|
||||||
n += r;
|
n += r;
|
||||||
|
@ -683,17 +723,15 @@ static int output_short(
|
||||||
if (flags & OUTPUT_CATALOG)
|
if (flags & OUTPUT_CATALOG)
|
||||||
(void) print_catalog(f, j);
|
(void) print_catalog(f, j);
|
||||||
|
|
||||||
*previous_display_ts = display_ts;
|
if (IN_SET(mode, OUTPUT_SHORT_MONOTONIC, OUTPUT_SHORT_DELTA)) {
|
||||||
*previous_boot_id = boot_id;
|
*previous_display_ts = display_ts;
|
||||||
|
*previous_boot_id = boot_id;
|
||||||
|
}
|
||||||
|
|
||||||
return ellipsized;
|
return ellipsized;
|
||||||
}
|
}
|
||||||
|
|
||||||
static int get_display_timestamp(
|
static int get_display_realtime(sd_journal *j, usec_t *ret) {
|
||||||
sd_journal *j,
|
|
||||||
dual_timestamp *ret_display_ts,
|
|
||||||
sd_id128_t *ret_boot_id) {
|
|
||||||
|
|
||||||
const void *data;
|
const void *data;
|
||||||
_cleanup_free_ char *realtime = NULL, *monotonic = NULL;
|
_cleanup_free_ char *realtime = NULL, *monotonic = NULL;
|
||||||
size_t length;
|
size_t length;
|
||||||
|
@ -704,8 +742,7 @@ static int get_display_timestamp(
|
||||||
int r;
|
int r;
|
||||||
|
|
||||||
assert(j);
|
assert(j);
|
||||||
assert(ret_display_ts);
|
assert(ret);
|
||||||
assert(ret_boot_id);
|
|
||||||
|
|
||||||
JOURNAL_FOREACH_DATA_RETVAL(j, data, length, r) {
|
JOURNAL_FOREACH_DATA_RETVAL(j, data, length, r) {
|
||||||
r = parse_fieldv(data, length, message_fields, ELEMENTSOF(message_fields));
|
r = parse_fieldv(data, length, message_fields, ELEMENTSOF(message_fields));
|
||||||
|
@ -718,7 +755,7 @@ static int get_display_timestamp(
|
||||||
if (r < 0)
|
if (r < 0)
|
||||||
return r;
|
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 */
|
/* Restart all data before */
|
||||||
sd_journal_restart_data(j);
|
sd_journal_restart_data(j);
|
||||||
|
@ -743,9 +780,8 @@ static int output_verbose(
|
||||||
size_t length;
|
size_t length;
|
||||||
_cleanup_free_ char *cursor = NULL;
|
_cleanup_free_ char *cursor = NULL;
|
||||||
char buf[FORMAT_TIMESTAMP_MAX + 7];
|
char buf[FORMAT_TIMESTAMP_MAX + 7];
|
||||||
dual_timestamp display_ts;
|
|
||||||
sd_id128_t boot_id;
|
|
||||||
const char *timestamp;
|
const char *timestamp;
|
||||||
|
usec_t usec;
|
||||||
int r;
|
int r;
|
||||||
|
|
||||||
assert(f);
|
assert(f);
|
||||||
|
@ -753,7 +789,7 @@ static int output_verbose(
|
||||||
|
|
||||||
(void) sd_journal_set_data_threshold(j, 0);
|
(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)) {
|
if (IN_SET(r, -EBADMSG, -EADDRNOTAVAIL)) {
|
||||||
log_debug_errno(r, "Skipping message we can't read: %m");
|
log_debug_errno(r, "Skipping message we can't read: %m");
|
||||||
return 0;
|
return 0;
|
||||||
|
@ -761,14 +797,14 @@ static int output_verbose(
|
||||||
if (r < 0)
|
if (r < 0)
|
||||||
return log_error_errno(r, "Failed to get journal fields: %m");
|
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");
|
return log_error_errno(SYNTHETIC_ERRNO(EINVAL), "No valid realtime timestamp available");
|
||||||
|
|
||||||
r = sd_journal_get_cursor(j, &cursor);
|
r = sd_journal_get_cursor(j, &cursor);
|
||||||
if (r < 0)
|
if (r < 0)
|
||||||
return log_error_errno(r, "Failed to get cursor: %m");
|
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);
|
flags & OUTPUT_UTC ? TIMESTAMP_US_UTC : TIMESTAMP_US);
|
||||||
fprintf(f, "%s%s%s %s[%s]%s\n",
|
fprintf(f, "%s%s%s %s[%s]%s\n",
|
||||||
timestamp && (flags & OUTPUT_COLOR) ? ANSI_UNDERLINE : "",
|
timestamp && (flags & OUTPUT_COLOR) ? ANSI_UNDERLINE : "",
|
||||||
|
|
Loading…
Reference in a new issue