[systemd-devel] systemd-journald doesn't follow max datagram length when forwarding messages to syslog

[Umut Tezduyar Lindskog]

On Wed, Aug 6, 2014 at 9:08 PM, Umut Tezduyar Lindskog
<umut at tezduyar.com> wrote:
> Hi,
>
> journald fails to forward messages to syslog when it is using
> Server->syslog_fd even before the limit of
> /proc/sys/net/unix/max_dgram_qlen is reached.
>
> For this experiment,
>
> 1) I have made sure /proc/sys/net/unix/max_dgram_qlen is set to 9999
> before syslog.socket is created.
> 2) Replaced rsyslog.service's ExecStart with /bin/sleep
> 3) Booted system and observed following messages:
>
> systemd-journal[434]: Forwarding to syslog missed 2 messages. (succeed
> 274 messages) [*]
> systemd-journal[434]: Forwarding to syslog missed 183 messages.
> (succeed 274 messages)
> systemd-journal[434]: Forwarding to syslog missed 41 messages.
> (succeed 274 messages)
>
> This got me interested since we are loosing messages and after further
> debugging I have come up with attached patch [**]. After booting up
> the system and filling up the journal with "systemd-cat echo hello",
> following correct behavior is observed.
>
> systemd-journal[449]: Forwarding to syslog missed 1 messages. (succeed
> 10000 messages)
>
> It is same hardware and clearly I have enough memory to store 1000
> messages. I can't explain why it would make a difference to use
> Server->syslog_fd vs a new socket fd but something is not right and
> hopefully someone can explain. Further, we can fix journal so we won't
> miss messages.

The problem is due to sending socket's SO_SNDBUF limit. My guess at
this point is the amount of messages you can queue to syslog socket is
determined by 3 factors. a) Sending socket's SO_SNDBUF b) Receiving
socket's SO_RCVBUF c) Global variable
/proc/sys/net/unix/max_dgram_qlen.

My workaround is adding SendBuffer=8M to
systemd-journald-dev-log.socket but I am not sure if the way we
account things is intuitive. My propose is passing
systemd-journald-dev-log.socket to systemd-journald so that
systemd-journald can forward messages to rsyslog through it. Or not
deal with this since newer rsyslog fetches logs.

References
https://git.kernel.org/cgit/linux/kernel/git/torvalds/linux.git/tree/net/unix/af_unix.c#n1445
http://vger.kernel.org/~davem/skb_sk.html

Umut


>
> Thank you
> Umut
>
>
> [*] The number 274 fluctuates a bit between boots and I patched
> journald to display how many messages have been sent to syslog.
> [**] Patch is only to show proof of concept and not optimized.