Dockerd stucks on stop/start/restart

[typoworx-de]

• This is a bug report
• This is a feature request
• I searched existing issues before opening this one

I'm running docker (version: docker-ce: 5:20.10.7) on my dev workstation with ubuntu. Since some time there where recurringly problems while trying to stop/restart dockerd service.

Expected behavior

I'm unable to successfully stop docker by "service docker stop", it hangs seemingly forever without any notice on CLI or syslog. All other docker commands also stuck on CLI.

Actual behavior

It's okay if docker stop or restart may take some time for clean-shutdown, but in my case it stuck for about 30 minutes yet without any reaction or cause whats going on under the hood!

Steps to reproduce the behavior

Output of docker version:
Commands stucks! But the deb-package installed is:
docker-ce:5:20.10.7~3-0~ubuntu-xenial

I'm not shure, running a few containers including portainer.io. I've been trying to run dockerd on CLI to find any hints:

sudo /usr/bin/dockerd -H fd:// --containerd=/run/containerd/containerd.sock

INFO[2022-07-26T16:50:58.124928429+02:00] Starting up                                  
INFO[2022-07-26T16:50:58.126793084+02:00] parsed scheme: "unix"                         module=grpc
INFO[2022-07-26T16:50:58.126814992+02:00] scheme "unix" not registered, fallback to default scheme  module=grpc
INFO[2022-07-26T16:50:58.126836740+02:00] ccResolverWrapper: sending update to cc: {[{unix:///run/containerd/containerd.sock  <nil> 0 <nil>}] <nil> <nil>}  module=grpc
INFO[2022-07-26T16:50:58.126846386+02:00] ClientConn switching balancer to "pick_first"  module=grpc
INFO[2022-07-26T16:50:58.127734835+02:00] parsed scheme: "unix"                         module=grpc
INFO[2022-07-26T16:50:58.127755574+02:00] scheme "unix" not registered, fallback to default scheme  module=grpc
INFO[2022-07-26T16:50:58.127774908+02:00] ccResolverWrapper: sending update to cc: {[{unix:///run/containerd/containerd.sock  <nil> 0 <nil>}] <nil> <nil>}  module=grpc
INFO[2022-07-26T16:50:58.127783924+02:00] ClientConn switching balancer to "pick_first"  module=grpc
WARN[2022-07-26T16:50:59.008676847+02:00] Your kernel does not support CPU realtime scheduler 
WARN[2022-07-26T16:50:59.008705159+02:00] Your kernel does not support cgroup blkio weight 
WARN[2022-07-26T16:50:59.008711437+02:00] Your kernel does not support cgroup blkio weight_device 
INFO[2022-07-26T16:50:59.008851313+02:00] Loading containers: start.                   
INFO[2022-07-26T16:51:00.072125948+02:00] ignoring event                                container=0435044b074572ead3ccfddb00dbe7ea3dd8a8bb1d925e802bd211445dc6118f module=libcontainerd namespace=moby topic=/tasks/delete type="*events.TaskDelete"
INFO[2022-07-26T16:51:00.254350848+02:00] ignoring event                                container=6a2041721f3e91baf56e80ad5af0b70ba437f7b24913b8f274d6af67a578bda5 module=libcontainerd namespace=moby topic=/tasks/delete type="*events.TaskDelete"
ERRO[2022-07-26T16:51:02.072616189+02:00] stream copy error: reading from a closed fifo 
INFO[2022-07-26T16:51:03.696819245+02:00] Removing stale sandbox 3a5bea986e25510dc6cc725d40876c3f6b57d239a4e76cc6b0e100b63f91be7f (0435044b074572ead3ccfddb00dbe7ea3dd8a8bb1d925e802bd211445dc6118f) 
WARN[2022-07-26T16:51:04.112226680+02:00] Error (Unable to complete atomic operation, key modified) deleting object [endpoint 70942b55bc59f95169a175a7ab23c5f5be4f4c6c5e7e4cb4f7c1134322343519 4eb96edd1ddfbf49cb785f55dd98627a5f28af947d83fcdcf487ad5ba064f031], retrying.... 
INFO[2022-07-26T16:51:05.381195190+02:00] Removing stale sandbox a1745e1236a8911c09038c641c530fd52866c463ce835d9b58a62e929f404cb8 (6a2041721f3e91baf56e80ad5af0b70ba437f7b24913b8f274d6af67a578bda5) 
WARN[2022-07-26T16:51:05.773679260+02:00] Error (Unable to complete atomic operation, key modified) deleting object [endpoint 1160798981a1a6f7aa5cf56e7250a1f70a4541864f3ac20012a6bc7861279711 92aeecab3339941e8fc6b37b55238d8c9576f800d0b5a738bfead73dc4d794e9], retrying.... 
INFO[2022-07-26T16:51:07.440250557+02:00] 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 
INFO[2022-07-26T16:51:10.040702467+02:00] No non-localhost DNS nameservers are left in resolv.conf. Using default external servers: [nameserver 8.8.8.8 nameserver 8.8.4.4] 
INFO[2022-07-26T16:51:10.040725060+02:00] IPv6 enabled; Adding default IPv6 external servers: [nameserver 2001:4860:4860::8888 nameserver 2001:4860:4860::8844] 
INFO[2022-07-26T16:51:10.040764307+02:00] No non-localhost DNS nameservers are left in resolv.conf. Using default external servers: [nameserver 8.8.8.8 nameserver 8.8.4.4] 
INFO[2022-07-26T16:51:10.040783109+02:00] IPv6 enabled; Adding default IPv6 external servers: [nameserver 2001:4860:4860::8888 nameserver 2001:4860:4860::8844] 
INFO[2022-07-26T16:51:13.326711189+02:00] Loading containers: done.                    
INFO[2022-07-26T16:51:14.124320717+02:00] Docker daemon                                 commit=b0f5bc3 graphdriver(s)=overlay2 version=20.10.7
INFO[2022-07-26T16:51:14.124397034+02:00] Daemon has completed initialization          

-- FROM HERE ON STUCKS --

I'm able to access portainer web-ui anyway, but it shows "offline" for local socket-connection. Any other CLI docker commands like docker events or docker info stuck as well!

Waiting about 30 minutes the process still stuck in the same state. From earlier issues of this type I had left running the dockerd about 1~2 hours and last time for some reason docker startet to respond as it never had any problem before. There was no traceable reason to be find in syslog yet.

I'm having this problem for recurring time now.

Additional environment details (AWS, VirtualBox, physical, etc.)
No virtualisation, it's running on my ubuntu system in host-system (ubuntu).

[dincercelik]

I am facing similar issues on Ubuntu 18.04 after upgrading to docker-ce:5:20.10.17~3-0~ubuntu-bionic. The daemon comes up but does not respond to any command. Trying to fix this without removing containers but couldn't find a proper way yet.

Aug 09 20:17:35 control06 dockerd[6978]: time="2022-08-09T20:17:35.421147176+03:00" level=info msg="Removing stale sandbox ac0cb17040a3233169c41128011dd1e27cc8f0aec7992700b423afe202c68765 (2861c8f66b5b7a1a2b6081d0761251ecb4a6171f9ed85880c2d5a9ee903fc9cf)"
Aug 09 20:17:50 control06 dockerd[6978]: time="2022-08-09T20:17:50.545145659+03:00" level=info msg="Removing stale sandbox eb1865a547b796f6c8f81197fc0b3c025d5072392d49195ecaaa512bf9a4ffdc (ebde8e91db1fa2d7710e0296c9699f71358fc519af20b8b2f5d74db8b312007f)"
Aug 09 20:18:05 control06 dockerd[6978]: time="2022-08-09T20:18:05.667394905+03:00" level=info msg="Removing stale sandbox 061a0d11521ba01efef801b2fe67c19803ab4e8e2c93a472c57562cbe8427fa3 (85569543862d33eec1556887fd77a5295cf188d3ad704c82ae9e747ab738a59e)"
Aug 09 20:18:20 control06 dockerd[6978]: time="2022-08-09T20:18:20.792642314+03:00" level=info msg="Removing stale sandbox 32e462303c61f491d21cfa5b771282c041cea2a43d88b8359255a88e1ae23c4e (0ad0b3430df63ac7909230bf5ae323a64241d54e05bcbd38e8c45da5a3613102)"
Aug 09 20:18:35 control06 dockerd[6978]: time="2022-08-09T20:18:35.916178180+03:00" level=info msg="Removing stale sandbox 90ecc99a53b54f3091fb7d4b095873b88bc6e6edb8cfb82c70a6a4f44eec06ac (a7c97e8c1c3ec6d78d4cb99f7e0ada1e400febd4863937197948b9cff226c8a1)"
Aug 09 20:18:51 control06 dockerd[6978]: time="2022-08-09T20:18:51.040429809+03:00" level=info msg="Removing stale sandbox b00defc85a98b281eecae0fd7b9603d9b505f06ca5781d0697afb44f394e607f (3c3f07977eaf7b286249e0b44ab4f1a34e780132321fd5d1b6b3fceb8935a20e)"
Aug 09 20:19:06 control06 dockerd[6978]: time="2022-08-09T20:19:06.165628869+03:00" level=info msg="Removing stale sandbox b3f87458515d385dd47eedc9bc77e990b2bb27e47dc681752d7048885d702363 (1b6d8e9bdf62fbeecba68423021c08dc0a4cd61c319ee1e62f57901f1b6a7e3a)"
Aug 09 20:19:21 control06 dockerd[6978]: time="2022-08-09T20:19:21.179351851+03:00" level=warning msg="Error (Unable to complete atomic operation, key modified) deleting object [endpoint 6ab540dfe04ad559e9e162f034d861f4177663da7e3779aa720213d226f0df5e 27afc5f03106042f7be3cc1d11bce4038eb2fe1dad0f916e93895d86f56beb5a], retrying...."
Aug 09 20:19:27 control06 dockerd[6978]: time="2022-08-09T20:19:27.291734213+03:00" level=info msg="Removing stale sandbox e5179f34ae3ff118cfd139c1bae8719255ccc79db4527961a4f36a937607f6ba (1ec81a7e440f8eeea3d0e3d5f3986789fc4b3d559c8fb099b12694422b4e57e9)"
Aug 09 20:19:42 control06 dockerd[6978]: time="2022-08-09T20:19:42.305721874+03:00" level=warning msg="Error (Unable to complete atomic operation, key modified) deleting object [endpoint 6ab540dfe04ad559e9e162f034d861f4177663da7e3779aa720213d226f0df5e 3f8315a7cdc8741411e613b264a7b300f1097915d84e42980458695dd2529f36], retrying...."
Aug 09 20:19:48 control06 dockerd[6978]: time="2022-08-09T20:19:48.418700501+03:00" level=info msg="Removing stale sandbox f869cb4bcc10b56e300c4012affe547b0ebf2b32aa20d6855a3d6bff94e211d6 (72a663931b7727b1dfa37d0c15a5535434554bc057ccd8d8b812f97ed44f3555)"
Aug 09 20:20:03 control06 dockerd[6978]: time="2022-08-09T20:20:03.433644137+03:00" level=warning msg="Error (Unable to complete atomic operation, key modified) deleting object [endpoint 6ab540dfe04ad559e9e162f034d861f4177663da7e3779aa720213d226f0df5e c90b1f2fa586f7a8a7bbab55a3cc1adadef55dbeabcc444da59f7196258b2959], retrying...."
Aug 09 20:20:05 control06 dockerd[6978]: time="2022-08-09T20:20:05.534618300+03:00" level=info msg="Processing signal 'terminated'"
Aug 09 20:20:09 control06 dockerd[6978]: time="2022-08-09T20:20:09.548287876+03:00" level=info msg="Removing stale sandbox 32def10cab2ecadd44694741c46dd4ebb4d49a6a3e3eddc62488496a68c787e2 (4021864a364f29d2362173bd2b1c0842b09d2b0ee104506d93ebcdbfe0e520ae)"
Aug 09 20:20:24 control06 dockerd[6978]: time="2022-08-09T20:20:24.666389701+03:00" level=info msg="Removing stale sandbox 5e5fe589dec2363dea7d7eceb16ef3567cfe7801d940743143f691fc7ece80c5 (ac07d6c3824b424b523831bcd09855e575d0b87ee0761cf2408a1dfc1014a110)"
Aug 09 20:20:39 control06 dockerd[6978]: time="2022-08-09T20:20:39.790282413+03:00" level=info msg="Removing stale sandbox 7c75a85e34b600efeb67b777dbcccb1684a49310ca9b70377a563aa13c59e38a (009f0d79ca9470673185d33a0f51d6d9a4f99c2de186c0f9d9175993055851fe)"
Aug 09 20:20:54 control06 dockerd[6978]: time="2022-08-09T20:20:54.908522972+03:00" level=info msg="Removing stale sandbox a1854d50610be64e66485ebf5a5446217c58760761ed873a13c3f78167204a75 (23ddd25748f98825f66d55dd59c1a2ae83279f2f746a7f71cd8193a67281de69)"
Aug 09 20:21:09 control06 dockerd[6978]: time="2022-08-09T20:21:09.925341354+03:00" level=warning msg="Error (Unable to complete atomic operation, key modified) deleting object [endpoint 6ab540dfe04ad559e9e162f034d861f4177663da7e3779aa720213d226f0df5e acca0a1724dc96bb9636ec7dcdc700ee50185d5e05f766a9e088ff2fb5cb7191], retrying...."
Aug 09 20:21:16 control06 dockerd[6978]: time="2022-08-09T20:21:16.039133083+03:00" level=info msg="Removing stale sandbox 26884c5ed4639899f8c4c343afa87439771531e8c223fc6485cded4090909ad1 (a625474f389bec12c59573ff3f25568cc717f5891397de8e475404f2f2c2cfd5)"
Aug 09 20:21:31 control06 dockerd[6978]: time="2022-08-09T20:21:31.159456655+03:00" level=info msg="Removing stale sandbox 6c4312f6a5846f7536f02969703a3584677e1751df1a31cddde8fa7c73ecdd29 (2ef638dbaa74be1bba12188afe04b2fd9d4913b85d7b3022f7babbd58f5d53a4)"
Aug 09 20:21:46 control06 dockerd[6978]: time="2022-08-09T20:21:46.282059623+03:00" level=info msg="Removing stale sandbox 7ee7bbe44bb00bcf7e5830896f3a0c1a29917b35a81ce6ad3ccfc146b4416e65 (83fec2668905a506bf41c15277712402b654fc6b1ceed1b18fb2ecfca85b3105)"
Aug 09 20:22:01 control06 dockerd[6978]: time="2022-08-09T20:22:01.405521933+03:00" level=info msg="Removing stale sandbox dcb38d7ba8921bece9595956f63e67f4f0d2fe9cd72157af477199da98be4e0e (ea76b8b712905b8996746d599350700ace275b9082611561010ca8ba7a839765)"
Aug 09 20:22:16 control06 dockerd[6978]: time="2022-08-09T20:22:16.421400630+03:00" level=warning msg="Error (Unable to complete atomic operation, key modified) deleting object [endpoint 6ab540dfe04ad559e9e162f034d861f4177663da7e3779aa720213d226f0df5e 5afb95fc391fd2ca075747851ab44cb1c254c2b1ff7fc003abbeb869025d5483], retrying...."
Aug 09 20:22:22 control06 dockerd[6978]: time="2022-08-09T20:22:22.537082750+03:00" level=info msg="Removing stale sandbox e7237180edc666f5596ee54cbf111929d81d8743f0f7be44e47cab5d2b6133c1 (d46adea9d94f45077798c29b9ed484135e7e7c15defb8ff374318aebb282271d)"
Aug 09 20:22:37 control06 dockerd[6978]: time="2022-08-09T20:22:37.551878738+03:00" level=warning msg="Error (Unable to complete atomic operation, key modified) deleting object [endpoint 6ab540dfe04ad559e9e162f034d861f4177663da7e3779aa720213d226f0df5e 7a46a4e9e0a1d8d67883b03f29f68458db44d83fc60bcde5f36c2d6e1e42ae02], retrying...."
Aug 09 20:22:43 control06 dockerd[6978]: time="2022-08-09T20:22:43.666602161+03:00" level=info msg="Removing stale sandbox 1e20fc75dcfaa37820f60f1a0a0905e7f90c8a5ee0f35fcc79ad0bdc396e97a5 (9bd5bcfc09ad27ba53b353479b6e6f47f1dda0b64cea3c64a08a2e4af1d3bc59)"
Aug 09 20:22:58 control06 dockerd[6978]: time="2022-08-09T20:22:58.792021925+03:00" level=info msg="Removing stale sandbox 3af50d7f25e647a9463869ad09edc7cbabfc3bf762faf9fecf433f70cc410294 (31559342583c40e6ef4b594ad61a8db00ce10fb55c8b5bb5cddd33f296df6b0b)"
Aug 09 20:23:13 control06 dockerd[6978]: time="2022-08-09T20:23:13.807337589+03:00" level=warning msg="Error (Unable to complete atomic operation, key modified) deleting object [endpoint 6ab540dfe04ad559e9e162f034d861f4177663da7e3779aa720213d226f0df5e 7abcd5e97bf9998a9384f5124622146282044db1154753b802788e599b45bc67], retrying...."