docker pull large image Fails (` ApplyLayer exit status 1 stdout: stderr: invalid argument`)

olegTarassov commented 2 years ago

Description

Hello -

The issue is happening when trying to docker pull an image of 1.2GB either on fedora 35, Ubuntu impish. The error is:

5dcbdc60ea6b: Already exists
8671113e1c57: Already exists
e5adf43c9842: Extracting [==================================================>]  146.5MB/146.5MB
1a61808e3bf3: Download complete
ffffd5d9f875: Download complete
d20c473b524d: Download complete
60e4da6dbe2c: Download complete
002de968eae0: Download complete
failed to register layer: ApplyLayer exit status 1 stdout:  stderr: invalid argument

Setup: rootless Docker Docker storage: tried btrfs, overlay2, overlay-FS lima version: 0.8.2 network: vmnet

docker info:

Client:
 Context:    fedora_test
 Debug Mode: false
 Plugins:
  buildx: Docker Buildx (Docker Inc., v0.7.1)
  compose: Docker Compose (Docker Inc., v2.2.3)
  scan: Docker Scan (Docker Inc., v0.16.0)

Server:
 Containers: 0
  Running: 0
  Paused: 0
  Stopped: 0
 Images: 0
 Server Version: 20.10.12
 Storage Driver: btrfs
  Build Version: Btrfs v5.15.1
  Library Version: 102
 Logging Driver: json-file
 Cgroup Driver: systemd
 Cgroup Version: 2
 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: io.containerd.runc.v2 io.containerd.runtime.v1.linux runc
 Default Runtime: runc
 Init Binary: docker-init
 containerd version: 7b11cfaabd73bb80907dd23182b9347b4245eb5d
 runc version: v1.0.2-0-g52b36a2
 init version: de40ad0
 Security Options:
  seccomp
   Profile: default
  rootless
  cgroupns
 Kernel Version: 5.14.10-300.fc35.x86_64
 Operating System: Fedora Linux 35 (Cloud Edition)
 OSType: linux
 Architecture: x86_64
 CPUs: 4
 Total Memory: 3.816GiB
 Name: lima-fedora
 ID: B4LY:WZAB:NEYN:KC3Z:ONUC:QGY6:JXBW:4XSH:USU7:64WH:I5EG:AMF7
 Docker Root Dir: /home/olegtarassov.linux/.local/share/docker
 Debug Mode: false
 Registry: https://index.docker.io/v1/
 Labels:
 Experimental: false
 Insecure Registries:
  127.0.0.0/8
 Live Restore Enabled: false

lima yaml file (inspired from colima)

images:
  - location: "https://download.fedoraproject.org/pub/fedora/linux/releases/35/Cloud/x86_64/images/Fedora-Cloud-Base-35-1.2.x86_64.qcow2"
    arch: "x86_64"
    digest: "sha256:fe84502779b3477284a8d4c86731f642ca10dd3984d2b5eccdf82630a9ca2de6"
cpus: 4
memory: 4GiB
disk: 32GiB

networks:
  - lima: bridged
    interface: en0

mounts:
  - location: "~"
    writable: true
  - location: "/tmp/lima"
    writable: true

containerd:
  system: false
  user: false

provision:
  - mode: system
    script: |
      #!/bin/sh
      sed -i 's/host.lima.internal.*/host.lima.internal host.docker.internal/' /etc/hosts
      setenforce 0
      sed -i --follow-symlinks 's/SELINUX=enforcing/SELINUX=disabled/g' /etc/sysconfig/selinux

  - mode: system
    script: |
      #!/bin/bash
      set -eux -o pipefail
      command -v docker >/dev/null 2>&1 && exit 0
      dnf install -y fuse-overlayfs dnf-plugins-core bash-completion
      dnf config-manager --add-repo https://download.docker.com/linux/fedora/docker-ce.repo
      dnf install -y docker-ce docker-ce-cli containerd.io
      systemctl disable --now docker.service docker.socket

  - mode: user
    script: |
      #!/bin/bash
      set -eux -o pipefail
      dockerd-rootless-setuptool.sh install
      docker context use rootless

probes:
  - script: |
      #!/bin/bash
      set -eux -o pipefail
      if ! timeout 30s bash -c "until command -v docker >/dev/null 2>&1; do sleep 3; done"; then
        echo >&2 "docker is not installed yet"
        exit 1
      fi
      if ! timeout 30s bash -c "until pgrep rootlesskit; do sleep 3; done"; then
        echo >&2 "rootlesskit (used by rootless docker) is not running"
        exit 1
      fi
    hint: See "/var/log/cloud-init-output.log". in the guest
# See "~/.lima/fedora/serial.log in the host

portForwards:
  - guestSocket: "/run/user/{{.UID}}/docker.sock"
    hostSocket: "{{.Dir}}/sock/docker.sock"

message: |
  To run `docker` on the host (assumes docker-cli is installed), run the following commands:
  ------
  docker context create lima --docker "host=unix://{{.Dir}}/sock/docker.sock"
  docker context use lima
  docker run hello-world
  sudo ln -sf ~/.lima/fedora/sock/docker.sock /var/run/docker.sock
  ------

Note that pulling images of smaller size work from either dockerhub or quay work as expected.

Thank you

Oleg

AkihiroSuda commented 2 years ago

Do you have a public image to hit this issue?
Could you try creating {"storage-driver": "fuse-overlayfs"} in /home/<USERNAME>.linux/.config/docker/daemon.json and run systemctl --user restart docker in the guest? You may also need sudo dnf install fuse-overlayfs.

olegTarassov commented 2 years ago

the package fuse-overlayfs is installed and is part of the bootup script.
As instructed, I changed the storage-driver to fuse-overlayfs and added debug.
restarted docker via systemctl

docker info

...
 Storage Driver: fuse-overlayfs
...

Performed a docker pull and the issue is still the same

5dcbdc60ea6b: Pull complete
8671113e1c57: Pull complete
e5adf43c9842: Extracting [==================================================>]  146.5MB/146.5MB

The logs associated to this are

Feb 09 15:18:14 lima-fedora dockerd-rootless.sh[2312]: time="2022-02-09T15:18:14.886121723Z" level=debug msg="Downloaded ffffd5d9f875 to tempfile /home/olegtarassov.linux/.local/share/docker/tmp/GetImageBlob793162514"
Feb 09 15:18:14 lima-fedora dockerd-rootless.sh[2312]: time="2022-02-09T15:18:14.890857776Z" level=debug msg="pulling blob \"sha256:002de968eae0586f47a84b448665ab3b4acb542abf4d91565809f507e7a69401\""
Feb 09 15:18:15 lima-fedora dockerd-rootless.sh[2312]: time="2022-02-09T15:18:15.434627777Z" level=debug msg="Downloaded 002de968eae0 to tempfile /home/olegtarassov.linux/.local/share/docker/tmp/GetImageBlob621480035"
Feb 09 15:18:15 lima-fedora dockerd-rootless.sh[2312]: time="2022-02-09T15:18:15.540034940Z" level=debug msg="Downloaded 60e4da6dbe2c to tempfile /home/olegtarassov.linux/.local/share/docker/tmp/GetImageBlob047549460"
Feb 09 15:18:20 lima-fedora dockerd-rootless.sh[2312]: time="2022-02-09T15:18:20.288029342Z" level=debug msg="Downloaded 5dcbdc60ea6b to tempfile /home/olegtarassov.linux/.local/share/docker/tmp/GetImageBlob347883774"
Feb 09 15:18:20 lima-fedora dockerd-rootless.sh[2312]: time="2022-02-09T15:18:20.288338345Z" level=debug msg="Using /usr/bin/unpigz to decompress"
Feb 09 15:18:20 lima-fedora dockerd-rootless.sh[2312]: time="2022-02-09T15:18:20.289642359Z" level=debug msg="Applying tar in /home/olegtarassov.linux/.local/share/docker/fuse-overlayfs/e49440609db56650ca5ff6448ed00cbbfb1b6c28a39d2c317d49020ae9b65d6b/diff" storage-driver=fuse-overlayfs
Feb 09 15:18:27 lima-fedora dockerd-rootless.sh[2312]: time="2022-02-09T15:18:27.480886726Z" level=debug msg="Applied tar sha256:a9820c2af00a34f160836f6ef2044d88e6019ca19b3c15ec22f34afe9d73f41c to e49440609db56650ca5ff6448ed00cbbfb1b6c28a39d2c317d49020ae9b65d6b, size: 215767463"
Feb 09 15:18:27 lima-fedora dockerd-rootless.sh[2312]: time="2022-02-09T15:18:27.583129854Z" level=debug msg="Using /usr/bin/unpigz to decompress"
Feb 09 15:18:27 lima-fedora dockerd-rootless.sh[2312]: time="2022-02-09T15:18:27.584824873Z" level=debug msg="Applying tar in /home/olegtarassov.linux/.local/share/docker/fuse-overlayfs/5400e4e029e50a5076c70289e78f485a8c5eee889c0d1b68670231204778e673/diff" storage-driver=fuse-overlayfs
Feb 09 15:18:27 lima-fedora dockerd-rootless.sh[2312]: time="2022-02-09T15:18:27.662948735Z" level=debug msg="Applied tar sha256:3d5ecee9360ea8711f32d2af0cab1eae4d53140496f961ca1a634b5e2e817412 to 5400e4e029e50a5076c70289e78f485a8c5eee889c0d1b68670231204778e673, size: 4719"
Feb 09 15:18:27 lima-fedora dockerd-rootless.sh[2312]: time="2022-02-09T15:18:27.679904922Z" level=debug msg="Using /usr/bin/unpigz to decompress"
Feb 09 15:18:27 lima-fedora dockerd-rootless.sh[2312]: time="2022-02-09T15:18:27.681379939Z" level=debug msg="Applying tar in /home/olegtarassov.linux/.local/share/docker/fuse-overlayfs/c8d699e2b329f8d512737caef7c21989f6c88f4a539bb795954583a75e1c4f12/diff" storage-driver=fuse-overlayfs
Feb 09 15:18:33 lima-fedora dockerd-rootless.sh[2312]: time="2022-02-09T15:18:33.331027291Z" level=debug msg="Cleaning up layer c8d699e2b329f8d512737caef7c21989f6c88f4a539bb795954583a75e1c4f12: Error processing tar file(exit status 1): invalid argument"
Feb 09 15:18:33 lima-fedora dockerd-rootless.sh[2312]: time="2022-02-09T15:18:33.361630629Z" level=info msg="Attempting next endpoint for pull after error: failed to register layer: Error processing tar file(exit status 1): invalid argument"
Feb 09 15:18:33 lima-fedora dockerd-rootless.sh[2312]: time="2022-02-09T15:18:33.365680674Z" level=info msg="Layer sha256:a3810ca2485d447bcde2b9809c6e7c6feec31f30f6baddf29fdaeb9266afff44 cleaned up"
Feb 09 15:18:33 lima-fedora dockerd-rootless.sh[2332]: time="2022-02-09T15:18:33.595668212Z" level=debug msg="remove content" key="sha256:ffe24bc3567731767f6e26d2464238f068bfc11f6ce073e7b4716d9e11eeec53"
Feb 09 15:18:33 lima-fedora dockerd-rootless.sh[2332]: time="2022-02-09T15:18:33.604714312Z" level=debug msg="schedule content cleanup"
Feb 09 15:18:33 lima-fedora dockerd-rootless.sh[2332]: time="2022-02-09T15:18:33.605164317Z" level=debug msg="removed content" digest="sha256:ffe24bc3567731767f6e26d2464238f068bfc11f6ce073e7b4716d9e11eeec53"
Feb 09 15:18:33 lima-fedora dockerd-rootless.sh[2332]: time="2022-02-09T15:18:33.605481320Z" level=debug msg="content garbage collected" d="503.005µs"
Feb 09 15:18:33 lima-fedora dockerd-rootless.sh[2332]: time="2022-02-09T15:18:33.605617322Z" level=debug msg="garbage collected" d=9.550106ms
Feb 09 15:18:34 lima-fedora dockerd-rootless.sh[2312]: time="2022-02-09T15:18:34.042746146Z" level=info msg="Layer sha256:a9820c2af00a34f160836f6ef2044d88e6019ca19b3c15ec22f34afe9d73f41c cleaned up"

Thank you for your help looking into this,

Oleg

olegTarassov commented 2 years ago

Small update,

I seem to have narrowed down the issue; It appears that when I build the image using bitbucket pipelines and try to pull it, I get this error. When I build it locally and push to the same registry I am able to pull the 1.2GB image. (note I pruned images and system before pulling)

Not sure what to make of this now...

Bladrak commented 2 years ago

I've got a similar issue. Host is Mac OS, using following lima config:

# Based on https://github.com/lima-vm/lima/blob/master/examples/docker.yaml
# To update it, just start from the base and make mount location ~ writable,
# then tweak cpus, memory and disk.

# Example to use Docker instead of containerd & nerdctl
# $ limactl start ./docker.yaml
# $ limactl shell docker docker run -it -v $HOME:$HOME --rm alpine

# To run `docker` on the host (assumes docker-cli is installed):
# $ export DOCKER_HOST=unix://$HOME/docker.sock
# $ docker ...

# This example requires Lima v0.7.3 or later
images:
  # Hint: run `limactl prune` to invalidate the "current" cache
  - location: "https://cloud-images.ubuntu.com/impish/current/impish-server-cloudimg-amd64.img"
    arch: "x86_64"
  - location: "https://cloud-images.ubuntu.com/impish/current/impish-server-cloudimg-arm64.img"
    arch: "aarch64"
mounts:
  - location: "~"
    writable: true
  - location: "/tmp/lima"
    writable: true
# CPUs: if you see performance issues, try limiting cpus to 1.
# Default: 4
cpus: 3
# Memory size
# Default: "4GiB"
memory: 2GiB
# Disk size
# Default: "100GiB"
disk: 100GiB
ssh:
  localPort: 60006
  # Load ~/.ssh/*.pub in addition to $LIMA_HOME/_config/user.pub , for allowing DOCKER_HOST=ssh:// .
  # This option is enabled by default.
  # If you have an insecure key under ~/.ssh, do not use this option.
  loadDotSSHPubKeys: true
# containerd is managed by Docker, not by Lima, so the values are set to false here.
containerd:
  system: false
  user: false
provision:
  - mode: system
    script: |
      #!/bin/bash
      set -eux -o pipefail
      command -v docker >/dev/null 2>&1 && exit 0
      export DEBIAN_FRONTEND=noninteractive
      curl -fsSL https://get.docker.com | sh
      # NOTE: you may remove the lines below, if you prefer to use rootful docker, not rootless
      systemctl disable --now docker
      apt-get install -y uidmap dbus-user-session
  - mode: user
    script: |
      #!/bin/bash
      set -eux -o pipefail
      systemctl --user start dbus
      dockerd-rootless-setuptool.sh install
      docker context use rootless
probes:
  - script: |
      #!/bin/bash
      set -eux -o pipefail
      if ! timeout 30s bash -c "until command -v docker >/dev/null 2>&1; do sleep 3; done"; then
        echo >&2 "docker is not installed yet"
        exit 1
      fi
      if ! timeout 30s bash -c "until pgrep rootlesskit; do sleep 3; done"; then
        echo >&2 "rootlesskit (used by rootless docker) is not running"
        exit 1
      fi
    hint: See "/var/log/cloud-init-output.log". in the guest
portForwards:
  - guestSocket: "/run/user/{{.UID}}/docker.sock"
    hostSocket: "{{.Home}}/docker.sock"

When trying to pull an image (this one is public), I've got the same error.

docker pull ekino/ci-golang:1.16-2022.03.31
1.16-2022.03.31: Pulling from ekino/ci-golang
e4d61adff207: Already exists 
4ff1945c672b: Already exists 
ff5b10aec998: Already exists 
12de8c754e45: Already exists 
8c86ff77a317: Already exists 
0395a1c478ba: Already exists 
245345d44ed8: Already exists 
1107990b1a95: Pull complete 
50bb36143eb1: Extracting  220.1MB/220.1MB
failed to register layer: ApplyLayer exit status 1 stdout:  stderr: lchown /usr/local/bin/mockgen: invalid argument

That's something that's referenced in docker documentation though (https://docs.docker.com/engine/security/rootless/#docker-pull-errors), but I checked the lima VM and everything looks good.

➜  lima limactl shell docker
lima@lima-docker:/Users/hugo.briand/Projects/Ekino/Internal/lima$ whoami
lima
lima@lima-docker:/Users/hugo.briand/Projects/Ekino/Internal/lima$ cat /etc/subuid
lima:100000:65536
lima@lima-docker:/Users/hugo.briand/Projects/Ekino/Internal/lima$ cat /etc/subgid
lima:100000:65536

CameronHudson8 commented 9 months ago

In my case, the error message indicated the UID and GID that the layer needed.

FATA[0069] failed to extract layer sha256:9374c898f33f8d7cdd68c8927d6ae64ded45e48c6bf9e83b7b153125188efe36: mount callback failed on /var/lib/containerd/tmpmounts/containerd-mount2038800669: failed to Lchown "/var/lib/containerd/tmpmounts/containerd-mount2038800669/my-file.txt" for UID 1374049, GID 1025: lchown /var/lib/containerd/tmpmounts/containerd-mount2038800669/my-file.txt: invalid argument (Hint: try increasing the number of subordinate IDs in /etc/subuid and /etc/subgid): unknown

While the GID of 1025 was within bounds, the UID of 1374049 was not.

$ lima cat /etc/subgid
cameronhudson:100000:65536

$ lima cat /etc/subuid
cameronhudson:100000:65536

I examined my existing lima config file (which was at ~/.lima/default/lima.yaml), and added the following section to increase the UID limit to the nearest power of 2:

provision:
- mode: user
  script: |
    #!/usr/bin/env bash
    set -eux -o pipefail
    UID_LIMIT=2097152
    username="$(whoami)"
    sudo sed -i -r "s/^(${username}):([0-9]+):([0-9]+)$/\1:\2:${UID_LIMIT}/" /etc/subuid

Then I stopped and started my VM, which was just named default.

limactl stop default
limactl start default

And now I'm able to pull the image.

lima-vm / lima

docker pull large image Fails (` ApplyLayer exit status 1 stdout: stderr: invalid argument`) #637

Description