Re: [systemd-devel] How to guarantee the stdout buffer between systemd and journald is flushed when program quits?
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?
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] How to guarantee the stdout buffer between systemd and journald is flushed when program quits?
That's it. Yep, I can see it in the `journalctl` but it's not in `journalctl -u servicename` Thanks On 18 May 2018 at 11:44, Michael Biebl wrote: > 2018-05-17 23:02 GMT+02:00 Ivan Kurnosov : > > > Here is the example of the `journald` output for the service: > > I assume you used journalctl -u bla.service? > If so, do the log messages turn up if you run journalctl? > > Then this might be another instance of > https://github.com/systemd/systemd/issues/2913 > > -- > Why is it that all of the instruments seeking intelligent life in the > universe are pointed away from Earth? > -- 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-17 23:02 GMT+02:00 Ivan Kurnosov : > Here is the example of the `journald` output for the service: I assume you used journalctl -u bla.service? If so, do the log messages turn up if you run journalctl? Then this might be another instance of https://github.com/systemd/systemd/issues/2913 -- Why is it that all of the instruments seeking intelligent life in the universe are pointed away from Earth? ___ systemd-devel mailing list systemd-devel@lists.freedesktop.org https://lists.freedesktop.org/mailman/listinfo/systemd-devel
[systemd-devel] How to guarantee the stdout buffer between systemd and journald is flushed when program quits?
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? -- With best regards, Ivan Kurnosov ___ systemd-devel mailing list systemd-devel@lists.freedesktop.org https://lists.freedesktop.org/mailman/listinfo/systemd-devel