Is there a better way for syncing journal files to disk?

I think

systemctl kill --signal SIGUSR1 --kill-who main systemd-journald.service; sleep 1

is ugly:)

/cc @poettering

@evverx yeah, there is "journalctl --flush", which waits for the flush to complete... But I figure you found that too, by now?

I am a bit confused by the order here... as the original message was updated after some of the comments, right? Patch looks good to me now, everybody else OK with this too?

Regarding /bin/sh vs. /bin/bash: I personally don't really believe in Debian's usage of "dash"... it sounds like an additional source of bugs for no real gain, but well..

Either way, I'd merge it with either /bin/bash or /bin/sh as long as the semaphore thing builds... On my systems both are the same anyway, and i am sure that folks who run into problems with it, will yell if it does break things...

Anyway, would be good to get feedback from @ronnychevalier, @martinpitt as @evverx requested, before we merge this.

@evverx yeah, there is "journalctl --flush", which waits for the flush to complete... But I figure you found that too, by now?

I don't understand. Why do you change journalctl --flush with sending SIGUSR1?

--flush checks /run/systemd/journal/flushed and exits (it doesn't send SIGUSR1 to systemd-journald)

I need a server_sync. I force it with the direct sending SIGUSR1 to the systemd-journald.

BTW

Regarding /bin/sh vs. /bin/bash: I personally don't really believe in Debian's usage of "dash"

https://wiki.ubuntu.com/DashAsBinSh

In Ubuntu 6.10, the default system shell, /bin/sh, was changed to dash (the Debian Almquist Shell); previously it had been bash (the GNU Bourne-Again Shell). The same change will affect users of Ubuntu 6.06 LTS upgrading directly to Ubuntu 8.04 LTS. This document explains this change and what you should do if you encounter problems.

https://wiki.debian.org/Shell

Up to DebianLenny, the default /bin/sh shell was bash. Starting with DebianSqueeze, the default shell will be dash

Hmm, @poettering since you added this feature, why this file is not removed afterward? Or maybe, this switch is meant to be used only once? (which would be contradictory with what the man page says) because nowhere in the journal we remove this file, so after systemd-journal-flush, journalctl --flush becomes a no-op.

Or maybe i'm missing something?

hmm?

"journalctl --flush" is about flushing the journal data from /run to /var, which is really a one-time operation. The command only sends a SIGUSR1 when invoked the first time. If the flush already took place it becomes a NOOP. As such it is idempotent: whenever you run it, you can be sure that afterwards the log data is in /var, if things are configured that way.

@evverx what precisely are you looking for? just a way to get the journal files into a clean state? There's no nice way for this, all ways are necessarily racy, since any log message will immediately cause the files to be marked dirty again...

What's precisely needed here? what exactly do you want journald to do for you?

Ok, just a misunderstanding from my part, thanks :)

@evverx what precisely are you looking for?

I want sync the journal before shutdown.

If I have a journalctl --flush in the end.service

$ cd test/TEST-01-BASIC/
$ sudo make clean setup run
...
$ cat .testdir
TESTDIR="/var/tmp/systemd-test.xERhYs"
LOOPDEV=/dev/loop4

$ sudo journalctl -D /var/tmp/systemd-test.xERhYs/nspawn-root/var/log/journal -u testsuite.service
-- Logs begin at Mon 2015-11-09 17:32:38 UTC, end at Mon 2015-11-09 17:32:38 UTC. --
Nov 09 17:32:38 systemd-testsuite systemd[1]: testsuite.service: About to execute: /bin/bash -c 'set -x; systemctl --failed --no-legend --no-pager > /failed ; echo OK > /testok;'
Nov 09 17:32:38 systemd-testsuite systemd[1]: testsuite.service: Forked /bin/bash as 33
Nov 09 17:32:38 systemd-testsuite systemd[1]: testsuite.service: Changed dead -> start
Nov 09 17:32:38 systemd-testsuite systemd[1]: Starting Testsuite service...
Nov 09 17:32:38 systemd-testsuite systemd[1]: testsuite.service: Child 33 belongs to testsuite.service
Nov 09 17:32:38 systemd-testsuite systemd[1]: testsuite.service: Main process exited, code=exited, status=0/SUCCESS
Nov 09 17:32:38 systemd-testsuite systemd[1]: testsuite.service: Changed start -> dead
Nov 09 17:32:38 systemd-testsuite systemd[1]: testsuite.service: Job testsuite.service/start finished, result=done
Nov 09 17:32:38 systemd-testsuite systemd[1]: Started Testsuite service.
Nov 09 17:32:38 systemd-testsuite systemd[1]: testsuite.service: cgroup is empty

Should be (note bash[34] + part)

-- Logs begin at Mon 2015-11-09 17:34:25 UTC, end at Mon 2015-11-09 17:34:26 UTC. --
Nov 09 17:34:25 systemd-testsuite systemd[1]: testsuite.service: About to execute: /bin/bash -c 'set -x; systemctl --failed --no-legend --no-pager > /failed ; echo OK > /testok;'
Nov 09 17:34:25 systemd-testsuite systemd[1]: testsuite.service: Forked /bin/bash as 34
Nov 09 17:34:25 systemd-testsuite systemd[1]: testsuite.service: Changed dead -> start
Nov 09 17:34:25 systemd-testsuite systemd[1]: Starting Testsuite service...
Nov 09 17:34:25 systemd-testsuite systemd[1]: testsuite.service: Child 34 belongs to testsuite.service
Nov 09 17:34:25 systemd-testsuite systemd[1]: testsuite.service: Main process exited, code=exited, status=0/SUCCESS
Nov 09 17:34:25 systemd-testsuite systemd[1]: testsuite.service: Changed start -> dead
Nov 09 17:34:25 systemd-testsuite systemd[1]: testsuite.service: Job testsuite.service/start finished, result=done
Nov 09 17:34:25 systemd-testsuite systemd[1]: Started Testsuite service.
Nov 09 17:34:25 systemd-testsuite systemd[1]: testsuite.service: cgroup is empty
Nov 09 17:34:25 systemd-testsuite systemd[1]: testsuite.service: Failed to send unit change signal for testsuite.service: Transport endpoint is not connected
Nov 09 17:34:25 systemd-testsuite bash[34]: + systemctl --failed --no-legend --no-pager
Nov 09 17:34:25 systemd-testsuite bash[34]: Sent message type=method_call sender=n/a destination=org.freedesktop.systemd1 object=/org/freedesktop/systemd1 interface=org.freedesktop.systemd1.Manager member
Nov 09 17:34:25 systemd-testsuite bash[34]: Got message type=method_return sender=n/a destination=n/a object=n/a interface=n/a member=n/a cookie=1 reply_cookie=1 error=n/a
Nov 09 17:34:25 systemd-testsuite bash[34]: + echo OK

I mean, I want 'save' stderr and stdout of the testsuite.service.

let me get this right. All you want to do is ensure that the journal picked up everything written to stdout/stderr of testsuite.serivce and wrote it to disk? i.e. an operation one could well describe as a "sync"? Why precisely do you need this? I mean, when shutting down, we'll sync things anyway... why does that not suffice?

I figure to support this properly we could intrdouce a new flag file "/run/systemd/journal/sync" or so that is touched each time systemd has synced all files to disk. Then, let's add a new sync signal to journald (for example SIGRTMIN+1), which will result in a sync of all files, and thus the date being updated on /run/systemd/journal/sync. If all files where already synced it would nonetheless touch the sync file. Then, in journalctl let's add a new --sync verb: it would get the current time, send the signal, and then wait with inotify until the mtime of the sync file is newer than the time it sent the signal.

That way by invoking "journalctl --sync" we'd have reliable way to know that everything that was logged before invoking it has hit the disk, after it returns.

@evverx does that make sense to you?

I mean, when shutting down, we'll sync things anyway... why does that not suffice?

I don't know why but it doesn't work for me. I always lose the output of the testsuite.service.

Hm,
journald calls server_done, server_done calls stdout_stream_free, stdout_stream_free calls safe_close, safe_close calls close. No one call fsync (or, maybe I'm missing something:))

That way by invoking "journalctl --sync" we'd have reliable way to know that everything that was logged before invoking it has hit the disk, after it returns.

@evverx does that make sense to you?

Yes.

I figure to support this properly we could intrdouce a new flag file "/run/systemd/journal/sync" or so that is touched each time systemd has synced all files to disk. Then, let's add a new sync signal to journald (for example SIGRTMIN+1), which will result in a sync of all files, and thus the date being updated on /run/systemd/journal/sync

There is an option SyncIntervalSec=:

The timeout before synchronizing journal files to disk. After syncing, journal files are placed in the OFFLINE state. Note that syncing is unconditionally done immediately after a log message of priority CRIT, ALERT or EMERG has been logged. This setting hence applies only to messages of the levels ERR, WARNING, NOTICE, INFO, DEBUG. The default timeout is 5 minutes.

Will it update /run/systemd/journal/sync too?

Anyway, journalctl --sync is a separate issue.

systemctl kill --signal SIGUSR1 --kill-who main systemd-journald.service; sleep 1 works fine (it forces fsync).

We can replace it later.

@evverx i just posted PR #1835 which should ensure we process all queued log messages before exiting. This should make the whole explicit syncing unnecessary. Does that work for you?

I rebased my commit on your branch, removed syncing, run make clean setup run && check-testsuite-output 10 times. My test passed.

@poettering , yes, that works for me. Thanks!

OK, merged this one now. Of course, this will only be complete if #1835 is merged too.

@evverx btw, I implemented a "journalctl --sync" now in PR #1848. Of course, we don't need this anymore for the tests, but I figured it's a good thing to have anyway.

@poettering , thanks. I'll take a look.