Bug 808907

Summary: /var/lib/random-seed file is not functional under readonly root enabled
Product: [Fedora] Fedora Reporter: Hui Li <huli>
Component: initscriptsAssignee: Bill Nottingham <notting>
Status: CLOSED ERRATA QA Contact: Fedora Extras Quality Assurance <extras-qa>
Severity: high Docs Contact:
Priority: unspecified    
Version: 16CC: dsd, iarlyy, johannbg, jonathan, lnykryn, metherid, notting, npatil, plautrba, rvokal, systemd-maint
Target Milestone: ---   
Target Release: ---   
Hardware: x86_64   
OS: Linux   
Whiteboard:
Fixed In Version: Doc Type: Bug Fix
Doc Text:
Story Points: ---
Clone Of:
: 888615 888618 (view as bug list) Environment:
Last Closed: 2012-07-14 21:52:21 UTC Type: ---
Regression: --- Mount Type: ---
Documentation: --- CRM:
Verified Versions: Category: ---
oVirt Team: --- RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: --- Target Upstream Version:
Bug Depends On:    
Bug Blocks: 888615, 888618    

Description Hui Li 2012-04-01 15:43:14 UTC
Description of problem:
/var/lib/random-seed file is not functional under readonly root enabled. This file cannot be removed due to "Read-only file system" error and the system will show the error message when booting: "systemd-random-seed[517]: Failed to write new random seed file: Bad file descriptor".

Version-Release number of selected component (if applicable):
initscripts-9.34.2-1.fc16.x86_64

How reproducible:
100%

Steps to Reproduce:
1. Just install base and core groups
2. Enable readonly root function in /etc/sysconfig/readonly-root file, set READONLY=yes and TEMPORARY_STATE=yes.
3. Add mount option ro in /etc/fstab for / directory.
4. Reboot
  
Actual results:
"systemd-random-seed[517]: Failed to write new random seed file: Bad file descriptor" and the file cannot be removed/modified.

Expected results:
No error for /var/lib/random-seed.

Additional info:

mount command output:

none on /var/lib/random-seed type tmpfs (rw,relatime,rootcontext=system_u:object_r:var_lib_t:s0,seclabel)

SELinux state: Permissive

Comment 1 Bill Nottingham 2012-04-02 15:53:36 UTC
That seems odd. The error at that point implies that open succeeded but write failed?

Comment 2 Hui Li 2012-04-02 16:25:19 UTC
Yes, here's the content of /etc/fstab file.

UUID=7c3c5c50-926d-47cc-a9e3-75cc71745bab	/	ext3	defaults,noatime,ro	1 1

Comment 3 Hui Li 2012-04-05 10:03:48 UTC
I just noticed that all items in /etc/rwtab with "files" type are also in r/o model. Not only /var/lib/random-seed file. I'm guessing there are something wrong in mount_files() function at /lib/systemd/fedora-readonly.

Comment 4 Hui Li 2012-04-10 09:12:03 UTC
Any available update here?

Comment 5 Bill Nottingham 2012-04-10 19:02:54 UTC
What's your /etc/sysconfig/readonly-root look like?

Comment 6 Hui Li 2012-04-11 04:53:47 UTC
# Set to 'yes' to mount the system filesystems read-only.
READONLY=yes
# Set to 'yes' to mount various temporary state as either tmpfs
# or on the block device labelled RW_LABEL. Implied by READONLY
TEMPORARY_STATE=yes
# Place to put a tmpfs for temporary scratch writable space
RW_MOUNT=/var/lib/stateless/writable
# Label on local filesystem which can be used for temporary scratch space
RW_LABEL=stateless-rw
# Options to use for temporary mount
RW_OPTIONS=
# Label for partition with persistent data
STATE_LABEL=stateless-state
# Where to mount to the persistent data
STATE_MOUNT=/var/lib/stateless/state
# Options to use for peristent mount
STATE_OPTIONS=
# NFS server to use for persistent data?
CLIENTSTATE=

Comment 7 Daniel Drake 2012-04-25 16:48:21 UTC
OLPC is facing a similar issue here. We use the readonly-root functionality for statetab and rwtab (but we don't put / as RO).

random-seed is being written to outside of the rwtab/statetab mount, which is the same as whats being described here.

Enabling systemd debug logs (http://fedoraproject.org/wiki/How_to_debug_Systemd_problems) it is easy to see that during boot, fedora-readonly.service and systemd-random-seed-load.service are being started in parallel, and this is therefore a race - if random-seed-load comes first, which it often does, we'll try to write to /var/lib/random-seed before the readonly stuff has kicked in.

This can be solved by adding
    Before=systemd-random-seed-load.service
in fedora-readonly.service

A similar problem occurs during shutdown. systemd debug logs show that it unmounts a whole load of stuff (including random seed) before executing systemd-random-seed-save.service. I tried changing systemd-random-seed-save.service to have:
    Before=umount.target
but this didn't change anything :( it still unmounts stuff before trying to save a random seed to disk.

Comment 8 Bill Nottingham 2012-04-25 17:53:39 UTC
Thanks, added. Hui - does that fix work for you?

Comment 9 Bill Nottingham 2012-04-25 17:55:16 UTC
Actually - if, instead, you have:
  Before=local-fs.target

does that help?

Comment 10 Daniel Drake 2012-04-25 17:58:55 UTC
Bill, I can test that later. Which file do you want me to modify with the above change?
Do I do it in addition to the changes I noted above (both?)?
Thanks

Comment 11 Bill Nottingham 2012-04-25 18:21:58 UTC
That would go in fedora-readonly.service, instead of 'Before=systemd-random-seed-load.service'. The idea is that anything that runs after local-fs.target on boot should be done after the readonly stuff is set up.

Not sure what the best way to handle shutdown would be.

Comment 12 Hui Li 2012-04-26 05:05:17 UTC
(In reply to comment #8)
> Thanks, added. Hui - does that fix work for you?

Yes. It is fixed. However, I didn't experience the issue when system shutdown. Here's the output of shutdown session.

[root@(none) ~]# init 0
[   18.941545] acpid[570]: exiting
[   18.944240] systemd[1]: nfs-lock.service: main process exited, code=exited, status=1
[   18.959233] login[655]: pam_unix(login:session): session closed for user root
[   18.960358] sshd[621]: Received signal 15; terminating.
[   18.961122] rpc.statd[645]: Caught signal 15, un-registering and exiting
[   18.997754] systemd[1]: mcelog.service: main process exited, code=exited, status=15
[   18.998943] systemd[1]: Unit mcelog.service entered failed state.
[   18.999861] dbus-daemon[603]: modem-manager[617]: <info>  Caught signal 15, shutting down...
[   19.003232] type=1305 audit(1335416378.876:71): audit_pid=0 old=571 auid=4294967295 ses=4294967295 subj=system_u:system_r1
[   19.008062] type=1131 audit(1335416378.881:72): pid=0 uid=0 auid=4294967295 ses=4294967295 subj=system_u:system_r:init_t:'
[   19.021430] type=1131 audit(1335416378.894:73): pid=0 uid=0 auid=4294967295 ses=4294967295 subj=system_u:system_r:init_t:'
[   19.026914] modem-manager[617]: <info>  Caught signal 15, shutting down...
[   19.028068] NetworkManager[580]: <warn> disconnected by the system bus.
[   19.029029] NetworkManager[580]: NetworkManager[580]: <warn> disconnected by the system bus.
[   19.032770] type=1131 audit(1335416378.905:74): pid=0 uid=0 auid=4294967295 ses=4294967295 subj=system_u:system_r:init_t:'
[   19.039476] auditd[571]: The audit daemon is exiting.
[   19.041353] NetworkManager[580]: g_dbus_connection_real_closed: Remote peer vanished with error: Underlying GIOStream ret.
[   19.046972] NetworkManager[580]: NetworkManager[580]: <info> caught signal 15, shutting down normally.
[   19.048759] NetworkManager[580]: <info> caught signal 15, shutting down normally.
[   19.050194] NetworkManager[580]: NetworkManager[580]: <warn> quit request received, terminating...
[   19.051612] NetworkManager[580]: <warn> quit request received, terminating...
[   19.052591] NetworkManager[580]: NetworkManager[580]: <info> exiting (success)
[   19.053804] NetworkManager[580]: <info> exiting (success)
[   19.055079] sysctl[875]: fs.nfs.nlm_tcpport = 0
[   19.055717] sysctl[875]: fs.nfs.nlm_udpport = 0
[   19.056480] systemd[1]: Unit nfs-lock.service entered failed state.
[   19.057388] nm-dispatcher.action[721]: Caught signal 15, shutting down...
[   19.058323] nm-dispatcher.action[721]: Caught signal 15, shutting down...
[   19.059530] type=1130 audit(1335416378.932:75): pid=0 uid=0 auid=4294967295 ses=4294967295 subj=system_u:system_r:init_t:'
[   19.062511] type=1131 audit(1335416378.935:76): pid=0 uid=0 auid=4294967295 ses=4294967295 subj=system_u:system_r:init_t:'
[   19.067986] rpcbind[629]: rpcbind terminating on signal. Restart with "rpcbind -w"
[   19.071912] systemd[1]: rpcbind.service: main process exited, code=exited, status=2
[   19.074144] type=1131 audit(1335416378.947:77): pid=0 uid=0 auid=4294967295 ses=4294967295 subj=system_u:system_r:init_t:'
[   19.078749] systemd[1]: Unit rpcbind.service entered failed state.
[  109.021934] systemd[1]: dbus.service stopping timed out (2). Killing.
[  109.027508] type=1131 audit(1335416468.899:78): pid=0 uid=0 auid=4294967295 ses=4294967295 subj=system_u:system_r:init_t:'
[  109.033831] systemd[1]: Unit dbus.service entered failed state.
[  109.042738] type=1131 audit(1335416468.914:79): pid=0 uid=0 auid=4294967295 ses=4294967295 subj=system_u:system_r:init_t:'
[  109.054549] type=1131 audit(1335416468.926:80): pid=0 uid=0 auid=4294967295 ses=4294967295 subj=system_u:system_r:init_t:'
[  109.057517] type=1131 audit(1335416468.929:81): pid=0 uid=0 auid=4294967295 ses=4294967295 subj=system_u:system_r:init_t:'
[  109.067709] type=1131 audit(1335416468.939:82): pid=0 uid=0 auid=4294967295 ses=4294967295 subj=system_u:system_r:init_t:'
[  109.077743] type=1131 audit(1335416468.949:83): pid=0 uid=0 auid=4294967295 ses=4294967295 subj=system_u:system_r:init_t:'
[  109.083641] type=1131 audit(1335416468.955:84): pid=0 uid=0 auid=4294967295 ses=4294967295 subj=system_u:system_r:init_t:'
[  109.086691] type=1131 audit(1335416468.958:85): pid=0 uid=0 auid=4294967295 ses=4294967295 subj=system_u:system_r:init_t:'
[  109.089575] type=1131 audit(1335416468.961:86): pid=0 uid=0 auid=4294967295 ses=4294967295 subj=system_u:system_r:init_t:'
[  109.092891] type=1131 audit(1335416468.964:87): pid=0 uid=0 auid=4294967295 ses=4294967295 subj=system_u:system_r:init_t:'
[  109.117580] systemd[1]: Shutting down.
[  109.128219] systemd-cgroups-agent[900]: Failed to get D-Bus connection: Failed to connect to socket /org/freedesktop/systd
Sending SIGTERM to remaining processes...
Sending SIGKILL to remaining processes...
Unmounting file systems.
Unmounted /var/lib/nfs/rpc_pipefs.
Unmounted /sys/kernel/config.
Unmounted /sys/kernel/security.
Unmounted /sys/kernel/debug.
Unmounted /dev/mqueue.
Unmounted /dev/hugepages.
[  114.212727] EXT4-fs (sda3): re-mounted. Opts: (null)
Disabling swaps.
Detaching loop devices.
Detaching DM devices.
Successfully changed into root pivot.
Unmounted /oldroot/proc.                      
Unmounted /oldroot/dev/pts.                  
Unmounted /oldroot/run.                       
Unmounted /oldroot/sys/fs/cgroup/systemd.       
Unmounted /oldroot/sys/fs/cgroup/cpu,cpuacct.   
Unmounted /oldroot/sys/fs/cgroup/devices.
Unmounted /oldroot/sys/fs/cgroup/net_cls.
Unmounted /oldroot/sys/fs/cgroup/perf_event.
Unmounted /oldroot/dev/shm.
Unmounted /oldroot/sys/fs/selinux.
Unmounted /oldroot/sys/fs/cgroup/cpuset.
Unmounted /oldroot/sys/fs/cgroup/freezer.
Unmounted /oldroot/dev.
Unmounted /oldroot/sys/fs/cgroup/memory.
Unmounted /oldroot/sys/fs/cgroup/blkio.
Unmounted /oldroot/sys/fs/cgroup.
Unmounted /oldroot/sys.
Unmounted /oldroot.
[  114.286228] dracut: Disassembling device-mapper devices
[  114.290289] dracut: Disassembling mdraid devices.
Powering off.
[  114.293854] md: stopping all md devices.
[  114.294534] sd 0:0:0:0: [sda] Stopping disk
[  114.296082] ACPI: Preparing to enter system sleep state S5
[  114.296984] Disabling non-boot CPUs ...
[  114.297595] Power down.

Comment 13 Hui Li 2012-04-26 05:14:50 UTC
By the way, 'Before=local-fs.target' is also work for it.

Comment 14 Fedora Update System 2012-07-06 13:15:54 UTC
initscripts-9.37.1-1.fc17 has been submitted as an update for Fedora 17.
https://admin.fedoraproject.org/updates/initscripts-9.37.1-1.fc17

Comment 15 Fedora Update System 2012-07-06 21:28:36 UTC
Package initscripts-9.37.1-1.fc17:
* should fix your issue,
* was pushed to the Fedora 17 testing repository,
* should be available at your local mirror within two days.
Update it with:
# su -c 'yum update --enablerepo=updates-testing initscripts-9.37.1-1.fc17'
as soon as you are able to.
Please go to the following url:
https://admin.fedoraproject.org/updates/FEDORA-2012-10354/initscripts-9.37.1-1.fc17
then log in and leave karma (feedback).

Comment 16 Fedora Update System 2012-07-14 21:52:21 UTC
initscripts-9.37.1-1.fc17 has been pushed to the Fedora 17 stable repository.  If problems still persist, please make note of it in this bug report.