Skip to content

Commit

Permalink
journal: Serialize __MONOTONIC_TIMESTAMP metadata field as well
Browse files Browse the repository at this point in the history
Otherwise the forwarded journals won't have any monotonic timestamps.
  • Loading branch information
DaanDeMeyer committed May 3, 2024
1 parent a56820d commit 2c93e5f
Show file tree
Hide file tree
Showing 5 changed files with 40 additions and 21 deletions.
28 changes: 15 additions & 13 deletions src/journal/journald-server.c
Original file line number Diff line number Diff line change
Expand Up @@ -20,6 +20,7 @@
#include "conf-parser.h"
#include "creds-util.h"
#include "dirent-util.h"
#include "event-util.h"
#include "extract-word.h"
#include "fd-util.h"
#include "fileio.h"
Expand Down Expand Up @@ -932,24 +933,19 @@ static void server_write_to_journal(
uid_t uid,
const struct iovec *iovec,
size_t n,
const dual_timestamp *ts,
int priority) {

bool vacuumed = false;
struct dual_timestamp ts;
JournalFile *f;
int r;

assert(s);
assert(iovec);
assert(n > 0);
assert(ts);

/* Get the closest, linearized time we have for this log event from the event loop. (Note that we do not use
* the source time, and not even the time the event was originally seen, but instead simply the time we started
* processing it, as we want strictly linear ordering in what we write out.) */
assert_se(sd_event_now(s->event, CLOCK_REALTIME, &ts.realtime) >= 0);
assert_se(sd_event_now(s->event, CLOCK_MONOTONIC, &ts.monotonic) >= 0);

if (ts.realtime < s->last_realtime_clock) {
if (ts->realtime < s->last_realtime_clock) {
/* When the time jumps backwards, let's immediately rotate. Of course, this should not happen during
* regular operation. However, when it does happen, then we should make sure that we start fresh files
* to ensure that the entries in the journal files are strictly ordered by time, in order to ensure
Expand Down Expand Up @@ -983,11 +979,11 @@ static void server_write_to_journal(
return;
}

s->last_realtime_clock = ts.realtime;
s->last_realtime_clock = ts->realtime;

r = journal_file_append_entry(
f,
&ts,
ts,
/* boot_id= */ NULL,
iovec, n,
&s->seqnum->seqnum,
Expand Down Expand Up @@ -1019,7 +1015,7 @@ static void server_write_to_journal(
log_debug_errno(r, "Retrying write.");
r = journal_file_append_entry(
f,
&ts,
ts,
/* boot_id= */ NULL,
iovec, n,
&s->seqnum->seqnum,
Expand Down Expand Up @@ -1188,9 +1184,15 @@ static void server_dispatch_message_real(
else
journal_uid = 0;

(void) server_forward_socket(s, iovec, n, priority);
/* Get the closest, linearized time we have for this log event from the event loop. (Note that we do
* not use the source time, and not even the time the event was originally seen, but instead simply
* the time we started processing it, as we want strictly linear ordering in what we write out.) */
struct dual_timestamp ts;
event_dual_timestamp_now(s->event, &ts);

(void) server_forward_socket(s, iovec, n, &ts, priority);

server_write_to_journal(s, journal_uid, iovec, n, priority);
server_write_to_journal(s, journal_uid, iovec, n, &ts, priority);
}

void server_driver_message(Server *s, pid_t object_pid, const char *message_id, const char *format, ...) {
Expand Down
20 changes: 13 additions & 7 deletions src/journal/journald-socket.c
Original file line number Diff line number Diff line change
Expand Up @@ -70,6 +70,7 @@ int server_forward_socket(
Server *s,
const struct iovec *iovec,
size_t n_iovec,
const dual_timestamp *ts,
int priority) {

_cleanup_free_ struct iovec *iov_alloc = NULL;
Expand All @@ -81,6 +82,7 @@ int server_forward_socket(
assert(s);
assert(iovec);
assert(n_iovec > 0);
assert(ts);

if (LOG_PRI(priority) > s->max_level_socket)
return 0;
Expand All @@ -90,8 +92,8 @@ int server_forward_socket(
return r;

/* We need a newline after each iovec + 4 for each we have to serialize in a binary safe way
* + 1 for the final __REALTIME_TIMESTAMP metadata field. */
size_t n = n_iovec * 5 + 1;
* + 2 for the final __REALTIME_TIMESTAMP and __MONOTONIC_TIMESTAMP metadata fields. */
size_t n = n_iovec * 5 + 2;

if (n < ALLOCA_MAX / (sizeof(struct iovec) + sizeof(le64_t)) / 2) {
iov = newa(struct iovec, n);
Expand Down Expand Up @@ -139,11 +141,15 @@ int server_forward_socket(
iov[iov_idx++] = nl;
}

/* Synthesise __REALTIME_TIMESTAMP as the last argument so systemd-journal-upload can receive these
* export messages. */
char buf[STRLEN("__REALTIME_TIMESTAMP=") + DECIMAL_STR_MAX(usec_t) + 2];
xsprintf(buf, "__REALTIME_TIMESTAMP="USEC_FMT"\n\n", now(CLOCK_REALTIME));
iov[iov_idx++] = IOVEC_MAKE_STRING(buf);
/* Synthesise __REALTIME_TIMESTAMP and __MONOTONIC_TIMESTAMP as the last arguments so
* systemd-journal-upload can receive these export messages. */
char realtime_buf[STRLEN("__REALTIME_TIMESTAMP=") + DECIMAL_STR_MAX(usec_t) + 1];
xsprintf(realtime_buf, "__REALTIME_TIMESTAMP="USEC_FMT"\n", ts->realtime);
iov[iov_idx++] = IOVEC_MAKE_STRING(realtime_buf);

char monotonic_buf[STRLEN("__MONOTONIC_TIMESTAMP=") + DECIMAL_STR_MAX(usec_t) + 2];
xsprintf(monotonic_buf, "__MONOTONIC_TIMESTAMP="USEC_FMT"\n\n", ts->monotonic);
iov[iov_idx++] = IOVEC_MAKE_STRING(monotonic_buf);

if (writev(s->forward_socket_fd, iov, iov_idx) < 0) {
log_debug_errno(errno, "Failed to forward log message over socket: %m");
Expand Down
2 changes: 1 addition & 1 deletion src/journal/journald-socket.h
Original file line number Diff line number Diff line change
Expand Up @@ -4,4 +4,4 @@
#include "journald-server.h"
#include "socket-util.h"

int server_forward_socket(Server *s, const struct iovec *iovec, size_t n, int priority);
int server_forward_socket(Server *s, const struct iovec *iovec, size_t n, const dual_timestamp *ts, int priority);
9 changes: 9 additions & 0 deletions src/libsystemd/sd-event/event-util.c
Original file line number Diff line number Diff line change
Expand Up @@ -168,3 +168,12 @@ int event_add_child_pidref(

return sd_event_add_child(e, s, pid->pid, options, callback, userdata);
}

dual_timestamp* event_dual_timestamp_now(sd_event *e, dual_timestamp *ts) {
assert(e);
assert(ts);

assert_se(sd_event_now(e, CLOCK_REALTIME, &ts->realtime) >= 0);
assert_se(sd_event_now(e, CLOCK_MONOTONIC, &ts->monotonic) >= 0);
return ts;
}
2 changes: 2 additions & 0 deletions src/libsystemd/sd-event/event-util.h
Original file line number Diff line number Diff line change
Expand Up @@ -36,3 +36,5 @@ static inline int event_source_disable(sd_event_source *s) {
int event_add_time_change(sd_event *e, sd_event_source **ret, sd_event_io_handler_t callback, void *userdata);

int event_add_child_pidref(sd_event *e, sd_event_source **s, const PidRef *pid, int options, sd_event_child_handler_t callback, void *userdata);

dual_timestamp* event_dual_timestamp_now(sd_event *e, dual_timestamp *ts);

0 comments on commit 2c93e5f

Please sign in to comment.