FS#40970 - [systemd] Units don't log their activity to the journal after systemd 214 upgrade

Attached to Project: Arch Linux
Opened by Davor Rotim (drot) - Wednesday, 25 June 2014, 11:04 GMT
Last edited by Dave Reisner (falconindy) - Friday, 04 July 2014, 13:43 GMT
Task Type Bug Report
Category Packages: Core
Status Closed
Assigned To Dave Reisner (falconindy)
Tom Gundersen (tomegun)
Architecture All
Severity High
Priority Normal
Reported Version
Due in Version Undecided
Due Date Undecided
Percent Complete 100%
Votes 5
Private No

Details

Description:
After upgrading to systemd 214 certain units like systemd-networkd or cups don't log their activity to the journal anymore (journalctl -u only shows entries before the systemd 214 update).

Additional info:
* package version(s)
systemd 214-2
3.15.1-1-ARCH i686

* config and/or log files etc.
journalctl -u systemd-journald.service: http://sprunge.us/LAUD
journalctl -u systemd-networkd.service: http://sprunge.us/CLgC
journalctl -u systemd-logind.service: http://sprunge.us/SHLU

Steps to reproduce:
I don't have reliable steps to reproduce this (besides upgrading to 214), but I did notice yesterday while doing a new install (with systemd 214 of course) that logging to journal worked normally at first (as you can see from the pasted logs) but then it somehow stopped after I set up systemd-networkd (before the connection was established with the dhcpcd.service).
This task depends upon

Closed by  Dave Reisner (falconindy)
Friday, 04 July 2014, 13:43 GMT
Reason for closing:  Not a bug
Additional comments about closing:  No evidence that this is anything but a user configuration issue. If there does turn out to be some tangible bug, please chase it down with upstream systemd.
Comment by Jan Alexander Steffens (heftig) - Wednesday, 25 June 2014, 11:39 GMT
Please check if regenerating the initrd (using "mkinitcpio -p linux" or similar) fixes the problem.
Comment by Davor Rotim (drot) - Wednesday, 25 June 2014, 12:33 GMT
Running mkinitcpio -p linux (and rebooting) with the following mkinitcpio.conf: http://sprunge.us/OYFg didn't fix the issue. Edit: I also don't get any notice when running systemctl enable <someunit>.
Comment by Stefan Tatschner (rumpelsepp) - Wednesday, 25 June 2014, 14:13 GMT Comment by AK (Andreaskem) - Wednesday, 25 June 2014, 16:09 GMT
Shot in the dark:
Ownership / permissions issue?
Who owns your /var/log/journal and its subfolders?
Does the systemd-journal group exist?
Comment by Davor Rotim (drot) - Wednesday, 25 June 2014, 16:19 GMT
http://sprunge.us/QKRD
pwck and grpck don't report any issues.
Comment by rewpqighpoqiuer (pekka) - Wednesday, 25 June 2014, 17:10 GMT
Confirm
Fresh install
" I also don't get any notice when running systemctl enable <someunit>."

Comment by Dave Reisner (falconindy) - Wednesday, 25 June 2014, 17:13 GMT
> " I also don't get any notice when running systemctl enable <someunit>."
This is entirely unrelated, and already "fixed" upstream.
Comment by AK (Andreaskem) - Wednesday, 25 June 2014, 17:14 GMT
A more complete journal including everything starting from boot (if necessary scrubbed of sensitive information) might help.
Comment by Stefan Tatschner (rumpelsepp) - Wednesday, 25 June 2014, 17:15 GMT
I have sent a journal to the mailing list but it has to be moderated.
   log (55.3 KiB)
Comment by AK (Andreaskem) - Wednesday, 25 June 2014, 17:23 GMT
"systemd 213 running in system mode. (+PAM -AUDIT -SELINUX -IMA -SYSVINIT +LIBCRYPTSETUP +GCRYPT +ACL +XZ +SECCOMP -APPARMOR)"

If there is an error with 214, a journal by 214 would be more helpful ;)

edit:
Wait...
"Jun 25 11:45:10 archvm systemd-udevd[179]: starting version 214"

Why is udev a different version?

edit 2:
Oh wait, virtualization. I'm an idiot. I also don't know how that might affect things, so I'm out, I guess. Sorry.
Comment by Dave Reisner (falconindy) - Wednesday, 25 June 2014, 17:30 GMT
> Why is udev a different version?
Because you didn't rebuild your initramfs after upgrading systemd.
Comment by Davor Rotim (drot) - Wednesday, 25 June 2014, 18:02 GMT
Deleted /var/log/journal and set Storage=volatile in journald.conf - same problem, then I tried setting it to persistent and now I can only see journalctl -b output if I'm root. Other than that the problem with logging still persists.

/etc/group: http://sprunge.us/KAZO
/etc/passwd: http://sprunge.us/GSeh
journalctl -b: http://sprunge.us/GYfc
Comment by Davor Rotim (drot) - Thursday, 26 June 2014, 16:18 GMT
I have done a fresh install today and immediately on first boot ran pwck and grpck. pwck reported no issues, while grpck reported that the following groups were missing from gshadow:

Jun 26 17:35:37 lambda grpck[185]: add group 'systemd-journal-gateway' to '/etc/gshadow'
Jun 26 17:35:39 lambda grpck[185]: add group 'systemd-timesync' to '/etc/gshadow'
Jun 26 17:35:40 lambda grpck[185]: add group 'systemd-network' to '/etc/gshadow'
Jun 26 17:35:42 lambda grpck[185]: add group 'systemd-bus-proxy' to '/etc/gshadow'
Jun 26 17:35:43 lambda grpck[185]: add group 'systemd-resolve' to '/etc/gshadow'
Comment by Dave Reisner (falconindy) - Thursday, 26 June 2014, 16:36 GMT
And if you run grpconv, does logging return?
Comment by Davor Rotim (drot) - Thursday, 26 June 2014, 16:50 GMT
Ran grpconv, still no luck.
Comment by Alex (aion) - Friday, 27 June 2014, 10:50 GMT
As I can see logging for these services performed to console.
Comment by Moviuro (Moviuro) - Wednesday, 02 July 2014, 12:04 GMT
I do have only part of the issue: only systemd-timesyncd doesn't log. However, when asking for debug, I get: http://sprunge.us/TRRh
I use systemd-networkd (no netctl whatsoever).

I don't get any feedback in 'journalctl -f' when # systemctl restart systemd-timesyncd.service
However, when # systemctl status systemd-timesyncd.service ; I do get the correct launch time (Active: active (running) since Wed 2014-07-02 14:01:25 CEST; 38s ago).

Arch x86_64
Comment by Stefan Tatschner (rumpelsepp) - Friday, 04 July 2014, 06:01 GMT
- Update to systemd 214
- reboot
- rebuild the initramdisk (mkinitcpio -p linux-lts, mkinitcpio -p linux)
- reboot
-> my problem was fixed

I always have rebuilt my initramdisk before rebooting; so my udev version was 213...
Comment by Dave Reisner (falconindy) - Friday, 04 July 2014, 13:43 GMT
> I always have rebuilt my initramdisk before rebooting; so my udev version was 213...
So when heftig suggested this 2 weeks ago...

Loading...