Docker fails to startup after data corruption due to UCS upgrade

Apps & App Center
#1

Hi All –

I recently ran updates on two UCS instances from 4.4.7 to 4.4.8. One is a host running a number of apps (Domain Controller, Mail Server, Nextcloud, Bluespice, Letsencrypt, SuiteCRM, CODE), and the second is a host which only runs Domain Controller, Zammad, Letsencrypt, and Wordpress.

It seems that during the upgrade of the busier host, docker shutdown timed out, and some of the containers were terminated. This corrupted something, which stops docker from starting up. Nextcloud, SuiteCRM, and Bluespice on this host are going to be a PITA to re-install from scratch.

I have managed to get docker to run by pivoting /var/lib/docker and letting it regenerate the directory as the daemon comes up. However, I would very much like to recover some of these containers if possible, rather than dump DB files and try to rebuild them that way.

Any ideas? Is there a cache file I can remove, or something (I don’t really know docker well – although I have 20 years of sysadmin experience)? The docker error is here (I can’t add it to this message due to forum restrictions): https://pastebin.com/gzJcvwbP

Kind regards,

travis

#2

Docker error from logs:

Jun 30 23:35:17 $hostname systemd[1]: Starting Docker Application Container Engine...
Jun 30 23:35:22 $hostname dockerd[1346]: time="2021-06-30T23:35:22.154106163+01:00" level=info msg="parsed scheme: \"unix\"" module=grpc
Jun 30 23:35:22 $hostname dockerd[1346]: time="2021-06-30T23:35:22.154347134+01:00" level=info msg="scheme \"unix\" not registered, fallback to default scheme" module=grpc
Jun 30 23:35:22 $hostname dockerd[1346]: time="2021-06-30T23:35:22.155609539+01:00" level=info msg="parsed scheme: \"unix\"" module=grpc
Jun 30 23:35:22 $hostname dockerd[1346]: time="2021-06-30T23:35:22.155631907+01:00" level=info msg="scheme \"unix\" not registered, fallback to default scheme" module=grpc
Jun 30 23:35:22 $hostname dockerd[1346]: time="2021-06-30T23:35:22.155832317+01:00" level=info msg="ccResolverWrapper: sending new addresses to cc: [{unix:///run/containerd/containerd.sock 0  <nil>}]" module=grpc
Jun 30 23:35:22 $hostname dockerd[1346]: time="2021-06-30T23:35:22.155854880+01:00" level=info msg="ccResolverWrapper: sending new addresses to cc: [{unix:///run/containerd/containerd.sock 0  <nil>}]" module=grpc
Jun 30 23:35:22 $hostname dockerd[1346]: time="2021-06-30T23:35:22.155919488+01:00" level=info msg="ClientConn switching balancer to \"pick_first\"" module=grpc
Jun 30 23:35:22 $hostname dockerd[1346]: time="2021-06-30T23:35:22.156258639+01:00" level=info msg="pickfirstBalancer: HandleSubConnStateChange: 0xc4201b2810, CONNECTING" module=grpc
Jun 30 23:35:22 $hostname dockerd[1346]: time="2021-06-30T23:35:22.155890587+01:00" level=info msg="ClientConn switching balancer to \"pick_first\"" module=grpc
Jun 30 23:35:22 $hostname dockerd[1346]: time="2021-06-30T23:35:22.156868471+01:00" level=info msg="pickfirstBalancer: HandleSubConnStateChange: 0xc420a04070, CONNECTING" module=grpc
Jun 30 23:35:22 $hostname dockerd[1346]: time="2021-06-30T23:35:22.169111223+01:00" level=info msg="pickfirstBalancer: HandleSubConnStateChange: 0xc420a04070, READY" module=grpc
Jun 30 23:35:22 $hostname dockerd[1346]: time="2021-06-30T23:35:22.169277579+01:00" level=info msg="pickfirstBalancer: HandleSubConnStateChange: 0xc4201b2810, READY" module=grpc
Jun 30 23:35:23 $hostname dockerd[1346]: time="2021-06-30T23:35:23.967533614+01:00" level=info msg="[graphdriver] using prior storage driver: overlay2"
Jun 30 23:35:27 $hostname dockerd[1346]: panic: invalid freelist page: 0, page type is unknown<00>
Jun 30 23:35:27 $hostname dockerd[1346]: goroutine 1 [running]:
Jun 30 23:35:27 $hostname dockerd[1346]: 'github.com/docker/docker/vendor/go.etcd.io/bbolt.(*freelist).read(0xc420a19980, 0x7f13e001b000)
Jun 30 23:35:27 $hostname dockerd[1346]:         /var/build/temp/tmp.exBUe9zdYr/pbuilder/docker.io-18.09.7/.gopath/src/github.com/docker/docker/vendor/go.etcd.io/bbolt/freelist.go:237 +0x2ff
Jun 30 23:35:27 $hostname dockerd[1346]: 'github.com/docker/docker/vendor/go.etcd.io/bbolt.(*DB).loadFreelist.func1()
Jun 30 23:35:27 $hostname dockerd[1346]:         /var/build/temp/tmp.exBUe9zdYr/pbuilder/docker.io-18.09.7/.gopath/src/github.com/docker/docker/vendor/go.etcd.io/bbolt/db.go:292 +0x12d
Jun 30 23:35:27 $hostname dockerd[1346]: sync.(*Once).Do(0xc420b94aa8, 0xc4206b0d50)
Jun 30 23:35:27 $hostname dockerd[1346]:         /usr/lib/go-1.10/src/sync/once.go:44 +0xc0
Jun 30 23:35:27 $hostname dockerd[1346]: 'github.com/docker/docker/vendor/go.etcd.io/bbolt.(*DB).loadFreelist(0xc420b94960)
Jun 30 23:35:27 $hostname dockerd[1346]:         /var/build/temp/tmp.exBUe9zdYr/pbuilder/docker.io-18.09.7/.gopath/src/github.com/docker/docker/vendor/go.etcd.io/bbolt/db.go:285 +0x50
Jun 30 23:35:27 $hostname dockerd[1346]: 'github.com/docker/docker/vendor/go.etcd.io/bbolt.Open(0xc420744ba0, 0x23, 0x180, 0xc4206b0e70, 0x23, 0xc4201770c0, 0xc420a19510)
Jun 30 23:35:27 $hostname dockerd[1346]:         /var/build/temp/tmp.exBUe9zdYr/pbuilder/docker.io-18.09.7/.gopath/src/github.com/docker/docker/vendor/go.etcd.io/bbolt/db.go:262 +0x316
Jun 30 23:35:27 $hostname dockerd[1346]: 'github.com/docker/docker/volume/service.NewStore(0xc4206cf650, 0xf, 0xc420a19560, 0x0, 0x0, 0x0)
Jun 30 23:35:27 $hostname dockerd[1346]:         /var/build/temp/tmp.exBUe9zdYr/pbuilder/docker.io-18.09.7/.gopath/src/github.com/docker/docker/volume/service/store.go:91 +0x286
Jun 30 23:35:27 $hostname dockerd[1346]: 'github.com/docker/docker/volume/service.NewVolumeService(0xc4206cf650, 0xf, 0x558b3d0db660, 0xc4208dc300, 0x0, 0x0, 0x0, 0x0, 0x558b3d0b6660, 0xc4209141e0, ...)
Jun 30 23:35:27 $hostname dockerd[1346]:         /var/build/temp/tmp.exBUe9zdYr/pbuilder/docker.io-18.09.7/.gopath/src/github.com/docker/docker/volume/service/service.go:44 +0x16d
Jun 30 23:35:27 $hostname dockerd[1346]: 'github.com/docker/docker/daemon.NewDaemon(0x558b3d0db0e0, 0xc420648400, 0xc4208fc000, 0xc4208dc300, 0x0, 0x0, 0x0)
Jun 30 23:35:27 $hostname dockerd[1346]:         /var/build/temp/tmp.exBUe9zdYr/pbuilder/docker.io-18.09.7/.gopath/src/github.com/docker/docker/daemon/daemon.go:891 +0x1d99
Jun 30 23:35:27 $hostname dockerd[1346]: main.(*DaemonCli).start(0xc420646900, 0xc420747800, 0x0, 0x0)
Jun 30 23:35:27 $hostname dockerd[1346]:         /var/build/temp/tmp.exBUe9zdYr/pbuilder/docker.io-18.09.7/.gopath/src/github.com/docker/docker/cmd/dockerd/daemon.go:180 +0x74f
Jun 30 23:35:27 $hostname dockerd[1346]: main.runDaemon(0xc420747800, 0xc4208e8100, 0x0)
Jun 30 23:35:27 $hostname dockerd[1346]:         /var/build/temp/tmp.exBUe9zdYr/pbuilder/docker.io-18.09.7/.gopath/src/github.com/docker/docker/cmd/dockerd/docker_unix.go:7 +0x47
Jun 30 23:35:27 $hostname dockerd[1346]: main.newDaemonCommand.func1(0xc420807680, 0xc4206468a0, 0x0, 0x3, 0x0, 0x0)
Jun 30 23:35:27 $hostname dockerd[1346]:         /var/build/temp/tmp.exBUe9zdYr/pbuilder/docker.io-18.09.7/.gopath/src/github.com/docker/docker/cmd/dockerd/docker.go:29 +0x5d
Jun 30 23:35:27 $hostname dockerd[1346]: 'github.com/docker/docker/vendor/github.com/spf13/cobra.(*Command).execute(0xc420807680, 0xc42003a0d0, 0x3, 0x3, 0xc420807680, 0xc42003a0d0)
Jun 30 23:35:27 $hostname dockerd[1346]:         /var/build/temp/tmp.exBUe9zdYr/pbuilder/docker.io-18.09.7/.gopath/src/github.com/docker/docker/vendor/github.com/spf13/cobra/command.go:762 +0x46a
Jun 30 23:35:27 $hostname dockerd[1346]: 'github.com/docker/docker/vendor/github.com/spf13/cobra.(*Command).ExecuteC(0xc420807680, 0x558b3d0b0570, 0x558b3cc70680, 0x558b3d0b0580)
Jun 30 23:35:27 $hostname dockerd[1346]:         /var/build/temp/tmp.exBUe9zdYr/pbuilder/docker.io-18.09.7/.gopath/src/github.com/docker/docker/vendor/github.com/spf13/cobra/command.go:852 +0x30c
Jun 30 23:35:27 $hostname dockerd[1346]: 'github.com/docker/docker/vendor/github.com/spf13/cobra.(*Command).Execute(0xc420807680, 0xc42000e020, 0x558b3af1fa0f)
Jun 30 23:35:27 $hostname dockerd[1346]:         /var/build/temp/tmp.exBUe9zdYr/pbuilder/docker.io-18.09.7/.gopath/src/github.com/docker/docker/vendor/github.com/spf13/cobra/command.go:800 +0x2d
Jun 30 23:35:27 $hostname dockerd[1346]: main.main()
Jun 30 23:35:27 $hostname dockerd[1346]:         /var/build/temp/tmp.exBUe9zdYr/pbuilder/docker.io-18.09.7/.gopath/src/github.com/docker/docker/cmd/dockerd/docker.go:70 +0xa2
Jun 30 23:35:27 $hostname systemd[1]: docker.service: Main process exited, code=exited, status=2/INVALIDARGUMENT
Jun 30 23:35:27 $hostname systemd[1]: Failed to start Docker Application Container Engine.
Jun 30 23:35:27 $hostname systemd[1]: docker.service: Unit entered failed state.
Jun 30 23:35:27 $hostname systemd[1]: docker.service: Failed with result 'exit-code'.
Mastodon