[solved] journald doesn't record boot logs

nesk · 2017-10-06 17:13:25

I did several reboots today (and one power cycle, just to be sure), but:

# journalctl --list-boots
-5 0eadc1402ebf415db90f5e7d37e12dfd Mon 2017-07-17 13:04:39 MSK—Mon 2017-07-17 13:52:22 MSK
-4 8fc32c01a30545f2bc2a93b585c3cd0b Mon 2017-07-17 13:52:44 MSK—Tue 2017-07-25 11:57:03 MSK
-3 22992e7c18f54e01a3ff2dd8cb2e3fed Thu 2017-08-03 12:18:32 MSK—Thu 2017-08-03 20:22:12 MSK
-2 1779528ef3a046f2a09b94549df35e49 Thu 2017-08-03 20:22:35 MSK—Sat 2017-08-05 10:00:12 MSK
-1 c61e21e665de49dd80982adc2eb4faa1 Sat 2017-08-05 11:09:31 MSK—Mon 2017-08-07 12:44:12 MSK
 0 e850afe2544745a0a50058f6773e4555 Fri 2017-10-06 20:02:21 MSK—Fri 2017-10-06 20:05:38 MSK
# journalctl --verify
PASS: /run/log/journal/b6b4ab29a58b486a803dfb751f2caca6/system.journal                                                                                             
PASS: /var/log/journal/b6b4ab29a58b486a803dfb751f2caca6/system.journal
# egrep -v "^#" /etc/systemd/journald.conf 
[Journal]
Storage=persistent
SystemMaxUse=5G
#

So, journald does not record boots since August? Why? How to fix this?

P.S. Can't create topics in Administration, don't know why, so posting here.

Last edited by nesk (2017-10-10 17:38:23)

berbae · 2017-10-07 09:05:08

Something is wrong with your installation: you should get more output from 'journalctl --verify' (all the rotated old journal files are missing),
and the volatile /run/log/journal/... should no longer be there.
Verify the partition where /var is mounted.

nesk · 2017-10-07 11:16:52

Verified - partition is clean.

seth · 2017-10-07 11:29:38

ls -l /run/log/journal/b6b4ab29a58b486a803dfb751f2caca6 /var/log/journal/b6b4ab29a58b486a803dfb751f2caca6

nesk · 2017-10-07 11:30:55

# ls -l /run/log/journal/b6b4ab29a58b486a803dfb751f2caca6 /var/log/journal/b6b4ab29a58b486a803dfb751f2caca6
/run/log/journal/b6b4ab29a58b486a803dfb751f2caca6:
total 3840
-rw-r-----+ 1 root systemd-journal 3932160 Oct  7 14:24 system.journal

/var/log/journal/b6b4ab29a58b486a803dfb751f2caca6:
total 24580
-rw-r-----+ 1 root systemd-journal 25165824 Aug  7 12:44 system.journal

x33a · 2017-10-07 12:08:33

Looks like the logs aren't being written to /var/log/journal since August.

What's the output of

# journalctl --flush

seth · 2017-10-07 12:17:13

If that's unsuspicious, and if /var is a mountpoint, umount /var and see whether the directory contains your old logs...

nesk · 2017-10-07 14:41:55

x33a wrote:

What's the output of
# journalctl --flush

Not much:

# journalctl --flush
# echo $?
0

seth wrote:

If that's unsuspicious, and if /var is a mountpoint, umount /var and see whether the directory contains your old logs...

No, /var is not a mount point, just a directory under /

seth · 2017-10-07 19:25:45

My best guess is to try to halt the system (instead of a powerdown) and see whether there're error messages in the shutdown process (iff you're still not getting journals archieved)

nesk · 2017-10-07 21:15:19

seth wrote:

My best guess is to try to halt the system (instead of a powerdown) and see whether there're error messages in the shutdown process (iff you're still not getting journals archieved)

The only error I get at halt is "A stop job is running for session c2 of user username". I'm trying to diagnose that error by getting more detailed logs from past boots, hence this thread.
Is there a way to cleanup the journal completely and start clean? I don't care about past logs. journalctl --vaccuum-time=1d didn't do anything, those Aug boots are still listed by journalctl --list-boots.

Last edited by nesk (2017-10-07 21:15:39)

seth · 2017-10-07 21:46:12

Recent problem?
https://bbs.archlinux.org/viewtopic.php … 3#p1739553 ?
(Check present dmesg)

nesk · 2017-10-08 08:29:53

seth wrote:

Recent problem?

No, I had this problem for a while, just got around to fixing it now. I used to blame it on pam_mount failing to unmount my encrypted partition on shutdown, but after removing all pam_mount stuff from PAM configs it's clear this error is from something else.

seth wrote:

https://bbs.archlinux.org/viewtopic.php … 3#p1739553 ?
(Check present dmesg)

Seems completely unrelated - I don't have those backtraces in dmesg, I don't use netctl (NetworkManager instead) and my shutdowns are successful ("A stop job is running for session c2 of user username" has a countdown of 1 min 29 sec, after which shutdown process proceeds as normal).

seth · 2017-10-08 10:03:58

Is it *literally* "user username"??

nesk · 2017-10-08 10:05:10

seth wrote:

Is it *literally* "user username"??

Yes. Generic is the new original

seth · 2017-10-08 12:47:58

(Your username is "username"??? ;-)

This is related to your actual session - I assume it does only happend when shutting down from the session, not when exiting the session and shutting down from the DM?
Something on session shutdown is then either waiting for IO (network?) or user input - and running into a 90 second timeout.
=> What session and does it happen when shutting down from the DM?

(ftr. this is also a superpoular bug in systemd)

nesk · 2017-10-08 12:58:42

seth wrote:

(Your username is "username"??? ;-)
This is related to your actual session - I assume it does only happend when shutting down from the session, not when exiting the session and shutting down from the DM?

Yes.
Shutdown is performed from LXQT session by going to terminal and running "systemctl poweroff".

seth wrote:

Something on session shutdown is then either waiting for IO (network?) or user input - and running into a 90 second timeout.
=> What session and does it happen when shutting down from the DM?

All I see at shutdown is this terse message ("A stop job is running for session c2 of user username"). I thought I could get more details by reviewing logs of past boots. GOTO OP

seth wrote:

(ftr. this is also a superpoular bug in systemd)

I'm aware, google throws up a gazillion results, I haven't found anything conclusive.

seth · 2017-10-08 13:24:54

The idea was to exit the session first - notably if you "kill" it by shutting down the system ...
If this doesn't happen then, look for a better way to "exit session & shutdown" so lxqt can do its stuff before the shutdown.

nesk · 2017-10-08 14:39:32

Let's get back to journald issue.

Is there a way to cleanup the journal completely and start clean? I don't care about past logs. journalctl --vaccuum-time=1d didn't do anything, those Aug boots are still listed by journalctl --list-boots.

seth · 2017-10-08 14:49:55

/var/log/journal/*/system.journal won't be touched and you don't have other copies.

Also I assume the problems are related:
1) you got trouble with your shutdown
2) your journal isn't archived at shutdown

berbae · 2017-10-08 15:34:07

nesk wrote:

Is there a way to cleanup the journal completely and start clean?

I suggest this process:
temporarily set 'Storage=volatile' in journald.conf and restart the journal or reboot,
remove /var/log/journal completely (or rename it if you prefer),
recreate it with:

# mkdir -p /var/log/journal
# systemd-tmpfiles --create --prefix /var/log/journal

set back 'Storage=persistent' in journald.conf and reboot.
Be sure you have available space in the partition, you can verify with:
df -h

nesk · 2017-10-08 15:47:45

berbae wrote:

nesk wrote:
Is there a way to cleanup the journal completely and start clean?
I suggest this process:
temporarily set 'Storage=volatile' in journald.conf and restart the journal or reboot,
remove /var/log/journal completely (or rename it if you prefer),
recreate it with:
# mkdir -p /var/log/journal
# systemd-tmpfiles --create --prefix /var/log/journal
set back 'Storage=persistent' in journald.conf and reboot.
Be sure you have available space in the partition, you can verify with:
df -h

Thanks. After this it seems journald doesn't want to store journals anymore (I made sure 'Storage=persistent' in journald.conf). Rebooted 2 times, journalctl --list-boots shows only current boot.

# nano /etc/systemd/journald.conf
# systemctl restart systemd-journald.service                                                                                                                                              
# systemctl status systemd-journald.service                                                                                                                                                
● systemd-journald.service - Journal Service                                                                                                                                                                       
   Loaded: loaded (/usr/lib/systemd/system/systemd-journald.service; static; vendor preset: disabled)                                                                                                              
   Active: active (running) since Sun 2017-10-08 18:45:43 MSK; 2s ago                                                                                                                                              
     Docs: man:systemd-journald.service(8)
           man:journald.conf(5)
 Main PID: 1214 (systemd-journal)
   Status: "Processing requests..."
    Tasks: 1 (limit: 4915)
   CGroup: /system.slice/systemd-journald.service
           └─1214 /usr/lib/systemd/systemd-journald

Oct 08 18:45:43 arch systemd-journald[1214]: Journal started
Oct 08 18:45:43 arch systemd-journald[1214]: Runtime journal (/run/log/journal/b6b4ab29a58b486a803dfb751f2caca6) is 3.7M, max 30.0M, 26.2M free.
# ls -l /var/log/journal/
total 0

berbae · 2017-10-09 08:40:50

It seems the journal is still in volatile mode; to be sure run 'systemctl daemon-reload' before restarting the journal, or reboot the machine.
Can you please post the output of 'df -h' and 'mount' commands.
Post also the result of:

# du -h -c /var|grep -v -e local -e man -e abs

Edit: filtering abs folders from the output

Last edited by berbae (2017-10-09 14:40:12)

nesk · 2017-10-09 09:04:41

berbae wrote:

It seems the journal is still in volatile mode; to be sure run 'systemctl daemon-reload' before restarting the journal, or reboot the machine.

nesk wrote:

Rebooted 2 times

... also tried systemctl daemon-reload, systemctl restart systemd-journald.service just now - still nothing in /var/log/journal/

berbae wrote:

Can you please post the output of 'df -h' and 'mount' commands.

# df -h
Filesystem             Size  Used Avail Use% Mounted on
dev                    5.9G     0  5.9G   0% /dev
run                    5.9G  5.2M  5.9G   1% /run
/dev/sdb7              143G   51G   85G  38% /
tmpfs                  5.9G   62M  5.8G   2% /dev/shm
tmpfs                  5.9G     0  5.9G   0% /sys/fs/cgroup
tmpfs                  5.9G  528K  5.9G   1% /tmp
/dev/sdb2               97M   33M   65M  34% /boot/efi
tmpfs                  1.2G   44K  1.2G   1% /run/user/1000
# mount
proc on /proc type proc (rw,nosuid,nodev,noexec,relatime)
sys on /sys type sysfs (rw,nosuid,nodev,noexec,relatime)
dev on /dev type devtmpfs (rw,nosuid,relatime,size=6086224k,nr_inodes=1521556,mode=755)
run on /run type tmpfs (rw,nosuid,nodev,relatime,mode=755)
efivarfs on /sys/firmware/efi/efivars type efivarfs (rw,nosuid,nodev,noexec,relatime)
/dev/sdb7 on / type ext4 (rw,noatime,data=ordered)
securityfs on /sys/kernel/security type securityfs (rw,nosuid,nodev,noexec,relatime)
tmpfs on /dev/shm type tmpfs (rw,nosuid,nodev)
devpts on /dev/pts type devpts (rw,nosuid,noexec,relatime,gid=5,mode=620,ptmxmode=000)
tmpfs on /sys/fs/cgroup type tmpfs (ro,nosuid,nodev,noexec,mode=755)
cgroup on /sys/fs/cgroup/unified type cgroup2 (rw,nosuid,nodev,noexec,relatime)
cgroup on /sys/fs/cgroup/systemd type cgroup (rw,nosuid,nodev,noexec,relatime,xattr,name=systemd)
pstore on /sys/fs/pstore type pstore (rw,nosuid,nodev,noexec,relatime)
cgroup on /sys/fs/cgroup/devices type cgroup (rw,nosuid,nodev,noexec,relatime,devices)
cgroup on /sys/fs/cgroup/cpu,cpuacct type cgroup (rw,nosuid,nodev,noexec,relatime,cpu,cpuacct)
cgroup on /sys/fs/cgroup/perf_event type cgroup (rw,nosuid,nodev,noexec,relatime,perf_event)
cgroup on /sys/fs/cgroup/pids type cgroup (rw,nosuid,nodev,noexec,relatime,pids)
cgroup on /sys/fs/cgroup/net_cls,net_prio type cgroup (rw,nosuid,nodev,noexec,relatime,net_cls,net_prio)
cgroup on /sys/fs/cgroup/blkio type cgroup (rw,nosuid,nodev,noexec,relatime,blkio)
cgroup on /sys/fs/cgroup/memory type cgroup (rw,nosuid,nodev,noexec,relatime,memory)
cgroup on /sys/fs/cgroup/freezer type cgroup (rw,nosuid,nodev,noexec,relatime,freezer)
cgroup on /sys/fs/cgroup/cpuset type cgroup (rw,nosuid,nodev,noexec,relatime,cpuset)
systemd-1 on /proc/sys/fs/binfmt_misc type autofs (rw,relatime,fd=32,pgrp=1,timeout=0,minproto=5,maxproto=5,direct)
debugfs on /sys/kernel/debug type debugfs (rw,relatime)
mqueue on /dev/mqueue type mqueue (rw,relatime)
hugetlbfs on /dev/hugepages type hugetlbfs (rw,relatime,pagesize=2M)
binfmt_misc on /proc/sys/fs/binfmt_misc type binfmt_misc (rw,relatime)
configfs on /sys/kernel/config type configfs (rw,relatime)
tmpfs on /tmp type tmpfs (rw,nosuid,nodev)
/dev/sdb2 on /boot/efi type vfat (rw,relatime,fmask=0022,dmask=0022,codepage=437,iocharset=iso8859-1,shortname=mixed,errors=remount-ro)
fusectl on /sys/fs/fuse/connections type fusectl (rw,relatime)
tmpfs on /run/user/1000 type tmpfs (rw,nosuid,nodev,relatime,size=1218564k,mode=700,uid=1000,gid=100)
gvfsd-fuse on /run/user/1000/gvfs type fuse.gvfsd-fuse (rw,nosuid,nodev,relatime,user_id=1000,group_id=100)

berbae wrote:

Post also the result of:
# du -h -c /var|grep -v -e local -e man

https://pastebin.com/T4aD7HBi

seth · 2017-10-09 13:42:57

Why is there a journal.bak and why is your root device /dev/sdb? Is that a SATA device or USB? (Just guessing because it looks suspicious)

nesk · 2017-10-09 13:46:04

seth wrote:

Why is there a journal.bak and why is your root device /dev/sdb? Is that a SATA device or USB? (Just guessing because it looks suspicious)

That's what I renamed /var/log/journal to (according to berbae's recommendations). It's a SATA device. Systemd seems to name drives randomly at boot (I also have almost-always-connected USB3 drive which I omitted from outputs). All mount points are assigned by UUIDs/labels in fstab.

Arch Linux

#1 2017-10-06 17:13:25

[solved] journald doesn't record boot logs

#2 2017-10-07 09:05:08

Re: [solved] journald doesn't record boot logs

#3 2017-10-07 11:16:52

Re: [solved] journald doesn't record boot logs

#4 2017-10-07 11:29:38

Re: [solved] journald doesn't record boot logs

#5 2017-10-07 11:30:55

Re: [solved] journald doesn't record boot logs

#6 2017-10-07 12:08:33

Re: [solved] journald doesn't record boot logs

#7 2017-10-07 12:17:13

Re: [solved] journald doesn't record boot logs

#8 2017-10-07 14:41:55

Re: [solved] journald doesn't record boot logs

#9 2017-10-07 19:25:45

Re: [solved] journald doesn't record boot logs

#10 2017-10-07 21:15:19

Re: [solved] journald doesn't record boot logs

#11 2017-10-07 21:46:12

Re: [solved] journald doesn't record boot logs

#12 2017-10-08 08:29:53

Re: [solved] journald doesn't record boot logs

#13 2017-10-08 10:03:58

Re: [solved] journald doesn't record boot logs

#14 2017-10-08 10:05:10

Re: [solved] journald doesn't record boot logs

#15 2017-10-08 12:47:58

Re: [solved] journald doesn't record boot logs

#16 2017-10-08 12:58:42

Re: [solved] journald doesn't record boot logs

#17 2017-10-08 13:24:54

Re: [solved] journald doesn't record boot logs

#18 2017-10-08 14:39:32

Re: [solved] journald doesn't record boot logs

#19 2017-10-08 14:49:55

Re: [solved] journald doesn't record boot logs

#20 2017-10-08 15:34:07

Re: [solved] journald doesn't record boot logs

#21 2017-10-08 15:47:45

Re: [solved] journald doesn't record boot logs

#22 2017-10-09 08:40:50

Re: [solved] journald doesn't record boot logs

#23 2017-10-09 09:04:41

Re: [solved] journald doesn't record boot logs

#24 2017-10-09 13:42:57

Re: [solved] journald doesn't record boot logs

#25 2017-10-09 13:46:04

Re: [solved] journald doesn't record boot logs

Board footer