`Error on docker event: InternalInconsistencyError: Expected supervised container to have name '<serviceName>_<imageId>_<releaseId>_<commit>', got: /$TEMPORARY_CONTAINER_NAME`

[cywang117]

trafficstars

Device type: raspberrypi4-64

Supervisor version: 13.1.1

Container stuck restarting and exiting with the following logs:

The service exit and service restart events log repeatedly, and the cause of that may be another issue not related to the Supervisor. The main bit that requires investigation is the InternalInconsistencyError which indicates something is not behaving as expected..

It may be possible to trigger this behavior by pushing a container that exits & restarts rapidly.

Apr 15 23:06:31 1934c68 3c8e646e80ab[1557]: [error]   Error on docker event: InternalInconsistencyError: Expected supervised container to have name '<serviceName>_<imageId>_<releaseId>_<commit>', got: /flamboyant_taussig
Apr 15 23:06:31 1934c68 3c8e646e80ab[1557]: [error]         at Function.fromDockerContainer (/usr/src/app/dist/app.js:10:832269)
Apr 15 23:06:31 1934c68 3c8e646e80ab[1557]: [error]       at getByDockerContainerId (/usr/src/app/dist/app.js:6:307112)
Apr 15 23:06:31 1934c68 3c8e646e80ab[1557]: [error]       at runMicrotasks (<anonymous>)
Apr 15 23:06:31 1934c68 3c8e646e80ab[1557]: [error]       at processTicksAndRejections (internal/process/task_queues.js:97:5)
Apr 15 23:06:31 1934c68 3c8e646e80ab[1557]: [error]       at async Stream.<anonymous> (/usr/src/app/dist/app.js:6:317107) InternalInconsistencyError: Expected supervised container to have name '<serviceName>_<imageId>_<releaseId>_<commit>', got: /flamboyant_taussig
Apr 15 23:06:31 1934c68 3c8e646e80ab[1557]: [error]       at Function.fromDockerContainer (/usr/src/app/dist/app.js:10:832269)
Apr 15 23:06:31 1934c68 3c8e646e80ab[1557]: [error]       at getByDockerContainerId (/usr/src/app/dist/app.js:6:307112)
Apr 15 23:06:31 1934c68 3c8e646e80ab[1557]: [error]       at runMicrotasks (<anonymous>)
Apr 15 23:06:31 1934c68 3c8e646e80ab[1557]: [error]       at processTicksAndRejections (internal/process/task_queues.js:97:5)
Apr 15 23:06:31 1934c68 3c8e646e80ab[1557]: [error]       at async Stream.<anonymous> (/usr/src/app/dist/app.js:6:317107)
Apr 15 23:07:19 1934c68 balenad[1557]: time="2022-04-15T23:07:19.167727385Z" level=warning msg="Configured runtime \"runc\" is deprecated and will be removed in the next release"
Apr 15 23:07:19 1934c68 balenad[1616]: time="2022-04-15T23:07:19.202680512Z" level=warning msg="runtime v1 is deprecated since containerd v1.4, consider using runtime v2"
Apr 15 23:07:19 1934c68 balenad[1616]: time="2022-04-15T23:07:19.206725552Z" level=info msg="shim balena-engine-containerd-shim started" address=/containerd-shim/1b99bb714a77c26c0f584949e5a464da663773d2e1080f615266634a6bdd29ee.sock debug=false pid=170880
Apr 15 23:07:19 1934c68 3c8e646e80ab[1557]: [event]   Event: Service restart {"service":{"appId":1751090,"serviceId":715860,"serviceName":"solmon","commit":"c44cf2c1e612468310695219e7caeebf","releaseId":2010423}}
Apr 15 23:07:21 1934c68 balenad[1616]: time="2022-04-15T23:07:21.019385010Z" level=info msg="shim reaped" id=beb85a59bfdc58c93a822e39c105c879aa2be9c2d6bbe047bd41bb34437e714b
Apr 15 23:07:21 1934c68 balenad[1557]: time="2022-04-15T23:07:21.028084325Z" level=info msg="ignoring event" container=beb85a59bfdc58c93a822e39c105c879aa2be9c2d6bbe047bd41bb34437e714b module=libcontainerd namespace=moby topic=/tasks/delete type="*events.TaskDelete"
Apr 15 23:07:21 1934c68 3c8e646e80ab[1557]: [event]   Event: Service exit {"service":{"appId":1751090,"serviceId":715860,"serviceName":"solmon","commit":"c44cf2c1e612468310695219e7caeebf","releaseId":2010423}}
Apr 15 23:07:47 1934c68 3c8e646e80ab[1557]: [info]    Healthcheck failure - At least ONE of the following conditions must be true:
Apr 15 23:07:47 1934c68 3c8e646e80ab[1557]: [info]              - No connectivityCheckEnabled   ? false
Apr 15 23:07:47 1934c68 3c8e646e80ab[1557]: [info]            - device state is disconnected  ? false
Apr 15 23:07:47 1934c68 3c8e646e80ab[1557]: [info]            - stateReportErrors less then 3 ? false
Apr 15 23:07:47 1934c68 3c8e646e80ab[1557]: [error]   Healthcheck failed
Apr 15 23:07:47 1934c68 3c8e646e80ab[1557]: [api]     GET /v1/healthy 500 - 9.223 ms

Source of error is in Service.fromDockerContainer

[jellyfish-bot]

[cywang117] This issue has attached support thread https://jel.ly.fish/3f4a1627-5bdf-45f3-b882-3c552280a1af

[majorz]

I've run across this issue as well with supervisor v13.1.3.

Customer attempted an OS upgrade and reported the device is staying in Rebooting mode on the dashboard. From the looks of it he has upgraded supervisor as well before attempting to upgrade the OS. When I looked into the supervisor logs I found repeatedly:

(node:1) UnhandledPromiseRejectionWarning: InternalInconsistencyError: Expected supervised container to have name '<serviceName>_<imageId>_<releaseId>_<commit>', got: /epic_wozniak
    at Function.fromDockerContainer (/usr/src/app/dist/app.js:10:832269)
    at /usr/src/app/dist/app.js:6:292713
    at processTicksAndRejections (internal/process/task_queues.js:97:5)
(node:1) UnhandledPromiseRejectionWarning: Unhandled promise rejection. This error originated either by throwing inside of an async function without a catch block, or by rejecting a promise which was not handled with .catch(). To terminate the node process on unhandled promise rejection, use the CLI flag `--unhandled-rejections=strict` (see https://nodejs.org/api/cli.html#cli_unhandled_rejections_mode). (rejection id: 1)

I checked with docker ps and found epic_wozniak and some other containers with similar autogenerated name. Those containers were 5 months old and have not been running for quite a while as well, so I assume those were some left-over containers caused by bugs in balenaEngine.

I cleaned those containers, restarted supervisor and afterwards the device started functioning again correctly.

I am not completely sure the original problem I investigated is related to the error, but at least on the surface it looked like that. The exception is unhandled and I assume that is a bug, so maybe although the generation of the exception is older, the code catching it is now changed in recent SV version.

[jellyfish-bot]

[majorz] This issue has attached support thread https://jel.ly.fish/2e3fcf44-a5de-4d2d-bfa7-ff2398578968

[jellyfish-bot]

[ja-ilija] This issue has attached support thread https://jel.ly.fish/aff55162-d9fd-43bc-90b8-cdbfbc77fe52