journald: bump log message buffer size to 64K #4875
Conversation
4z3
force-pushed
the
journald-streams-bufsiz
branch
from
c1b0767 to
fffc4cc
Compare
4z3
changed the title
|
Well, I am fine with bumping the buffer size, but if we do that we should really do the same for all transports, and that means server_process_datagram() should probably use the same limit as we use for the streams. Also, I am not a fan of unnecessary abbreviations. Please name this BUFFER_SIZE, not BUFSIZ. |
poettering
added
journal
reviewed/needs-rework 🔨
poettering
changed the title
|
hmm, the other thing i don't like is that allocating 64K just like that for each stream sounds quite wasteful. 4K was already a lot, but 64K sounds way to much to just allocate for each stream, as we may have many of those in parallel, and we are unlikely to ever use that much. Hence, I figure the buffer should grow dynamically, and the 64K limit should just be a limit. GREEDY_REALLOC() makes it easier to have dynamically growing buffers. |
4z3
force-pushed
the
journald-streams-bufsiz
branch
from
fffc4cc to
ab7c9e0
Compare
|
Please grow the per-stream buffers dynamically using GREEDY_REALLOC, so that we don't waste such a large buffer for each stream |
|
This is not a good idea given how journald is currently implemented. The buffer size essentially sets the time-slice upper bound a given log stream event may consume, this isn't just about copying larger buffers at a time. For every newline in the buffer, journald does a whole mountain of pointlessly redundant work interrogating the process metadata in /proc. Even today, with the relatively tiny LINE_MAX buffer size, if you do something as minor as Imagine if the buffer were 64KiB in size. A regular user would be able to produce disproportionate swaths of what's essentially an atomic chunk of work for journald depriving all other loggers from getting anything in for undesirable periods of time, essentially a DoS, with very little effort. The metadata caching proposed in #2280 changed this to acquire the metadata on a per-buffer basis. I wouldn't increase the buffer size until the amount of work done on behalf of the buffer no longer depends so greatly on its newline density. |
According to you, is it possible to let the user configure this value into |
|
I have the same issue. Long java log lines are split. Set a configuration parameter in |
Agreed. journald is slow anyway, fixing this would help even non-malicious users. |
|
It's terrible that this is still unsolved. Same with the journal race and /proc spamming. |
|
Somebody needs to work through the problem and prep a patch ;) |
… it to 48K This adds a new setting LineMax= to journald.conf, and sets it by default to 48K. When we convert stream-based stdout/stderr logging into record-based log entries, read up to the specified amount of bytes before forcing a line-break. This also makes three related changes: - When a NUL byte is read we'll not recognize this as alternative line break, instead of silently dropping everything after it. (see systemd#4863) - The reason for a line-break is now encoded in the log record, if it wasn't a plain newline. Specifically, we distuingish "nul", "max-reached" and "eof", for line breaks due to NUL byte, due to the maximum line length as configured with LineMax= or due to end of stream. This data is stored in the new implicit _LINE_BREAK= field. It's not synthesized for plain \n line breaks. - A randomized 128bit ID is assigned to each log stream. With these three changes in place it's (mostly) possible to reconstruct the original byte streams from log data, as (most) of the context of the conversion from the byte stream to log records is saved now. (So, the only bits we still drop are empty lines. Which might be something to look into in a future change, and which is outside of the scope of this work) Fixes: https://bugs.freedesktop.org/show_bug.cgi?id=86465 Fixes: systemd#4863 Replaces: systemd#4875
|
I have prepared a patch now implemented the suggested logic and more. Let's close this PR and follow up in #6838. |
… it to 48K This adds a new setting LineMax= to journald.conf, and sets it by default to 48K. When we convert stream-based stdout/stderr logging into record-based log entries, read up to the specified amount of bytes before forcing a line-break. This also makes three related changes: - When a NUL byte is read we'll not recognize this as alternative line break, instead of silently dropping everything after it. (see systemd#4863) - The reason for a line-break is now encoded in the log record, if it wasn't a plain newline. Specifically, we distuingish "nul", "max-reached" and "eof", for line breaks due to NUL byte, due to the maximum line length as configured with LineMax= or due to end of stream. This data is stored in the new implicit _LINE_BREAK= field. It's not synthesized for plain \n line breaks. - A randomized 128bit ID is assigned to each log stream. With these three changes in place it's (mostly) possible to reconstruct the original byte streams from log data, as (most) of the context of the conversion from the byte stream to log records is saved now. (So, the only bits we still drop are empty lines. Which might be something to look into in a future change, and which is outside of the scope of this work) Fixes: https://bugs.freedesktop.org/show_bug.cgi?id=86465 See: systemd#4863 Replaces: systemd#4875
… it to 48K This adds a new setting LineMax= to journald.conf, and sets it by default to 48K. When we convert stream-based stdout/stderr logging into record-based log entries, read up to the specified amount of bytes before forcing a line-break. This also makes three related changes: - When a NUL byte is read we'll not recognize this as alternative line break, instead of silently dropping everything after it. (see systemd#4863) - The reason for a line-break is now encoded in the log record, if it wasn't a plain newline. Specifically, we distuingish "nul", "line-max" and "eof", for line breaks due to NUL byte, due to the maximum line length as configured with LineMax= or due to end of stream. This data is stored in the new implicit _LINE_BREAK= field. It's not synthesized for plain \n line breaks. - A randomized 128bit ID is assigned to each log stream. With these three changes in place it's (mostly) possible to reconstruct the original byte streams from log data, as (most) of the context of the conversion from the byte stream to log records is saved now. (So, the only bits we still drop are empty lines. Which might be something to look into in a future change, and which is outside of the scope of this work) Fixes: https://bugs.freedesktop.org/show_bug.cgi?id=86465 See: systemd#4863 Replaces: systemd#4875
… it to 48K (#6838) This adds a new setting LineMax= to journald.conf, and sets it by default to 48K. When we convert stream-based stdout/stderr logging into record-based log entries, read up to the specified amount of bytes before forcing a line-break. This also makes three related changes: - When a NUL byte is read we'll not recognize this as alternative line break, instead of silently dropping everything after it. (see #4863) - The reason for a line-break is now encoded in the log record, if it wasn't a plain newline. Specifically, we distuingish "nul", "line-max" and "eof", for line breaks due to NUL byte, due to the maximum line length as configured with LineMax= or due to end of stream. This data is stored in the new implicit _LINE_BREAK= field. It's not synthesized for plain \n line breaks. - A randomized 128bit ID is assigned to each log stream. With these three changes in place it's (mostly) possible to reconstruct the original byte streams from log data, as (most) of the context of the conversion from the byte stream to log records is saved now. (So, the only bits we still drop are empty lines. Which might be something to look into in a future change, and which is outside of the scope of this work) Fixes: https://bugs.freedesktop.org/show_bug.cgi?id=86465 See: #4863 Replaces: #4875
… it to 48K (systemd#6838) This adds a new setting LineMax= to journald.conf, and sets it by default to 48K. When we convert stream-based stdout/stderr logging into record-based log entries, read up to the specified amount of bytes before forcing a line-break. This also makes three related changes: - When a NUL byte is read we'll not recognize this as alternative line break, instead of silently dropping everything after it. (see systemd#4863) - The reason for a line-break is now encoded in the log record, if it wasn't a plain newline. Specifically, we distuingish "nul", "line-max" and "eof", for line breaks due to NUL byte, due to the maximum line length as configured with LineMax= or due to end of stream. This data is stored in the new implicit _LINE_BREAK= field. It's not synthesized for plain \n line breaks. - A randomized 128bit ID is assigned to each log stream. With these three changes in place it's (mostly) possible to reconstruct the original byte streams from log data, as (most) of the context of the conversion from the byte stream to log records is saved now. (So, the only bits we still drop are empty lines. Which might be something to look into in a future change, and which is outside of the scope of this work) Fixes: https://bugs.freedesktop.org/show_bug.cgi?id=86465 See: systemd#4863 Replaces: systemd#4875 (cherry picked from commit ec20fe5) Resolves: #1442262 [msekleta: I had to manually rewrite upstream commit, because git did very poor job merging old and new code and identified a lot of merge conflicts in a code that was totally unrelated.]
7 participants
Fixes:
https://bugs.freedesktop.org/show_bug.cgi?id=86465