Open imrehg opened 6 years ago
A possible recurrence of this issue on BalenaOS 2.15.1r2. Balena support was able to clear this issue by removing the contents of /var/lib/docker/network/files but it is concerning that we don't know the trigger.
Nov 27 15:32:35 1141401 systemd[1]: balena.service: Failed with result 'exit-code'.
Nov 27 15:32:35 1141401 systemd[1]: Failed to start Balena Application Container Engine.
Nov 27 15:32:35 1141401 systemd[1]: balena.service: Service hold-off time over, scheduling restart.
Nov 27 15:32:35 1141401 systemd[1]: balena.service: Scheduled restart job, restart counter is at 98.
Nov 27 15:32:35 1141401 systemd[1]: Stopped Balena Application Container Engine.
Nov 27 15:32:35 1141401 systemd[1]: Starting Balena Application Container Engine...
Nov 27 15:32:35 1141401 healthdog[16937]: time="2018-11-27T15:32:35Z" level=warning msg="Running experimental build"
Nov 27 15:32:35 1141401 healthdog[16937]: time="2018-11-27T15:32:35.777538023Z" level=info msg="libcontainerd: started new balena-containerd process" pid=16951
Nov 27 15:32:35 1141401 healthdog[16937]: time="2018-11-27T15:32:35Z" level=info msg="starting containerd" module=containerd revision= version=1.0.0+unknown
Nov 27 15:32:35 1141401 healthdog[16937]: time="2018-11-27T15:32:35Z" level=info msg="setting subreaper..." module=containerd
Nov 27 15:32:35 1141401 healthdog[16937]: time="2018-11-27T15:32:35Z" level=info msg="changing OOM score to -500" module=containerd
Nov 27 15:32:35 1141401 healthdog[16937]: time="2018-11-27T15:32:35Z" level=info msg="loading plugin \"io.containerd.content.v1.content\"..." module=containerd type=io.containerd.content.v1
Nov 27 15:32:35 1141401 healthdog[16937]: time="2018-11-27T15:32:35Z" level=info msg="loading plugin \"io.containerd.snapshotter.v1.overlayfs\"..." module=containerd type=io.containerd.snapshotter.v1
Nov 27 15:32:35 1141401 healthdog[16937]: time="2018-11-27T15:32:35Z" level=info msg="loading plugin \"io.containerd.metadata.v1.bolt\"..." module=containerd type=io.containerd.metadata.v1
Nov 27 15:32:35 1141401 healthdog[16937]: time="2018-11-27T15:32:35Z" level=info msg="loading plugin \"io.containerd.differ.v1.walking\"..." module=containerd type=io.containerd.differ.v1
Nov 27 15:32:35 1141401 healthdog[16937]: time="2018-11-27T15:32:35Z" level=info msg="loading plugin \"io.containerd.gc.v1.scheduler\"..." module=containerd type=io.containerd.gc.v1
Nov 27 15:32:35 1141401 healthdog[16937]: time="2018-11-27T15:32:35Z" level=info msg="loading plugin \"io.containerd.grpc.v1.containers\"..." module=containerd type=io.containerd.grpc.v1
Nov 27 15:32:35 1141401 healthdog[16937]: time="2018-11-27T15:32:35Z" level=info msg="loading plugin \"io.containerd.grpc.v1.content\"..." module=containerd type=io.containerd.grpc.v1
Nov 27 15:32:35 1141401 healthdog[16937]: time="2018-11-27T15:32:35Z" level=info msg="loading plugin \"io.containerd.grpc.v1.diff\"..." module=containerd type=io.containerd.grpc.v1
Nov 27 15:32:35 1141401 healthdog[16937]: time="2018-11-27T15:32:35Z" level=info msg="loading plugin \"io.containerd.grpc.v1.events\"..." module=containerd type=io.containerd.grpc.v1
Nov 27 15:32:35 1141401 healthdog[16937]: time="2018-11-27T15:32:35Z" level=info msg="loading plugin \"io.containerd.grpc.v1.healthcheck\"..." module=containerd type=io.containerd.grpc.v1
Nov 27 15:32:35 1141401 healthdog[16937]: time="2018-11-27T15:32:35Z" level=info msg="loading plugin \"io.containerd.grpc.v1.images\"..." module=containerd type=io.containerd.grpc.v1
Nov 27 15:32:35 1141401 healthdog[16937]: time="2018-11-27T15:32:35Z" level=info msg="loading plugin \"io.containerd.grpc.v1.leases\"..." module=containerd type=io.containerd.grpc.v1
Nov 27 15:32:35 1141401 healthdog[16937]: time="2018-11-27T15:32:35Z" level=info msg="loading plugin \"io.containerd.grpc.v1.namespaces\"..." module=containerd type=io.containerd.grpc.v1
Nov 27 15:32:35 1141401 healthdog[16937]: time="2018-11-27T15:32:35Z" level=info msg="loading plugin \"io.containerd.grpc.v1.snapshots\"..." module=containerd type=io.containerd.grpc.v1
Nov 27 15:32:35 1141401 healthdog[16937]: time="2018-11-27T15:32:35Z" level=info msg="loading plugin \"io.containerd.monitor.v1.cgroups\"..." module=containerd type=io.containerd.monitor.v1
Nov 27 15:32:35 1141401 healthdog[16937]: time="2018-11-27T15:32:35Z" level=info msg="loading plugin \"io.containerd.runtime.v1.linux\"..." module=containerd type=io.containerd.runtime.v1
Nov 27 15:32:35 1141401 healthdog[16937]: time="2018-11-27T15:32:35Z" level=info msg="loading plugin \"io.containerd.grpc.v1.tasks\"..." module=containerd type=io.containerd.grpc.v1
Nov 27 15:32:35 1141401 healthdog[16937]: time="2018-11-27T15:32:35Z" level=info msg="loading plugin \"io.containerd.grpc.v1.version\"..." module=containerd type=io.containerd.grpc.v1
Nov 27 15:32:35 1141401 healthdog[16937]: time="2018-11-27T15:32:35Z" level=info msg="loading plugin \"io.containerd.grpc.v1.introspection\"..." module=containerd type=io.containerd.grpc.v1
Nov 27 15:32:35 1141401 healthdog[16937]: time="2018-11-27T15:32:35Z" level=info msg=serving... address=/var/run/balena/containerd/balena-containerd-debug.sock module=containerd/debug
Nov 27 15:32:35 1141401 healthdog[16937]: time="2018-11-27T15:32:35Z" level=info msg=serving... address=/var/run/balena/containerd/balena-containerd.sock module=containerd/grpc
Nov 27 15:32:35 1141401 healthdog[16937]: time="2018-11-27T15:32:35Z" level=info msg="containerd successfully booted in 0.010905s" module=containerd
Nov 27 15:32:35 1141401 healthdog[16937]: time="2018-11-27T15:32:35.976583967Z" level=info msg="Graph migration to content-addressability took 0.00 seconds"
Nov 27 15:32:35 1141401 healthdog[16937]: time="2018-11-27T15:32:35.978708547Z" level=warning msg="Your kernel does not support cgroup rt period"
Nov 27 15:32:35 1141401 healthdog[16937]: time="2018-11-27T15:32:35.978872869Z" level=warning msg="Your kernel does not support cgroup rt runtime"
Nov 27 15:32:35 1141401 healthdog[16937]: time="2018-11-27T15:32:35.979693754Z" level=warning msg="mountpoint for pids not found"
Nov 27 15:32:35 1141401 healthdog[16937]: time="2018-11-27T15:32:35.982998696Z" level=info msg="Loading containers: start."
Nov 27 15:32:37 1141401 healthdog[16937]: time="2018-11-27T15:32:37.025846519Z" level=warning msg="could not create bridge network for id 8793096df3b66c21bac9f68bfec17844480d0451067f94192cc2726d1ebfddec bridge name docker0 while booting up from persistent state: bridge device with non default name docker0 must be created manually"
Nov 27 15:32:37 1141401 healthdog[16937]: time="2018-11-27T15:32:37.672362295Z" level=info msg="Removing stale sandbox 630d5ff8b54c64cf33877da308f34bef3e0a0e4ed1e6de3ccf6d6ba9607f8f08 (f4f0ed04eb12b8d5b3912dd06f1a394bb0b79f91a2d6f150fc3be06dce321810)"
Nov 27 15:32:37 1141401 healthdog[16937]: panic: page 11 already freed
Nov 27 15:32:37 1141401 healthdog[16937]: goroutine 1 [running]:
Nov 27 15:32:37 1141401 healthdog[16937]: github.com/docker/docker/vendor/github.com/boltdb/bolt.(*freelist).free(0x1305f740, 0x1c0f0, 0x0, 0x74872000)
Nov 27 15:32:37 1141401 healthdog[16937]: /yocto/resin-board/build/tmp/work/cortexa7hf-neon-vfpv4-poky-linux-gnueabi/balena/17.12.0-dev+git2bfe621117ac146265c720e6c64d32d08445f843-r0/git/src/import/.gopath/src/github.com/docker/docker/vendor/github.com/boltdb/bolt/freelist.go:117 +0x2f4
Nov 27 15:32:37 1141401 healthdog[16937]: github.com/docker/docker/vendor/github.com/boltdb/bolt.(*node).spill(0x1296cf40, 0x12ad6a50, 0x17ef0d8)
Nov 27 15:32:37 1141401 healthdog[16937]: /yocto/resin-board/build/tmp/work/cortexa7hf-neon-vfpv4-poky-linux-gnueabi/balena/17.12.0-dev+git2bfe621117ac146265c720e6c64d32d08445f843-r0/git/src/import/.gopath/src/github.com/docker/docker/vendor/github.com/boltdb/bolt/node.go:363 +0x1e4
Nov 27 15:32:37 1141401 healthdog[16937]: github.com/docker/docker/vendor/github.com/boltdb/bolt.(*node).spill(0x1296cf00, 0x1305f800, 0x12f76afc)
Nov 27 15:32:37 1141401 healthdog[16937]: /yocto/resin-board/build/tmp/work/cortexa7hf-neon-vfpv4-poky-linux-gnueabi/balena/17.12.0-dev+git2bfe621117ac146265c720e6c64d32d08445f843-r0/git/src/import/.gopath/src/github.com/docker/docker/vendor/github.com/boltdb/bolt/node.go:350 +0x90
Nov 27 15:32:37 1141401 healthdog[16937]: github.com/docker/docker/vendor/github.com/boltdb/bolt.(*Bucket).spill(0x1305f7e0, 0x1305f700, 0x12f76c6c)
Nov 27 15:32:37 1141401 healthdog[16937]: /yocto/resin-board/build/tmp/work/cortexa7hf-neon-vfpv4-poky-linux-gnueabi/balena/17.12.0-dev+git2bfe621117ac146265c720e6c64d32d08445f843-r0/git/src/import/.gopath/src/github.com/docker/docker/vendor/github.com/boltdb/bolt/bucket.go:571 +0x37c
Nov 27 15:32:37 1141401 healthdog[16937]: github.com/docker/docker/vendor/github.com/boltdb/bolt.(*Bucket).spill(0x12a5e78c, 0xbef776c5, 0x78646a1d)
Nov 27 15:32:37 1141401 healthdog[16937]: /yocto/resin-board/build/tmp/work/cortexa7hf-neon-vfpv4-poky-linux-gnueabi/balena/17.12.0-dev+git2bfe621117ac146265c720e6c64d32d08445f843-r0/git/src/import/.gopath/src/github.com/docker/docker/vendor/github.com/boltdb/bolt/bucket.go:538 +0x2d8
Nov 27 15:32:37 1141401 healthdog[16937]: github.com/docker/docker/vendor/github.com/boltdb/bolt.(*Tx).Commit(0x12a5e780, 0x0, 0x0)
Nov 27 15:32:37 1141401 healthdog[16937]: /yocto/resin-board/build/tmp/work/cortexa7hf-neon-vfpv4-poky-linux-gnueabi/balena/17.12.0-dev+git2bfe621117ac146265c720e6c64d32d08445f843-r0/git/src/import/.gopath/src/github.com/docker/docker/vendor/github.com/boltdb/bolt/tx.go:163 +0xb8
Nov 27 15:32:37 1141401 healthdog[16937]: github.com/docker/docker/vendor/github.com/boltdb/bolt.(*DB).Update(0x12c7eea0, 0x12f76da0, 0x0, 0x0)
Nov 27 15:32:37 1141401 healthdog[16937]: /yocto/resin-board/build/tmp/work/cortexa7hf-neon-vfpv4-poky-linux-gnueabi/balena/17.12.0-dev+git2bfe621117ac146265c720e6c64d32d08445f843-r0/git/src/import/.gopath/src/github.com/docker/docker/vendor/github.com/boltdb/bolt/db.go:602 +0xd0
Nov 27 15:32:37 1141401 healthdog[16937]: github.com/docker/docker/vendor/github.com/docker/libkv/store/boltdb.(*BoltDB).AtomicDelete(0x1296cb00, 0x12e65800, 0x5d, 0x1305f6e0, 0x0, 0x0, 0x0)
Nov 27 15:32:37 1141401 healthdog[16937]: /yocto/resin-board/build/tmp/work/cortexa7hf-neon-vfpv4-poky-linux-gnueabi/balena/17.12.0-dev+git2bfe621117ac146265c720e6c64d32d08445f843-r0/git/src/import/.gopath/src/github.com/docker/docker/vendor/github.com/docker/libkv/store/boltdb/boltdb.go:329 +0x114
Nov 27 15:32:37 1141401 healthdog[16937]: github.com/docker/docker/vendor/github.com/docker/libnetwork/datastore.(*datastore).DeleteObjectAtomic(0x1297be90, 0x17f4730, 0x12970dc0, 0x0, 0x0)
Nov 27 15:32:37 1141401 healthdog[16937]: /yocto/resin-board/build/tmp/work/cortexa7hf-neon-vfpv4-poky-linux-gnueabi/balena/17.12.0-dev+git2bfe621117ac146265c720e6c64d32d08445f843-r0/git/src/import/.gopath/src/github.com/docker/docker/vendor/github.com/docker/libnetwork/datastore/datastore.go:623 +0x1dc
Nov 27 15:32:37 1141401 healthdog[16937]: github.com/docker/docker/vendor/github.com/docker/libnetwork.(*controller).deleteFromStore(0x12a4bef0, 0x17f4730, 0x12970dc0, 0x2, 0x0)
Nov 27 15:32:37 1141401 healthdog[16937]: /yocto/resin-board/build/tmp/work/cortexa7hf-neon-vfpv4-poky-linux-gnueabi/balena/17.12.0-dev+git2bfe621117ac146265c720e6c64d32d08445f843-r0/git/src/import/.gopath/src/github.com/docker/docker/vendor/github.com/docker/libnetwork/store.go:248 +0xd4
Nov 27 15:32:37 1141401 healthdog[16937]: github.com/docker/docker/vendor/github.com/docker/libnetwork.(*sandbox).storeDelete(0x12c7ed80, 0x0, 0x0)
Nov 27 15:32:37 1141401 healthdog[16937]: /yocto/resin-board/build/tmp/work/cortexa7hf-neon-vfpv4-poky-linux-gnueabi/balena/17.12.0-dev+git2bfe621117ac146265c720e6c64d32d08445f843-r0/git/src/import/.gopath/src/github.com/docker/docker/vendor/github.com/docker/libnetwork/sandbox_store.go:190 +0xb8
Nov 27 15:32:37 1141401 healthdog[16937]: github.com/docker/docker/vendor/github.com/docker/libnetwork.(*sandbox).delete(0x12c7ed80, 0x1, 0x12f77094, 0x2)
Nov 27 15:32:37 1141401 healthdog[16937]: /yocto/resin-board/build/tmp/work/cortexa7hf-neon-vfpv4-poky-linux-gnueabi/balena/17.12.0-dev+git2bfe621117ac146265c720e6c64d32d08445f843-r0/git/src/import/.gopath/src/github.com/docker/docker/vendor/github.com/docker/libnetwork/sandbox.go:252 +0x480
Nov 27 15:32:37 1141401 healthdog[16937]: github.com/docker/docker/vendor/github.com/docker/libnetwork.(*controller).sandboxCleanup(0x12a4bef0, 0x0)
Nov 27 15:32:37 1141401 healthdog[16937]: /yocto/resin-board/build/tmp/work/cortexa7hf-neon-vfpv4-poky-linux-gnueabi/balena/17.12.0-dev+git2bfe621117ac146265c720e6c64d32d08445f843-r0/git/src/import/.gopath/src/github.com/docker/docker/vendor/github.com/docker/libnetwork/sandbox_store.go:280 +0xee8
Nov 27 15:32:37 1141401 healthdog[16937]: github.com/docker/docker/vendor/github.com/docker/libnetwork.New(0x1296cac0, 0x9, 0x10, 0x12cb6f20, 0x12d57d80, 0x1296cac0, 0x9)
Nov 27 15:32:37 1141401 healthdog[16937]: /yocto/resin-board/build/tmp/work/cortexa7hf-neon-vfpv4-poky-linux-gnueabi/balena/17.12.0-dev+git2bfe621117ac146265c720e6c64d32d08445f843-r0/git/src/import/.gopath/src/github.com/docker/docker/vendor/github.com/docker/libnetwork/controller.go:246 +0x64c
Nov 27 15:32:37 1141401 healthdog[16937]: github.com/docker/docker/daemon.(*Daemon).initNetworkController(0x12c927e0, 0x12cb8000, 0x12d57d80, 0x12c927e0, 0x129799a8, 0x12d57d80, 0x12d57d60)
Nov 27 15:32:37 1141401 healthdog[16937]: /yocto/resin-board/build/tmp/work/cortexa7hf-neon-vfpv4-poky-linux-gnueabi/balena/17.12.0-dev+git2bfe621117ac146265c720e6c64d32d08445f843-r0/git/src/import/.gopath/src/github.com/docker/docker/daemon/daemon_unix.go:862 +0x68
Nov 27 15:32:37 1141401 healthdog[16937]: github.com/docker/docker/daemon.(*Daemon).restore(0x12c927e0, 0xf33708, 0x4)
Nov 27 15:32:37 1141401 healthdog[16937]: /yocto/resin-board/build/tmp/work/cortexa7hf-neon-vfpv4-poky-linux-gnueabi/balena/17.12.0-dev+git2bfe621117ac146265c720e6c64d32d08445f843-r0/git/src/import/.gopath/src/github.com/docker/docker/daemon/daemon.go:367 +0xa48
Nov 27 15:32:37 1141401 healthdog[16937]: github.com/docker/docker/daemon.NewDaemon(0x12cb8000, 0x17f4c78, 0x12a7d030, 0x17e8e58, 0x12a848c0, 0x12cb6f20, 0x0, 0x0, 0x0)
Nov 27 15:32:37 1141401 healthdog[16937]: /yocto/resin-board/build/tmp/work/cortexa7hf-neon-vfpv4-poky-linux-gnueabi/balena/17.12.0-dev+git2bfe621117ac146265c720e6c64d32d08445f843-r0/git/src/import/.gopath/src/github.com/docker/docker/daemon/daemon.go:942 +0x1d88
Nov 27 15:32:37 1141401 healthdog[16937]: github.com/docker/docker/cmd/dockerd.(*DaemonCli).start(0x12cb6520, 0x12ca5a80, 0x0, 0x0)
Nov 27 15:32:37 1141401 healthdog[16937]: /yocto/resin-board/build/tmp/work/cortexa7hf-neon-vfpv4-poky-linux-gnueabi/balena/17.12.0-dev+git2bfe621117ac146265c720e6c64d32d08445f843-r0/git/src/import/.gopath/src/github.com/docker/docker/cmd/dockerd/daemon.go:223 +0xda4
Nov 27 15:32:37 1141401 healthdog[16937]: github.com/docker/docker/cmd/dockerd.runDaemon(0x12ca5a80, 0x12c3a500, 0x0)
Nov 27 15:32:37 1141401 healthdog[16937]: /yocto/resin-board/build/tmp/work/cortexa7hf-neon-vfpv4-poky-linux-gnueabi/balena/17.12.0-dev+git2bfe621117ac146265c720e6c64d32d08445f843-r0/git/src/import/.gopath/src/github.com/docker/docker/cmd/dockerd/docker.go:78 +0x54
Nov 27 15:32:37 1141401 healthdog[16937]: github.com/docker/docker/cmd/dockerd.newDaemonCommand.func1(0x12c925a0, 0x12c43560, 0x0, 0xb, 0x0, 0x0)
Nov 27 15:32:37 1141401 healthdog[16937]: /yocto/resin-board/build/tmp/work/cortexa7hf-neon-vfpv4-poky-linux-gnueabi/balena/17.12.0-dev+git2bfe621117ac146265c720e6c64d32d08445f843-r0/git/src/import/.gopath/src/github.com/docker/docker/cmd/dockerd/docker.go:29 +0x50
Nov 27 15:32:37 1141401 healthdog[16937]: github.com/docker/docker/vendor/github.com/spf13/cobra.(*Command).execute(0x12c925a0, 0x1297c008, 0xb, 0xb, 0x12c925a0, 0x1297c008)
Nov 27 15:32:37 1141401 healthdog[16937]: /yocto/resin-board/build/tmp/work/cortexa7hf-neon-vfpv4-poky-linux-gnueabi/balena/17.12.0-dev+git2bfe621117ac146265c720e6c64d32d08445f843-r0/git/src/import/.gopath/src/github.com/docker/docker/vendor/github.com/spf13/cobra/command.go:700 +0x364
Nov 27 15:32:37 1141401 healthdog[16937]: github.com/docker/docker/vendor/github.com/spf13/cobra.(*Command).ExecuteC(0x12c925a0, 0x12c925a0, 0xfbc03c, 0x1297a138)
Nov 27 15:32:37 1141401 healthdog[16937]: /yocto/resin-board/build/tmp/work/cortexa7hf-neon-vfpv4-poky-linux-gnueabi/balena/17.12.0-dev+git2bfe621117ac146265c720e6c64d32d08445f843-r0/git/src/import/.gopath/src/github.com/docker/docker/vendor/github.com/spf13/cobra/command.go:785 +0x1f8
Nov 27 15:32:37 1141401 healthdog[16937]: github.com/docker/docker/vendor/github.com/spf13/cobra.(*Command).Execute(0x12c925a0, 0x1296e0d0, 0xca0449)
Nov 27 15:32:37 1141401 healthdog[16937]: /yocto/resin-board/build/tmp/work/cortexa7hf-neon-vfpv4-poky-linux-gnueabi/balena/17.12.0-dev+git2bfe621117ac146265c720e6c64d32d08445f843-r0/git/src/import/.gopath/src/github.com/docker/docker/vendor/github.com/spf13/cobra/command.go:738 +0x1c
Nov 27 15:32:37 1141401 healthdog[16937]: github.com/docker/docker/cmd/dockerd.Main()
Nov 27 15:32:37 1141401 healthdog[16937]: /yocto/resin-board/build/tmp/work/cortexa7hf-neon-vfpv4-poky-linux-gnueabi/balena/17.12.0-dev+git2bfe621117ac146265c720e6c64d32d08445f843-r0/git/src/import/.gopath/src/github.com/docker/docker/cmd/dockerd/docker.go:106 +0x7c
Nov 27 15:32:37 1141401 healthdog[16937]: main.main()
Nov 27 15:32:37 1141401 healthdog[16937]: /yocto/resin-board/build/tmp/work/cortexa7hf-neon-vfpv4-poky-linux-gnueabi/balena/17.12.0-dev+git2bfe621117ac146265c720e6c64d32d08445f843-r0/git/src/import/.gopath/src/github.com/docker/docker/cmd/balena/main.go:29 +0x1c0
Nov 27 15:32:37 1141401 systemd[1]: balena.service: Main process exited, code=exited, status=2/INVALIDARGUMENT
Nov 27 15:32:37 1141401 systemd[1]: balena.service: Failed with result 'exit-code'.```
@memory I'm not sure this is the same issue, the supervisor would never try to create docker0
. It's more likely that this is an issue in balenaEngine. That being said, I'm not going to rule out the supervisor having some role in causing this issue.
Fair enough. Paulo had suggested that this bug might be the one to append to; would you prefer I open a bug against balena-engine?
I'd say leave it here for now, I'm still looking into how this could happen. It might be worth opening another issue in balena-engine and referencing this issues - thanks!
Run into an issue where a service is not successfully started up. Multicontainer application:
The
main
service is using balena networking. The logs are:and the networks on the device:
It was on a resinOS 2.13.5 (custom build for some proxy testing).
There's another one when after a reboot:
In both cases the device worked first, and hit this issue after reboot.
Flowdock thread 1, Flowdock thread 2.
Front conversations