[systemd-devel] list-boots is incorrect, was: lost journal persistence

Thu May 15 20:45:46 PDT 2014

On Thu, May 15, 2014 at 05:19:28PM -0600, Chris Murphy wrote:
> 
> On May 15, 2014, at 3:55 PM, Lennart Poettering <lennart at poettering.net> wrote:
> 
> > On Thu, 15.05.14 12:01, Chris Murphy (lists at colorremedies.com) wrote:
> > 
> >> 
> >> 
> >> On May 12, 2014, at 9:58 AM, Chris Murphy <lists at colorremedies.com> wrote:
> >> 
> >>> 
> >>> On May 12, 2014, at 7:06 AM, Kirill Elagin <kirelagin at gmail.com> wrote:
> >>> 
> >>>> Could it be that all the boot ids are actually the same for some reason?
> >>>> I had this issue in a container when systemd was reading boot_id from `/proc/sys/kernel/random/boot_id` and since /proc was bind-mounted, boot_id always was host's boot_id.
> >>>> 
> >>>> You can also run `journalctl -F _BOOT_ID` to see a set of all the boot ids recorded in the journal (this must agree with `journalctl --list-boots`.
> >>> 
> >>> 
> >>> # journalctl --list-boots | wc -l
> >>> 36
> >>> [root at rawhide ~]# journalctl -F _BOOT_ID | wc -l
> >>> 80
> >>> # cat /proc/sys/kernel/random/boot_id
> >>> 420fa190-e7dd-4cd7-b248-fd62417d7c02
> >>> # reboot
> >>> ###
> >>> # journalctl --list-boots | wc -l
> >>> 36
> >>> [root at rawhide ~]# journalctl -F _BOOT_ID | wc -l
> >>> 81
> >>> # cat /proc/sys/kernel/random/boot_id
> >>> 1e0d5346-85cb-477b-9ae2-2cfb53097b97
> >>> 
> >>> 
> >>> So there are more boot ID's than there are list-boots, and list-boots doesn't increment while boot ID's do. And neither of these boot id's match any of the boot id's in --list-boots.
> >> 
> >> Deleting the files in /var/log/journal/<machineid>/ fixes the problem on the Fedora 20 and Fedora Rawhide VMs experiencing this problem. If the files are restored, the problem returns. Yet --verify shows PASS for each log file. So it seems there's some kind of corruption or confusion with these log files.
> >> 
> >> The btrfs filesystem is mounted with autodefrag option, for which there have been some problems with kernel 3.12 and older. But the Rawhide system has only been using 3.14 and 3.15 kernels so if there's still some problem I'm not sure how to isolate it since journalctl --verify seems to think the files are OK.
> >> 
> >> Despite autodefrag enabled, the systemjournal has ~1450 fragments according to filefrag. If I boot from a rescue image so nothing is actively writing to these journal files, and recopy them such that they are each 1 extent only, then reboot the system, the list-boots changes. It actually goes down, from 45 boots to 31 boots, and stays stuck with additional reboots. Whereas BOOT_ID continues to increment as before. So just by copying the log files I get different --list-boot behavior. That's pretty strange.
> >> 
> >> Yes, of course also btrfs check and scrub find no problems with either Fedora 20 or Fedora Rawhide Btrfs file systems this problem is happening on.
> > 
> > This is certainly weird... Copying these files to ext4, does that change
> > anything?
> 

> Each time I copy, no matter the file system, I get a different
  number of list-boots results each time. Yet each time the source and
  destination sha256sums for the journal files are the same. It makes
  no sense. Same sha256sums yet different --list-boot behavior. It's a
  non-deterministic hell it seems. Once the journals are affected by
  whatever is happening, they're permanently weird.

Probably the order of files in the directory (ls -U) changes randomly
upon copying to a different fs.

> I think the state is sufficiently bizarre, with a huge pile of Btrfs
  patches applied in the 3.14 time frame (both systems ran 3.14 and
  3.15 rc kernels) that this is just not worth looking at
  further. I'll keep the journals elsewhere, but I'm going to clear
  out /var/log/journal and let it start new ones from scratch and see
  how it goes, if the problem reoccurs.

I wouldn't rule out an issue with the journal code...

Zbyszek