shaba/systemd-stable
1
1
Fork 0
mirror of https://github.com/systemd/systemd-stable.git synced 2025-01-12 09:17:44 +03:00
Code

Merge pull request #15801 from poettering/journal-pid-change-fix

Browse Source 
journald: stream pid change newline fix
This commit is contained in:
Lennart Poettering 2020-05-14 09:04:23 +02:00 committed by GitHub
commit de07add2c9
No known key found for this signature in database
GPG Key ID: 4AEE18F83AFDEB23
3 changed files with 117 additions and 62 deletions
Show Stats Download Patch File Download Diff File Expand all files Collapse all files

19
man/systemd.journal-fields.xml
View File

@ -347,15 +347,16 @@
<varlistentry>
<term><varname>_LINE_BREAK=</varname></term>
<listitem>
<para>Only applies to <literal>_TRANSPORT=stdout</literal> records: indicates that the log message in the
standard output/error stream was not terminated with a normal newline character (<literal>\n</literal>,
i.e. ASCII 10). Specifically, when set this field is one of <option>nul</option> (in case the line was
terminated by a NUL byte), <option>line-max</option> (in case the maximum log line length was reached, as
configured with <varname>LineMax=</varname> in
<citerefentry><refentrytitle>journald.conf</refentrytitle><manvolnum>5</manvolnum></citerefentry>) or
<option>eof</option> (if this was the last log record of a stream and the stream ended without a final
newline character). Note that this record is not generated when a normal newline character was used for
marking the log line end.</para>
<para>Only applies to <literal>_TRANSPORT=stdout</literal> records: indicates that the log message
in the standard output/error stream was not terminated with a normal newline character
(<literal>\n</literal>, i.e. ASCII 10). Specifically, when set this field is one of
<option>nul</option> (in case the line was terminated by a NUL byte), <option>line-max</option> (in
case the maximum log line length was reached, as configured with <varname>LineMax=</varname> in
<citerefentry><refentrytitle>journald.conf</refentrytitle><manvolnum>5</manvolnum></citerefentry>),
<option>eof</option> (if this was the last log record of a stream and the stream ended without a
final newline character), or <option>pid-change</option> (if the process which generated the log
output changed in the middle of a line). Note that this record is not generated when a normal
newline character was used for marking the log line end.</para>
</listitem>
</varlistentry>
<varlistentry>

148
src/journal/journald-stream.c
View File

@ -58,6 +58,9 @@ typedef enum LineBreak {
LINE_BREAK_NUL,
LINE_BREAK_LINE_MAX,
LINE_BREAK_EOF,
LINE_BREAK_PID_CHANGE,
_LINE_BREAK_MAX,
_LINE_BREAK_INVALID = -1,
} LineBreak;
struct StdoutStream {
@ -238,7 +241,11 @@ fail:
return log_error_errno(r, "Failed to save stream data %s: %m", s->state_file);
}
static int stdout_stream_log(StdoutStream *s, const char *p, LineBreak line_break) {
static int stdout_stream_log(
StdoutStream *s,
const char *p,
LineBreak line_break) {
struct iovec *iovec;
int priority;
char syslog_priority[] = "PRIORITY=\0";
@ -250,6 +257,9 @@ static int stdout_stream_log(StdoutStream *s, const char *p, LineBreak line_brea
assert(s);
assert(p);
assert(line_break >= 0);
assert(line_break < _LINE_BREAK_MAX);
if (s->context)
(void) client_context_maybe_refresh(s->server, s->context, NULL, NULL, 0, NULL, USEC_INFINITY);
else if (pid_is_valid(s->ucred.pid)) {
@ -301,17 +311,20 @@ static int stdout_stream_log(StdoutStream *s, const char *p, LineBreak line_brea
iovec[n++] = IOVEC_MAKE_STRING(syslog_identifier);
}
if (line_break != LINE_BREAK_NEWLINE) {
const char *c;
static const char * const line_break_field_table[_LINE_BREAK_MAX] = {
[LINE_BREAK_NEWLINE] = NULL, /* Do not add field if traditional newline */
[LINE_BREAK_NUL] = "_LINE_BREAK=nul",
[LINE_BREAK_LINE_MAX] = "_LINE_BREAK=line-max",
[LINE_BREAK_EOF] = "_LINE_BREAK=eof",
[LINE_BREAK_PID_CHANGE] = "_LINE_BREAK=pid-change",
};
/* If this log message was generated due to an uncommon line break then mention this in the log
* entry */
const char *c = line_break_field_table[line_break];
c = line_break == LINE_BREAK_NUL ? "_LINE_BREAK=nul" :
line_break == LINE_BREAK_LINE_MAX ? "_LINE_BREAK=line-max" :
"_LINE_BREAK=eof";
/* If this log message was generated due to an uncommon line break then mention this in the log
* entry */
if (c)
iovec[n++] = IOVEC_MAKE_STRING(c);
}
message = strjoin("MESSAGE=", p);
if (message)
@ -322,8 +335,8 @@ static int stdout_stream_log(StdoutStream *s, const char *p, LineBreak line_brea
}
static int stdout_stream_line(StdoutStream *s, char *p, LineBreak line_break) {
int r;
char *orig;
int r;
assert(s);
assert(p);
@ -332,10 +345,9 @@ static int stdout_stream_line(StdoutStream *s, char *p, LineBreak line_break) {
p = strstrip(p);
/* line breaks by NUL, line max length or EOF are not permissible during the negotiation part of the protocol */
if (line_break != LINE_BREAK_NEWLINE && s->state != STDOUT_STREAM_RUNNING) {
log_warning("Control protocol line not properly terminated.");
return -EINVAL;
}
if (line_break != LINE_BREAK_NEWLINE && s->state != STDOUT_STREAM_RUNNING)
return log_warning_errno(SYNTHETIC_ERRNO(EINVAL),
"Control protocol line not properly terminated.");
switch (s->state) {
@ -425,21 +437,43 @@ static int stdout_stream_line(StdoutStream *s, char *p, LineBreak line_break) {
assert_not_reached("Unknown stream state");
}
static int stdout_stream_scan(StdoutStream *s, bool force_flush) {
char *p;
size_t remaining;
static int stdout_stream_found(
StdoutStream *s,
char *p,
size_t l,
LineBreak line_break) {
char saved;
int r;
assert(s);
assert(p);
p = s->buffer;
remaining = s->length;
/* Let's NUL terminate the specified buffer for this call, and revert back afterwards */
saved = p[l];
p[l] = 0;
r = stdout_stream_line(s, p, line_break);
p[l] = saved;
/* XXX: This function does nothing if (s->length == 0) */
return r;
}
static int stdout_stream_scan(
StdoutStream *s,
char *p,
size_t remaining,
LineBreak force_flush,
size_t *ret_consumed) {
size_t consumed = 0;
int r;
assert(s);
assert(p);
for (;;) {
LineBreak line_break;
size_t skip;
size_t skip, found;
char *end1, *end2;
end1 = memchr(p, '\n', remaining);
@ -447,43 +481,40 @@ static int stdout_stream_scan(StdoutStream *s, bool force_flush) {
if (end2) {
/* We found a NUL terminator */
skip = end2 - p + 1;
found = end2 - p;
skip = found + 1;
line_break = LINE_BREAK_NUL;
} else if (end1) {
/* We found a \n terminator */
*end1 = 0;
skip = end1 - p + 1;
found = end1 - p;
skip = found + 1;
line_break = LINE_BREAK_NEWLINE;
} else if (remaining >= s->server->line_max) {
/* Force a line break after the maximum line length */
*(p + s->server->line_max) = 0;
skip = remaining;
found = skip = s->server->line_max;
line_break = LINE_BREAK_LINE_MAX;
} else
break;
r = stdout_stream_line(s, p, line_break);
r = stdout_stream_found(s, p, found, line_break);
if (r < 0)
return r;
remaining -= skip;
p += skip;
consumed += skip;
remaining -= skip;
}
if (force_flush && remaining > 0) {
p[remaining] = 0;
r = stdout_stream_line(s, p, LINE_BREAK_EOF);
if (force_flush >= 0 && remaining > 0) {
r = stdout_stream_found(s, p, remaining, force_flush);
if (r < 0)
return r;
p += remaining;
remaining = 0;
consumed += remaining;
}
if (p > s->buffer) {
memmove(s->buffer, p, remaining);
s->length = remaining;
}
if (ret_consumed)
*ret_consumed = consumed;
return 0;
}
@ -491,10 +522,11 @@ static int stdout_stream_scan(StdoutStream *s, bool force_flush) {
static int stdout_stream_process(sd_event_source *es, int fd, uint32_t revents, void *userdata) {
CMSG_BUFFER_TYPE(CMSG_SPACE(sizeof(struct ucred))) control;
StdoutStream *s = userdata;
size_t limit, consumed;
struct ucred *ucred;
struct iovec iovec;
size_t limit;
ssize_t l;
char *p;
int r;
struct msghdr msghdr = {
@ -511,8 +543,8 @@ static int stdout_stream_process(sd_event_source *es, int fd, uint32_t revents,
goto terminate;
}
/* If the buffer is full already (discounting the extra NUL we need), add room for another 1K */
if (s->length + 1 >= s->allocated) {
/* If the buffer is almost full, add room for another 1K */
if (s->length + 512 >= s->allocated) {
if (!GREEDY_REALLOC(s->buffer, s->allocated, s->length + 1 + 1024)) {
log_oom();
goto terminate;
@ -522,7 +554,7 @@ static int stdout_stream_process(sd_event_source *es, int fd, uint32_t revents,
/* Try to make use of the allocated buffer in full, but never read more than the configured line size. Also,
* always leave room for a terminating NUL we might need to add. */
limit = MIN(s->allocated - 1, s->server->line_max);
assert(s->length <= limit);
iovec = IOVEC_MAKE(s->buffer + s->length, limit - s->length);
l = recvmsg(s->fd, &msghdr, MSG_DONTWAIT|MSG_CMSG_CLOEXEC);
@ -536,32 +568,42 @@ static int stdout_stream_process(sd_event_source *es, int fd, uint32_t revents,
cmsg_close_all(&msghdr);
if (l == 0) {
stdout_stream_scan(s, true);
(void) stdout_stream_scan(s, s->buffer, s->length, /* force_flush = */ LINE_BREAK_EOF, NULL);
goto terminate;
}
/* Invalidate the context if the pid of the sender changed. This happens when a forked process
* inherits stdout / stderr from a parent. In this case getpeercred returns the ucred of the parent,
* which can be invalid if the parent has exited in the meantime.
*/
/* Invalidate the context if the PID of the sender changed. This happens when a forked process
* inherits stdout/stderr from a parent. In this case getpeercred() returns the ucred of the parent,
* which can be invalid if the parent has exited in the meantime. */
ucred = CMSG_FIND_DATA(&msghdr, SOL_SOCKET, SCM_CREDENTIALS, struct ucred);
if (ucred && ucred->pid != s->ucred.pid) {
/* force out any previously half-written lines from a different process, before we switch to
/* Force out any previously half-written lines from a different process, before we switch to
* the new ucred structure for everything we just added */
r = stdout_stream_scan(s, true);
r = stdout_stream_scan(s, s->buffer, s->length, /* force_flush = */ LINE_BREAK_PID_CHANGE, NULL);
if (r < 0)
goto terminate;
s->ucred = *ucred;
client_context_release(s->server, s->context);
s->context = NULL;
s->context = client_context_release(s->server, s->context);
p = s->buffer + s->length;
} else {
p = s->buffer;
l += s->length;
}
s->length += l;
r = stdout_stream_scan(s, false);
/* Always copy in the new credentials */
if (ucred)
s->ucred = *ucred;
r = stdout_stream_scan(s, p, l, _LINE_BREAK_INVALID, &consumed);
if (r < 0)
goto terminate;
/* Move what wasn't consumed to the front of the buffer */
assert(consumed <= (size_t) l);
s->length = l - consumed;
memmove(s->buffer, p + consumed, s->length);
return 1;
terminate:

12
test/units/testsuite-04.sh
View File

@ -87,6 +87,18 @@ journalctl -b -o export -t "$ID" --output-fields=_PID | grep '^_PID=' >/output
grep -q "^_PID=$PID" /output
grep -vq "^_PID=$PID" /output
# https://github.com/systemd/systemd/issues/15654
ID=$(journalctl --new-id128 | sed -n 2p)
printf "This will\nusually fail\nand be truncated\n">/expected
systemd-cat -t "$ID" /bin/sh -c 'env echo -n "This will";echo;env echo -n "usually fail";echo;env echo -n "and be truncated";echo;'
journalctl --sync
journalctl -b -o cat -t "$ID" >/output
cmp /expected /output
[[ $(journalctl -b -o cat -t "$ID" --output-fields=_TRANSPORT | grep -Pc "^stdout$") -eq 3 ]]
[[ $(journalctl -b -o cat -t "$ID" --output-fields=_LINE_BREAK | grep -Pc "^pid-change$") -eq 3 ]]
[[ $(journalctl -b -o cat -t "$ID" --output-fields=_PID | sort -u | grep -c "^.*$") -eq 3 ]]
[[ $(journalctl -b -o cat -t "$ID" --output-fields=MESSAGE | grep -Pc "^(This will|usually fail|and be truncated)$") -eq 3 ]]
# Add new tests before here, the journald restarts below
# may make tests flappy.