localmount unmount /var/log on shutdown preventing rc_logger from saving messages and throwing "Unable to.." errors

[e-pirate]

Hi everyone.
This is a fallow up bug report after a small investigation described on Gentoo forums here.

Long story short: recently I found that there is no shutdown messages in /var/log/rc.log anymore. After some digging I found, that localmount now unmount /var on reboot making /var/log/* inaccessible and therefore preventing rc_logger from saving messages also throwing "Unable to.." red asterisk errors to console.

Temporary moving/redirecting rc.log to /opt directory solved the problem: I see full shutdown logs and no "Unable to" errors during shutdown process.

I have /var as a separate partition on this particular system since 2009 AFAIR (this, a believe, very common case for production systems that may have unpredictable log and data grows that could potentially break the system if located on root partition) and previously had no this issue. I remember to have full shutdown logs having "Stopping.." messages down to udev on this system with /var mounted as separate partition. Unfortunately, I have no evidence because this was perfectly-working and therefore abandoned system until month ago when I upgraded it to a newer platform and had a closer look at what is going on. All logs are rotated and gone, so I have no exact date when things changed.

I believe we should add /var/log to no_umounts_r variable and have it be RW accessible till the very end just as we have root.

[navi-desu]

more specifically, we probably should add $rc_log_path to no_umounts_r, similar to how we do $rc_svcdir

the mount code got refactored recently to unmount in parallel, but that part wasn't touched, so if this is a regression, seems to be an ooold one

will send a fix later today

[e-pirate]

more specifically, we probably should add $rc_log_path to no_umounts_r, similar to how we do $rc_svcdir

Even better idea as it could be that rc.log is the only log to be accessible for write in /var/log because all other processes should be already stopped and most likely /var can be unmounted safely.

the mount code got refactored recently to unmount in parallel, but that part wasn't touched, so if this is a regression, seems to be an ooold one

Definitely is. The system that I noticed this was set (including separate /var) in 2009 or something like this. It was Core Duo 2Gb RAM fanless headless machine serving my apt. infra. Some 7-8 year ago I moved to g.f. and abandoned the thing. Just let it run as it is. But I remember to investigate random reboots and I bet my bottom dollar, I've seen all the shutdown sequence in rc.log and this is how I figured out that reboots were power (most likely) or hardware related - there were no shutdown messages after previous reboot with shutdown messages present in rc.log. The kernel version was 4.19 and it was Gentoo's stable at the moment which gives us late 2018 when the system was updated last time that kind of corresponds the time I moved to g.f. and stopped updating the system. Some year ago I decided to updated platform to a modern CPU (primarily because of the old system having no PCIE slots preventing me from installation of modern 5Ghz WiFi card) and was forced to update Gentoo. I spent about a week updating Gentoo in 1-2 week steps from historical portage git repo facing almost no problems excepting some sources are missing from mirrors and hard to find. When the Gentoo was up to date I let it settle from several month then switched the motherboard (2 weeks ago) finally noticing the absence of shutdown portion of logs in rc.log and some error stating "Unable to.." that I was unable to figure out what it exactly is because it goes out to fast before system reboots. To draw the line, the umount behavior was changed in last.. 8 years or so - quite a long period many things changed.

[e-pirate]

@navi-desu any updates here?

[navi-desu]

@navi-desu any updates here?

sorry, taking a bit longer because i'm not quite sure to handle the path, as do_unmount only takes regexes

[e-pirate]

@navi-desu I tried to do it myself with dirname, cut and some other basic bash tricks and now I see what you mean. Finally, I found a working solution but I need to test and work out some rare cases. I will come back with MR soon. I successfully tested my solution with rc.log located on separate partition and on root partition - works as expected. But I also would like to treat the case when file does not exists (initial condition when user just switched the rc_logger and there is no file yet because the system is running and had no chance to write any startup messages).

[navi-desu]

i was thinking of adding a mountinfo option to query "what mountpoint is $arg under?"

though i'll wait to see your PR before trying anything since you've already done some work

[e-pirate]

@navi-desu the fix is ready, I test-proved it in various simulated cases and on a real server. It took me some effort to write it in openrc-run-kindish style (especially yesno thing), but it works. I will make MR a little bit later.

[e-pirate]

Since stat misses required parameter in both busybox and FreeBSD, I found a way to implement desired behavior with mountpoint and some very schmick string variable manipulation in sh the does the job for Linuxes. After getting a fully working code I found another approach that uses only df and awk and looks to be portable across GNU/Linux, Busybox and FreeBSD giving us a universal solution. I tested most vital parts on Gentoo, Alpine and FreeBSD and they work as expected. I'm still testing new implementation, but it looks like a I'm close to a working solution.

[e-pirate]

This will take some extra time because my old Lenovo X230 fan died and I'm unable to run VMs to test-prove my fix on a real FreeBSD and Alpine systems. The new fix that is suppose to work on all distributives is ready and partly tested, but I would like to test it on real systems to be sure it work and will not introduce any new issues.