Latest system update to 6.1.21-v8+broke the RPi Reporter

[Anto79-ops]

I updated my RPi4 today (April 14) using sudo apt-get update/upgrade, then restarted the RPi and it seems something has broke with the reporter

bullseye 6.1.21-v8+

my other two RPis are running 6.1.19-v8+ and working fine

here's what I see:
Checklist:

• [ yes] I updated to the latest version available
• [yes ] I checked that my MQTT broker is otherwise working

Release with the issue:
ISP-RPi-mqtt-daemon v1.8.4

Last working release (if known):

Hardware, Operating System, Python version:

Description of problem:

Run our report script 'genBugInfo' on your failing device and include the output here:

Python errors shown in the logs (if applicable):

Password:
==== AUTHENTICATION COMPLETE ===
pi@raspberrypi:~ $ systemctl status isp-rpi-reporter.service
● isp-rpi-reporter.service - RPi Reporter MQTT Client/Daemon
     Loaded: loaded (/opt/RPi-Reporter-MQTT2HA-Daemon/isp-rpi-reporter.service; enabled; vendor preset: enabled)
     Active: active (running) since Fri 2023-04-14 09:26:31 MDT; 4s ago
       Docs: https://github.com/ironsheep/RPi-Reporter-MQTT2HA-Daemon
   Main PID: 1355 (python3)
     Status: "Apr 14 09:26:30 - * NOTIFY: * MQTT connection established."
      Tasks: 4 (limit: 3933)
        CPU: 3.067s
     CGroup: /system.slice/isp-rpi-reporter.service
             └─1355 /usr/bin/python3 -u /opt/RPi-Reporter-MQTT2HA-Daemon/ISP-RPi-mqtt-daemon.py

Apr 14 09:26:32 raspberrypi python3[1355]:     afterMQTTConnect()  # now instead of after?
Apr 14 09:26:32 raspberrypi python3[1355]:   File "/opt/RPi-Reporter-MQTT2HA-Daemon/ISP-RPi-mqtt-daemon.py", line 1799, in afterMQTTConnect
Apr 14 09:26:32 raspberrypi python3[1355]:     handle_interrupt(0)
Apr 14 09:26:32 raspberrypi python3[1355]:   File "/opt/RPi-Reporter-MQTT2HA-Daemon/ISP-RPi-mqtt-daemon.py", line 1782, in handle_interrupt
Apr 14 09:26:32 raspberrypi python3[1355]:     update_values()
Apr 14 09:26:32 raspberrypi python3[1355]:   File "/opt/RPi-Reporter-MQTT2HA-Daemon/ISP-RPi-mqtt-daemon.py", line 1763, in update_values
Apr 14 09:26:32 raspberrypi python3[1355]:     getSystemTemperature()
Apr 14 09:26:32 raspberrypi python3[1355]:   File "/opt/RPi-Reporter-MQTT2HA-Daemon/ISP-RPi-mqtt-daemon.py", line 968, in getSystemTemperature
Apr 14 09:26:32 raspberrypi python3[1355]:     interpretedTemp = float(rpi_gpu_temp_raw)
Apr 14 09:26:32 raspberrypi python3[1355]: ValueError: could not convert string to float: "Can't open device file: /dev/vcio\nTry creating a device file with: sudo mknod /dev/vcio c 100 0"

pi@raspberrypi:~ $ journalctl --unit=isp-rpi-reporter.service -n 100 --no-pager
-- Journal begins at Mon 2022-04-04 08:41:41 MDT, ends at Fri 2023-04-14 09:28:32 MDT. --
Mar 29 07:57:46 raspberrypi systemd[1]: Stopped RPi Reporter MQTT Client/Daemon.
Mar 29 07:57:46 raspberrypi systemd[1]: isp-rpi-reporter.service: Consumed 52.203s CPU time.
Mar 29 07:57:46 raspberrypi systemd[1]: Starting RPi Reporter MQTT Client/Daemon...
Mar 29 07:57:51 raspberrypi systemd[1]: Started RPi Reporter MQTT Client/Daemon.
Mar 29 08:19:54 raspberrypi systemd[1]: Stopping RPi Reporter MQTT Client/Daemon...
Mar 29 08:19:54 raspberrypi systemd[1]: isp-rpi-reporter.service: Succeeded.
Mar 29 08:19:54 raspberrypi systemd[1]: Stopped RPi Reporter MQTT Client/Daemon.
Mar 29 08:19:54 raspberrypi systemd[1]: isp-rpi-reporter.service: Consumed 6.091s CPU time.
Mar 29 08:20:17 raspberrypi systemd[1]: Starting RPi Reporter MQTT Client/Daemon...
Mar 29 08:20:21 raspberrypi systemd[1]: Started RPi Reporter MQTT Client/Daemon.
Mar 29 08:24:18 raspberrypi systemd[1]: Stopping RPi Reporter MQTT Client/Daemon...
Mar 29 08:24:18 raspberrypi systemd[1]: isp-rpi-reporter.service: Succeeded.
Mar 29 08:24:18 raspberrypi systemd[1]: Stopped RPi Reporter MQTT Client/Daemon.
Mar 29 08:24:18 raspberrypi systemd[1]: isp-rpi-reporter.service: Consumed 3.305s CPU time.
-- Boot 236751d95c7440b69f03d50ba25cda1e --
Mar 29 08:26:02 raspberrypi systemd[1]: Starting RPi Reporter MQTT Client/Daemon...
Mar 29 08:26:08 raspberrypi systemd[1]: Started RPi Reporter MQTT Client/Daemon.
Apr 14 08:59:08 raspberrypi systemd[1]: Stopping RPi Reporter MQTT Client/Daemon...
Apr 14 08:59:08 raspberrypi systemd[1]: isp-rpi-reporter.service: Succeeded.
Apr 14 08:59:08 raspberrypi systemd[1]: Stopped RPi Reporter MQTT Client/Daemon.
Apr 14 08:59:08 raspberrypi systemd[1]: isp-rpi-reporter.service: Consumed 1h 14.179s CPU time.
-- Boot 265a01cb62f94d1fa63a18664eda8907 --
Apr 14 09:00:52 raspberrypi systemd[1]: Starting RPi Reporter MQTT Client/Daemon...
Apr 14 09:00:58 raspberrypi systemd[1]: Started RPi Reporter MQTT Client/Daemon.
Apr 14 09:00:59 raspberrypi python3[636]: Traceback (most recent call last):
Apr 14 09:00:59 raspberrypi python3[636]:   File "/opt/RPi-Reporter-MQTT2HA-Daemon/ISP-RPi-mqtt-daemon.py", line 1809, in <module>
Apr 14 09:00:59 raspberrypi python3[636]:     afterMQTTConnect()  # now instead of after?
Apr 14 09:00:59 raspberrypi python3[636]:   File "/opt/RPi-Reporter-MQTT2HA-Daemon/ISP-RPi-mqtt-daemon.py", line 1799, in afterMQTTConnect
Apr 14 09:00:59 raspberrypi python3[636]:     handle_interrupt(0)
Apr 14 09:00:59 raspberrypi python3[636]:   File "/opt/RPi-Reporter-MQTT2HA-Daemon/ISP-RPi-mqtt-daemon.py", line 1782, in handle_interrupt
Apr 14 09:00:59 raspberrypi python3[636]:     update_values()
Apr 14 09:00:59 raspberrypi python3[636]:   File "/opt/RPi-Reporter-MQTT2HA-Daemon/ISP-RPi-mqtt-daemon.py", line 1763, in update_values
Apr 14 09:00:59 raspberrypi python3[636]:     getSystemTemperature()
Apr 14 09:00:59 raspberrypi python3[636]:   File "/opt/RPi-Reporter-MQTT2HA-Daemon/ISP-RPi-mqtt-daemon.py", line 968, in getSystemTemperature
Apr 14 09:00:59 raspberrypi python3[636]:     interpretedTemp = float(rpi_gpu_temp_raw)
Apr 14 09:00:59 raspberrypi python3[636]: ValueError: could not convert string to float: "Can't open device file: /dev/vcio\nTry creating a device file with: sudo mknod /dev/vcio c 100 0"
Apr 14 09:02:59 raspberrypi python3[636]: Exception in thread Thread-5:
Apr 14 09:02:59 raspberrypi python3[636]: Traceback (most recent call last):
Apr 14 09:02:59 raspberrypi python3[636]:   File "/usr/lib/python3.9/threading.py", line 954, in _bootstrap_inner
Apr 14 09:02:59 raspberrypi python3[636]:     self.run()
Apr 14 09:02:59 raspberrypi python3[636]:   File "/usr/lib/python3.9/threading.py", line 1266, in run
Apr 14 09:02:59 raspberrypi python3[636]:     self.function(*self.args, **self.kwargs)
Apr 14 09:02:59 raspberrypi python3[636]:   File "/opt/RPi-Reporter-MQTT2HA-Daemon/ISP-RPi-mqtt-daemon.py", line 1490, in periodTimeoutHandler
Apr 14 09:02:59 raspberrypi python3[636]:     handle_interrupt(TIMER_INTERRUPT)  # '0' means we have a timer interrupt!!!
Apr 14 09:02:59 raspberrypi python3[636]:   File "/opt/RPi-Reporter-MQTT2HA-Daemon/ISP-RPi-mqtt-daemon.py", line 1782, in handle_interrupt
Apr 14 09:02:59 raspberrypi python3[636]:     update_values()
Apr 14 09:02:59 raspberrypi python3[636]:   File "/opt/RPi-Reporter-MQTT2HA-Daemon/ISP-RPi-mqtt-daemon.py", line 1763, in update_values
Apr 14 09:02:59 raspberrypi python3[636]:     getSystemTemperature()
Apr 14 09:02:59 raspberrypi python3[636]:   File "/opt/RPi-Reporter-MQTT2HA-Daemon/ISP-RPi-mqtt-daemon.py", line 968, in getSystemTemperature
Apr 14 09:02:59 raspberrypi python3[636]:     interpretedTemp = float(rpi_gpu_temp_raw)
Apr 14 09:02:59 raspberrypi python3[636]: ValueError: could not convert string to float: "Can't open device file: /dev/vcio\nTry creating a device file with: sudo mknod /dev/vcio c 100 0"
Apr 14 09:23:19 raspberrypi systemd[1]: Stopping RPi Reporter MQTT Client/Daemon...
Apr 14 09:23:19 raspberrypi systemd[1]: isp-rpi-reporter.service: Succeeded.
Apr 14 09:23:19 raspberrypi systemd[1]: Stopped RPi Reporter MQTT Client/Daemon.
Apr 14 09:23:19 raspberrypi systemd[1]: isp-rpi-reporter.service: Consumed 3.616s CPU time.
Apr 14 09:23:19 raspberrypi systemd[1]: Starting RPi Reporter MQTT Client/Daemon...
Apr 14 09:23:23 raspberrypi systemd[1]: Started RPi Reporter MQTT Client/Daemon.
Apr 14 09:23:24 raspberrypi python3[1128]: Traceback (most recent call last):
Apr 14 09:23:24 raspberrypi python3[1128]:   File "/opt/RPi-Reporter-MQTT2HA-Daemon/ISP-RPi-mqtt-daemon.py", line 1809, in <module>
Apr 14 09:23:24 raspberrypi python3[1128]:     afterMQTTConnect()  # now instead of after?
Apr 14 09:23:24 raspberrypi python3[1128]:   File "/opt/RPi-Reporter-MQTT2HA-Daemon/ISP-RPi-mqtt-daemon.py", line 1799, in afterMQTTConnect
Apr 14 09:23:24 raspberrypi python3[1128]:     handle_interrupt(0)
Apr 14 09:23:24 raspberrypi python3[1128]:   File "/opt/RPi-Reporter-MQTT2HA-Daemon/ISP-RPi-mqtt-daemon.py", line 1782, in handle_interrupt
Apr 14 09:23:24 raspberrypi python3[1128]:     update_values()
Apr 14 09:23:24 raspberrypi python3[1128]:   File "/opt/RPi-Reporter-MQTT2HA-Daemon/ISP-RPi-mqtt-daemon.py", line 1763, in update_values
Apr 14 09:23:24 raspberrypi python3[1128]:     getSystemTemperature()
Apr 14 09:23:24 raspberrypi python3[1128]:   File "/opt/RPi-Reporter-MQTT2HA-Daemon/ISP-RPi-mqtt-daemon.py", line 968, in getSystemTemperature
Apr 14 09:23:24 raspberrypi python3[1128]:     interpretedTemp = float(rpi_gpu_temp_raw)
Apr 14 09:23:24 raspberrypi python3[1128]: ValueError: could not convert string to float: "Can't open device file: /dev/vcio\nTry creating a device file with: sudo mknod /dev/vcio c 100 0"
Apr 14 09:23:46 raspberrypi systemd[1]: Stopping RPi Reporter MQTT Client/Daemon...
Apr 14 09:23:46 raspberrypi systemd[1]: isp-rpi-reporter.service: Succeeded.
Apr 14 09:23:46 raspberrypi systemd[1]: Stopped RPi Reporter MQTT Client/Daemon.
Apr 14 09:23:46 raspberrypi systemd[1]: isp-rpi-reporter.service: Consumed 3.025s CPU time.
Apr 14 09:26:27 raspberrypi systemd[1]: Starting RPi Reporter MQTT Client/Daemon...
Apr 14 09:26:31 raspberrypi systemd[1]: Started RPi Reporter MQTT Client/Daemon.
Apr 14 09:26:32 raspberrypi python3[1355]: Traceback (most recent call last):
Apr 14 09:26:32 raspberrypi python3[1355]:   File "/opt/RPi-Reporter-MQTT2HA-Daemon/ISP-RPi-mqtt-daemon.py", line 1809, in <module>
Apr 14 09:26:32 raspberrypi python3[1355]:     afterMQTTConnect()  # now instead of after?
Apr 14 09:26:32 raspberrypi python3[1355]:   File "/opt/RPi-Reporter-MQTT2HA-Daemon/ISP-RPi-mqtt-daemon.py", line 1799, in afterMQTTConnect
Apr 14 09:26:32 raspberrypi python3[1355]:     handle_interrupt(0)
Apr 14 09:26:32 raspberrypi python3[1355]:   File "/opt/RPi-Reporter-MQTT2HA-Daemon/ISP-RPi-mqtt-daemon.py", line 1782, in handle_interrupt
Apr 14 09:26:32 raspberrypi python3[1355]:     update_values()
Apr 14 09:26:32 raspberrypi python3[1355]:   File "/opt/RPi-Reporter-MQTT2HA-Daemon/ISP-RPi-mqtt-daemon.py", line 1763, in update_values
Apr 14 09:26:32 raspberrypi python3[1355]:     getSystemTemperature()
Apr 14 09:26:32 raspberrypi python3[1355]:   File "/opt/RPi-Reporter-MQTT2HA-Daemon/ISP-RPi-mqtt-daemon.py", line 968, in getSystemTemperature
Apr 14 09:26:32 raspberrypi python3[1355]:     interpretedTemp = float(rpi_gpu_temp_raw)
Apr 14 09:26:32 raspberrypi python3[1355]: ValueError: could not convert string to float: "Can't open device file: /dev/vcio\nTry creating a device file with: sudo mknod /dev/vcio c 100 0"
Apr 14 09:28:32 raspberrypi python3[1355]: Exception in thread Thread-5:
Apr 14 09:28:32 raspberrypi python3[1355]: Traceback (most recent call last):
Apr 14 09:28:32 raspberrypi python3[1355]:   File "/usr/lib/python3.9/threading.py", line 954, in _bootstrap_inner
Apr 14 09:28:32 raspberrypi python3[1355]:     self.run()
Apr 14 09:28:32 raspberrypi python3[1355]:   File "/usr/lib/python3.9/threading.py", line 1266, in run
Apr 14 09:28:32 raspberrypi python3[1355]:     self.function(*self.args, **self.kwargs)
Apr 14 09:28:32 raspberrypi python3[1355]:   File "/opt/RPi-Reporter-MQTT2HA-Daemon/ISP-RPi-mqtt-daemon.py", line 1490, in periodTimeoutHandler
Apr 14 09:28:32 raspberrypi python3[1355]:     handle_interrupt(TIMER_INTERRUPT)  # '0' means we have a timer interrupt!!!
Apr 14 09:28:32 raspberrypi python3[1355]:   File "/opt/RPi-Reporter-MQTT2HA-Daemon/ISP-RPi-mqtt-daemon.py", line 1782, in handle_interrupt
Apr 14 09:28:32 raspberrypi python3[1355]:     update_values()
Apr 14 09:28:32 raspberrypi python3[1355]:   File "/opt/RPi-Reporter-MQTT2HA-Daemon/ISP-RPi-mqtt-daemon.py", line 1763, in update_values
Apr 14 09:28:32 raspberrypi python3[1355]:     getSystemTemperature()
Apr 14 09:28:32 raspberrypi python3[1355]:   File "/opt/RPi-Reporter-MQTT2HA-Daemon/ISP-RPi-mqtt-daemon.py", line 968, in getSystemTemperature
Apr 14 09:28:32 raspberrypi python3[1355]:     interpretedTemp = float(rpi_gpu_temp_raw)
Apr 14 09:28:32 raspberrypi python3[1355]: ValueError: could not convert string to float: "Can't open device file: /dev/vcio\nTry creating a device file with: sudo mknod /dev/vcio c 100 0"

Additional information:

[Anto79-ops]

Ok, I can confirm its related to some system update. I just ran updates on my second RPi (sudo apt-get update/upgrade), and rebooted and now RPi Reporter is broken on my second RPi with the same error message as above.

2 of 3 down. I guess I won't update my 3rd RPi... ahhh :)

[Anto79-ops]

another thing I would like to mention is that if I stop the service and run the RPi Reporter manually, it actually works and updates every 2 minutes, for example:

pi@raspberrypi:~ $ python3 /opt/RPi-Reporter-MQTT2HA-Daemon/ISP-RPi-mqtt-daemon.py
[2023-04-14 10:10:15] * NOTIFY: MQTT subscripton to raspberrypi/nodes/radon-rpi/command/radon-spi/+ disabled
[2023-04-14 10:10:15] * NOTIFY: * MQTT connection established
[2023-04-14 10:10:15] 
[2023-04-14 10:10:16] Announcing RPi Monitoring device to MQTT broker for auto-discovery ...
[2023-04-14 10:10:17] Publishing to MQTT topic "raspberrypi/nodes/radon-rpi/sensor/radon-spi/monitor, Data:{"info": {"timestamp": "2023-04-14T10:10:16-06:00", "rpi_model": "RPi 4 Model B r1.2", "ifaces": "e,w,b", "host_name": "raspberrypi", "fqdn": "raspberrypi", "ux_release": "bullseye", "ux_version": "6.1.21-v8+", "ux_updates": 0, "up_time": "9 min", "up_time_secs": 540, "last_update": "2023-04-14T11:34:36-06:00", "fs_total_gb": 32, "fs_free_prcnt": 71, "fs_used_prcnt": 29, "networking": {"eth0": {"IP": "[redacted]", "mac": "[redacted]", "rx_data": 3923, "tx_data": 7984}, "wlan0": {"mac": "[redacted]", "rx_data": 0, "tx_data": 0}}, "drives": {"root": {"size_gb": 32, "used_prcnt": 29, "device": "/dev/root", "mount_pt": "/"}}, "memory": {"size_mb": 3794, "free_mb": 3483, "size_swap": 100, "free_swap": 100}, "mem_used_prcnt": 8, "cpu": {"hardware": "BCM2835", "model": "", "number_cores": 4, "bogo_mips": "432.00", "serial": "[redacted]", "load_1min_prcnt": 8.0, "load_5min_prcnt": 8.5, "load_15min_prcnt": 6.8}, "throttle": ["throttled = 0x0", "Not throttled"], "temperature_c": 37.0, "temp_gpu_c": 37.0, "temp_cpu_c": 38.0, "reporter": "ISP-RPi-mqtt-daemon v1.8.4", "reporter_releases": "v1.8.4,v1.7.2,v1.7.3,v1.7.4,v1.8.3", "report_interval": 2}}"
[2023-04-14 10:12:18] Publishing to MQTT topic "raspberrypi/nodes/radon-rpi/sensor/radon-spi/monitor, Data:{"info": {"timestamp": "2023-04-14T10:12:16-06:00", "rpi_model": "RPi 4 Model B r1.2", "ifaces": "e,w,b", "host_name": "raspberrypi", "fqdn": "raspberrypi", "ux_release": "bullseye", "ux_version": "6.1.21-v8+", "ux_updates": 0, "up_time": "11 min", "up_time_secs": 660, "last_update": "2023-04-14T11:34:36-06:00", "fs_total_gb": 32, "fs_free_prcnt": 71, "fs_used_prcnt": 29, "networking": {"eth0": {"IP": "[redacted]", "mac": "[redacted]", "rx_data": 149, "tx_data": 293}, "wlan0": {"mac": "[redacted]", "rx_data": 0, "tx_data": 0}}, "drives": {"root": {"size_gb": 32, "used_prcnt": 29, "device": "/dev/root", "mount_pt": "/"}}, "memory": {"size_mb": 3794, "free_mb": 3487, "size_swap": 100, "free_swap": 100}, "mem_used_prcnt": 8, "cpu": {"hardware": "BCM2835", "model": "", "number_cores": 4, "bogo_mips": "432.00", "serial": "[redacted]", "load_1min_prcnt": 6.0, "load_5min_prcnt": 7.8, "load_15min_prcnt": 6.8}, "throttle": ["throttled = 0x0", "Not throttled"], "temperature_c": 35.5, "temp_gpu_c": 35.5, "temp_cpu_c": 35.5, "reporter": "ISP-RPi-mqtt-daemon v1.8.4", "reporter_releases": "v1.8.4,v1.7.2,v1.7.3,v1.7.4,v1.8.3", "report_interval": 2}}"

[bsimmo]

Given I tested. .21 for RPL and it is the SenseHAT fix, mine are still working fine and have been for a eek or so.
Will check though.

[Anto79-ops]

interesting. Maybe its not related to .21 but something else to .21. Having 2 RPi down, something changed for sure.

[ironsheep]

@Anto79-ops I have updated a number of RPi 4's here and am not seeing any issues.

Since the errors you show appear to be access to temps can you please recheck that your daemon account has the correct permissions?
https://github.com/ironsheep/RPi-Reporter-MQTT2HA-Daemon#set-up-daemon-account-to-allow-access-to-temperature-values

(Since you can run interactively, it seems to be an issue with the Daemon account.)

[Anto79-ops]

hey! that was it. Problem is fixed after repeating those steps.

I wonder how that got reset?

thank you for your help.

Closing