balenaOS 2.80.5+rev1, supervisor version 12.8.10 keeps rebooting.

gktl · July 1, 2021, 12:15am

I updated the OS recently and it keeps rebooting on several of my devices.

balenaOS 2.80.5+rev1
Supervisor version 12.8.10
Raspberry Pi 4 (using 64bit OS)

rcooke-warwick · July 1, 2021, 2:05pm

Do you see any messages hinting as to why the supervisor is restarting in the logs?

One thing you can try is the command journalctl --no-pager --no-hostname -n 200 -a -u balena-supervisor -u resin-supervisor in the Host OS to see if the logs from the supervisor give us any clues.

How frequently is the supervisor rebooting would you say?

gktl · July 1, 2021, 5:39pm

The devices reboots every couple of hours or so. Here are logs from two devices.

Device 1:

-- Logs begin at Thu 2021-07-01 13:07:59 UTC, end at Thu 2021-07-01 17:37:06 UTC. --
Jul 01 14:46:53 balena-supervisor[2103]: [debug]   Container log timestamp flush complete
Jul 01 14:47:28 balena-supervisor[2103]: [api]     GET /v1/healthy 200 - 13.125 ms
Jul 01 14:52:29 balena-supervisor[2103]: [api]     GET /v1/healthy 200 - 7.430 ms
Jul 01 14:56:53 balena-supervisor[2103]: [debug]   Attempting container log timestamp flush...
Jul 01 14:56:53 balena-supervisor[2103]: [debug]   Container log timestamp flush complete
Jul 01 14:57:29 balena-supervisor[2103]: [api]     GET /v1/healthy 200 - 8.904 ms
-- Reboot --
Jul 01 15:00:14 balena-supervisor[1910]: Error response from daemon: No such container: resin_supervisor
Jul 01 15:00:15 balena-supervisor[1928]: Error: No such container: resin_supervisor
Jul 01 15:00:15 balena-supervisor[1945]: balena_supervisor
Jul 01 15:00:15 balena-supervisor[1961]: active
Jul 01 15:00:18 balena-supervisor[1962]: Container config has not changed
-- Reboot --
Jul 01 15:02:30 balena-supervisor[2103]: [api]     GET /v1/healthy 200 - 5.897 ms
Jul 01 15:06:53 balena-supervisor[2103]: [debug]   Attempting container log timestamp flush...
Jul 01 15:06:53 balena-supervisor[2103]: [debug]   Container log timestamp flush complete
Jul 01 15:07:31 balena-supervisor[2103]: [api]     GET /v1/healthy 200 - 5.513 ms
Jul 01 15:12:31 balena-supervisor[2103]: [api]     GET /v1/healthy 200 - 5.025 ms
-- Reboot --
Jul 01 15:16:15 balena-supervisor[2154]: [info]    Supervisor v12.8.10 starting up...
Jul 01 15:16:15 balena-supervisor[2154]: [info]    Setting host to discoverable
Jul 01 15:16:15 balena-supervisor[2154]: [warn]    Invalid firewall mode: . Reverting to state: off
Jul 01 15:16:15 balena-supervisor[2154]: [info]    🔥 Applying firewall mode: off
Jul 01 15:16:15 balena-supervisor[2154]: [debug]   Starting logging infrastructure
Jul 01 15:16:15 balena-supervisor[2154]: [debug]   Performing database cleanup for container log timestamps
Jul 01 15:16:15 balena-supervisor[2154]: [info]    Starting firewall
Jul 01 15:16:15 balena-supervisor[2154]: [info]    Previous engine snapshot was not stored. Skipping cleanup.
Jul 01 15:16:15 balena-supervisor[2154]: [debug]   Handling of local mode switch is completed
Jul 01 15:16:15 balena-supervisor[2154]: (node:1) [DEP0005] DeprecationWarning: Buffer() is deprecated due to security and usability issues. Please use the Buffer.alloc(), Buffer.allocUnsafe(), or Buffer.from() methods instead.
Jul 01 15:16:15 balena-supervisor[2154]: [info]    API Binder bound to: https://api.balena-cloud.com/v6/
Jul 01 15:16:15 balena-supervisor[2154]: [debug]   Spawning journald with: chroot  /mnt/root journalctl -a -S 2021-07-01 15:06:40 -o json CONTAINER_ID_FULL=6e20e7ff8d9d3967d9dd13068e5e06e447f69d0203c2895837277e5955cdae03
Jul 01 15:16:15 balena-supervisor[2154]: [success] 🔥 Firewall mode applied
Jul 01 15:16:15 balena-supervisor[2154]: [debug]   Starting api binder
Jul 01 15:16:15 balena-supervisor[2154]: [event]   Event: Supervisor start {}
Jul 01 15:16:15 balena-supervisor[2154]: [debug]   Connectivity check enabled: true
Jul 01 15:16:15 balena-supervisor[2154]: [debug]   Starting periodic check for IP addresses
Jul 01 15:16:15 balena-supervisor[2154]: [info]    Reporting initial state, supervisor version and API info
Jul 01 15:16:15 balena-supervisor[2154]: [debug]   Skipping preloading
Jul 01 15:16:15 balena-supervisor[2154]: [info]    VPN connection is not active.
Jul 01 15:16:15 balena-supervisor[2154]: [info]    Waiting for connectivity...
Jul 01 15:16:15 balena-supervisor[2154]: [info]    Starting API server
Jul 01 15:16:15 balena-supervisor[2154]: [info]    Supervisor API successfully started on port 48484
Jul 01 15:16:15 balena-supervisor[2154]: [info]    Applying target state
Jul 01 15:16:15 balena-supervisor[2154]: [debug]   Ensuring device is provisioned
Jul 01 15:16:15 balena-supervisor[2154]: [debug]   Starting current state report
Jul 01 15:16:15 balena-supervisor[2154]: [debug]   Starting target state poll
Jul 01 15:16:15 balena-supervisor[2154]: [debug]   Spawning journald with: chroot  /mnt/root journalctl -a --follow -o json _SYSTEMD_UNIT=balena.service
Jul 01 15:16:17 balena-supervisor[2154]: [debug]   Finished applying target state
Jul 01 15:16:17 balena-supervisor[2154]: [success] Device state apply success
Jul 01 15:16:17 balena-supervisor[2154]: [info]    Applying target state
Jul 01 15:16:17 balena-supervisor[2154]: [debug]   Finished applying target state
Jul 01 15:16:17 balena-supervisor[2154]: [success] Device state apply success
Jul 01 15:16:35 balena-supervisor[2154]: [info]    VPN connection is active.
Jul 01 15:16:35 balena-supervisor[2154]: [info]    VPN connection is active.
Jul 01 15:16:35 balena-supervisor[2154]: [info]    VPN connection is active.
Jul 01 15:16:35 balena-supervisor[2154]: [info]    VPN connection is active.
Jul 01 15:16:35 balena-supervisor[2154]: [info]    Internet Connectivity: OK
Jul 01 15:21:12 balena-supervisor[2154]: [api]     GET /v1/healthy 200 - 21.957 ms
Jul 01 15:26:13 balena-supervisor[2154]: [api]     GET /v1/healthy 200 - 7.048 ms
Jul 01 15:26:14 balena-supervisor[2154]: [debug]   Attempting container log timestamp flush...
Jul 01 15:26:14 balena-supervisor[2154]: [debug]   Container log timestamp flush complete
Jul 01 15:31:14 balena-supervisor[2154]: [api]     GET /v1/healthy 200 - 18.030 ms
Jul 01 15:36:14 balena-supervisor[2154]: [debug]   Attempting container log timestamp flush...
Jul 01 15:36:14 balena-supervisor[2154]: [debug]   Container log timestamp flush complete
Jul 01 15:36:15 balena-supervisor[2154]: [api]     GET /v1/healthy 200 - 7.151 ms
Jul 01 15:41:15 balena-supervisor[2154]: [api]     GET /v1/healthy 200 - 5.173 ms
Jul 01 15:46:14 balena-supervisor[2154]: [debug]   Attempting container log timestamp flush...
Jul 01 15:46:14 balena-supervisor[2154]: [debug]   Container log timestamp flush complete
Jul 01 15:46:16 balena-supervisor[2154]: [api]     GET /v1/healthy 200 - 14.242 ms
Jul 01 15:51:17 balena-supervisor[2154]: [api]     GET /v1/healthy 200 - 7.805 ms
Jul 01 15:56:14 balena-supervisor[2154]: [debug]   Attempting container log timestamp flush...
Jul 01 15:56:14 balena-supervisor[2154]: [debug]   Container log timestamp flush complete
Jul 01 15:56:18 balena-supervisor[2154]: [api]     GET /v1/healthy 200 - 7.431 ms
-- Reboot --
Jul 01 16:00:12 balena-supervisor[1915]: Error response from daemon: No such container: resin_supervisor
Jul 01 16:00:12 balena-supervisor[1938]: Error: No such container: resin_supervisor
Jul 01 16:00:12 balena-supervisor[1950]: balena_supervisor
Jul 01 16:00:12 balena-supervisor[1965]: active
Jul 01 16:00:15 balena-supervisor[1972]: Container config has not changed
-- Reboot --
Jul 01 16:01:18 balena-supervisor[2154]: [api]     GET /v1/healthy 200 - 16.060 ms
-- Reboot --
Jul 01 16:05:12 balena-supervisor[2142]: [info]    Supervisor v12.8.10 starting up...
Jul 01 16:05:12 balena-supervisor[2142]: [info]    Setting host to discoverable
Jul 01 16:05:12 balena-supervisor[2142]: [warn]    Invalid firewall mode: . Reverting to state: off
Jul 01 16:05:12 balena-supervisor[2142]: [info]    🔥 Applying firewall mode: off
Jul 01 16:05:12 balena-supervisor[2142]: [debug]   Starting logging infrastructure
Jul 01 16:05:12 balena-supervisor[2142]: [debug]   Performing database cleanup for container log timestamps
Jul 01 16:05:12 balena-supervisor[2142]: [info]    Starting firewall
Jul 01 16:05:12 balena-supervisor[2142]: [info]    Previous engine snapshot was not stored. Skipping cleanup.
Jul 01 16:05:12 balena-supervisor[2142]: [debug]   Handling of local mode switch is completed
Jul 01 16:05:12 balena-supervisor[2142]: (node:1) [DEP0005] DeprecationWarning: Buffer() is deprecated due to security and usability issues. Please use the Buffer.alloc(), Buffer.allocUnsafe(), or Buffer.from() methods instead.
Jul 01 16:05:12 balena-supervisor[2142]: [info]    API Binder bound to: https://api.balena-cloud.com/v6/
Jul 01 16:05:12 balena-supervisor[2142]: [debug]   Spawning journald with: chroot  /mnt/root journalctl -a -S 2021-07-01 15:55:59 -o json CONTAINER_ID_FULL=6e20e7ff8d9d3967d9dd13068e5e06e447f69d0203c2895837277e5955cdae03
Jul 01 16:05:12 balena-supervisor[2142]: [success] 🔥 Firewall mode applied
Jul 01 16:05:12 balena-supervisor[2142]: [debug]   Starting api binder
Jul 01 16:05:12 balena-supervisor[2142]: [event]   Event: Supervisor start {}
Jul 01 16:05:12 balena-supervisor[2142]: [debug]   Connectivity check enabled: true
Jul 01 16:05:12 balena-supervisor[2142]: [debug]   Starting periodic check for IP addresses
Jul 01 16:05:12 balena-supervisor[2142]: [info]    Reporting initial state, supervisor version and API info
Jul 01 16:05:12 balena-supervisor[2142]: [debug]   Skipping preloading
Jul 01 16:05:12 balena-supervisor[2142]: [info]    VPN connection is not active.
Jul 01 16:05:12 balena-supervisor[2142]: [info]    Waiting for connectivity...
Jul 01 16:05:12 balena-supervisor[2142]: [info]    Starting API server
Jul 01 16:05:12 balena-supervisor[2142]: [info]    Supervisor API successfully started on port 48484
Jul 01 16:05:12 balena-supervisor[2142]: [info]    Applying target state
Jul 01 16:05:12 balena-supervisor[2142]: [debug]   Ensuring device is provisioned
Jul 01 16:05:12 balena-supervisor[2142]: [debug]   Starting current state report
Jul 01 16:05:12 balena-supervisor[2142]: [debug]   Starting target state poll
Jul 01 16:05:12 balena-supervisor[2142]: [debug]   Spawning journald with: chroot  /mnt/root journalctl -a --follow -o json _SYSTEMD_UNIT=balena.service
Jul 01 16:05:13 balena-supervisor[2142]: [debug]   Finished applying target state
Jul 01 16:05:13 balena-supervisor[2142]: [success] Device state apply success
Jul 01 16:05:14 balena-supervisor[2142]: [info]    Applying target state
Jul 01 16:05:14 balena-supervisor[2142]: [debug]   Finished applying target state
Jul 01 16:05:14 balena-supervisor[2142]: [success] Device state apply success
Jul 01 16:05:15 balena-supervisor[2142]: [info]    VPN connection is active.
Jul 01 16:05:15 balena-supervisor[2142]: [info]    VPN connection is active.
Jul 01 16:05:15 balena-supervisor[2142]: [info]    VPN connection is active.
Jul 01 16:05:15 balena-supervisor[2142]: [info]    VPN connection is active.
Jul 01 16:05:22 balena-supervisor[2142]: [info]    Internet Connectivity: OK
Jul 01 16:05:53 balena-supervisor[2142]: [event]   Event: Device state report failure {"error":{"message":""}}
Jul 01 16:10:10 balena-supervisor[2142]: [api]     GET /v1/healthy 200 - 20.919 ms
Jul 01 16:15:10 balena-supervisor[2142]: [api]     GET /v1/healthy 200 - 11.143 ms
Jul 01 16:15:11 balena-supervisor[2142]: [debug]   Attempting container log timestamp flush...
Jul 01 16:15:11 balena-supervisor[2142]: [debug]   Container log timestamp flush complete
Jul 01 16:20:11 balena-supervisor[2142]: [api]     GET /v1/healthy 200 - 12.671 ms
Jul 01 16:25:11 balena-supervisor[2142]: [debug]   Attempting container log timestamp flush...
Jul 01 16:25:11 balena-supervisor[2142]: [debug]   Container log timestamp flush complete
Jul 01 16:25:12 balena-supervisor[2142]: [api]     GET /v1/healthy 200 - 19.236 ms
Jul 01 16:30:13 balena-supervisor[2142]: [api]     GET /v1/healthy 200 - 11.828 ms
Jul 01 16:35:11 balena-supervisor[2142]: [debug]   Attempting container log timestamp flush...
Jul 01 16:35:11 balena-supervisor[2142]: [debug]   Container log timestamp flush complete
Jul 01 16:35:13 balena-supervisor[2142]: [api]     GET /v1/healthy 200 - 8.877 ms
Jul 01 16:40:14 balena-supervisor[2142]: [api]     GET /v1/healthy 200 - 15.699 ms
Jul 01 16:45:11 balena-supervisor[2142]: [debug]   Attempting container log timestamp flush...
Jul 01 16:45:11 balena-supervisor[2142]: [debug]   Container log timestamp flush complete
Jul 01 16:45:15 balena-supervisor[2142]: [api]     GET /v1/healthy 200 - 15.415 ms
Jul 01 16:50:16 balena-supervisor[2142]: [api]     GET /v1/healthy 200 - 9.090 ms
Jul 01 16:55:11 balena-supervisor[2142]: [debug]   Attempting container log timestamp flush...
Jul 01 16:55:11 balena-supervisor[2142]: [debug]   Container log timestamp flush complete
Jul 01 16:55:16 balena-supervisor[2142]: [api]     GET /v1/healthy 200 - 9.513 ms
Jul 01 17:00:04 balena-supervisor[2142]: [error]   Error from the API: 503
Jul 01 17:00:04 balena-supervisor[2142]: [error]   Non-200 response from the API! Status code: 503 - message: Error: "The API cannot handle your request right now"
Jul 01 17:00:04 balena-supervisor[2142]: [error]         at sendReportPatch (/usr/src/app/dist/app.js:22:642937)
Jul 01 17:00:04 balena-supervisor[2142]: [error]       at runMicrotasks (<anonymous>)
Jul 01 17:00:04 balena-supervisor[2142]: [error]       at processTicksAndRejections (internal/process/task_queues.js:97:5)
Jul 01 17:00:04 balena-supervisor[2142]: [error]       at async /usr/src/app/dist/app.js:22:644023
Jul 01 17:00:04 balena-supervisor[2142]: [error]       at async /usr/src/app/dist/app.js:22:644931
-- Reboot --
Jul 01 17:00:13 balena-supervisor[1906]: Error response from daemon: No such container: resin_supervisor
Jul 01 17:00:13 balena-supervisor[1930]: Error: No such container: resin_supervisor
Jul 01 17:00:13 balena-supervisor[1946]: balena_supervisor
Jul 01 17:00:13 balena-supervisor[1962]: active
Jul 01 17:00:16 balena-supervisor[1963]: Container config has not changed
-- Reboot --
Jul 01 17:00:17 balena-supervisor[2142]: [api]     GET /v1/healthy 200 - 14.906 ms
Jul 01 17:05:11 balena-supervisor[2142]: [debug]   Attempting container log timestamp flush...
Jul 01 17:05:11 balena-supervisor[2142]: [debug]   Container log timestamp flush complete
Jul 01 17:05:18 balena-supervisor[2142]: [api]     GET /v1/healthy 200 - 7.310 ms
Jul 01 17:10:18 balena-supervisor[2142]: [api]     GET /v1/healthy 200 - 7.543 ms
Jul 01 17:15:11 balena-supervisor[2142]: [debug]   Attempting container log timestamp flush...
Jul 01 17:15:11 balena-supervisor[2142]: [debug]   Container log timestamp flush complete
Jul 01 17:15:19 balena-supervisor[2142]: [api]     GET /v1/healthy 200 - 11.617 ms
Jul 01 17:20:20 balena-supervisor[2142]: [api]     GET /v1/healthy 200 - 13.643 ms
Jul 01 17:25:11 balena-supervisor[2142]: [debug]   Attempting container log timestamp flush...
Jul 01 17:25:11 balena-supervisor[2142]: [debug]   Container log timestamp flush complete
Jul 01 17:25:21 balena-supervisor[2142]: [api]     GET /v1/healthy 200 - 12.845 ms
Jul 01 17:30:21 balena-supervisor[2142]: [api]     GET /v1/healthy 200 - 11.973 ms
Jul 01 17:30:47 balena-supervisor[2142]: [api]     GET /v1/healthy 200 - 4.332 ms
-- Reboot --
Jul 01 17:34:00 balena-supervisor[2142]: [info]    Supervisor v12.8.10 starting up...
Jul 01 17:34:00 balena-supervisor[2142]: [info]    Setting host to discoverable
Jul 01 17:34:00 balena-supervisor[2142]: [warn]    Invalid firewall mode: . Reverting to state: off
Jul 01 17:34:00 balena-supervisor[2142]: [info]    🔥 Applying firewall mode: off
Jul 01 17:34:00 balena-supervisor[2142]: [debug]   Starting logging infrastructure
Jul 01 17:34:00 balena-supervisor[2142]: [debug]   Performing database cleanup for container log timestamps
Jul 01 17:34:00 balena-supervisor[2142]: [info]    Starting firewall
Jul 01 17:34:00 balena-supervisor[2142]: [info]    Previous engine snapshot was not stored. Skipping cleanup.
Jul 01 17:34:00 balena-supervisor[2142]: [debug]   Handling of local mode switch is completed
Jul 01 17:34:00 balena-supervisor[2142]: (node:1) [DEP0005] DeprecationWarning: Buffer() is deprecated due to security and usability issues. Please use the Buffer.alloc(), Buffer.allocUnsafe(), or Buffer.from() methods instead.
Jul 01 17:34:00 balena-supervisor[2142]: [info]    API Binder bound to: https://api.balena-cloud.com/v6/
Jul 01 17:34:00 balena-supervisor[2142]: [debug]   Spawning journald with: chroot  /mnt/root journalctl -a -S 2021-07-01 17:25:10 -o json CONTAINER_ID_FULL=6e20e7ff8d9d3967d9dd13068e5e06e447f69d0203c2895837277e5955cdae03
Jul 01 17:34:00 balena-supervisor[2142]: [success] 🔥 Firewall mode applied
Jul 01 17:34:00 balena-supervisor[2142]: [debug]   Starting api binder
Jul 01 17:34:00 balena-supervisor[2142]: [event]   Event: Supervisor start {}
Jul 01 17:34:00 balena-supervisor[2142]: [debug]   Connectivity check enabled: true
Jul 01 17:34:00 balena-supervisor[2142]: [debug]   Starting periodic check for IP addresses
Jul 01 17:34:00 balena-supervisor[2142]: [info]    Reporting initial state, supervisor version and API info
Jul 01 17:34:00 balena-supervisor[2142]: [debug]   Skipping preloading
Jul 01 17:34:00 balena-supervisor[2142]: [info]    VPN connection is not active.
Jul 01 17:34:00 balena-supervisor[2142]: [info]    Waiting for connectivity...
Jul 01 17:34:01 balena-supervisor[2142]: [info]    Starting API server
Jul 01 17:34:01 balena-supervisor[2142]: [info]    Supervisor API successfully started on port 48484
Jul 01 17:34:01 balena-supervisor[2142]: [info]    Applying target state
Jul 01 17:34:01 balena-supervisor[2142]: [debug]   Ensuring device is provisioned
Jul 01 17:34:01 balena-supervisor[2142]: [debug]   Starting current state report
Jul 01 17:34:01 balena-supervisor[2142]: [debug]   Starting target state poll
Jul 01 17:34:01 balena-supervisor[2142]: [debug]   Spawning journald with: chroot  /mnt/root journalctl -a --follow -o json _SYSTEMD_UNIT=balena.service
Jul 01 17:34:02 balena-supervisor[2142]: [debug]   Finished applying target state
Jul 01 17:34:02 balena-supervisor[2142]: [success] Device state apply success
Jul 01 17:34:02 balena-supervisor[2142]: [info]    Applying target state
Jul 01 17:34:02 balena-supervisor[2142]: [info]    VPN connection is active.
Jul 01 17:34:02 balena-supervisor[2142]: [info]    VPN connection is active.
Jul 01 17:34:02 balena-supervisor[2142]: [info]    VPN connection is active.
Jul 01 17:34:02 balena-supervisor[2142]: [debug]   Finished applying target state
Jul 01 17:34:02 balena-supervisor[2142]: [success] Device state apply success
Jul 01 17:34:10 balena-supervisor[2142]: [info]    Internet Connectivity: OK
Jul 01 17:35:03 balena-supervisor[2142]: [api]     GET /v1/device 200 - 85.870 ms
Jul 01 17:35:18 balena-supervisor[2142]: [api]     GET /v1/healthy 200 - 11.932 ms

gktl · July 1, 2021, 5:40pm

Device 2:

-- Logs begin at Thu 2021-07-01 09:15:46 UTC, end at Thu 2021-07-01 17:38:04 UTC. --
Jul 01 14:29:32 balena-supervisor[2136]: [debug]   Attempting container log timestamp flush...
Jul 01 14:29:32 balena-supervisor[2136]: [debug]   Container log timestamp flush complete
Jul 01 14:30:57 balena-supervisor[2136]: [api]     GET /v1/healthy 200 - 4.455 ms
Jul 01 14:35:58 balena-supervisor[2136]: [api]     GET /v1/healthy 200 - 8.276 ms
Jul 01 14:39:32 balena-supervisor[2136]: [debug]   Attempting container log timestamp flush...
Jul 01 14:39:32 balena-supervisor[2136]: [debug]   Container log timestamp flush complete
Jul 01 14:40:59 balena-supervisor[2136]: [api]     GET /v1/healthy 200 - 5.328 ms
Jul 01 14:45:59 balena-supervisor[2136]: [api]     GET /v1/healthy 200 - 6.901 ms
Jul 01 14:49:32 balena-supervisor[2136]: [debug]   Attempting container log timestamp flush...
Jul 01 14:49:32 balena-supervisor[2136]: [debug]   Container log timestamp flush complete
Jul 01 14:51:00 balena-supervisor[2136]: [api]     GET /v1/healthy 200 - 8.199 ms
Jul 01 14:56:01 balena-supervisor[2136]: [api]     GET /v1/healthy 200 - 10.260 ms
Jul 01 14:59:32 balena-supervisor[2136]: [debug]   Attempting container log timestamp flush...
Jul 01 14:59:32 balena-supervisor[2136]: [debug]   Container log timestamp flush complete
Jul 01 15:01:02 balena-supervisor[2136]: [api]     GET /v1/healthy 200 - 4.352 ms
Jul 01 15:06:02 balena-supervisor[2136]: [api]     GET /v1/healthy 200 - 9.145 ms
Jul 01 15:09:32 balena-supervisor[2136]: [debug]   Attempting container log timestamp flush...
Jul 01 15:09:32 balena-supervisor[2136]: [debug]   Container log timestamp flush complete
Jul 01 15:11:03 balena-supervisor[2136]: [api]     GET /v1/healthy 200 - 6.976 ms
Jul 01 15:16:04 balena-supervisor[2136]: [api]     GET /v1/healthy 200 - 10.118 ms
Jul 01 15:19:32 balena-supervisor[2136]: [debug]   Attempting container log timestamp flush...
Jul 01 15:19:32 balena-supervisor[2136]: [debug]   Container log timestamp flush complete
Jul 01 15:21:04 balena-supervisor[2136]: [api]     GET /v1/healthy 200 - 7.809 ms
Jul 01 15:26:05 balena-supervisor[2136]: [api]     GET /v1/healthy 200 - 12.012 ms
Jul 01 15:29:32 balena-supervisor[2136]: [debug]   Attempting container log timestamp flush...
Jul 01 15:29:32 balena-supervisor[2136]: [debug]   Container log timestamp flush complete
Jul 01 15:31:06 balena-supervisor[2136]: [api]     GET /v1/healthy 200 - 7.652 ms
Jul 01 15:36:07 balena-supervisor[2136]: [api]     GET /v1/healthy 200 - 10.286 ms
Jul 01 15:39:32 balena-supervisor[2136]: [debug]   Attempting container log timestamp flush...
Jul 01 15:39:32 balena-supervisor[2136]: [debug]   Container log timestamp flush complete
Jul 01 15:41:07 balena-supervisor[2136]: [api]     GET /v1/healthy 200 - 4.085 ms
Jul 01 15:46:08 balena-supervisor[2136]: [api]     GET /v1/healthy 200 - 12.213 ms
Jul 01 15:49:32 balena-supervisor[2136]: [debug]   Attempting container log timestamp flush...
Jul 01 15:49:32 balena-supervisor[2136]: [debug]   Container log timestamp flush complete
Jul 01 15:51:09 balena-supervisor[2136]: [api]     GET /v1/healthy 200 - 9.203 ms
Jul 01 15:56:09 balena-supervisor[2136]: [api]     GET /v1/healthy 200 - 12.244 ms
Jul 01 15:59:32 balena-supervisor[2136]: [debug]   Attempting container log timestamp flush...
Jul 01 15:59:32 balena-supervisor[2136]: [debug]   Container log timestamp flush complete
-- Reboot --
Jul 01 16:00:10 balena-supervisor[1906]: Error response from daemon: No such container: resin_supervisor
Jul 01 16:00:10 balena-supervisor[1928]: Error: No such container: resin_supervisor
Jul 01 16:00:10 balena-supervisor[1944]: balena_supervisor
Jul 01 16:00:10 balena-supervisor[1962]: active
-- Reboot --
Jul 01 16:00:11 balena-supervisor[1907]: Error response from daemon: No such container: resin_supervisor
Jul 01 16:00:12 balena-supervisor[1923]: Error: No such container: resin_supervisor
Jul 01 16:00:12 balena-supervisor[1941]: balena_supervisor
Jul 01 16:00:12 balena-supervisor[1956]: active
-- Reboot --
Jul 01 16:00:13 balena-supervisor[1963]: Container config has not changed
-- Reboot --
Jul 01 16:00:15 balena-supervisor[1957]: Container config has not changed
-- Reboot --
Jul 01 16:01:10 balena-supervisor[2136]: [api]     GET /v1/healthy 200 - 4.959 ms
-- Reboot --
Jul 01 16:02:25 balena-supervisor[2125]: [info]    Supervisor v12.8.10 starting up...
Jul 01 16:02:25 balena-supervisor[2125]: [info]    Setting host to discoverable
Jul 01 16:02:25 balena-supervisor[2125]: [warn]    Invalid firewall mode: . Reverting to state: off
Jul 01 16:02:25 balena-supervisor[2125]: [info]    🔥 Applying firewall mode: off
Jul 01 16:02:25 balena-supervisor[2125]: [debug]   Starting logging infrastructure
Jul 01 16:02:25 balena-supervisor[2125]: [debug]   Performing database cleanup for container log timestamps
Jul 01 16:02:25 balena-supervisor[2125]: [info]    Starting firewall
Jul 01 16:02:25 balena-supervisor[2125]: [info]    Previous engine snapshot was not stored. Skipping cleanup.
Jul 01 16:02:25 balena-supervisor[2125]: [debug]   Handling of local mode switch is completed
Jul 01 16:02:25 balena-supervisor[2125]: (node:1) [DEP0005] DeprecationWarning: Buffer() is deprecated due to security and usability issues. Please use the Buffer.alloc(), Buffer.allocUnsafe(), or Buffer.from() methods instead.
Jul 01 16:02:25 balena-supervisor[2125]: [info]    API Binder bound to: https://api.balena-cloud.com/v6/
Jul 01 16:02:25 balena-supervisor[2125]: [debug]   Spawning journald with: chroot  /mnt/root journalctl -a -S 2021-07-01 15:59:29 -o json CONTAINER_ID_FULL=2cd223e04a35714b9ac36d3ac6abf6aa80f6bcef7e512bc52eba2fc4a84362ac
Jul 01 16:02:25 balena-supervisor[2125]: [success] 🔥 Firewall mode applied
Jul 01 16:02:25 balena-supervisor[2125]: [debug]   Starting api binder
Jul 01 16:02:25 balena-supervisor[2125]: [event]   Event: Supervisor start {}
Jul 01 16:02:25 balena-supervisor[2125]: [debug]   Connectivity check enabled: true
Jul 01 16:02:25 balena-supervisor[2125]: [debug]   Starting periodic check for IP addresses
Jul 01 16:02:25 balena-supervisor[2125]: [info]    Reporting initial state, supervisor version and API info
Jul 01 16:02:25 balena-supervisor[2125]: [debug]   Skipping preloading
Jul 01 16:02:25 balena-supervisor[2125]: [info]    VPN connection is not active.
Jul 01 16:02:25 balena-supervisor[2125]: [info]    Waiting for connectivity...
Jul 01 16:02:25 balena-supervisor[2125]: [info]    Starting API server
Jul 01 16:02:25 balena-supervisor[2125]: [info]    Supervisor API successfully started on port 48484
Jul 01 16:02:25 balena-supervisor[2125]: [info]    Applying target state
Jul 01 16:02:25 balena-supervisor[2125]: [debug]   Ensuring device is provisioned
Jul 01 16:02:26 balena-supervisor[2125]: [debug]   Starting current state report
Jul 01 16:02:26 balena-supervisor[2125]: [debug]   Starting target state poll
Jul 01 16:02:26 balena-supervisor[2125]: [debug]   Spawning journald with: chroot  /mnt/root journalctl -a --follow -o json _SYSTEMD_UNIT=balena.service
Jul 01 16:02:27 balena-supervisor[2125]: [debug]   Finished applying target state
Jul 01 16:02:27 balena-supervisor[2125]: [success] Device state apply success
Jul 01 16:02:27 balena-supervisor[2125]: [info]    Applying target state
Jul 01 16:02:27 balena-supervisor[2125]: [debug]   Finished applying target state
Jul 01 16:02:27 balena-supervisor[2125]: [success] Device state apply success
Jul 01 16:02:28 balena-supervisor[2125]: [info]    VPN connection is active.
Jul 01 16:02:28 balena-supervisor[2125]: [info]    VPN connection is active.
Jul 01 16:02:28 balena-supervisor[2125]: [info]    VPN connection is active.
Jul 01 16:02:28 balena-supervisor[2125]: [info]    VPN connection is active.
Jul 01 16:02:35 balena-supervisor[2125]: [info]    Internet Connectivity: OK
Jul 01 16:07:22 balena-supervisor[2125]: [api]     GET /v1/healthy 200 - 21.710 ms
Jul 01 16:12:23 balena-supervisor[2125]: [api]     GET /v1/healthy 200 - 9.352 ms
Jul 01 16:12:24 balena-supervisor[2125]: [debug]   Attempting container log timestamp flush...
Jul 01 16:12:24 balena-supervisor[2125]: [debug]   Container log timestamp flush complete
Jul 01 16:16:56 balena-supervisor[2125]: (node:1) UnhandledPromiseRejectionWarning: Error: ETIMEDOUT
Jul 01 16:16:56 balena-supervisor[2125]:     at Timeout.<anonymous> (/usr/src/app/dist/app.js:10:1664782)
Jul 01 16:16:56 balena-supervisor[2125]:     at listOnTimeout (internal/timers.js:549:17)
Jul 01 16:16:56 balena-supervisor[2125]:     at processTimers (internal/timers.js:492:7)
Jul 01 16:16:56 balena-supervisor[2125]: (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)
Jul 01 16:16:56 balena-supervisor[2125]: (node:1) [DEP0018] DeprecationWarning: Unhandled promise rejections are deprecated. In the future, promise rejections that are not handled will terminate the Node.js process with a non-zero exit code.
Jul 01 16:17:23 balena-supervisor[2125]: [api]     GET /v1/healthy 200 - 10.877 ms
Jul 01 16:17:26 balena-supervisor[2125]: (node:1) UnhandledPromiseRejectionWarning: Error: ETIMEDOUT
Jul 01 16:17:26 balena-supervisor[2125]:     at Timeout.<anonymous> (/usr/src/app/dist/app.js:10:1664782)
Jul 01 16:17:26 balena-supervisor[2125]:     at listOnTimeout (internal/timers.js:549:17)
Jul 01 16:17:26 balena-supervisor[2125]:     at processTimers (internal/timers.js:492:7)
Jul 01 16:17:26 balena-supervisor[2125]: (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: 2)
Jul 01 16:17:56 balena-supervisor[2125]: [event]   Event: Device state report failure {"error":{"message":""}}
Jul 01 16:20:16 balena-supervisor[2125]: [event]   Event: Device state report failure {"error":{"message":""}}
Jul 01 16:22:24 balena-supervisor[2125]: [debug]   Attempting container log timestamp flush...
Jul 01 16:22:24 balena-supervisor[2125]: [api]     GET /v1/healthy 200 - 15.563 ms
Jul 01 16:22:24 balena-supervisor[2125]: [debug]   Container log timestamp flush complete
Jul 01 16:23:16 balena-supervisor[2125]: (node:1) UnhandledPromiseRejectionWarning: Error: ETIMEDOUT
Jul 01 16:23:16 balena-supervisor[2125]:     at Timeout.<anonymous> (/usr/src/app/dist/app.js:10:1664782)
Jul 01 16:23:16 balena-supervisor[2125]:     at listOnTimeout (internal/timers.js:549:17)
Jul 01 16:23:16 balena-supervisor[2125]:     at processTimers (internal/timers.js:492:7)
Jul 01 16:23:16 balena-supervisor[2125]: (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: 3)
Jul 01 16:24:09 balena-supervisor[2125]: [info]    VPN connection is not active.
Jul 01 16:24:16 balena-supervisor[2125]: [info]    Waiting for connectivity...
Jul 01 16:24:16 balena-supervisor[2125]: [info]    VPN connection is active.
Jul 01 16:24:16 balena-supervisor[2125]: [info]    VPN connection is active.
Jul 01 16:24:16 balena-supervisor[2125]: [info]    VPN connection is active.
Jul 01 16:24:16 balena-supervisor[2125]: [info]    VPN connection is active.
Jul 01 16:24:16 balena-supervisor[2125]: [info]    VPN connection is not active.
Jul 01 16:25:35 balena-supervisor[2125]: [info]    VPN connection is active.
Jul 01 16:25:35 balena-supervisor[2125]: [info]    VPN connection is active.
Jul 01 16:25:35 balena-supervisor[2125]: [info]    VPN connection is active.
Jul 01 16:25:36 balena-supervisor[2125]: [info]    Internet Connectivity: OK
Jul 01 16:27:06 balena-supervisor[2125]: (node:1) UnhandledPromiseRejectionWarning: Error: ETIMEDOUT
Jul 01 16:27:06 balena-supervisor[2125]:     at Timeout.<anonymous> (/usr/src/app/dist/app.js:10:1664782)
Jul 01 16:27:06 balena-supervisor[2125]:     at listOnTimeout (internal/timers.js:549:17)
Jul 01 16:27:06 balena-supervisor[2125]:     at processTimers (internal/timers.js:492:7)
Jul 01 16:27:06 balena-supervisor[2125]: (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: 4)
Jul 01 16:27:25 balena-supervisor[2125]: [api]     GET /v1/healthy 200 - 10.617 ms
Jul 01 16:28:26 balena-supervisor[2125]: [event]   Event: Device state report failure {"error":{"message":""}}
Jul 01 16:31:16 balena-supervisor[2125]: [event]   Event: Device state report failure {"error":{"message":""}}
Jul 01 16:32:24 balena-supervisor[2125]: [debug]   Attempting container log timestamp flush...
Jul 01 16:32:24 balena-supervisor[2125]: [debug]   Container log timestamp flush complete
Jul 01 16:32:26 balena-supervisor[2125]: [api]     GET /v1/healthy 200 - 19.824 ms
Jul 01 16:37:26 balena-supervisor[2125]: [api]     GET /v1/healthy 200 - 10.973 ms
Jul 01 16:42:24 balena-supervisor[2125]: [debug]   Attempting container log timestamp flush...
Jul 01 16:42:24 balena-supervisor[2125]: [debug]   Container log timestamp flush complete
Jul 01 16:42:27 balena-supervisor[2125]: [api]     GET /v1/healthy 200 - 10.910 ms
-- Reboot --
Jul 01 16:44:35 balena-supervisor[2136]: [info]    Supervisor v12.8.10 starting up...
Jul 01 16:44:35 balena-supervisor[2136]: [info]    Setting host to discoverable
Jul 01 16:44:35 balena-supervisor[2136]: [warn]    Invalid firewall mode: . Reverting to state: off
Jul 01 16:44:35 balena-supervisor[2136]: [info]    🔥 Applying firewall mode: off
Jul 01 16:44:35 balena-supervisor[2136]: [debug]   Starting logging infrastructure
Jul 01 16:44:35 balena-supervisor[2136]: [debug]   Performing database cleanup for container log timestamps
Jul 01 16:44:35 balena-supervisor[2136]: [info]    Starting firewall
Jul 01 16:44:35 balena-supervisor[2136]: [info]    Previous engine snapshot was not stored. Skipping cleanup.
Jul 01 16:44:35 balena-supervisor[2136]: [debug]   Handling of local mode switch is completed
Jul 01 16:44:35 balena-supervisor[2136]: (node:1) [DEP0005] DeprecationWarning: Buffer() is deprecated due to security and usability issues. Please use the Buffer.alloc(), Buffer.allocUnsafe(), or Buffer.from() methods instead.
Jul 01 16:44:35 balena-supervisor[2136]: [info]    API Binder bound to: https://api.balena-cloud.com/v6/
Jul 01 16:44:35 balena-supervisor[2136]: [debug]   Spawning journald with: chroot  /mnt/root journalctl -a -S 2021-07-01 16:42:09 -o json CONTAINER_ID_FULL=2cd223e04a35714b9ac36d3ac6abf6aa80f6bcef7e512bc52eba2fc4a84362ac
Jul 01 16:44:35 balena-supervisor[2136]: [success] 🔥 Firewall mode applied
Jul 01 16:44:35 balena-supervisor[2136]: [debug]   Starting api binder
Jul 01 16:44:35 balena-supervisor[2136]: [event]   Event: Supervisor start {}
Jul 01 16:44:35 balena-supervisor[2136]: [debug]   Connectivity check enabled: true
Jul 01 16:44:35 balena-supervisor[2136]: [debug]   Starting periodic check for IP addresses
Jul 01 16:44:35 balena-supervisor[2136]: [info]    Reporting initial state, supervisor version and API info
Jul 01 16:44:35 balena-supervisor[2136]: [debug]   Skipping preloading
Jul 01 16:44:35 balena-supervisor[2136]: [info]    VPN connection is not active.
Jul 01 16:44:35 balena-supervisor[2136]: [info]    Waiting for connectivity...
Jul 01 16:44:35 balena-supervisor[2136]: [info]    Starting API server
Jul 01 16:44:35 balena-supervisor[2136]: [info]    Supervisor API successfully started on port 48484
Jul 01 16:44:35 balena-supervisor[2136]: [info]    Applying target state
Jul 01 16:44:35 balena-supervisor[2136]: [debug]   Ensuring device is provisioned
Jul 01 16:44:36 balena-supervisor[2136]: [debug]   Starting current state report
Jul 01 16:44:36 balena-supervisor[2136]: [debug]   Starting target state poll
Jul 01 16:44:36 balena-supervisor[2136]: [debug]   Spawning journald with: chroot  /mnt/root journalctl -a --follow -o json _SYSTEMD_UNIT=balena.service
Jul 01 16:44:37 balena-supervisor[2136]: [debug]   Finished applying target state
Jul 01 16:44:37 balena-supervisor[2136]: [success] Device state apply success
Jul 01 16:44:37 balena-supervisor[2136]: [info]    Applying target state
Jul 01 16:44:37 balena-supervisor[2136]: [debug]   Finished applying target state
Jul 01 16:44:37 balena-supervisor[2136]: [success] Device state apply success
Jul 01 16:45:36 balena-supervisor[2136]: [info]    VPN connection is active.
Jul 01 16:45:36 balena-supervisor[2136]: [info]    VPN connection is active.
Jul 01 16:45:36 balena-supervisor[2136]: [info]    VPN connection is active.
Jul 01 16:45:36 balena-supervisor[2136]: [info]    VPN connection is active.
Jul 01 16:45:45 balena-supervisor[2136]: [info]    Internet Connectivity: OK
Jul 01 16:49:32 balena-supervisor[2136]: [api]     GET /v1/healthy 200 - 22.453 ms
Jul 01 16:54:33 balena-supervisor[2136]: [api]     GET /v1/healthy 200 - 16.129 ms
Jul 01 16:54:34 balena-supervisor[2136]: [debug]   Attempting container log timestamp flush...
Jul 01 16:54:34 balena-supervisor[2136]: [debug]   Container log timestamp flush complete
Jul 01 16:59:34 balena-supervisor[2136]: [api]     GET /v1/healthy 200 - 5.754 ms
Jul 01 17:04:34 balena-supervisor[2136]: [debug]   Attempting container log timestamp flush...
Jul 01 17:04:34 balena-supervisor[2136]: [debug]   Container log timestamp flush complete
Jul 01 17:04:35 balena-supervisor[2136]: [api]     GET /v1/healthy 200 - 10.094 ms
Jul 01 17:09:35 balena-supervisor[2136]: [api]     GET /v1/healthy 200 - 6.559 ms
Jul 01 17:14:34 balena-supervisor[2136]: [debug]   Attempting container log timestamp flush...
Jul 01 17:14:34 balena-supervisor[2136]: [debug]   Container log timestamp flush complete
Jul 01 17:14:36 balena-supervisor[2136]: [api]     GET /v1/healthy 200 - 87.389 ms
Jul 01 17:19:37 balena-supervisor[2136]: [api]     GET /v1/healthy 200 - 12.802 ms
Jul 01 17:24:34 balena-supervisor[2136]: [debug]   Attempting container log timestamp flush...
Jul 01 17:24:34 balena-supervisor[2136]: [debug]   Container log timestamp flush complete
Jul 01 17:24:38 balena-supervisor[2136]: [api]     GET /v1/healthy 200 - 15.372 ms
Jul 01 17:29:38 balena-supervisor[2136]: [api]     GET /v1/healthy 200 - 11.879 ms
Jul 01 17:30:47 balena-supervisor[2136]: [api]     GET /v1/healthy 200 - 3.645 ms
Jul 01 17:34:34 balena-supervisor[2136]: [debug]   Attempting container log timestamp flush...
Jul 01 17:34:34 balena-supervisor[2136]: [debug]   Container log timestamp flush complete
Jul 01 17:34:39 balena-supervisor[2136]: [api]     GET /v1/healthy 200 - 11.464 ms
Jul 01 17:35:13 balena-supervisor[2136]: [api]     GET /v1/healthy 200 - 4.751 ms
Jul 01 17:36:17 balena-supervisor[2136]: [api]     GET /v1/healthy 200 - 3.431 ms

gktl · July 1, 2021, 11:27pm

Device 3:

-- Logs begin at Thu 2021-07-01 20:07:48 UTC, end at Thu 2021-07-01 23:25:04 UTC. --
Jul 01 20:10:13 balena-supervisor[2146]: [api]     GET /v1/healthy 200 - 5.764 ms
Jul 01 20:13:53 balena-supervisor[2146]: [debug]   Attempting container log timestamp flush...
Jul 01 20:13:53 balena-supervisor[2146]: [debug]   Container log timestamp flush complete
Jul 01 20:15:14 balena-supervisor[2146]: [api]     GET /v1/healthy 200 - 7.833 ms
Jul 01 20:20:15 balena-supervisor[2146]: [api]     GET /v1/healthy 200 - 5.863 ms
Jul 01 20:23:53 balena-supervisor[2146]: [debug]   Attempting container log timestamp flush...
Jul 01 20:23:53 balena-supervisor[2146]: [debug]   Container log timestamp flush complete
Jul 01 20:25:15 balena-supervisor[2146]: [api]     GET /v1/healthy 200 - 5.841 ms
Jul 01 20:30:16 balena-supervisor[2146]: [api]     GET /v1/healthy 200 - 4.757 ms
Jul 01 20:33:53 balena-supervisor[2146]: [debug]   Attempting container log timestamp flush...
Jul 01 20:33:53 balena-supervisor[2146]: [debug]   Container log timestamp flush complete
Jul 01 20:35:17 balena-supervisor[2146]: [api]     GET /v1/healthy 200 - 30.924 ms
Jul 01 20:40:18 balena-supervisor[2146]: [api]     GET /v1/healthy 200 - 7.449 ms
Jul 01 20:43:53 balena-supervisor[2146]: [debug]   Attempting container log timestamp flush...
Jul 01 20:43:53 balena-supervisor[2146]: [debug]   Container log timestamp flush complete
Jul 01 20:45:18 balena-supervisor[2146]: [api]     GET /v1/healthy 200 - 9.806 ms
Jul 01 20:50:19 balena-supervisor[2146]: [api]     GET /v1/healthy 200 - 12.448 ms
Jul 01 20:53:53 balena-supervisor[2146]: [debug]   Attempting container log timestamp flush...
Jul 01 20:53:53 balena-supervisor[2146]: [debug]   Container log timestamp flush complete
Jul 01 20:55:20 balena-supervisor[2146]: [api]     GET /v1/healthy 200 - 11.930 ms
Jul 01 21:00:21 balena-supervisor[2146]: [api]     GET /v1/healthy 200 - 3.865 ms
Jul 01 21:03:53 balena-supervisor[2146]: [debug]   Attempting container log timestamp flush...
Jul 01 21:03:53 balena-supervisor[2146]: [debug]   Container log timestamp flush complete
Jul 01 21:05:21 balena-supervisor[2146]: [api]     GET /v1/healthy 200 - 15.515 ms
Jul 01 21:10:22 balena-supervisor[2146]: [api]     GET /v1/healthy 200 - 10.830 ms
Jul 01 21:13:53 balena-supervisor[2146]: [debug]   Attempting container log timestamp flush...
Jul 01 21:13:53 balena-supervisor[2146]: [debug]   Container log timestamp flush complete
Jul 01 21:15:23 balena-supervisor[2146]: [api]     GET /v1/healthy 200 - 11.234 ms
Jul 01 21:20:24 balena-supervisor[2146]: [api]     GET /v1/healthy 200 - 6.674 ms
Jul 01 21:23:53 balena-supervisor[2146]: [debug]   Attempting container log timestamp flush...
Jul 01 21:23:53 balena-supervisor[2146]: [debug]   Container log timestamp flush complete
Jul 01 21:25:24 balena-supervisor[2146]: [api]     GET /v1/healthy 200 - 4.926 ms
Jul 01 21:30:25 balena-supervisor[2146]: [api]     GET /v1/healthy 200 - 4.162 ms
Jul 01 21:33:53 balena-supervisor[2146]: [debug]   Attempting container log timestamp flush...
Jul 01 21:33:53 balena-supervisor[2146]: [debug]   Container log timestamp flush complete
Jul 01 21:35:26 balena-supervisor[2146]: [api]     GET /v1/healthy 200 - 12.482 ms
Jul 01 21:37:58 balena-supervisor[2146]: [error]   Error from the API: 503
Jul 01 21:37:58 balena-supervisor[2146]: [error]   Non-200 response from the API! Status code: 503 - message: Error: "The API cannot handle your request right now"
Jul 01 21:37:58 balena-supervisor[2146]: [error]         at sendReportPatch (/usr/src/app/dist/app.js:22:642937)
Jul 01 21:37:58 balena-supervisor[2146]: [error]       at runMicrotasks (<anonymous>)
Jul 01 21:37:58 balena-supervisor[2146]: [error]       at processTicksAndRejections (internal/process/task_queues.js:97:5)
Jul 01 21:37:58 balena-supervisor[2146]: [error]       at async /usr/src/app/dist/app.js:22:644023
Jul 01 21:40:26 balena-supervisor[2146]: [api]     GET /v1/healthy 200 - 13.565 ms
Jul 01 21:43:53 balena-supervisor[2146]: [debug]   Attempting container log timestamp flush...
Jul 01 21:43:53 balena-supervisor[2146]: [debug]   Container log timestamp flush complete
Jul 01 21:45:27 balena-supervisor[2146]: [api]     GET /v1/healthy 200 - 5.216 ms
Jul 01 21:50:28 balena-supervisor[2146]: [api]     GET /v1/healthy 200 - 10.113 ms
Jul 01 21:53:53 balena-supervisor[2146]: [debug]   Attempting container log timestamp flush...
Jul 01 21:53:53 balena-supervisor[2146]: [debug]   Container log timestamp flush complete
Jul 01 21:55:29 balena-supervisor[2146]: [api]     GET /v1/healthy 200 - 6.300 ms
-- Reboot --
Jul 01 22:00:11 balena-supervisor[1906]: Error response from daemon: No such container: resin_supervisor
Jul 01 22:00:11 balena-supervisor[1921]: Error: No such container: resin_supervisor
Jul 01 22:00:11 balena-supervisor[1938]: balena_supervisor
Jul 01 22:00:11 balena-supervisor[1954]: active
Jul 01 22:00:14 balena-supervisor[1955]: Container config has not changed
-- Reboot --
Jul 01 22:00:29 balena-supervisor[2146]: [api]     GET /v1/healthy 200 - 8.903 ms
Jul 01 22:03:53 balena-supervisor[2146]: [debug]   Attempting container log timestamp flush...
Jul 01 22:03:53 balena-supervisor[2146]: [debug]   Container log timestamp flush complete
Jul 01 22:05:07 balena-supervisor[2146]: [event]   Event: Device state report failure {"error":{"message":""}}
Jul 01 22:05:31 balena-supervisor[2146]: [api]     GET /v1/healthy 200 - 14.210 ms
Jul 01 22:06:02 balena-supervisor[2146]: [event]   Event: Device state report failure {"error":{"message":""}}
Jul 01 22:09:57 balena-supervisor[2146]: (node:1) UnhandledPromiseRejectionWarning: Error: ETIMEDOUT
Jul 01 22:09:57 balena-supervisor[2146]:     at Timeout.<anonymous> (/usr/src/app/dist/app.js:10:1664782)
Jul 01 22:09:57 balena-supervisor[2146]:     at listOnTimeout (internal/timers.js:549:17)
Jul 01 22:09:57 balena-supervisor[2146]:     at processTimers (internal/timers.js:492:7)
Jul 01 22:09:57 balena-supervisor[2146]: (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: 4)
Jul 01 22:10:32 balena-supervisor[2146]: [api]     GET /v1/healthy 200 - 6.052 ms
Jul 01 22:13:53 balena-supervisor[2146]: [debug]   Attempting container log timestamp flush...
Jul 01 22:13:53 balena-supervisor[2146]: [debug]   Container log timestamp flush complete
Jul 01 22:15:33 balena-supervisor[2146]: [api]     GET /v1/healthy 200 - 5.981 ms
Jul 01 22:20:33 balena-supervisor[2146]: [api]     GET /v1/healthy 200 - 3.662 ms
Jul 01 22:23:53 balena-supervisor[2146]: [debug]   Attempting container log timestamp flush...
Jul 01 22:23:53 balena-supervisor[2146]: [debug]   Container log timestamp flush complete
Jul 01 22:25:34 balena-supervisor[2146]: [api]     GET /v1/healthy 200 - 7.281 ms
Jul 01 22:30:35 balena-supervisor[2146]: [api]     GET /v1/healthy 200 - 5.504 ms
Jul 01 22:33:53 balena-supervisor[2146]: [debug]   Attempting container log timestamp flush...
Jul 01 22:33:53 balena-supervisor[2146]: [debug]   Container log timestamp flush complete
Jul 01 22:35:36 balena-supervisor[2146]: [api]     GET /v1/healthy 200 - 4.948 ms
Jul 01 22:40:36 balena-supervisor[2146]: [api]     GET /v1/healthy 200 - 6.010 ms
Jul 01 22:43:53 balena-supervisor[2146]: [debug]   Attempting container log timestamp flush...
Jul 01 22:43:53 balena-supervisor[2146]: [debug]   Container log timestamp flush complete
Jul 01 22:45:37 balena-supervisor[2146]: [api]     GET /v1/healthy 200 - 33.943 ms
-- Reboot --
Jul 01 22:49:04 balena-supervisor[2123]: [info]    Supervisor v12.8.10 starting up...
Jul 01 22:49:04 balena-supervisor[2123]: [info]    Setting host to discoverable
Jul 01 22:49:04 balena-supervisor[2123]: [warn]    Invalid firewall mode: . Reverting to state: off
Jul 01 22:49:04 balena-supervisor[2123]: [info]    🔥 Applying firewall mode: off
Jul 01 22:49:04 balena-supervisor[2123]: [debug]   Starting logging infrastructure
Jul 01 22:49:04 balena-supervisor[2123]: [debug]   Performing database cleanup for container log timestamps
Jul 01 22:49:04 balena-supervisor[2123]: [info]    Starting firewall
Jul 01 22:49:04 balena-supervisor[2123]: [info]    Previous engine snapshot was not stored. Skipping cleanup.
Jul 01 22:49:04 balena-supervisor[2123]: [debug]   Handling of local mode switch is completed
Jul 01 22:49:04 balena-supervisor[2123]: (node:1) [DEP0005] DeprecationWarning: Buffer() is deprecated due to security and usability issues. Please use the Buffer.alloc(), Buffer.allocUnsafe(), or Buffer.from() methods instead.
Jul 01 22:49:04 balena-supervisor[2123]: [info]    API Binder bound to: https://api.balena-cloud.com/v6/
Jul 01 22:49:04 balena-supervisor[2123]: [debug]   Spawning journald with: chroot  /mnt/root journalctl -a -S 2021-07-01 22:43:52 -o json CONTAINER_ID_FULL=63fa7ab06e4aa3c0dc3e9b2efe8df499ba4da34ee4585f0568e2cd045b4410a3
Jul 01 22:49:04 balena-supervisor[2123]: [success] 🔥 Firewall mode applied
Jul 01 22:49:04 balena-supervisor[2123]: [debug]   Starting api binder
Jul 01 22:49:04 balena-supervisor[2123]: [event]   Event: Supervisor start {}
Jul 01 22:49:04 balena-supervisor[2123]: [debug]   Connectivity check enabled: true
Jul 01 22:49:04 balena-supervisor[2123]: [debug]   Starting periodic check for IP addresses
Jul 01 22:49:04 balena-supervisor[2123]: [info]    Reporting initial state, supervisor version and API info
Jul 01 22:49:04 balena-supervisor[2123]: [debug]   Skipping preloading
Jul 01 22:49:04 balena-supervisor[2123]: [debug]   VPN status path exists.
Jul 01 22:49:04 balena-supervisor[2123]: [info]    VPN connection is not active.
Jul 01 22:49:04 balena-supervisor[2123]: [info]    Waiting for connectivity...
Jul 01 22:49:04 balena-supervisor[2123]: [info]    Starting API server
Jul 01 22:49:04 balena-supervisor[2123]: [info]    Supervisor API successfully started on port 48484
Jul 01 22:49:04 balena-supervisor[2123]: [info]    Applying target state
Jul 01 22:49:04 balena-supervisor[2123]: [debug]   Ensuring device is provisioned
Jul 01 22:49:05 balena-supervisor[2123]: [debug]   Starting current state report
Jul 01 22:49:05 balena-supervisor[2123]: [debug]   Starting target state poll
Jul 01 22:49:05 balena-supervisor[2123]: [debug]   Spawning journald with: chroot  /mnt/root journalctl -a --follow -o json _SYSTEMD_UNIT=balena.service
Jul 01 22:49:06 balena-supervisor[2123]: [debug]   Finished applying target state
Jul 01 22:49:06 balena-supervisor[2123]: [success] Device state apply success
Jul 01 22:49:06 balena-supervisor[2123]: [info]    Applying target state
Jul 01 22:49:06 balena-supervisor[2123]: [debug]   Finished applying target state
Jul 01 22:49:06 balena-supervisor[2123]: [success] Device state apply success
Jul 01 22:49:11 balena-supervisor[2123]: [info]    VPN connection is active.
Jul 01 22:49:11 balena-supervisor[2123]: [info]    VPN connection is active.
Jul 01 22:49:11 balena-supervisor[2123]: [info]    VPN connection is active.
Jul 01 22:49:11 balena-supervisor[2123]: [info]    VPN connection is active.
Jul 01 22:49:12 balena-supervisor[2123]: [info]    VPN connection is not active.
Jul 01 22:49:25 balena-supervisor[2123]: [info]    VPN connection is active.
Jul 01 22:49:25 balena-supervisor[2123]: [info]    VPN connection is active.
Jul 01 22:49:25 balena-supervisor[2123]: [info]    VPN connection is active.
Jul 01 22:49:25 balena-supervisor[2123]: [info]    VPN connection is active.
Jul 01 22:49:34 balena-supervisor[2123]: [info]    Internet Connectivity: OK
Jul 01 22:54:01 balena-supervisor[2123]: [api]     GET /v1/healthy 200 - 22.929 ms
Jul 01 22:59:02 balena-supervisor[2123]: [api]     GET /v1/healthy 200 - 14.812 ms
Jul 01 22:59:03 balena-supervisor[2123]: [debug]   Attempting container log timestamp flush...
Jul 01 22:59:03 balena-supervisor[2123]: [debug]   Container log timestamp flush complete
-- Reboot --
Jul 01 23:00:12 balena-supervisor[1902]: Error response from daemon: No such container: resin_supervisor
Jul 01 23:00:12 balena-supervisor[1921]: Error: No such container: resin_supervisor
Jul 01 23:00:13 balena-supervisor[1943]: balena_supervisor
Jul 01 23:00:13 balena-supervisor[1959]: active
-- Reboot --
Jul 01 23:00:13 balena-supervisor[1913]: Error response from daemon: No such container: resin_supervisor
Jul 01 23:00:13 balena-supervisor[1936]: Error: No such container: resin_supervisor
Jul 01 23:00:13 balena-supervisor[1954]: balena_supervisor
Jul 01 23:00:13 balena-supervisor[1971]: active
-- Reboot --
Jul 01 23:00:15 balena-supervisor[1961]: Container config has not changed
-- Reboot --
Jul 01 23:00:16 balena-supervisor[1972]: Container config has not changed
-- Reboot --
Jul 01 23:04:03 balena-supervisor[2123]: [api]     GET /v1/healthy 200 - 8.653 ms
Jul 01 23:09:03 balena-supervisor[2123]: [debug]   Attempting container log timestamp flush...
Jul 01 23:09:03 balena-supervisor[2123]: [debug]   Container log timestamp flush complete
Jul 01 23:09:03 balena-supervisor[2123]: [api]     GET /v1/healthy 200 - 7.208 ms
Jul 01 23:10:16 balena-supervisor[2123]: [error]   Error from the API: 503
Jul 01 23:10:16 balena-supervisor[2123]: [error]   Non-200 response from the API! Status code: 503 - message: Error: "The API cannot handle your request right now"
Jul 01 23:10:16 balena-supervisor[2123]: [error]         at sendReportPatch (/usr/src/app/dist/app.js:22:642937)
Jul 01 23:10:16 balena-supervisor[2123]: [error]       at runMicrotasks (<anonymous>)
Jul 01 23:10:16 balena-supervisor[2123]: [error]       at processTicksAndRejections (internal/process/task_queues.js:97:5)
Jul 01 23:10:16 balena-supervisor[2123]: [error]       at async /usr/src/app/dist/app.js:22:644023
Jul 01 23:10:16 balena-supervisor[2123]: [error]       at async /usr/src/app/dist/app.js:22:644931
Jul 01 23:14:04 balena-supervisor[2123]: [api]     GET /v1/healthy 200 - 13.673 ms
-- Reboot --
Jul 01 23:18:33 balena-supervisor[2151]: [info]    Supervisor v12.8.10 starting up...
Jul 01 23:18:33 balena-supervisor[2151]: [info]    Setting host to discoverable
Jul 01 23:18:33 balena-supervisor[2151]: [warn]    Invalid firewall mode: . Reverting to state: off
Jul 01 23:18:33 balena-supervisor[2151]: [info]    🔥 Applying firewall mode: off
Jul 01 23:18:33 balena-supervisor[2151]: [debug]   Performing database cleanup for container log timestamps
Jul 01 23:18:33 balena-supervisor[2151]: [debug]   Starting logging infrastructure
Jul 01 23:18:33 balena-supervisor[2151]: [info]    Starting firewall
Jul 01 23:18:33 balena-supervisor[2151]: [info]    Previous engine snapshot was not stored. Skipping cleanup.
Jul 01 23:18:33 balena-supervisor[2151]: [debug]   Handling of local mode switch is completed
Jul 01 23:18:33 balena-supervisor[2151]: (node:1) [DEP0005] DeprecationWarning: Buffer() is deprecated due to security and usability issues. Please use the Buffer.alloc(), Buffer.allocUnsafe(), or Buffer.from() methods instead.
Jul 01 23:18:33 balena-supervisor[2151]: [info]    API Binder bound to: https://api.balena-cloud.com/v6/
Jul 01 23:18:33 balena-supervisor[2151]: [debug]   Spawning journald with: chroot  /mnt/root journalctl -a -S 2021-07-01 23:08:57 -o json CONTAINER_ID_FULL=63fa7ab06e4aa3c0dc3e9b2efe8df499ba4da34ee4585f0568e2cd045b4410a3
Jul 01 23:18:33 balena-supervisor[2151]: [success] 🔥 Firewall mode applied
Jul 01 23:18:33 balena-supervisor[2151]: [debug]   Starting api binder
Jul 01 23:18:33 balena-supervisor[2151]: [event]   Event: Supervisor start {}
Jul 01 23:18:33 balena-supervisor[2151]: [debug]   Connectivity check enabled: true
Jul 01 23:18:33 balena-supervisor[2151]: [debug]   Starting periodic check for IP addresses
Jul 01 23:18:33 balena-supervisor[2151]: [info]    Reporting initial state, supervisor version and API info
Jul 01 23:18:33 balena-supervisor[2151]: [debug]   Skipping preloading
Jul 01 23:18:33 balena-supervisor[2151]: [debug]   VPN status path exists.
Jul 01 23:18:33 balena-supervisor[2151]: [info]    VPN connection is active.
Jul 01 23:18:33 balena-supervisor[2151]: [info]    Waiting for connectivity...
Jul 01 23:18:33 balena-supervisor[2151]: [info]    Starting API server
Jul 01 23:18:33 balena-supervisor[2151]: [info]    Supervisor API successfully started on port 48484
Jul 01 23:18:33 balena-supervisor[2151]: [info]    Applying target state
Jul 01 23:18:33 balena-supervisor[2151]: [debug]   Ensuring device is provisioned
Jul 01 23:18:34 balena-supervisor[2151]: [info]    VPN connection is not active.
Jul 01 23:18:34 balena-supervisor[2151]: [debug]   Starting current state report
Jul 01 23:18:34 balena-supervisor[2151]: [debug]   Starting target state poll
Jul 01 23:18:34 balena-supervisor[2151]: [debug]   Spawning journald with: chroot  /mnt/root journalctl -a --follow -o json _SYSTEMD_UNIT=balena.service
Jul 01 23:18:35 balena-supervisor[2151]: [debug]   Finished applying target state
Jul 01 23:18:35 balena-supervisor[2151]: [success] Device state apply success
Jul 01 23:18:36 balena-supervisor[2151]: [info]    Applying target state
Jul 01 23:18:36 balena-supervisor[2151]: [debug]   Finished applying target state
Jul 01 23:18:36 balena-supervisor[2151]: [success] Device state apply success
Jul 01 23:18:41 balena-supervisor[2151]: [info]    VPN connection is active.
Jul 01 23:18:41 balena-supervisor[2151]: [info]    VPN connection is active.
Jul 01 23:18:41 balena-supervisor[2151]: [info]    VPN connection is active.
Jul 01 23:18:41 balena-supervisor[2151]: [info]    VPN connection is active.
Jul 01 23:18:41 balena-supervisor[2151]: [info]    VPN connection is not active.
Jul 01 23:18:56 balena-supervisor[2151]: [info]    VPN connection is active.
Jul 01 23:18:56 balena-supervisor[2151]: [info]    VPN connection is active.
Jul 01 23:18:56 balena-supervisor[2151]: [info]    VPN connection is active.
Jul 01 23:19:03 balena-supervisor[2151]: [info]    Internet Connectivity: OK
-- Reboot --
Jul 01 23:24:31 balena-supervisor[2135]: [info]    Supervisor v12.8.10 starting up...
Jul 01 23:24:31 balena-supervisor[2135]: [info]    Setting host to discoverable
Jul 01 23:24:31 balena-supervisor[2135]: [warn]    Invalid firewall mode: . Reverting to state: off
Jul 01 23:24:31 balena-supervisor[2135]: [info]    🔥 Applying firewall mode: off
Jul 01 23:24:31 balena-supervisor[2135]: [debug]   Starting logging infrastructure
Jul 01 23:24:31 balena-supervisor[2135]: [debug]   Performing database cleanup for container log timestamps
Jul 01 23:24:31 balena-supervisor[2135]: [info]    Starting firewall
Jul 01 23:24:31 balena-supervisor[2135]: [info]    Previous engine snapshot was not stored. Skipping cleanup.
Jul 01 23:24:31 balena-supervisor[2135]: [debug]   Handling of local mode switch is completed
Jul 01 23:24:31 balena-supervisor[2135]: (node:1) [DEP0005] DeprecationWarning: Buffer() is deprecated due to security and usability issues. Please use the Buffer.alloc(), Buffer.allocUnsafe(), or Buffer.from() methods instead.
Jul 01 23:24:31 balena-supervisor[2135]: [info]    API Binder bound to: https://api.balena-cloud.com/v6/
Jul 01 23:24:31 balena-supervisor[2135]: [debug]   Spawning journald with: chroot  /mnt/root journalctl -a -S 2021-07-01 23:08:57 -o json CONTAINER_ID_FULL=63fa7ab06e4aa3c0dc3e9b2efe8df499ba4da34ee4585f0568e2cd045b4410a3
Jul 01 23:24:31 balena-supervisor[2135]: [success] 🔥 Firewall mode applied
Jul 01 23:24:31 balena-supervisor[2135]: [debug]   Starting api binder
Jul 01 23:24:31 balena-supervisor[2135]: [event]   Event: Supervisor start {}
Jul 01 23:24:31 balena-supervisor[2135]: [debug]   Connectivity check enabled: true
Jul 01 23:24:31 balena-supervisor[2135]: [debug]   Starting periodic check for IP addresses
Jul 01 23:24:31 balena-supervisor[2135]: [info]    Reporting initial state, supervisor version and API info
Jul 01 23:24:31 balena-supervisor[2135]: [debug]   Skipping preloading
Jul 01 23:24:31 balena-supervisor[2135]: [info]    VPN connection is not active.
Jul 01 23:24:31 balena-supervisor[2135]: [info]    Waiting for connectivity...
Jul 01 23:24:31 balena-supervisor[2135]: [info]    Starting API server
Jul 01 23:24:31 balena-supervisor[2135]: [info]    Supervisor API successfully started on port 48484
Jul 01 23:24:32 balena-supervisor[2135]: [info]    Applying target state
Jul 01 23:24:32 balena-supervisor[2135]: [debug]   Ensuring device is provisioned
Jul 01 23:24:32 balena-supervisor[2135]: [debug]   Starting current state report
Jul 01 23:24:32 balena-supervisor[2135]: [debug]   Starting target state poll
Jul 01 23:24:32 balena-supervisor[2135]: [debug]   Spawning journald with: chroot  /mnt/root journalctl -a --follow -o json _SYSTEMD_UNIT=balena.service
Jul 01 23:24:33 balena-supervisor[2135]: [debug]   Finished applying target state
Jul 01 23:24:33 balena-supervisor[2135]: [success] Device state apply success
Jul 01 23:24:34 balena-supervisor[2135]: [info]    Applying target state
Jul 01 23:24:34 balena-supervisor[2135]: [debug]   Finished applying target state
Jul 01 23:24:34 balena-supervisor[2135]: [success] Device state apply success
Jul 01 23:24:34 balena-supervisor[2135]: [info]    VPN connection is active.
Jul 01 23:24:34 balena-supervisor[2135]: [info]    VPN connection is active.
Jul 01 23:24:34 balena-supervisor[2135]: [info]    VPN connection is active.
Jul 01 23:24:34 balena-supervisor[2135]: [info]    VPN connection is active.
Jul 01 23:24:41 balena-supervisor[2135]: [info]    Internet Connectivity: OK

Hades32 · July 2, 2021, 3:24pm

Have you enabled persistent logging? You can do so either on the device or for the whole application in the “fleet variables” tab.
After you’ve enabled those, you could look at journalctl (without parameters) and look for errors that happened right before the reboot

klutchell · July 15, 2021, 9:01pm

Are you still having issues with this release? Did you discover any details when viewing the journalctl logs without the filters? Let us know if we can continue to troubleshoot.