batpred icon indicating copy to clipboard operation
batpred copied to clipboard

Numerous Auto-restart triggered when GivTCP has Error getting data from cache

Open apone2000 opened this issue 8 months ago • 1 comments

Describe the bug Several times per day Predbat is having to restart givtcp as it think its timed out. Not sure if it has or if predbat is detecting failure incorrectly, so putting bug here and on givtcp issues list. On calling restart all comes back to life, so the restart scripts all work fine. https://github.com/britkat1980/giv_tcp/issues/388

Predbat version 1.2.4 / v8.18.12

Environment details GivEnergy AC3 inverter with 3x5kwh batteries. D0.210-A0.210 inverter firmwar 3020 battery firmware RTC enabled

HAOS 15.1 running in virtual box on a PC, Home Assistant Core 2025.4.1

Note: this may be a predbat issue or givTCP, but started when i did the givtcp upgrade. https://github.com/britkat1980/giv_tcp/issues/388 bug raised on givtcp board too

Since upgrading to giveTCP 3.1.6 for RTC entities I now get several restarts via Predbat each day.

from predbat logs 2025-04-30 09:01:43.825464: Error: Auto-restart triggered 2025-04-30 09:11:42.335005: Error: Auto-restart triggered 2025-04-30 09:41:43.400811: Error: Auto-restart triggered 2025-04-30 10:01:46.395532: Error: Auto-restart triggered 2025-04-30 10:50:20.081391: Error: Auto-restart triggered 2025-04-30 12:26:43.318414: Error: Auto-restart triggered 2025-04-30 12:55:19.456025: Error: Auto-restart triggered 2025-04-30 13:10:19.839046: Error: Auto-restart triggered 2025-04-30 13:45:19.960829: Error: Auto-restart triggered 2025-04-30 14:26:41.438146: Error: Auto-restart triggered 2025-04-30 16:10:19.620160: Error: Auto-restart triggered 2025-04-30 16:45:19.487760: Error: Auto-restart triggered 2025-04-30 17:16:38.218739: Error: Auto-restart triggered 2025-04-30 17:45:20.134205: Error: Auto-restart triggered 2025-04-30 18:10:19.560780: Error: Auto-restart triggered 2025-04-30 19:55:19.866908: Error: Auto-restart triggered 2025-04-30 20:31:39.199275: Error: Auto-restart triggered 2025-04-30 21:06:35.285531: Error: Auto-restart triggered

Logs from givTCP log for some of the same time entries

2025-04-30 09:01:28,048 - GivTCP - read - [ERROR ] - Error getting data from cache: ('AttributeError', 'read.py', 2167) 2025-04-30 09:01:28,077 - GivTCP - read - [ERROR ] - Error getting data from cache: ('AttributeError', 'read.py', 2167) 2025-04-30 09:01:38,902 - GivTCP - read - [ERROR ] - inverter Update failed so using last known good data from cache: ((<class 'Exception'>, Exception('Process Data Failure'), <traceback object at 0x7f88e715fb80>), 1949) 2025-04-30 09:01:38,904 - GivTCP - read - [ERROR ] - runAll2 Error processing registers: ('KeyError', 'read.py', 2130)

2025-04-30 13:45:04,158 - GivTCP - read - [ERROR ] - Error getting data from cache: ('AttributeError', 'read.py', 2167) 2025-04-30 13:45:04,169 - GivTCP - read - [ERROR ] - Error getting data from cache: ('AttributeError', 'read.py', 2167) 2025-04-30 13:45:05,853 - GivTCP - read - [ERROR ] - inverter Update failed so using last known good data from cache: ((<class 'Exception'>, Exception('Process Data Failure'), <traceback object at 0x7f92dc31b640>), 1949) 2025-04-30 13:45:05,853 - GivTCP - read - [ERROR ] - runAll2 Error processing registers: ('KeyError', 'read.py', 2130)

2025-04-30 18:10:03,579 - GivTCP - read - [ERROR ] - Error getting data from cache: ('AttributeError', 'read.py', 2167) 2025-04-30 18:10:03,589 - GivTCP - read - [ERROR ] - Error getting data from cache: ('AttributeError', 'read.py', 2167) 2025-04-30 18:10:08,894 - GivTCP - read - [ERROR ] - inverter Update failed so using last known good data from cache: ((<class 'Exception'>, Exception('Process Data Failure'), <traceback object at 0x7f92dc2e3c40>), 1949) 2025-04-30 18:10:08,895 - GivTCP - read - [ERROR ] - runAll2 Error processing registers: ('KeyError', 'read.py', 2130)

2025-04-30 19:55:03,964 - GivTCP - read - [ERROR ] - Error getting data from cache: ('AttributeError', 'read.py', 2167) 2025-04-30 19:55:03,974 - GivTCP - read - [ERROR ] - Error getting data from cache: ('AttributeError', 'read.py', 2167)

2025-04-30 20:31:23,401 - GivTCP - read - [ERROR ] - Error getting data from cache: ('AttributeError', 'read.py', 2167) 2025-04-30 20:31:23,413 - GivTCP - read - [ERROR ] - Error getting data from cache: ('AttributeError', 'read.py', 2167)

2025-04-30 21:06:19,507 - GivTCP - read - [ERROR ] - Error getting data from cache: ('AttributeError', 'read.py', 2167) 2025-04-30 21:06:19,521 - GivTCP - read - [ERROR ] - Error getting data from cache: ('AttributeError', 'read.py', 2167)

FOllowing is also from predbat for the 18:10 restart for extra info on what it was doing: 2025-04-30 18:10:03.593187: Warn: Inverter 0 read bad REST data from http://homeassistant.local:6345/runAll - REST will be disabled 2025-04-30 18:10:03.607076: Warn: record_status Inverter 0 read bad REST data from http://homeassistant.local:6345/runAll - REST will be disabled 2025-04-30 18:10:03.607269: Warn: Inverter control auto restart trigger: REST read failure command [{'shell': 'rm -rf /homeassistant/GivTCP/.pkl'}, {'service': 'hassio/addon_restart', 'addon': 'a6a2857d_givtcp'}] 2025-04-30 18:10:03.607304: Warn: Calling restart shell command: rm -rf /homeassistant/GivTCP/.pkl 2025-04-30 18:10:03.609653: Warn: Calling restart service hassio/addon_restart with addon a6a2857d_givtcp 2025-04-30 18:10:03.636323: Warn: Service call hassio/addon_restart data {'addon': 'a6a2857d_givtcp'} failed with response None 2025-04-30 18:10:19.542032: Error: Exception raised Auto-restart triggered 2025-04-30 18:10:19.543441: Error: Traceback (most recent call last): File "/config/predbat.py", line 1392, in run_time_loop self.update_pred(scheduled=True) File "/config/predbat.py", line 616, in update_pred self.fetch_inverter_data() File "/config/execute.py", line 643, in fetch_inverter_data inverter = Inverter(self, id) File "/config/inverter.py", line 232, in init self.auto_restart("REST read failure") File "/config/inverter.py", line 101, in auto_restart raise Exception("Auto-restart triggered") Exception: Auto-restart triggered 2025-04-30 18:10:19.560696: Info: record_status Error: Exception raised Auto-restart triggered 2025-04-30 18:10:19.560780: Error: Auto-restart triggered Traceback (most recent call last): File "/config/hass.py", line 190, in timer_tick item"callback" File "/config/predbat.py", line 1397, in run_time_loop raise e File "/config/predbat.py", line 1392, in run_time_loop self.update_pred(scheduled=True) File "/config/predbat.py", line 616, in update_pred self.fetch_inverter_data() File "/config/execute.py", line 643, in fetch_inverter_data inverter = Inverter(self, id) File "/config/inverter.py", line 232, in init self.auto_restart("REST read failure") File "/config/inverter.py", line 101, in auto_restart raise Exception("Auto-restart triggered") Exception: Auto-restart triggered

apone2000 avatar Apr 30 '25 20:04 apone2000

Have you made any progress on this? Restarting GivTCP has not resolved it for me, so now Predbat is dead.

pacemaker82 avatar May 02 '25 07:05 pacemaker82

This is a GivTCP issue, you can disable the Predbat auto restart in apps.yaml if you wish

springfall2008 avatar May 12 '25 10:05 springfall2008

@apone2000 if you are getting lots of read failures on givtcp then I'd suggest looking at the underlying network. If your inverter is connected by wifi then check the signal strength, maybe consider a mesh network or a wifi repeater to improve the connection.

Also your HA server should be hard wired, not wifi connected.

I used to get loads of givtcp problems, moving the HA server to a wired connection and putting in a mesh has improved things. I still get read errors and weirdly more during the hot weather, but its a lot improved

gcoan avatar May 12 '25 10:05 gcoan