diff --git a/src/journal/journalctl.c b/src/journal/journalctl.c index 5d19341568..9b2eb8fa8e 100644 --- a/src/journal/journalctl.c +++ b/src/journal/journalctl.c @@ -175,12 +175,6 @@ static enum { ACTION_LIST_FIELD_NAMES, } arg_action = ACTION_SHOW; -typedef struct BootId { - sd_id128_t id; - usec_t first_usec; - usec_t last_usec; -} BootId; - static int add_matches_for_device(sd_journal *j, const char *devpath) { _cleanup_(sd_device_unrefp) sd_device *device = NULL; sd_device *d = NULL; @@ -1225,207 +1219,6 @@ static int add_matches(sd_journal *j, char **args) { return 0; } -static int discover_next_boot( - sd_journal *j, - sd_id128_t previous_boot_id, - bool advance_older, - BootId *ret) { - - BootId boot; - int r; - - assert(j); - assert(ret); - - /* We expect the journal to be on the last position of a boot - * (in relation to the direction we are going), so that the next - * invocation of sd_journal_next/previous will be from a different - * boot. We then collect any information we desire and then jump - * to the last location of the new boot by using a _BOOT_ID match - * coming from the other journal direction. */ - - /* Make sure we aren't restricted by any _BOOT_ID matches, so that - * we can actually advance to a *different* boot. */ - sd_journal_flush_matches(j); - - do { - if (advance_older) - r = sd_journal_previous(j); - else - r = sd_journal_next(j); - if (r < 0) - return r; - else if (r == 0) { - *ret = (BootId) {}; - return 0; /* End of journal, yay. */ - } - - r = sd_journal_get_monotonic_usec(j, NULL, &boot.id); - if (r < 0) - return r; - - /* We iterate through this in a loop, until the boot ID differs from the previous one. Note that - * normally, this will only require a single iteration, as we moved to the last entry of the previous - * boot entry already. However, it might happen that the per-journal-field entry arrays are less - * complete than the main entry array, and hence might reference an entry that's not actually the last - * one of the boot ID as last one. Let's hence use the per-field array is initial seek position to - * speed things up, but let's not trust that it is complete, and hence, manually advance as - * necessary. */ - - } while (sd_id128_equal(boot.id, previous_boot_id)); - - r = sd_journal_get_realtime_usec(j, &boot.first_usec); - if (r < 0) - return r; - - /* Now seek to the last occurrence of this boot ID. */ - r = add_match_boot_id(j, boot.id); - if (r < 0) - return r; - - if (advance_older) - r = sd_journal_seek_head(j); - else - r = sd_journal_seek_tail(j); - if (r < 0) - return r; - - if (advance_older) - r = sd_journal_next(j); - else - r = sd_journal_previous(j); - if (r < 0) - return r; - else if (r == 0) - return log_debug_errno(SYNTHETIC_ERRNO(ENODATA), - "Whoopsie! We found a boot ID but can't read its last entry."); /* This shouldn't happen. We just came from this very boot ID. */ - - r = sd_journal_get_realtime_usec(j, &boot.last_usec); - if (r < 0) - return r; - - sd_journal_flush_matches(j); - *ret = boot; - return 1; -} - -static int find_boot_by_id(sd_journal *j) { - int r; - - assert(j); - - sd_journal_flush_matches(j); - - r = add_match_boot_id(j, arg_boot_id); - if (r < 0) - return r; - - r = sd_journal_seek_head(j); /* seek to oldest */ - if (r < 0) - return r; - - r = sd_journal_next(j); /* read the oldest entry */ - if (r < 0) - return r; - - /* At this point the read pointer is positioned at the oldest occurrence of the reference boot ID. - * After flushing the matches, one more invocation of _previous() will hence place us at the - * following entry, which must then have an older boot ID */ - - sd_journal_flush_matches(j); - return r > 0; -} - -static int find_boot_by_offset(sd_journal *j) { - bool advance_older, skip_once; - int r; - - /* Adjust for the asymmetry that offset 0 is the last (and current) boot, while 1 is considered the - * (chronological) first boot in the journal. */ - advance_older = skip_once = arg_boot_offset <= 0; - - if (advance_older) - r = sd_journal_seek_tail(j); /* seek to newest */ - else - r = sd_journal_seek_head(j); /* seek to oldest */ - if (r < 0) - return r; - - /* No sd_journal_next()/_previous() here. - * - * At this point the read pointer is positioned after the newest/before the oldest entry in the whole - * journal. The next invocation of _previous()/_next() will hence position us at the newest/oldest - * entry we have. */ - - int offset = arg_boot_offset; - sd_id128_t previous_boot_id = SD_ID128_NULL; - for (;;) { - BootId boot; - - r = discover_next_boot(j, previous_boot_id, advance_older, &boot); - if (r <= 0) - return r; - - previous_boot_id = boot.id; - - if (!skip_once) - offset += advance_older ? 1 : -1; - skip_once = false; - - if (offset == 0) { - arg_boot_id = boot.id; - return true; - } - } -} - -static int get_boots(sd_journal *j, BootId **ret_boots, size_t *ret_n_boots) { - _cleanup_free_ BootId *boots = NULL; - size_t n_boots = 0; - int r; - - assert(j); - assert(ret_boots); - assert(ret_n_boots); - - r = sd_journal_seek_head(j); /* seek to oldest */ - if (r < 0) - return r; - - /* No sd_journal_next()/_previous() here. - * - * At this point the read pointer is positioned before the oldest entry in the whole journal. The - * next invocation of _next() will hence position us at the oldest entry we have. */ - - sd_id128_t previous_boot_id = SD_ID128_NULL; - for (;;) { - BootId boot; - - r = discover_next_boot(j, previous_boot_id, /* advance_older = */ false, &boot); - if (r < 0) - return r; - if (r == 0) - break; - - previous_boot_id = boot.id; - - FOREACH_ARRAY(i, boots, n_boots) - if (sd_id128_equal(i->id, boot.id)) - /* The boot id is already stored, something wrong with the journal files. - * Exiting as otherwise this problem would cause an infinite loop. */ - break; - - if (!GREEDY_REALLOC(boots, n_boots + 1)) - return -ENOMEM; - - boots[n_boots++] = boot; - } - - *ret_boots = TAKE_PTR(boots); - *ret_n_boots = n_boots; - return n_boots > 0; -} - static int list_boots(sd_journal *j) { _cleanup_(table_unrefp) Table *table = NULL; _cleanup_free_ BootId *boots = NULL; @@ -1434,7 +1227,7 @@ static int list_boots(sd_journal *j) { assert(j); - r = get_boots(j, &boots, &n_boots); + r = journal_get_boots(j, &boots, &n_boots); if (r < 0) return log_error_errno(r, "Failed to determine boots: %m"); if (r == 0) @@ -1488,7 +1281,7 @@ static int add_boot(sd_journal *j) { return add_match_this_boot(j, arg_machine); if (sd_id128_is_null(arg_boot_id)) { - r = find_boot_by_offset(j); + r = journal_find_boot_by_offset(j, arg_boot_offset, &arg_boot_id); if (r < 0) return log_error_errno(r, "Failed to find journal entry from the specified boot offset (%+i): %m", arg_boot_offset); @@ -1497,7 +1290,7 @@ static int add_boot(sd_journal *j) { "No journal boot entry found from the specified boot offset (%+i).", arg_boot_offset); } else { - r = find_boot_by_id(j); + r = journal_find_boot_by_id(j, arg_boot_id); if (r < 0) return log_error_errno(r, "Failed to find journal entry from the specified boot ID (%s): %m", SD_ID128_TO_STRING(arg_boot_id)); diff --git a/src/journal/test-journal-interleaving.c b/src/journal/test-journal-interleaving.c index 21c5bdddae..dfd4497cfd 100644 --- a/src/journal/test-journal-interleaving.c +++ b/src/journal/test-journal-interleaving.c @@ -11,6 +11,7 @@ #include "io-util.h" #include "journal-vacuum.h" #include "log.h" +#include "logs-show.h" #include "managed-journal-file.h" #include "parse-util.h" #include "rm-rf.h" @@ -19,6 +20,7 @@ /* This program tests skipping around in a multi-file journal. */ static bool arg_keep = false; +static dual_timestamp previous_ts = {}; _noreturn_ static void log_assert_errno(const char *text, int error, const char *file, unsigned line, const char *func) { log_internal(LOG_CRIT, error, file, line, func, @@ -33,26 +35,34 @@ _noreturn_ static void log_assert_errno(const char *text, int error, const char log_assert_errno(#expr, -_r_, PROJECT_FILE, __LINE__, __func__); \ } while (false) -static ManagedJournalFile *test_open(const char *name) { +static ManagedJournalFile *test_open_internal(const char *name, JournalFileFlags flags) { _cleanup_(mmap_cache_unrefp) MMapCache *m = NULL; ManagedJournalFile *f; m = mmap_cache_new(); assert_se(m != NULL); - assert_ret(managed_journal_file_open(-1, name, O_RDWR|O_CREAT, JOURNAL_COMPRESS, 0644, UINT64_MAX, NULL, m, NULL, NULL, &f)); + assert_ret(managed_journal_file_open(-1, name, O_RDWR|O_CREAT, flags, 0644, UINT64_MAX, NULL, m, NULL, NULL, &f)); return f; } +static ManagedJournalFile *test_open(const char *name) { + return test_open_internal(name, JOURNAL_COMPRESS); +} + +static ManagedJournalFile *test_open_strict(const char *name) { + return test_open_internal(name, JOURNAL_COMPRESS | JOURNAL_STRICT_ORDER); +} + static void test_close(ManagedJournalFile *f) { (void) managed_journal_file_close(f); } -static void append_number(ManagedJournalFile *f, int n, uint64_t *seqnum) { - char *p; +static void append_number(ManagedJournalFile *f, int n, const sd_id128_t *boot_id, uint64_t *seqnum) { + _cleanup_free_ char *p = NULL, *q = NULL; dual_timestamp ts; - static dual_timestamp previous_ts = {}; - struct iovec iovec[1]; + struct iovec iovec[2]; + size_t n_iov = 0; dual_timestamp_get(&ts); @@ -65,20 +75,43 @@ static void append_number(ManagedJournalFile *f, int n, uint64_t *seqnum) { previous_ts = ts; assert_se(asprintf(&p, "NUMBER=%d", n) >= 0); - iovec[0] = IOVEC_MAKE_STRING(p); - assert_ret(journal_file_append_entry(f->file, &ts, NULL, iovec, 1, seqnum, NULL, NULL, NULL)); - free(p); + iovec[n_iov++] = IOVEC_MAKE_STRING(p); + + if (boot_id) { + assert_se(q = strjoin("_BOOT_ID=", SD_ID128_TO_STRING(*boot_id))); + iovec[n_iov++] = IOVEC_MAKE_STRING(q); + } + + assert_ret(journal_file_append_entry(f->file, &ts, boot_id, iovec, n_iov, seqnum, NULL, NULL, NULL)); +} + +static void append_unreferenced_data(ManagedJournalFile *f, const sd_id128_t *boot_id) { + _cleanup_free_ char *q = NULL; + dual_timestamp ts; + struct iovec iovec; + + assert(boot_id); + + ts.monotonic = usec_sub_unsigned(previous_ts.monotonic, 10); + ts.realtime = usec_sub_unsigned(previous_ts.realtime, 10); + + assert_se(q = strjoin("_BOOT_ID=", SD_ID128_TO_STRING(*boot_id))); + iovec = IOVEC_MAKE_STRING(q); + + assert_se(journal_file_append_entry(f->file, &ts, boot_id, &iovec, 1, NULL, NULL, NULL, NULL) == -EREMCHG); } static void test_check_number(sd_journal *j, int n) { + sd_id128_t boot_id; const void *d; _cleanup_free_ char *k = NULL; size_t l; int x; + assert_se(sd_journal_get_monotonic_usec(j, NULL, &boot_id) >= 0); assert_ret(sd_journal_get_data(j, "NUMBER", &d, &l)); assert_se(k = strndup(d, l)); - printf("%s (expected=%i)\n", k, n); + printf("%s %s (expected=%i)\n", SD_ID128_TO_STRING(boot_id), k, n); assert_se(safe_atoi(k + STRLEN("NUMBER="), &x) >= 0); assert_se(n == x); @@ -114,19 +147,26 @@ static void test_check_numbers_up(sd_journal *j, int count) { static void setup_sequential(void) { ManagedJournalFile *f1, *f2, *f3; + sd_id128_t id; f1 = test_open("one.journal"); f2 = test_open("two.journal"); f3 = test_open("three.journal"); - append_number(f1, 1, NULL); - append_number(f1, 2, NULL); - append_number(f1, 3, NULL); - append_number(f2, 4, NULL); - append_number(f2, 5, NULL); - append_number(f2, 6, NULL); - append_number(f3, 7, NULL); - append_number(f3, 8, NULL); - append_number(f3, 9, NULL); + assert_se(sd_id128_randomize(&id) >= 0); + log_info("boot_id: %s", SD_ID128_TO_STRING(id)); + append_number(f1, 1, &id, NULL); + append_number(f1, 2, &id, NULL); + append_number(f1, 3, &id, NULL); + append_number(f2, 4, &id, NULL); + assert_se(sd_id128_randomize(&id) >= 0); + log_info("boot_id: %s", SD_ID128_TO_STRING(id)); + append_number(f2, 5, &id, NULL); + append_number(f2, 6, &id, NULL); + append_number(f3, 7, &id, NULL); + append_number(f3, 8, &id, NULL); + assert_se(sd_id128_randomize(&id) >= 0); + log_info("boot_id: %s", SD_ID128_TO_STRING(id)); + append_number(f3, 9, &id, NULL); test_close(f1); test_close(f2); test_close(f3); @@ -134,19 +174,53 @@ static void setup_sequential(void) { static void setup_interleaved(void) { ManagedJournalFile *f1, *f2, *f3; + sd_id128_t id; f1 = test_open("one.journal"); f2 = test_open("two.journal"); f3 = test_open("three.journal"); - append_number(f1, 1, NULL); - append_number(f2, 2, NULL); - append_number(f3, 3, NULL); - append_number(f1, 4, NULL); - append_number(f2, 5, NULL); - append_number(f3, 6, NULL); - append_number(f1, 7, NULL); - append_number(f2, 8, NULL); - append_number(f3, 9, NULL); + assert_se(sd_id128_randomize(&id) >= 0); + log_info("boot_id: %s", SD_ID128_TO_STRING(id)); + append_number(f1, 1, &id, NULL); + append_number(f2, 2, &id, NULL); + append_number(f3, 3, &id, NULL); + append_number(f1, 4, &id, NULL); + append_number(f2, 5, &id, NULL); + append_number(f3, 6, &id, NULL); + append_number(f1, 7, &id, NULL); + append_number(f2, 8, &id, NULL); + append_number(f3, 9, &id, NULL); + test_close(f1); + test_close(f2); + test_close(f3); +} + +static void setup_unreferenced_data(void) { + ManagedJournalFile *f1, *f2, *f3; + sd_id128_t id; + + /* For issue #29275. */ + + f1 = test_open_strict("one.journal"); + f2 = test_open_strict("two.journal"); + f3 = test_open_strict("three.journal"); + assert_se(sd_id128_randomize(&id) >= 0); + log_info("boot_id: %s", SD_ID128_TO_STRING(id)); + append_number(f1, 1, &id, NULL); + append_number(f1, 2, &id, NULL); + append_number(f1, 3, &id, NULL); + assert_se(sd_id128_randomize(&id) >= 0); + log_info("boot_id: %s", SD_ID128_TO_STRING(id)); + append_unreferenced_data(f1, &id); + append_number(f2, 4, &id, NULL); + append_number(f2, 5, &id, NULL); + append_number(f2, 6, &id, NULL); + assert_se(sd_id128_randomize(&id) >= 0); + log_info("boot_id: %s", SD_ID128_TO_STRING(id)); + append_unreferenced_data(f2, &id); + append_number(f3, 7, &id, NULL); + append_number(f3, 8, &id, NULL); + append_number(f3, 9, &id, NULL); test_close(f1); test_close(f2); test_close(f3); @@ -320,6 +394,58 @@ TEST(skip) { test_skip_one(setup_interleaved); } +static void test_boot_id_one(void (*setup)(void), size_t n_boots_expected) { + char t[] = "/var/tmp/journal-boot-id-XXXXXX"; + sd_journal *j; + _cleanup_free_ BootId *boots = NULL; + size_t n_boots; + + mkdtemp_chdir_chattr(t); + + setup(); + + assert_ret(sd_journal_open_directory(&j, t, 0)); + assert_se(journal_get_boots(j, &boots, &n_boots) >= 0); + assert_se(boots); + assert_se(n_boots == n_boots_expected); + sd_journal_close(j); + + FOREACH_ARRAY(b, boots, n_boots) { + assert_ret(sd_journal_open_directory(&j, t, 0)); + assert_se(journal_find_boot_by_id(j, b->id) == 1); + sd_journal_close(j); + } + + for (int i = - (int) n_boots + 1; i <= (int) n_boots; i++) { + sd_id128_t id; + + assert_ret(sd_journal_open_directory(&j, t, 0)); + assert_se(journal_find_boot_by_offset(j, i, &id) == 1); + if (i <= 0) + assert_se(sd_id128_equal(id, boots[n_boots + i - 1].id)); + else + assert_se(sd_id128_equal(id, boots[i - 1].id)); + sd_journal_close(j); + } + + log_info("Done..."); + + if (arg_keep) + log_info("Not removing %s", t); + else { + journal_directory_vacuum(".", 3000000, 0, 0, NULL, true); + + assert_se(rm_rf(t, REMOVE_ROOT|REMOVE_PHYSICAL) >= 0); + } + + puts("------------------------------------------------------------"); +} + +TEST(boot_id) { + test_boot_id_one(setup_sequential, 3); + test_boot_id_one(setup_unreferenced_data, 3); +} + static void test_sequence_numbers_one(void) { _cleanup_(mmap_cache_unrefp) MMapCache *m = NULL; char t[] = "/var/tmp/journal-seq-XXXXXX"; @@ -335,10 +461,10 @@ static void test_sequence_numbers_one(void) { assert_se(managed_journal_file_open(-1, "one.journal", O_RDWR|O_CREAT, JOURNAL_COMPRESS, 0644, UINT64_MAX, NULL, m, NULL, NULL, &one) == 0); - append_number(one, 1, &seqnum); + append_number(one, 1, NULL, &seqnum); printf("seqnum=%"PRIu64"\n", seqnum); assert_se(seqnum == 1); - append_number(one, 2, &seqnum); + append_number(one, 2, NULL, &seqnum); printf("seqnum=%"PRIu64"\n", seqnum); assert_se(seqnum == 2); @@ -354,24 +480,27 @@ static void test_sequence_numbers_one(void) { assert_se(two->file->header->state == STATE_ONLINE); assert_se(!sd_id128_equal(two->file->header->file_id, one->file->header->file_id)); - assert_se(sd_id128_equal(one->file->header->machine_id, one->file->header->machine_id)); - assert_se(sd_id128_equal(one->file->header->tail_entry_boot_id, one->file->header->tail_entry_boot_id)); - assert_se(sd_id128_equal(one->file->header->seqnum_id, one->file->header->seqnum_id)); + assert_se(sd_id128_equal(two->file->header->machine_id, one->file->header->machine_id)); + assert_se(sd_id128_is_null(two->file->header->tail_entry_boot_id)); /* Not written yet. */ + assert_se(sd_id128_equal(two->file->header->seqnum_id, one->file->header->seqnum_id)); - append_number(two, 3, &seqnum); + append_number(two, 3, NULL, &seqnum); printf("seqnum=%"PRIu64"\n", seqnum); assert_se(seqnum == 3); - append_number(two, 4, &seqnum); + append_number(two, 4, NULL, &seqnum); printf("seqnum=%"PRIu64"\n", seqnum); assert_se(seqnum == 4); + /* Verify tail_entry_boot_id. */ + assert_se(sd_id128_equal(two->file->header->tail_entry_boot_id, one->file->header->tail_entry_boot_id)); + test_close(two); - append_number(one, 5, &seqnum); + append_number(one, 5, NULL, &seqnum); printf("seqnum=%"PRIu64"\n", seqnum); assert_se(seqnum == 5); - append_number(one, 6, &seqnum); + append_number(one, 6, NULL, &seqnum); printf("seqnum=%"PRIu64"\n", seqnum); assert_se(seqnum == 6); @@ -388,7 +517,7 @@ static void test_sequence_numbers_one(void) { assert_se(sd_id128_equal(two->file->header->seqnum_id, seqnum_id)); - append_number(two, 7, &seqnum); + append_number(two, 7, NULL, &seqnum); printf("seqnum=%"PRIu64"\n", seqnum); assert_se(seqnum == 5); diff --git a/src/libsystemd/sd-journal/journal-file.c b/src/libsystemd/sd-journal/journal-file.c index ef860d228b..5d3f85e4cc 100644 --- a/src/libsystemd/sd-journal/journal-file.c +++ b/src/libsystemd/sd-journal/journal-file.c @@ -623,10 +623,36 @@ static int journal_file_verify_header(JournalFile *f) { return -ENODATA; } - if (JOURNAL_HEADER_CONTAINS(f->header, tail_entry_offset)) - if (!offset_is_valid(le64toh(f->header->tail_entry_offset), header_size, tail_object_offset)) + if (JOURNAL_HEADER_CONTAINS(f->header, tail_entry_offset)) { + uint64_t offset = le64toh(f->header->tail_entry_offset); + + if (!offset_is_valid(offset, header_size, tail_object_offset)) return -ENODATA; + if (offset > 0) { + /* When there is an entry object, then these fields must be filled. */ + if (sd_id128_is_null(f->header->tail_entry_boot_id)) + return -ENODATA; + if (!VALID_REALTIME(le64toh(f->header->head_entry_realtime))) + return -ENODATA; + if (!VALID_REALTIME(le64toh(f->header->tail_entry_realtime))) + return -ENODATA; + if (!VALID_MONOTONIC(le64toh(f->header->tail_entry_realtime))) + return -ENODATA; + } else { + /* Otherwise, the fields must be zero. */ + if (JOURNAL_HEADER_TAIL_ENTRY_BOOT_ID(f->header) && + !sd_id128_is_null(f->header->tail_entry_boot_id)) + return -ENODATA; + if (f->header->head_entry_realtime != 0) + return -ENODATA; + if (f->header->tail_entry_realtime != 0) + return -ENODATA; + if (f->header->tail_entry_realtime != 0) + return -ENODATA; + } + } + /* Verify number of objects */ uint64_t n_objects = le64toh(f->header->n_objects); if (n_objects > arena_size / sizeof(ObjectHeader)) @@ -2272,6 +2298,8 @@ static int journal_file_append_entry_internal( assert(f); assert(f->header); assert(ts); + assert(boot_id); + assert(!sd_id128_is_null(*boot_id)); assert(items || n_items == 0); if (f->strict_order) { @@ -2292,7 +2320,7 @@ static int journal_file_append_entry_internal( "timestamp %" PRIu64 ", refusing entry.", ts->realtime, le64toh(f->header->tail_entry_realtime)); - if ((!boot_id || sd_id128_equal(*boot_id, f->header->tail_entry_boot_id)) && + if (sd_id128_equal(*boot_id, f->header->tail_entry_boot_id) && ts->monotonic < le64toh(f->header->tail_entry_monotonic)) return log_debug_errno( SYNTHETIC_ERRNO(ENOTNAM), @@ -2332,9 +2360,7 @@ static int journal_file_append_entry_internal( o->entry.realtime = htole64(ts->realtime); o->entry.monotonic = htole64(ts->monotonic); o->entry.xor_hash = htole64(xor_hash); - if (boot_id) - f->header->tail_entry_boot_id = *boot_id; - o->entry.boot_id = f->header->tail_entry_boot_id; + o->entry.boot_id = f->header->tail_entry_boot_id = *boot_id; for (size_t i = 0; i < n_items; i++) write_entry_item(f, o, i, &items[i]); @@ -2503,7 +2529,10 @@ int journal_file_append_entry( ts = &_ts; } - if (!boot_id) { + if (boot_id) { + if (sd_id128_is_null(*boot_id)) + return log_debug_errno(SYNTHETIC_ERRNO(EBADMSG), "Empty boot ID, refusing entry."); + } else { r = sd_id128_get_boot(&_boot_id); if (r < 0) return r; @@ -3322,10 +3351,8 @@ int journal_file_move_to_entry_by_monotonic( assert(f); r = find_data_object_by_boot_id(f, boot_id, &o, NULL); - if (r < 0) + if (r <= 0) return r; - if (r == 0) - return -ENOENT; return generic_array_bisect_plus_one( f, @@ -3517,10 +3544,8 @@ int journal_file_move_to_entry_by_monotonic_for_data( /* First, seek by time */ r = find_data_object_by_boot_id(f, boot_id, &o, &b); - if (r < 0) + if (r <= 0) return r; - if (r == 0) - return -ENOENT; r = generic_array_bisect_plus_one(f, le64toh(o->data.entry_offset), diff --git a/src/libsystemd/sd-journal/sd-journal.c b/src/libsystemd/sd-journal/sd-journal.c index 5e49311327..1b9dcbdecb 100644 --- a/src/libsystemd/sd-journal/sd-journal.c +++ b/src/libsystemd/sd-journal/sd-journal.c @@ -667,7 +667,7 @@ static int find_location_for_match( return journal_file_move_to_entry_by_seqnum_for_data(f, d, j->current_location.seqnum, direction, ret, offset); if (j->current_location.monotonic_set) { r = journal_file_move_to_entry_by_monotonic_for_data(f, d, j->current_location.boot_id, j->current_location.monotonic, direction, ret, offset); - if (r != -ENOENT) + if (r != 0) return r; /* The data object might have been invalidated. */ @@ -762,7 +762,7 @@ static int find_location_with_matches( return journal_file_move_to_entry_by_seqnum(f, j->current_location.seqnum, direction, ret, offset); if (j->current_location.monotonic_set) { r = journal_file_move_to_entry_by_monotonic(f, j->current_location.boot_id, j->current_location.monotonic, direction, ret, offset); - if (r != -ENOENT) + if (r != 0) return r; } if (j->current_location.realtime_set) @@ -2445,14 +2445,6 @@ static int journal_file_read_tail_timestamp(sd_journal *j, JournalFile *f) { mo = le64toh(f->header->tail_entry_monotonic); rt = le64toh(f->header->tail_entry_realtime); id = f->header->tail_entry_boot_id; - - /* Some superficial checking if what we read makes sense. Note that we only do this - * when reading the timestamps from the Header object, but not when reading them from - * the most recent entry object, because in that case journal_file_move_to_object() - * already validated them. */ - if (!VALID_MONOTONIC(mo) || !VALID_REALTIME(rt)) - return -ENODATA; - } else { /* Otherwise let's find the last entry manually (this possibly means traversing the * chain of entry arrays, till the end */ diff --git a/src/shared/logs-show.c b/src/shared/logs-show.c index abe11b817c..0130e747bf 100644 --- a/src/shared/logs-show.c +++ b/src/shared/logs-show.c @@ -1827,3 +1827,203 @@ int show_journal_by_unit( return show_journal(f, j, mode, n_columns, not_before, how_many, flags, ellipsized); } + +static int discover_next_boot( + sd_journal *j, + sd_id128_t previous_boot_id, + bool advance_older, + BootId *ret) { + + BootId boot; + int r; + + assert(j); + assert(ret); + + /* We expect the journal to be on the last position of a boot + * (in relation to the direction we are going), so that the next + * invocation of sd_journal_next/previous will be from a different + * boot. We then collect any information we desire and then jump + * to the last location of the new boot by using a _BOOT_ID match + * coming from the other journal direction. */ + + /* Make sure we aren't restricted by any _BOOT_ID matches, so that + * we can actually advance to a *different* boot. */ + sd_journal_flush_matches(j); + + do { + r = sd_journal_step_one(j, !advance_older); + if (r < 0) + return r; + if (r == 0) { + *ret = (BootId) {}; + return 0; /* End of journal, yay. */ + } + + r = sd_journal_get_monotonic_usec(j, NULL, &boot.id); + if (r < 0) + return r; + + /* We iterate through this in a loop, until the boot ID differs from the previous one. Note that + * normally, this will only require a single iteration, as we moved to the last entry of the previous + * boot entry already. However, it might happen that the per-journal-field entry arrays are less + * complete than the main entry array, and hence might reference an entry that's not actually the last + * one of the boot ID as last one. Let's hence use the per-field array is initial seek position to + * speed things up, but let's not trust that it is complete, and hence, manually advance as + * necessary. */ + + } while (sd_id128_equal(boot.id, previous_boot_id)); + + r = sd_journal_get_realtime_usec(j, &boot.first_usec); + if (r < 0) + return r; + + /* Now seek to the last occurrence of this boot ID. */ + r = add_match_boot_id(j, boot.id); + if (r < 0) + return r; + + if (advance_older) + r = sd_journal_seek_head(j); + else + r = sd_journal_seek_tail(j); + if (r < 0) + return r; + + r = sd_journal_step_one(j, advance_older); + if (r < 0) + return r; + if (r == 0) + return log_debug_errno(SYNTHETIC_ERRNO(ENODATA), + "Whoopsie! We found a boot ID but can't read its last entry."); /* This shouldn't happen. We just came from this very boot ID. */ + + r = sd_journal_get_realtime_usec(j, &boot.last_usec); + if (r < 0) + return r; + + sd_journal_flush_matches(j); + *ret = boot; + return 1; +} + +int journal_find_boot_by_id(sd_journal *j, sd_id128_t boot_id) { + int r; + + assert(j); + assert(!sd_id128_is_null(boot_id)); + + sd_journal_flush_matches(j); + + r = add_match_boot_id(j, boot_id); + if (r < 0) + return r; + + r = sd_journal_seek_head(j); /* seek to oldest */ + if (r < 0) + return r; + + r = sd_journal_next(j); /* read the oldest entry */ + if (r < 0) + return r; + + /* At this point the read pointer is positioned at the oldest occurrence of the reference boot ID. + * After flushing the matches, one more invocation of _previous() will hence place us at the + * following entry, which must then have an older boot ID */ + + sd_journal_flush_matches(j); + return r > 0; +} + +int journal_find_boot_by_offset(sd_journal *j, int offset, sd_id128_t *ret) { + bool advance_older; + int r; + + assert(j); + assert(ret); + + /* Adjust for the asymmetry that offset 0 is the last (and current) boot, while 1 is considered the + * (chronological) first boot in the journal. */ + advance_older = offset <= 0; + + if (advance_older) + r = sd_journal_seek_tail(j); /* seek to newest */ + else + r = sd_journal_seek_head(j); /* seek to oldest */ + if (r < 0) + return r; + + /* No sd_journal_next()/_previous() here. + * + * At this point the read pointer is positioned after the newest/before the oldest entry in the whole + * journal. The next invocation of _previous()/_next() will hence position us at the newest/oldest + * entry we have. */ + + sd_id128_t boot_id = SD_ID128_NULL; + for (int off = !advance_older; ; off += advance_older ? -1 : 1) { + BootId boot; + + r = discover_next_boot(j, boot_id, advance_older, &boot); + if (r < 0) + return r; + if (r == 0) { + *ret = SD_ID128_NULL; + return false; + } + + boot_id = boot.id; + log_debug("Found boot ID %s by offset %i", SD_ID128_TO_STRING(boot_id), off); + + if (off == offset) + break; + } + + *ret = boot_id; + return true; +} + +int journal_get_boots(sd_journal *j, BootId **ret_boots, size_t *ret_n_boots) { + _cleanup_free_ BootId *boots = NULL; + size_t n_boots = 0; + int r; + + assert(j); + assert(ret_boots); + assert(ret_n_boots); + + r = sd_journal_seek_head(j); /* seek to oldest */ + if (r < 0) + return r; + + /* No sd_journal_next()/_previous() here. + * + * At this point the read pointer is positioned before the oldest entry in the whole journal. The + * next invocation of _next() will hence position us at the oldest entry we have. */ + + sd_id128_t previous_boot_id = SD_ID128_NULL; + for (;;) { + BootId boot; + + r = discover_next_boot(j, previous_boot_id, /* advance_older = */ false, &boot); + if (r < 0) + return r; + if (r == 0) + break; + + previous_boot_id = boot.id; + + FOREACH_ARRAY(i, boots, n_boots) + if (sd_id128_equal(i->id, boot.id)) + /* The boot id is already stored, something wrong with the journal files. + * Exiting as otherwise this problem would cause an infinite loop. */ + break; + + if (!GREEDY_REALLOC(boots, n_boots + 1)) + return -ENOMEM; + + boots[n_boots++] = boot; + } + + *ret_boots = TAKE_PTR(boots); + *ret_n_boots = n_boots; + return n_boots > 0; +} diff --git a/src/shared/logs-show.h b/src/shared/logs-show.h index a7ecfeb774..3a8ce8b7c1 100644 --- a/src/shared/logs-show.h +++ b/src/shared/logs-show.h @@ -13,6 +13,12 @@ #include "output-mode.h" #include "time-util.h" +typedef struct BootId { + sd_id128_t id; + usec_t first_usec; + usec_t last_usec; +} BootId; + int show_journal_entry( FILE *f, sd_journal *j, @@ -65,3 +71,7 @@ void json_escape( const char* p, size_t l, OutputFlags flags); + +int journal_find_boot_by_id(sd_journal *j, sd_id128_t boot_id); +int journal_find_boot_by_offset(sd_journal *j, int offset, sd_id128_t *ret); +int journal_get_boots(sd_journal *j, BootId **ret_boots, size_t *ret_n_boots); diff --git a/test/TEST-09-REBOOT/Makefile b/test/TEST-09-REBOOT/Makefile new file mode 120000 index 0000000000..e9f93b1104 --- /dev/null +++ b/test/TEST-09-REBOOT/Makefile @@ -0,0 +1 @@ +../TEST-01-BASIC/Makefile \ No newline at end of file diff --git a/test/TEST-09-REBOOT/test.sh b/test/TEST-09-REBOOT/test.sh new file mode 100755 index 0000000000..53c5974efa --- /dev/null +++ b/test/TEST-09-REBOOT/test.sh @@ -0,0 +1,10 @@ +#!/usr/bin/env bash +# SPDX-License-Identifier: LGPL-2.1-or-later +set -e + +TEST_DESCRIPTION="Test various scenarios involving (multiple) machine reboots" + +# shellcheck source=test/test-functions +. "${TEST_BASE_DIR:?}/test-functions" + +do_test "$@" diff --git a/test/test-functions b/test/test-functions index 6187aa84e8..3b26b0ca06 100644 --- a/test/test-functions +++ b/test/test-functions @@ -3311,6 +3311,9 @@ test_run() { local test_id="${1:?}" mount_initdir + # Reset the boot counter, if present + rm -f "${initdir:?}/var/tmp/.systemd_reboot_count" + if ! get_bool "${TEST_NO_QEMU:=}"; then if run_qemu "$test_id"; then check_result_qemu || { echo "qemu test failed"; return 1; } diff --git a/test/units/testsuite-09.journal.sh b/test/units/testsuite-09.journal.sh new file mode 100755 index 0000000000..c6c1f6eccb --- /dev/null +++ b/test/units/testsuite-09.journal.sh @@ -0,0 +1,72 @@ +#!/usr/bin/env bash +# SPDX-License-Identifier: LGPL-2.1-or-later +set -eux +set -o pipefail + +# shellcheck source=test/units/util.sh +. "$(dirname "$0")"/util.sh + +get_first_boot_id() { + journalctl -b "${1:?}" -o json | jq -sr '.[0]._BOOT_ID' +} + +get_last_boot_id() { + journalctl -b "${1:?}" -o json -n 1 | jq -r '._BOOT_ID' +} + +get_first_timestamp() { + journalctl -b "${1:?}" -o json | jq -sr '.[0].__REALTIME_TIMESTAMP' +} + +get_last_timestamp() { + journalctl -b "${1:?}" -o json -n 1 | jq -r '.__REALTIME_TIMESTAMP' +} + +# Issue: #29275, second part +# Now let's check if the boot entries are in the correct/expected order +index=0 +SYSTEMD_LOG_LEVEL=debug journalctl --list-boots +journalctl --list-boots -o json | jq -r '.[] | [.index, .boot_id, .first_entry, .last_entry] | @tsv' | + while read -r offset boot_id first_ts last_ts; do + : "Boot #$((++index)) ($offset) with ID $boot_id" + + # Try the "regular" (non-json) variants first, as they provide a helpful + # error message if something is not right + SYSTEMD_LOG_LEVEL=debug journalctl -q -n 0 -b "$index" + SYSTEMD_LOG_LEVEL=debug journalctl -q -n 0 -b "$offset" + SYSTEMD_LOG_LEVEL=debug journalctl -q -n 0 -b "$boot_id" + + # Check the boot ID of the first entry + entry_boot_id="$(get_first_boot_id "$index")" + assert_eq "$entry_boot_id" "$boot_id" + entry_boot_id="$(get_first_boot_id "$offset")" + assert_eq "$entry_boot_id" "$boot_id" + entry_boot_id="$(get_first_boot_id "$boot_id")" + assert_eq "$entry_boot_id" "$boot_id" + + # Check the timestamp of the first entry + entry_ts="$(get_first_timestamp "$index")" + assert_eq "$entry_ts" "$first_ts" + entry_ts="$(get_first_timestamp "$offset")" + assert_eq "$entry_ts" "$first_ts" + entry_ts="$(get_first_timestamp "$boot_id")" + assert_eq "$entry_ts" "$first_ts" + + # Check the boot ID of the last entry + entry_boot_id="$(get_last_boot_id "$index")" + assert_eq "$entry_boot_id" "$boot_id" + entry_boot_id="$(get_last_boot_id "$offset")" + assert_eq "$entry_boot_id" "$boot_id" + entry_boot_id="$(get_last_boot_id "$boot_id")" + assert_eq "$entry_boot_id" "$boot_id" + + # Check the timestamp of the last entry + if [[ "$offset" != "0" ]]; then + entry_ts="$(get_last_timestamp "$index")" + assert_eq "$entry_ts" "$last_ts" + entry_ts="$(get_last_timestamp "$offset")" + assert_eq "$entry_ts" "$last_ts" + entry_ts="$(get_last_timestamp "$boot_id")" + assert_eq "$entry_ts" "$last_ts" + fi + done diff --git a/test/units/testsuite-09.service b/test/units/testsuite-09.service new file mode 100644 index 0000000000..6c957ecbd1 --- /dev/null +++ b/test/units/testsuite-09.service @@ -0,0 +1,9 @@ +# SPDX-License-Identifier: LGPL-2.1-or-later +[Unit] +Description=TEST-09-REBOOT +After=multi-user.target + +[Service] +ExecStartPre=rm -f /failed /testok +ExecStart=/usr/lib/systemd/tests/testdata/units/%N.sh +Type=oneshot diff --git a/test/units/testsuite-09.sh b/test/units/testsuite-09.sh new file mode 100755 index 0000000000..cd95660021 --- /dev/null +++ b/test/units/testsuite-09.sh @@ -0,0 +1,25 @@ +#!/usr/bin/env bash +# SPDX-License-Identifier: LGPL-2.1-or-later +set -eux +set -o pipefail + +NUM_REBOOT=4 + +# shellcheck source=test/units/test-control.sh +. "$(dirname "$0")"/test-control.sh + +# shellcheck source=test/units/util.sh +. "$(dirname "$0")"/util.sh + +systemd-cat echo "Reboot count: $REBOOT_COUNT" +systemd-cat journalctl --list-boots + +run_subtests + +if [[ "$REBOOT_COUNT" -lt "$NUM_REBOOT" ]]; then + systemctl_final reboot +elif [[ "$REBOOT_COUNT" -gt "$NUM_REBOOT" ]]; then + assert_not_reached +fi + +touch /testok diff --git a/test/units/util.sh b/test/units/util.sh index 932fe1e603..8a01c5c07a 100755 --- a/test/units/util.sh +++ b/test/units/util.sh @@ -3,6 +3,9 @@ # Utility functions for shell tests +# shellcheck disable=SC2034 +[[ -e /var/tmp/.systemd_reboot_count ]] && REBOOT_COUNT="$(&2 "Code should not be reached at ${BASH_SOURCE[1]}:${BASH_LINENO[1]}, function ${FUNCNAME[1]}()" + exit 1 +} + run_and_grep() {( set +ex @@ -149,3 +156,18 @@ create_dummy_container() { cp -a /testsuite-13-container-template/* "$root" coverage_create_nspawn_dropin "$root" } + +# Bump the reboot counter and call systemctl with the given arguments +systemctl_final() { + local counter + + if [[ $# -eq 0 ]]; then + echo >&2 "Missing arguments" + exit 1 + fi + + [[ -e /var/tmp/.systemd_reboot_count ]] && counter="$(/var/tmp/.systemd_reboot_count + + systemctl "$@" +}