AIO failing to respond to predbat "commands"

Hi,

My AIO was due to go into charge mode at 13:00. but failed to do so. It appears from the following log extract that updating the inverter has failed repeatedly. I suspected a timeout at the inverter, but when I go into the GE dashboard and add a timed charge slot manually, all is OK.

Can anybody point me in the right direction to diagnose the issue?

PS - I know why I am getting the missing data, so I don't ythink that is the source of the problem

2024-10-02 13:01:23.751400: Warn: Inverter 0 Trying to write pause_mode to Disabled didn't complete got PauseDischarge
2024-10-02 13:01:23.873828: Info: record_status Warn: Inverter 0 write to pause_mode failed
2024-10-02 13:03:58.367989: Warn: Inverter 0 Trying to write scheduled_charge_enable to True didn't complete got off
2024-10-02 13:03:58.494725: Info: record_status Warn: Inverter 0 write to scheduled_charge_enable failed
2024-10-02 13:04:59.252705: Warn: Inverter 0 Trying to write 73 to charge_limit didn't complete got 15
2024-10-02 13:04:59.329955: Info: record_status Warn: Inverter 0 write to charge_limit failed
2024-10-02 13:07:28.792494: Warn: Inverter 0 Trying to write pause_mode to Disabled didn't complete got PauseDischarge
2024-10-02 13:07:29.201893: Info: record_status Warn: Inverter 0 write to pause_mode failed
2024-10-02 13:08:29.823205: Warn: Inverter 0 Trying to write scheduled_charge_enable to True didn't complete got off
2024-10-02 13:08:29.890494: Info: record_status Warn: Inverter 0 write to scheduled_charge_enable failed
2024-10-02 13:08:57.523750: Warn: Historical day 3 has 715 minutes of gap in the data, filled from 14.83 kWh to make new average 29.46 kWh (percent 50%)
2024-10-02 13:10:57.061680: Warn: Inverter 0 Trying to write scheduled_charge_enable to True didn't complete got off
2024-10-02 13:10:57.128588: Info: record_status Warn: Inverter 0 write to scheduled_charge_enable failed
2024-10-02 13:11:05.379440: Warn: Historical day 3 has 720 minutes of gap in the data, filled from 14.6 kWh to make new average 29.2 kWh (percent 50%)
2024-10-02 13:15:36.785401: Warn: Inverter 0 Trying to write 100 to charge_limit didn't complete got 73
2024-10-02 13:15:37.058622: Info: record_status Warn: Inverter 0 write to charge_limit failed
2024-10-02 13:15:46.164010: Warn: Historical day 3 has 725 minutes of gap in the data, filled from 14.4 kWh to make new average 29.0 kWh (percent 50%)

Weasel Have a look at what’s in the GivTCP log as well.

It points to comms failures between Home Assistant, GivTCP and your AIO. Check your AIO is online on your network. Try restarting the GivTCP add-on, and if that doesn’t work, do a ‘reset to defaults’ of the AIO through the GivEnergy portal.

geoffreycoan

I think I might have found something... The GIvTCP log shows that it finds my AIO, but does not find the Gateway - or at least it fails to connect to it at 192.168.1.136. I will see if the GW is indeed at that IP address (it used to be) and try to get it reset/back online. This will probably happen tomorrow for me, but in the meantime, can I exclude the GW somehow?

2024-10-02 14:11:08,402 - Startup - startup     -  [INFO    ] - ==================== STARTING GivTCP==========================
2024-10-02 14:11:10,461 - Startup - startup     -  [INFO    ] - Searching for Inverters
2024-10-02 14:11:10,462 - Startup - startup     -  [INFO    ] - Scanning network for GivEnergy Devices...
2024-10-02 14:11:22,711 - Startup - client      -  [INFO    ] - Connection established to 192.168.1.213:8899
2024-10-02 14:11:22,712 - Startup - client      -  [INFO    ] - Detecting plant
2024-10-02 14:11:23,876 - Startup - client      -  [INFO    ] - Plant Detected
2024-10-02 14:11:31,400 - Startup - startup     -  [INFO    ] - Inverter CD2347G136 which is a Gen1 - All_in_one with 4 batteries has been found at: 192.168.1.213
2024-10-02 14:11:31,419 - Startup - startup     -  [INFO    ] - Setting up invertor: 1
2024-10-02 14:11:31,555 - Startup - startup     -  [INFO    ] - ==============================================================
2024-10-02 14:11:31,556 - Startup - startup     -  [INFO    ] - ====             Web Gui Config is at                     ====
2024-10-02 14:11:31,557 - Startup - startup     -  [INFO    ] - ====     http://192.168.1.117:8099/config.html             ====
2024-10-02 14:11:31,558 - Startup - startup     -  [INFO    ] - ==============================================================
2024-10-02 14:11:31,560 - Startup - startup     -  [INFO    ] - Running Invertor 1 (GW2335G432) read loop every 30/120s
2024-10-02 14:11:31,566 - Startup - startup     -  [INFO    ] - Setting up invertor: 2
2024-10-02 14:11:31,786 - Startup - startup     -  [INFO    ] - ==============================================================
2024-10-02 14:11:31,788 - Startup - startup     -  [INFO    ] - ====             Web Gui Config is at                     ====
2024-10-02 14:11:31,790 - Startup - startup     -  [INFO    ] - ====     http://192.168.1.117:8099/config.html             ====
2024-10-02 14:11:31,791 - Startup - startup     -  [INFO    ] - ==============================================================
2024-10-02 14:11:31,802 - Startup - startup     -  [INFO    ] - Running Invertor 2 (CD2347G136) read loop every 30/120s
2024-10-02 14:11:31,823 - Startup - startup     -  [INFO    ] - Serving Web Dashboard from port 3000
[2024-10-02 14:11:32 +0100] [80] [INFO] Starting gunicorn 23.0.0
[2024-10-02 14:11:32 +0100] [80] [INFO] Listening at: http://0.0.0.0:6345 (80)
[2024-10-02 14:11:32 +0100] [80] [INFO] Using worker: sync
[2024-10-02 14:11:32 +0100] [95] [INFO] Booting worker with pid: 95
[2024-10-02 14:11:32 +0100] [96] [INFO] Booting worker with pid: 96
[2024-10-02 14:11:32 +0100] [97] [INFO] Booting worker with pid: 97
[2024-10-02 14:11:33 +0100] [83] [INFO] Starting gunicorn 23.0.0
[2024-10-02 14:11:33 +0100] [83] [INFO] Listening at: http://0.0.0.0:6346 (83)
[2024-10-02 14:11:33 +0100] [83] [INFO] Using worker: sync
[2024-10-02 14:11:33 +0100] [98] [INFO] Booting worker with pid: 98
[2024-10-02 14:11:33 +0100] [99] [INFO] Booting worker with pid: 99
[2024-10-02 14:11:33 +0100] [100] [INFO] Booting worker with pid: 100
(node:84) [DEP0040] DeprecationWarning: The `punycode` module is deprecated. Please use a userland alternative instead.
(Use `node --trace-deprecation ...` to show where the warning was created)
2024-10-02 14:11:39,400 - Inv1 - read        -  [INFO    ] - Starting watch_plant loop...
2024-10-02 14:11:40,625 - Inv2 - read        -  [INFO    ] - Starting watch_plant loop...
2024-10-02 14:11:40,642 - Inv2 - read        -  [CRITICAL] - Detecting inverter characteristics...
 INFO  Accepting connections at http://localhost:3000
2024-10-02 14:11:41,416 - Inv1 - read        -  [ERROR   ] - Unable to connect to inverter on: 192.168.1.136
2024-10-02 14:11:41,423 - Inv1 - read        -  [ERROR   ] - Error in self_run. Re-running watch_plant: ('UnboundLocalError', 'read.py', 1858)

I set the following in the GivTCP settings JSON file
"inverter_enable_1": false,
to stop GivTCP trying to talk to the gateway, but I sttill had the following erro in the GivTCP log

2024-10-02 14:46:19,806 - Inv2 - read        -  [INFO    ] - Publishing Home Assistant Discovery messages
2024-10-02 14:46:25,929 - Inv2 - HA_Discovery -  [ERROR   ] - Error connecting to MQTT Broker: ('RuntimeError', 398)

I restarted Mosquitto broker and so far have no error messages in the GivTCP log

I will keep you updated once I restart predbat

Weasel Assume you only have a single AIO and not multiple?

If you have a single AIO then Predbat should do all commands to that AIO, if it’s a multi-AIO setup then all the commands should go to the gateway.

So with a single AIO, failure to talk to the gateway shouldn’t be an issue. I don’t think you can stop GivTCP from finding and trying to communicate with the gateway, in v3 it now auto discovers GivEnergy devices on your network.

The AIO is found first so those devices are prefixed givtcp, the gateway device is second so prefixed givtcp2, so just make sure that in your apps.yaml it is pointing to use geserial and that you have commented out the geserial2 and givtcp2_ lines to stop predbat from trying to control the gateway.
The error messages were from inverter 0 so I don’t think this is an issue for you, but worth checking.

geoffreycoan In my case, the gateway was discovered first and the AIO was second and is thus prefixed with givtcp2. I figured that out pretty quickly a week or more ago and predbat has been working flawlessly for what I was using it for until this afternoon when it borked.

The steps I took earlier seem to have done the trick, but the proof will be later when I enter a forced export. This is my first day with a predbat configuration that will actively try to export during peak periods. My expected forced export time will start at 17:30, but I am quietly hopeful

Once I am happy that this issue is resolved, I will move onto my next "snag", but that's something for another day and another thread

Weasel And all appears to be well ie. the battery changes state appropriately and this is reflected in the GivEnergy app and dashboard.

I might start to see if I can tweak the settings to better bias export during the timed discharge sessions. For some reason, predbat has initiated a pause in my export at a point where I have 69% SOC.

Weasel For some reason, predbat has initiated a pause in my export at a point where I have 69% SOC.

Based on your predicted house load and future solar generation, Predbat probably figures that you need to continue charging the battery rather than exporting any more.
Its worth looking at the future predbat plan and seeing how the SoC changes over time. And Predbat runs every 5 minutes so it may re-evaluate the plan and change its mind in 5 minutes time, especially if the financial benefit is very finely balanced!

geoffreycoan Agreed. Predbat is definitely predicting the future load until the next charging cycle. It took me a while to figure it out, but I eventually got there 🙂