Balena Engine won't start

I was having problems updating to new releases of my software with various problems depending on how I did things. This last time I got it to download the releases and each container said that he was at the new release but the status of one hung at installed and would never run. Starting thinking something was up with the supervisor. I saw this in journalctl -xe

Jun 11 22:24:31 ceb30a9 systemd[1]: Failed to start Balena Application Container Engine.
Jun 11 22:24:31 ceb30a9 resin-supervisor[10320]: Cannot connect to the balenaEngine daemon at unix:///var/run/balena-engine.sock. Is the balenaEngine daemon running?
Jun 11 22:24:31 ceb30a9 resin-supervisor[10329]: activating

Here is an interesting section from journalctl -u balena.service -t balenad. The backtrace was over 1500 lines long so I only grabbed a section. There were more error messages as well.

Jun 11 19:07:37 ceb30a9 balenad[703]: time="2020-06-11T19:07:37.231861209Z" level=info msg="shim reaped" id=b2819ad74edfa308a7fb2aa6ba3084a53f9325a1fd80cdd9b9173306b8ff1e66
Jun 11 19:07:37 ceb30a9 balenad[703]: time="2020-06-11T19:07:37.241289312Z" level=error msg="stream copy error: reading from a closed fifo"
Jun 11 19:07:37 ceb30a9 balenad[703]: time="2020-06-11T19:07:37.286284936Z" level=error msg="b2819ad74edfa308a7fb2aa6ba3084a53f9325a1fd80cdd9b9173306b8ff1e66 cleanup: failed to delete container from containerd: no such container"
Jun 11 19:07:37 ceb30a9 balenad[703]: time="2020-06-11T19:07:37.286350454Z" level=error msg="Handler for POST /containers/b2819ad74edfa308a7fb2aa6ba3084a53f9325a1fd80cdd9b9173306b8ff1e66/start returned error: OCI runtime create failed: container_linux.go:345: starting container process caused \"process_linux.go:275: applying cgroup configuration for process caused \\\"Process with ID 6387 does not exist.\\\"\": unknown"
Jun 11 19:07:45 ceb30a9 balenad[703]: time="2020-06-11T19:07:45.374372511Z" level=info msg="shim balena-engine-containerd-shim started" address=/containerd-shim/moby/b2819ad74edfa308a7fb2aa6ba3084a53f9325a1fd80cdd9b9173306b8ff1e66/shim.sock debug=false pid=6390
Jun 11 19:07:45 ceb30a9 balenad[703]: time="2020-06-11T19:07:45.444322596Z" level=info msg="shim reaped" id=b2819ad74edfa308a7fb2aa6ba3084a53f9325a1fd80cdd9b9173306b8ff1e66
Jun 11 19:07:45 ceb30a9 balenad[703]: time="2020-06-11T19:07:45.453791058Z" level=error msg="stream copy error: reading from a closed fifo"
Jun 11 19:07:45 ceb30a9 balenad[703]: time="2020-06-11T19:07:45.486289496Z" level=error msg="b2819ad74edfa308a7fb2aa6ba3084a53f9325a1fd80cdd9b9173306b8ff1e66 cleanup: failed to delete container from containerd: no such container"
Jun 11 19:07:45 ceb30a9 balenad[703]: time="2020-06-11T19:07:45.486330405Z" level=error msg="Handler for POST /containers/b2819ad74edfa308a7fb2aa6ba3084a53f9325a1fd80cdd9b9173306b8ff1e66/start returned error: OCI runtime create failed: container_linux.go:345: starting container process caused \"process_linux.go:275: applying cgroup configuration for process caused \\\"Process with ID 6404 does not exist.\\\"\": unknown"
Jun 11 19:08:01 ceb30a9 balenad[703]: time="2020-06-11T19:08:01.608707168Z" level=info msg="shim balena-engine-containerd-shim started" address=/containerd-shim/moby/b2819ad74edfa308a7fb2aa6ba3084a53f9325a1fd80cdd9b9173306b8ff1e66/shim.sock debug=false pid=6407
Jun 11 19:08:01 ceb30a9 balenad[703]: time="2020-06-11T19:08:01.679206489Z" level=info msg="shim reaped" id=b2819ad74edfa308a7fb2aa6ba3084a53f9325a1fd80cdd9b9173306b8ff1e66
Jun 11 19:08:01 ceb30a9 balenad[703]: time="2020-06-11T19:08:01.688733524Z" level=error msg="stream copy error: reading from a closed fifo"
Jun 11 19:08:01 ceb30a9 balenad[703]: time="2020-06-11T19:08:01.712301460Z" level=error msg="b2819ad74edfa308a7fb2aa6ba3084a53f9325a1fd80cdd9b9173306b8ff1e66 cleanup: failed to delete container from containerd: no such container"
Jun 11 19:08:01 ceb30a9 balenad[703]: time="2020-06-11T19:08:01.712340980Z" level=error msg="Handler for POST /containers/b2819ad74edfa308a7fb2aa6ba3084a53f9325a1fd80cdd9b9173306b8ff1e66/start returned error: OCI runtime create failed: container_linux.go:345: starting container process caused \"process_linux.go:275: applying cgroup configuration for process caused \\\"Process with ID 6421 does not exist.\\\"\": unknown"
Jun 11 19:08:33 ceb30a9 balenad[703]: time="2020-06-11T19:08:33.811169078Z" level=info msg="shim balena-engine-containerd-shim started" address=/containerd-shim/moby/b2819ad74edfa308a7fb2aa6ba3084a53f9325a1fd80cdd9b9173306b8ff1e66/shim.sock debug=false pid=6428
Jun 11 19:08:33 ceb30a9 balenad[703]: time="2020-06-11T19:08:33.884909217Z" level=info msg="shim reaped" id=b2819ad74edfa308a7fb2aa6ba3084a53f9325a1fd80cdd9b9173306b8ff1e66
Jun 11 19:08:33 ceb30a9 balenad[703]: time="2020-06-11T19:08:33.894241558Z" level=error msg="stream copy error: reading from a closed fifo"
Jun 11 19:08:33 ceb30a9 balenad[703]: time="2020-06-11T19:08:33.923139951Z" level=error msg="b2819ad74edfa308a7fb2aa6ba3084a53f9325a1fd80cdd9b9173306b8ff1e66 cleanup: failed to delete container from containerd: no such container"
Jun 11 19:08:33 ceb30a9 balenad[703]: time="2020-06-11T19:08:33.923175823Z" level=error msg="Handler for POST /containers/b2819ad74edfa308a7fb2aa6ba3084a53f9325a1fd80cdd9b9173306b8ff1e66/start returned error: OCI runtime create failed: container_linux.go:345: starting container process caused \"process_linux.go:275: applying cgroup configuration for process caused \\\"Process with ID 6444 does not exist.\\\"\": unknown"
Jun 11 19:08:52 ceb30a9 balenad[703]: SIGABRT: abort
Jun 11 19:08:52 ceb30a9 balenad[703]: PC=0x460df3 m=0 sigcode=0
Jun 11 19:08:52 ceb30a9 balenad[703]: goroutine 52 [syscall]:
Jun 11 19:08:52 ceb30a9 balenad[703]: runtime.notetsleepg(0x2685160, 0x141612b81b, 0x0)
Jun 11 19:08:52 ceb30a9 balenad[703]:         /usr/lib/go/src/runtime/lock_futex.go:227 +0x42 fp=0xc420055760 sp=0xc420055730 pc=0x414362
Jun 11 19:08:52 ceb30a9 balenad[703]: runtime.timerproc(0x2685140)
Jun 11 19:08:52 ceb30a9 balenad[703]:         /usr/lib/go/src/runtime/time.go:261 +0x2e7 fp=0xc4200557d8 sp=0xc420055760 pc=0x44ed67SIGABRT: abort
Jun 11 19:08:52 ceb30a9 balenad[703]: runtime.goexitPC=0x460df1( m=)
Jun 11 19:08:52 ceb30a9 balenad[703]: 0         sigcode=0/usr/lib/go/src/runtime/asm_amd64.s
Jun 11 19:08:52 ceb30a9 balenad[703]: :
Jun 11 19:08:52 ceb30a9 balenad[703]: 2361goroutine  +0 [0x1idle fp=]:
Jun 11 19:08:52 ceb30a9 balenad[703]: 0xc4200557e0 sp=0xc4200557d8 pc=0x45f861runtime.futex
Jun 11 19:08:52 ceb30a9 balenad[703]: (created by 0x2681ce8, runtime.(*timersBucket).addtimerLocked0x0
Jun 11 19:08:52 ceb30a9 balenad[703]: , 0x0        , /usr/lib/go/src/runtime/time.go0x0:, 1600x7ffe00000000 +, 0x1070x0
Jun 11 19:08:52 ceb30a9 balenad[703]: , 0x0
Jun 11 19:08:52 ceb30a9 balenad[703]: , goroutine 0x01 [, chan receive0x7ffe4e0b60c8, , 90x41407b minutes, ...]:
Jun 11 19:08:52 ceb30a9 balenad[703]: )
Jun 11 19:08:52 ceb30a9 balenad[703]:         /usr/lib/go/src/runtime/sys_linux_amd64.s:530 +0x21
Jun 11 19:08:52 ceb30a9 balenad[703]: runtime.futexsleep(0x2681ce8, 0x7ffe00000000, 0xffffffffffffffff)
Jun 11 19:08:52 ceb30a9 balenad[703]:         /usr/lib/go/src/runtime/os_linux.go:45 +0x4b
Jun 11 19:08:52 ceb30a9 balenad[703]: runtime.notesleep(0x2681ce8)
Jun 11 19:08:52 ceb30a9 balenad[703]:         /usr/lib/go/src/runtime/lock_futex.go:151 +0x9b
Jun 11 19:08:52 ceb30a9 balenad[703]: runtime.stoplockedm()
Jun 11 19:08:52 ceb30a9 balenad[703]:         /usr/lib/go/src/runtime/proc.go:2101 +0x8cgithub.com/docker/docker/cmd/dockerd.(*DaemonCli).start(
Jun 11 19:08:52 ceb30a9 balenad[703]: 0xc4204cf350runtime.schedule, (0xc4203e6240)
Jun 11 19:08:52 ceb30a9 balenad[703]: ,         0x0/usr/lib/go/src/runtime/proc.go, :0x02493)
Jun 11 19:08:52 ceb30a9 balenad[703]:  +        0x2da/yocto/resin-board/build/tmp/work/core2-64-poky-linux/balena/18.09.10-dev+git7cb464a406748016f2df0c31a9851d20456a3d31-r0/git/src/import/.gopath/src/github.com/docker/docker/cmd/dockerd/daemon.go
Jun 11 19:08:52 ceb30a9 balenad[703]: :runtime.park_m222( +0xc4200016800xb83)
Jun 11 19:08:52 ceb30a9 balenad[703]:         /usr/lib/go/src/runtime/proc.gogithub.com/docker/docker/cmd/dockerd.runDaemon:(26040xc4203e6240 +, 0xb60xc4207d4300
Jun 11 19:08:52 ceb30a9 balenad[703]: , runtime.mcall0x0()
Jun 11 19:08:52 ceb30a9 balenad[703]: 0x15d9300        )
Jun 11 19:08:52 ceb30a9 balenad[703]: /yocto/resin-board/build/tmp/work/core2-64-poky-linux/balena/18.09.10-dev+git7cb464a406748016f2df0c31a9851d20456a3d31-r0/git/src/import/.gopath/src/github.com/docker/docker/cmd/dockerd/docker_unix.go        :/usr/lib/go/src/runtime/asm_amd64.s7: +3510x45 +
Jun 11 19:08:52 ceb30a9 balenad[703]: 0x5b
Jun 11 19:08:52 ceb30a9 balenad[703]: github.com/docker/docker/cmd/dockerd.newDaemonCommand.func1
Jun 11 19:08:52 ceb30a9 balenad[703]: (goroutine 0xc42043c5001,  [0xc42043a500chan receive, , 0x09,  minutes0x14]:
Jun 11 19:08:52 ceb30a9 balenad[703]: , 0x0, 0x0)
Jun 11 19:08:52 ceb30a9 balenad[703]:         github.com/docker/docker/vendor/github.com/containerd/containerd/cmd/containerd/command.App.func1/yocto/resin-board/build/tmp/work/core2-64-poky-linux/balena/18.09.10-dev+git7cb464a406748016f2df0c31a9851d20456a3d31-r0/git/src/import/.gopath/src/github.com/docker/docker/cmd/dockerd/docker.go(:0xc42013c42029,  +0xc42013c4200x5b,
Jun 11 19:08:52 ceb30a9 balenad[703]: 0xc4205ebc77)
Jun 11 19:08:52 ceb30a9 balenad[703]:         /yocto/resin-board/build/tmp/work/core2-64-poky-linux/balena/18.09.10-dev+git7cb464a406748016f2df0c31a9851d20456a3d31-r0/git/src/import/.gopath/src/github.com/docker/docker/vendor/github.com/containerd/containerd/cmd/containerd/command/main.go:github.com/docker/docker/vendor/github.com/spf13/cobra.(*Command).execute199( +0xc42043c5000xa21,
Jun 11 19:08:52 ceb30a9 balenad[703]: 0xc42003a170, github.com/docker/docker/vendor/github.com/urfave/cli.HandleAction0x14(, 0x1747e000x15, 0x1af4248, , 0xc42043c5000xc42013c420, , 0xc42003a1700xc4200ae6c0)
Jun 11 19:08:52 ceb30a9 balenad[703]: ,         0x0/yocto/resin-board/build/tmp/work/core2-64-poky-linux/balena/18.09.10-dev+git7cb464a406748016f2df0c31a9851d20456a3d31-r0/git/src/import/.gopath/src/github.com/docker/docker/vendor/github.com/spf13/cobra/command.go)
Jun 11 19:08:52 ceb30a9 balenad[703]: :        762/yocto/resin-board/build/tmp/work/core2-64-poky-linux/balena/18.09.10-dev+git7cb464a406748016f2df0c31a9851d20456a3d31-r0/git/src/import/.gopath/src/github.com/docker/docker/vendor/github.com/urfave/cli/app.go +:0x468502

Hi, can you share some additional details like on what board you are running this and what OS version? Want to run this through the person maintaining the balena engine and check if this rings any bell

Hi, one more thing: could you also check the diagnostics page for this device, run its health checks and let us know if anything is failing? If those turn out to be all green, can you then try running the full device diagnostics and sending us the output of that?

This is running on an Intel NUC. Host OS Version is balenaOS 2.47.1+rev1 development version. Severel health checks failed.

  • Container engine balena is NOT
  • Some networking issues detected:
    test_upstream_dns: DNS lookup failed for 0.resinio.pool.ntp.org via upstream: 10.10.9.1
    test_upstream_dns: DNS lookup failed for 0.resinio.pool.ntp.org via upstream: 10.10.9.2
    test_dockerhub: Could not query Docker Hub
    test_balena_registry: Could not communicate with registry2.balena-cloud.com for authentication
  • Supervisor is NOT running (unmatched local and remote Supervisor versions)
  • Time is not being synchronized via NTP

We did switch it from one project to another and it has been coming in and out of local mode.

Anything make sense from the health checks?

Hi,
this issue has been investigated further in a different (paid support) thread and discussed with […] . The last message was that […] was upgrading the device to a up to date OS and was going to report if that was successful . The conversation stopped there because we did not hear back.

I can’t seem to get to the old conversations on the support thread. The interface changed and I can’t see how to see past conversations.

Have you upgraded the device ? Maybe the person answering to […] might be able to help you about the status of the device and continue the conversation.

That person would be me, but I didn’t see any message about upgrading the device. I just searched my email, including the spam folder and didn’t find anything. Also can’t get to the conversation through the balena dashboard.

Unfortunately I do not have access to the client facing paid support interface so I can not guide you here. I will try to find someone for you who can help…

Last words from you were:

Yeah… like I said those didn’t have any issue at all
on Jun 16th, 2020 10:43

I’m upgrading the device now to the latest development os
on Jun 16th, 2020 10:44

the new UUID is 651ceed401cf7281acb65d30bf0e73bc

After which we asked you to report if you see further misbehavior…

Hi, I’m trying to get you back on track connected to our support agents, Could you email me at (email removed)?