Description of problem: Sep 09 12:34:59 localhost.localdomain oci-register-machine[6027]: 2016/09/09 12:34:59 Register machine: prestart e86d1bdd67fc7a64ab918b0f960c315a127a5e0d313b6719a2e88e575e416307 6004 /var/lib/docker/devicemapper/mnt/4f12b0ed721c4458a1bdf2b853067944a24a4dbbd66f6dcbf2d30afb4282ec7d/rootfs Sep 09 12:34:59 localhost.localdomain systemd-machined[2031]: New machine e86d1bdd67fc7a64ab918b0f960c315a. Sep 09 12:34:59 localhost.localdomain oci-systemd-hook[6030]: systemdhook <debug>: Skipping as container command is /pause, not init or systemd Sep 09 12:34:59 localhost.localdomain systemd[1]: libcontainer-6032-systemd-test-default-dependencies.scope: Scope has no PIDs. Refusing. Sep 09 12:34:59 localhost.localdomain systemd[1]: libcontainer-6032-systemd-test-default-dependencies.scope: Scope has no PIDs. Refusing. Sep 09 12:34:59 localhost.localdomain audit[6004]: AVC avc: denied { transition } for pid=6004 comm="exe" path="/pause" dev="dm-3" ino=133 scontext=system_u:system_r:unconfined_service_t:s0 tcontext=system_u:system_r:svirt_lxc_net_t:s0:c185,c583 tclass=process permissive=0 Sep 09 12:34:59 localhost.localdomain audit[6004]: SYSCALL arch=c000003e syscall=59 success=no exit=-13 a0=c42010c777 a1=c42010c790 a2=c4200ec780 a3=0 items=0 ppid=5989 pid=6004 auid=4294967295 uid=0 gid=0 euid=0 suid=0 fsuid=0 egid=0 sgid=0 fsgid=0 tty=(none) ses=4294967295 comm="exe" exe="/usr/libexec/docker/docker-runc" subj=system_u:system_r:unconfined_service_t:s0 key=(null) Sep 09 12:34:59 localhost.localdomain audit: PROCTITLE proctitle=2F7573722F6C6962657865632F646F636B65722F646F636B65722D72756E6300696E6974 Sep 09 12:34:59 localhost.localdomain dockerd[1324]: standard_init_linux.go:175: exec user process caused "permission denied" Sep 09 12:34:59 localhost.localdomain systemd-machined[2031]: Machine e86d1bdd67fc7a64ab918b0f960c315a terminated. Sep 09 12:34:59 localhost.localdomain systemd[1]: libcontainer-6041-systemd-test-default-dependencies.scope: Scope has no PIDs. Refusing. Sep 09 12:34:59 localhost.localdomain systemd[1]: libcontainer-6041-systemd-test-default-dependencies.scope: Scope has no PIDs. Refusing. Sep 09 12:34:59 localhost.localdomain oci-register-machine[6045]: 2016/09/09 12:34:59 Register machine: poststop e86d1bdd67fc7a64ab918b0f960c315a127a5e0d313b6719a2e88e575e416307 0 /var/lib/docker/devicemapper/mnt/4f12b0ed721c4458a1bdf2b853067944a24a4dbbd66f6dcbf2d30afb4282ec7d/rootfs Sep 09 12:34:59 localhost.localdomain oci-register-machine[6045]: 2016/09/09 12:34:59 TerminateMachine failed: No machine 'e86d1bdd67fc7a64ab918b0f960c315a127a5e0d313b6719a2e88e575e416307' known Version-Release number of selected component (if applicable): kubernetes-1.2.0-0.27.git4a3f9c5.fc25.x86_64 oci-register-machine-0-2.4.git352a2a2.fc25.x86_64 docker-1.12.1-9.git2649fe1.fc25.x86_64 selinux-policy-3.13.1-211.fc25.noarch How reproducible: Happens during Cockpit integration tests related to kubernetes. https://stefw.fedorapeople.org/logs/pull-ba275a3a-verify-fedora-25/TestKubernetes-testTopology-10.111.126.126-FAIL.log
ls -lZ /usr/bin/docker* ps -eZ | grep docker Looks like docker is not running as docker_t
Indeed. This is on a freshly upgraded Fedora 24 -> Fedora 25 system: # ls -lZ /usr/bin/docker* -rwxr-xr-x. 1 root root system_u:object_r:bin_t:s0 10080176 Sep 2 04:27 /usr/bin/docker -rwxr-xr-x. 1 root root system_u:object_r:bin_t:s0 28510904 Sep 2 04:27 /usr/bin/dockerd -rwxr-xr-x. 1 root root system_u:object_r:bin_t:s0 1683432 Sep 2 04:27 /usr/bin/docker-proxy -rwxr-xr-x. 1 root root system_u:object_r:bin_t:s0 27660 May 10 10:45 /usr/bin/docker-storage-setup # ps -eZ | grep docker system_u:system_r:unconfined_service_t:s0 1503 ? 00:00:00 docker-containe system_u:system_r:unconfined_service_t:s0 1577 ? 00:00:00 dockerd In addition a yum distro-sync, I see this upgrade: docker x86_64 2:1.12.1-10.git9a3752d.fc25 updates-testing 17 M docker-selinux x86_64 2:1.12.1-10.git9a3752d.fc25 updates-testing 75 k However while running the upgrade ... Upgrading : docker-selinux-2:1.12.1-10.git9a3752d.fc25.x86_64 47/145 [ 444.157270] SELinux: Permission validate_trans in class security not defined in policy. [ 444.157805] SELinux: Permission module_load in class system not defined in policy. [ 444.158327] SELinux: the above unknown classes and permissions will be allowed [ 444.657423] audit: type=1107 audit(1473664223.376:215): pid=813 uid=81 auid=4294967295 ses=4294967295 subj=system_u:system_r:system_dbusd_t:s0-s0:c0.c1023 msg='avc: received policyload notice (seqno=2) [ 444.657423] exe="/usr/bin/dbus-daemon" sauid=81 hostname=? addr=? terminal=?' [ 444.663798] audit: type=1403 audit(1473664222.840:216): policy loaded auid=0 ses=1 [ 444.664418] audit: type=1300 audit(1473664222.840:216): arch=c000003e syscall=1 success=yes exit=3810206 a0=4 a1=7faca28eb000 a2=3a239e a3=73 items=0 ppid=1924 pid=1930 auid=0 uid=0 gid=0 euid=0 suid=0 fsuid=0 egid=0 sgid=0 fsgid=0 tty=ttyS0 ses=1 comm="load_policy" exe="/usr/sbin/load_policy" subj=unconfined_u:unconfined_r:load_policy_t:s0-s0:c0.c1023 key=(null) [ 444.666786] audit: type=1327 audit(1473664222.840:216): proctitle="/usr/sbin/load_policy" /etc/selinux/targeted/contexts/files/file_contexts: Multiple different specifications for /var/lib/kubelet(/.*)? (system_u:object_r:svirt_sandbox_file_t:s0 and system_u:object_r:docker_var_lib_t:s0). /etc/selinux/targeted/contexts/files/file_contexts: Invalid argument libsemanage.semanage_install_final_tmp: setfiles returned error code 1. (No such file or directory). /etc/selinux/targeted/contexts/files/file_contexts: Multiple different specifications for /var/lib/kubelet(/.*)? (system_u:object_r:svirt_sandbox_file_t:s0 and system_u:object_r:docker_var_lib_t:s0). /etc/selinux/targeted/contexts/files/file_contexts: Invalid argument libsemanage.semanage_install_final_tmp: setfiles returned error code 1. (No such file or directory). /usr/sbin/semodule: Failed! Upgrading : docker-2:1.12.1-10.git9a3752d.fc25.x86_64 48/145 Upgrading : cockpit-ws-118-1.fc25.x86_64 49/145 [ 449.296476] audit: type=1325 audit(1473664228.015:217): table=filter family=7 entries=3 [ 449.297106] audit: type=1300 audit(1473664228.015:217): arch=c000003e syscall=54 success=yes exit=0 a0=3 a1=0 a2=80 a3=55ef17e44530 items=0 ppid=850 pid=1944 auid=4294967295 uid=0 gid=0 euid=0 suid=0 fsuid=0 egid=0 sgid=0 fsgid=0 tty=(none) ses=4294967295 comm="ebtables-restor" exe="/usr/sbin/ebtables-restore" subj=system_u:system_r:iptables_t:s0 key=(null) [ 449.298932] audit: type=1327 audit(1473664228.015:217): proctitle=2F7573722F7362696E2F65627461626C65732D726573746F7265002D2D6E6F666C757368 [ 449.299719] audit: type=1325 audit(1473664228.018:218): table=broute family=7 entries=1 [ 449.300248] audit: type=1300 audit(1473664228.018:218): arch=c000003e syscall=54 success=yes exit=0 a0=3 a1=0 a2=80 a3=55ef17e44a20 items=0 ppid=850 pid=1944 auid=4294967295 uid=0 gid=0 euid=0 suid=0 fsuid=0 egid=0 sgid=0 fsgid=0 tty=(none) ses=4294967295 comm="ebtables-restor" exe="/usr/sbin/ebtables-restore" subj=system_u:system_r:iptables_t:s0 key=(null) [ 449.302070] audit: type=1327 audit(1473664228.018:218): proctitle=2F7573722F7362696E2F65627461626C65732D726573746F7265002D2D6E6F666C757368 Upgrading : skopeo-0.1.14-2.git362bfc5 [========== ] 50/145[ 449.661735] audit_printk_skb: 414 callbacks suppressed [ 449.662080] audit: type=1325 audit(1473664228.381:265): table=filter family=2 entries=100 [ 449.662590] audit: type=1300 audit(1473664228.381:265): arch=c000003e syscall=54 success=yes exit=0 a0=4 a1=0 a2=40 a3=55baa4e94320 items=0 ppid=850 pid=1995 auid=4294967295 uid=0 gid=0 euid=0 suid=0 fsuid=0 egid=0 sgid=0 fsgid=0 tty=(none) ses=4294967295 comm="iptables" exe="/usr/sbin/xtables-multi" subj=system_u:system_r:iptables_t:s0 key=(null) Upgrading : skopeo-0.1.14-2.git362bfc5 [=========== ] 50/145[ 449.667795] audit: type=1327 audit(1473664228.381:265): proctitle=2F7573722F7362696E2F69707461626C6573002D7732002D4900464F5257415244002D6900646F636B6572300000002D6F00646F636B657230002D6A00414343455054 [ 449.673875] audit: type=1325 audit(1473664228.393:266): table=nat family=2 entries=57 [ 449.674406] audit: type=1300 audit(1473664228.393:266): arch=c000003e syscall=54 success=yes exit=0 a0=4 a1=0 a2=40 a3=55cd30f3d290 items=0 ppid=850 pid=1996 auid=4294967295 uid=0 gid=0 euid=0 suid=0 fsuid=0 egid=0 sgid=0 fsgid=0 tty=(none) ses=4294967295 comm="iptables" exe="/usr/sbin/xtables-multi" subj=system_u:system_r:iptables_t:s0 key=(null) Upgrading : skopeo-0.1.14-2.git362bfc5 [============ ] 50/145[ 449.680802] audit: type=1327 audit(1473664228.393:266): proctitle=2F7573722F7362696E2F69707461626C6573002D7732002D77002D2D7461626C65006E6174002D2D696E7365727400504F5354524F5554494E47002D2D736F75726365003139322E3136382E3132322E302F3234002D70007564700000002D2D64657374696E6174696F6E003139322E3136382E3132322E302F3234002D2D6A Upgrading : skopeo-0.1.14-2.git362bfc5 [============= ] 50/145[ 449.696592] audit: type=1325 audit(1473664228.415:267): table=nat family=2 entries=58 [ 449.697108] audit: type=1300 audit(1473664228.415:267): arch=c000003e syscall=54 success=yes exit=0 a0=4 a1=0 a2=40 a3=557c8fc20430 items=0 ppid=850 pid=1998 auid=4294967295 uid=0 gid=0 euid=0 suid=0 fsuid=0 egid=0 sgid=0 fsgid=0 tty=(none) ses=4294967295 comm="iptables" exe="/usr/sbin/xtables-multi" subj=system_u:system_r:iptables_t:s0 key=(null) [ 449.702806] audit: type=1327 audit(1473664228.415:267): proctitle=2F7573722F7362696E2F69707461626C6573002D7732002D77002D2D7461626C65006E6174002D2D696E7365727400504F5354524F5554494E47002D2D736F75726365003139322E3136382E3132322E302F3234002D70007463700000002D2D64657374696E6174696F6E003139322E3136382E3132322E302F3234002D2D6A Upgrading : skopeo-0.1.14-2.git362bfc5 [============== ] 50/145[ 449.714720] audit: type=1325 audit(1473664228.432:268): table=filter family=2 entries=101 Upgrading : skopeo-0.1.14-2.git362bfc5.fc25.x86_64 50/145 And sure enough after a reboot, the problem persists. Similar to bug #1358819 ?
Need an updated docker-selinux package for F25. F25 is behind the Rawhide package right now and their is a conflict between selinux-policy and docker-selinux. We need to get the latest docker-selinux into F25.
docker-1.12.1-12.git9a3752d.fc25 has been submitted as an update to Fedora 25. https://bodhi.fedoraproject.org/updates/FEDORA-2016-094a559bf8
docker-1.12.1-12.git9a3752d.fc25 has been pushed to the Fedora 25 testing repository. If problems still persist, please make note of it in this bug report. See https://fedoraproject.org/wiki/QA:Updates_Testing for instructions on how to install test updates. You can provide feedback for this update here: https://bodhi.fedoraproject.org/updates/FEDORA-2016-094a559bf8
Even with the above mentioned updated it is still failing. [fedora@kushal-f25 ~]$ uname -a Linux kushal-f25.novalocal 4.8.0-0.rc5.git4.1.fc25.x86_64 #1 SMP Fri Sep 9 22:08:28 UTC 2016 x86_64 x86_64 x86_64 GNU/Linux [fedora@kushal-f25 ~]$ rpm -q docker-selinux docker selinux-policy docker-selinux-1.12.1-12.git9a3752d.fc25.x86_64 docker-1.12.1-12.git9a3752d.fc25.x86_64 selinux-policy-3.13.1-211.fc25.noarch $ sudo docker run -it --rm centos:7 standard_init_linux.go:175: exec user process caused "permission denied >From journalctl Sep 14 19:14:59 kushal-f25.novalocal systemd-machined[1128]: New machine 51b4d247cf2f105601eaebfc55c74b26. Sep 14 19:14:59 kushal-f25.novalocal oci-systemd-hook[1145]: systemdhook <debug>: Skipping as container command is /bin/bash, not init or systemd Sep 14 19:14:59 kushal-f25.novalocal systemd[1]: libcontainer-1152-systemd-test-default-dependencies.scope: Scope has no PIDs. Refusing. Sep 14 19:14:59 kushal-f25.novalocal systemd[1]: libcontainer-1152-systemd-test-default-dependencies.scope: Scope has no PIDs. Refusing. Sep 14 19:14:59 kushal-f25.novalocal audit[1051]: AVC avc: denied { entrypoint } for pid=1051 comm="exe" path="/usr/bin/bash" dev="overlay" ino=18 Sep 14 19:14:59 kushal-f25.novalocal dockerd[880]: [73B blob data] Sep 14 19:14:59 kushal-f25.novalocal systemd-machined[1128]: Machine 51b4d247cf2f105601eaebfc55c74b26 terminated. Sep 14 19:14:59 kushal-f25.novalocal audit[880]: VIRT_CONTROL pid=880 uid=0 auid=4294967295 ses=4294967295 subj=system_u:system_r:docker_t:s0 msg='vm Sep 14 19:14:59 kushal-f25.novalocal systemd[1]: libcontainer-1164-systemd-test-default-dependencies.scope: Scope has no PIDs. Refusing. Sep 14 19:14:59 kushal-f25.novalocal docker[880]: time="2016-09-14T19:14:59.208938038Z" level=info msg="{Action=resize, Username=fedora, LoginUID=100 Sep 14 19:14:59 kushal-f25.novalocal systemd[1]: libcontainer-1164-systemd-test-default-dependencies.scope: Scope has no PIDs. Refusing. Sep 14 19:14:59 kushal-f25.novalocal oci-register-machine[1173]: 2016/09/14 19:14:59 Register machine: poststop 51b4d247cf2f105601eaebfc55c74b26dcef9 Sep 14 19:14:59 kushal-f25.novalocal oci-register-machine[1173]: 2016/09/14 19:14:59 TerminateMachine failed: No machine '51b4d247cf2f105601eaebfc55c Sep 14 19:14:59 kushal-f25.novalocal docker[880]: time="2016-09-14T19:14:59.281096569Z" level=error msg="Handler for POST /v1.24/containers/51b4d247c Sep 14 19:14:59 kushal-f25.novalocal kernel: docker0: port 1(veth0648986) entered disabled state
Could you show the actual avc? ausearch -m avc
(In reply to Daniel Walsh from comment #7) > Could you show the actual avc? > > ausearch -m avc $ sudo ausearch -m avc ---- time->Mon Sep 12 13:11:34 2016 type=AVC msg=audit(1473685894.390:78): avc: denied { getattr } for pid=1 comm="systemd" path="/run/systemd/inaccessible/blk" dev="tmpfs" ino=1200 scontext=system_u:system_r:init_t:s0 tcontext=system_u:object_r:tmpfs_t:s0 tclass=blk_file permissive=0 ---- time->Mon Sep 12 13:18:19 2016 type=AVC msg=audit(1473686299.082:67): avc: denied { getattr } for pid=1 comm="systemd" path="/run/systemd/inaccessible/blk" dev="tmpfs" ino=1200 scontext=system_u:system_r:init_t:s0 tcontext=system_u:object_r:tmpfs_t:s0 tclass=blk_file permissive=0 ---- time->Mon Sep 12 13:26:09 2016 type=AVC msg=audit(1473686769.079:150): avc: denied { entrypoint } for pid=1021 comm="exe" path="/usr/bin/bash" dev="overlay" ino=17927 scontext=system_u:system_r:svirt_lxc_net_t:s0:c196,c220 tcontext=system_u:object_r:docker_var_lib_t:s0 tclass=file permissive=0 ---- time->Mon Sep 12 20:18:51 2016 type=AVC msg=audit(1473711531.459:79): avc: denied { getattr } for pid=1 comm="systemd" path="/run/systemd/inaccessible/blk" dev="tmpfs" ino=1261 scontext=system_u:system_r:init_t:s0 tcontext=system_u:object_r:tmpfs_t:s0 tclass=blk_file permissive=0 ---- time->Tue Sep 13 07:45:43 2016 type=AVC msg=audit(1473752743.922:556): avc: denied { getattr } for pid=1 comm="systemd" path="/run/systemd/inaccessible/blk" dev="tmpfs" ino=1261 scontext=system_u:system_r:init_t:s0 tcontext=system_u:object_r:tmpfs_t:s0 tclass=blk_file permissive=0 ---- time->Tue Sep 13 17:35:20 2016 type=AVC msg=audit(1473788120.871:1774): avc: denied { getattr } for pid=1 comm="systemd" path="/run/systemd/inaccessible/blk" dev="tmpfs" ino=1261 scontext=system_u:system_r:init_t:s0 tcontext=system_u:object_r:tmpfs_t:s0 tclass=blk_file permissive=0 ---- time->Wed Sep 14 02:58:27 2016 type=AVC msg=audit(1473821907.886:3268): avc: denied { getattr } for pid=1 comm="systemd" path="/run/systemd/inaccessible/blk" dev="tmpfs" ino=1261 scontext=system_u:system_r:init_t:s0 tcontext=system_u:object_r:tmpfs_t:s0 tclass=blk_file permissive=0 ---- time->Wed Sep 14 12:08:03 2016 type=AVC msg=audit(1473854883.314:3968): avc: denied { getattr } for pid=1 comm="systemd" path="/run/systemd/inaccessible/blk" dev="tmpfs" ino=1261 scontext=system_u:system_r:init_t:s0 tcontext=system_u:object_r:tmpfs_t:s0 tclass=blk_file permissive=0 ---- time->Wed Sep 14 19:12:02 2016 type=AVC msg=audit(1473880322.594:79): avc: denied { getattr } for pid=1 comm="systemd" path="/run/systemd/inaccessible/blk" dev="tmpfs" ino=10174 scontext=system_u:system_r:init_t:s0 tcontext=system_u:object_r:tmpfs_t:s0 tclass=blk_file permissive=0 ---- time->Wed Sep 14 19:14:59 2016 type=AVC msg=audit(1473880499.118:160): avc: denied { entrypoint } for pid=1051 comm="exe" path="/usr/bin/bash" dev="overlay" ino=18025 scontext=system_u:system_r:svirt_lxc_net_t:s0:c387,c595 tcontext=system_u:object_r:docker_var_lib_t:s0 tclass=file permissive=0 ---- time->Thu Sep 15 06:50:18 2016 type=AVC msg=audit(1473922218.972:602): avc: denied { getattr } for pid=1 comm="systemd" path="/run/systemd/inaccessible/blk" dev="tmpfs" ino=10174 scontext=system_u:system_r:init_t:s0 tcontext=system_u:object_r:tmpfs_t:s0 tclass=blk_file permissive=0 ---- time->Thu Sep 15 16:56:47 2016 type=AVC msg=audit(1473958607.396:1637): avc: denied { getattr } for pid=1 comm="systemd" path="/run/systemd/inaccessible/blk" dev="tmpfs" ino=10174 scontext=system_u:system_r:init_t:s0 tcontext=system_u:object_r:tmpfs_t:s0 tclass=blk_file permissive=0 ---- time->Fri Sep 16 02:27:43 2016 type=AVC msg=audit(1473992863.644:2230): avc: denied { getattr } for pid=1 comm="systemd" path="/run/systemd/inaccessible/blk" dev="tmpfs" ino=10174 scontext=system_u:system_r:init_t:s0 tcontext=system_u:object_r:tmpfs_t:s0 tclass=blk_file permissive=0 ---- time->Fri Sep 16 11:57:41 2016 type=AVC msg=audit(1474027061.070:2545): avc: denied { getattr } for pid=1 comm="systemd" path="/run/systemd/inaccessible/blk" dev="tmpfs" ino=10174 scontext=system_u:system_r:init_t:s0 tcontext=system_u:object_r:tmpfs_t:s0 tclass=blk_file permissive=0
docker-1.12.1-13.git9a3752d.fc25 has been submitted as an update to Fedora 25. https://bodhi.fedoraproject.org/updates/FEDORA-2016-93c58fa1b3
The entrypoint label is the problem. Are you using overlay or overlay2? Could you run restorecon -R -v /var/lib/docker After updating to the docker-1.12-1-13 release. What is the labels of /var/lib/docker/overlay ls -lZd /var/lib/docker/overlay*
docker-1.12.1-13.git9a3752d.fc25 has been pushed to the Fedora 25 testing repository. If problems still persist, please make note of it in this bug report. See https://fedoraproject.org/wiki/QA:Updates_Testing for instructions on how to install test updates. You can provide feedback for this update here: https://bodhi.fedoraproject.org/updates/FEDORA-2016-93c58fa1b3
using the listed nvr's, docker still fails to run when in enforcing: root@localhost ~]# rpm -q docker docker-selinux selinux-policy docker-1.12.1-13.git9a3752d.fc25.armv7hl docker-selinux-1.12.1-13.git9a3752d.fc25.armv7hl selinux-policy-3.13.1-214.fc25.noarch [root@localhost ~]# docker images REPOSITORY TAG IMAGE ID CREATED SIZE fedora-docker-base-25-20160912.n.0.armhfp latest 3c6a76719b04 8 days ago 184.9 MB [root@localhost ~]# docker run -it --rm fedora-docker-base-25-20160912.n.0.armhfp /bin/bash [root@624530423aff /]# exit [root@localhost ~]# getenforce Permissive [root@localhost ~]# setenforce 1 [root@localhost ~]# docker run -it --rm fedora-docker-base-25-20160912.n.0.armhfp /bin/bash standard_init_linux.go:175: exec user process caused "permission denied" no change after running 'restorecon -R -v /var/lib/docker'
docker-1.12.1-12.git9a3752d.fc25 has been pushed to the Fedora 25 stable repository. If problems still persist, please make note of it in this bug report.
Paul you might be seeing a different bug. Check the labels on the docker daemons ps -eZ | grep docker You can also attach the AVC's that you are seeing ausearch -m avc -ts recent
On a clean installation, docker works as expected, thanks.
docker-1.12.1-13.git9a3752d.fc25 has been pushed to the Fedora 25 stable repository. If problems still persist, please make note of it in this bug report.