[systemd-devel] /dev/log tends to block on socket based activation ...

[Hoyer, Marko (ADITG/SW2)]

Hi,

Best regards

Marko Hoyer
Software Group II (ADITG/SW2)

Tel. +49 5121 49 6948
> -----Original Message-----
> From: Umut Tezduyar Lindskog [mailto:umut at tezduyar.com]
> Sent: Wednesday, August 06, 2014 10:38 AM
> To: Hoyer, Marko (ADITG/SW2)
> Cc: systemd-devel at lists.freedesktop.org
> Subject: Re: [systemd-devel] /dev/log tends to block on socket based
> activation ...
> 
> Hi,
> 
> On Wed, Aug 6, 2014 at 8:36 AM, Hoyer, Marko (ADITG/SW2) <mhoyer at de.adit-
> jv.com> wrote:
> > Good morning everyone,
> >
> >
> >
> > I’m playing around a bit with systemd’s socket based activation of
> > systemd-journald. My intention is to shift back in time the actual
> > startup of systemd-journald.service to save resources (CPU) for early
> > applications during startup. The respective socket is activated as
> > usual to not lose any early (sys)logs. The actual startup of the
> > service is delayed by adding some dependencies to targets (basic.target for
> instance).
> >
> >
> >
> > In principal, the idea is working as expected but sometimes the
> > logging via
> > syslog(“..”) blocks applications until the daemon is actually started.
> > Depending on how the startup of such application is integrated into
> > the startup configuration, this might lead to deadlock situations.
> >
> >
> >
> > Has anyone here any idea how one can prevent the blocking situation.
> >
> >
> >
> > Some observations:
> >
> > - The blocking situation is not happening on each syslog call,
> > sometimes this happens after one call, sometimes after a few calls. I
> > wasn’t able by now isolating the concrete case that leads to a
> > blocking socket
> >
> > - I doubt that the underlying socket buffer is full
> >
> > - The call is blocked by the kernel syscall send() that is invoked by
> > the
> > syslog() call
> >
> >
> >
> > Thx in advance for any hints …
> >
> >
> 
> syslog() is a sync call and on the other side of the syslog() socket is
> systemd-journald. If you deprioritize (or delay) systemd-journald, eventually
> socket holding syslog() (it is /dev/log ->
> /run/systemd/journal/dev-log) will get filled up and calls to syslog() will
> wait until systemd-journald empties the socket buffer.
> 
> The default limit for /dev/log is 10 messages (implementation is 10 + 1, so it
> actually stores 11 messages) and can be changed by a similar trick as I did on
> http://lists.freedesktop.org/archives/systemd-devel/2014-July/021536.html.
> In your case the socket you are interested in is systemd-journald-dev-
> log.socket.
> 
> Let me know how it goes.
> Umut
> 

That's exactly what I was searching for. I just started "systemtap"ing me into the kernel to find out
where I got blocked - you were faster. Thx a lot.

Btw: I agree with Kay that a kind of kernel configuration is needed (config parameter) and a per socket mechanism to override this value dynamically ...



However, I think this will work for me for now.

Cheers,
Marko