Bug 1311758

Can you pull this with docker-1.9?

my f23 boxes don't suffer this bug

Operating System: Fedora 23 (Cloud Edition)

is there anything different - storage wise - probably in a f23 cloud edition?

@dwalsh - I'll go back and try with 1.9.

@runcom - I added a virtual disk to my VM and created a VG from it to be used by d-s-s.  Since both VMs were running on my system, perhaps it is something on my workstation.  I'll try reproducing in a different environment, i.e. bare metal or OpenStack.

I was able to reproduce this on an OpenStack VM running Fedora Cloud 23.

This was done using both 1.10 and 1.9.  And I tested using loopback and thin-pool as backing storage.

Additionally, I was able to reproduce this with the same combinations of version + backing storage using Fedora Server 23 on bare metal.

The failure seems to occur when the image is getting extracted to disk right around the 22.68 MB mark.

1.9.1 + loopback
=================
# docker info
Containers: 0
Images: 1
Server Version: 1.9.1
Storage Driver: devicemapper
 Pool Name: docker-252:1-262312-pool
 Pool Blocksize: 65.54 kB
 Base Device Size: 107.4 GB
 Backing Filesystem: xfs
 Data file: /dev/loop0
 Metadata file: /dev/loop1
 Data Space Used: 295.3 MB
 Data Space Total: 107.4 GB
 Data Space Available: 41.08 GB
 Metadata Space Used: 716.8 kB
 Metadata Space Total: 2.147 GB
 Metadata Space Available: 2.147 GB
 Udev Sync Supported: true
 Deferred Removal Enabled: false
 Deferred Deletion Enabled: false
 Deferred Deleted Device Count: 0
 Data loop file: /var/lib/docker/devicemapper/devicemapper/data
 Metadata loop file: /var/lib/docker/devicemapper/devicemapper/metadata
 Library Version: 1.02.107 (2015-09-05)
Execution Driver: native-0.2
Logging Driver: journald
Kernel Version: 4.2.3-300.fc23.x86_64
Operating System: Fedora 23 (Cloud Edition)
CPUs: 2
Total Memory: 3.86 GiB
Name: micah-fedora-cloud-23-vm0.novalocal
ID: 7LWQ:OBKJ:PDHJ:P67U:TTFN:3UY4:76VZ:EJPH:EEET:ITSU:O4XL:4ZXZ

# docker pull registry.access.redhat.com/rhel6
Using default tag: latest
c631ca2f5641: Downloading 22.68 MB
failed
Error pulling image (latest) from registry.access.redhat.com/rhel6, ApplyLayer exit status 1 stdout:  stderr: invalid argument



1.9.1 + thin-pool
===================
# docker info
Containers: 0
Images: 0
Server Version: 1.9.1
Storage Driver: devicemapper
 Pool Name: fedora-docker--pool
 Pool Blocksize: 524.3 kB
 Base Device Size: 107.4 GB
 Backing Filesystem: xfs
 Data file: 
 Metadata file: 
 Data Space Used: 62.39 MB
 Data Space Total: 8.577 GB
 Data Space Available: 8.515 GB
 Metadata Space Used: 45.06 kB
 Metadata Space Total: 25.17 MB
 Metadata Space Available: 25.12 MB
 Udev Sync Supported: true
 Deferred Removal Enabled: true
 Deferred Deletion Enabled: true
 Deferred Deleted Device Count: 0
 Library Version: 1.02.107 (2015-09-05)
Execution Driver: native-0.2
Logging Driver: journald
Kernel Version: 4.2.3-300.fc23.x86_64
Operating System: Fedora 23 (Cloud Edition)
CPUs: 2
Total Memory: 3.86 GiB
Name: micah-fedora-cloud-23-vm0.novalocal
ID: 7LWQ:OBKJ:PDHJ:P67U:TTFN:3UY4:76VZ:EJPH:EEET:ITSU:O4XL:4ZXZ

# docker pull registry.access.redhat.com/rhel6 
Using default tag: latest
c631ca2f5641: Downloading 22.68 MB
failed
Error pulling image (latest) from registry.access.redhat.com/rhel6, ApplyLayer exit status 1 stdout:  stderr: invalid argument



1.10 + loopback
================
# docker info
Containers: 0
 Running: 0
 Paused: 0
 Stopped: 0
Images: 0
Server Version: 1.10.2
Storage Driver: devicemapper
 Pool Name: docker-252:1-262323-pool
 Pool Blocksize: 65.54 kB
 Base Device Size: 10.74 GB
 Backing Filesystem: xfs
 Data file: /dev/loop0
 Metadata file: /dev/loop1
 Data Space Used: 11.8 MB
 Data Space Total: 107.4 GB
 Data Space Available: 41.35 GB
 Metadata Space Used: 581.6 kB
 Metadata Space Total: 2.147 GB
 Metadata Space Available: 2.147 GB
 Udev Sync Supported: true
 Deferred Removal Enabled: false
 Deferred Deletion Enabled: false
 Deferred Deleted Device Count: 0
 Data loop file: /var/lib/docker/devicemapper/devicemapper/data
 WARNING: Usage of loopback devices is strongly discouraged for production use. Either use `--storage-opt dm.thinpooldev` or use `--storage-opt dm.no_warn_on_loop_devices=true` to suppress this warning.
 Metadata loop file: /var/lib/docker/devicemapper/devicemapper/metadata
 Library Version: 1.02.107 (2015-09-05)
Execution Driver: native-0.2
Logging Driver: journald
Plugins: 
 Volume: local
 Network: null host bridge
Kernel Version: 4.2.3-300.fc23.x86_64
Operating System: Fedora 23 (Cloud Edition)
OSType: linux
Architecture: x86_64
Number of Docker Hooks: 0
CPUs: 2
Total Memory: 3.86 GiB
Name: micah-fedora-cloud-23-vm0.novalocal
ID: 7LWQ:OBKJ:PDHJ:P67U:TTFN:3UY4:76VZ:EJPH:EEET:ITSU:O4XL:4ZXZ
Registries: docker.io (secure)

# docker pull registry.access.redhat.com/rhel6
Using default tag: latest
Trying to pull repository registry.access.redhat.com/rhel6 ... 
Pulling repository registry.access.redhat.com/rhel6
c631ca2f5641: Error pulling image (latest) from registry.access.redhat.com/rhel6, failed to register layer: ApplyLayer exit status 1 stdout:  stderr: invalid argument 
Error pulling image (latest) from registry.access.redhat.com/rhel6, failed to register layer: ApplyLayer exit status 1 stdout:  stderr: invalid argument



1.10 + thin-pool
=================
# docker info
Containers: 0
 Running: 0
 Paused: 0
 Stopped: 0
Images: 0
Server Version: 1.10.2
Storage Driver: devicemapper
 Pool Name: fedora-docker--pool
 Pool Blocksize: 524.3 kB
 Base Device Size: 10.74 GB
 Backing Filesystem: xfs
 Data file: 
 Metadata file: 
 Data Space Used: 20.45 MB
 Data Space Total: 8.577 GB
 Data Space Available: 8.557 GB
 Metadata Space Used: 45.06 kB
 Metadata Space Total: 25.17 MB
 Metadata Space Available: 25.12 MB
 Udev Sync Supported: true
 Deferred Removal Enabled: true
 Deferred Deletion Enabled: true
 Deferred Deleted Device Count: 0
 Library Version: 1.02.107 (2015-09-05)
Execution Driver: native-0.2
Logging Driver: journald
Plugins: 
 Volume: local
 Network: null host bridge
Kernel Version: 4.2.3-300.fc23.x86_64
Operating System: Fedora 23 (Cloud Edition)
OSType: linux
Architecture: x86_64
Number of Docker Hooks: 0
CPUs: 2
Total Memory: 3.86 GiB
Name: micah-fedora-cloud-23-vm0.novalocal
ID: 7LWQ:OBKJ:PDHJ:P67U:TTFN:3UY4:76VZ:EJPH:EEET:ITSU:O4XL:4ZXZ
Registries: docker.io (secure)

# docker pull registry.access.redhat.com/rhel6
Using default tag: latest
Trying to pull repository registry.access.redhat.com/rhel6 ... 
Pulling repository registry.access.redhat.com/rhel6
c631ca2f5641: Error pulling image (latest) from registry.access.redhat.com/rhel6, failed to register layer: ApplyLayer exit status 1 stdout:  stderr: invalid argument 
Error pulling image (latest) from registry.access.redhat.com/rhel6, failed to register layer: ApplyLayer exit status 1 stdout:  stderr: invalid argument

I am getting the same issue on rawhide with latest docker.

docker pull registry.access.redhat.com/rhel6:latestTrying to pull repository registry.access.redhat.com/rhel6 ... 
Pulling repository registry.access.redhat.com/rhel6
c631ca2f5641: Error pulling image (latest) from registry.access.redhat.com/rhel6c631ca2f5641: Error pulling image (latest) from registry.access.redhat.com/rhel6, failed to register layer: ApplyLayer exit status 1 stdout:  stderr: invalid arError pulling image (latest) from registry.access.redhat.com/rhel6, failed to register layer: ApplyLayer exit status 1 stdout:  stderr: invalid argument

Moving this to rhel

According to https://errata.devel.redhat.com/advisory/22738 pull from registry.access.stage.redhat.com was working a week ago. Right now it fails the same way as registry.access.redhat.com:

docker pull registry.access.stage.redhat.com/rhel6
Using default tag: latest
c631ca2f5641: Downloading 22.69 MB
failed
Error pulling image (latest) from registry.access.stage.redhat.com/rhel6, ApplyLayer exit status 1 stdout:  stderr: invalid argument

Might this suggest that the image was built correctly but later some piece of infrastructure broke?

I am not sure where to report this. Lets start with the next link in the chain and ask a release engineer.

When I tried reproducing this again using an F23 Cloud system, I noticed I was getting AVC denials now.


# date
Tue Mar  8 15:09:00 UTC 2016

# docker pull registry.access.redhat.com/rhel6
Using default tag: latest
31b925c88737: Downloading 12.65 MB
failed
Error pulling image (latest) from registry.access.redhat.com/rhel6, ApplyLayer exit status 1 stdout:  stderr: invalid argument

# journalctl --since 15:09
-- Logs begin at Fri 2016-02-26 20:22:41 UTC, end at Tue 2016-03-08 15:09:08 UTC. --
Mar 08 15:09:02 rhel-atomic-7.2-test docker[980]: time="2016-03-08T15:09:02.902958443Z" level=info msg="{Action=create, Username=cloud-user, LoginUID=1000, PID=1141}"
Mar 08 15:09:03 rhel-atomic-7.2-test docker[980]: time="2016-03-08T15:09:03.225377323Z" level=warning msg="Error getting v2 registry: endpoint does not support v2 API"
Mar 08 15:09:06 rhel-atomic-7.2-test kernel: XFS (dm-3): Mounting V5 Filesystem
Mar 08 15:09:06 rhel-atomic-7.2-test kernel: XFS (dm-3): Ending clean mount
Mar 08 15:09:07 rhel-atomic-7.2-test audit[1164]: AVC avc:  denied  { mac_admin } for  pid=1164 comm="exe" capability=33  scontext=system_u:system_r:docker_t:s0 tcontext=system_u:system_r:docker_t:s0 tclass=capa
Mar 08 15:09:07 rhel-atomic-7.2-test audit: SELINUX_ERR op=setxattr invalid_context="system_u:object_r:shutdown_exec_t:s0"
Mar 08 15:09:08 rhel-atomic-7.2-test kernel: XFS (dm-3): Unmounting Filesystem

# journalctl --since 15:09 | grep denied
Mar 08 15:09:07 rhel-atomic-7.2-test audit[1164]: AVC avc:  denied  { mac_admin } for  pid=1164 comm="exe" capability=33  scontext=system_u:system_r:docker_t:s0 tcontext=system_u:system_r:docker_t:s0 tclass=capability2 permissive=0


# rpm -qa | grep docker
docker-selinux-1.9.1-6.git6ec29ef.fc23.x86_64
docker-1.9.1-6.git6ec29ef.fc23.x86_64
python-docker-py-1.5.0-1.fc23.noarch

I am seeing the same ting. It looks like the docker tar ball includes XAttrs that docker is trying to set "shutdown_exec_t" the docker image should not contain any SELinux labels.

With SELinux temporarily set to permissive, I see this:

$ sudo docker pull registry.access.redhat.com/rhel6.7:latest
[sudo] password for pok: 
c77d113b1842: Download complete 
Status: Downloaded newer image for registry.access.redhat.com/rhel6.7:latest
registry.access.redhat.com/rhel6.7: this image was pulled from a legacy registry.  Important: This registry version will not be supported in future versions of docker.
$ rpm -qa | grep docker
python-dockerfile-parse-0.0.5-1.fc23.noarch
docker-1.9.1-6.git6ec29ef.fc23.x86_64
python-docker-registry-core-2.0.3-2.fc23.noarch
docker-selinux-1.9.1-6.git6ec29ef.fc23.x86_64
docker-registry-0.9.1-2.fc23.noarch

Is there some old docker-registry version on registry.access.redhat.com?

(In reply to Jan Hutař from comment #11)
> With SELinux temporarily set to permissive, I see this:
> 
> $ sudo docker pull registry.access.redhat.com/rhel6.7:latest
> [sudo] password for pok: 
> c77d113b1842: Download complete 
> Status: Downloaded newer image for registry.access.redhat.com/rhel6.7:latest
> registry.access.redhat.com/rhel6.7: this image was pulled from a legacy
> registry.  Important: This registry version will not be supported in future
> versions of docker.
> $ rpm -qa | grep docker
> python-dockerfile-parse-0.0.5-1.fc23.noarch
> docker-1.9.1-6.git6ec29ef.fc23.x86_64
> python-docker-registry-core-2.0.3-2.fc23.noarch
> docker-selinux-1.9.1-6.git6ec29ef.fc23.x86_64
> docker-registry-0.9.1-2.fc23.noarch
> 
> Is there some old docker-registry version on registry.access.redhat.com?

no worry, that's just a warning from docker saying that our registry it's V1

Hello team,

we don't own registry itself, we just push data in it. I was also told that this issue with v1 is already fixed (confirmed with Stanislav Graf).

So marking as current release.

Lubos

The SELinux issues are fixed in the current release.