[systemd-devel] journalctl --sync blocks when some app intensively log to stdout

[Belisko Marek]

Hi,

I have an application which print bit often to log (every 500ms) and
when ap is started by systemd and try to perform journalctl --sync (I
don't have persistent flag in conf set so it should sync on /tmp
AFAIU) it blocks with this trace:

getpid()                                = 2571
getpid()                                = 2571
clock_gettime(CLOCK_MONOTONIC, {tv_sec=3813, tv_nsec=915577000}) = 0
ppoll([{fd=3, events=POLLIN}], 1, {tv_sec=24, tv_nsec=995165000},
NULL, 8) = 1 ([{fd=3, revents=POLLIN}], left {tv_sec=24,
tv_nsec=982606806})
getpid()                                = 2571
clock_gettime(CLOCK_MONOTONIC, {tv_sec=3813, tv_nsec=928915925}) = 0
recvmsg(3, {msg_name=NULL, msg_namelen=0, msg_iov=[{iov_base="OK
6e2e8cbedf9644b5b5558f89be197"..., iov_len=256}], msg_iovlen=1,
msg_controllen=0, msg_flags=MSG_CMSG_CLOEXEC},
MSG_DONTWAIT|MSG_NOSIGNAL|MSG_CMSG_CLOEXEC) = 52
getpid()                                = 2571
sendmsg(3, {msg_name=NULL, msg_namelen=0,
msg_iov=[{iov_base="l\1\0\0010\0\0\0\1\0\0\0\241\0\0\0\1\1o\0\31\0\0\0/org/fre"...,
iov_len=184}, {iov_base="\30\0\0\0systemd-journald.service\0\0\0\0"...,
iov_len=48}], msg_iovlen=2, msg_controll2
clock_gettime(CLOCK_MONOTONIC, {tv_sec=3813, tv_nsec=929704948}) = 0
recvmsg(3, {msg_namelen=0},
MSG_DONTWAIT|MSG_NOSIGNAL|MSG_CMSG_CLOEXEC) = -1 EAGAIN (Resource
temporarily unavailable)
clock_gettime(CLOCK_MONOTONIC, {tv_sec=3813, tv_nsec=929976080}) = 0
getpid()                                = 2571
ppoll([{fd=3, events=POLLIN}], 1, {tv_sec=24, tv_nsec=999728000},
NULL, 8) = 1 ([{fd=3, revents=POLLIN}], left {tv_sec=24,
tv_nsec=984302182})
recvmsg(3, {msg_name=NULL, msg_namelen=0,
msg_iov=[{iov_base="l\2\1\1\0\0\0\0\1\0\0\0\10\0\0\0\5\1u\0\1\0\0\0",
iov_len=24}], msg_iovlen=1, msg_controllen=0,
msg_flags=MSG_CMSG_CLOEXEC},
MSG_DONTWAIT|MSG_NOSIGNAL|MSG_CMSG_CLOEXEC) = 24
openat(AT_FDCWD, "/run/systemd/journal/synced",
O_RDONLY|O_LARGEFILE|O_CLOEXEC) = -1 ENOENT (No such file or
directory)
stat64("/run/systemd", {st_mode=S_IFDIR|0755, st_size=380, ...}) = 0
mkdir("/run/systemd/journal", 0755)     = -1 EEXIST (File exists)
stat64("/run/systemd/journal", {st_mode=S_IFDIR|0755, st_size=180, ...}) = 0
inotify_init1(IN_NONBLOCK|IN_CLOEXEC)   = 4
inotify_add_watch(4, "/run/systemd/journal",
IN_MOVED_TO|IN_ONLYDIR|IN_DONT_FOLLOW) = 1
openat(AT_FDCWD, "/run/systemd/journal/synced",
O_RDONLY|O_LARGEFILE|O_CLOEXEC) = -1 ENOENT (No such file or
directory)
ppoll([{fd=4, events=POLLIN}], 1, NULL, NULL, 8

and it blocks forever. I was looking into a similar issue:
https://github.com/systemd/systemd/pull/1848 but this part is already
included in the systemd we're using (v234) and it's about persistent
logging. Any ideas on what we can check or what can cause this
behavior?

Thanks and BR,

marek

-- 
as simple and primitive as possible
-------------------------------------------------
Marek Belisko - OPEN-NANDRA
Freelance Developer

Ruska Nova Ves 219 | Presov, 08005 Slovak Republic
Tel: +421 915 052 184
skype: marekwhite
twitter: #opennandra
web: http://open-nandra.com