Hide Forgot
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
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