moby: Native Swarm in 1.12 - panic: runtime error: index out of range

Output of docker version:

Client:
 Version:      1.12.0
 API version:  1.24
 Go version:   go1.6.3
 Git commit:   8eab29e
 Built:        
 OS/Arch:      linux/amd64

Server:
 Version:      1.12.0
 API version:  1.24
 Go version:   go1.6.3
 Git commit:   8eab29e
 Built:        
 OS/Arch:      linux/amd64

Output of docker info:

Containers: 1
 Running: 0
 Paused: 0
 Stopped: 1
Images: 2
Server Version: 1.12.0
Storage Driver: devicemapper
 Pool Name: docker-253:0-1970762-pool
 Pool Blocksize: 65.54 kB
 Base Device Size: 10.74 GB
 Backing Filesystem: xfs
 Data file: /dev/loop0
 Metadata file: /dev/loop1
 Data Space Used: 10.46 GB
 Data Space Total: 107.4 GB
 Data Space Available: 28.07 GB
 Metadata Space Used: 6.238 MB
 Metadata Space Total: 2.147 GB
 Metadata Space Available: 2.141 GB
 Thin Pool Minimum Free Space: 10.74 GB
 Udev Sync Supported: true
 Deferred Removal Enabled: false
 Deferred Deletion Enabled: false
 Deferred Deleted Device Count: 0
 Data loop file: /mnt/docker/devicemapper/devicemapper/data
 WARNING: Usage of loopback devices is strongly discouraged for production use. Use `--storage-opt dm.thinpooldev` to specify a custom block storage device.
 Metadata loop file: /mnt/docker/devicemapper/devicemapper/metadata
 Library Version: 1.02.107-RHEL7 (2016-06-09)
Logging Driver: json-file
Cgroup Driver: cgroupfs
Plugins:
 Volume: local
 Network: overlay bridge null host
Swarm: active
 NodeID: 2vyiapx1ngzr5s0lj87x3nqxd
 Is Manager: false
 Node Address: 172.28.128.18
Runtimes: runc
Default Runtime: runc
Security Options: seccomp
Kernel Version: 3.10.0-327.22.2.el7.x86_64
Operating System: CentOS Linux 7 (Core)
OSType: linux
Architecture: x86_64
CPUs: 1
Total Memory: 993 MiB
Name: dt-dev-2
ID: 7IDM:SHKD:MMTJ:USU6:U7BD:CZAK:P3QO:IXFM:UCM3:S2LB:OIJP:GW6P
Docker Root Dir: /mnt/docker
Debug Mode (client): false
Debug Mode (server): false
Registry: https://index.docker.io/v1/
WARNING: bridge-nf-call-ip6tables is disabled
Insecure Registries:
 127.0.0.0/8

Additional environment details (AWS, VirtualBox, physical, etc.):

CentOS7 @ VirtualBox (via Vagrant)

Additional information:

I had Swarm setup with 2 nodes (and 2 different services started). I’ve restarted one of nodes and I was surprised that now the restarted node hosts both services (they were auto-balanced before). Turns out that Docker at machine that was NOT restarted died - this is the stacktrace:

Aug 11 06:13:28 dt-dev-2 dockerd[17100]: time="2016-08-11T06:13:28.138941967Z" level=warning msg="cannot find proper key indices while processing key upda
Aug 11 08:31:24 dt-dev-2 dockerd[17100]: time="2016-08-11T08:31:24.552409257Z" level=error msg="agent: session failed" error="rpc error: code = 13 desc = 
Aug 11 08:31:24 dt-dev-2 dockerd[17100]: time="2016-08-11T08:31:24Z" level=info msg="Firewalld running: false"
Aug 11 08:31:24 dt-dev-2 dockerd[17100]: time="2016-08-11T08:31:24Z" level=info msg="Firewalld running: false"
Aug 11 08:31:27 dt-dev-2 dockerd[17100]: time="2016-08-11T08:31:27.274591339Z" level=info msg="2016/08/11 08:31:27 [INFO] memberlist: Suspect dt-dev-1 has
Aug 11 08:31:29 dt-dev-2 dockerd[17100]: time="2016-08-11T08:31:29.274701535Z" level=info msg="2016/08/11 08:31:29 [INFO] memberlist: Suspect dt-dev-1 has
Aug 11 08:31:29 dt-dev-2 dockerd[17100]: time="2016-08-11T08:31:29.274859714Z" level=error msg="periodic bulk sync failure for network 1ms79jc1lu6z29l9ra0
Aug 11 08:31:29 dt-dev-2 dockerd[17100]: time="2016-08-11T08:31:29.625202513Z" level=error msg="agent: session failed" error="session initiation timed out
Aug 11 08:31:31 dt-dev-2 dockerd[17100]: time="2016-08-11T08:31:31.274195993Z" level=info msg="2016/08/11 08:31:31 [INFO] memberlist: Suspect dt-dev-1 has
Aug 11 08:31:32 dt-dev-2 dockerd[17100]: time="2016-08-11T08:31:32.274488016Z" level=warning msg="cannot find proper key indices while processing key upda
Aug 11 08:31:32 dt-dev-2 dockerd[17100]: time="2016-08-11T08:31:32.275195889Z" level=info msg="2016/08/11 08:31:32 [INFO] memberlist: Suspect dt-dev-1 has
Aug 11 08:31:32 dt-dev-2 dockerd[17100]: time="2016-08-11T08:31:32.275233408Z" level=info msg="2016/08/11 08:31:32 [INFO] memberlist: Marking dt-dev-1 as 
Aug 11 08:31:32 dt-dev-2 dockerd[17100]: time="2016-08-11T08:31:32.286804614Z" level=error msg="container status unavailable" error="context canceled" mod
Aug 11 08:43:35 dt-dev-2 dockerd[17100]: time="2016-08-11T08:43:35.005839511Z" level=error msg="agent: session failed" error="rpc error: code = 13 desc = 
Aug 11 08:43:40 dt-dev-2 dockerd[17100]: time="2016-08-11T08:43:40.990620593Z" level=error msg="agent: session failed" error="session initiation timed out
Aug 11 08:43:42 dt-dev-2 dockerd[17100]: time="2016-08-11T08:43:42.520821682Z" level=warning msg="cannot find proper key indices while processing key upda
Aug 11 08:43:42 dt-dev-2 dockerd[17100]: time="2016-08-11T08:43:42.555826038Z" level=error msg="container status unavailable" error="context canceled" mod
Aug 11 08:47:25 dt-dev-2 dockerd[17100]: time="2016-08-11T08:47:25.336033855Z" level=error msg="agent: session failed" error="rpc error: code = 13 desc = 
Aug 11 08:47:31 dt-dev-2 dockerd[17100]: time="2016-08-11T08:47:31.229495064Z" level=error msg="agent: session failed" error="session initiation timed out
Aug 11 08:47:32 dt-dev-2 dockerd[17100]: panic: runtime error: index out of range
Aug 11 08:47:32 dt-dev-2 dockerd[17100]: goroutine 870 [running]:
Aug 11 08:47:32 dt-dev-2 dockerd[17100]: panic(0x1a6fa00, 0xc82000e020)
Aug 11 08:47:32 dt-dev-2 dockerd[17100]: /usr/local/go/src/runtime/panic.go:481 +0x3e6
Aug 11 08:47:32 dt-dev-2 dockerd[17100]: github.com/docker/libnetwork/drivers/overlay.updateNodeKey(0xc820c300f0, 0x10, 0x10, 0xc820c30100, 0x10, 0x10, 0x
Aug 11 08:47:32 dt-dev-2 dockerd[17100]: /root/rpmbuild/BUILD/docker-engine/vendor/src/github.com/docker/libnetwork/drivers/overlay/encryption.go:496 +0x1
Aug 11 08:47:32 dt-dev-2 dockerd[17100]: github.com/docker/libnetwork/drivers/overlay.(*driver).updateKeys.func1(0xc820970e20, 0xd, 0xc820be9400, 0x3, 0x3
Aug 11 08:47:32 dt-dev-2 dockerd[17100]: /root/rpmbuild/BUILD/docker-engine/vendor/src/github.com/docker/libnetwork/drivers/overlay/encryption.go:444 +0x1
Aug 11 08:47:32 dt-dev-2 dockerd[17100]: github.com/docker/libnetwork/drivers/overlay.(*driver).secMapWalk(0xc820082e00, 0xc821b9cfc0, 0x0, 0x0)
Aug 11 08:47:32 dt-dev-2 dockerd[17100]: /root/rpmbuild/BUILD/docker-engine/vendor/src/github.com/docker/libnetwork/drivers/overlay/encryption.go:382 +0x1
Aug 11 08:47:32 dt-dev-2 dockerd[17100]: github.com/docker/libnetwork/drivers/overlay.(*driver).updateKeys(0xc820082e00, 0xc820aba1e0, 0xc820aba200, 0xc82
Aug 11 08:47:32 dt-dev-2 dockerd[17100]: /root/rpmbuild/BUILD/docker-engine/vendor/src/github.com/docker/libnetwork/drivers/overlay/encryption.go:445 +0x8
Aug 11 08:47:32 dt-dev-2 dockerd[17100]: github.com/docker/libnetwork/drivers/overlay.(*driver).DiscoverNew(0xc820082e00, 0x4, 0x1b9a4e0, 0xc821442c00, 0x
Aug 11 08:47:32 dt-dev-2 dockerd[17100]: /root/rpmbuild/BUILD/docker-engine/vendor/src/github.com/docker/libnetwork/drivers/overlay/overlay.go:351 +0xbbc
Aug 11 08:47:32 dt-dev-2 dockerd[17100]: github.com/docker/libnetwork.(*controller).handleKeyChange.func1(0x1d53098, 0x7, 0x7f7542cd07e8, 0xc820082e00, 0x
Aug 11 08:47:32 dt-dev-2 dockerd[17100]: /root/rpmbuild/BUILD/docker-engine/vendor/src/github.com/docker/libnetwork/agent.go:151 +0x94
Aug 11 08:47:32 dt-dev-2 dockerd[17100]: github.com/docker/libnetwork/drvregistry.(*DrvRegistry).WalkDrivers(0xc8201cf1d0, 0xc821b9d6e0)
Aug 11 08:47:32 dt-dev-2 dockerd[17100]: /root/rpmbuild/BUILD/docker-engine/vendor/src/github.com/docker/libnetwork/drvregistry/drvregistry.go:107 +0x2ce
Aug 11 08:47:32 dt-dev-2 dockerd[17100]: github.com/docker/libnetwork.(*controller).handleKeyChange(0xc8203f43c0, 0xc8210b9840, 0x6, 0x8, 0x0, 0x0)
Aug 11 08:47:32 dt-dev-2 dockerd[17100]: /root/rpmbuild/BUILD/docker-engine/vendor/src/github.com/docker/libnetwork/agent.go:156 +0x836
Aug 11 08:47:32 dt-dev-2 dockerd[17100]: github.com/docker/libnetwork.(*controller).SetKeys(0xc8203f43c0, 0xc8210b9840, 0x6, 0x8, 0x0, 0x0)
Aug 11 08:47:32 dt-dev-2 dockerd[17100]: /root/rpmbuild/BUILD/docker-engine/vendor/src/github.com/docker/libnetwork/controller.go:275 +0x35f
Aug 11 08:47:32 dt-dev-2 dockerd[17100]: github.com/docker/docker/daemon.(*Daemon).SetNetworkBootstrapKeys(0xc8203656c0, 0xc8210b9840, 0x6, 0x8, 0x0, 0x0)
Aug 11 08:47:32 dt-dev-2 dockerd[17100]: /root/rpmbuild/BUILD/docker-engine/.gopath/src/github.com/docker/docker/daemon/network.go:185 +0x6d
Aug 11 08:47:32 dt-dev-2 dockerd[17100]: github.com/docker/docker/daemon/cluster/executor/container.(*executor).SetNetworkBootstrapKeys(0xc820c10fb0, 0xc8
Aug 11 08:47:32 dt-dev-2 dockerd[17100]: /root/rpmbuild/BUILD/docker-engine/.gopath/src/github.com/docker/docker/daemon/cluster/executor/container/executo
Aug 11 08:47:32 dt-dev-2 dockerd[17100]: github.com/docker/swarmkit/agent.(*Agent).handleSessionMessage(0xc8209c6850, 0x7f7542cc6a98, 0xc820bb9dd0, 0xc820
Aug 11 08:47:32 dt-dev-2 dockerd[17100]: /root/rpmbuild/BUILD/docker-engine/vendor/src/github.com/docker/swarmkit/agent/agent.go:272 +0x5ca
Aug 11 08:47:32 dt-dev-2 dockerd[17100]: github.com/docker/swarmkit/agent.(*Agent).run(0xc8209c6850, 0x7f7542cc6a98, 0xc820bb9dd0)
Aug 11 08:47:32 dt-dev-2 dockerd[17100]: /root/rpmbuild/BUILD/docker-engine/vendor/src/github.com/docker/swarmkit/agent/agent.go:170 +0xbe6
Aug 11 08:47:32 dt-dev-2 dockerd[17100]: created by github.com/docker/swarmkit/agent.(*Agent).Start
Aug 11 08:47:32 dt-dev-2 dockerd[17100]: /root/rpmbuild/BUILD/docker-engine/vendor/src/github.com/docker/swarmkit/agent/agent.go:81 +0x37d
Aug 11 08:47:32 dt-dev-2 systemd[1]: docker.service: main process exited, code=exited, status=2/INVALIDARGUMENT
Aug 11 08:47:32 dt-dev-2 systemd[1]: Unit docker.service entered failed state.
Aug 11 08:47:32 dt-dev-2 systemd[1]: docker.service failed.

About this issue

  • Original URL
  • State: closed
  • Created 8 years ago
  • Comments: 33 (17 by maintainers)

Commits related to this issue

Most upvoted comments

Thank you @mmh36 for the extra logs, and the info about the 12 hrs frequency. They confirm the issue fixed in https://github.com/docker/libnetwork/pull/1453 is the same root cause of your panic.