From ae940730c6f29798db4f443fcf029b89d8ef1bae Mon Sep 17 00:00:00 2001 From: Frantisek Sumsal Date: Thu, 6 Aug 2026 09:50:30 +0200 Subject: [PATCH] sd-journal: prefer machine ID from the tail entry compare_boot_ids() (from 262299dccbb09f36c8c830dabd6a104469d9852b) skips the tail entry realtime timestamp ordering when the compared locations are from two different machines (and hence have two different machine IDs) - in that case we fall through to a realtime comparison between the two locations. This works fine except for journals that were imported via systemd-journal-remote - the machine ID in the journal header is set to the receiving machine's ID instead of the original one; but the original machine ID is kept in the _MACHINE_ID= field. This, however, defeats the check in compare_boot_ids() so we treat the remote journals as local ones and try to compare the boots based on their tail entry realtime timestamps, which results in grouping the entries by their boot ID instead of interleaving them by their realtime timestamp. Given that we (transitively) call journal_file_read_tail_timestamp() from compare_boot_ids(), where we both (re)set the newest_machine_id field to the machine ID from the journal header and have the tail entry at hand, let's try to get the _MACHINE_ID= field from the tail entry and set newest_machine_id to that if it's present and valid. This way compare_boot_ids() will correctly determine that the entries are from two different machines and compare_locations() eventually falls through to the entry realtime check, so we end up with properly interleaved entries instead of entries grouped by boot ID. The performance impact should be pretty negligible in vast majority of cases, as we'd do this only when: - opening a new file - comparing entries across different boots - advancing to a next location The first case is a one-time thing only per journal. The second and third case might call this a bit more frequently, but we fall through to the _MACHINE_ID= parsing only if the journal file got a new entry since the last check. The most significant impact would be on journals that are being actively written into, but even then iterating through the handful of typical fields is negligible compared to what the rest of the function does. Also, since 8f8ab4bf98f930fcbbdd7efcbba8577981d31df9 the journal_file_read_tail_timestamp() calls are ratelimited when walking through the journal, lessening the impact even further. Resolves: #34169 --- src/libsystemd/sd-journal/sd-journal.c | 60 +++++++++++++- .../sd-journal/test-journal-interleaving.c | 78 +++++++++++++++++-- 2 files changed, 131 insertions(+), 7 deletions(-) diff --git a/src/libsystemd/sd-journal/sd-journal.c b/src/libsystemd/sd-journal/sd-journal.c index 2340ecebe4..1579c9a6e1 100644 --- a/src/libsystemd/sd-journal/sd-journal.c +++ b/src/libsystemd/sd-journal/sd-journal.c @@ -2598,6 +2598,44 @@ _public_ void sd_journal_close(sd_journal *j) { free(j); } +static int journal_file_entry_get_machine_id(JournalFile *f, Object *o, sd_id128_t *ret) { + assert(f); + assert(o); + assert(o->object.type == OBJECT_ENTRY); + assert(ret); + + uint64_t n = journal_file_entry_n_items(f, o); + for (uint64_t i = 0; i < n; i++) { + uint64_t p; + void *d; + size_t l; + int r; + + p = journal_file_entry_item_object_offset(f, o, i); + r = journal_file_data_payload(f, /* o= */ NULL, p, "_MACHINE_ID", STRLEN("_MACHINE_ID"), + SIZE_MAX, &d, &l); + if (r == 0) + continue; + if (IN_SET(r, -EADDRNOTAVAIL, -EBADMSG)) { + log_debug_errno(r, "Entry item %"PRIu64" data object is bad, skipping over it: %m", i); + continue; + } + if (r < 0) + return r; + + if (l != STRLEN("_MACHINE_ID=") + SD_ID128_STRING_MAX - 1) + return -EBADMSG; + + /* The data payload is not null-terminated, copy the hex ID to a local buffer. */ + char id_string[SD_ID128_STRING_MAX] = {}; + memcpy(id_string, (const char*) d + STRLEN("_MACHINE_ID="), SD_ID128_STRING_MAX - 1); + + return id128_from_string_nonzero(id_string, ret); + } + + return -ENOENT; +} + static int journal_file_read_tail_timestamp(sd_journal *j, JournalFile *f) { uint64_t offset, mo, rt; sd_id128_t id; @@ -2676,9 +2714,27 @@ static int journal_file_read_tail_timestamp(sd_journal *j, JournalFile *f) { if (mo > rt) /* monotonic clock is further ahead than realtime? that's weird, refuse to use the data */ return -ENODATA; + /* Try to get the machine ID from the tail entry's _MACHINE_ID= field rather than from the file + * header, as the header always reflects the machine that *wrote* the file, not necessarily the + * machine that *originated* the entries. This distinction matters for journal files created by + * systemd-journal-remote, which stamps all files with the receiving machine's ID while the entries + * inside carry the source machine's _MACHINE_ID=. Without this, compare_boot_ids() would + * incorrectly consider boot IDs from different source machines as comparable (since they'd all + * share the receiver's machine ID), leading to boot-grouped rather than realtime-interleaved + * iteration order when merging cross-machine journals. + * + * If we don't have an entry object (header-only fallback for archived files) or the entry lacks + * the _MACHINE_ID= field (older journals), fall back to the header's machine_id. */ + sd_id128_t mid = f->header->machine_id; + if (o && o->object.type == OBJECT_ENTRY) { + r = journal_file_entry_get_machine_id(f, o, &mid); + if (r < 0 && r != -ENOENT) + log_debug_errno(r, "Failed to read _MACHINE_ID from tail entry, using header value: %m"); + } + if (offset == f->newest_entry_offset) { /* Cached data and the current one should be equivalent. */ - if (!sd_id128_equal(f->newest_machine_id, f->header->machine_id) || + if (!sd_id128_equal(f->newest_machine_id, mid) || !sd_id128_equal(f->newest_boot_id, id) || f->newest_monotonic_usec != mo || f->newest_realtime_usec != rt) @@ -2693,7 +2749,7 @@ static int journal_file_read_tail_timestamp(sd_journal *j, JournalFile *f) { f->newest_boot_id = id; f->newest_monotonic_usec = mo; f->newest_realtime_usec = rt; - f->newest_machine_id = f->header->machine_id; + f->newest_machine_id = mid; f->newest_entry_offset = offset; f->newest_state = f->header->state; diff --git a/src/libsystemd/sd-journal/test-journal-interleaving.c b/src/libsystemd/sd-journal/test-journal-interleaving.c index 69c5563a5b..8d3725d01e 100644 --- a/src/libsystemd/sd-journal/test-journal-interleaving.c +++ b/src/libsystemd/sd-journal/test-journal-interleaving.c @@ -1344,12 +1344,13 @@ static void append_number_at( JournalFile *f, unsigned n, const sd_id128_t *boot_id, + const sd_id128_t *machine_id, uint64_t realtime, uint64_t monotonic) { - _cleanup_free_ char *p = NULL, *q = NULL; + _cleanup_free_ char *p = NULL, *q = NULL, *m = NULL; dual_timestamp ts = { .realtime = realtime, .monotonic = monotonic }; - struct iovec iovec[2]; + struct iovec iovec[3]; size_t n_iov = 0; ASSERT_OK(asprintf(&p, "NUMBER=%u", n)); @@ -1360,6 +1361,11 @@ static void append_number_at( iovec[n_iov++] = IOVEC_MAKE_STRING(q); } + if (machine_id) { + ASSERT_NOT_NULL((m = strjoin("_MACHINE_ID=", SD_ID128_TO_STRING(*machine_id)))); + iovec[n_iov++] = IOVEC_MAKE_STRING(m); + } + ASSERT_OK(journal_file_append_entry(f, &ts, boot_id, iovec, n_iov, NULL, NULL, NULL, NULL)); } @@ -1398,9 +1404,9 @@ TEST(cursor_broken_rtc) { log_info("boot1: %s, boot2: %s", SD_ID128_TO_STRING(boot1), SD_ID128_TO_STRING(boot2)); - append_number_at(f1, 1, &boot1, 2 * USEC_PER_SEC, 100 * USEC_PER_MSEC); - append_number_at(f2, 2, &boot2, 1 * USEC_PER_SEC, 100 * USEC_PER_MSEC); - append_number_at(f2, 3, &boot2, 3 * USEC_PER_SEC, 200 * USEC_PER_MSEC); + append_number_at(f1, 1, &boot1, NULL, 2 * USEC_PER_SEC, 100 * USEC_PER_MSEC); + append_number_at(f2, 2, &boot2, NULL, 1 * USEC_PER_SEC, 100 * USEC_PER_MSEC); + append_number_at(f2, 3, &boot2, NULL, 3 * USEC_PER_SEC, 200 * USEC_PER_MSEC); } ASSERT_OK(sd_journal_open_directory(&j, t, SD_JOURNAL_ASSUME_IMMUTABLE)); @@ -1418,6 +1424,68 @@ TEST(cursor_broken_rtc) { test_check_numbers_up(j, 3); } +TEST(merge_interleaving) { + /* Reproducer for https://github.com/systemd/systemd/issues/34169. + * + * Simulate journals received via systemd-journal-remote from two different source + * machines. journal-remote stamps all files with the receiving machine's machine_id + * (per the journal file format spec), so all files share the same header machine_id + * even though the entries originate from different machines with different boot IDs. + * + * This defeats the machine_id guard in compare_boot_ids(), which then orders entries + * by boot rather than interleaving them by realtime. The expected behavior is that + * forward iteration produces entries in realtime order regardless of boot ID. + * + * Setup: 2 files with different boot IDs, entries interleaved by realtime. Each + * entry carries a _MACHINE_ID= field identifying the source machine (as journal-remote + * preserves from the source): + * + * machine-a.journal (boot A, machine A): entries at realtime = 1s, 3s, 5s (NUMBER = 1, 3, 5) + * machine-b.journal (boot B, machine B): entries at realtime = 2s, 4s, 6s (NUMBER = 2, 4, 6) */ + _cleanup_(test_donep) char *t = NULL; + _cleanup_(sd_journal_closep) sd_journal *j = NULL; + + mkdtemp_chdir_chattr("/var/tmp/journal-merge-XXXXXX", &t); + + { + _cleanup_(journal_file_offline_closep) JournalFile *f1 = NULL, *f2 = NULL; + sd_id128_t bootA, bootB, machineA, machineB; + + f1 = test_open("machine-a.journal"); + f2 = test_open("machine-b.journal"); + + ASSERT_OK(sd_id128_randomize(&bootA)); + ASSERT_OK(sd_id128_randomize(&bootB)); + ASSERT_OK(sd_id128_randomize(&machineA)); + ASSERT_OK(sd_id128_randomize(&machineB)); + + log_info("bootA: %s, bootB: %s, machineA: %s, machineB: %s", + SD_ID128_TO_STRING(bootA), SD_ID128_TO_STRING(bootB), + SD_ID128_TO_STRING(machineA), SD_ID128_TO_STRING(machineB)); + + append_number_at(f1, 1, &bootA, &machineA, 1 * USEC_PER_SEC, 100 * USEC_PER_MSEC); + append_number_at(f2, 2, &bootB, &machineB, 2 * USEC_PER_SEC, 100 * USEC_PER_MSEC); + append_number_at(f1, 3, &bootA, &machineA, 3 * USEC_PER_SEC, 200 * USEC_PER_MSEC); + append_number_at(f2, 4, &bootB, &machineB, 4 * USEC_PER_SEC, 200 * USEC_PER_MSEC); + append_number_at(f1, 5, &bootA, &machineA, 5 * USEC_PER_SEC, 300 * USEC_PER_MSEC); + append_number_at(f2, 6, &bootB, &machineB, 6 * USEC_PER_SEC, 300 * USEC_PER_MSEC); + } + + ASSERT_OK(sd_journal_open_directory(&j, t, SD_JOURNAL_ASSUME_IMMUTABLE)); + + /* Test cursor seeking */ + test_cursor(j); + + /* Verify forward and backward iterations */ + ASSERT_OK(sd_journal_seek_head(j)); + ASSERT_OK_POSITIVE(sd_journal_next(j)); + test_check_numbers_down(j, 6); + + ASSERT_OK(sd_journal_seek_tail(j)); + ASSERT_OK_POSITIVE(sd_journal_previous(j)); + test_check_numbers_up(j, 6); +} + static int intro(void) { /* journal_file_open() requires a valid machine id */ if (access("/etc/machine-id", F_OK) != 0)