moby Fail to pull an image after it's been interrupted by a power cut

Description

If an image pull is interrupted by a power cut then subsequent image pulls fails. Specifically, if an image pull is interrupted during download or extraction of fourth (or further, fifth, sixth and so on) new layer then subsequent download/extraction tries of the third layer fails with the error failed to register layer: error creating overlay mount to. The issue was discovered and has been reproduced on two platforms, i.MX 8M Mini and Raspberry PI v4.

Steps to reproduce the issue:

On your device, start pulling a new image that includes at least four new layers. For example, these images can be used for the issue reproducing, docker pull foundries/testpull and docker pull foundries/testpull-01. Optionally, you might wanna do it on a "clean" setup to make it easier to analyze and debug the issue (rm -rf /var/lib/docker before running the docker daemon). Also, it makes sense to run the docker daemon from a command line in a debug mode and instruct it to download layers sequentially (dockerd -D -l debug --max-concurrent-downloads 1).
Turn power off during the fourth layer download.

root@imx8mmevk:/var/rootdirs/home/fio# docker pull foundries/testpull   
Using default tag: latest
latest: Pulling from foundries/testpull
24fb2886d6f6: Pull complete 
3e69afb49bb5: Pull complete 
c00241bb9585: Pull complete 
724e50c935a6: Downloading [============================>                      ]  19.22MB/33.56MB

Turn power on and wait until a device is booted. Then, start the image pulling again, docker pull foundries/testpull.

Describe the results you received: This is the output of the pull command failed to register layer: error creating overlay mount to /var/lib/docker/overlay2/95cb96f115d3d23f3fdd1db51b7a09183d291db0481d8014b2122324303ac640/merged: too many levels of symbolic links

The state of the overlay2 store just after device boot and before running of the docker daemon. As you might see link and lower files are empty.

root@imx8mmevk:/var/rootdirs/home/fio# tree -shL 2 /var/lib/docker/overlay2/
/var/lib/docker/overlay2/
|-- [4.0K]  5b081797a1247310a027535f6c7619b6485d609189d8131025f443199a964819
|   |-- [   0]  committed
|   |-- [4.0K]  diff
|   |-- [   0]  link
|   |-- [   0]  lower
|   `-- [4.0K]  work
|-- [4.0K]  a33b711332720f52050665010e925f91573e426d42c2b0cb0fbeab183e21784e
|   |-- [4.0K]  diff
|   |-- [   0]  link
|   |-- [   0]  lower
|   `-- [4.0K]  work
|-- [4.0K]  be9d5c3b8a16c20fa8e627cef8695d7856372c016edefadc0d9472d005b3159e
|   |-- [   0]  committed
|   |-- [4.0K]  diff
|   `-- [   0]  link
`-- [4.0K]  l
    |-- [  72]  6SYQMZLLKVFFYUXJSGFLI2VHJU -> ../be9d5c3b8a16c20fa8e627cef8695d7856372c016edefadc0d9472d005b3159e/diff
    |-- [  72]  C43KNAAL2FV3NQPOAUVBC4PPZN -> ../5b081797a1247310a027535f6c7619b6485d609189d8131025f443199a964819/diff
    `-- [  72]  FBXGMY6OOYKB357DRVIHTVFDPR -> ../a33b711332720f52050665010e925f91573e426d42c2b0cb0fbeab183e21784e/diff

These are the docker daemon's logs.

DEBU[2021-10-25T10:09:14.406798657Z] Calling POST /v1.41/images/create?fromImage=foundries%2Ftestpull&tag=latest 
DEBU[2021-10-25T10:09:14.414461227Z] Trying to pull foundries/testpull from https://registry-1.docker.io v2 
DEBU[2021-10-25T10:09:16.255075238Z] Pulling ref from V2 registry: foundries/testpull:latest 
DEBU[2021-10-25T10:09:16.257659796Z] Layer already exists: 24fb2886d6f6           
DEBU[2021-10-25T10:09:16.267286387Z] Layer already exists: 3e69afb49bb5           
DEBU[2021-10-25T10:09:16.276331839Z] pulling blob "sha256:c00241bb9585dd4c8d564cac43ed722dca8ea2ca8113159cc3baf7639b5717f4" 
DEBU[2021-10-25T10:09:19.785657949Z] Downloaded c00241bb9585 to tempfile /var/lib/docker/tmp/GetImageBlob544169577 
DEBU[2021-10-25T10:09:19.786032330Z] pulling blob "sha256:724e50c935a65a285dd3d0cf521f508ec0c16a6b4e187da25f839d3ff90be194" 
DEBU[2021-10-25T10:09:19.786530715Z] Using /bin/unpigz to decompress              
ERRO[2021-10-25T10:09:19.799286825Z] error unmounting /var/lib/docker/overlay2/95cb96f115d3d23f3fdd1db51b7a09183d291db0481d8014b2122324303ac640/merged: invalid argument  storage-driver=overlay2
DEBU[2021-10-25T10:09:20.191615732Z] Cleaning up layer 95cb96f115d3d23f3fdd1db51b7a09183d291db0481d8014b2122324303ac640: error creating overlay mount to /var/lib/docker/overlay2/95cb96f115d3d23f3fdd1db51b7a09183d291db0481d8014b2122324303ac640/merged: too many levels of symbolic links 
DEBU[2021-10-25T10:09:23.285879912Z] Downloaded 724e50c935a6 to tempfile /var/lib/docker/tmp/GetImageBlob254672052 
INFO[2021-10-25T10:09:23.315554961Z] Attempting next endpoint for pull after error: failed to register layer: error creating overlay mount to /var/lib/docker/overlay2/95cb96f115d3d23f3fdd1db51b7a09183d291db0481d8014b2122324303ac640/merged: too many levels of symbolic links

These are the docker cli logs:

root@imx8mmevk:/var/rootdirs/home/fio# docker pull foundries/testpull
Using default tag: latest
latest: Pulling from foundries/testpull
24fb2886d6f6: Already exists 
3e69afb49bb5: Already exists 
c00241bb9585: Extracting [==================================================>]  33.56MB/33.56MB
724e50c935a6: Download complete 
failed to register layer: error creating overlay mount to /var/lib/docker/overlay2/95cb96f115d3d23f3fdd1db51b7a09183d291db0481d8014b2122324303ac640/merged: too many levels of symbolic links

Describe the results you expected: I expected the image pull command to succeed.

root@imx8mmevk:/var/rootdirs/home/fio# docker pull foundries/testpull
Using default tag: latest
latest: Pulling from foundries/testpull
24fb2886d6f6: Pull complete 
3e69afb49bb5: Pull complete 
c00241bb9585: Pull complete 
724e50c935a6: Pull complete 
Digest: sha256:b9047bca08a0ec1bccd33539ee330461664b90106ba730e38c91aa4a28f73468
Status: Downloaded newer image for foundries/testpull:latest
docker.io/foundries/testpull:latest

Additional information you deem important (e.g. issue happens only occasionally): The issue is reproducible on each try.

Output of docker version:

Client:
 Version:           20.10.8
 API version:       1.41
 Go version:        go1.16.7
 Git commit:        62eae52c2a
 Built:             Mon Oct 25 08:20:23 2021
 OS/Arch:           linux/arm64
 Context:           default
 Experimental:      true

Server:
 Engine:
  Version:          20.10.8
  API version:      1.41 (minimum version 1.12)
  Go version:       go1.16.7
  Git commit:       d24c6dc5cf5e68dfb30027b2db454099566a9b9e
  Built:            Mon Oct 25 08:19:02 2021
  OS/Arch:          linux/arm64
  Experimental:     false
 containerd:
  Version:          v1.5.5-11-g69e5db821.m
  GitCommit:        69e5db821af6458b4078d654ad3dcb3f31faa522.m
 runc:
  Version:          1.0.2+dev
  GitCommit:        v1.0.2-1-g86d83333-dirty
 docker-init:
  Version:          0.19.0
  GitCommit:        b9f42a0-dirty

Output of docker info:

Client:
 Context:    default
 Debug Mode: false

Server:
 Containers: 0
  Running: 0
  Paused: 0
  Stopped: 0
 Images: 1
 Server Version: 20.10.8
 Storage Driver: overlay2
  Backing Filesystem: extfs
  Supports d_type: true
  Native Overlay Diff: true
  userxattr: false
 Logging Driver: journald
 Cgroup Driver: cgroupfs
 Cgroup Version: 1
 Plugins:
  Volume: local
  Network: bridge host ipvlan macvlan null overlay
  Log: awslogs fluentd gcplogs gelf journald json-file local logentries splunk syslog
 Swarm: inactive
 Runtimes: runc io.containerd.runc.v2 io.containerd.runtime.v1.linux
 Default Runtime: runc
 Init Binary: docker-init
 containerd version: 69e5db821af6458b4078d654ad3dcb3f31faa522.m
 runc version: v1.0.2-1-g86d83333-dirty
 init version: b9f42a0-dirty (expected: de40ad007797e)
 Security Options:
  seccomp
   Profile: default
 Kernel Version: 5.4.144-lmp-standard
 Operating System: Linux-microPlatform 3.3.3-366-75-321-g91ddee0
 OSType: linux
 Architecture: aarch64
 CPUs: 4
 Total Memory: 1.905GiB
 Name: imx8mmevk
 ID: 6NW4:M6JW:VQKH:IX6C:E3PW:S7CK:CMKB:GOB6:V3QP:UGUT:6RST:R6PO
 Docker Root Dir: /var/lib/docker
 Debug Mode: true
  File Descriptors: 24
  Goroutines: 33
  System Time: 2021-10-25T10:17:45.070105716Z
  EventsListeners: 0
 Registry: https://index.docker.io/v1/
 Labels:
 Experimental: false
 Insecure Registries:
  127.0.0.0/8
 Live Restore Enabled: false

Additional environment details (AWS, VirtualBox, physical, etc.):

Hardware platforms: Raspberry PI v4, i.MX 8M Mini. OS: Linux microPlatform v83 (https://github.com/foundriesio/lmp-manifest/releases/tag/83)

** Workaround **

This patch helped us to overcome the issue https://github.com/foundriesio/meta-lmp/commit/86d02315bd73dbd99d7fe42adb05ac134dde1008.

Oct 25 '21 10:10 mike-sul

@mike-sul We are also facing the same issue of "too many levels of symbolic links" when the docker image pull was interrupted. Did you hear anything from docker on the resolution?

Feb 13 '23 16:02 Abvik

This did the trick for me:

service docker stop
cd /var/lib
mv docker docker.old
mkdir docker
chmod 710 docker
service docker start

Feb 27 '23 01:02 apowers313

I also ran into this issue today. I'm curious is there any chance of merging the patch from @mike-sul upstream?

Jun 30 '23 00:06 hrfuller

A pull request from @mike-sul would be welcome; at least having a PR can help discussing the approach and if it makes sense to others. I'm also wondering if containerd's overlay snapshotter would have the same issue (and could benefit from changes there as well).

@mike-sul are you interested in opening a PR for discussion?

Jun 30 '23 15:06 thaJeztah

What could be the other reasons for similar issue?

docker pull on the interrupted image(i.e. system rebooted while image pull) is failing with following error whereas docker pull for a different image is successful.

Also, can someone please help on how to recover under such situation? Is there a way to just cleanup this stale image and pull again?

overlay2/2e977f8093851ee9086a542c79f17339468ccae490d03ade08f537ce8c75b047/merged: too many levels of symbolic links

Dec 12 '23 10:12 rajanarayanaa

moby moby copied to clipboard

Fail to pull an image after it's been interrupted by a power cut

moby
moby copied to clipboard