Docker daemon crashes (again) with "fatal error: concurrent map read and map write" #39643
Description
BUG REPORT INFORMATION
Description
Docker process crashes randomly with a possible concurrency / race issue similar to one observed, and corrected a year ago.
Steps to reproduce the issue:
- Install Docker CE 19.3.0
- Configure overlayfs2 as storage driver
- Enable project quotas on an XFS filesystem
- Set Docker daemon level quota for the maximum size of the container's disk
- Create containers, delete containers, observe the system for a time
Describe the results you received:
Docker daemon crashed with error:
-- Logs begin at Tue 2019-07-30 03:12:23 CEST, end at Wed 2019-07-31 15:37:29 CEST. --
Jul 31 13:06:57 controller-1 dockerd[258948]: fatal error: concurrent map read and map write
Jul 31 13:06:57 controller-1 dockerd[258948]: goroutine 1371198 [running]:
Jul 31 13:06:57 controller-1 dockerd[258948]: runtime.throw(0x55f62389c0dc, 0x21)
Jul 31 13:06:57 controller-1 dockerd[258948]: /usr/local/go/src/runtime/panic.go:617 +0x74 fp=0xc000db2d08 sp=0xc000db2cd8 pc=0x55f621f6c1b4
Jul 31 13:06:57 controller-1 dockerd[258948]: runtime.mapaccess2_faststr(0x55f62451a880, 0xc0008a0ff0, 0xc000b01680, 0x59, 0x0, 0x0)
Jul 31 13:06:57 controller-1 dockerd[258948]: /usr/local/go/src/runtime/map_faststr.go:116 +0x4ab fp=0xc000db2d78 sp=0xc000db2d08 pc=0x55f621f512fb
Jul 31 13:06:57 controller-1 dockerd[258948]: github.com/docker/docker/daemon/graphdriver/quota.(*Control).SetQuota(0xc0005e3640, 0xc000b01680, 0x59, 0x80000000, 0x0, 0x0)
Jul 31 13:06:57 controller-1 dockerd[258948]: /root/rpmbuild/BUILD/src/engine/.gopath/src/github.com/docker/docker/daemon/graphdriver/quota/projectquota.go:170 +0x6c fp=0xc000db2e08 sp=0xc000db2d78 pc=0x55f623388e6c
Jul 31 13:06:57 controller-1 dockerd[258948]: github.com/docker/docker/daemon/graphdriver/overlay2.(*Driver).create(0xc0005e8f00, 0xc0009159c0, 0x40, 0xc001605810, 0x45, 0xc001037fa0, 0x0, 0x0)
Jul 31 13:06:57 controller-1
946C
dockerd[258948]: /root/rpmbuild/BUILD/src/engine/.gopath/src/github.com/docker/docker/daemon/graphdriver/overlay2/overlay.go:420 +0x96f fp=0xc000db3078 sp=0xc000db2e08 pc=0x55f623390cbf
Jul 31 13:06:57 controller-1 dockerd[258948]: github.com/docker/docker/daemon/graphdriver/overlay2.(*Driver).CreateReadWrite(0xc0005e8f00, 0xc0009159c0, 0x40, 0xc001605810, 0x45, 0xc001037fa0, 0x0, 0xc000dd6170)
Jul 31 13:06:57 controller-1 dockerd[258948]: /root/rpmbuild/BUILD/src/engine/.gopath/src/github.com/docker/docker/daemon/graphdriver/overlay2/overlay.go:375 +0xf1 fp=0xc000db3100 sp=0xc000db3078 pc=0x55f62338ffb1
Jul 31 13:06:57 controller-1 dockerd[258948]: github.com/docker/docker/layer.(*layerStore).CreateRWLayer(0xc0006dc4e0, 0xc000915280, 0x40, 0xc0016057c0, 0x47, 0xc000ed1be0, 0x0, 0x0, 0x0, 0x0)
Jul 31 13:06:57 controller-1 dockerd[258948]: /root/rpmbuild/BUILD/src/engine/.gopath/src/github.com/docker/docker/layer/layer_store.go:550 +0x30d fp=0xc000db31d8 sp=0xc000db3100 pc=0x55f622b5113d
Jul 31 13:06:57 controller-1 dockerd[258948]: github.com/docker/docker/daemon/images.(*ImageService).CreateLayer(0xc0004e0cf0, 0xc001999d40, 0xc000dd6170, 0x0, 0x0, 0xc000faf180, 0xc000dbb680)
Jul 31 13:06:57 controller-1 dockerd[258948]: /root/rpmbuild/BUILD/src/engine/.gopath/src/github.com/docker/docker/daemon/images/service.go:133 +0x143 fp=0xc000db3250 sp=0xc000db31d8 pc=0x55f622c78793
Jul 31 13:06:57 controller-1 dockerd[258948]: github.com/docker/docker/daemon.(*Daemon).create(0xc00000c780, 0xc0008b0c1d, 0x59, 0xc000faf180, 0xc000dbb680, 0x0, 0x0, 0x0, 0x0, 0x0, ...)
Jul 31 13:06:57 controller-1 dockerd[258948]: /root/rpmbuild/BUILD/src/engine/.gopath/src/github.com/docker/docker/daemon/create.go:191 +0x2c4 fp=0xc000db3320 sp=0xc000db3250 pc=0x55f62361f5b4
Jul 31 13:06:57 controller-1 dockerd[258948]: github.com/docker/docker/daemon.(*Daemon).containerCreate(0xc00000c780, 0xc0008b0c1d, 0x59, 0xc000faf180, 0xc000dbb680, 0x0, 0x0, 0x0, 0x0, 0x0, ...)
Jul 31 13:06:57 controller-1 dockerd[258948]: /root/rpmbuild/BUILD/src/engine/.gopath/src/github.com/docker/docker/daemon/create.go:93 +0x1c9 fp=0xc000db33f0 sp=0xc000db3320 pc=0x55f62361edf9
Jul 31 13:06:57 controller-1 dockerd[258948]: github.com/docker/docker/daemon.(*Daemon).ContainerCreate(0xc00000c780, 0xc0008b0c1d, 0x59, 0xc000faf180, 0xc000dbb680, 0x0, 0x0, 0x0, 0x0, 0x0, ...)
Jul 31 13:06:57 controller-1 dockerd[258948]: /root/rpmbuild/BUILD/src/engine/.gopath/src/github.com/docker/docker/daemon/create.go:40 +0xf3 fp=0xc000db34d8 sp=0xc000db33f0 pc=0x55f62361ea23
Jul 31 13:06:57 controller-1 dockerd[258948]: github.com/docker/docker/api/server/router/container.(*containerRouter).postContainersCreate(0xc00079b540, 0x55f6249678a0, 0xc00144a630, 0x55f624956ca0, 0xc001ee9500, 0xc001d0b700, 0xc00144a570, 0xc0000a2001, 0xc001740dc0)
Jul 31 13:06:57 controller-1 dockerd[258948]: /root/rpmbuild/BUILD/src/engine/.gopath/src/github.com/docker/docker/api/server/router/container/container_routes.go:502 +0x3e2 fp=0xc000db36e8 sp=0xc000db34d8 pc=0x55f6231f6212
Jul 31 13:06:57 controller-1 dockerd[258948]: github.com/docker/docker/api/server/router/container.(*containerRouter).postContainersCreate-fm(0x55f6249678a0, 0xc00144a630, 0x55f624956ca0, 0xc001ee9500, 0xc001d0b700, 0xc00144a570, 0x55f624741e00, 0x1)
Jul 31 13:06:57 controller-1 dockerd[258948]: /root/rpmbuild/BUILD/src/engine/.gopath/src/github.com/docker/docker/api/server/router/container/container_routes.go:453 +0x6b fp=0xc000db3740 sp=0xc000db36e8 pc=0x55f6231fb43b
Jul 31 13:06:57 controller-1 dockerd[258948]: github.com/docker/docker/api/server/middleware.ExperimentalMiddleware.WrapHandler.func1(0x55f6249678a0, 0xc00144a630, 0x55f624956ca0, 0xc001ee9500, 0xc001d0b700, 0xc00144a570, 0x55f6249678a0, 0xc00144a630)
Jul 31 13:06:57 controller-1 dockerd[258948]: /root/rpmbuild/BUILD/src/engine/.gopath/src/github.com/docker/docker/api/server/middleware/experimental.go:26 +0x17b fp=0xc000db37c8 sp=0xc000db3740 pc=0x55f622ab51bb
Jul 31 13:06:57 controller-1 dockerd[258948]: github.com/docker/docker/api/server/middleware.VersionMiddleware.WrapHandler.func1(0x55f6249678a0, 0xc00144a600, 0x55f624956ca0, 0xc001ee9500, 0xc001d0b700, 0xc00144a570, 0x203000, 0x203000)
Jul 31 13:06:57 controller-1 dockerd[258948]: /root/rpmbuild/BUILD/src/engine/.gopath/src/github.com/docker/docker/api/server/middleware/version.go:62 +0x60d fp=0xc000db38d8 sp=0xc000db37c8 pc=0x55f622ab581d
Jul 31 13:06:57 controller-1 dockerd[258948]: github.com/docker/docker/pkg/authorization.(*Middleware).WrapHandler.func1(0x55f6249678a0, 0xc00144a600, 0x55f624956ca0, 0xc001ee9500, 0xc001d0b700, 0xc00144a570, 0x55f6249678a0, 0xc00144a600)
Jul 31 13:06:57 controller-1 dockerd[258948]: /root/rpmbuild/BUILD/src/engine/.gopath/src/github.com/docker/docker/pkg/authorization/middleware.go:59 +0x82f fp=0xc000db3a80 sp=0xc000db38d8 pc=0x55f6225e168f
Jul 31 13:06:57 controller-1 dockerd[258948]: github.com/docker/docker/api/server.(*Server).makeHTTPHandler.func1(0x55f624956ca0, 0xc001ee9500, 0xc001d0b600)
Jul 31 13:06:57 controller-1 dockerd[258948]: /root/rpmbuild/BUILD/src/engine/.gopath/src/github.com/docker/docker/api/server/server.go:142 +0x225 fp=0xc000db3b60 sp=0xc000db3a80 pc=0x55f622aca9a5
Jul 31 13:06:57 controller-1 dockerd[258948]: net/http.HandlerFunc.ServeHTTP(0xc0008e0b60, 0x55f624956ca0, 0xc001ee9500, 0xc001d0b600)
Jul 31 13:06:57 controller-1 dockerd[258948]: /usr/local/go/src/net/http/server.go:1995 +0x46 fp=0xc000db3b88 sp=0xc000db3b60 pc=0x55f62227eac6
Jul 31 13:06:57 controller-1 dockerd[258948]: github.com/docker/docker/vendor/github.com/gorilla/mux.(*Router).ServeHTTP(0xc000912540, 0x55f624956ca0, 0xc001ee9500, 0xc001d0b400)
Jul 31 13:06:57 controller-1 dockerd[258948]: /root/rpmbuild/BUILD/src/engine/.gopath/src/github.com/docker/docker/vendor/github.com/gorilla/mux/mux.go:212 +0xe5 fp=0xc000db3cb8 sp=0xc000db3b88 pc=0x55f6225ed635
Jul 31 13:06:57 controller-1 dockerd[258948]: github.com/docker/docker/api/server.(*routerSwapper).ServeHTTP(0xc000b6f2b0, 0x55f624956ca0, 0xc001ee9500, 0xc001d0b400)
...
Describe the results you expected:
Docker never crashes.
Additional information you deem important (e.g. issue happens only occasionally):
The issue is eerily similar to the issue reported in #32893, although the top of the stack trace here is a little bit different.
It seems to be related to the overlayfs2 storage driver.
Recently there were a couple of PRs seemingly touching the area:
#39135
#38265
The description of the PR mentions actually removing artificial locks (?) to speed-up container creation.
Can't it be that you have accidentally removed a lock which was guarding against some real race conditions?
@thaJeztah @kolyshkin @AkihiroSuda
Output of docker version:
$ docker version
Client: Docker Engine - Community
Version: 19.03.0
API version: 1.40
Go version: go1.12.5
Git commit: aeac9490dc
Built: Wed Jul 17 18:15:40 2019
OS/Arch: linux/amd64
Experimental: false
Server: Docker Engine - Community
Engine:
Version: 19.03.0
API version: 1.40 (minimum version 1.12)
Go version: go1.12.5
Git commit: aeac9490dc
Built: Wed Jul 17 18:14:16 2019
OS/Arch: linux/amd64
Experimental: false
containerd:
Version: 1.2.6
GitCommit: 894b81a4b802e4eb2a91d1ce216b8817763c29fb
runc:
Version: 1.0.0-rc8
GitCommit: 425e105d5a03fabd737a126ad93d62a9eeede87f
docker-init:
Version: 0.18.0
GitCommit: fec3683
Output of docker info:
$ docker info
Client:
Debug Mode: false
Server:
Containers: 30
Running: 27
Paused: 0
Stopped: 3
Images: 18
Server Version: 19.03.0
Storage Driver: overlay2
Backing Filesystem: xfs
Supports d_type: true
Native Overlay Diff: true
Logging Driver: json-file
Cgroup Driver: cgroupfs
Plugins:
Volume: local
Network: bridge host ipvlan macvlan null overlay
Log: awslogs fluentd gcplogs gelf journald json-file local logentries splunk syslog
Swarm: inactive
Runtimes: runc
Default Runtime: runc
Init Binary: docker-init
containerd version: 894b81a4b802e4eb2a91d1ce216b8817763c29fb
runc version: 425e105d5a03fabd737a126ad93d62a9eeede87f
init version: fec3683
Security Options:
seccomp
Profile: default
Kernel Version: 4.19.57
Operating System: CentOS Linux 7 (Core)
OSType: linux
Architecture: x86_64
CPUs: 4
Total Memory: 187.3GiB
Name: controller-1
ID: JMXB:VTC6:4FDW:XNLI:RB2F:GS76:TJ4Z:ZCPN:C3UF:W6V2:2HLX:BWFS
Docker Root Dir: /var/lib/docker
Debug Mode: false
Registry: https://index.docker.io/v1/
Labels:
Experimental: false
Insecure Registries:
127.0.0.0/8
Live Restore Enabled: true
Additional environment details (AWS, VirtualBox, physical, etc.):
Physical server machine