Bug 1585802 - Unable to pull new images from any Docker registry when SELinux is enabled
Summary: Unable to pull new images from any Docker registry when SELinux is enabled
Keywords:
Status: CLOSED WORKSFORME
Alias: None
Product: Fedora
Classification: Fedora
Component: docker
Version: 28
Hardware: x86_64
OS: Linux
unspecified
high
Target Milestone: ---
Assignee: Daniel Walsh
QA Contact: Fedora Extras Quality Assurance
URL:
Whiteboard:
Depends On:
Blocks:
TreeView+ depends on / blocked
 
Reported: 2018-06-04 19:01 UTC by Justin Wheeler
Modified: 2018-08-31 16:02 UTC (History)
13 users (show)

Fixed In Version:
Clone Of:
Environment:
Last Closed: 2018-08-31 16:02:10 UTC
Type: Bug
Embargoed:


Attachments (Terms of Use)

Description Justin Wheeler 2018-06-04 19:01:55 UTC
Whenever I try to pull an image with Docker on my Fedora 28 system, the connections time out while waiting for headers. Disabling SELinux fixes the problem and images are successfully pulled from registries.



### Expected behavior

**Note**: This *does* happen if I disable SELinux (`setenforce 0`).

    $ docker run -it --rm centos:latest bash
    Unable to find image 'centos:latest' locally
    Trying to pull repository docker.io/library/centos ... 
    sha256:67b491e26d566ee9c55578bfd6115554a6e1b805a49502ead32cb1a324466f2c: Pulling from docker.io/library/centos
    987d765a926d: Pull complete 
    Digest: sha256:67b491e26d566ee9c55578bfd6115554a6e1b805a49502ead32cb1a324466f2c
    Status: Downloaded newer image for docker.io/centos:latest



### Actual behavior

What happens when SELinux is enabled:

    $ docker run -it --rm centos:latest bash
    Unable to find image 'centos:latest' locally
    Trying to pull repository docker.io/library/centos ... 
    Trying to pull repository registry.fedoraproject.org/centos ... 
    Trying to pull repository quay.io/centos ... 
    Trying to pull repository registry.access.redhat.com/centos ... 
    Trying to pull repository docker.io/library/centos ... 
    /usr/bin/docker-current: Get https://registry-1.docker.io/v2/: net/http: request canceled while waiting for connection (Client.Timeout exceeded while awaiting headers).
    See '/usr/bin/docker-current run --help'.



### Background

I've noticed this for the last couple of Fedora releases, but I haven't had a chance to debug it further until recently.



### Details

I've tried the following to debug my problem:

1. Run Docker in debug mode
2. Check for errors or issues in systemd logs
3. Check for SELinux denials in `audit.log`

I set Docker to run in debug mode, per the `/etc/docker/daemon.json` file:

    {
      "debug": true
    }

I tailed the systemd logs for Docker (`journalctl -f -u docker`), but it yielded no new information.

    Jun 04 13:31:59 fossbook.justinwflory.com dockerd-current[5056]: time="2018-06-04T13:31:59.125852937-05:00" level=error msg="Handler for POST /v1.26/containers/create returned error: No such image: centos:latest"
    Jun 04 13:32:14 fossbook.justinwflory.com dockerd-current[5056]: time="2018-06-04T13:32:14.130985506-05:00" level=warning msg="Error getting v2 registry: Get https://registry-1.docker.io/v2/: net/http: request canceled while waiting for connection (Client.Timeout exceeded while awaiting headers)"
    Jun 04 13:32:14 fossbook.justinwflory.com dockerd-current[5056]: time="2018-06-04T13:32:14.131117960-05:00" level=error msg="Attempting next endpoint for pull after error: Get https://registry-1.docker.io/v2/: net/http: request canceled while waiting for connection (Client.Timeout exceeded while awaiting headers)"
    Jun 04 13:34:29 fossbook.justinwflory.com dockerd-current[5056]: time="2018-06-04T13:34:29.142313716-05:00" level=warning msg="Error getting v2 registry: Get https://registry.fedoraproject.org/v2/: net/http: request canceled while waiting for connection (Client.Timeout exceeded while awaiting headers)"
    Jun 04 13:34:29 fossbook.justinwflory.com dockerd-current[5056]: time="2018-06-04T13:34:29.142431187-05:00" level=error msg="Attempting next endpoint for pull after error: Get https://registry.fedoraproject.org/v2/: net/http: request canceled while waiting for connection (Client.Timeout exceeded while awaiting headers)"
    Jun 04 13:36:44 fossbook.justinwflory.com dockerd-current[5056]: time="2018-06-04T13:36:44.248503828-05:00" level=error msg="Attempting next endpoint for pull after error: Get https://registry.fedoraproject.org/v1/_ping: dial tcp: i/o timeout"
    Jun 04 13:38:59 fossbook.justinwflory.com dockerd-current[5056]: time="2018-06-04T13:38:59.319214287-05:00" level=warning msg="Error getting v2 registry: Get https://quay.io/v2/: net/http: request canceled while waiting for connection (Client.Timeout exceeded while awaiting headers)"
    Jun 04 13:38:59 fossbook.justinwflory.com dockerd-current[5056]: time="2018-06-04T13:38:59.319842249-05:00" level=error msg="Attempting next endpoint for pull after error: Get https://quay.io/v2/: net/http: request canceled while waiting for connection (Client.Timeout exceeded while awaiting headers)"
    Jun 04 13:41:14 fossbook.justinwflory.com dockerd-current[5056]: time="2018-06-04T13:41:14.351227680-05:00" level=error msg="Attempting next endpoint for pull after error: Get https://quay.io/v1/_ping: dial tcp: i/o timeout"
    Jun 04 13:43:29 fossbook.justinwflory.com dockerd-current[5056]: time="2018-06-04T13:43:29.459856743-05:00" level=warning msg="Error getting v2 registry: Get https://registry.access.redhat.com/v2/: net/http: request canceled while waiting for connection (Client.Timeout exceeded while awaiting headers)"
    Jun 04 13:43:29 fossbook.justinwflory.com dockerd-current[5056]: time="2018-06-04T13:43:29.459965386-05:00" level=error msg="Attempting next endpoint for pull after error: Get https://registry.access.redhat.com/v2/: net/http: request canceled while waiting for connection (Client.Timeout exceeded while awaiting headers)"
    Jun 04 13:45:44 fossbook.justinwflory.com dockerd-current[5056]: time="2018-06-04T13:45:44.524412574-05:00" level=error msg="Attempting next endpoint for pull after error: Get https://registry.access.redhat.com/v1/_ping: dial tcp: i/o timeout"
    Jun 04 13:45:59 fossbook.justinwflory.com dockerd-current[5056]: time="2018-06-04T13:45:59.526067302-05:00" level=warning msg="Error getting v2 registry: Get https://registry-1.docker.io/v2/: net/http: request canceled while waiting for connection (Client.Timeout exceeded while awaiting headers)"
    Jun 04 13:45:59 fossbook.justinwflory.com dockerd-current[5056]: time="2018-06-04T13:45:59.526139072-05:00" level=error msg="Attempting next endpoint for pull after error: Get https://registry-1.docker.io/v2/: net/http: request canceled while waiting for connection (Client.Timeout exceeded while awaiting headers)"

I tailed the `audit.log` for more information, but I did not see any `type=USER_AVC` issues in the log for the time period when I used Docker.

I am completely stumped on this one. I'm not sure how to debug further. Is there any way I can resolve this issue without disabling SELinux on my system?

Comment 1 Daniel Walsh 2018-06-29 10:05:39 UTC
So you are not seeing any AVC messages?

If not try turning off the dontaudit messages.

# semodule -DB
run your commands 
See if you have new audit messages
# semodule -B 
Turns the dontaudits back on.

If I had a guess I would figure there is a labeling problem in /var/lib/docker
restorecon -R -v /var/lib/docker

Alsohave you tried podman?

Comment 2 Justin Wheeler 2018-06-29 18:19:38 UTC
Thank you for the reply.

(In reply to Daniel Walsh from comment #1)
> So you are not seeing any AVC messages?
> 
> If not try turning off the dontaudit messages.
> 

I tried turning them off, and now I see several of these messages when Docker is trying to pull a container. All occurrences of this AVC message are mostly similar and are for the same pid/uid:

type=USER_AVC msg=audit(1530295827.551:412): pid=1113 uid=81 auid=4294967295 ses=4294967295 subj=system_u:system_r:system_dbusd_t:s0-s0:c0.c1023 msg='avc:  denied  { send_msg } for msgtype=method_return dest=:1.440 spid=1071 tpid=4163 scontext=system_u:system_r:systemd_resolved_t:s0 tcontext=system_u:system_r:container_runtime_t:s0 tclass=dbus permissive=0  exe="/usr/bin/dbus-daemon" sauid=81 hostname=? addr=? terminal=?'

I'm not sure how to make sense of this message or what it means.


> If I had a guess I would figure there is a labeling problem in
> /var/lib/docker
> restorecon -R -v /var/lib/docker
> 

I forgot to mention I've also tried a full filesystem relabel twice before filing this bug (`touch /.autorelabel`). However, restoring context on this directory still changed some labels when I ran this. It did not solve the original issue, however.

# restorecon -R -v /var/lib/docker
/var/lib/docker/containers/37700f7d182e0e1a0f2bcc8ba2c95007c78c7d136f4a3d5d57bf2cd0668fcc5b/resolv.conf not reset as customized by admin to system_u:object_r:container_file_t:s0:c298,c334
/var/lib/docker/containers/37700f7d182e0e1a0f2bcc8ba2c95007c78c7d136f4a3d5d57bf2cd0668fcc5b/secrets not reset as customized by admin to system_u:object_r:container_file_t:s0:c298,c334
/var/lib/docker/containers/37700f7d182e0e1a0f2bcc8ba2c95007c78c7d136f4a3d5d57bf2cd0668fcc5b/secrets/rhsm not reset as customized by admin to system_u:object_r:container_file_t:s0:c298,c334
/var/lib/docker/containers/37700f7d182e0e1a0f2bcc8ba2c95007c78c7d136f4a3d5d57bf2cd0668fcc5b/secrets/rhsm/ca not reset as customized by admin to system_u:object_r:container_file_t:s0:c298,c334
/var/lib/docker/containers/37700f7d182e0e1a0f2bcc8ba2c95007c78c7d136f4a3d5d57bf2cd0668fcc5b/secrets/rhsm/ca/redhat-uep.pem not reset as customized by admin to system_u:object_r:container_file_t:s0:c298,c334
/var/lib/docker/containers/37700f7d182e0e1a0f2bcc8ba2c95007c78c7d136f4a3d5d57bf2cd0668fcc5b/hostname not reset as customized by admin to system_u:object_r:container_file_t:s0:c298,c334
/var/lib/docker/containers/37700f7d182e0e1a0f2bcc8ba2c95007c78c7d136f4a3d5d57bf2cd0668fcc5b/hosts not reset as customized by admin to system_u:object_r:container_file_t:s0:c298,c334


> Alsohave you tried podman?

I have not. What do you recommend I try?

Comment 3 Justin Wheeler 2018-08-30 21:36:59 UTC
Has anyone had a chance to look at this? I am still experiencing this issue.

Comment 4 Daniel Walsh 2018-08-31 11:54:17 UTC
Try
dnf -y reinstall container-selinux
restorecon -R -v /var/lib/docker

I think this will solve your problem.
Also have you tried podman?

Comment 5 Justin Wheeler 2018-08-31 16:02:10 UTC
(In reply to Daniel Walsh from comment #4)
> dnf -y reinstall container-selinux
> restorecon -R -v /var/lib/docker
> 
> I think this will solve your problem.

The reinstall appears to have fixed it. I had tried reinstalling different Docker / container packages, but not this one. Since there was no output of restorecon, I assume the package reinstall was the fix.

Not sure why this solved it, but thanks – it is good to finally have Docker and SELinux playing nicely on Fedora.

> Also have you tried podman?

Not yet, but it's on my list from what I've been reading about it.


Note You need to log in before you can comment on or make changes to this bug.