Bug 2239849

Summary: Basic `docker run` commands fail
Product: [Fedora] Fedora Reporter: fifofonix
Component: containerdAssignee: Sergio Basto <sergio>
Status: CLOSED DUPLICATE QA Contact: Fedora Extras Quality Assurance <extras-qa>
Severity: high Docs Contact:
Priority: unspecified    
Version: 39CC: carlos.sepulveda, copper_fin, dustymabe, go-sig, jlebon, maxwell, mhofmann, sergio
Target Milestone: ---Keywords: Regression, Upgrades
Target Release: ---   
Hardware: x86_64   
OS: Linux   
Whiteboard:
Fixed In Version: Doc Type: If docs needed, set a value
Doc Text:
Story Points: ---
Clone Of: Environment:
Last Closed: 2023-09-22 13:43:39 UTC Type: ---
Regression: --- Mount Type: ---
Documentation: --- CRM:
Verified Versions: Category: ---
oVirt Team: --- RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: --- Target Upstream Version:
Embargoed:
Bug Depends On:    
Bug Blocks: 2143447    

Description fifofonix 2023-09-20 13:57:34 UTC 
Most basic docker run functionality fails on minimal FedoraCoreOS `next` installation (next to no ignition configuration other than proxies).

Same behaviour also observed with SELinux switched to PERMISSIVE.

Reproducible: Always

Steps to Reproduce:
1. Commission new FedoraCoreOS node (on VMWareFusion, VMWare or AWS)
2. Execute `docker run -d nginx`
Actual Results:  
[map7071@minimal ~]$ docker run -d nginx
Unable to find image 'nginx:latest' locally
latest: Pulling from library/nginx
360eba32fa65: Pull complete 
c5903f3678a7: Pull complete 
27e923fb52d3: Pull complete 
72de7d1ce3a4: Pull complete 
94f34d60e454: Pull complete 
e42dcfe1730b: Pull complete 
907d1bb4e931: Pull complete 
Digest: sha256:f84caae4439aa1d6b8b645f9bb0557d2ad7b8f654c9f360f24f48eb1363f9deb
Status: Downloaded newer image for nginx:latest
c0aacda980e66d3cab40c8f34a6cb73c67f25e4c8e546a0cf6aab30b522f99bb
docker: Error response from daemon: failed to create task for container: failed to create shim task: ttrpc: cannot marshal unknown type: *task.CreateTaskRequest: unknown.
[map7071@minimal ~]$ docker ps
CONTAINER ID   IMAGE     COMMAND   CREATED   STATUS    PORTS     NAMES
[map7071@minimal ~]$ 

Expected Results:  
No error.

`docker ps` shows running process.

Docker journal info

[map7071@minimal ~]$ sudo journalctl -u docker
Sep 20 13:41:49 minimal systemd[1]: Starting docker.service - Docker Application Container Engine...
Sep 20 13:41:49 minimal dockerd[1356]: time="2023-09-20T13:41:49.840102271Z" level=info msg="Starting up"
Sep 20 13:41:49 minimal dockerd[1356]: time="2023-09-20T13:41:49.863521895Z" level=info msg="containerd not runnin>
Sep 20 13:41:49 minimal dockerd[1356]: time="2023-09-20T13:41:49.868417041Z" level=info msg="started new container>
Sep 20 13:41:50 minimal dockerd[1363]: time="2023-09-20T13:41:50.049900942Z" level=info msg="starting containerd" >
Sep 20 13:41:50 minimal dockerd[1363]: time="2023-09-20T13:41:50.065045515Z" level=info msg="loading plugin \"io.c>
Sep 20 13:41:50 minimal dockerd[1363]: time="2023-09-20T13:41:50.071608501Z" level=info msg="skip loading plugin \>
Sep 20 13:41:50 minimal dockerd[1363]: time="2023-09-20T13:41:50.071753748Z" level=info msg="loading plugin \"io.c>
Sep 20 13:41:50 minimal dockerd[1363]: time="2023-09-20T13:41:50.074806119Z" level=info msg="loading plugin \"io.c>
Sep 20 13:41:50 minimal dockerd[1363]: time="2023-09-20T13:41:50.075747676Z" level=info msg="skip loading plugin \>
Sep 20 13:41:50 minimal dockerd[1363]: time="2023-09-20T13:41:50.075771799Z" level=info msg="loading plugin \"io.c>
Sep 20 13:41:50 minimal dockerd[1363]: time="2023-09-20T13:41:50.075783830Z" level=warning msg="failed to load plu>
Sep 20 13:41:50 minimal dockerd[1363]: time="2023-09-20T13:41:50.075790784Z" level=info msg="loading plugin \"io.c>
Sep 20 13:41:50 minimal dockerd[1363]: time="2023-09-20T13:41:50.076863644Z" level=info msg="loading plugin \"io.c>
Sep 20 13:41:50 minimal dockerd[1363]: time="2023-09-20T13:41:50.078493286Z" level=info msg="loading plugin \"io.c>
Sep 20 13:41:50 minimal dockerd[1363]: time="2023-09-20T13:41:50.079202391Z" level=info msg="skip loading plugin \>
Sep 20 13:41:50 minimal dockerd[1363]: time="2023-09-20T13:41:50.079307790Z" level=info msg="loading plugin \"io.c>
Sep 20 13:41:50 minimal dockerd[1363]: time="2023-09-20T13:41:50.079400245Z" level=warning msg="could not use snap>
Sep 20 13:41:50 minimal dockerd[1363]: time="2023-09-20T13:41:50.079446061Z" level=info msg="metadata content stor>
Sep 20 13:41:50 minimal dockerd[1363]: time="2023-09-20T13:41:50.080792849Z" level=info msg="loading plugin \"io.c>
Sep 20 13:41:50 minimal dockerd[1363]: time="2023-09-20T13:41:50.080871443Z" level=info msg="loading plugin \"io.c>
Sep 20 13:41:50 minimal dockerd[1363]: time="2023-09-20T13:41:50.080909378Z" level=info msg="loading plugin \"io.c>
Sep 20 13:41:50 minimal dockerd[1363]: time="2023-09-20T13:41:50.081031935Z" level=info msg="loading plugin \"io.c>
Sep 20 13:41:50 minimal dockerd[1363]: time="2023-09-20T13:41:50.081559648Z" level=info msg="loading plugin \"io.c>
Sep 20 13:41:50 minimal dockerd[1363]: time="2023-09-20T13:41:50.082267982Z" level=info msg="loading plugin \"io.c>
Sep 20 13:41:50 minimal dockerd[1363]: time="2023-09-20T13:41:50.082861067Z" level=info msg="loading plugin \"io.c>
Sep 20 13:41:50 minimal dockerd[1363]: time="2023-09-20T13:41:50.084008478Z" level=info msg="loading plugin \"io.c>
Sep 20 13:41:50 minimal dockerd[1363]: time="2023-09-20T13:41:50.084081435Z" level=info msg="loading plugin \"io.c>
Sep 20 13:41:50 minimal dockerd[1363]: time="2023-09-20T13:41:50.084178243Z" level=info msg="loading plugin \"io.c>
Sep 20 13:41:50 minimal dockerd[1363]: time="2023-09-20T13:41:50.084225922Z" level=info msg="loading plugin \"io.c>
Sep 20 13:41:50 minimal dockerd[1363]: time="2023-09-20T13:41:50.084263084Z" level=info msg="loading plugin \"io.c>
Sep 20 13:41:50 minimal dockerd[1363]: time="2023-09-20T13:41:50.084299390Z" level=info msg="loading plugin \"io.c>
Sep 20 13:41:50 minimal dockerd[1363]: time="2023-09-20T13:41:50.084334524Z" level=info msg="loading plugin \"io.c>
Sep 20 13:41:50 minimal dockerd[1363]: time="2023-09-20T13:41:50.084395102Z" level=info msg="loading plugin \"io.c>
Sep 20 13:41:50 minimal dockerd[1363]: time="2023-09-20T13:41:50.084444096Z" level=info msg="loading plugin \"io.c>
Sep 20 13:41:50 minimal dockerd[1363]: time="2023-09-20T13:41:50.084532184Z" level=info msg="loading plugin \"io.c>
Sep 20 13:41:50 minimal dockerd[1363]: time="2023-09-20T13:41:50.084595875Z" level=info msg="loading plugin \"io.c>
Sep 20 13:41:50 minimal dockerd[1363]: time="2023-09-20T13:41:50.084638695Z" level=info msg="loading plugin \"io.c>
Sep 20 13:41:50 minimal dockerd[1363]: time="2023-09-20T13:41:50.084673251Z" level=info msg="loading plugin \"io.c>
Sep 20 13:41:50 minimal dockerd[1363]: time="2023-09-20T13:41:50.084707262Z" level=info msg="loading plugin \"io.c>
Sep 20 13:41:50 minimal dockerd[1363]: time="2023-09-20T13:41:50.084741930Z" level=info msg="loading plugin \"io.c>
Sep 20 13:41:50 minimal dockerd[1363]: time="2023-09-20T13:41:50.084793115Z" level=info msg="loading plugin \"io.c>
Sep 20 13:41:50 minimal dockerd[1363]: time="2023-09-20T13:41:50.084840184Z" level=info msg="loading plugin \"io.c>
Sep 20 13:41:50 minimal dockerd[1363]: time="2023-09-20T13:41:50.084893377Z" level=info msg="loading plugin \"io.c>
Sep 20 13:41:50 minimal dockerd[1363]: time="2023-09-20T13:41:50.084939856Z" level=info msg="loading plugin \"io.c>
Sep 20 13:41:50 minimal dockerd[1363]: time="2023-09-20T13:41:50.084974882Z" level=info msg="loading plugin \"io.c>
Sep 20 13:41:50 minimal dockerd[1363]: time="2023-09-20T13:41:50.085007996Z" level=info msg="loading plugin \"io.c>
Sep 20 13:41:50 minimal dockerd[1363]: time="2023-09-20T13:41:50.085051777Z" level=info msg="skip loading plugin \>
Sep 20 13:41:50 minimal dockerd[1363]: time="2023-09-20T13:41:50.085194282Z" level=info msg="loading plugin \"io.c>
Sep 20 13:41:50 minimal dockerd[1363]: time="2023-09-20T13:41:50.085354252Z" level=error msg="failed to initialize>
Sep 20 13:41:50 minimal dockerd[1363]: time="2023-09-20T13:41:50.085499129Z" level=info msg="loading plugin \"io.c>
Sep 20 13:41:50 minimal dockerd[1363]: time="2023-09-20T13:41:50.086055186Z" level=info msg="loading plugin \"io.c>
Sep 20 13:41:50 minimal dockerd[1363]: time="2023-09-20T13:41:50.087918136Z" level=info msg=serving... address=/va>
Sep 20 13:41:50 minimal dockerd[1363]: time="2023-09-20T13:41:50.088228160Z" level=info msg=serving... address=/va>
Sep 20 13:41:50 minimal dockerd[1363]: time="2023-09-20T13:41:50.088427788Z" level=info msg=serving... address=/va>
Sep 20 13:41:50 minimal dockerd[1363]: time="2023-09-20T13:41:50.088508922Z" level=info msg="containerd successful>
Sep 20 13:41:50 minimal dockerd[1356]: time="2023-09-20T13:41:50.100743230Z" level=info msg="detected 127.0.0.53 n>
Sep 20 13:41:50 minimal dockerd[1356]: time="2023-09-20T13:41:50.193803118Z" level=info msg="Loading containers: s>
Sep 20 13:41:50 minimal dockerd[1356]: time="2023-09-20T13:41:50.574183320Z" level=info msg="Loading containers: d>
Sep 20 13:41:50 minimal dockerd[1356]: time="2023-09-20T13:41:50.635544006Z" level=info msg="Docker daemon" commit>
Sep 20 13:41:50 minimal dockerd[1356]: time="2023-09-20T13:41:50.636180202Z" level=info msg="Daemon has completed >
Sep 20 13:41:50 minimal dockerd[1356]: time="2023-09-20T13:41:50.676219570Z" level=info msg="API listen on /run/do>
Sep 20 13:41:50 minimal systemd[1]: Started docker.service - Docker Application Container Engine.
Sep 20 13:48:16 minimal dockerd[1363]: time="2023-09-20T13:48:16.650073914Z" level=info msg="shim disconnected" id>
Sep 20 13:48:16 minimal dockerd[1363]: time="2023-09-20T13:48:16.650407497Z" level=warning msg="cleaning up after >
Sep 20 13:48:16 minimal dockerd[1363]: time="2023-09-20T13:48:16.650436343Z" level=info msg="cleaning up dead shim"
Sep 20 13:48:16 minimal dockerd[1356]: time="2023-09-20T13:48:16.650623552Z" level=error msg="stream copy error: r>
Sep 20 13:48:16 minimal dockerd[1356]: time="2023-09-20T13:48:16.650599861Z" level=error msg="stream copy error: r>
Sep 20 13:48:16 minimal dockerd[1363]: time="2023-09-20T13:48:16.660760933Z" level=error msg="failed to delete" cm>
Sep 20 13:48:16 minimal dockerd[1363]: time="2023-09-20T13:48:16.660819434Z" level=warning msg="failed to clean up>
Sep 20 13:48:16 minimal dockerd[1356]: time="2023-09-20T13:48:16.676403604Z" level=error msg="Handler for POST /v1>
[map7071@minimal ~]$
Comment 1 Jonathan Lebon 2023-09-20 17:44:38 UTC 
This is also an issue on Fedora Cloud.

```
[root@cloudy ~]# grep VARIANT_ID /etc/os-release
VARIANT_ID=cloud
[root@cloudy ~]# rpm -q moby-engine
moby-engine-24.0.5-1.fc39.x86_64
[root@cloudy ~]# docker run -d nginx
Unable to find image 'nginx:latest' locally
latest: Pulling from library/nginx
360eba32fa65: Pull complete
c5903f3678a7: Pull complete
27e923fb52d3: Pull complete
72de7d1ce3a4: Pull complete
94f34d60e454: Pull complete
e42dcfe1730b: Pull complete
907d1bb4e931: Pull complete
Digest: sha256:5b3a3b0b90e962a4af9db38fd247775a3bf6ae47b7fd55b799e5834ce9921a59
Status: Downloaded newer image for nginx:latest
2b6d2cf4c10edeb389cb11d90388e3496d79ec0ab9b25a93807d1d77ed058248
[  102.798153] docker0: port 1(veth5501cc9) entered blocking state
[  102.798481] docker0: port 1(veth5501cc9) entered disabled state
[  102.798785] veth5501cc9: entered allmulticast mode
[  102.799199] veth5501cc9: entered promiscuous mode
[  102.839506] docker0: port 1(veth5501cc9) entered disabled state
[  102.840974] veth5501cc9 (unregistering): left allmulticast mode
[  102.841278] veth5501cc9 (unregistering): left promiscuous mode
[  102.841559] docker0: port 1(veth5501cc9) entered disabled state
docker: Error response from daemon: failed to create task for container: failed to create shim task: ttrpc: cannot marshal unknown type: *task.CreateTaskRequest: unknown.
```
Comment 2 Dusty Mabe 2023-09-21 17:31:05 UTC 
According to the reports over in https://github.com/coreos/fedora-coreos-tracker/issues/1578#issuecomment-1729357930 it appears the issue is actually with containerd-1.6.23-1.fc39
Comment 3 Fedora Blocker Bugs Application 2023-09-21 17:32:45 UTC 
Proposed as a Freeze Exception for 39-final by Fedora user dustymabe using the blocker tracking app because:

 Having docker work on day 1 would be nice.
Comment 4 Sergio Basto 2023-09-22 13:43:39 UTC 

*** This bug has been marked as a duplicate of bug 2237396 ***