ironsheep / RPi-Reporter-MQTT2HA-Daemon

Linux service to collect and transfer Raspberry Pi data via MQTT to Home Assistant (for RPi Monitoring)
GNU General Public License v3.0
475 stars 64 forks source link

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

Closed Anto79-ops closed 1 year ago

Anto79-ops commented 1 year ago

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:

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 commented 1 year ago

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 commented 1 year ago

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 commented 1 year ago

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 commented 1 year ago

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

ironsheep commented 1 year ago

@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 commented 1 year ago

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

I wonder how that got reset?

thank you for your help.

Closing