Docker Fails to Start After Upgrade from 19.03.14 to 20.10.01 on Debian

[iandonnelly]

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

Expected behavior

After upgrading docker-ce and docker-ce-cli the docker service should be restart and be brought up successfully.

Actual behavior

Docker fails to start after upgrade

Steps to reproduce the behavior

1. Run apt upgrade to upgrade docker-ce and docker-ce-cli as available:

docker-ce-cli/buster 5:20.10.1~3-0~debian-buster amd64 [upgradable from: 5:19.03.14~3-0~debian-buster]
docker-ce/buster 5:20.10.1~3-0~debian-buster amd64 [upgradable from: 5:19.03.14~3-0~debian-buster]

2. The docker service fails to start during the upgrade preventing a successful upgrade.
   Logs:

Reading package lists... Done
Building dependency tree
Reading state information... Done
Calculating upgrade... Done
The following packages will be upgraded:
  docker-ce docker-ce-cli
2 upgraded, 0 newly installed, 0 to remove and 0 not upgraded.
Need to get 0 B/66.1 MB of archives.
After this operation, 2,372 kB disk space will be freed.
Do you want to continue? [Y/n]
Reading changelogs... Done
(Reading database ... 131538 files and directories currently installed.)
Preparing to unpack .../docker-ce-cli_5%3a20.10.1~3-0~debian-buster_amd64.deb ...
Unpacking docker-ce-cli (5:20.10.1~3-0~debian-buster) over (5:19.03.14~3-0~debian-buster) ...
Preparing to unpack .../docker-ce_5%3a20.10.1~3-0~debian-buster_amd64.deb ...
Unpacking docker-ce (5:20.10.1~3-0~debian-buster) over (5:19.03.14~3-0~debian-buster) ...
Setting up docker-ce-cli (5:20.10.1~3-0~debian-buster) ...
Setting up docker-ce (5:20.10.1~3-0~debian-buster) ...
Job for docker.service failed because the control process exited with error code.
See "systemctl status docker.service" and "journalctl -xe" for details.
invoke-rc.d: initscript docker, action "restart" failed.
● docker.service - Docker Application Container Engine
   Loaded: loaded (/lib/systemd/system/docker.service; enabled; vendor preset: enabled)
   Active: activating (auto-restart) (Result: exit-code) since Wed 2020-12-30 16:42:10 EST; 7ms ago
     Docs: https://docs.docker.com
  Process: 25827 ExecStart=/usr/bin/dockerd -H fd:// --containerd=/run/containerd/containerd.sock (code=exited, status=1/FAILURE)
 Main PID: 25827 (code=exited, status=1/FAILURE)
dpkg: error processing package docker-ce (--configure):
 installed docker-ce package post-installation script subprocess returned error exit status 1
Processing triggers for man-db (2.8.5-2) ...
Processing triggers for systemd (241-7~deb10u5) ...
Errors were encountered while processing:
 docker-ce
needrestart is being skipped since dpkg has failed
E: Sub-process /usr/bin/dpkg returned an error code (1)

Output of systemctl status docker.service:

● docker.service - Docker Application Container Engine
   Loaded: loaded (/lib/systemd/system/docker.service; enabled; vendor preset: enabled)
   Active: failed (Result: exit-code) since Wed 2020-12-30 16:42:19 EST; 3min 39s ago
     Docs: https://docs.docker.com
  Process: 26433 ExecStart=/usr/bin/dockerd -H fd:// --containerd=/run/containerd/containerd.sock (code=exited, status=1/FAILURE)
 Main PID: 26433 (code=exited, status=1/FAILURE)

Additional environment details (AWS, VirtualBox, physical, etc.)
This is running on Debian Buster (10) with all other packages up-to-date.

[thaJeztah]

Do the logs show anything useful?

sudo journalctl -xeu docker.service

[thaJeztah]

This output is a bit confusing (saw something similar in another issue that was posted); for some reason, systemd seems to be triggering the rc.d scripts as well (it should skip them if there's a systemd unit with the same name);

invoke-rc.d: initscript docker, action "restart" failed.

(https://manpages.debian.org/unstable/init-system-helpers/invoke-rc.d.8.en.html, http://manpages.ubuntu.com/manpages/bionic/man1/deb-systemd-invoke.1p.html)

[tstenel]

i'm having a similar problem, i think it is linked to cgroups,

output of sudo service docker status:

● docker.service - Docker Application Container Engine
     Loaded: loaded (/lib/systemd/system/docker.service; enabled; vendor preset: enabled)
     Active: failed (Result: exit-code) since Wed 2021-01-06 21:17:33 CET; 4s ago
TriggeredBy: ● docker.socket
       Docs: https://docs.docker.com
    Process: 10611 ExecStart=/usr/bin/dockerd -H fd:// (code=exited, status=1/FAILURE)
   Main PID: 10611 (code=exited, status=1/FAILURE)
        CPU: 57ms

Jan 06 21:17:33 OVERLORD systemd[1]: docker.service: Scheduled restart job, restart counter is at 3.
Jan 06 21:17:33 OVERLORD systemd[1]: Stopped Docker Application Container Engine.
Jan 06 21:17:33 OVERLORD systemd[1]: docker.service: Start request repeated too quickly.
Jan 06 21:17:33 OVERLORD systemd[1]: docker.service: Failed with result 'exit-code'.
Jan 06 21:17:33 OVERLORD systemd[1]: Failed to start Docker Application Container Engine.

output of sudo journalctl -xeu docker.service:

░░ A start job for unit docker.service has finished with a failure.
░░ 
░░ The job identifier is 5036 and the job result is failed.
Jan 06 21:17:33 OVERLORD systemd[1]: docker.service: Scheduled restart job, restart counter is at 3.
░░ Subject: Automatic restarting of a unit has been scheduled
░░ Defined-By: systemd
░░ Support: https://www.debian.org/support
░░ 
░░ Automatic restarting of the unit docker.service has been scheduled, as the result for
░░ the configured Restart= setting for the unit.
Jan 06 21:17:33 OVERLORD systemd[1]: Stopped Docker Application Container Engine.
░░ Subject: A stop job for unit docker.service has finished
░░ Defined-By: systemd
░░ Support: https://www.debian.org/support
░░ 
░░ A stop job for unit docker.service has finished.
░░ 
░░ The job identifier is 5163 and the job result is done.
Jan 06 21:17:33 OVERLORD systemd[1]: docker.service: Start request repeated too quickly.
Jan 06 21:17:33 OVERLORD systemd[1]: docker.service: Failed with result 'exit-code'.
░░ Subject: Unit failed
░░ Defined-By: systemd
░░ Support: https://www.debian.org/support
░░ 
░░ The unit docker.service has entered the 'failed' state with result 'exit-code'.
Jan 06 21:17:33 OVERLORD systemd[1]: Failed to start Docker Application Container Engine.
░░ Subject: A start job for unit docker.service has failed
░░ Defined-By: systemd
░░ Support: https://www.debian.org/support
░░ 
░░ A start job for unit docker.service has finished with a failure.
░░ 
░░ The job identifier is 5163 and the job result is failed.

if i try to launch dockerd manualy : sudo dockerd

INFO[2021-01-06T21:19:36.280867882+01:00] libcontainerd: started new docker-containerd process  pid=10694
INFO[2021-01-06T21:19:36.280925118+01:00] parsed scheme: "unix"                         module=grpc
INFO[2021-01-06T21:19:36.280932039+01:00] scheme "unix" not registered, fallback to default scheme  module=grpc
INFO[2021-01-06T21:19:36.280968367+01:00] ccResolverWrapper: sending new addresses to cc: [{unix:///var/run/docker/containerd/docker-containerd.sock 0  <nil>}]  module=grpc
INFO[2021-01-06T21:19:36.280975690+01:00] ClientConn switching balancer to "pick_first"  module=grpc
INFO[2021-01-06T21:19:36.280998770+01:00] pickfirstBalancer: HandleSubConnStateChange: 0xc420183d50, CONNECTING  module=grpc
INFO[0000] starting containerd                           revision=468a545b9edcd5932818eb9de8e72413e616e86e version=v1.1.2
INFO[0000] loading plugin "io.containerd.content.v1.content"...  type=io.containerd.content.v1
INFO[0000] loading plugin "io.containerd.snapshotter.v1.btrfs"...  type=io.containerd.snapshotter.v1
WARN[0000] failed to load plugin io.containerd.snapshotter.v1.btrfs  error="path /var/lib/docker/containerd/daemon/io.containerd.snapshotter.v1.btrfs must be a btrfs filesystem to be used with the btrfs snapshotter"
INFO[0000] loading plugin "io.containerd.snapshotter.v1.aufs"...  type=io.containerd.snapshotter.v1
WARN[0000] failed to load plugin io.containerd.snapshotter.v1.aufs  error="modprobe aufs failed: "modprobe: FATAL: Module aufs not found in directory /lib/modules/5.10.0-1-amd64\n": exit status 1"
INFO[0000] loading plugin "io.containerd.snapshotter.v1.native"...  type=io.containerd.snapshotter.v1
INFO[0000] loading plugin "io.containerd.snapshotter.v1.overlayfs"...  type=io.containerd.snapshotter.v1
INFO[0000] loading plugin "io.containerd.snapshotter.v1.zfs"...  type=io.containerd.snapshotter.v1
WARN[0000] failed to load plugin io.containerd.snapshotter.v1.zfs  error="path /var/lib/docker/containerd/daemon/io.containerd.snapshotter.v1.zfs must be a zfs filesystem to be used with the zfs snapshotter"
INFO[0000] loading plugin "io.containerd.metadata.v1.bolt"...  type=io.containerd.metadata.v1
WARN[0000] could not use snapshotter aufs in metadata plugin  error="modprobe aufs failed: "modprobe: FATAL: Module aufs not found in directory /lib/modules/5.10.0-1-amd64\n": exit status 1"
WARN[0000] could not use snapshotter zfs in metadata plugin  error="path /var/lib/docker/containerd/daemon/io.containerd.snapshotter.v1.zfs must be a zfs filesystem to be used with the zfs snapshotter"
WARN[0000] could not use snapshotter btrfs in metadata plugin  error="path /var/lib/docker/containerd/daemon/io.containerd.snapshotter.v1.btrfs must be a btrfs filesystem to be used with the btrfs snapshotter"
INFO[0000] loading plugin "io.containerd.differ.v1.walking"...  type=io.containerd.differ.v1
INFO[0000] loading plugin "io.containerd.gc.v1.scheduler"...  type=io.containerd.gc.v1
INFO[0000] loading plugin "io.containerd.service.v1.containers-service"...  type=io.containerd.service.v1
INFO[0000] loading plugin "io.containerd.service.v1.content-service"...  type=io.containerd.service.v1
INFO[0000] loading plugin "io.containerd.service.v1.diff-service"...  type=io.containerd.service.v1
INFO[0000] loading plugin "io.containerd.service.v1.images-service"...  type=io.containerd.service.v1
INFO[0000] loading plugin "io.containerd.service.v1.leases-service"...  type=io.containerd.service.v1
INFO[0000] loading plugin "io.containerd.service.v1.namespaces-service"...  type=io.containerd.service.v1
INFO[0000] loading plugin "io.containerd.service.v1.snapshots-service"...  type=io.containerd.service.v1
INFO[0000] loading plugin "io.containerd.monitor.v1.cgroups"...  type=io.containerd.monitor.v1
INFO[0000] loading plugin "io.containerd.runtime.v1.linux"...  type=io.containerd.runtime.v1
INFO[0000] loading plugin "io.containerd.service.v1.tasks-service"...  type=io.containerd.service.v1
INFO[0000] loading plugin "io.containerd.grpc.v1.containers"...  type=io.containerd.grpc.v1
INFO[0000] loading plugin "io.containerd.grpc.v1.content"...  type=io.containerd.grpc.v1
INFO[0000] loading plugin "io.containerd.grpc.v1.diff"...  type=io.containerd.grpc.v1
INFO[0000] loading plugin "io.containerd.grpc.v1.events"...  type=io.containerd.grpc.v1
INFO[0000] loading plugin "io.containerd.grpc.v1.healthcheck"...  type=io.containerd.grpc.v1
INFO[0000] loading plugin "io.containerd.grpc.v1.images"...  type=io.containerd.grpc.v1
INFO[0000] loading plugin "io.containerd.grpc.v1.leases"...  type=io.containerd.grpc.v1
INFO[0000] loading plugin "io.containerd.grpc.v1.namespaces"...  type=io.containerd.grpc.v1
INFO[0000] loading plugin "io.containerd.grpc.v1.snapshots"...  type=io.containerd.grpc.v1
INFO[0000] loading plugin "io.containerd.grpc.v1.tasks"...  type=io.containerd.grpc.v1
INFO[0000] loading plugin "io.containerd.grpc.v1.version"...  type=io.containerd.grpc.v1
INFO[0000] loading plugin "io.containerd.grpc.v1.introspection"...  type=io.containerd.grpc.v1
INFO[0000] serving...                                    address="/var/run/docker/containerd/docker-containerd-debug.sock"
INFO[0000] serving...                                    address="/var/run/docker/containerd/docker-containerd.sock"
INFO[0000] containerd successfully booted in 0.003931s  
INFO[2021-01-06T21:19:36.301406714+01:00] pickfirstBalancer: HandleSubConnStateChange: 0xc420183d50, READY  module=grpc
INFO[2021-01-06T21:19:36.302439760+01:00] parsed scheme: "unix"                         module=grpc
INFO[2021-01-06T21:19:36.302461460+01:00] scheme "unix" not registered, fallback to default scheme  module=grpc
INFO[2021-01-06T21:19:36.302488200+01:00] ccResolverWrapper: sending new addresses to cc: [{unix:///var/run/docker/containerd/docker-containerd.sock 0  <nil>}]  module=grpc
INFO[2021-01-06T21:19:36.302496874+01:00] ClientConn switching balancer to "pick_first"  module=grpc
INFO[2021-01-06T21:19:36.302526324+01:00] pickfirstBalancer: HandleSubConnStateChange: 0xc42003a6f0, CONNECTING  module=grpc
INFO[2021-01-06T21:19:36.302618090+01:00] pickfirstBalancer: HandleSubConnStateChange: 0xc42003a6f0, READY  module=grpc
INFO[2021-01-06T21:19:36.304074383+01:00] [graphdriver] using prior storage driver: overlay2 
INFO[2021-01-06T21:19:36.316594218+01:00] Graph migration to content-addressability took 0.00 seconds 
WARN[2021-01-06T21:19:36.316762872+01:00] Your kernel does not support cgroup memory limit 
WARN[2021-01-06T21:19:36.316778960+01:00] Unable to find cpu cgroup in mounts          
WARN[2021-01-06T21:19:36.316787363+01:00] Unable to find blkio cgroup in mounts        
WARN[2021-01-06T21:19:36.316796460+01:00] Unable to find cpuset cgroup in mounts       
WARN[2021-01-06T21:19:36.316838934+01:00] mountpoint for pids not found                
Error starting daemon: Devices cgroup isn't mounted

I found there is an open issue about this:

docker/cli#2104

I fixed it using the fix described in this issue:

adding the systemd.unified_cgroup_hierarchy=0 kernel parameters

to do so, i edited the file /etc/default/grub

and added this line (check if it doesn't exist before adding the full line, only add the parameter if it exists)

GRUB_CMDLINE_LINUX="systemd.unified_cgroup_hierarchy=0"

then run update-grub

after a reboot, the docker daemon worked again

i'm thinking this was caused by an update in cgroup at one point during last week

[thaJeztah]

INFO[2021-01-06T21:19:36.280998770+01:00] pickfirstBalancer: HandleSubConnStateChange: 0xc420183d50, CONNECTING  module=grpc
INFO[0000] starting containerd                           revision=468a545b9edcd5932818eb9de8e72413e616e86e version=v1.1.2

What version of docker do you have installed? Did you install from the official packages from download.docker.com ?

Looks like a very old version of containerd is installed (v1.1.2)

Current version of docker (20.10) and containerd (v1.4.x) should now support cgroupsv2, so there should no longer be a need to switch to cgroups v1

[tstenel]

docker --version output:

Docker version 18.06.3-ce, build d7080c1

containerd --version output:

containerd containerd.io 1.2.6 894b81a4b802e4eb2a91d1ce216b8817763c29fb

this is on a debian install on my personal computer, I installed it about 5 years ago and kept it updated with apt
I'm on debian testing (bullseyes), and the docker install was done using
sudo apt install docker-ce

I never had any problems before this, and I've been using docker on this machine for over 3 years

[iandonnelly]

Sorry for the delay but I just retried and it seems it's a firewall related issue. Here is the relevant log:

Jan 07 16:03:01 ian-server systemd[1]: Starting Docker Application Container Engine...
-- Subject: A start job for unit docker.service has begun execution
-- Defined-By: systemd
-- Support: https://www.debian.org/support
--
-- A start job for unit docker.service has begun execution.
--
-- The job identifier is 29533.
Jan 07 16:03:01 ian-server dockerd[4340]: time="2021-01-07T16:03:01.232734878-05:00" level=info msg="Starting up"
Jan 07 16:03:01 ian-server dockerd[4340]: time="2021-01-07T16:03:01.233716347-05:00" level=info msg="parsed scheme: \"unix\"" module=grpc
Jan 07 16:03:01 ian-server dockerd[4340]: time="2021-01-07T16:03:01.233735779-05:00" level=info msg="scheme \"unix\" not registered, fallback to default scheme" module=grpc
Jan 07 16:03:01 ian-server dockerd[4340]: time="2021-01-07T16:03:01.233755589-05:00" level=info msg="ccResolverWrapper: sending update to cc: {[{unix:///run/containerd/containerd.sock  <nil> 0 <nil>}] <nil> <nil>}" module=grpc
Jan 07 16:03:01 ian-server dockerd[4340]: time="2021-01-07T16:03:01.233767488-05:00" level=info msg="ClientConn switching balancer to \"pick_first\"" module=grpc
Jan 07 16:03:01 ian-server dockerd[4340]: time="2021-01-07T16:03:01.238543527-05:00" level=info msg="parsed scheme: \"unix\"" module=grpc
Jan 07 16:03:01 ian-server dockerd[4340]: time="2021-01-07T16:03:01.238558755-05:00" level=info msg="scheme \"unix\" not registered, fallback to default scheme" module=grpc
Jan 07 16:03:01 ian-server dockerd[4340]: time="2021-01-07T16:03:01.238577244-05:00" level=info msg="ccResolverWrapper: sending update to cc: {[{unix:///run/containerd/containerd.sock  <nil> 0 <nil>}] <nil> <nil>}" module=grpc
Jan 07 16:03:01 ian-server dockerd[4340]: time="2021-01-07T16:03:01.238603760-05:00" level=info msg="ClientConn switching balancer to \"pick_first\"" module=grpc
Jan 07 16:03:01 ian-server dockerd[4340]: time="2021-01-07T16:03:01.278938905-05:00" level=info msg="[graphdriver] using prior storage driver: overlay2"
Jan 07 16:03:01 ian-server dockerd[4340]: time="2021-01-07T16:03:01.293847039-05:00" level=warning msg="Your kernel does not support swap memory limit"
Jan 07 16:03:01 ian-server dockerd[4340]: time="2021-01-07T16:03:01.293871881-05:00" level=warning msg="Your kernel does not support CPU realtime scheduler"
Jan 07 16:03:01 ian-server dockerd[4340]: time="2021-01-07T16:03:01.294022937-05:00" level=info msg="Loading containers: start."
Jan 07 16:03:01 ian-server dockerd[4340]: time="2021-01-07T16:03:01.360210953-05:00" level=info msg="Firewalld: docker zone already exists, returning"
Jan 07 16:03:01 ian-server dockerd[4340]: time="2021-01-07T16:03:01.471714666-05:00" level=warning msg="could not create bridge network for id eb159bfd58e3a670da1caacd1ae6ea199527198e548c2ca7b47d75109def7d8b bridge name docker0 while bo
Jan 07 16:03:01 ian-server dockerd[4340]: time="2021-01-07T16:03:01.472690328-05:00" 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"
Jan 07 16:03:01 ian-server dockerd[4340]: time="2021-01-07T16:03:01.493726589-05:00" level=info msg="stopping event stream following graceful shutdown" error="<nil>" module=libcontainerd namespace=moby
Jan 07 16:03:01 ian-server dockerd[4340]: failed to start daemon: Error initializing network controller: Error creating default "bridge" network: Failed to program NAT chain: ZONE_CONFLICT: 'docker0' already bound to a zone
Jan 07 16:03:01 ian-server systemd[1]: docker.service: Main process exited, code=exited, status=1/FAILURE
-- Subject: Unit process exited
-- Defined-By: systemd
-- Support: https://www.debian.org/support
--
-- An ExecStart= process belonging to unit docker.service has exited.
--
-- The process' exit code is 'exited' and its exit status is 1.
Jan 07 16:03:01 ian-server systemd[1]: docker.service: Failed with result 'exit-code'.
-- Subject: Unit failed
-- Defined-By: systemd
-- Support: https://www.debian.org/support
--
-- The unit docker.service has entered the 'failed' state with result 'exit-code'.

[iandonnelly]

Did a little more digging and it seems it was the same issue as moby/moby#41609
I am using firewalld on the system so it makes sense. Feel free to close this, I think @tstenel should open a separate issue to avoid confusion.

[thaJeztah]

docker --version output:

Docker version 18.06.3-ce, build d7080c1

That's a really old version of docker, that reached EOL two years ago

this is on a debian install on my personal computer, I installed it about 5 years ago and kept it updated with apt
I'm on debian testing (bullseyes), and the docker install was done using
sudo apt install docker-ce

@tstenel If it's from 5 years ago, and you upgraded your distro version, did you also update the package repositories to point to the new distro? I suspect your apt distro configuration might still be pointing to the jessie or buster Debian distro packages. Some details can be found in docker/docs#10285 (which is for Ubuntu, but similarly)

[tstenel]

you're making a good point, i haven't updated my source.list for a while, this must be the reason

don't keep this issue open over me, my problem in the end was not related to this issue, and I was able to fix with the steps i described in my previous comments

[edit]

you were right, my sources.list file pointed to the jessie repositories for docker, i updated it to point to the buster one and it works without using the workaround from my previous comments

[thaJeztah]

Good to hear! Thanks for the "reminder" that I need to find some time again to update those instructions for the docs. Haven't found the time yet 😓)

Let me also try to review docker/docs#11944, which provides instructions for the changes needed for the original report 😅

Let me close this ticket, but feel free to continue the conversation after I closed 👍