Docker Containers Getting Stopped

[egmanoj]

I’ve installed Docker using Snap. Recently running containers have been getting stopped on their own. This happens say 2-3 times in the space of ~8-10 hours. I’ve been trying to find a root cause without much success. Relevant information below. Let me know if I can provide more information to help.

$ docker --version
Docker version 19.03.13, build cd8016b6bc

$ snap --version
snap    2.51.4
snapd   2.51.4
series  16
ubuntu  18.04
kernel  5.4.0-81-generic

Docker daemon.json

$ cat /var/snap/docker/current/config/daemon.json 
{
  "log-level": "error",
  "storage-driver": "aufs",
  "bip": "172.28.0.1/24"
}

$ dmesg -T
[Tue Sep 14 20:31:37 2021] aufs aufs_fill_super:918:mount[18200]: no arg
[Tue Sep 14 20:31:37 2021] overlayfs: missing 'lowerdir'
[Tue Sep 14 20:31:43 2021] br-6c6facc1a891: port 5(veth4c212a4) entered disabled state
[Tue Sep 14 20:31:43 2021] device veth4c212a4 left promiscuous mode
[Tue Sep 14 20:31:43 2021] br-6c6facc1a891: port 5(veth4c212a4) entered disabled state
[Tue Sep 14 20:31:45 2021] br-6c6facc1a891: port 1(veth1c95aae) entered disabled state
[Tue Sep 14 20:31:45 2021] device veth1c95aae left promiscuous mode
[Tue Sep 14 20:31:45 2021] br-6c6facc1a891: port 1(veth1c95aae) entered disabled state
[Tue Sep 14 20:31:45 2021] br-6c6facc1a891: port 4(veth1dfd80e) entered disabled state
[Tue Sep 14 20:31:45 2021] device veth1dfd80e left promiscuous mode
[Tue Sep 14 20:31:45 2021] br-6c6facc1a891: port 4(veth1dfd80e) entered disabled state
[Tue Sep 14 20:31:46 2021] br-6c6facc1a891: port 2(veth8e48cf4) entered disabled state
[Tue Sep 14 20:31:46 2021] device veth8e48cf4 left promiscuous mode
[Tue Sep 14 20:31:46 2021] br-6c6facc1a891: port 2(veth8e48cf4) entered disabled state
[Tue Sep 14 20:31:46 2021] br-6c6facc1a891: port 3(veth534c1d3) entered disabled state
[Tue Sep 14 20:31:46 2021] device veth534c1d3 left promiscuous mode
[Tue Sep 14 20:31:46 2021] br-6c6facc1a891: port 3(veth534c1d3) entered disabled state
[Tue Sep 14 20:31:47 2021] br-6c6facc1a891: port 6(veth316fdd7) entered disabled state
[Tue Sep 14 20:31:47 2021] device veth316fdd7 left promiscuous mode

Note the difference in timestamp between Docker logs, below and dmesg, above.
The Docker logs appear to be from previous time I restarted containers using docker-compose.

$ sudo snap logs docker
2021-09-14T15:01:19Z docker.dockerd[27385]: time="2021-09-14T20:31:19.783211664+05:30" level=error msg="connecting to shim" error="dial unix \x00/containerd-shim/af7c138e4399d3bb8a5615ec05fd1ba90bc7e98391b468067374a020d792906d.sock: connect: connection refused" id=2b9e8a563dad5f61e2ad525c5d590804c33c6cd323d580fe365c170fd5a68a8a namespace=moby
2021-09-14T15:01:19Z docker.dockerd[27385]: time="2021-09-14T20:31:19.860328985+05:30" level=error msg="connecting to shim" error="dial unix \x00/containerd-shim/281fedfbf5b11053d28853b6ad6175009903b338995d5faa0862e8f1ab0e3b10.sock: connect: connection refused" id=43449775462debc8336ab1bc63e2020e8a554ee25db31befa561dc790c76e1ac namespace=moby
2021-09-14T15:01:19Z docker.dockerd[27385]: time="2021-09-14T20:31:19.878788076+05:30" level=error msg="connecting to shim" error="dial unix \x00/containerd-shim/ff2c9cacd1ef1ac083f93e4823f5d0fa4146593f2b6508a098b22270b48507b4.sock: connect: connection refused" id=4d91c4451a011d87b2d21fe7d74e3c4e7ffa20f2df69076f36567b5389597637 namespace=moby
2021-09-14T15:01:19Z docker.dockerd[27385]: time="2021-09-14T20:31:19.906212149+05:30" level=error msg="connecting to shim" error="dial unix \x00/containerd-shim/017a3907df26803a221be66a2a0ac25e43a994d26432cba30f6c81c078ad62fa.sock: connect: connection refused" id=79e0d419a1d82f83dd81898a02fa1161b909ae88c1e46575a1bec894df31a482 namespace=moby
2021-09-14T15:01:19Z docker.dockerd[27385]: time="2021-09-14T20:31:19.919895281+05:30" level=error msg="connecting to shim" error="dial unix \x00/containerd-shim/47e9b56ce80402793038edf72fe64b44a05f659371c212361e47d1463ad269ae.sock: connect: connection refused" id=99aba37c4f1521854130601f19afeb196231a924effba1cfcfb7da90b5703a86 namespace=moby
2021-09-14T15:01:19Z docker.dockerd[27385]: time="2021-09-14T20:31:19.931562562+05:30" level=error msg="connecting to shim" error="dial unix \x00/containerd-shim/58d5711ddbcc9faf6a4d8d7d0433d4254d5069c9e559d61eb1551f80d193a3eb.sock: connect: connection refused" id=a09358b02332b18dfa99b4dc99edf4b1ebac80671c29b91946875a53e1b8bd7e namespace=moby
2021-09-14T15:01:19Z docker.dockerd[27385]: time="2021-09-14T20:31:19.949511272+05:30" level=error msg="connecting to shim" error="dial unix \x00/containerd-shim/67de51fdf40350feb583255a5e703c719745ef9123a8a47dad72df075c12f953.sock: connect: connection refused" id=ee145dfe0eb44fde323a431b191a62aa47ad265c438239f7243c684e10713042 namespace=moby
2021-09-14T15:01:24Z docker.dockerd[27385]: time="2021-09-14T20:31:24.671615174+05:30" level=error msg="Force shutdown daemon"
2021-09-14T15:01:25Z systemd[1]: Stopped Service for snap application docker.dockerd.
2021-09-14T15:01:37Z systemd[1]: Started Service for snap application docker.dockerd.

[mborzecki]

Can you attach the output of snap changes docker ?

[egmanoj]

Sure. Here goes:

$ snap changes docker --abs-time
ID   Status  Spawn                      Ready                      Summary
201  Error   2021-09-16T14:12:21+05:30  2021-09-16T14:25:32+05:30  Auto-refresh snap "docker"
202  Error   2021-09-16T22:37:20+05:30  2021-09-16T22:48:29+05:30  Auto-refresh snap "docker"
203  Error   2021-09-17T08:58:06+05:30  2021-09-17T09:00:13+05:30  Auto-refresh snap "docker"

[mborzecki]

What’s the output of snap change 203 then? (you can grab it for 202 and 201 as well).

[egmanoj]

@mborzecki

snap change 203

$ snap change 203
Status  Spawn               Ready               Summary
Done    today at 08:58 IST  today at 09:00 IST  Ensure prerequisites for "docker" are available
Undone  today at 08:58 IST  today at 09:00 IST  Download snap "docker" (1125) from channel "latest/stable"
Done    today at 08:58 IST  today at 09:00 IST  Fetch and check assertions for snap "docker" (1125)
Undone  today at 08:58 IST  today at 09:00 IST  Mount snap "docker" (1125)
Undone  today at 08:58 IST  today at 09:00 IST  Run pre-refresh hook of "docker" snap if present
Undone  today at 08:58 IST  today at 09:00 IST  Stop snap "docker" services
Undone  today at 08:58 IST  today at 09:00 IST  Remove aliases for snap "docker"
Undone  today at 08:58 IST  today at 09:00 IST  Make current revision for snap "docker" unavailable
Undone  today at 08:58 IST  today at 09:00 IST  Copy snap "docker" data
Undone  today at 08:58 IST  today at 09:00 IST  Setup snap "docker" (1125) security profiles
Undone  today at 08:58 IST  today at 09:00 IST  Make snap "docker" (1125) available to the system
Undone  today at 08:58 IST  today at 09:00 IST  Automatically connect eligible plugs and slots of snap "docker"
Undone  today at 08:58 IST  today at 09:00 IST  Set automatic aliases for snap "docker"
Undone  today at 08:58 IST  today at 09:00 IST  Setup snap "docker" aliases
Error   today at 08:58 IST  today at 09:00 IST  Run post-refresh hook of "docker" snap if present
Hold    today at 08:58 IST  today at 09:00 IST  Start snap "docker" (1125) services
Hold    today at 08:58 IST  today at 09:00 IST  Remove data for snap "docker" (471)
Hold    today at 08:58 IST  today at 09:00 IST  Remove snap "docker" (471) from the system
Hold    today at 08:58 IST  today at 09:00 IST  Clean up "docker" (1125) install
Hold    today at 08:58 IST  today at 09:00 IST  Run configure hook of "docker" snap if present
Hold    today at 08:58 IST  today at 09:00 IST  Run health check of "docker" snap
Done    today at 08:58 IST  today at 09:00 IST  Consider re-refresh of "docker"

......................................................................
Run post-refresh hook of "docker" snap if present

2021-09-17T09:00:06+05:30 ERROR run hook "post-refresh": 
-----
cannot update snap namespace: cannot create symlink in "/etc/docker": existing file in the way
snap-update-ns failed with code 1
-----

$ snap change 202
Status  Spawn                   Ready                   Summary
Done    yesterday at 22:37 IST  yesterday at 22:48 IST  Ensure prerequisites for "docker" are available
Undone  yesterday at 22:37 IST  yesterday at 22:48 IST  Download snap "docker" (1125) from channel "latest/stable"
Done    yesterday at 22:37 IST  yesterday at 22:48 IST  Fetch and check assertions for snap "docker" (1125)
Undone  yesterday at 22:37 IST  yesterday at 22:48 IST  Mount snap "docker" (1125)
Undone  yesterday at 22:37 IST  yesterday at 22:48 IST  Run pre-refresh hook of "docker" snap if present
Undone  yesterday at 22:37 IST  yesterday at 22:48 IST  Stop snap "docker" services
Undone  yesterday at 22:37 IST  yesterday at 22:48 IST  Remove aliases for snap "docker"
Undone  yesterday at 22:37 IST  yesterday at 22:48 IST  Make current revision for snap "docker" unavailable
Undone  yesterday at 22:37 IST  yesterday at 22:48 IST  Copy snap "docker" data
Error   yesterday at 22:37 IST  yesterday at 22:48 IST  Setup snap "docker" (1125) security profiles
Hold    yesterday at 22:37 IST  yesterday at 22:48 IST  Make snap "docker" (1125) available to the system
Hold    yesterday at 22:37 IST  yesterday at 22:48 IST  Automatically connect eligible plugs and slots of snap "docker"
Hold    yesterday at 22:37 IST  yesterday at 22:48 IST  Set automatic aliases for snap "docker"
Hold    yesterday at 22:37 IST  yesterday at 22:48 IST  Setup snap "docker" aliases
Hold    yesterday at 22:37 IST  yesterday at 22:48 IST  Run post-refresh hook of "docker" snap if present
Hold    yesterday at 22:37 IST  yesterday at 22:48 IST  Start snap "docker" (1125) services
Hold    yesterday at 22:37 IST  yesterday at 22:48 IST  Remove data for snap "docker" (471)
Hold    yesterday at 22:37 IST  yesterday at 22:48 IST  Remove snap "docker" (471) from the system
Hold    yesterday at 22:37 IST  yesterday at 22:48 IST  Clean up "docker" (1125) install
Hold    yesterday at 22:37 IST  yesterday at 22:48 IST  Run configure hook of "docker" snap if present
Hold    yesterday at 22:37 IST  yesterday at 22:48 IST  Run health check of "docker" snap
Done    yesterday at 22:37 IST  yesterday at 22:48 IST  Consider re-refresh of "docker"

......................................................................
Setup snap "docker" (1125) security profiles

2021-09-16T22:48:20+05:30 ERROR cannot update mount namespace of snap "docker": cannot update preserved namespace of snap "docker": cannot update snap namespace: cannot create symlink in "/etc/docker": existing file in the way

$ snap change 201
Status  Spawn                   Ready                   Summary
Done    yesterday at 14:12 IST  yesterday at 14:25 IST  Ensure prerequisites for "docker" are available
Undone  yesterday at 14:12 IST  yesterday at 14:25 IST  Download snap "docker" (1125) from channel "latest/stable"
Done    yesterday at 14:12 IST  yesterday at 14:25 IST  Fetch and check assertions for snap "docker" (1125)
Undone  yesterday at 14:12 IST  yesterday at 14:25 IST  Mount snap "docker" (1125)
Undone  yesterday at 14:12 IST  yesterday at 14:25 IST  Run pre-refresh hook of "docker" snap if present
Undone  yesterday at 14:12 IST  yesterday at 14:25 IST  Stop snap "docker" services
Undone  yesterday at 14:12 IST  yesterday at 14:25 IST  Remove aliases for snap "docker"
Undone  yesterday at 14:12 IST  yesterday at 14:25 IST  Make current revision for snap "docker" unavailable
Undone  yesterday at 14:12 IST  yesterday at 14:25 IST  Copy snap "docker" data
Error   yesterday at 14:12 IST  yesterday at 14:25 IST  Setup snap "docker" (1125) security profiles
Hold    yesterday at 14:12 IST  yesterday at 14:25 IST  Make snap "docker" (1125) available to the system
Hold    yesterday at 14:12 IST  yesterday at 14:25 IST  Automatically connect eligible plugs and slots of snap "docker"
Hold    yesterday at 14:12 IST  yesterday at 14:25 IST  Set automatic aliases for snap "docker"
Hold    yesterday at 14:12 IST  yesterday at 14:25 IST  Setup snap "docker" aliases
Hold    yesterday at 14:12 IST  yesterday at 14:25 IST  Run post-refresh hook of "docker" snap if present
Hold    yesterday at 14:12 IST  yesterday at 14:25 IST  Start snap "docker" (1125) services
Hold    yesterday at 14:12 IST  yesterday at 14:25 IST  Remove data for snap "docker" (471)
Hold    yesterday at 14:12 IST  yesterday at 14:25 IST  Remove snap "docker" (471) from the system
Hold    yesterday at 14:12 IST  yesterday at 14:25 IST  Clean up "docker" (1125) install
Hold    yesterday at 14:12 IST  yesterday at 14:25 IST  Run configure hook of "docker" snap if present
Hold    yesterday at 14:12 IST  yesterday at 14:25 IST  Run health check of "docker" snap
Done    yesterday at 14:12 IST  yesterday at 14:25 IST  Consider re-refresh of "docker"

......................................................................
Setup snap "docker" (1125) security profiles

2021-09-16T14:25:21+05:30 ERROR cannot update mount namespace of snap "docker": cannot update preserved namespace of snap "docker": cannot update snap namespace: cannot create symlink in "/etc/docker": existing file in the way

[egmanoj]

$ ll /etc/docker
total 32
drwxr-xr-x   2 root root  4096 Aug 29 17:03  ./
drwxr-xr-x 155 root root 12288 Sep 17 09:01  ../
-rw-r--r--   1 root root    44 Oct 12  2020 'daemon.json.11851.2020-10-12@15:56:38~'
-rw-r--r--   1 root root    44 Oct 13  2020 'daemon.json.25463.2020-10-14@10:30:35~'
-rw-r--r--   1 root root    69 Mar 14  2020 'daemon.json.32335.2020-10-12@15:11:16~'
-rw-------   1 root root   244 Aug 29 17:03  key.json

[mborzecki]

Please see this post:

Layouts still brittle when refreshing snaps

I think this was likely caused by the following change: In particular, it changes /etc/docker from a directory bind to a symlink. If the host system has a /etc/docker directory present, then the layouts code will fail to place a symlink at the location. It might also fail if /etc/docker had been created as a directory in the mount namespace created by the previous revision of the snap, when trying to update that mount namespace. It looks like this particular change has been reverted, with th…

[egmanoj]

Thanks! It appears that the problem has been fixed and the fix made available in the edge channel. Should I just wait for the fix to make its way to stable? Are there any other alternatives?