diff --git a/src/libsystemd/sd-journal/journal-file.c b/src/libsystemd/sd-journal/journal-file.c index f72498c2e7..2812eb386a 100644 --- a/src/libsystemd/sd-journal/journal-file.c +++ b/src/libsystemd/sd-journal/journal-file.c @@ -2913,9 +2913,19 @@ static int generic_array_bisect_step( if (IN_SET(r, -EBADMSG, -EADDRNOTAVAIL)) { log_debug_errno(r, "Encountered invalid entry while bisecting, cutting algorithm short."); - /* The first entry in the array is corrupted, let's go back to the previous array. */ - if (i == 0) + if (i == *left) { + /* This happens on two situations: + * + * a) i == 0 (hence, *left == 0): + * The first entry in the array is corrupted, let's go back to the previous array. + * + * b) *right == *left or *left + 1, and we are going to downwards: + * In that case, the (i-1)-th object has been already tested in the previous call, + * which returned TEST_LEFT. See below. So, there is no matching entry in this + * array nor in the whole entry array chain. */ + assert(i == 0 || (*right - *left <= 1 && direction == DIRECTION_DOWN)); return TEST_GOTO_PREVIOUS; + } /* Otherwise, cutting the array short. So, here we limit the number of elements we will see * in this array, and set the right boundary to the last possibly non-corrupted object. */ @@ -3006,10 +3016,11 @@ static int generic_array_bisect( * check that first. */ r = test_object(f, ci->begin, needle); - if (r < 0) + if (IN_SET(r, -EBADMSG, -EADDRNOTAVAIL)) + log_debug_errno(r, "Cached entry is corrupted, ignoring: %m"); + else if (r < 0) return r; - - if (r == TEST_LEFT) { + else if (r == TEST_LEFT) { /* OK, what we are looking for is right of the begin of this EntryArray, so let's * jump straight to previously cached array in the chain */ @@ -3021,14 +3032,14 @@ static int generic_array_bisect( } while (a > 0) { - uint64_t left, right, k, m; + uint64_t left, right, k, m, m_original; r = journal_file_move_to_object(f, OBJECT_ENTRY_ARRAY, a, &array); if (r < 0) return r; k = journal_file_entry_array_n_items(f, array); - m = MIN(k, n); + m = m_original = MIN(k, n); if (m <= 0) return 0; @@ -3079,6 +3090,27 @@ static int generic_array_bisect( for (;;) { if (left == right) { + /* We found one or more corrupted entries in generic_array_bisect_step(). + * In that case, the entry pointed by 'right' may not be tested. + * + * When we are going to downwards, the entry object pointed by 'left' + * has not been tested yet, Hence, even if left == right, we still + * have to check the final entry to see if it actually matches. + * + * On the other hand, when we are going to upwards, the entry pointed + * by 'left' is always tested, So, it is not necessary to test the + * final entry again. */ + if (m != m_original && direction == DIRECTION_DOWN) { + r = generic_array_bisect_step(f, array, left, needle, test_object, direction, &m, &left, &right); + if (r < 0) + return r; + if (IN_SET(r, TEST_GOTO_PREVIOUS, TEST_GOTO_NEXT)) + return 0; /* The entry does not pass the test, or is corrupted */ + + assert(TEST_RIGHT); + assert(left == right); + } + i = left; goto found; } @@ -3091,6 +3123,8 @@ static int generic_array_bisect( return r; if (r == TEST_GOTO_PREVIOUS) goto previous; + if (r == TEST_GOTO_NEXT) + return 0; /* Found a corrupt entry, and the array was cut short. */ } } diff --git a/src/libsystemd/sd-journal/test-journal-interleaving.c b/src/libsystemd/sd-journal/test-journal-interleaving.c index eff908bde0..8aeef8f607 100644 --- a/src/libsystemd/sd-journal/test-journal-interleaving.c +++ b/src/libsystemd/sd-journal/test-journal-interleaving.c @@ -14,6 +14,7 @@ #include "log.h" #include "logs-show.h" #include "parse-util.h" +#include "random-util.h" #include "rm-rf.h" #include "tests.h" @@ -58,7 +59,21 @@ static void test_close(JournalFile *f) { (void) journal_file_offline_close(f); } -static void append_number(JournalFile *f, int n, const sd_id128_t *boot_id, uint64_t *seqnum) { +static void test_done(const char *t) { + 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); + } + + log_info("------------------------------------------------------------"); +} + +static void append_number(JournalFile *f, int n, const sd_id128_t *boot_id, uint64_t *seqnum, uint64_t *ret_offset) { _cleanup_free_ char *p = NULL, *q = NULL; dual_timestamp ts; struct iovec iovec[2]; @@ -82,7 +97,7 @@ static void append_number(JournalFile *f, int n, const sd_id128_t *boot_id, uint iovec[n_iov++] = IOVEC_MAKE_STRING(q); } - assert_ret(journal_file_append_entry(f, &ts, boot_id, iovec, n_iov, seqnum, NULL, NULL, NULL)); + assert_ret(journal_file_append_entry(f, &ts, boot_id, iovec, n_iov, seqnum, NULL, NULL, ret_offset)); } static void append_unreferenced_data(JournalFile *f, const sd_id128_t *boot_id) { @@ -154,19 +169,19 @@ static void setup_sequential(void) { f3 = test_open("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); - append_number(f2, 4, &id, NULL); + append_number(f1, 1, &id, NULL, NULL); + append_number(f1, 2, &id, NULL, NULL); + append_number(f1, 3, &id, NULL, NULL); + append_number(f2, 4, &id, NULL, 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); + append_number(f2, 5, &id, NULL, NULL); + append_number(f2, 6, &id, NULL, NULL); + append_number(f3, 7, &id, NULL, NULL); + append_number(f3, 8, &id, NULL, NULL); assert_se(sd_id128_randomize(&id) >= 0); log_info("boot_id: %s", SD_ID128_TO_STRING(id)); - append_number(f3, 9, &id, NULL); + append_number(f3, 9, &id, NULL, NULL); test_close(f1); test_close(f2); test_close(f3); @@ -181,15 +196,15 @@ static void setup_interleaved(void) { f3 = test_open("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(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); + append_number(f1, 1, &id, NULL, NULL); + append_number(f2, 2, &id, NULL, NULL); + append_number(f3, 3, &id, NULL, NULL); + append_number(f1, 4, &id, NULL, NULL); + append_number(f2, 5, &id, NULL, NULL); + append_number(f3, 6, &id, NULL, NULL); + append_number(f1, 7, &id, NULL, NULL); + append_number(f2, 8, &id, NULL, NULL); + append_number(f3, 9, &id, NULL, NULL); test_close(f1); test_close(f2); test_close(f3); @@ -206,21 +221,21 @@ static void setup_unreferenced_data(void) { 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); + append_number(f1, 1, &id, NULL, NULL); + append_number(f1, 2, &id, NULL, NULL); + append_number(f1, 3, &id, NULL, 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); + append_number(f2, 4, &id, NULL, NULL); + append_number(f2, 5, &id, NULL, NULL); + append_number(f2, 6, &id, NULL, 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); + append_number(f3, 7, &id, NULL, NULL); + append_number(f3, 8, &id, NULL, NULL); + append_number(f3, 9, &id, NULL, NULL); test_close(f1); test_close(f2); test_close(f3); @@ -376,17 +391,7 @@ static void test_skip_one(void (*setup)(void)) { test_check_numbers_up(j, 9); 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_done(t); } TEST(skip) { @@ -428,17 +433,7 @@ static void test_boot_id_one(void (*setup)(void), size_t n_boots_expected) { 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_done(t); } TEST(boot_id) { @@ -461,10 +456,10 @@ static void test_sequence_numbers_one(void) { assert_se(journal_file_open(-1, "one.journal", O_RDWR|O_CREAT, JOURNAL_COMPRESS, 0644, UINT64_MAX, NULL, m, NULL, &one) == 0); - append_number(one, 1, NULL, &seqnum); + append_number(one, 1, NULL, &seqnum, NULL); printf("seqnum=%"PRIu64"\n", seqnum); assert_se(seqnum == 1); - append_number(one, 2, NULL, &seqnum); + append_number(one, 2, NULL, &seqnum, NULL); printf("seqnum=%"PRIu64"\n", seqnum); assert_se(seqnum == 2); @@ -484,10 +479,10 @@ static void test_sequence_numbers_one(void) { assert_se(sd_id128_is_null(two->header->tail_entry_boot_id)); /* Not written yet. */ assert_se(sd_id128_equal(two->header->seqnum_id, one->header->seqnum_id)); - append_number(two, 3, NULL, &seqnum); + append_number(two, 3, NULL, &seqnum, NULL); printf("seqnum=%"PRIu64"\n", seqnum); assert_se(seqnum == 3); - append_number(two, 4, NULL, &seqnum); + append_number(two, 4, NULL, &seqnum, NULL); printf("seqnum=%"PRIu64"\n", seqnum); assert_se(seqnum == 4); @@ -496,11 +491,11 @@ static void test_sequence_numbers_one(void) { test_close(two); - append_number(one, 5, NULL, &seqnum); + append_number(one, 5, NULL, &seqnum, NULL); printf("seqnum=%"PRIu64"\n", seqnum); assert_se(seqnum == 5); - append_number(one, 6, NULL, &seqnum); + append_number(one, 6, NULL, &seqnum, NULL); printf("seqnum=%"PRIu64"\n", seqnum); assert_se(seqnum == 6); @@ -517,7 +512,7 @@ static void test_sequence_numbers_one(void) { assert_se(sd_id128_equal(two->header->seqnum_id, seqnum_id)); - append_number(two, 7, NULL, &seqnum); + append_number(two, 7, NULL, &seqnum, NULL); printf("seqnum=%"PRIu64"\n", seqnum); assert_se(seqnum == 5); @@ -527,15 +522,7 @@ static void test_sequence_numbers_one(void) { test_close(two); } - 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); - } + test_done(t); } TEST(sequence_numbers) { @@ -546,6 +533,197 @@ TEST(sequence_numbers) { test_sequence_numbers_one(); } +static int expected_result(uint64_t needle, const uint64_t *candidates, const uint64_t *offset, size_t n, direction_t direction, uint64_t *ret) { + switch (direction) { + case DIRECTION_DOWN: + for (size_t i = 0; i < n; i++) { + if (candidates[i] == 0) { + *ret = 0; + return 0; + } + if (needle <= candidates[i]) { + *ret = offset[i]; + return 1; + } + } + *ret = 0; + return 0; + + case DIRECTION_UP: + for (size_t i = 0; i < n; i++) + if (needle < candidates[i] || candidates[i] == 0) { + if (i == 0) { + *ret = 0; + return 0; + } + *ret = offset[i - 1]; + return 1; + } + *ret = offset[n - 1]; + return 1; + + default: + assert_not_reached(); + } +} + +static void verify(JournalFile *f, const uint64_t *seqnum, const uint64_t *offset, size_t n) { + uint64_t p, q; + int r, e; + + /* by seqnum (sequential) */ + for (uint64_t i = 0; i < n + 2; i++) { + p = 0; + r = journal_file_move_to_entry_by_seqnum(f, i, DIRECTION_DOWN, NULL, &p); + e = expected_result(i, seqnum, offset, n, DIRECTION_DOWN, &q); + assert_se(r == e); + assert_se(p == q); + + p = 0; + r = journal_file_move_to_entry_by_seqnum(f, i, DIRECTION_UP, NULL, &p); + e = expected_result(i, seqnum, offset, n, DIRECTION_UP, &q); + assert_se(r == e); + assert_se(p == q); + } + + /* by seqnum (random) */ + for (size_t trial = 0; trial < 3 * n; trial++) { + uint64_t i = random_u64_range(n + 2); + + p = 0; + r = journal_file_move_to_entry_by_seqnum(f, i, DIRECTION_DOWN, NULL, &p); + e = expected_result(i, seqnum, offset, n, DIRECTION_DOWN, &q); + assert_se(r == e); + assert_se(p == q); + } + for (size_t trial = 0; trial < 3 * n; trial++) { + uint64_t i = random_u64_range(n + 2); + + p = 0; + r = journal_file_move_to_entry_by_seqnum(f, i, DIRECTION_UP, NULL, &p); + e = expected_result(i, seqnum, offset, n, DIRECTION_UP, &q); + assert_se(r == e); + assert_se(p == q); + } + + /* by offset (sequential) */ + for (size_t i = 0; i < n; i++) { + p = 0; + r = journal_file_move_to_entry_by_offset(f, offset[i] - 1, DIRECTION_DOWN, NULL, &p); + e = expected_result(offset[i] - 1, offset, offset, n, DIRECTION_DOWN, &q); + assert_se(r == e); + assert_se(p == q); + + p = 0; + r = journal_file_move_to_entry_by_offset(f, offset[i], DIRECTION_DOWN, NULL, &p); + e = expected_result(offset[i], offset, offset, n, DIRECTION_DOWN, &q); + assert_se(r == e); + assert_se(p == q); + + p = 0; + r = journal_file_move_to_entry_by_offset(f, offset[i] + 1, DIRECTION_DOWN, NULL, &p); + e = expected_result(offset[i] + 1, offset, offset, n, DIRECTION_DOWN, &q); + assert_se(r == e); + assert_se(p == q); + + p = 0; + r = journal_file_move_to_entry_by_offset(f, offset[i] - 1, DIRECTION_UP, NULL, &p); + e = expected_result(offset[i] - 1, offset, offset, n, DIRECTION_UP, &q); + assert_se(r == e); + assert_se(p == q); + + p = 0; + r = journal_file_move_to_entry_by_offset(f, offset[i], DIRECTION_UP, NULL, &p); + e = expected_result(offset[i], offset, offset, n, DIRECTION_UP, &q); + assert_se(r == e); + assert_se(p == q); + + p = 0; + r = journal_file_move_to_entry_by_offset(f, offset[i] + 1, DIRECTION_UP, NULL, &p); + e = expected_result(offset[i] + 1, offset, offset, n, DIRECTION_UP, &q); + assert_se(r == e); + assert_se(p == q); + } + + /* by offset (random) */ + for (size_t trial = 0; trial < 3 * n; trial++) { + uint64_t i = offset[0] - 1 + random_u64_range(offset[n-1] - offset[0] + 2); + + p = 0; + r = journal_file_move_to_entry_by_offset(f, i, DIRECTION_DOWN, NULL, &p); + e = expected_result(i, offset, offset, n, DIRECTION_DOWN, &q); + assert_se(r == e); + assert_se(p == q); + } + for (size_t trial = 0; trial < 3 * n; trial++) { + uint64_t i = offset[0] - 1 + random_u64_range(offset[n-1] - offset[0] + 2); + + p = 0; + r = journal_file_move_to_entry_by_offset(f, i, DIRECTION_UP, NULL, &p); + e = expected_result(i, offset, offset, n, DIRECTION_UP, &q); + assert_se(r == e); + assert_se(p == q); + } +} + +static void test_generic_array_bisect_one(size_t n, size_t num_corrupted) { + _cleanup_(mmap_cache_unrefp) MMapCache *m = NULL; + char t[] = "/var/tmp/journal-seq-XXXXXX"; + _cleanup_free_ uint64_t *seqnum = NULL, *offset = NULL; + JournalFile *f; + + log_info("/* %s(%zu, %zu) */", __func__, n, num_corrupted); + + assert_se(m = mmap_cache_new()); + + mkdtemp_chdir_chattr(t); + + assert_se(journal_file_open(-1, "test.journal", O_RDWR|O_CREAT, JOURNAL_COMPRESS, 0644, + UINT64_MAX, NULL, m, NULL, &f) == 0); + + assert_se(seqnum = new0(uint64_t, n)); + assert_se(offset = new0(uint64_t, n)); + + for (size_t i = 0; i < n; i++) { + append_number(f, i, NULL, seqnum + i, offset + i); + if (i == 0) { + assert_se(seqnum[i] > 0); + assert_se(offset[i] > 0); + } else { + assert_se(seqnum[i] > seqnum[i-1]); + assert_se(offset[i] > offset[i-1]); + } + } + + verify(f, seqnum, offset, n); + + /* Reset chain cache. */ + assert_se(journal_file_move_to_entry_by_offset(f, offset[0], DIRECTION_DOWN, NULL, NULL) > 0); + + /* make journal corrupted by clearing seqnum. */ + for (size_t i = n - num_corrupted; i < n; i++) { + Object *o; + + assert_se(journal_file_move_to_object(f, OBJECT_ENTRY, offset[i], &o) >= 0); + assert_se(o); + o->entry.seqnum = 0; + seqnum[i] = 0; + } + + verify(f, seqnum, offset, n); + + test_close(f); + test_done(t); +} + +TEST(generic_array_bisect) { + for (size_t n = 1; n < 10; n++) + for (size_t m = 1; m <= n; m++) + test_generic_array_bisect_one(n, m); + + test_generic_array_bisect_one(100, 40); +} + static int intro(void) { /* journal_file_open() requires a valid machine id */ if (access("/etc/machine-id", F_OK) != 0) diff --git a/test/units/testsuite-04.journal.sh b/test/units/testsuite-04.journal.sh index 6ea4cc4296..3efac616e0 100755 --- a/test/units/testsuite-04.journal.sh +++ b/test/units/testsuite-04.journal.sh @@ -238,6 +238,6 @@ done < <(find /test-journals/no-rtc -name "*.zst") journalctl --directory="$JOURNAL_DIR" --list-boots --output=json >/tmp/lb1 diff -u /tmp/lb1 - <<'EOF' -[{"index":-3,"boot_id":"5ea5fc4f82a14186b5332a788ef9435e","first_entry":1666569600994371,"last_entry":1666584266223608},{"index":-2,"boot_id":"bea6864f21ad4c9594c04a99d89948b0","first_entry":1666569601005945,"last_entry":1666584347230411},{"index":-1,"boot_id":"4c708e1fd0744336be16f3931aa861fb","first_entry":1666584293354007,"last_entry":1666584354649355},{"index":0,"boot_id":"35e8501129134edd9df5267c49f744a4","first_entry":1666569601009823,"last_entry":1666584438086856}] +[{"index":-3,"boot_id":"5ea5fc4f82a14186b5332a788ef9435e","first_entry":1666569600994371,"last_entry":1666584266223608},{"index":-2,"boot_id":"bea6864f21ad4c9594c04a99d89948b0","first_entry":1666569601005945,"last_entry":1666584347230411},{"index":-1,"boot_id":"4c708e1fd0744336be16f3931aa861fb","first_entry":1666569601017222,"last_entry":1666584354649355},{"index":0,"boot_id":"35e8501129134edd9df5267c49f744a4","first_entry":1666569601009823,"last_entry":1666584438086856}] EOF rm -rf "$JOURNAL_DIR" /tmp/lb1