britkat1980 / giv_tcp

TCP connection (from inverter) and MQTT implementation
71 stars 32 forks source link

Gen1 AC inverter, no serial number #191

Open jr298 opened 1 week ago

jr298 commented 1 week ago

Having been working reliably for months (thank you) GivTCP suddenly failed to talk to the inverter last night - it looks like this was just after midnight.

I've therefore:

Add-on is currently at 2.4.3 Talking with a Gen1 AC coupled inverter with one battery. Last inverter firmware update was in December (Inverter: D0.535-A0.535; Battery: 3015)

This looks very similar to the recent AIO issues (https://github.com/britkat1980/giv_tcp/issues/189), but this isn't an AIO - and it's been running for months. Any suggestions for further diagnostics?

Cheers,

2024-06-21 08:07:47,880 - startup - [CRITICAL] - HA MQTT Service has been found at core-mosquitto
2024-06-21 08:07:47,884 - startup - [INFO] - Supervisor Timezone: Europe/London
2024-06-21 08:07:49,892 - startup - [CRITICAL] - Scanning network for GivEnergy Devices...
2024-06-21 08:07:53,739 - startup - [CRITICAL] - Inverter CE22****** which is a Gen 1 - AC has been found at: 192.168.7.170
2024-06-21 08:07:53,740 - startup - [INFO] - Searching for Inverters again
2024-06-21 08:07:53,741 - startup - [CRITICAL] - Running Redis
2024-06-21 08:07:53,743 - startup - [CRITICAL] - Setting up invertor: 1 of 1
2024/06/21 08:07:53 [notice] 69#69: using the "epoll" event method
2024/06/21 08:07:53 [notice] 69#69: nginx/1.20.2
2024/06/21 08:07:53 [notice] 69#69: OS: Linux 6.6.33-haos
2024/06/21 08:07:53 [notice] 69#69: getrlimit(RLIMIT_NOFILE): 1073741816:1073741816
2024/06/21 08:07:53 [notice] 69#69: start worker processes
2024/06/21 08:07:53 [notice] 69#69: start worker process 73
2024/06/21 08:07:53 [notice] 69#69: start worker process 74
2024-06-21 08:07:53,773 - startup - [CRITICAL] - Running RQ worker to queue and process givernergy-modbus calls
2024-06-21 08:07:53,774 - startup - [CRITICAL] - Running Invertor (192.168.7.170) read loop every 20s
2024-06-21 08:07:53,775 - startup - [CRITICAL] - Subscribing MQTT Broker for control
2024-06-21 08:07:53,776 - startup - [CRITICAL] - Starting Gunicorn on port 6345
[2024-06-21 08:07:54 +0100] [78] [INFO] Starting gunicorn 21.2.0
[2024-06-21 08:07:54 +0100] [78] [INFO] Listening at: http://0.0.0.0:6345 (78)
[2024-06-21 08:07:54 +0100] [78] [INFO] Using worker: sync
[2024-06-21 08:07:54 +0100] [79] [INFO] Booting worker with pid: 79
[2024-06-21 08:07:54 +0100] [80] [INFO] Booting worker with pid: 80
[2024-06-21 08:07:54 +0100] [81] [INFO] Booting worker with pid: 81
2024-06-21 08:07:55,323 - Inv1 - mqtt_client -  [CRITICAL] - Connecting to MQTT broker for control- core-mosquitto
2024-06-21 08:09:35,426 - Inv1 - mqtt_client -  [ERROR   ] - No serial_number found in MQTT queue. MQTT Control not available.
Traceback (most recent call last):
  File "/app/GivTCP_1/mqtt_client.py", line 402, in <module>
    client.loop_forever()
  File "/usr/local/lib/python3.10/site-packages/paho/mqtt/client.py", line 1756, in loop_forever
    rc = self._loop(timeout)
  File "/usr/local/lib/python3.10/site-packages/paho/mqtt/client.py", line 1164, in _loop
    rc = self.loop_read()
  File "/usr/local/lib/python3.10/site-packages/paho/mqtt/client.py", line 1556, in loop_read
    rc = self._packet_read()
  File "/usr/local/lib/python3.10/site-packages/paho/mqtt/client.py", line 2439, in _packet_read
    rc = self._packet_handle()
  File "/usr/local/lib/python3.10/site-packages/paho/mqtt/client.py", line 3039, in _packet_handle
    return self._handle_connack()
  File "/usr/local/lib/python3.10/site-packages/paho/mqtt/client.py", line 3138, in _handle_connack
    on_connect(
  File "/app/GivTCP_1/mqtt_client.py", line 386, in on_connect
    client.subscribe(MQTT_Topic+"/control/"+GiV_Settings.serial_number+"/#")
AttributeError: type object 'GiV_Settings' has no attribute 'serial_number'
2024-06-21 08:10:08,998 - Inv1 - read        -  [ERROR   ] - 10 failed inverter reads in a row so removing regCache to force update...
2024-06-21 08:14:40,456 - Inv1 - read        -  [ERROR   ] - 10 failed inverter reads in a row so removing regCache to force update...

MQTT explorer shoes me that there is a current* GivEnergy/Serial/status=online message, but nothing else in the GE tree.

I don't always get the traceback, but there is still no connection:

2024-06-21 08:46:26,997 - startup - [CRITICAL] - HA MQTT Service has been found at core-mosquitto
2024-06-21 08:46:27,001 - startup - [INFO] - Supervisor Timezone: Europe/London
2024-06-21 08:46:29,008 - startup - [CRITICAL] - Scanning network for GivEnergy Devices...
2024-06-21 08:46:32,839 - startup - [CRITICAL] - Inverter CE22****** which is a Gen 1 - AC has been found at: 192.168.7.170
2024-06-21 08:46:32,839 - startup - [INFO] - Searching for Inverters again
2024-06-21 08:46:32,840 - startup - [CRITICAL] - Running Redis
2024-06-21 08:46:32,843 - startup - [CRITICAL] - Setting up invertor: 1 of 1
2024/06/21 08:46:32 [notice] 69#69: using the "epoll" event method
2024/06/21 08:46:32 [notice] 69#69: nginx/1.20.2
2024/06/21 08:46:32 [notice] 69#69: OS: Linux 6.6.33-haos
2024/06/21 08:46:32 [notice] 69#69: getrlimit(RLIMIT_NOFILE): 1073741816:1073741816
2024/06/21 08:46:32 [notice] 69#69: start worker processes
2024/06/21 08:46:32 [notice] 69#69: start worker process 73
2024/06/21 08:46:32 [notice] 69#69: start worker process 74
2024-06-21 08:46:32,874 - startup - [CRITICAL] - Running RQ worker to queue and process givernergy-modbus calls
2024-06-21 08:46:32,874 - startup - [CRITICAL] - Running Invertor (192.168.7.170) read loop every 20s
2024-06-21 08:46:32,877 - startup - [CRITICAL] - Subscribing MQTT Broker for control
2024-06-21 08:46:32,879 - startup - [CRITICAL] - Starting Gunicorn on port 6345
[2024-06-21 08:46:33 +0100] [78] [INFO] Starting gunicorn 21.2.0
[2024-06-21 08:46:33 +0100] [78] [INFO] Listening at: http://0.0.0.0:6345 (78)
[2024-06-21 08:46:33 +0100] [78] [INFO] Using worker: sync
[2024-06-21 08:46:33 +0100] [79] [INFO] Booting worker with pid: 79
[2024-06-21 08:46:33 +0100] [80] [INFO] Booting worker with pid: 80
[2024-06-21 08:46:33 +0100] [82] [INFO] Booting worker with pid: 82
2024-06-21 08:46:34,214 - Inv1 - mqtt_client -  [CRITICAL] - Connecting to MQTT broker for control- core-mosquitto
2024-06-21 08:46:38,947 - Inv1 - read        -  [ERROR   ] - 10 failed inverter reads in a row so removing regCache to force update...
jr298 commented 1 week ago

Update: Installed tcpdump on home assistant, and can't see any traffic to the inverter IP.

gcoan commented 1 week ago

This looks very similar to the recent AIO issues (#189), but this isn't an AIO - and it's been running for months. Any suggestions for further diagnostics?

From my own experience of having the same issue occur on my Gen 1 hybrid, and of others that have randomly had it happen, 4 suggestions:

  1. Reset the inverter to defaults (this worked for me)
  2. Restore a backup of an old version of the add-on (if you have it, again this worked for me)
  3. Delete the PKL files from the givtcp directory (others have reported this works)
  4. Install the GivTCP beta version (again, others have found this works)

No idea why it happens either

jr298 commented 1 week ago

I tried deleting the PKL files - nothing Tried deleting and re-installing GivTCP - nothing Reset Inverter - that did the trick.

What the.... At least all my automations can carry on now.

Also - Thank you!

Now - I wonder if I can detect the issue in home assistant and at least send myself a notification.

jr298 commented 1 week ago

Well - looks like the best indicator will be "Last Updated" So I've added a helper which will update when that updates and every minute:

{{ as_timestamp(now()) - as_timestamp(states.sensor.givtcp_ce22*****_last_updated_time['state']) }}

And now I have an automation which notifies me if that exceeds 100 seconds.

gcoan commented 1 week ago

Well - looks like the best indicator will be "Last Updated"

So I've added a helper which will update when that updates and every minute:

{{ as_timestamp(now()) - as_timestamp(states.sensor.givtcp_ce22*****_last_updated_time['state']) }}

And now I have an automation which notifies me if that exceeds 100 seconds.

I have an automation that monitors this and a bunch of other things like battery temperature or add-on not running as indicators of failure that you are welcome to reuse: https://springfall2008.github.io/batpred/output-data/#givtcp-activity-monitor

I have the 'staleness' test set to 15 minutes not 100 seconds as occasionally you get inverter comms issues that would give false alerts otherwise

jr298 commented 1 week ago

I noticed this morning that the last updated time just stayed at "early morning" until I restarted GivTCP, then it went unknown. I'm hoping that my helper will detect this scenario - I was alerted to an issue by my "peak export" notification - obviously too late to do anything to get the battery to charge.

gazm2k5 commented 11 hours ago

Where and how do you toggle old firmware to false? I've seen people suggesting this but can't find anything relating to old firmware in any documentation. Literally have no idea if they're talking about the docker stack or something else.

gcoan commented 10 hours ago

'old firmware' is in the add-on config in Home Assistant.

image

If you're running GivTCP directly under docker, sorry can't help. Would imagine it'd be in a config file ??