Balena OS > 2.5 -> Screen on PI4s not starting

golemun · August 8, 2023, 9:13am

We are using many raspberry pi 4 B boards to display information. The system itself is running quite well since ~3years and we decided to try a new version of balenaOS recently.

Our Touchscreens are connected using HDMI and they also have an option of outputting sound.

With BalenaOS until v.2.5. everything works, whereas using an recent image, like for example 3.1.1 does not work with the screen - after powering it goes into hybernation. The screen itself never shows anything. Tested on multiple devices, the only difference being the balenaOS image.

Has anyone else experienced something like this or has any idea where to go looking for errors?

Working version:

2.107.10+rev3

Not working versions:

3.0.8+rev2
3.1.1

golemun · August 8, 2023, 11:03am

Some additional information:

cat /mnt/boot/config.txt
dtoverlay=uart1
dtoverlay=vc4-fkms-v3d
enable_uart=1
gpu_mem=128
avoid_warnings=1
disable_splash=1
dtparam=i2c_arm=on
dtparam=spi=on
dtparam=audio=on

and under dmesg: Warning: unable to open an initial console.

alanb128 · August 9, 2023, 2:14am

Hello, other than the dmesg warning, are you seeing any other errors in the OS or application logs?

golemun · August 9, 2023, 5:35am

Any specific logs you are interested in? From the device?

journalctl:

Aug 09 05:38:47 490a269 healthdog[2927]: try: 1, refid: D9C4912A, correction: 0.000000113, skew: 0.469
Aug 09 05:38:51 490a269 7b0bad39e88d[1968]: [api]     GET /v1/healthy 200 - 6.542 ms
Aug 09 05:38:51 490a269 balena-supervisor[2565]: [api]     GET /v1/healthy 200 - 6.542 ms
Aug 09 05:38:55 490a269 7b0bad39e88d[1968]: [debug]   Attempting container log timestamp flush...
Aug 09 05:38:55 490a269 balena-supervisor[2565]: [debug]   Attempting container log timestamp flush...
Aug 09 05:38:55 490a269 balena-supervisor[2565]: [debug]   Container log timestamp flush complete
Aug 09 05:38:55 490a269 7b0bad39e88d[1968]: [debug]   Container log timestamp flush complete
Aug 09 05:39:00 490a269 7b0bad39e88d[1968]: [info]    Reported current state to the cloud
Aug 09 05:39:00 490a269 balena-supervisor[2565]: [info]    Reported current state to the cloud
Aug 09 05:40:47 490a269 healthdog[2988]: try: 1, refid: D9C4912A, correction: 0.000000110, skew: 0.469
Aug 09 05:41:57 490a269 NetworkManager[1917]: <info>  [1691559717.9739] device (wlan0): set-hw-addr: set MAC address to CE:6C:0A:FB:D4:5F (scanning)
Aug 09 05:41:57 490a269 kernel: brcmfmac: brcmf_cfg80211_set_power_mgmt: power save disabled
Aug 09 05:41:57 490a269 NetworkManager[1917]: <info>  [1691559717.9821] device (wlan0): supplicant interface state: inactive -> disconnected
Aug 09 05:41:57 490a269 NetworkManager[1917]: <info>  [1691559717.9822] device (p2p-dev-wlan0): supplicant management interface state: inactive -> disconnected
Aug 09 05:41:57 490a269 NetworkManager[1917]: <info>  [1691559717.9862] device (wlan0): supplicant interface state: disconnected -> inactive
Aug 09 05:41:57 490a269 NetworkManager[1917]: <info>  [1691559717.9864] device (p2p-dev-wlan0): supplicant management interface state: disconnected -> inactive
Aug 09 05:42:47 490a269 healthdog[3016]: try: 1, refid: D9C4912A, correction: 0.000000106, skew: 0.469
Aug 09 05:43:12 490a269 systemd-tmpfiles[3017]: /usr/lib/tmpfiles.d/dbus.conf:13: Line references path below legacy directory /var/run/, updating /var/run/dbus/containers → /run/dbus/containers; please update the tmpfiles.d/ drop-in file accordingly.
Aug 09 05:43:12 490a269 systemd-tmpfiles[3017]: /usr/lib/tmpfiles.d/legacy.conf:13: Duplicate line for path "/run/lock", ignoring.
Aug 09 05:43:12 490a269 systemd-tmpfiles[3017]: /etc/tmpfiles.d/openvpn.conf:1: Line references path below legacy directory /var/run/, updating /var/run/openvpn → /run/openvpn; please update the tmpfiles.d/ drop-in file accordingly.
Aug 09 05:43:51 490a269 7b0bad39e88d[1968]: [api]     GET /v1/healthy 200 - 9.240 ms
Aug 09 05:43:51 490a269 balena-supervisor[2565]: [api]     GET /v1/healthy 200 - 9.240 ms
Aug 09 05:44:31 490a269 7b0bad39e88d[1968]: [info]    Reported current state to the cloud
Aug 09 05:44:31 490a269 balena-supervisor[2565]: [info]    Reported current state to the cloud
Aug 09 05:44:47 490a269 healthdog[3104]: try: 1, refid: D9C4912A, correction: 0.000000103, skew: 0.469
Aug 09 05:46:47 490a269 healthdog[3134]: try: 1, refid: D9C4912A, correction: 0.000000100, skew: 0.469
Aug 09 05:48:46 490a269 NetworkManager[1917]: <info>  [1691560126.9679] device (wlan0): set-hw-addr: set MAC address to C2:19:02:1B:08:51 (scanning)
Aug 09 05:48:46 490a269 kernel: brcmfmac: brcmf_cfg80211_set_power_mgmt: power save disabled
Aug 09 05:48:46 490a269 NetworkManager[1917]: <info>  [1691560126.9760] device (wlan0): supplicant interface state: inactive -> disconnected
Aug 09 05:48:46 490a269 NetworkManager[1917]: <info>  [1691560126.9761] device (p2p-dev-wlan0): supplicant management interface state: inactive -> disconnected
Aug 09 05:48:46 490a269 NetworkManager[1917]: <info>  [1691560126.9799] device (wlan0): supplicant interface state: disconnected -> inactive
Aug 09 05:48:46 490a269 NetworkManager[1917]: <info>  [1691560126.9801] device (p2p-dev-wlan0): supplicant management interface state: disconnected -> inactive
Aug 09 05:48:47 490a269 healthdog[3162]: try: 1, refid: D9C4912A, correction: 0.000000096, skew: 0.469
Aug 09 05:48:52 490a269 7b0bad39e88d[1968]: [api]     GET /v1/healthy 200 - 8.872 ms
Aug 09 05:48:52 490a269 balena-supervisor[2565]: [api]     GET /v1/healthy 200 - 8.872 ms
Aug 09 05:48:55 490a269 7b0bad39e88d[1968]: [debug]   Attempting container log timestamp flush...
Aug 09 05:48:55 490a269 7b0bad39e88d[1968]: [debug]   Container log timestamp flush complete
Aug 09 05:48:55 490a269 balena-supervisor[2565]: [debug]   Attempting container log timestamp flush...
Aug 09 05:48:55 490a269 balena-supervisor[2565]: [debug]   Container log timestamp flush complete
Aug 09 05:50:47 490a269 healthdog[3286]: try: 1, refid: D9C4912A, correction: 0.000000093, skew: 0.469
Aug 09 05:52:47 490a269 healthdog[3423]: try: 1, refid: D9C4912A, correction: 0.000000090, skew: 0.469
Aug 09 05:53:52 490a269 7b0bad39e88d[1968]: [api]     GET /v1/healthy 200 - 6.994 ms
Aug 09 05:53:52 490a269 balena-supervisor[2565]: [api]     GET /v1/healthy 200 - 6.994 ms
Aug 09 05:54:47 490a269 healthdog[3580]: try: 1, refid: D9C4912A, correction: 0.000000086, skew: 0.469
Aug 09 05:55:35 490a269 NetworkManager[1917]: <info>  [1691560535.9578] device (wlan0): set-hw-addr: set MAC address to 6A:D9:D3:7A:16:14 (scanning)
Aug 09 05:55:35 490a269 kernel: brcmfmac: brcmf_cfg80211_set_power_mgmt: power save disabled
Aug 09 05:55:35 490a269 NetworkManager[1917]: <info>  [1691560535.9684] device (wlan0): supplicant interface state: inactive -> disconnected
Aug 09 05:55:35 490a269 NetworkManager[1917]: <info>  [1691560535.9690] device (p2p-dev-wlan0): supplicant management interface state: inactive -> disconnected
Aug 09 05:55:35 490a269 NetworkManager[1917]: <info>  [1691560535.9748] device (wlan0): supplicant interface state: disconnected -> inactive
Aug 09 05:55:35 490a269 NetworkManager[1917]: <info>  [1691560535.9753] device (p2p-dev-wlan0): supplicant management interface state: disconnected -> inactive
Aug 09 05:56:47 490a269 healthdog[3717]: try: 1, refid: D9C4912A, correction: 0.000000083, skew: 0.469
Aug 09 05:58:47 490a269 healthdog[3844]: try: 1, refid: D9C4912A, correction: 0.000000080, skew: 0.469
Aug 09 05:58:53 490a269 balena-supervisor[2565]: [api]     GET /v1/healthy 200 - 9.643 ms
Aug 09 05:58:53 490a269 7b0bad39e88d[1968]: [api]     GET /v1/healthy 200 - 9.643 ms
Aug 09 05:58:55 490a269 7b0bad39e88d[1968]: [debug]   Attempting container log timestamp flush...
Aug 09 05:58:55 490a269 balena-supervisor[2565]: [debug]   Attempting container log timestamp flush...
Aug 09 05:58:55 490a269 balena-supervisor[2565]: [debug]   Container log timestamp flush complete
Aug 09 05:58:55 490a269 7b0bad39e88d[1968]: [debug]   Container log timestamp flush complete
Aug 09 06:00:01 490a269 fake-hwclock[3951]: [fake-hwclock][INFO] Saving system time to /etc/fake-hwclock/fake-hwclock.data.
Aug 09 06:00:47 490a269 healthdog[4011]: try: 1, refid: D9C4912A, correction: 0.000000076, skew: 0.469
Aug 09 06:02:23 490a269 NetworkManager[1917]: <info>  [1691560943.9905] device (wlan0): set-hw-addr: set MAC address to 16:D7:B2:7B:4E:26 (scanning)
Aug 09 06:02:23 490a269 kernel: brcmfmac: brcmf_cfg80211_set_power_mgmt: power save disabled
Aug 09 06:02:24 490a269 NetworkManager[1917]: <info>  [1691560944.0386] device (wlan0): supplicant interface state: inactive -> disconnected
Aug 09 06:02:24 490a269 NetworkManager[1917]: <info>  [1691560944.0388] device (p2p-dev-wlan0): supplicant management interface state: inactive -> disconnected
Aug 09 06:02:24 490a269 NetworkManager[1917]: <info>  [1691560944.0671] device (wlan0): supplicant interface state: disconnected -> inactive
Aug 09 06:02:24 490a269 NetworkManager[1917]: <info>  [1691560944.0674] device (p2p-dev-wlan0): supplicant management interface state: disconnected -> inactive
Aug 09 06:02:47 490a269 healthdog[4148]: try: 1, refid: D9C4912A, correction: 0.000000073, skew: 0.469
Aug 09 06:03:02 490a269 7b0bad39e88d[1968]: [info]    Reported current state to the cloud
Aug 09 06:03:02 490a269 balena-supervisor[2565]: [info]    Reported current state to the cloud
Aug 09 06:03:53 490a269 balena-supervisor[2565]: [api]     GET /v1/healthy 200 - 7.010 ms
Aug 09 06:03:53 490a269 7b0bad39e88d[1968]: [api]     GET /v1/healthy 200 - 7.010 ms
Aug 09 06:04:47 490a269 healthdog[4216]: try: 1, refid: D9C4912A, correction: 0.000000070, skew: 0.469
Aug 09 06:06:47 490a269 healthdog[4245]: try: 1, refid: D9C4912A, correction: 0.000000066, skew: 0.469
Aug 09 06:08:03 490a269 7b0bad39e88d[1968]: [info]    Reported current state to the cloud
Aug 09 06:08:03 490a269 balena-supervisor[2565]: [info]    Reported current state to the cloud
Aug 09 06:08:47 490a269 healthdog[4282]: try: 1, refid: D9C4912A, correction: 0.000000063, skew: 0.469
Aug 09 06:08:54 490a269 7b0bad39e88d[1968]: [api]     GET /v1/healthy 200 - 7.055 ms
Aug 09 06:08:54 490a269 balena-supervisor[2565]: [api]     GET /v1/healthy 200 - 7.055 ms
Aug 09 06:08:55 490a269 7b0bad39e88d[1968]: [debug]   Attempting container log timestamp flush...
Aug 09 06:08:55 490a269 balena-supervisor[2565]: [debug]   Attempting container log timestamp flush...
Aug 09 06:08:55 490a269 balena-supervisor[2565]: [debug]   Container log timestamp flush complete
Aug 09 06:08:55 490a269 7b0bad39e88d[1968]: [debug]   Container log timestamp flush complete
Aug 09 06:09:12 490a269 NetworkManager[1917]: <info>  [1691561352.9832] device (wlan0): set-hw-addr: set MAC address to A2:54:A4:44:3D:8A (scanning)
Aug 09 06:09:12 490a269 kernel: brcmfmac: brcmf_cfg80211_set_power_mgmt: power save disabled
Aug 09 06:09:12 490a269 NetworkManager[1917]: <info>  [1691561352.9908] device (wlan0): supplicant interface state: inactive -> disconnected
Aug 09 06:09:12 490a269 NetworkManager[1917]: <info>  [1691561352.9915] device (p2p-dev-wlan0): supplicant management interface state: inactive -> disconnected
Aug 09 06:09:12 490a269 NetworkManager[1917]: <info>  [1691561352.9958] device (wlan0): supplicant interface state: disconnected -> inactive
Aug 09 06:09:12 490a269 NetworkManager[1917]: <info>  [1691561352.9968] device (p2p-dev-wlan0): supplicant management interface state: disconnected -> inactive
Aug 09 06:10:47 490a269 healthdog[4335]: try: 1, refid: D9C4912A, correction: 0.000000060, skew: 0.469
Aug 09 06:12:47 490a269 healthdog[4363]: try: 1, refid: D9C4912A, correction: 0.000000056, skew: 0.469
Aug 09 06:13:54 490a269 7b0bad39e88d[1968]: [api]     GET /v1/healthy 200 - 10.784 ms
Aug 09 06:13:54 490a269 balena-supervisor[2565]: [api]     GET /v1/healthy 200 - 10.784 ms
Aug 09 06:14:47 490a269 healthdog[4513]: try: 1, refid: D9C4912A, correction: 0.000000053, skew: 0.469
Aug 09 06:16:00 490a269 NetworkManager[1917]: <info>  [1691561760.9830] device (wlan0): set-hw-addr: set MAC address to 42:F7:1E:59:C7:6A (scanning)
Aug 09 06:16:00 490a269 kernel: brcmfmac: brcmf_cfg80211_set_power_mgmt: power save disabled
Aug 09 06:16:00 490a269 NetworkManager[1917]: <info>  [1691561760.9902] device (wlan0): supplicant interface state: inactive -> interface_disabled
Aug 09 06:16:00 490a269 NetworkManager[1917]: <info>  [1691561760.9903] device (p2p-dev-wlan0): supplicant management interface state: inactive -> interface_disabled
Aug 09 06:16:00 490a269 NetworkManager[1917]: <info>  [1691561760.9952] device (wlan0): supplicant interface state: interface_disabled -> inactive
Aug 09 06:16:00 490a269 NetworkManager[1917]: <info>  [1691561760.9953] device (p2p-dev-wlan0): supplicant management interface state: interface_disabled -> inactive
Aug 09 06:16:47 490a269 healthdog[4651]: try: 1, refid: D9C4912A, correction: 0.000000050, skew: 0.469
Aug 09 06:18:07 490a269 7b0bad39e88d[1968]: [info]    Reported current state to the cloud
Aug 09 06:18:07 490a269 balena-supervisor[2565]: [info]    Reported current state to the cloud
Aug 09 06:18:47 490a269 healthdog[4751]: try: 1, refid: D9C4912A, correction: 0.000000046, skew: 0.469
Aug 09 06:18:55 490a269 7b0bad39e88d[1968]: [api]     GET /v1/healthy 200 - 8.163 ms
Aug 09 06:18:55 490a269 balena-supervisor[2565]: [api]     GET /v1/healthy 200 - 8.163 ms
Aug 09 06:18:55 490a269 7b0bad39e88d[1968]: [debug]   Attempting container log timestamp flush...
Aug 09 06:18:55 490a269 7b0bad39e88d[1968]: [debug]   Container log timestamp flush complete
Aug 09 06:18:55 490a269 balena-supervisor[2565]: [debug]   Attempting container log timestamp flush...
Aug 09 06:18:55 490a269 balena-supervisor[2565]: [debug]   Container log timestamp flush complete
Aug 09 06:20:47 490a269 healthdog[4803]: try: 1, refid: D9C4912A, correction: 0.000000043, skew: 0.469
Aug 09 06:22:47 490a269 healthdog[4832]: try: 1, refid: D9C4912A, correction: 0.000000040, skew: 0.469
Aug 09 06:22:48 490a269 NetworkManager[1917]: <info>  [1691562168.9827] device (wlan0): set-hw-addr: set MAC address to E2:B6:C2:39:DD:20 (scanning)
Aug 09 06:22:48 490a269 kernel: brcmfmac: brcmf_cfg80211_set_power_mgmt: power save disabled
Aug 09 06:22:49 490a269 NetworkManager[1917]: <info>  [1691562169.0098] device (wlan0): supplicant interface state: inactive -> disconnected
Aug 09 06:22:49 490a269 NetworkManager[1917]: <info>  [1691562169.0100] device (p2p-dev-wlan0): supplicant management interface state: inactive -> disconnected
Aug 09 06:22:49 490a269 NetworkManager[1917]: <info>  [1691562169.0307] device (wlan0): supplicant interface state: disconnected -> inactive
Aug 09 06:22:49 490a269 NetworkManager[1917]: <info>  [1691562169.0309] device (p2p-dev-wlan0): supplicant management interface state: disconnected -> inactive
Aug 09 06:23:08 490a269 7b0bad39e88d[1968]: [info]    Reported current state to the cloud
Aug 09 06:23:08 490a269 balena-supervisor[2565]: [info]    Reported current state to the cloud
Aug 09 06:23:55 490a269 7b0bad39e88d[1968]: [api]     GET /v1/healthy 200 - 6.712 ms
Aug 09 06:23:55 490a269 balena-supervisor[2565]: [api]     GET /v1/healthy 200 - 6.712 ms
Aug 09 06:24:47 490a269 healthdog[4891]: try: 1, refid: D9C4912A, correction: 0.000000037, skew: 0.469
Aug 09 06:25:02 490a269 sh[4892]: Getting image name and version...
Aug 09 06:25:02 490a269 sh[4892]: No supervisor configuration found from API.
Aug 09 06:25:02 490a269 sh[4892]: Using preloaded values.
Aug 09 06:25:02 490a269 sh[4892]: Set based on preloaded values image=registry2.balena-cloud.com/v2/94e0105759d7df961f2d91b4cedf4f5e and version=v14.11.12.
Aug 09 06:25:02 490a269 sh[4892]: Getting image id...
Aug 09 06:25:02 490a269 sh[4892]: Supervisor registry2.balena-cloud.com/v2/94e0105759d7df961f2d91b4cedf4f5e at version v14.11.12 already downloaded.
Aug 09 06:26:47 490a269 healthdog[4947]: try: 1, refid: D9C4912A, correction: 0.000000033, skew: 0.469
Aug 09 06:28:47 490a269 healthdog[5014]: try: 1, refid: D9C4912A, correction: 0.000000030, skew: 0.469
Aug 09 06:28:55 490a269 7b0bad39e88d[1968]: [debug]   Attempting container log timestamp flush...
Aug 09 06:28:55 490a269 7b0bad39e88d[1968]: [debug]   Container log timestamp flush complete
Aug 09 06:28:55 490a269 balena-supervisor[2565]: [debug]   Attempting container log timestamp flush...
Aug 09 06:28:55 490a269 balena-supervisor[2565]: [debug]   Container log timestamp flush complete
Aug 09 06:28:56 490a269 7b0bad39e88d[1968]: [api]     GET /v1/healthy 200 - 6.684 ms
Aug 09 06:28:56 490a269 balena-supervisor[2565]: [api]     GET /v1/healthy 200 - 6.684 ms
Aug 09 06:29:36 490a269 NetworkManager[1917]: <info>  [1691562576.9816] device (wlan0): set-hw-addr: set MAC address to 3A:6E:07:EE:09:69 (scanning)
Aug 09 06:29:36 490a269 kernel: brcmfmac: brcmf_cfg80211_set_power_mgmt: power save disabled
Aug 09 06:29:36 490a269 NetworkManager[1917]: <info>  [1691562576.9920] device (wlan0): supplicant interface state: inactive -> disconnected
Aug 09 06:29:36 490a269 NetworkManager[1917]: <info>  [1691562576.9921] device (p2p-dev-wlan0): supplicant management interface state: inactive -> disconnected
Aug 09 06:29:36 490a269 NetworkManager[1917]: <info>  [1691562576.9951] device (wlan0): supplicant interface state: disconnected -> inactive
Aug 09 06:29:36 490a269 NetworkManager[1917]: <info>  [1691562576.9953] device (p2p-dev-wlan0): supplicant management interface state: disconnected -> inactive
Aug 09 06:30:47 490a269 healthdog[5172]: try: 1, refid: D9C4912A, correction: 0.000000027, skew: 0.469
Aug 09 06:31:51 490a269 7b0bad39e88d[1968]: [info]    Reported current state to the cloud
Aug 09 06:31:51 490a269 balena-supervisor[2565]: [info]    Reported current state to the cloud
Aug 09 06:32:48 490a269 healthdog[5265]: try: 1, refid: D9C4912A, correction: 0.000000023, skew: 0.469
Aug 09 06:33:56 490a269 7b0bad39e88d[1968]: [api]     GET /v1/healthy 200 - 7.575 ms
Aug 09 06:33:56 490a269 balena-supervisor[2565]: [api]     GET /v1/healthy 200 - 7.575 ms
Aug 09 06:34:48 490a269 healthdog[5315]: try: 1, refid: D9C4912A, correction: 0.000000020, skew: 0.469
Aug 09 06:36:23 490a269 NetworkManager[1917]: <info>  [1691562983.9889] device (wlan0): set-hw-addr: set MAC address to 8A:CE:B7:A1:90:FC (scanning)
Aug 09 06:36:23 490a269 kernel: brcmfmac: brcmf_cfg80211_set_power_mgmt: power save disabled
Aug 09 06:36:48 490a269 healthdog[5347]: try: 1, refid: D9C4912A, correction: 0.000000017, skew: 0.469
Aug 09 06:36:52 490a269 7b0bad39e88d[1968]: [info]    Reported current state to the cloud
Aug 09 06:36:52 490a269 balena-supervisor[2565]: [info]    Reported current state to the cloud

golemun · August 9, 2023, 6:59am

I also tried setting hdmi_safe=1 and I am wondering if this is hitting us, we have mostly raspberry pi 4b+ rev 1.5 (but not exclusively).

golemun · August 15, 2023, 5:35pm

I am still working on this and what I tried is to isolate combinations of raspberry pi 4s with balena images.
What always works: Taking a combination of Pi 4 (for example a rev 1.5) and balena 3.1.1. which is not working. Now I just took a standard raspbian image and tried all of those raspberry / touch screen combinations that were not working before with the raspbian image - all of them worked. I did this to rule out any cable / monitor issues.
I still have no idea what is causing this.