Bug 13784

Summary: Sysvinit log file creation in /var/log sometimes fails at first boot
Product: [Runtime] Installation Reporter: Trevor Gamblin <tvgamblin>
Component: InstallationAssignee: Trevor Gamblin <tvgamblin>
Status: RESOLVED WORKSFORME QA Contact:
Severity: normal    
Priority: Medium+ CC: kevin.tian, randy.macleod, tvgamblin
Version: 3.1   
Target Milestone: 4.0 M2   
Hardware: x86   
OS: Multiple   
Whiteboard:
OS type for building Yocto: --- Type of Regression: ---
Verified: Documentation change: Don't know

Description Trevor Gamblin 2020-02-06 17:38:25 UTC 
First seen when working on bug #13632, building core-image-full-cmdline and core-image-sato-sdk.

On systems with sysvinit there may be a race condition with volatiles creation leading to messages such as the following in /var/log/boot:

Fri Jan 31 15:50:35 2020: touch: cannot touch '/var/log/wtmp': No such file or directory
Fri Jan 31 15:50:35 2020: chown: cannot access '/var/log/wtmp': No such file or directory
Fri Jan 31 15:50:35 2020: Failed to set owner -root- for -/var/log/wtmp-.
Fri Jan 31 15:50:35 2020: chmod: cannot access '/var/log/wtmp': No such file or directory
Fri Jan 31 15:50:35 2020: Failed to set mode -0664- for -/var/log/wtmp-.

/etc/volatile.cache contains something like the following after boot:

touch "/var/log/wtmp";
                                         
chown root:root /var/log/wtmp || echo "Failed to set owner -root- for -/var/log/wtmp-." >/dev/tty0 2>&1;       
chmod 0664 /var/log/wtmp || echo "Failed to set mode -0664- for -/var/log/wtmp-." >/dev/tty0 2>&1

It appears that this in turn comes from meta/recipes-core/initscripts/initscripts-1.0/populate-volatile.sh. meta/recipes-core/initscripts/initscripts-1.0/volatiles contains a list of files that populate-volatile.sh should create:

26 d root root 1777 /run/lock none
27 d root root 0755 /var/volatile/log none
28 d root root 1777 /var/volatile/tmp none
29 l root root 1777 /var/lock /run/lock
30 l root root 0755 /var/run /run
31 l root root 1777 /var/tmp /var/volatile/tmp
32 l root root 1777 /tmp /var/tmp
33 d root root 0755 /var/lock/subsys none
34 f root root 0664 /var/log/wtmp none
35 f root root 0664 /var/run/utmp none
36 l root root 0644 /etc/resolv.conf /var/run/resolv.conf
37 f root root 0644 /var/run/resolv.conf none

I haven't seen this with systemd, but it's possible that something similar could be happening on builds with it installed, depending on the root cause.
Comment 1 Trevor Gamblin 2020-02-06 18:15:22 UTC 
Note that I can't consistently recreate this issue - for some builds I've never seen it, while on others I see some variation of the offending boot messages about 50% of the time after e.g. bitbake -c cleanall core-image-sato-sdk && bitbake core-image-sato-sdk.
Comment 2 Trevor Gamblin 2020-05-06 12:16:59 UTC 
Seems pretty consistent now, although I've only tested this in two environments.

Looking at a fix in meta/recipes-core/initscripts/initscripts-1.0/populate-volatile.sh. The simplest solution would be to use the until keyword to run touch/chown/chmod until they work, but that may be lead to confusion about expected behavior...
Comment 3 Trevor Gamblin 2020-05-06 16:40:34 UTC 
Been attempting to put "wait" loops of the following form in before any of the key steps run in create_file() and mk_dir() in populate_volatiles.sh:

while [ ! -w \"$1\" ]; do sleep 1; done;

But I haven't yet added anything that consistently covers both the "touch" and the "chown" calls that show up. I am seeing at least one of the two happen during each boot.
Comment 4 Randy MacLeod 2021-04-21 19:45:51 UTC 
Have you seen/reproduced this bug recently Trevor?
Comment 5 Trevor Gamblin 2021-04-21 19:55:42 UTC 
I am actually still seeing it sometimes, but it is not consistent. Will take another look.
Comment 6 Trevor Gamblin 2021-12-23 15:07:00 UTC 
Haven't seen this in a while now. I suspect that this patch may have fixed it:

https://git.openembedded.org/openembedded-core/commit/?id=64b659b9e40da3280ba8911b4044b19aa7366262

Marking as WORKSFORME.