journald is unable to attribute messages incoming from processes that exited to their cgroup, due to /proc vs SCM_CREDS race #2913
Description
- Bug report
systemd 229
+PAM -AUDIT -SELINUX -IMA -APPARMOR +SMACK -SYSVINIT +UTMP +LIBCRYPTSETUP
+GCRYPT +GNUTLS +ACL +XZ +LZ4 +SECCOMP +BLKID +ELFUTILS +KMOD +IDN
[Arch Linux] It looks like journalctl --user-unit=... is dropping log lines that happen immediately before a user job exits. Note that I was only able to repro this with user jobs; system jobs don't seem to have this problem.
I create ~/.config/systemd/user/test.service with the following:
[Service]
ExecStart=/usr/bin/bash -c "echo before sleep; sleep 0.1; echo after sleep"
In one terminal I run journalctl --user-unit=test.service --follow. In another terminal, I run (a bunch of times) systemctl --user start test.service.
EXPECTED: I should see both before sleep and after sleep in the output of journalctl.
ACTUAL: I only see before sleep.
Here's what shows up in the -o verbose logs:
Tue 2016-03-29 20:41:14.671948 EDT [s=e9568fd8d1454a3980cda3097f710645;i=152f1f;b=21d5a26bac4b44a89e22b5cc7622f804;m=ab73464fe0;t=52f3967343f4c;x=74e3c7d0a425d757]
_TRANSPORT=stdout
PRIORITY=6
_UID=1000
_GID=1000
_CAP_EFFECTIVE=0
_SYSTEMD_OWNER_UID=1000
_SYSTEMD_SLICE=user-1000.slice
_MACHINE_ID=513a1e851c594baaaeefc79eca7fb0ab
_HOSTNAME=arch-host
SYSLOG_FACILITY=3
[email protected]
_BOOT_ID=21d5a26bac4b44a89e22b5cc7622f804
_EXE=/usr/bin/bash
SYSLOG_IDENTIFIER=bash
_COMM=bash
_SYSTEMD_CGROUP=/user.slice/user-1000.slice/[email protected]/test.service
_SYSTEMD_USER_UNIT=test.service
MESSAGE=before sleep
_PID=3818
_CMDLINE=/usr/bin/bash -c echo before sleep; sleep 0.1; echo after sleep
Tue 2016-03-29 20:41:14.772507 EDT [s=e9568fd8d1454a3980cda3097f710645;i=152f20;b=21d5a26bac4b44a89e22b5cc7622f804;m=ab7347d8af;t=52f396735c81b;x=eb4c5410c92a5ef4]
_TRANSPORT=stdout
PRIORITY=6
_UID=1000
_GID=1000
_CAP_EFFECTIVE=0
_MACHINE_ID=513a1e851c594baaaeefc79eca7fb0ab
_HOSTNAME=arch-host
SYSLOG_FACILITY=3
_SYSTEMD_CGROUP=/
_SYSTEMD_SLICE=-.slice
_BOOT_ID=21d5a26bac4b44a89e22b5cc7622f804
SYSLOG_IDENTIFIER=bash
_COMM=bash
_PID=3818
MESSAGE=after sleep
Note that _SYSTEMD_USER_UNIT is not defined for the second message.