Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

Infinite loop when starting docker after update. #6260

Closed
NawafSwe opened this issue Mar 31, 2022 · 7 comments
Closed

Infinite loop when starting docker after update. #6260

NawafSwe opened this issue Mar 31, 2022 · 7 comments
Labels
lifecycle/locked

Comments

@NawafSwe
Copy link

NawafSwe commented Mar 31, 2022 •
edited

  • [✅] I have tried with the latest version of Docker Desktop
  • [✅] I have tried disabling enabled experimental features
  • [✅] I have uploaded Diagnostics
  • Diagnostics ID: 20220331084238

Expected behavior

When I update docker to the latest version it should starts successfully within maximum 10 seconds.

Actual behavior

The Actual behavior it goes into Infinite loop trying to starting the docker process.

Temporary Solution

I revert the update and install Docker desktop with version (4.5.0)

Running /Applications/Docker.app/Contents/MacOS/com.docker.diagnose check

/Applications/Docker.app/Contents/MacOS/com.docker.diagnose check
Starting diagnostics

[PASS] DD0027: is there available disk space on the host?
[PASS] DD0028: is there available VM disk space?
[FAIL] DD0031: does the Docker API work? Cannot connect to the Docker daemon at unix://Library/Containers/com.docker.docker/Data/docker.raw.sock. Is the docker daemon running?
[PASS] DD0004: is the Docker engine running?
[PASS] DD0011: are the LinuxKit services running?
[PASS] DD0016: is the LinuxKit VM running?
[PASS] DD0001: is the application running?
[PASS] DD0018: does the host support virtualization?
[PASS] DD0017: can a VM be started?
[PASS] DD0015: are the binary symlinks installed?
Error response from daemon: dial unix /Users/n/Library/Containers/com.docker.docker/Data/docker.raw.sock: connect: connection refused
[FAIL] DD0003: is the Docker CLI working? exit status 1
[PASS] DD0013: is the $PATH ok?
[PASS] DD0007: is the backend responding?
[PASS] DD0014: are the backend processes running?
[PASS] DD0008: is the native API responding?
[PASS] DD0009: is the vpnkit API responding?
[PASS] DD0010: is the Docker API proxy responding?
[PASS] DD0012: is the VM networking working?
[FAIL] DD0032: do Docker networks overlap with host IPs? Cannot connect to the Docker daemon at unix://Library/Containers/com.docker.docker/Data/docker.raw.sock. Is the docker daemon running?
[SKIP] DD0030: is the image access management authorized?
[PASS] DD0019: is the com.docker.vmnetd process responding?
[PASS] DD0033: does the host have Internet access?

Information

  • macOS Version: macOS Monterey version (12.3)
  • Intel chip or Apple chip: Latest M1 Pro apple chip
  • Docker Desktop Version: latest version (4.6.1)
@sorokod
Copy link

sorokod commented Apr 1, 2022

I have the same symptom with the same solution.
Tailing ~/Library/Containers/com.docker.docker/Data/log/vm/docker.log I see repeated ... still waiting for /Users to be mounted after ... messages

@moon-sam
Copy link

moon-sam commented Apr 1, 2022 •
edited

Same solution (going back to prior version) worked for me. Used a DMG I had from Jan 1.

➜   ✗ tail -100 ~/Library/Containers/com.docker.docker/Data/log/vm/docker.log
tail -100 ~/Library/Containers/com.docker.docker/Data/log/vm/docker.log
[091:19:56:46.386][I]
[linuxkit/pkg/desktop-host-tools/pkg/containerd.Start()
[	linuxkit/pkg/desktop-host-tools/pkg/containerd/containerd.go:27 +0xa8
[main.run()
[	linuxkit/pkg/desktop-host-tools/cmd/lifecycle-server/main.go:101 +0x4c4
[main.main()
[	linuxkit/pkg/desktop-host-tools/cmd/lifecycle-server/main.go:36 +0x1e4
[091:19:56:46.386][I] time="2022-04-01T19:56:46Z" level=info msg="Starting lifecycle-server"
[091:19:56:46.386][I] time="2022-04-01T19:56:46Z" level=info msg="Setting up certificates"
[091:19:56:46.387][I] time="2022-04-01T19:56:46Z" level=info msg="iptables -w -t nat -N desktop"
[091:19:56:46.390][I] time="2022-04-01T19:56:46Z" level=info msg="Increasing resource limits"
[091:19:56:46.390][I] time="2022-04-01T19:56:46Z" level=info msg="Starting docker engine"
[091:19:56:46.390][I] waiting for the backend to respond
[091:19:56:46.390][I] (efcf43bc) 39c214db-DockerdPKG C->S BackendAPI GET /ping
[091:19:56:46.394][I] time="2022-04-01T19:56:46Z" level=info msg="iptables -w -t nat -A PREROUTING -j desktop"
[091:19:56:46.392][I] (efcf43bc) 39c214db-DockerdPKG C<-S 4a56c212-VMAPI GET /ping (2.189ms): {"serverTime":1648843006392062000}
[091:19:56:46.392][I] backend is responding
[091:19:56:46.392][I] mounting host fileserver
[091:19:56:46.392][I] create symlinks
[091:19:56:46.392][I] try to mount host fileserver
[091:19:56:46.393][I] mount server is on unix:/run/grpcfuse.mount.sock
[091:19:56:46.393][I] c959a59d-VMDockerdAPI : registering GET /ping
[091:19:56:46.393][I] c959a59d-VMDockerdAPI : registering GET /
[091:19:56:46.393][I] c959a59d-VMDockerdAPI : registering GET /goroutines/stacks
[091:19:56:46.393][I] ipc.NewServer: c959a59d-VMDockerdAPI <- /run/guest-services/lifecycle-server.sock
[linuxkit/pkg/desktop-host-tools/pkg/server.(*server).Start(0x4000287f70)
[	linuxkit/pkg/desktop-host-tools/pkg/server/server.go:50 +0xd8
[main.run.func1(0x4000486380, {0xe9d290, 0x400059e060}, 0x0, 0x400062ecc0)
[	linuxkit/pkg/desktop-host-tools/cmd/lifecycle-server/main.go:95 +0xd8
[created by main.run
[	linuxkit/pkg/desktop-host-tools/cmd/lifecycle-server/main.go:92 +0x474
[091:19:56:46.393][I] c959a59d-VMDockerdAPI : registering GET /vm/resume
[091:19:56:46.393][I] c959a59d-VMDockerdAPI : registering POST /vm/shutdown
[091:19:56:46.393][I] c959a59d-VMDockerdAPI : registering POST /vm/httpproxy
[091:19:56:46.393][I] c959a59d-VMDockerdAPI : registering POST /kubernetes/start
[091:19:56:46.393][I] c959a59d-VMDockerdAPI : registering GET /kubernetes/stop
[091:19:56:46.393][I] c959a59d-VMDockerdAPI : registering GET /kubernetes/reset
[091:19:56:46.393][I] c959a59d-VMDockerdAPI : registering GET /kubernetes/ensure-controllers
[091:19:56:46.393][I] c959a59d-VMDockerdAPI : registering POST /mutagen/cleanup
[091:19:56:46.393][I] c959a59d-VMDockerdAPI : registering GET /docker/reload
[091:19:56:46.393][I] c959a59d-VMDockerdAPI : registering GET /docker
[091:19:56:46.393][I] c959a59d-VMDockerdAPI : registering GET /fuse/time
[091:19:56:46.393][I] c959a59d-VMDockerdAPI : registering GET /fuse/count
[091:19:56:46.393][I] c959a59d-VMDockerdAPI : registering GET /fuse/filename
[091:19:56:46.393][I] c959a59d-VMDockerdAPI : registering GET /fuse/calls
[091:19:56:46.393][I] c959a59d-VMDockerdAPI : registering GET /fuse/follow
[091:19:56:46.393][I] c959a59d-VMDockerdAPI : registering GET /mutagen/info
[091:19:56:46.393][I] c959a59d-VMDockerdAPI : registering POST /volume/approve
[091:19:56:46.393][I] c959a59d-VMDockerdAPI : registering GET /profile/start
[091:19:56:46.393][I] c959a59d-VMDockerdAPI : registering GET /profile/stop
[091:19:56:46.393][I] c959a59d-VMDockerdAPI : registering POST /hub-login
[091:19:56:46.393][I] c959a59d-VMDockerdAPI : registering POST /fuse/reset
[091:19:56:46.393][I] starting c959a59d-VMDockerdAPI for component lifecycle-server-pkg on /run/guest-services/lifecycle-server.sock
[091:19:56:46.395][I] time="2022-04-01T19:56:46Z" level=info msg="iptables -w -t nat -I desktop -p tcp -d 10.96.0.0/12 -j RETURN"
[091:19:56:46.399][I] time="2022-04-01T19:56:46Z" level=info msg="attempting to mount filesystem / with ID 2 on /host_mnt"
[091:19:56:46.399][I] time="2022-04-01T19:56:46Z" level=info msg="kernel entry timeout: 1h0m0s"
[091:19:56:46.399][I] time="2022-04-01T19:56:46Z" level=info msg="kernel attribute timeout: 1h0m0s"
[091:19:56:46.399][I] time="2022-04-01T19:56:46Z" level=info msg="kernel negative timeout: 0s"
[091:19:56:46.401][I] time="2022-04-01T19:56:46Z" level=info msg="iptables -w -t nat -I desktop -p tcp -d 10.1.0.0/16 -j RETURN"
[091:19:56:46.401][I] time="2022-04-01T19:56:46Z" level=info msg="Filesystem mounted to root /host_mnt"
[091:19:56:46.401][I] fuse successfully mounted on /host_mnt
[091:19:56:46.401][I] starting dockerd bootstrap
[091:19:56:46.401][I] shutting down any old Docker engine
[091:19:56:46.401][I] waiting for the clock to be set
[091:19:56:46.401][I] clock value looks plausible: 2022-04-01 19:56:46.401514417 +0000 UTC m=+1.479555918
[091:19:56:46.401][I] fetching daemon.json from the host
[091:19:56:46.401][I] (51fafd7a) 39c214db-DockerdPKG C->S BackendAPI GET /engine/daemon.json
[091:19:56:46.404][I] time="2022-04-01T19:56:46Z" level=info msg="iptables -w -t nat -I desktop -p tcp -d 192.168.65.5/32 -j RETURN"
[091:19:56:46.404][I] (51fafd7a) 39c214db-DockerdPKG C<-S 4a56c212-VMAPI GET /engine/daemon.json (3.096459ms): {"builder":{"gc":{"defaultKeepStorage":"20GB","enabled":true}},"experimental":false,"features":{"buildkit":true}}
[091:19:56:46.404][I] adding hosts to daemon.json
[091:19:56:46.404][I] writing daemon.json
[091:19:56:46.404][I] no metrics-addr in daemon.json: not exposing a metrics port
[091:19:56:46.404][I] waiting for internal network to respond
[091:19:56:46.405][I] time="2022-04-01T19:56:46Z" level=info msg="iptables -w -t nat -I desktop -p tcp -d 127.0.0.0/8 -j RETURN"
[091:19:56:46.407][I] time="2022-04-01T19:56:46Z" level=info msg="iptables -w -t nat -I desktop -p tcp -d 192.168.65.0/24 -j RETURN"
[091:19:56:46.411][I] detected DNS gateway.docker.internal -> [192.168.65.2]
[091:19:56:46.411][I] reading HTTP proxy configuration
[091:19:56:46.411][I] creating /run/xtables.lock file
[091:19:56:46.411][I] waiting for Docker API proxy socket
[091:19:56:46.411][I] resolving host.docker.internal. DNS
[091:19:56:46.413][I] mutagen: connection received
[091:19:56:46.413][I] launching docker engine
[091:19:56:46.414][I] detected cgroup2 on /sys/fs/cgroup
[091:19:56:46.414][I] adding process 1687 to /sys/fs/cgroup/restricted
[091:19:56:46.422][I] waiting for Docker API to respond on unix:///var/run/docker.sock
[091:19:56:46.422][I] wait for engine: Client: &{scheme:http host:unix:///var/run/docker.sock proto:unix addr:/var/run/docker.sock basePath: client:0x40002f3440 version:1.41 customHTTPHeaders:map[] manualOverride:false negotiateVersion:true negotiated:false}
[091:19:56:46.565][E] dockerd died before the API started up: exit status 1
[linuxkit/pkg/desktop-host-tools/pkg/dockerd.Start()
[	linuxkit/pkg/desktop-host-tools/pkg/dockerd/start.go:52 +0x184
[main.run()
[	linuxkit/pkg/desktop-host-tools/cmd/lifecycle-server/main.go:116 +0x5e4
[main.main()
[	linuxkit/pkg/desktop-host-tools/cmd/lifecycle-server/main.go:36 +0x1e4
[091:19:56:46.565][I] sending fatal error to GUI: exit status 1
[091:19:56:46.565][I] (11d58854) 73d47f1a-DockerdPKG C->S  POST /fatal: {"diagnose":"exit status 1","message":"failed"}
[091:19:56:46.573][I] (11d58854) 73d47f1a-DockerdPKG C<-S b5250cc3-SwiftAPI POST /fatal (7.572709ms): OK
[091:19:56:46.573][I] sending docker state failed to backend: exit status 1
[091:19:56:46.573][I] (a12111a9) 39c214db-DockerdPKG C->S BackendAPI POST /events: {"HasServerTimestamp":false,"content":"lifecycle-server sent docker state failed","docker":"failed","timestamp":1648843006573261300}
[091:19:56:46.582][I] (a12111a9) 39c214db-DockerdPKG C<-S 4a56c212-VMAPI POST /events (9.128042ms): OK
[091:19:56:46.582][I] time="2022-04-01T19:56:46Z" level=fatal msg="exit status 1"

@AndreaCensi
Copy link

I have exactly the same problem, with the same messages as @sorokod.
The issues persist even after a complete manual uninstall of docker.
Downgrading to 4.5.0 is the only solution I found,

@giorginogreg
Copy link

@sorokod Same for me.
Found a temporary solution looking at this post

@NawafSwe
Copy link
Author

NawafSwe commented Apr 6, 2022

@giorginogreg @AndreaCensi @moon-sam @sorokod
Please Follow this article it solved the problem for me. I updated docker to the latest version finally 🤣.
Article: https://www.mytecbits.com/apple/macos/clean-way-to-uninstall-docker

@NawafSwe NawafSwe closed this as completed Apr 6, 2022
@giorginogreg
Copy link

giorginogreg commented Apr 6, 2022 •
edited

@NawafSwe
for what I can see, this still remains an issue because the update process has not finished successfully, I mean, it worked but had left a product in a non consistent status, because after the update Docker still doesn't refreshed / deleted the files that it need for working in the good way.

What do you think about?

@docker-robott
Copy link
Collaborator

Closed issues are locked after 30 days of inactivity.
This helps our team focus on active issues.

If you have found a problem that seems similar to this, please open a new issue.

Send feedback to Docker Community Slack channels #docker-for-mac or #docker-for-windows.
/lifecycle locked

@docker docker locked and limited conversation to collaborators May 6, 2022
Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Assignees
No one assigned
Labels
lifecycle/locked
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
6 participants
@AndreaCensi @sorokod @giorginogreg @NawafSwe @docker-robott @moon-sam