| Summary: | systemd-journal cannot read urandom and quits | ||||||
|---|---|---|---|---|---|---|---|
| Product: | [Fedora] Fedora | Reporter: | Wendell Baker <wendellcraigbaker> | ||||
| Component: | selinux-policy | Assignee: | Miroslav Grepl <mgrepl> | ||||
| Status: | CLOSED RAWHIDE | QA Contact: | Fedora Extras Quality Assurance <extras-qa> | ||||
| Severity: | unspecified | Docs Contact: | |||||
| Priority: | unspecified | ||||||
| Version: | rawhide | CC: | dominick.grift, dwalsh, johannbg, metherid, mgrepl, mschmidt, notting, plautrba, systemd-maint | ||||
| Target Milestone: | --- | ||||||
| Target Release: | --- | ||||||
| Hardware: | Unspecified | ||||||
| OS: | Unspecified | ||||||
| Whiteboard: | |||||||
| Fixed In Version: | Doc Type: | Bug Fix | |||||
| Doc Text: | Story Points: | --- | |||||
| Clone Of: | Environment: | ||||||
| Last Closed: | 2012-01-14 22:08:47 UTC | Type: | --- | ||||
| Regression: | --- | Mount Type: | --- | ||||
| Documentation: | --- | CRM: | |||||
| Verified Versions: | Category: | --- | |||||
| oVirt Team: | --- | RHEL 7.3 requirements from Atomic Host: | |||||
| Cloudforms Team: | --- | Target Upstream Version: | |||||
| Attachments: |
|
||||||
What version of selinux-policy do you have installed? (host spillage) $ rpm -q selinux-policy selinux-policy-3.10.0-74.fc17.noarch On point ... version (prior comment) seems "old" with respect to rawnide. See actualities from updating below.
Explanation: There was an issue with yum update this morning. In the update, the machine went off the lan (em1 went down spontaneously, upon reboot, didn't come up). I haven't characterized that, it may be a ghost. But what that probably means is that this report was initiated with an older version of rawhide selinux-policy, circa last week or earlier. I haven't characterized that problem so let's consider that not part of this report, but a confounding factor as to why selinux-policy was perhaps stale.
[root@spillage]# date
um, around 13:30
[root@spillage]# yum update -y selinux-policy
Loaded plugins: langpacks, presto, refresh-packagekit
Setting up Update Process
Resolving Dependencies
--> Running transaction check
---> Package selinux-policy.noarch 0:3.10.0-74.fc17 will be updated
--> Processing Dependency: selinux-policy = 3.10.0-74.fc17 for package: selinux-policy-targeted-3.10.0-74.fc17.noarch
--> Processing Dependency: selinux-policy = 3.10.0-74.fc17 for package: selinux-policy-targeted-3.10.0-74.fc17.noarch
---> Package selinux-policy.noarch 0:3.10.0-74.2.fc17 will be an update
--> Running transaction check
---> Package selinux-policy-targeted.noarch 0:3.10.0-74.fc17 will be updated
---> Package selinux-policy-targeted.noarch 0:3.10.0-74.2.fc17 will be an update
--> Finished Dependency Resolution
Dependencies Resolved
================================================================================
Package Arch Version Repository Size
================================================================================
Updating:
selinux-policy noarch 3.10.0-74.2.fc17 rawhide 809 k
Updating for dependencies:
selinux-policy-targeted noarch 3.10.0-74.2.fc17 rawhide 3.2 M
Transaction Summary
================================================================================
Upgrade 1 Package (+1 Dependent package)
Total download size: 4.0 M
Downloading Packages:
Setting up and reading Presto delta metadata
Processing delta metadata
Download delta size: 214 k
Presto reduced the update size by 74% (from 809 k to 214 k).
Package(s) data still to download: 3.2 M
Running Transaction Check
Running Transaction Test
Transaction Test Succeeded
Running Transaction
Updating : selinux-policy-3.10.0-74.2.fc17.noarch 1/4
Updating : selinux-policy-targeted-3.10.0-74.2.fc17.noarch 2/4
Cleanup : selinux-policy-targeted-3.10.0-74.fc17.noarch 3/4
Cleanup : selinux-policy-3.10.0-74.fc17.noarch 4/4
Verifying : selinux-policy-targeted-3.10.0-74.2.fc17.noarch 1/4
Verifying : selinux-policy-3.10.0-74.2.fc17.noarch 2/4
Verifying : selinux-policy-targeted-3.10.0-74.fc17.noarch 3/4
Verifying : selinux-policy-3.10.0-74.fc17.noarch 4/4
Updated:
selinux-policy.noarch 0:3.10.0-74.2.fc17
Dependency Updated:
selinux-policy-targeted.noarch 0:3.10.0-74.2.fc17
Complete!
[root@spillage]# date
Sat Jan 14 13:33:52 PST 2012
[root@spillage]# date
Sat Jan 14 13:34:56 PST 2012
[root@spillage]# systemctl status systemd-journald.service
systemd-journald.service - Journal Service
Loaded: loaded (/lib/systemd/system/systemd-journald.service; static)
Active: failed since Sat, 14 Jan 2012 09:35:30 -0800; 3h 59min ago
Process: 1408 ExecStart=/lib/systemd/systemd-journald (code=exited, status=1/FAILURE)
Status: "Shutting down..."
CGroup: name=systemd:/system/systemd-journald.service
(as expected, it was down before, it is still down, let's try bringing it up)
[root@spillage]# systemctl restart systemd-journald.service
[root@spillage]# systemctl status systemd-journald.service
systemd-journald.service - Journal Service
Loaded: loaded (/lib/systemd/system/systemd-journald.service; static)
Active: active (running) since Sat, 14 Jan 2012 13:35:03 -0800; 6s ago
Main PID: 4514 (systemd-journal)
Status: "Processing requests..."
CGroup: name=systemd:/system/systemd-journald.service
└ 4514 /lib/systemd/systemd-journald
Jan 14 13:35:03 spillage.local systemd-journal[4514]: Journal started
tail /var/log/messages (since the new selinux-policy was installed and systemd-journald was restarted)
Jan 14 13:33:26 spillage ed: selinux-policy-3.10.0-74.2.fc17.noarch
Jan 14 13:33:41 spillage kernel: [12776.342734] sched: RT throttling activated
Jan 14 13:33:41 spillage dbus[1145]: avc: received policyload notice (seqno=2)
Jan 14 13:33:41 spillage dbus[644]: avc: received policyload notice (seqno=2)
Jan 14 13:33:41 spillage kernel: [12776.451000] type=1403 audit(1326576821.149:49): policy loaded auid=0 ses=2
Jan 14 13:33:41 spillage dbus[644]: [system] Reloaded configuration
Jan 14 13:33:46 spillage ed: selinux-policy-targeted-3.10.0-74.2.fc17.noarch
Jan 14 13:33:49 spillage dbus[644]: [system] Activating service name='org.freedesktop.PackageKit' (using servicehelper)
Jan 14 13:33:49 spillage dbus[644]: [system] Successfully activated service 'org.freedesktop.PackageKit'
Jan 14 13:34:31 spillage dhclient[1075]: DHCPREQUEST on em1 to 192.168.0.44 port 67 (xid=0x737d1075)
Jan 14 13:34:31 spillage dhclient[1075]: DHCPACK from 192.168.0.44 (xid=0x737d1075)
Jan 14 13:34:34 spillage kernel: [12829.455232] type=1400 audit(1326576874.153:50): avc: denied { search } for pid=4502 comm="systemctl" name="log" dev=tmpfs ino=10253 scontext=unconfined_u:system_r:dhcpc_t:s0-s0:c0.c1023 tcontext=system_u:object_r:syslogd_var_run_t:s0 tclass=dir
Jan 14 13:34:34 spillage dhclient[1075]: bound to 192.168.0.81 -- renewal in 807 seconds.
[root@spillage ~]#
I haven't characterized the systemctl-log-search avc denial; that seems like a separate issue.
(still happy?)
# systemctl status systemd-journald.service
systemd-journald.service - Journal Service
Loaded: loaded (/lib/systemd/system/systemd-journald.service; static)
Active: active (running) since Sat, 14 Jan 2012 13:35:03 -0800; 7min ago
Main PID: 4514 (systemd-journal)
Status: "Processing requests..."
CGroup: name=systemd:/system/systemd-journald.service
└ 4514 /lib/systemd/systemd-journald
Jan 14 13:35:03 spillage.local systemd-journal[4514]: Journal started
# date
Sat Jan 14 13:43:25 PST 2012
(still happy ten minutes later)
Probably: notabug, stale selinux-policy
|
Created attachment 555277 [details] grep systemd /var/log/audit/audit.log Description of problem: system-journald has avc issues reading urandom Jan 14 09:35:30 spillage kernel: [ 1180.542611] type=1400 audit(1326562530.489:32): avc: denied { read } for pid=1406 comm="systemd-journal" name="urandom" dev=devtmpfs ino=4573 scontext=system_u:system_r:sy slogd_t:s0 tcontext=system_u:object_r:urandom_device_t:s0 tclass=chr_file Jan 14 09:35:30 spillage systemd[1]: systemd-journald.service: main process exited, code=exited, status=1 Jan 14 09:35:30 spillage kernel: [ 1180.574948] type=1400 audit(1326562530.522:33): avc: denied { read } for pid=1408 comm="systemd-journal" name="urandom" dev=devtmpfs ino=4573 scontext=system_u:system_r:sy slogd_t:s0 tcontext=system_u:object_r:urandom_device_t:s0 tclass=chr_file Jan 14 09:35:30 spillage systemd[1]: systemd-journald.service: main process exited, code=exited, status=1 Version-Release number of selected component (if applicable): # rpm -q -f /lib/systemd/system/systemd-journald.service systemd-units-38-3.fc17.i686 # rpm -q systemd systemd-units-38-3.fc17.i686 systemd-38-3.fc17.i686 How reproducible: yes Steps to Reproduce: 1. install rawhide 2. observe /var/log/messages 3. obsreve /var/log/audit/audit.log Actual results: [root@spillage network-scripts]# systemctl status systemd-journald.service systemd-journald.service - Journal Service Loaded: loaded (/lib/systemd/system/systemd-journald.service; static) Active: failed since Sat, 14 Jan 2012 09:35:30 -0800; 1h 25min ago Process: 1408 ExecStart=/lib/systemd/systemd-journald (code=exited, status=1/FAILURE) Status: "Shutting down..." CGroup: name=systemd:/system/systemd-journald.service Expected results: no avc complaints if it's up then it's up, it shouldn't spontaneously shut down. Additional info: see the attached audit.log fragment Jan 14 09:35:30 spillage kernel: [ 1180.420558] type=1400 audit(1326562530.367:28): avc: denied { read } for pid=1398 comm="systemd-journal" name="urandom" dev=devtmpfs ino=4573 scontext=system_u:system_r:sy slogd_t:s0 tcontext=system_u:object_r:urandom_device_t:s0 tclass=chr_file Jan 14 09:35:30 spillage systemd[1]: systemd-journald.service: main process exited, code=exited, status=1 Jan 14 09:35:30 spillage kernel: [ 1180.451819] type=1400 audit(1326562530.399:29): avc: denied { read } for pid=1400 comm="systemd-journal" name="urandom" dev=devtmpfs ino=4573 scontext=system_u:system_r:sy slogd_t:s0 tcontext=system_u:object_r:urandom_device_t:s0 tclass=chr_file Jan 14 09:35:30 spillage systemd[1]: systemd-journald.service: main process exited, code=exited, status=1 Jan 14 09:35:30 spillage kernel: [ 1180.486288] type=1400 audit(1326562530.433:30): avc: denied { read } for pid=1402 comm="systemd-journal" name="urandom" dev=devtmpfs ino=4573 scontext=system_u:system_r:sy slogd_t:s0 tcontext=system_u:object_r:urandom_device_t:s0 tclass=chr_file Jan 14 09:35:30 spillage systemd[1]: systemd-journald.service: main process exited, code=exited, status=1 Jan 14 09:35:30 spillage kernel: [ 1180.512983] type=1400 audit(1326562530.460:31): avc: denied { read } for pid=1404 comm="systemd-journal" name="urandom" dev=devtmpfs ino=4573 scontext=system_u:system_r:sy slogd_t:s0 tcontext=system_u:object_r:urandom_device_t:s0 tclass=chr_file Jan 14 09:35:30 spillage systemd[1]: systemd-journald.service: main process exited, code=exited, status=1 Jan 14 09:35:30 spillage kernel: [ 1180.542611] type=1400 audit(1326562530.489:32): avc: denied { read } for pid=1406 comm="systemd-journal" name="urandom" dev=devtmpfs ino=4573 scontext=system_u:system_r:sy slogd_t:s0 tcontext=system_u:object_r:urandom_device_t:s0 tclass=chr_file Jan 14 09:35:30 spillage systemd[1]: systemd-journald.service: main process exited, code=exited, status=1 Jan 14 09:35:30 spillage kernel: [ 1180.574948] type=1400 audit(1326562530.522:33): avc: denied { read } for pid=1408 comm="systemd-journal" name="urandom" dev=devtmpfs ino=4573 scontext=system_u:system_r:sy slogd_t:s0 tcontext=system_u:object_r:urandom_device_t:s0 tclass=chr_file Jan 14 09:35:30 spillage systemd[1]: systemd-journald.service: main process exited, code=exited, status=1