From: Yu Watanabe Date: Tue, 2 Jan 2024 19:28:25 +0000 (+0900) Subject: logs-show: get timestamp and boot ID only when necessary X-Git-Tag: v256-rc1~902^2 X-Git-Url: http://git.ipfire.org/cgi-bin/gitweb.cgi?a=commitdiff_plain;h=63d2c7554e12dca3cde77431acc7d32ec8a3ba8c;p=thirdparty%2Fsystemd.git logs-show: get timestamp and boot ID only when necessary Previously, get_display_timestamp() is unconditionally called even if we will show logs in e.g. json format. This drops unnecessary call of get_display_timestamp(). This also makes journal fields in each entry parsed only once in output_short(). Still output_verbose() twice though. This should improve performance of dumping journals. Replaces #29365. Co-authored-by: Costa Tsaousis --- diff --git a/src/shared/logs-show.c b/src/shared/logs-show.c index 18780ad30ac..598c8ed12af 100644 --- a/src/shared/logs-show.c +++ b/src/shared/logs-show.c @@ -453,6 +453,39 @@ static int output_timestamp_realtime( return (int) strlen(buf); } +static void parse_display_timestamp( + sd_journal *j, + const char *realtime, + const char *monotonic, + dual_timestamp *ret_display_ts, + sd_id128_t *ret_boot_id) { + + bool realtime_good = false, monotonic_good = false, boot_id_good = false; + + 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 (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 (!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; +} + static int output_short( FILE *f, sd_journal *j, @@ -461,42 +494,43 @@ static int output_short( OutputFlags flags, const Set *output_fields, const size_t highlight[2], - const dual_timestamp *display_ts, - const sd_id128_t *boot_id, - const dual_timestamp *previous_display_ts, - const sd_id128_t *previous_boot_id) { + dual_timestamp *previous_display_ts, /* in and out */ + sd_id128_t *previous_boot_id) { /* in and out */ 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, *priority = NULL, *transport = NULL, - *config_file = NULL, *unit = NULL, *user_unit = NULL, *documentation_url = NULL; + *config_file = NULL, *unit = NULL, *user_unit = NULL, *documentation_url = NULL, + *realtime = NULL, *monotonic = NULL; size_t hostname_len = 0, identifier_len = 0, comm_len = 0, pid_len = 0, fake_pid_len = 0, message_len = 0, priority_len = 0, transport_len = 0, config_file_len = 0, unit_len = 0, user_unit_len = 0, documentation_url_len = 0; + dual_timestamp display_ts; + sd_id128_t boot_id; int p = LOG_INFO; bool ellipsized = false, audit; const ParseFieldVec fields[] = { - PARSE_FIELD_VEC_ENTRY("_PID=", &pid, &pid_len), - PARSE_FIELD_VEC_ENTRY("_COMM=", &comm, &comm_len), - PARSE_FIELD_VEC_ENTRY("MESSAGE=", &message, &message_len), - PARSE_FIELD_VEC_ENTRY("PRIORITY=", &priority, &priority_len), - PARSE_FIELD_VEC_ENTRY("_TRANSPORT=", &transport, &transport_len), - 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("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), - PARSE_FIELD_VEC_ENTRY("DOCUMENTATION=", &documentation_url, &documentation_url_len), + PARSE_FIELD_VEC_ENTRY("_PID=", &pid, &pid_len ), + PARSE_FIELD_VEC_ENTRY("_COMM=", &comm, &comm_len ), + PARSE_FIELD_VEC_ENTRY("MESSAGE=", &message, &message_len ), + PARSE_FIELD_VEC_ENTRY("PRIORITY=", &priority, &priority_len ), + PARSE_FIELD_VEC_ENTRY("_TRANSPORT=", &transport, &transport_len ), + 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("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 ), + PARSE_FIELD_VEC_ENTRY("DOCUMENTATION=", &documentation_url, &documentation_url_len), + PARSE_FIELD_VEC_ENTRY("_SOURCE_REALTIME_TIMESTAMP=", &realtime, NULL ), + PARSE_FIELD_VEC_ENTRY("_SOURCE_MONOTONIC_TIMESTAMP=", &monotonic, NULL ), }; size_t highlight_shifted[] = {highlight ? highlight[0] : 0, highlight ? highlight[1] : 0}; assert(f); assert(j); - assert(display_ts); - assert(boot_id); assert(previous_display_ts); assert(previous_boot_id); @@ -526,6 +560,8 @@ 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); @@ -538,9 +574,9 @@ static int output_short( audit = streq_ptr(transport, "audit"); if (IN_SET(mode, OUTPUT_SHORT_MONOTONIC, OUTPUT_SHORT_DELTA)) - 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 - r = output_timestamp_realtime(f, j, mode, flags, display_ts); + r = output_timestamp_realtime(f, j, mode, flags, &display_ts); if (r < 0) return r; n += r; @@ -661,9 +697,51 @@ static int output_short( if (flags & OUTPUT_CATALOG) (void) print_catalog(f, j); + *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) { + + const void *data; + _cleanup_free_ char *realtime = NULL, *monotonic = NULL; + size_t length; + const ParseFieldVec message_fields[] = { + PARSE_FIELD_VEC_ENTRY("_SOURCE_REALTIME_TIMESTAMP=", &realtime, NULL), + PARSE_FIELD_VEC_ENTRY("_SOURCE_MONOTONIC_TIMESTAMP=", &monotonic, NULL), + }; + int r; + + assert(j); + assert(ret_display_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 (realtime && monotonic) + break; + } + if (r < 0) + return r; + + (void) parse_display_timestamp(j, realtime, monotonic, ret_display_ts, ret_boot_id); + + /* Restart all data before */ + sd_journal_restart_data(j); + sd_journal_restart_unique(j); + sd_journal_restart_fields(j); + + return 0; +} + static int output_verbose( FILE *f, sd_journal *j, @@ -672,35 +750,39 @@ static int output_verbose( OutputFlags flags, const Set *output_fields, const size_t highlight[2], - const dual_timestamp *display_ts, - const sd_id128_t *boot_id, - const dual_timestamp *previous_display_ts, - const sd_id128_t *previous_boot_id) { + dual_timestamp *previous_display_ts, /* unused */ + sd_id128_t *previous_boot_id) { /* unused */ const void *data; 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; int r; assert(f); assert(j); - assert(display_ts); - assert(boot_id); - assert(previous_display_ts); - assert(previous_boot_id); (void) sd_journal_set_data_threshold(j, 0); - if (!VALID_REALTIME(display_ts->realtime)) + r = get_display_timestamp(j, &display_ts, &boot_id); + if (IN_SET(r, -EBADMSG, -EADDRNOTAVAIL)) { + 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"); + + if (!VALID_REALTIME(display_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(buf, sizeof buf, display_ts->realtime, + timestamp = format_timestamp_style(buf, sizeof buf, display_ts.realtime, flags & OUTPUT_UTC ? TIMESTAMP_US_UTC : TIMESTAMP_US); fprintf(f, "%s%s%s %s[%s]%s\n", timestamp && (flags & OUTPUT_COLOR) ? ANSI_UNDERLINE : "", @@ -789,10 +871,8 @@ static int output_export( OutputFlags flags, const Set *output_fields, const size_t highlight[2], - const dual_timestamp *display_ts, - const sd_id128_t *boot_id, - const dual_timestamp *previous_display_ts, - const sd_id128_t *previous_boot_id) { + dual_timestamp *previous_display_ts, /* unused */ + sd_id128_t *previous_boot_id) { /* unused */ sd_id128_t journal_boot_id, seqnum_id; _cleanup_free_ char *cursor = NULL; @@ -803,10 +883,6 @@ static int output_export( int r; assert(j); - assert(display_ts); - assert(boot_id); - assert(previous_display_ts); - assert(previous_boot_id); (void) sd_journal_set_data_threshold(j, 0); @@ -1058,10 +1134,8 @@ static int output_json( OutputFlags flags, const Set *output_fields, const size_t highlight[2], - const dual_timestamp *display_ts, - const sd_id128_t *boot_id, - const dual_timestamp *previous_display_ts, - const sd_id128_t *previous_boot_id) { + dual_timestamp *previous_display_ts, /* unused */ + sd_id128_t *previous_boot_id) { /* unused */ char usecbuf[CONST_MAX(DECIMAL_STR_MAX(usec_t), DECIMAL_STR_MAX(uint64_t))]; _cleanup_(json_variant_unrefp) JsonVariant *object = NULL; @@ -1076,10 +1150,6 @@ static int output_json( int r; assert(j); - assert(display_ts); - assert(boot_id); - assert(previous_display_ts); - assert(previous_boot_id); (void) sd_journal_set_data_threshold(j, flags & OUTPUT_SHOW_ALL ? 0 : JSON_THRESHOLD); @@ -1241,20 +1311,14 @@ static int output_cat( OutputFlags flags, const Set *output_fields, const size_t highlight[2], - const dual_timestamp *display_ts, - const sd_id128_t *boot_id, - const dual_timestamp *previous_display_ts, - const sd_id128_t *previous_boot_id) { + dual_timestamp *previous_display_ts, /* unused */ + sd_id128_t *previous_boot_id) { /* unused */ int r, prio = LOG_INFO; const char *field; assert(j); assert(f); - assert(display_ts); - assert(boot_id); - assert(previous_display_ts); - assert(previous_boot_id); (void) sd_journal_set_data_threshold(j, 0); @@ -1294,63 +1358,6 @@ static int output_cat( return 0; } -static int get_display_timestamp( - sd_journal *j, - dual_timestamp *ret_display_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; - bool realtime_good = false, monotonic_good = false, boot_id_good = false; - - assert(j); - assert(ret_display_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 (realtime && monotonic) - break; - } - if (r < 0) - return r; - - 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 (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 (!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; - - /* Restart all data before */ - sd_journal_restart_data(j); - sd_journal_restart_unique(j); - sd_journal_restart_fields(j); - - return 0; -} - typedef int (*output_func_t)( FILE *f, sd_journal *j, @@ -1359,10 +1366,8 @@ typedef int (*output_func_t)( OutputFlags flags, const Set *output_fields, const size_t highlight[2], - const dual_timestamp *display_ts, - const sd_id128_t *boot_id, - const dual_timestamp *previous_display_ts, - const sd_id128_t *previous_boot_id); + dual_timestamp *previous_display_ts, + sd_id128_t *previous_boot_id); static output_func_t output_funcs[_OUTPUT_MODE_MAX] = { @@ -1396,8 +1401,6 @@ int show_journal_entry( dual_timestamp *previous_display_ts, sd_id128_t *previous_boot_id) { - dual_timestamp display_ts = DUAL_TIMESTAMP_NULL; - sd_id128_t boot_id = SD_ID128_NULL; int r; assert(mode >= 0); @@ -1408,14 +1411,6 @@ int show_journal_entry( if (n_columns <= 0) n_columns = columns(); - r = get_display_timestamp(j, &display_ts, &boot_id); - if (IN_SET(r, -EBADMSG, -EADDRNOTAVAIL)) { - 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, @@ -1424,15 +1419,9 @@ int show_journal_entry( flags, output_fields, highlight, - &display_ts, - &boot_id, previous_display_ts, previous_boot_id); - /* Store timestamp and boot ID for next iteration */ - *previous_display_ts = display_ts; - *previous_boot_id = boot_id; - if (ellipsized && r > 0) *ellipsized = true;