Re: [systemd-devel] How to guarantee the stdout buffer between systemd and journald is flushed when program quits?

2018-05-18 Thread Ivan Kurnosov 
I'm observing it on the ubuntu bionic that comes with systemd 237

On 19 May 2018 at 07:27, Lennart Poettering  wrote:

> On Fr, 18.05.18 09:02, Ivan Kurnosov (zer...@zerkms.ru) wrote:
>
> > Hi,
> >
> > I originally asked this question on the stackoverflow (
> > https://stackoverflow.com/q/50400145/251311) but I feel I wouldn't get
> an
> > answer there.
> >
> > The simplified example that demonstrates a problem is
> >
> > #include 
> >
> > int main(void)
> > {
> > printf("foo\n");
> > fflush(stdout);
> > getchar();
> > return 0;
> > }
> >
> > (it's not programming language specific though - the original
> application I
> > discovered the problem with is in Go).
> >
> > If it's compiled and is run by the following unit:
> >
> > [Unit]
> > Description=description
> > After=network.target
> >
> > [Service]
> > ExecStart=/path/to/binary
> >
> > [Install]
> > WantedBy=multi-user.target
> >
> > then on `systemctl restart` `journald` would in most cases not get the
> > `foo\n` output, while `syslog` successfully writes it down to the
> > `/var/log/syslog`.
> >
> > Here is the example of the `journald` output for the service:
> >
> > May 18 08:30:38 hostname systemd[1]: Stopped servicename
> > May 18 08:30:38 hostname systemd[1]: Started servicename
> > May 18 08:30:38 hostname systemd[1]: Stopped servicename
> > May 18 08:30:38 hostname systemd[1]: Started servicename
> > May 18 08:30:38 hostname servicename[7701]: foo
> > May 18 08:30:41 hostname systemd[1]: Stopped servicename
> > May 18 08:30:41 hostname systemd[1]: Started servicename
> > May 18 08:30:46 hostname systemd[1]: Stopped servicename
> > May 18 08:30:46 hostname systemd[1]: Started servicename
> >
> > and then the corresponding part of the `/var/log/syslog`:
> >
> > May 18 08:30:38 hostname systemd[1]: Stopped servicename.
> > May 18 08:30:38 hostname systemd[1]: Started servicename.
> > May 18 08:30:38 hostname servicename[7682]: foo
> > May 18 08:30:38 hostname systemd[1]: Stopped servicename.
> > May 18 08:30:38 hostname systemd[1]: Started servicename.
> > May 18 08:30:38 hostname servicename[7701]: foo
> > May 18 08:30:41 hostname systemd[1]: Stopped servicename.
> > May 18 08:30:41 hostname systemd[1]: Started servicename.
> > May 18 08:30:41 hostname servicename[7720]: foo
> > May 18 08:30:46 hostname systemd[1]: Stopped servicename.
> > May 18 08:30:46 hostname systemd[1]: Started servicename.
> > May 18 08:30:46 hostname servicename[7739]: foo
> >
> > What would be a way to **guarantee** journald received the `stdout`, if
> any?
>
> It is guaranteed that it wil get the data. However, you are probably
> running into this:
>
> https://github.com/systemd/systemd/issues/2913
>
> i.e. stuff that is logged right before a process exits might miss the
> metadata we need for "-u" to work correctly. The message itself is not
> lost though, you should see it if you drop the "-u"...
>
> The situation is improved a ton with systemd 235 where metadata is
> cached in journald if possible, which increases the chance we wil have
> the metadata around even if the sending process is already gone. It
> fixes most common cases, but there are still some cases around which
> aren't covered by that.
>
> hence, make sure to run 235 (or some release that backported the
> caching).
>
> Lennart
>
> --
> Lennart Poettering, Red Hat
>



-- 
With best regards, Ivan Kurnosov
___
systemd-devel mailing list
systemd-devel@lists.freedesktop.org
https://lists.freedesktop.org/mailman/listinfo/systemd-devel

Re: [systemd-devel] How to guarantee the stdout buffer between systemd and journald is flushed when program quits?

2018-05-18 Thread Lennart Poettering 
On Fr, 18.05.18 09:02, Ivan Kurnosov (zer...@zerkms.ru) wrote:

> Hi,
> 
> I originally asked this question on the stackoverflow (
> https://stackoverflow.com/q/50400145/251311) but I feel I wouldn't get an
> answer there.
> 
> The simplified example that demonstrates a problem is
> 
> #include 
> 
> int main(void)
> {
> printf("foo\n");
> fflush(stdout);
> getchar();
> return 0;
> }
> 
> (it's not programming language specific though - the original application I
> discovered the problem with is in Go).
> 
> If it's compiled and is run by the following unit:
> 
> [Unit]
> Description=description
> After=network.target
> 
> [Service]
> ExecStart=/path/to/binary
> 
> [Install]
> WantedBy=multi-user.target
> 
> then on `systemctl restart` `journald` would in most cases not get the
> `foo\n` output, while `syslog` successfully writes it down to the
> `/var/log/syslog`.
> 
> Here is the example of the `journald` output for the service:
> 
> May 18 08:30:38 hostname systemd[1]: Stopped servicename
> May 18 08:30:38 hostname systemd[1]: Started servicename
> May 18 08:30:38 hostname systemd[1]: Stopped servicename
> May 18 08:30:38 hostname systemd[1]: Started servicename
> May 18 08:30:38 hostname servicename[7701]: foo
> May 18 08:30:41 hostname systemd[1]: Stopped servicename
> May 18 08:30:41 hostname systemd[1]: Started servicename
> May 18 08:30:46 hostname systemd[1]: Stopped servicename
> May 18 08:30:46 hostname systemd[1]: Started servicename
> 
> and then the corresponding part of the `/var/log/syslog`:
> 
> May 18 08:30:38 hostname systemd[1]: Stopped servicename.
> May 18 08:30:38 hostname systemd[1]: Started servicename.
> May 18 08:30:38 hostname servicename[7682]: foo
> May 18 08:30:38 hostname systemd[1]: Stopped servicename.
> May 18 08:30:38 hostname systemd[1]: Started servicename.
> May 18 08:30:38 hostname servicename[7701]: foo
> May 18 08:30:41 hostname systemd[1]: Stopped servicename.
> May 18 08:30:41 hostname systemd[1]: Started servicename.
> May 18 08:30:41 hostname servicename[7720]: foo
> May 18 08:30:46 hostname systemd[1]: Stopped servicename.
> May 18 08:30:46 hostname systemd[1]: Started servicename.
> May 18 08:30:46 hostname servicename[7739]: foo
> 
> What would be a way to **guarantee** journald received the `stdout`, if any?

It is guaranteed that it wil get the data. However, you are probably
running into this:

https://github.com/systemd/systemd/issues/2913

i.e. stuff that is logged right before a process exits might miss the
metadata we need for "-u" to work correctly. The message itself is not
lost though, you should see it if you drop the "-u"...

The situation is improved a ton with systemd 235 where metadata is
cached in journald if possible, which increases the chance we wil have
the metadata around even if the sending process is already gone. It
fixes most common cases, but there are still some cases around which
aren't covered by that.

hence, make sure to run 235 (or some release that backported the
caching).

Lennart

-- 
Lennart Poettering, Red Hat
___
systemd-devel mailing list
systemd-devel@lists.freedesktop.org
https://lists.freedesktop.org/mailman/listinfo/systemd-devel

Re: [systemd-devel] option to wait for pid file to appear

2018-05-18 Thread Lennart Poettering 
On Do, 17.05.18 22:54, Igor Bukanov (i...@mir2.org) wrote:

> On 17 May 2018 at 19:23, Lennart Poettering  wrote:
> 
> > So yes, this is a bug in nginx. They really should fix that. And this
> > is not only broken when you use systemd, but on sysvinit too, as a
> > command like this would likely fail there too: "service nginx start
> > service nginx status", as the start would return before the PID file
> > is written, and then status would claim the service to be down...
> 
> Given that systemd deals with this situation in a very reasonable way,
> nginx must not be alone in doing this. And if this a common way to
> write such code, perhaps it should not be considered a bug but rather
> one more peculiarity of application services the service manager
> should deal

Well, no. The protocol is clear, and what we do is pretty close to
black magic, and still racy in many ways.

I mean, broken behaviour is still broken behaviour, even if we
nowadays handle it pretty nicely. Really, nginx should be fixed,
everybody benefits, sysvinit as much as we do.

Or, to turn this around: if nginx is happy that all only works
somewhat reliably on systemd systems, then they might as well just do
this properly, and rework this to Type=notify. Because right now,
systemd can deal with the broken behaviour, but *only* systemd really
can, and this will trip up on other systems, such as sysvinit or
upstart.

Lennart

-- 
Lennart Poettering, Red Hat
___
systemd-devel mailing list
systemd-devel@lists.freedesktop.org
https://lists.freedesktop.org/mailman/listinfo/systemd-devel

Re: [systemd-devel] option to wait for pid file to appear

2018-05-18 Thread Ian Pilcher 

On 05/17/2018 03:54 PM, Igor Bukanov wrote:

Given that systemd deals with this situation in a very reasonable way,
nginx must not be alone in doing this. And if this a common way to
write such code, perhaps it should not be considered a bug but rather
one more peculiarity of application services the service manager
should deal


IIRC, the Python daemon library does this.

--

Ian Pilcher arequip...@gmail.com
 "I grew up before Mark Zuckerberg invented friendship" 


___
systemd-devel mailing list
systemd-devel@lists.freedesktop.org
https://lists.freedesktop.org/mailman/listinfo/systemd-devel