morgan/systemd
1
0
Fork 0
mirror of https://github.com/morgan9e/systemd synced 2026-04-14 00:14:32 +09:00
Code Issues Packages Projects Releases Wiki Activity

Merge pull request #32592 from yuwata/journal-timestamp

Browse Source 
journal: several timestamp cleanups and improvements
This commit is contained in:
Luca Boccassi
2024-05-02 13:57:40 +02:00
committed by GitHub
parent 57188d1467 affde1d7e7
commit afb1c42f5a
9 changed files with 119 additions and 93 deletions
Download Patch File Download Diff File Expand all files Collapse all files

1
src/basic/time-util.h
View File

@@ -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);

19
src/journal/journald-audit.c
View File

@@ -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. */

17
src/journal/journald-kmsg.c
View File

@@ -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");

4
src/journal/journald-server.c
View File

@@ -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);
}

4
src/journal/journald-server.h
View File

@@ -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;

2
src/journal/journald-socket.c
View File

@@ -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);

4
src/journal/journald-syslog.c
View File

@@ -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;

6
src/libsystemd/sd-journal/sd-journal.c
View File

@@ -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;
}

155
src/shared/logs-show.c
View File

@@ -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 : "",