sd-journal: prefer machine ID from the tail entry
compare_boot_ids() (from262299dccb) 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, since8f8ab4bf98the journal_file_read_tail_timestamp() calls are ratelimited when walking through the journal, lessening the impact even further. Resolves: #34169
This commit is contained in:
committed by
Yu Watanabe
parent
0f2671b34b
commit
ae940730c6
@@ -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;
|
||||
|
||||
|
||||
@@ -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)
|
||||
|
||||
Reference in New Issue
Block a user