From 4f0165fd34fcae33fd4b38f6d3641be75193ec0e Mon Sep 17 00:00:00 2001 From: Yu Watanabe Date: Thu, 4 May 2023 09:39:50 +0900 Subject: [PATCH 01/11] journalctl: always initialize global variables That's not necessary, as they are initialized with zero, but for safety and readability. --- src/journal/journalctl.c | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/src/journal/journalctl.c b/src/journal/journalctl.c index c53f2d5847..d5172a3842 100644 --- a/src/journal/journalctl.c +++ b/src/journal/journalctl.c @@ -115,7 +115,7 @@ static char *arg_verify_key = NULL; static usec_t arg_interval = DEFAULT_FSS_INTERVAL_USEC; static bool arg_force = false; #endif -static usec_t arg_since, arg_until; +static usec_t arg_since = 0, arg_until = 0; static bool arg_since_set = false, arg_until_set = false; static char **arg_syslog_identifier = NULL; static char **arg_system_units = NULL; From 20e933ae7404154f642fd5459c11532102f8a598 Mon Sep 17 00:00:00 2001 From: Yu Watanabe Date: Thu, 4 May 2023 09:42:42 +0900 Subject: [PATCH 02/11] journalctl: use correct variable to check if --since is specified --- src/journal/journalctl.c | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/src/journal/journalctl.c b/src/journal/journalctl.c index d5172a3842..b59791d437 100644 --- a/src/journal/journalctl.c +++ b/src/journal/journalctl.c @@ -1047,7 +1047,7 @@ static int parse_argv(int argc, char *argv[]) { assert_not_reached(); } - if (arg_follow && !arg_no_tail && !arg_since && arg_lines == ARG_LINES_DEFAULT) + if (arg_follow && !arg_no_tail && !arg_since_set && arg_lines == ARG_LINES_DEFAULT) arg_lines = 10; if (arg_follow && !arg_merge && !arg_boot) { From 3f2203f64df1d71564acd8b878906254f2a76c35 Mon Sep 17 00:00:00 2001 From: Yu Watanabe Date: Thu, 4 May 2023 10:09:37 +0900 Subject: [PATCH 03/11] journalctl: fix --no-tail handling Fixes a bug introduced by 62f21ec91ad8e7e24079962f4df066b0094fe68d. --- src/journal/journalctl.c | 5 ++++- 1 file changed, 4 insertions(+), 1 deletion(-) diff --git a/src/journal/journalctl.c b/src/journal/journalctl.c index b59791d437..35fb2d275f 100644 --- a/src/journal/journalctl.c +++ b/src/journal/journalctl.c @@ -1047,7 +1047,10 @@ static int parse_argv(int argc, char *argv[]) { assert_not_reached(); } - if (arg_follow && !arg_no_tail && !arg_since_set && arg_lines == ARG_LINES_DEFAULT) + if (arg_no_tail) + arg_lines = ARG_LINES_ALL; + + if (arg_follow && !arg_since_set && arg_lines == ARG_LINES_DEFAULT) arg_lines = 10; if (arg_follow && !arg_merge && !arg_boot) { From 2ce9a07b3476e8a376dd852352b576b2daa86242 Mon Sep 17 00:00:00 2001 From: Yu Watanabe Date: Thu, 4 May 2023 06:51:40 +0900 Subject: [PATCH 04/11] journalctl: split out action_list_fields() No functional change, just refactoring. --- src/journal/journalctl.c | 66 +++++++++++++++++++++------------------- 1 file changed, 35 insertions(+), 31 deletions(-) diff --git a/src/journal/journalctl.c b/src/journal/journalctl.c index 35fb2d275f..a480bb9b3b 100644 --- a/src/journal/journalctl.c +++ b/src/journal/journalctl.c @@ -2061,6 +2061,39 @@ static int sync_journal(void) { return simple_varlink_call("--sync", "io.systemd.Journal.Synchronize"); } +static int action_list_fields(sd_journal *j) { + const void *data; + size_t size; + int r, n_shown = 0; + + assert(arg_field); + + r = sd_journal_set_data_threshold(j, 0); + if (r < 0) + return log_error_errno(r, "Failed to unset data size threshold: %m"); + + r = sd_journal_query_unique(j, arg_field); + if (r < 0) + return log_error_errno(r, "Failed to query unique data objects: %m"); + + SD_JOURNAL_FOREACH_UNIQUE(j, data, size) { + const void *eq; + + if (arg_lines >= 0 && n_shown >= arg_lines) + break; + + eq = memchr(data, '=', size); + if (eq) + printf("%.*s\n", (int) (size - ((const uint8_t*) eq - (const uint8_t*) data + 1)), (const char*) eq + 1); + else + printf("%.*s\n", (int) size, (const char*) data); + + n_shown++; + } + + return 0; +} + static int wait_for_change(sd_journal *j, int poll_fd) { struct pollfd pollfds[] = { { .fd = poll_fd, .events = POLLIN }, @@ -2384,37 +2417,8 @@ static int run(int argc, char *argv[]) { log_debug("Journal filter: %s", filter); } - if (arg_action == ACTION_LIST_FIELDS) { - const void *data; - size_t size; - - assert(arg_field); - - r = sd_journal_set_data_threshold(j, 0); - if (r < 0) - return log_error_errno(r, "Failed to unset data size threshold: %m"); - - r = sd_journal_query_unique(j, arg_field); - if (r < 0) - return log_error_errno(r, "Failed to query unique data objects: %m"); - - SD_JOURNAL_FOREACH_UNIQUE(j, data, size) { - const void *eq; - - if (arg_lines >= 0 && n_shown >= arg_lines) - break; - - eq = memchr(data, '=', size); - if (eq) - printf("%.*s\n", (int) (size - ((const uint8_t*) eq - (const uint8_t*) data + 1)), (const char*) eq + 1); - else - printf("%.*s\n", (int) size, (const char*) data); - - n_shown++; - } - - return 0; - } + if (arg_action == ACTION_LIST_FIELDS) + return action_list_fields(j); /* Opening the fd now means the first sd_journal_wait() will actually wait */ if (arg_follow) { From 8c12d3586a4537b5fb508a3bcf04ed77262f6aa2 Mon Sep 17 00:00:00 2001 From: Yu Watanabe Date: Thu, 4 May 2023 09:29:25 +0900 Subject: [PATCH 05/11] journalctl: split out update_cursor() No functional change, just refactoring. --- src/journal/journalctl.c | 50 ++++++++++++++++++++++++---------------- 1 file changed, 30 insertions(+), 20 deletions(-) diff --git a/src/journal/journalctl.c b/src/journal/journalctl.c index a480bb9b3b..75af23ecc8 100644 --- a/src/journal/journalctl.c +++ b/src/journal/journalctl.c @@ -2094,6 +2094,33 @@ static int action_list_fields(sd_journal *j) { return 0; } +static int update_cursor(sd_journal *j) { + _cleanup_free_ char *cursor = NULL; + int r; + + assert(j); + + if (!arg_show_cursor && !arg_cursor_file) + return 0; + + r = sd_journal_get_cursor(j, &cursor); + if (r == -EADDRNOTAVAIL) + return 0; + if (r < 0) + return log_error_errno(r, "Failed to get cursor: %m"); + + if (arg_show_cursor) + printf("-- cursor: %s\n", cursor); + + if (arg_cursor_file) { + r = write_string_file(arg_cursor_file, cursor, WRITE_STRING_FILE_CREATE | WRITE_STRING_FILE_ATOMIC); + if (r < 0) + return log_error_errno(r, "Failed to write new cursor to %s: %m", arg_cursor_file); + } + + return 0; +} + static int wait_for_change(sd_journal *j, int poll_fd) { struct pollfd pollfds[] = { { .fd = poll_fd, .events = POLLIN }, @@ -2690,26 +2717,9 @@ static int run(int argc, char *argv[]) { first_line = false; } - if (arg_show_cursor || arg_cursor_file) { - _cleanup_free_ char *cursor = NULL; - - r = sd_journal_get_cursor(j, &cursor); - if (r < 0 && r != -EADDRNOTAVAIL) - return log_error_errno(r, "Failed to get cursor: %m"); - if (r >= 0) { - if (arg_show_cursor) - printf("-- cursor: %s\n", cursor); - - if (arg_cursor_file) { - r = write_string_file(arg_cursor_file, cursor, - WRITE_STRING_FILE_CREATE | - WRITE_STRING_FILE_ATOMIC); - if (r < 0) - return log_error_errno(r, "Failed to write new cursor to %s: %m", - arg_cursor_file); - } - } - } + r = update_cursor(j); + if (r < 0) + return r; if (arg_compiled_pattern && n_shown == 0) /* --grep was used, no error was thrown, but the pattern didn't From e4c4a9db87f79292d79abae2afadaec240026829 Mon Sep 17 00:00:00 2001 From: Yu Watanabe Date: Thu, 4 May 2023 08:13:59 +0900 Subject: [PATCH 06/11] journalctl: split out show() No functional changes, just refactoring. --- src/journal/journalctl.c | 317 ++++++++++++++++++++++----------------- 1 file changed, 178 insertions(+), 139 deletions(-) diff --git a/src/journal/journalctl.c b/src/journal/journalctl.c index 75af23ecc8..0f1a738fa5 100644 --- a/src/journal/journalctl.c +++ b/src/journal/journalctl.c @@ -2156,16 +2156,162 @@ static int wait_for_change(sd_journal *j, int poll_fd) { return 0; } +typedef struct Context { + sd_journal *journal; + bool need_seek; + bool since_seeked; + bool ellipsized; + bool previous_boot_id_valid; + sd_id128_t previous_boot_id; + sd_id128_t previous_boot_id_output; + dual_timestamp previous_ts_output; +} Context; + +static int show(Context *c) { + sd_journal *j; + int r, n_shown = 0; + + assert(c); + + j = ASSERT_PTR(c->journal); + + while (arg_lines < 0 || n_shown < arg_lines || arg_follow) { + int flags; + size_t highlight[2] = {}; + + if (c->need_seek) { + if (!arg_reverse) + r = sd_journal_next(j); + else + r = sd_journal_previous(j); + if (r < 0) + return log_error_errno(r, "Failed to iterate through journal: %m"); + if (r == 0) + break; + } + + if (arg_until_set && !arg_reverse && (arg_lines < 0 || arg_since_set)) { + /* If --lines= is set, we usually rely on the n_shown to tell us + * when to stop. However, if --since= is set too, we may end up + * having less than --lines= to output. In this case let's also + * check if the entry is in range. */ + + usec_t usec; + + r = sd_journal_get_realtime_usec(j, &usec); + if (r < 0) + return log_error_errno(r, "Failed to determine timestamp: %m"); + if (usec > arg_until) + break; + } + + if (arg_since_set && (arg_reverse || !c->since_seeked)) { + usec_t usec; + + r = sd_journal_get_realtime_usec(j, &usec); + if (r < 0) + return log_error_errno(r, "Failed to determine timestamp: %m"); + + if (usec < arg_since) { + if (arg_reverse) + break; /* Reached the earliest entry */ + + /* arg_lines >= 0 (!since_seeked): + * We jumped arg_lines back and it seems to be too much */ + r = sd_journal_seek_realtime_usec(j, arg_since); + if (r < 0) + return log_error_errno(r, "Failed to seek to date: %m"); + c->since_seeked = true; + + c->need_seek = true; + continue; + } + c->since_seeked = true; /* We're surely within the range of --since now */ + } + + if (!arg_merge && !arg_quiet) { + sd_id128_t boot_id; + + r = sd_journal_get_monotonic_usec(j, NULL, &boot_id); + if (r >= 0) { + if (c->previous_boot_id_valid && + !sd_id128_equal(boot_id, c->previous_boot_id)) + printf("%s-- Boot "SD_ID128_FORMAT_STR" --%s\n", + ansi_highlight(), SD_ID128_FORMAT_VAL(boot_id), ansi_normal()); + + c->previous_boot_id = boot_id; + c->previous_boot_id_valid = true; + } + } + + if (arg_compiled_pattern) { + const void *message; + size_t len; + + r = sd_journal_get_data(j, "MESSAGE", &message, &len); + if (r < 0) { + if (r == -ENOENT) { + c->need_seek = true; + continue; + } + + return log_error_errno(r, "Failed to get MESSAGE field: %m"); + } + + assert_se(message = startswith(message, "MESSAGE=")); + + r = pattern_matches_and_log(arg_compiled_pattern, message, + len - strlen("MESSAGE="), highlight); + if (r < 0) + return r; + if (r == 0) { + c->need_seek = true; + continue; + } + } + + flags = + arg_all * OUTPUT_SHOW_ALL | + arg_full * OUTPUT_FULL_WIDTH | + colors_enabled() * OUTPUT_COLOR | + arg_catalog * OUTPUT_CATALOG | + arg_utc * OUTPUT_UTC | + arg_no_hostname * OUTPUT_NO_HOSTNAME; + + r = show_journal_entry(stdout, j, arg_output, 0, flags, + arg_output_fields, highlight, &c->ellipsized, + &c->previous_ts_output, &c->previous_boot_id_output); + c->need_seek = true; + if (r == -EADDRNOTAVAIL) + break; + if (r < 0) + return r; + + n_shown++; + + /* If journalctl take a long time to process messages, and during that time journal file + * rotation occurs, a journalctl client will keep those rotated files open until it calls + * sd_journal_process(), which typically happens as a result of calling sd_journal_wait() below + * in the "following" case. By periodically calling sd_journal_process() during the processing + * loop we shrink the window of time a client instance has open file descriptors for rotated + * (deleted) journal files. */ + if ((n_shown % PROCESS_INOTIFY_INTERVAL) == 0) { + r = sd_journal_process(j); + if (r < 0) + return log_error_errno(r, "Failed to process inotify events: %m"); + } + } + + return n_shown; +} + static int run(int argc, char *argv[]) { + bool need_seek = false, since_seeked = false, use_cursor = false, after_cursor = false; _cleanup_(loop_device_unrefp) LoopDevice *loop_device = NULL; _cleanup_(umount_and_freep) char *mounted_dir = NULL; - bool previous_boot_id_valid = false, first_line = true, ellipsized = false, need_seek = false, since_seeked = false; - bool use_cursor = false, after_cursor = false; _cleanup_(sd_journal_closep) sd_journal *j = NULL; - sd_id128_t previous_boot_id = SD_ID128_NULL, previous_boot_id_output = SD_ID128_NULL; - dual_timestamp previous_ts_output = DUAL_TIMESTAMP_NULL; _cleanup_close_ int machine_fd = -EBADF; - int n_shown = 0, r, poll_fd = -EBADF; + int n_shown, r, poll_fd = -EBADF; setlocale(LC_ALL, ""); log_setup(); @@ -2574,149 +2720,42 @@ static int run(int argc, char *argv[]) { } } - for (;;) { - while (arg_lines < 0 || n_shown < arg_lines || (arg_follow && !first_line)) { - int flags; - size_t highlight[2] = {}; + Context c = { + .journal = j, + .need_seek = need_seek, + .since_seeked = since_seeked, + }; - if (need_seek) { - if (!arg_reverse) - r = sd_journal_next(j); - else - r = sd_journal_previous(j); - if (r < 0) - return log_error_errno(r, "Failed to iterate through journal: %m"); - if (r == 0) - break; - } - - if (arg_until_set && !arg_reverse && (arg_lines < 0 || arg_since_set)) { - /* If --lines= is set, we usually rely on the n_shown to tell us - * when to stop. However, if --since= is set too, we may end up - * having less than --lines= to output. In this case let's also - * check if the entry is in range. */ - - usec_t usec; - - r = sd_journal_get_realtime_usec(j, &usec); - if (r < 0) - return log_error_errno(r, "Failed to determine timestamp: %m"); - if (usec > arg_until) - break; - } - - if (arg_since_set && (arg_reverse || !since_seeked)) { - usec_t usec; - - r = sd_journal_get_realtime_usec(j, &usec); - if (r < 0) - return log_error_errno(r, "Failed to determine timestamp: %m"); - - if (usec < arg_since) { - if (arg_reverse) - break; /* Reached the earliest entry */ - - /* arg_lines >= 0 (!since_seeked): - * We jumped arg_lines back and it seems to be too much */ - r = sd_journal_seek_realtime_usec(j, arg_since); - if (r < 0) - return log_error_errno(r, "Failed to seek to date: %m"); - since_seeked = true; - - need_seek = true; - continue; - } - since_seeked = true; /* We're surely within the range of --since now */ - } - - if (!arg_merge && !arg_quiet) { - sd_id128_t boot_id; - - r = sd_journal_get_monotonic_usec(j, NULL, &boot_id); - if (r >= 0) { - if (previous_boot_id_valid && - !sd_id128_equal(boot_id, previous_boot_id)) - printf("%s-- Boot "SD_ID128_FORMAT_STR" --%s\n", - ansi_highlight(), SD_ID128_FORMAT_VAL(boot_id), ansi_normal()); - - previous_boot_id = boot_id; - previous_boot_id_valid = true; - } - } - - if (arg_compiled_pattern) { - const void *message; - size_t len; - - r = sd_journal_get_data(j, "MESSAGE", &message, &len); - if (r < 0) { - if (r == -ENOENT) { - need_seek = true; - continue; - } - - return log_error_errno(r, "Failed to get MESSAGE field: %m"); - } - - assert_se(message = startswith(message, "MESSAGE=")); - - r = pattern_matches_and_log(arg_compiled_pattern, message, - len - strlen("MESSAGE="), highlight); - if (r < 0) - return r; - if (r == 0) { - need_seek = true; - continue; - } - } - - flags = - arg_all * OUTPUT_SHOW_ALL | - arg_full * OUTPUT_FULL_WIDTH | - colors_enabled() * OUTPUT_COLOR | - arg_catalog * OUTPUT_CATALOG | - arg_utc * OUTPUT_UTC | - arg_no_hostname * OUTPUT_NO_HOSTNAME; - - r = show_journal_entry(stdout, j, arg_output, 0, flags, - arg_output_fields, highlight, &ellipsized, - &previous_ts_output, &previous_boot_id_output); - need_seek = true; - if (r == -EADDRNOTAVAIL) - break; + if (arg_follow) { + if (arg_lines != 0 || arg_since_set) { + r = show(&c); if (r < 0) return r; - n_shown++; - - /* If journalctl take a long time to process messages, and during that time journal file - * rotation occurs, a journalctl client will keep those rotated files open until it calls - * sd_journal_process(), which typically happens as a result of calling sd_journal_wait() below - * in the "following" case. By periodically calling sd_journal_process() during the processing - * loop we shrink the window of time a client instance has open file descriptors for rotated - * (deleted) journal files. */ - if ((n_shown % PROCESS_INOTIFY_INTERVAL) == 0) { - r = sd_journal_process(j); - if (r < 0) - return log_error_errno(r, "Failed to process inotify events: %m"); - } + fflush(stdout); } - if (!arg_follow) { - if (n_shown == 0 && !arg_quiet) - printf("-- No entries --\n"); - break; + for (;;) { + r = wait_for_change(j, poll_fd); + if (r < 0) + return r; + + r = show(&c); + if (r < 0) + return r; + + fflush(stdout); } - - fflush(stdout); - - r = wait_for_change(j, poll_fd); - if (r < 0) - return r; - - first_line = false; } + r = show(&c); + if (r < 0) + return r; + n_shown = r; + + if (n_shown == 0 && !arg_quiet) + printf("-- No entries --\n"); + r = update_cursor(j); if (r < 0) return r; From 713342d9b09d717e9942ed08bd620c9159a98fb8 Mon Sep 17 00:00:00 2001 From: Yu Watanabe Date: Thu, 4 May 2023 08:38:53 +0900 Subject: [PATCH 07/11] journalctl: replace ppoll() loop with sd_event_loop() No functional change, just refactoring. --- src/journal/journalctl.c | 122 +++++++++++++++++++++++---------------- 1 file changed, 71 insertions(+), 51 deletions(-) diff --git a/src/journal/journalctl.c b/src/journal/journalctl.c index 0f1a738fa5..9bfeb121ee 100644 --- a/src/journal/journalctl.c +++ b/src/journal/journalctl.c @@ -2121,41 +2121,6 @@ static int update_cursor(sd_journal *j) { return 0; } -static int wait_for_change(sd_journal *j, int poll_fd) { - struct pollfd pollfds[] = { - { .fd = poll_fd, .events = POLLIN }, - { .fd = STDOUT_FILENO }, - }; - usec_t timeout; - int r; - - assert(j); - assert(poll_fd >= 0); - - /* Much like sd_journal_wait() but also keeps an eye on STDOUT, and exits as soon as we see a POLLHUP on that, - * i.e. when it is closed. */ - - r = sd_journal_get_timeout(j, &timeout); - if (r < 0) - return log_error_errno(r, "Failed to determine journal waiting time: %m"); - - r = ppoll_usec(pollfds, ELEMENTSOF(pollfds), timeout); - if (r == -EINTR) - return 0; - if (r < 0) - return log_error_errno(r, "Couldn't wait for journal event: %m"); - - if (pollfds[1].revents & (POLLHUP|POLLERR)) /* STDOUT has been closed? */ - return log_debug_errno(SYNTHETIC_ERRNO(ECANCELED), - "Standard output has been closed."); - - r = sd_journal_process(j); - if (r < 0) - return log_error_errno(r, "Failed to process journal events: %m"); - - return 0; -} - typedef struct Context { sd_journal *journal; bool need_seek; @@ -2305,6 +2270,71 @@ static int show(Context *c) { return n_shown; } +static int show_and_fflush(Context *c, sd_event_source *s) { + int r; + + assert(c); + assert(s); + + r = show(c); + if (r < 0) + return sd_event_exit(sd_event_source_get_event(s), r); + + fflush(stdout); + return 0; +} + +static int on_journal_event(sd_event_source *s, int fd, uint32_t revents, void *userdata) { + Context *c = ASSERT_PTR(userdata); + int r; + + assert(s); + + r = sd_journal_process(c->journal); + if (r < 0) { + log_error_errno(r, "Failed to process journal events: %m"); + return sd_event_exit(sd_event_source_get_event(s), r); + } + + return show_and_fflush(c, s); +} + +static int on_first_event(sd_event_source *s, void *userdata) { + return show_and_fflush(userdata, s); +} + +static int setup_event(Context *c, int fd, sd_event **ret) { + _cleanup_(sd_event_unrefp) sd_event *e = NULL; + int r; + + assert(arg_follow); + assert(c); + assert(fd >= 0); + assert(ret); + + r = sd_event_default(&e); + if (r < 0) + return log_error_errno(r, "Failed to allocate sd_event object: %m"); + + r = sd_event_add_io(e, NULL, fd, EPOLLIN, &on_journal_event, c); + if (r < 0) + return log_error_errno(r, "Failed to add io event source for journal: %m"); + + /* Also keeps an eye on STDOUT, and exits as soon as we see a POLLHUP on that, i.e. when it is closed. */ + r = sd_event_add_io(e, NULL, STDOUT_FILENO, EPOLLHUP|EPOLLERR, NULL, INT_TO_PTR(-ECANCELED)); + if (r < 0) + return log_error_errno(r, "Failed to add io event source for stdout: %m"); + + if (arg_lines != 0 || arg_since_set) { + r = sd_event_add_defer(e, NULL, on_first_event, c); + if (r < 0) + return log_error_errno(r, "Failed to add defer event source: %m"); + } + + *ret = TAKE_PTR(e); + return 0; +} + static int run(int argc, char *argv[]) { bool need_seek = false, since_seeked = false, use_cursor = false, after_cursor = false; _cleanup_(loop_device_unrefp) LoopDevice *loop_device = NULL; @@ -2727,25 +2757,15 @@ static int run(int argc, char *argv[]) { }; if (arg_follow) { - if (arg_lines != 0 || arg_since_set) { - r = show(&c); - if (r < 0) - return r; + _cleanup_(sd_event_unrefp) sd_event *e = NULL; - fflush(stdout); - } + assert(poll_fd >= 0); - for (;;) { - r = wait_for_change(j, poll_fd); - if (r < 0) - return r; + r = setup_event(&c, poll_fd, &e); + if (r < 0) + return r; - r = show(&c); - if (r < 0) - return r; - - fflush(stdout); - } + return sd_event_loop(e); } r = show(&c); From 24d633e4385d7cd5b8197ecc09876044d7c280e8 Mon Sep 17 00:00:00 2001 From: Yu Watanabe Date: Thu, 4 May 2023 09:36:27 +0900 Subject: [PATCH 08/11] journalctl: also update cursor with --follow Fixes #26746. --- src/journal/journalctl.c | 32 +++++++++++++++++++++++++++++++- 1 file changed, 31 insertions(+), 1 deletion(-) diff --git a/src/journal/journalctl.c b/src/journal/journalctl.c index 9bfeb121ee..8944c95e64 100644 --- a/src/journal/journalctl.c +++ b/src/journal/journalctl.c @@ -65,6 +65,7 @@ #include "rlimit-util.h" #include "set.h" #include "sigbus.h" +#include "signal-util.h" #include "static-destruct.h" #include "stdio-util.h" #include "string-table.h" @@ -2303,6 +2304,14 @@ static int on_first_event(sd_event_source *s, void *userdata) { return show_and_fflush(userdata, s); } +static int on_signal(sd_event_source *s, const struct signalfd_siginfo *si, void *userdata) { + assert(s); + assert(si); + assert(IN_SET(si->ssi_signo, SIGTERM, SIGINT)); + + return sd_event_exit(sd_event_source_get_event(s), si->ssi_signo); +} + static int setup_event(Context *c, int fd, sd_event **ret) { _cleanup_(sd_event_unrefp) sd_event *e = NULL; int r; @@ -2316,6 +2325,9 @@ static int setup_event(Context *c, int fd, sd_event **ret) { if (r < 0) return log_error_errno(r, "Failed to allocate sd_event object: %m"); + (void) sd_event_add_signal(e, NULL, SIGTERM | SD_EVENT_SIGNAL_PROCMASK, on_signal, NULL); + (void) sd_event_add_signal(e, NULL, SIGINT | SD_EVENT_SIGNAL_PROCMASK, on_signal, NULL); + r = sd_event_add_io(e, NULL, fd, EPOLLIN, &on_journal_event, c); if (r < 0) return log_error_errno(r, "Failed to add io event source for journal: %m"); @@ -2758,6 +2770,7 @@ static int run(int argc, char *argv[]) { if (arg_follow) { _cleanup_(sd_event_unrefp) sd_event *e = NULL; + int sig; assert(poll_fd >= 0); @@ -2765,7 +2778,24 @@ static int run(int argc, char *argv[]) { if (r < 0) return r; - return sd_event_loop(e); + r = sd_event_loop(e); + if (r < 0) + return r; + sig = r; + + /* unref signal event sources. */ + e = sd_event_unref(e); + + r = update_cursor(j); + if (r < 0) + return r; + + /* re-send the original signal. */ + assert(SIGNAL_VALID(sig)); + if (raise(sig) < 0) + log_error("Failed to raise the original signal SIG%s, ignoring: %m", signal_to_string(sig)); + + return 0; } r = show(&c); From fb35feae979e0a124ab1c3dcb337f47c186373f3 Mon Sep 17 00:00:00 2001 From: Yu Watanabe Date: Sat, 27 May 2023 06:12:09 +0900 Subject: [PATCH 09/11] test: add testcase for 'journalctl --follow --cursor-file=' Also, add a FIXME comment to illustrate the issue uncovered after by 7a4ee861615101ddd2f95056cf30e69e41da86ce. --- test/units/testsuite-04.sh | 20 ++++++++++++++++++++ 1 file changed, 20 insertions(+) diff --git a/test/units/testsuite-04.sh b/test/units/testsuite-04.sh index 6ed41f24ea..5280cf8cb1 100755 --- a/test/units/testsuite-04.sh +++ b/test/units/testsuite-04.sh @@ -161,6 +161,26 @@ journalctl --follow --file=/var/log/journal/*/* | head -n1 | grep . journalctl --follow --merge | head -n1 | grep . set -o pipefail +# https://github.com/systemd/systemd/issues/26746 +rm -f /tmp/issue-26746-log /tmp/issue-26746-cursor +ID=$(systemd-id128 new) + +# FIXME: +# After the commit 7a4ee861615101ddd2f95056cf30e69e41da86ce, +# journalctl --follow does not work if no matching entry stored in the journal. +# To workaround the issue, we need to add an entry before calling journalctl below. +systemd-cat -t "$ID" /bin/sh -c 'echo aaa' + +journalctl -t "$ID" --follow --cursor-file=/tmp/issue-26746-cursor | tee /tmp/issue-26746-log & +systemd-cat -t "$ID" /bin/sh -c 'echo hogehoge' +# shellcheck disable=SC2016 +timeout 10 bash -c 'while ! [[ -f /tmp/issue-26746-log && "$(cat /tmp/issue-26746-log)" =~ hogehoge ]]; do sleep .5; done' +pkill -TERM journalctl +test -f /tmp/issue-26746-cursor +CURSOR_FROM_FILE=$(cat /tmp/issue-26746-cursor) +CURSOR_FROM_JOURNAL=$(journalctl -t "$ID" --output export MESSAGE=hogehoge | sed -n -e '/__CURSOR=/ { s/__CURSOR=//; p }') +test "$CURSOR_FROM_FILE" = "$CURSOR_FROM_JOURNAL" + add_logs_filtering_override() { local unit="${1:?}" local override_name="${2:?}" From b78f9481bc03455eafd9239c33fc2f124779760c Mon Sep 17 00:00:00 2001 From: Yu Watanabe Date: Sun, 28 May 2023 14:20:27 +0900 Subject: [PATCH 10/11] sd-journal: introduce sd_journal_step_one() After the commit 7a4ee861615101ddd2f95056cf30e69e41da86ce, sd_journal_next() following sd_journal_seek_tail() takes no-op, and we need to call sd_journal_previous(). This may be useful in some cases, e.g. to fix the issue explained in the previous commit. --- man/rules/meson.build | 3 ++- man/sd_journal_next.xml | 17 +++++++++++++++++ src/libsystemd/libsystemd.sym | 1 + src/libsystemd/sd-journal/sd-journal.c | 10 ++++++++++ src/systemd/sd-journal.h | 1 + 5 files changed, 31 insertions(+), 1 deletion(-) diff --git a/man/rules/meson.build b/man/rules/meson.build index d496ebc747..4658ef99f0 100644 --- a/man/rules/meson.build +++ b/man/rules/meson.build @@ -742,7 +742,8 @@ manpages = [ 'SD_JOURNAL_FOREACH_BACKWARDS', 'sd_journal_next_skip', 'sd_journal_previous', - 'sd_journal_previous_skip'], + 'sd_journal_previous_skip', + 'sd_journal_step_one'], ''], ['sd_journal_open', '3', diff --git a/man/sd_journal_next.xml b/man/sd_journal_next.xml index 628abb296c..cc267fa1bd 100644 --- a/man/sd_journal_next.xml +++ b/man/sd_journal_next.xml @@ -18,6 +18,7 @@ sd_journal_next sd_journal_previous + sd_journal_step_one sd_journal_next_skip sd_journal_previous_skip SD_JOURNAL_FOREACH @@ -39,6 +40,12 @@ sd_journal *j + + int sd_journal_step_one + sd_journal *j + int advanced + + int sd_journal_next_skip sd_journal *j @@ -77,6 +84,16 @@ Similarly, sd_journal_previous() sets the read pointer back one entry. + sd_journal_step_one() also moves the read pointer. If the current location + is the head of the journal, e.g. when this is called following + sd_journal_seek_head(), then this is equivalent to + sd_journal_next(), and the argument advanced will be ignored. + Similary, if the current location is the tail of the journal, e.g. when this is called following + sd_journal_seek_tail(), then this is equivalent to + sd_journal_previous(), and advanced will be ignored. Otherwise, + this is equivalent to sd_journal_next() when advanced is + non-zero, and sd_journal_previous() when advanced is zero. + sd_journal_next_skip() and sd_journal_previous_skip() advance/set back the read pointer by multiple entries at once, as specified in the skip parameter. The skip diff --git a/src/libsystemd/libsystemd.sym b/src/libsystemd/libsystemd.sym index 35352dc832..936a3577f5 100644 --- a/src/libsystemd/libsystemd.sym +++ b/src/libsystemd/libsystemd.sym @@ -825,4 +825,5 @@ global: sd_event_trim_memory; sd_pid_notify_barrier; sd_event_source_leave_ratelimit; + sd_journal_step_one; } LIBSYSTEMD_253; diff --git a/src/libsystemd/sd-journal/sd-journal.c b/src/libsystemd/sd-journal/sd-journal.c index 47532e2cbc..957817bfab 100644 --- a/src/libsystemd/sd-journal/sd-journal.c +++ b/src/libsystemd/sd-journal/sd-journal.c @@ -979,6 +979,16 @@ _public_ int sd_journal_previous(sd_journal *j) { return real_journal_next(j, DIRECTION_UP); } +_public_ int sd_journal_step_one(sd_journal *j, int advanced) { + assert_return(j, -EINVAL); + + if (j->current_location.type == LOCATION_HEAD) + return sd_journal_next(j); + if (j->current_location.type == LOCATION_TAIL) + return sd_journal_previous(j); + return real_journal_next(j, advanced ? DIRECTION_DOWN : DIRECTION_UP); +} + static int real_journal_next_skip(sd_journal *j, direction_t direction, uint64_t skip) { int c = 0, r; diff --git a/src/systemd/sd-journal.h b/src/systemd/sd-journal.h index 24e67663b9..4af540400d 100644 --- a/src/systemd/sd-journal.h +++ b/src/systemd/sd-journal.h @@ -93,6 +93,7 @@ void sd_journal_close(sd_journal *j); int sd_journal_previous(sd_journal *j); int sd_journal_next(sd_journal *j); +int sd_journal_step_one(sd_journal *j, int advanced); int sd_journal_previous_skip(sd_journal *j, uint64_t skip); int sd_journal_next_skip(sd_journal *j, uint64_t skip); From 80ec3db5c7a4cfef237d4a1a3d33097bd4b50ec4 Mon Sep 17 00:00:00 2001 From: Yu Watanabe Date: Sun, 28 May 2023 14:28:32 +0900 Subject: [PATCH 11/11] journalctl: fix --follow with non-matching filter When there is no matching entry stored in journal, then initial call of `sd_journal_previous()` following `sd_journal_seek_tail()` returns zero, and does not move the read pointer. In the main loop, on every journal event, we call `sd_journal_next()`, even though the current location is tail, and it takes no effect. In such a case, we need to call `sd_journal_previous()` instead of `sd_journal_next()`. --- src/journal/journalctl.c | 5 +---- test/units/testsuite-04.sh | 7 ------- 2 files changed, 1 insertion(+), 11 deletions(-) diff --git a/src/journal/journalctl.c b/src/journal/journalctl.c index 8944c95e64..4f9c1f4780 100644 --- a/src/journal/journalctl.c +++ b/src/journal/journalctl.c @@ -2146,10 +2146,7 @@ static int show(Context *c) { size_t highlight[2] = {}; if (c->need_seek) { - if (!arg_reverse) - r = sd_journal_next(j); - else - r = sd_journal_previous(j); + r = sd_journal_step_one(j, !arg_reverse); if (r < 0) return log_error_errno(r, "Failed to iterate through journal: %m"); if (r == 0) diff --git a/test/units/testsuite-04.sh b/test/units/testsuite-04.sh index 5280cf8cb1..4af619941b 100755 --- a/test/units/testsuite-04.sh +++ b/test/units/testsuite-04.sh @@ -164,13 +164,6 @@ set -o pipefail # https://github.com/systemd/systemd/issues/26746 rm -f /tmp/issue-26746-log /tmp/issue-26746-cursor ID=$(systemd-id128 new) - -# FIXME: -# After the commit 7a4ee861615101ddd2f95056cf30e69e41da86ce, -# journalctl --follow does not work if no matching entry stored in the journal. -# To workaround the issue, we need to add an entry before calling journalctl below. -systemd-cat -t "$ID" /bin/sh -c 'echo aaa' - journalctl -t "$ID" --follow --cursor-file=/tmp/issue-26746-cursor | tee /tmp/issue-26746-log & systemd-cat -t "$ID" /bin/sh -c 'echo hogehoge' # shellcheck disable=SC2016