Handler for POST /v1.41/containers/create returned error: operation not supported

JustcallmeTuner commented 1 year ago

Description

I use yocto to build a 4.19 kernel image, and embeded docker to the image. After successfully running the Linux system, when I execute "docker pull hello-world", but when I run "docker run hello-world", it gives me an error message: "docker: Error response from daemon: operation not supported. See docker run --help." Then I execute journalctl -exu docker, the message is following:

May 13 00:02:41 wanghuo systemd[1]: Starting Docker Application Container Engine...
-- Subject: A start job for unit docker.service has begun execution
-- Defined-By: systemd
-- Support: https://lists.freedesktop.org/mailman/listinfo/systemd-devel
--
-- A start job for unit docker.service has begun execution.
--
-- The job identifier is 734.
May 13 00:02:41 wanghuo dockerd[2992]: time="2023-05-13T00:02:41.601398158Z" level=info msg="Starting up"
May 13 00:02:41 wanghuo dockerd[2992]: time="2023-05-13T00:02:41.603526658Z" level=info msg="parsed scheme: \"unix\"" module=grpc
May 13 00:02:41 wanghuo dockerd[2992]: time="2023-05-13T00:02:41.603772616Z" level=info msg="scheme \"unix\" not registered, fallback to default scheme" module=grpc
May 13 00:02:41 wanghuo dockerd[2992]: time="2023-05-13T00:02:41.603842220Z" level=info msg="ccResolverWrapper: sending update to cc: {[{unix:///run/containerd/containerd.sock  <nil> 0 <nil>}] <nil> <nil>}" module=grpc
May 13 00:02:41 wanghuo dockerd[2992]: time="2023-05-13T00:02:41.603913241Z" level=info msg="ClientConn switching balancer to \"pick_first\"" module=grpc
May 13 00:02:41 wanghuo dockerd[2992]: time="2023-05-13T00:02:41.610500533Z" level=info msg="parsed scheme: \"unix\"" module=grpc
May 13 00:02:41 wanghuo dockerd[2992]: time="2023-05-13T00:02:41.610803866Z" level=info msg="scheme \"unix\" not registered, fallback to default scheme" module=grpc
May 13 00:02:41 wanghuo dockerd[2992]: time="2023-05-13T00:02:41.610963366Z" level=info msg="ccResolverWrapper: sending update to cc: {[{unix:///run/containerd/containerd.sock  <nil> 0 <nil>}] <nil> <nil>}" module=grpc
May 13 00:02:41 wanghuo dockerd[2992]: time="2023-05-13T00:02:41.611089658Z" level=info msg="ClientConn switching balancer to \"pick_first\"" module=grpc
May 13 00:02:41 wanghuo dockerd[2992]: time="2023-05-13T00:02:41.613183033Z" level=error msg="Failed to built-in GetDriver graph btrfs /var/lib/docker"
May 13 00:02:41 wanghuo dockerd[2992]: time="2023-05-13T00:02:41.619635345Z" level=error msg="failed to mount overlay: no such device" storage-driver=overlay2
May 13 00:02:41 wanghuo dockerd[2992]: time="2023-05-13T00:02:41.619955179Z" level=error msg="exec: \"fuse-overlayfs\": executable file not found in $PATH" storage-driver=fuse-overlayfs
May 13 00:02:41 wanghuo dockerd[2992]: time="2023-05-13T00:02:41.622389470Z" level=error msg="AUFS was not found in /proc/filesystems" storage-driver=aufs
May 13 00:02:41 wanghuo dockerd[2992]: time="2023-05-13T00:02:41.624188283Z" level=error msg="failed to mount overlay: no such device" storage-driver=overlay
May 13 00:02:41 wanghuo dockerd[2992]: time="2023-05-13T00:02:41.624224554Z" level=error msg="Failed to built-in GetDriver graph devicemapper /var/lib/docker"
May 13 00:02:41 wanghuo dockerd[2992]: time="2023-05-13T00:02:41.626495366Z" level=warning msg="Your kernel does not support CPU realtime scheduler"
May 13 00:02:41 wanghuo dockerd[2992]: time="2023-05-13T00:02:41.626973887Z" level=info msg="Loading containers: start."
May 13 00:02:41 wanghuo dockerd[2992]: time="2023-05-13T00:02:41.757165824Z" level=info msg="Default bridge (docker0) is assigned with an IP address 172.17.0.0/16. Daemon option --bip can be used to set a preferred IP address"
May 13 00:02:41 wanghuo dockerd[2992]: time="2023-05-13T00:02:41.875782762Z" level=info msg="Loading containers: done."
May 13 00:02:41 wanghuo dockerd[2992]: time="2023-05-13T00:02:41.891814741Z" level=info msg="Docker daemon" commit=3056208812eb5e792fa99736c9167d1e10f4ab49 graphdriver(s)=vfs version=20.10.21-ce
May 13 00:02:41 wanghuo dockerd[2992]: time="2023-05-13T00:02:41.891967303Z" level=info msg="Daemon has completed initialization"
May 13 00:02:41 wanghuo systemd[1]: Started Docker Application Container Engine.
-- Subject: A start job for unit docker.service has finished successfully
-- Defined-By: systemd
-- Support: https://lists.freedesktop.org/mailman/listinfo/systemd-devel
--
-- A start job for unit docker.service has finished successfully.
--
-- The job identifier is 734.
May 13 00:02:41 wanghuo dockerd[2992]: time="2023-05-13T00:02:41.914603533Z" level=info msg="API listen on /run/docker.sock"
May 13 00:03:25 wanghuo dockerd[2992]: time="2023-05-13T00:03:25.393079304Z" level=error msg="Handler for POST /v1.41/containers/create returned error: operation not supported"

Reproduce

docker pull hello-world
docker run hello-world

Expected behavior

This message shows that your installation appears to be working correctly.

To generate this message, Docker took the following steps:
 1. The Docker client contacted the Docker daemon.
 2. The Docker daemon pulled the "hello-world" image from the Docker Hub.
    (amd64)
 3. The Docker daemon created a new container from that image which runs the
    executable that produces the output you are currently reading.
 4. The Docker daemon streamed that output to the Docker client, which sent it
    to your terminal.

To try something more ambitious, you can run an Ubuntu container with:
 $ docker run -it ubuntu bash

Share images, automate workflows, and more with a free Docker ID:
 https://hub.docker.com/

For more examples and ideas, visit:
 https://docs.docker.com/get-started/

docker version

Client:
 Version:           20.10.21-ce
 API version:       1.41
 Go version:        go1.17.13
 Git commit:        baeda1f82a
 Built:             Thu Apr 27 01:24:32 2023
 OS/Arch:           linux/arm64
 Context:           default
 Experimental:      true

Server:
 Engine:
  Version:          20.10.21-ce
  API version:      1.41 (minimum version 1.12)
  Go version:       go1.17.13
  Git commit:       3056208812eb5e792fa99736c9167d1e10f4ab49
  Built:            Tue Oct 25 17:53:02 2022
  OS/Arch:          linux/arm64
  Experimental:     false
 containerd:
  Version:          v1.6.19.m
  GitCommit:        1e1ea6e986c6c86565bc33d52e34b81b3e2bc71f.m
 runc:
  Version:          1.1.4+dev
  GitCommit:        v1.1.4-8-g974efd2d-dirty
 docker-init:
  Version:          0.19.0
  GitCommit:        b9f42a0-dirty

docker info

Client:
 Context:    default
 Debug Mode: false

Server:
 Containers: 0
  Running: 0
  Paused: 0
  Stopped: 0
 Images: 1
 Server Version: 20.10.21-ce
 Storage Driver: vfs
 Logging Driver: json-file
 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: io.containerd.runtime.v1.linux runc io.containerd.runc.v2
 Default Runtime: runc
 Init Binary: docker-init
 containerd version: 1e1ea6e986c6c86565bc33d52e34b81b3e2bc71f.m
 runc version: v1.1.4-8-g974efd2d-dirty
 init version: b9f42a0-dirty
 Security Options:
  seccomp
   Profile: default
 Kernel Version: 4.19.0-rt1-wanghuo
 Operating System: WangHuo test0513 (kirkstone)
 OSType: linux
 Architecture: aarch64
 CPUs: 2
 Total Memory: 7.708GiB
 Name: wanghuo
 ID: ZV7V:M5MM:52NQ:E7ZZ:LVLN:ZFLX:56X7:FELF:VX3F:QT4E:IHBK:VA7X
 Docker Root Dir: /var/lib/docker
 Debug Mode: false
 Registry: https://index.docker.io/v1/
 Labels:
 Experimental: false
 Insecure Registries:
  127.0.0.0/8
 Registry Mirrors:
  http://hub-mirror.c.163.com/
 Live Restore Enabled: false

Additional Info

I have executed the check-config.sh scrip, and the message is the following: info: reading kernel config from /proc/config.gz ...

Generally Necessary:
- cgroup hierarchy: properly mounted [/sys/fs/cgroup]
- CONFIG_NAMESPACES: enabled
- CONFIG_NET_NS: enabled
- CONFIG_PID_NS: enabled
- CONFIG_IPC_NS: enabled
- CONFIG_UTS_NS: enabled
- CONFIG_CGROUPS: enabled
- CONFIG_CGROUP_CPUACCT: enabled
- CONFIG_CGROUP_DEVICE: enabled
- CONFIG_CGROUP_FREEZER: enabled
- CONFIG_CGROUP_SCHED: enabled
- CONFIG_CPUSETS: enabled
- CONFIG_MEMCG: enabled
- CONFIG_KEYS: enabled
- CONFIG_VETH: enabled
- CONFIG_BRIDGE: enabled
- CONFIG_BRIDGE_NETFILTER: enabled
- CONFIG_IP_NF_FILTER: enabled (as module)
- CONFIG_IP_NF_TARGET_MASQUERADE: enabled (as module)
- CONFIG_NETFILTER_XT_MATCH_ADDRTYPE: enabled (as module)
- CONFIG_NETFILTER_XT_MATCH_CONNTRACK: enabled (as module)
- CONFIG_NETFILTER_XT_MATCH_IPVS: enabled (as module)
- CONFIG_NETFILTER_XT_MARK: enabled (as module)
- CONFIG_IP_NF_NAT: enabled (as module)
- CONFIG_NF_NAT: enabled (as module)
- CONFIG_POSIX_MQUEUE: enabled
- CONFIG_NF_NAT_IPV4: enabled (as module)
- CONFIG_NF_NAT_NEEDED: enabled
- CONFIG_CGROUP_BPF: enabled

Optional Features:
- CONFIG_USER_NS: enabled
- CONFIG_SECCOMP: enabled
- CONFIG_SECCOMP_FILTER: enabled
- CONFIG_CGROUP_PIDS: enabled
- CONFIG_MEMCG_SWAP: enabled
- CONFIG_MEMCG_SWAP_ENABLED: enabled
    (cgroup swap accounting is currently enabled)
- CONFIG_IOSCHED_CFQ: enabled
- CONFIG_CFQ_GROUP_IOSCHED: enabled
- CONFIG_BLK_CGROUP: enabled
- CONFIG_BLK_DEV_THROTTLING: enabled
- CONFIG_CGROUP_PERF: enabled
- CONFIG_CGROUP_HUGETLB: enabled
- CONFIG_NET_CLS_CGROUP: enabled (as module)
- CONFIG_CGROUP_NET_PRIO: enabled
- CONFIG_CFS_BANDWIDTH: enabled
- CONFIG_FAIR_GROUP_SCHED: enabled
- CONFIG_IP_NF_TARGET_REDIRECT: enabled (as module)
- CONFIG_IP_VS: enabled (as module)
- CONFIG_IP_VS_NFCT: enabled
- CONFIG_IP_VS_PROTO_TCP: enabled
- CONFIG_IP_VS_PROTO_UDP: enabled
- CONFIG_IP_VS_RR: enabled (as module)
- CONFIG_SECURITY_SELINUX: enabled
- CONFIG_SECURITY_APPARMOR: enabled
- CONFIG_EXT3_FS: enabled
- CONFIG_EXT3_FS_XATTR: missing
- CONFIG_EXT3_FS_POSIX_ACL: enabled
- CONFIG_EXT3_FS_SECURITY: enabled
    (enable these ext3 configs if you are using ext3 as backing filesystem)
- CONFIG_EXT4_FS: enabled
- CONFIG_EXT4_FS_POSIX_ACL: enabled
- CONFIG_EXT4_FS_SECURITY: enabled
- Network Drivers:
  - "overlay":
    - CONFIG_VXLAN: enabled (as module)
    - CONFIG_BRIDGE_VLAN_FILTERING: enabled
      Optional (for encrypted networks):
      - CONFIG_CRYPTO: enabled
      - CONFIG_CRYPTO_AEAD: enabled
      - CONFIG_CRYPTO_GCM: enabled (as module)
      - CONFIG_CRYPTO_SEQIV: enabled (as module)
      - CONFIG_CRYPTO_GHASH: enabled (as module)
      - CONFIG_XFRM: enabled
      - CONFIG_XFRM_USER: enabled
      - CONFIG_XFRM_ALGO: enabled
      - CONFIG_INET_ESP: enabled
      - CONFIG_INET_XFRM_MODE_TRANSPORT: enabled
  - "ipvlan":
    - CONFIG_IPVLAN: enabled
  - "macvlan":
    - CONFIG_MACVLAN: enabled
    - CONFIG_DUMMY: enabled
  - "ftp,tftp client in container":
    - CONFIG_NF_NAT_FTP: enabled (as module)
    - CONFIG_NF_CONNTRACK_FTP: enabled (as module)
    - CONFIG_NF_NAT_TFTP: enabled (as module)
    - CONFIG_NF_CONNTRACK_TFTP: enabled (as module)
- Storage Drivers:
  - "btrfs":
    - CONFIG_BTRFS_FS: enabled (as module)
    - CONFIG_BTRFS_FS_POSIX_ACL: enabled
  - "devicemapper":
    - CONFIG_BLK_DEV_DM: enabled
    - CONFIG_DM_THIN_PROVISIONING: enabled
  - "overlay":
    - CONFIG_OVERLAY_FS: enabled (as module)
  - "zfs":
    - /dev/zfs: missing
    - zfs command: missing
    - zpool command: missing

Limits:
- /proc/sys/kernel/keys/root_maxkeys: 1000000

corhere commented 1 year ago

That's unfortunate; a syscall.Errno got returned without being annotated with any context which could tell us which operation wasn't supported. Could you please enable debug mode on the daemon and post the debug logs? Even though it likely is some disabled feature in your custom kernel, the resulting error from the daemon not being actionable or even particularly troubleshoot-able is itself a bug.

JustcallmeTuner commented 1 year ago

thanks for your reply. I have fixed this bug by run the custom os on the disk rather than ram. I suspect the reason is no enouth resource to run docker virtualization.

corhere commented 1 year ago

@JustcallmeTuner glad you found a solution, but the uninformative error message is still unfixed. It would really help out other people who will run into the same issue in the future if you could help us fix it by reproducing the issue and provide us the debug logs.

nocker01 commented 1 year ago

Hi, I am in the exact same situation (glad I've found this thread!!!).... that is:

I have a custom Yocto image
I have added the /meta-virtualisation layer
Executing docker --version outputs the docker version
Executing docker pull hello-world:linux looks like it works
Executing docker image ls shows the pulled image
Executing docker run hello-world:linux results in: docker: Error response from daemon: operation not supported.

Looking in /var/log/dockerd is see:

time="2023-07-20T17:03:01.389212715+10:00" level=error msg="Handler for POST /v1.41/containers/create returned error: operation not supported"

I'm not sure how to do as @corhere asked:

Could you please enable debug mode on the daemon and post the debug logs?

I tried docker --debug run hello-world:linux but this resulted in the same log message in /var/log/dockerd. I will Google and try to find out how to run the dockerd process in debug mode

akerouanton commented 1 year ago

@nocker01 You have to follow this docs section to enable debug mode: https://docs.docker.com/config/daemon/logs/#enable-debugging

Once the debug mode is enabled, you have to:

Reproduce the bug ;
Look at your daemon logs and copy/paste here the logs above the last log saying Handler for POST /v1.41/containers/create returned error: operation not supported ;
Then, you can turn off debug mode ;

nocker01 commented 1 year ago

Thanks for the guidance @akerouanton .

Here are the logs I've captured with debug mode enabled:

time="2023-07-20T20:51:44.651398670+10:00" level=debug msg="Calling HEAD /_ping"
time="2023-07-20T20:51:44.654996491+10:00" level=debug msg="Calling POST /v1.41/containers/create"
time="2023-07-20T20:51:44.655883758+10:00" level=debug msg="form data: {\"AttachStderr\":true,\"AttachStdin\":false,\"AttachStdout\":true,\"Cmd\":null,\"Domainname\":\"\",\"Entrypoint\":null,\"Env\":null,\"HostConfig\":{\"AutoRemove\":false,\"Binds\":null,\"BlkioDeviceReadBps\":null,\"BlkioDeviceReadIOps\":null,\"BlkioDeviceWriteBps\":null,\"BlkioDeviceWriteIOps\":null,\"BlkioWeight\":0,\"BlkioWeightDevice\":[],\"CapAdd\":null,\"CapDrop\":null,\"Cgroup\":\"\",\"CgroupParent\":\"\",\"CgroupnsMode\":\"\",\"ConsoleSize\":[0,0],\"ContainerIDFile\":\"\",\"CpuCount\":0,\"CpuPercent\":0,\"CpuPeriod\":0,\"CpuQuota\":0,\"CpuRealtimePeriod\":0,\"CpuRealtimeRuntime\":0,\"CpuShares\":0,\"CpusetCpus\":\"\",\"CpusetMems\":\"\",\"DeviceCgroupRules\":null,\"DeviceRequests\":null,\"Devices\":[],\"Dns\":[],\"DnsOptions\":[],\"DnsSearch\":[],\"ExtraHosts\":null,\"GroupAdd\":null,\"IOMaximumBandwidth\":0,\"IOMaximumIOps\":0,\"IpcMode\":\"\",\"Isolation\":\"\",\"KernelMemory\":0,\"KernelMemoryTCP\":0,\"Links\":null,\"LogConfig\":{\"Config\":{},\"Type\":\"\"},\"MaskedPaths\":null,\"Memory\":0,\"MemoryReservation\":0,\"MemorySwap\":0,\"MemorySwappiness\":-1,\"NanoCpus\":0,\"NetworkMode\":\"default\",\"OomKillDisable\":false,\"OomScoreAdj\":0,\"PidMode\":\"\",\"PidsLimit\":0,\"PortBindings\":{},\"Privileged\":false,\"PublishAllPorts\":false,\"ReadonlyPaths\":null,\"ReadonlyRootfs\":false,\"RestartPolicy\":{\"MaximumRetryCount\":0,\"Name\":\"no\"},\"SecurityOpt\":null,\"ShmSize\":0,\"UTSMode\":\"\",\"Ulimits\":null,\"UsernsMode\":\"\",\"VolumeDriver\":\"\",\"VolumesFrom\":null},\"Hostname\":\"\",\"Image\":\"hello-world:linux\",\"Labels\":{},\"NetworkingConfig\":{\"EndpointsConfig\":{}},\"OnBuild\":null,\"OpenStdin\":false,\"StdinOnce\":false,\"Tty\":false,\"User\":\"\",\"Volumes\":{},\"WorkingDir\":\"\"}"
time="2023-07-20T20:51:44.661517869+10:00" level=error msg="Handler for POST /v1.41/containers/create returned error: operation not supported"

corhere commented 1 year ago

Unfortunately, the debug logs hold no clues either. Anyone willing and able to reproduce the issue while running the daemon under strace and provide the (unabridged) strace log? Or provide me with a prebuilt disk image I could use to reproduce the issue in a VM?

nocker01 commented 1 year ago

Hi, here are the logs I've captured. Let me know if these are not what was requested. Thanks.

strace_docker.log dockerd.log

nocker01 commented 1 year ago

Hi, I've just come across this check-config.sh script that is used to identify if your system is able to run docker containers. I have several kernel modules that are missing. I will address these and then try again. I will post an update if I do or don't get it running. Apologies if I've wasted anyone time.

corhere commented 1 year ago

@nocker01 it looks like you captured an strace log of a docker CLI invocation. Unfortunately that does not contain the information I need to track down which operation is in need of better error handling. I need an strace log of the dockerd daemon process for that. Thanks!

nocker01 commented 1 year ago

@corhere forgive my lack of knowledge, here is the strace log from the dockerd process: strace_dockerd.log

corhere commented 1 year ago

@nocker01 perfect, that's exactly what I needed.

1431  lgetxattr("/var/lib/docker/vfs/dir/fc42475c78ab05f736abd9ebd676e6268a0f19c4434ca19b0dd397956d66cb17", "security.capability", 0x40006cd400, 128) = -1 EOPNOTSUPP (Operation not supported)

Ah, that's a known issue: #45417. It has been fixed by #45463 and the error handling was improved in https://github.com/moby/moby/pull/45464/commits/0cdfd5f27582a5fb2e9627fbec1245453eac4c15. More recent versions of Moby handle missing xattr support more gracefully.

corhere commented 1 year ago

Given that @JustcallmeTuner was able to work around the error by switching the backing filesystem, it's probably safe to assume that their kernel was configured with CONFIG_TMPFS_XATTR=n. I'm closing this issue as a duplicate of #45417

moby / moby