[systemd-devel] [PATCH 2/2] journald: when buffering stdout, allow buffer to grow if needed

[Zbigniew Jędrzejewski-Szmek]

On Sun, Dec 08, 2013 at 11:32:34AM -0600, Dan McGee wrote:
> When logging really long lines (e.g. those without an '\n') to journald
> via capture of stdout, the hardcoded buffer length of LINE_MAX limited
> us to processing the data in 2KB chunks. This is rather inefficient if
> we are getting a 1+ MB message handed to us.
> 
> Actual case is via a unit file where PostgreSQL logs via stdout and
> emits slow query logs. When the slow query is a long multi-row insert
> statement, it can often be a megabyte or more of text. Rather than
> process this as one message and going down the stack to the compression
> code just once, we were doing it for each and every 2K read() call.
> ---
> 
> As stated in the prior patch, if there is some preexisting dynamic buffer stuff
> I should be using, please let me know.
See below.
 
> Here is a brief test script that stresses the stdout capture. Run it through
> systemd-run and watch the CPU usage of the systemd-journal process before and
> after.
> 
> #!/usr/bin/env python2
> 
> data = []
> for i in range(1000):
>     data.append('abcdefghijklmnopqrstuvwxyz')
>     data.append('%d' % i)
> 
> print ' '.join(data * 5)
> print ' '.join(data * 15)
> print ' '.join(data * 25)
> 
> 
>  src/journal/journald-stream.c | 19 ++++++++++++++++++-
>  1 file changed, 18 insertions(+), 1 deletion(-)
> 
> diff --git a/src/journal/journald-stream.c b/src/journal/journald-stream.c
> index 193d438..890c0bf 100644
> --- a/src/journal/journald-stream.c
> +++ b/src/journal/journald-stream.c
> @@ -236,6 +236,8 @@ static int stdout_stream_line(StdoutStream *s, char *p) {
>          assert_not_reached("Unknown stream state");
>  }
>  
> +#define STDOUT_BUFFER_MAX 256*1024u
> +
>  static int stdout_stream_scan(StdoutStream *s, bool force_flush) {
>          char *p;
>          size_t remaining;
> @@ -253,7 +255,22 @@ static int stdout_stream_scan(StdoutStream *s, bool force_flush) {
>                  if (end)
>                          skip = end - p + 1;
>                  else if (remaining >= s->size - 1) {
We have GREEDY_REALLOC which wraps the realloc() with exponential increase of size.
It doesn't test for maximum size, so you'll still have to do that.

> -                        /* ran out of buffer space, log what we have */
> +                        /* grow buffer up to max permitted size if possible; if
> +                         * we fail to alloc just use the old buffer. */
> +                        if (s->size < STDOUT_BUFFER_MAX) {
> +                            char *new_buffer;
> +                            size_t new_size;
> +
> +                            new_size = MIN(s->size * 2, STDOUT_BUFFER_MAX);
> +                            new_buffer = realloc(s->buffer, new_size);
> +                            if (new_buffer) {
> +                                p = new_buffer + (p - s->buffer);
> +                                memset(&new_buffer[s->size], 0, new_size-s->size);
I hope zeroing the buffer is not necessary. We should always know what
parts of it are filled.

> +                                s->size = new_size;
> +                                s->buffer = new_buffer;
> +                            }
> +                            break;
> +                        }
>                          end = s->buffer + s->size - 1;
>                          skip = remaining;
>                  } else

Zbyszek