Bug 7892

Created attachment 5882 [details]
List of overlay files and folders

Created attachment 5888 [details]
Permissions table

Created attachment 5894 [details]
User table

Created attachment 5900 [details]
Kernel Configuration

Further testing has shown that editing tmpfiles.d to create the folders results in them being used, and seems to stop the logspam, but journalctl still reports no logs were found.

Testing on the x86 machine has shown that after commit (not inclusive) cb8ce5f0016fa14f5e6971e07416ed465e641ff7 all builds tested resulted in the same issue.

The bug was likely introduced in d380dde1d2878bd8f09317081960bfc82b0f420b ("skeleton: make /run a proper directory/filesystem"), but that build fails. (The build failure was fixed in c6ca6fc9a3714842485618676390aba114442511)

Reverting d380dde1d2878bd8f09317081960bfc82b0f420b and c6ca6fc9a3714842485618676390aba114442511 fixes the issue.

Further discussion with dywi on the IRC has led me to try Storage=volatile in /etc/systemd/journald.conf and this solves the issue additionally. It seems to be more "honest" as all /var/log/journal was getting written to was memory anyway.

(In reply to comment #7)
> Further discussion with dywi on the IRC has led me to try Storage=volatile in
> /etc/systemd/journald.conf and this solves the issue additionally. It seems to
> be more "honest" as all /var/log/journal was getting written to was memory
> anyway.

Can you provide more details about your testing setup? I cannot reproduce it here.

setup: (with current git head, 2015.02-rc3-31-gc9ba844)

- make qemu_arm_versatile_defconfig
- change to external sourcery codebench 2014.05 toolchain, enable systemd)
- run in qemu as explained in board/qemu/arm-versatile/readme.txt

..
systemd[1]: Starting Journal Socket.
[  OK  ] Listening on Journal Socket.
systemd[1]: Listening on Journal Socket.
..
systemd[1]: Starting Journal Socket (/dev/log).
[  OK  ] Listening on Journal Socket (/dev/log).
systemd[1]: Listening on Journal Socket (/dev/log).
systemd[1]: Starting Journal Service...
         Starting Journal Service...
..
[  OK  ] Started Journal Service.
systemd[1]: Started Journal Service.
         Starting Load/Save Random Seed...
         Starting Flush Journal to Persistent Storage...
         Starting Create Static Device Nodes in /dev...
[FAILED] Failed to start Load/Save Random Seed.
See "systemctl status systemd-random-seed.service" for details.
systemd-journald[57]: Received request to flush runtime journal from PID 1
[  OK  ] Started Flush Journal to Persistent Storage.
[  OK  ] Started Journal Service.
systemd[1]: Started Journal Service.
         Starting Load/Save Random Seed...
         Starting Flush Journal to Persistent Storage...
         Starting Create Static Device Nodes in /dev...
[FAILED] Failed to start Load/Save Random Seed.
See "systemctl status systemd-random-seed.service" for details.
systemd-journald[57]: Received request to flush runtime journal from PID 1
[  OK  ] Started Flush Journal to Persistent Storage.
..
Welcome to Buildroot
buildroot login: root
# journalctl 
-- Logs begin at Thu 1970-01-01 00:00:05 UTC, end at Thu 1970-01-01 00:06:41 UTC. --
Jan 01 00:00:05 buildroot systemd-journal[57]: Runtime journal is using 4.0M (max allowed 8.0M, trying to leave 9.1M free of 57.1M available → current limit 8.0M).
Jan 01 00:00:05 buildroot systemd-journal[57]: Runtime journal is using 4.0M (max allowed 8.0M, trying to leave 9.1M free of 57.1M available → current limit 8.0M).
Jan 01 00:00:05 buildroot kernel: Booting Linux on physical CPU 0x0
Jan 01 00:00:05 buildroot kernel: Linux version 3.18.4 (peko@dell) (gcc version 4.8.3 20140320 (prerelease) (Sourcery CodeBench Lite 2014.05-29) ) #1 Sun Mar 1 21:20:21 CET 2015
Jan 01 00:00:05 buildroot kernel: CPU: ARM926EJ-S [41069265] revision 5 (ARMv5TEJ), cr=00093177
Jan 01 00:00:05 buildroot kernel: CPU: VIVT data cache, VIVT instruction cache
Jan 01 00:00:05 buildroot kernel: Machine: ARM-Versatile PB
Jan 01 00:00:05 buildroot kernel: Memory policy: Data cache writeback
Jan 01 00:00:05 buildroot kernel: On node 0 totalpages: 32768
Jan 01 00:00:05 buildroot kernel: free_area_init_node: node 0, pgdat c047bef4, node_mem_map c7efa000
Jan 01 00:00:05 buildroot kernel:   Normal zone: 256 pages used for memmap
Jan 01 00:00:05 buildroot kernel:   Normal zone: 0 pages reserved
Jan 01 00:00:05 buildroot kernel:   Normal zone: 32768 pages, LIFO batch:7


# grep Storage /etc/systemd/journald.conf 
#Storage=auto

# ls -lah /run/log/journal/*/system.journal 
-rw-r-----    1 root     systemd-    4.0M Jan  1 00:06 /run/log/journal/9d2e12bc7f174fe28e052094ddb7e92b/system.journal

So it looks like it works ok.

(In reply to comment #8)
> (In reply to comment #7)
> > Further discussion with dywi on the IRC has led me to try Storage=volatile in
> > /etc/systemd/journald.conf and this solves the issue additionally. It seems to
> > be more "honest" as all /var/log/journal was getting written to was memory
> > anyway.
> 
> Can you provide more details about your testing setup? I cannot reproduce it
> here.
> 
> setup: (with current git head, 2015.02-rc3-31-gc9ba844)
> 
> - make qemu_arm_versatile_defconfig
> - change to external sourcery codebench 2014.05 toolchain, enable systemd)
> - run in qemu as explained in board/qemu/arm-versatile/readme.txt
> 

I used qemu_arm_versatile, enabled glibc and systemd (no code sourcery) and it worked fine here too.

I'm not sure what other info I can provide; The x86 machine has all of it's valid configuration info posted above. It's a IBM ThinkCentre 9210 with a nocona Pentium D with 2 GiB of ram.

The ARM system is an Atmel sama5d3-xplained that's acting as my residential gateway.

I'll see if I can reproduce this on a blank x86 config for the thinkcentre.

(In reply to comment #9)
> I used qemu_arm_versatile, enabled glibc and systemd (no code sourcery) and it
> worked fine here too.

Ok, interesting. What is the difference in Buildroot configuration between this and your sama5d3-xplained config?

> I'm not sure what other info I can provide; The x86 machine has all of it's
> valid configuration info posted above. It's a IBM ThinkCentre 9210 with a
> nocona Pentium D with 2 GiB of ram.

Ok, I'll give qemu_x86_defconfig a try. What file system are you using?

(In reply to comment #10)
> (In reply to comment #9)
> 
> Ok, interesting. What is the difference in Buildroot configuration between this
> and your sama5d3-xplained config?
> 
Quite a bit as my config has a lot of packages, but I couldn't spot anything that would make a difference. I'll attach it. The permissions and user table should be the same as the x86 system's.
> 
> Ok, I'll give qemu_x86_defconfig a try. What file system are you using?

ext2 on the sama and ext4 on the x86.

Created attachment 5906 [details]
Buildroot config (sama5d3)

As per the conversation over IRC a while ago:

This issue occurs when the 'rw' flag is given to the kernel. This flag was added many versions ago as a workaround for another issue.

The fix/workaround seems to be to edit in "Storage=Volatile" in /etc/systemd/journald.conf , as per http://patchwork.ozlabs.org/patch/444707/.http://patchwork.ozlabs.org/patch/444707/

>This issue occurs when the 'rw' flag is given to the kernel.

Problem with journalctl reporting "No journal files were found" also occurs when using initramfs as output image, which has a writeable / as well.

Seems that journald starts early, before fstab is processed, and uses /var/log/journal -> /tmp/journal if it is able to (has a writeable fs at that point).
Later fstab is processed which with the default skeleton mounts another /tmp tmpfs on top:

==
tmpfs           /tmp            tmpfs   mode=1777       0       0
==

rendering the journal file unreachable.


>The fix/workaround seems to be to edit in "Storage=Volatile" in /etc/systemd/journald.conf

Yes, that solves it for me as well.

Hi,

Sorry to get back on this after such a long period, here are my findings and maybe explanation:

The skeleton has changed since that times, and systemd has been updated too, so this has to be kept in mind.

From the test I did using NFS, I played with the exportfs (RW or RO) and with the kernel command line (RW, RO), here's a quick table of my results:

By results, I mean that journald started properly and doing journalctl worked as expected.
And I kept the journald.conf as default (so the Storage=auto)

NFS    KERNEL    RESULTS
RO     RO        OK
RO     RW        NAK
RW     RO        OK
RW     RW        OK

The only options where it went awry is when I told the kernel that my storage was RW when in reality it was RO, so we could say that journald is stupid because it takes what the user say for granted and maybe it should double check, but I don't think the fix should come from Buildroot.

I would add that the patch that changes the Storage options unconditionally is too harsh anyway. We can't enforce where the log should be or not be, written. This should be a post-build scripts tweak to me, or if it's really an issue with journalctl, maybe I need to find some SAMA5 board somewhere, maybe theres' something special about this board, but as is, I really can't reproduce.

(In reply to Maxime Hadjinlian from comment #15)
>The skeleton has changed since that times, and systemd has been updated too, so 
>this has to be kept in mind.

The updates did not improve a thing.

Still broken for me to this date if the root file system is mounted read-write (by an initramfs) before passing control over to systemd

Journal service starts quicker on my test system (Raspberry) and creates /tmp/journal (/var/log/journal) first. Then 0.2 seconds later a tmpfs /tmp is mounted on top, rendering the journal files unreachable.

==
[   12.145381] systemd[1]: Starting Journal Service...
[   12.154950] systemd[1]: Started Create list of required static device nodes for the current kernel.
[   12.157820] systemd[1]: Starting Create Static Device Nodes in /dev...
[   12.174068] systemd[1]: Mounted POSIX Message Queue File System.
[   12.179373] systemd[1]: Mounted Debug File System.
[   12.179523] systemd[1]: Mounted Configuration File System.
[   12.294936] systemd[1]: Started Apply Kernel Variables.
[   12.299556] systemd[1]: Started Remount Root and Kernel File Systems.
[   12.369659] systemd[1]: Starting udev Coldplug all Devices...
[   12.374580] systemd[1]: Started Create Static Device Nodes in /dev.
[   12.379076] systemd[1]: Starting udev Kernel Device Manager...
[   12.379246] systemd[1]: Reached target Local File Systems (Pre).
[   12.382691] systemd[1]: tmp.mount: Directory /tmp to mount over is not empty, mounting anyway.
[   12.386300] systemd[1]: Mounting /tmp...
[   12.399922] systemd[1]: Mounted /tmp.
[   12.409040] systemd[1]: Reached target Local File Systems.
==

Due to the asynchronious nature of systemd the results during your test may differ, but that doesn't mean the problem isn't still there.


>I would add that the patch that changes the Storage options unconditionally is 
>too harsh anyway. We can't enforce where the log should be or not be, written. 
>This should be a post-build scripts tweak to me

Would argue that systemd should work with the default skeleton out-of-the-box, and the "Storage=Volatile" patch makes sense in that situation.
Why not let the people that want to deviate from the default do post-build tweaks instead?!

Hello,

There is a WIP re-organisation of the skeleton to accomodate with
systemd:
    http://lists.busybox.net/pipermail/buildroot/2016-July/167831.html

Some comments were made on this series, and I am in the process of
taking them into account. It is not finished yet, bu I hope that it
will be ready by the end of the September.

Regards,
Yann E. MORIN.

(In reply to Maxime Hadjinlian from comment #15)
>maybe I need to find some SAMA5 board somewhere, 
>maybe theres' something special about this board, but as is, I really can't reproduce


Minimal steps to reproduce if you do have a Pi 3 laying around:

make raspberrypi3_defconfig
make menuconfig
"toolchain" -> "c library" -> "glibc"
"system configuration" -> "init system" -> "systemd"
"system configuration" -> "getty" -> "TTY port" -> tty1 (the default value "console" is currently broken with systemd)
"filesystem images" -> enable "initial RAM file system linked into linux kernel"
make

Copy output/images/zImage output/images/*.dtb output/images/rpi-firmware/* to a FAT formatted SD card, stick it in the Pi, and boot it
Type "journalctl" and notice that it claims that "No journal files were found."

I would argue that a configuration as simple as this should just work out-of-the-box, without post-build anything.


In this example config buildroot produces the initramfs. But it also happens if you have a normal file system, but there is another initramfs that mounts the root filesystem rw, and passes control over to you with switch_root.

Floris,

As I said in my previous comment, this is all known, and is being worked on. ;-)

Besides, there is nothing rpi-specific in this issue. It can very well be
reprocuced with any of our qemu-targetting defconfigs.

Regards,
Yann E. MORIN.

(In reply to Yann E. MORIN from comment #19)
>As I said in my previous comment, this is all known, and is being worked on. ;-)

Good, I wasn't sure of that, as the bug was marked RESOLVED WORKSFORME... ;-)

>Besides, there is nothing rpi-specific in this issue. It can very well be
>reprocuced with any of our qemu-targetting defconfigs.

Well, earlier in the bug report people claimed it was unreproducible with qemu.
Then again it probably wasn't tested as initramfs.

Floris,

> the bug was marked RESOLVED WORKSFORME...

Weird, here it looks like it is "ASSIGNED" (to me!).

> people claimed it was unreproducible with qemu.

OK, I'll try to look at that...

Regards,
Yann E. MORIN.

(In reply to Yann E. MORIN from comment #21)

Yann,

I am seeing this bug in 2016.11 release and I would love to come up with some fix for it, so I was wondering if you ever made any progress w.r.t fixing the problem? I would like to try to come up with the fix myself and if you have anything that can give me a headstart, please do share.

Thank you.

Andrey,

I have a series that fixes systemd globally, especially sytemd-journald:
    https://git.buildroot.org/~ymorin/git/buildroot/log/?h=yem/systemd-skeleton

It is not complete nor correct for now (there was some comments by
Thomas), and I have a rewite in progress (so it is not finished):
    https://git.buildroot.org/~ymorin/git/buildroot/log/?h=yem/systemd-skeleton-2

I hope I'll have something clean before the end of the month, so it can
go in for the next release.

Regards,
Yann E. MORIN.

(In reply to Yann E. MORIN from comment #23)

Yann,

Thank you, this is even better than I could've hoped for!

I have a custom PowerPC (e500) based system I emulate in QEMU (I didn't try real HW since I could easily reproduce the bug in QEMU) and I did try out both branches you mentioned. First one definitely fixed the journalctl problems, second, given how it seem to be missing anything similar to "system: make systemd work on a read-only rootfs", OTOH didn't (which was expected).

I would love to see your work go upstream sooner rather than later, so if there's any meaningful way we can collaborate on this, besides me providing "Tested-by" etc. for your commits, please let me know (feel free to contact me via e-mail if that's more convenient)

Thanks!

Created attachment 6841 [details]
0001-skeleton-common.mk-Fix-password-related-variable-nam

Yann,

I did more testing and found a small bug in yem/systemd-skeleton, which I think you might know of since I don't think it is present in yem/systemd-skeleton-2, so had to apply this patch to fix it.

The patch series from Yann that allows to have a systemd specific skeleton, and proper support for systemd on a read-only filesystem has been merged. Hence this bug is now fixed. Thanks a lot Yann for the work. Thanks to Arnout for the final polish. Thanks Andrey for the testing!