Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Version 2.3.0 fails to connect to inverter #90

Closed
Adrian57 opened this issue Jul 30, 2023 · 19 comments
Closed

Version 2.3.0 fails to connect to inverter #90

Adrian57 opened this issue Jul 30, 2023 · 19 comments

Comments

@Adrian57
Copy link

Adrian57 commented Jul 30, 2023

Upgraded from Version 2.2.4 to 2.3.0. After upgrade I get many errors like this:

2023-07-30 16:00:30,860 - Inv1 - read - [ERROR ] - Consecutive failure count= 11 -- (<class 'Exception'>, Exception("Garbage or failed inverter Response: ERROR:-(<class 'KeyError'>, KeyError(HR:243), <traceback object at 0x7f804e95c0>)"), <traceback object at 0x7f821f4e80>)

I have restored to 2.2.4 and tried upgrade again. Same problem. Restored again.

(Interestingly, even though in the configuration inverters 2 and 3 are disabled, givtcp goes through a scan on the network for servers. It finds my (only) inverter (a Gen 1 Hybrid) AND my Humax TV box which it interrogates and fails to get inverter info from!
I have noticed that even on 2.2.4 it does this as well - though it doesn't cause any problems and hence seems unrelated to this issue)

@slip83
Copy link

slip83 commented Jul 30, 2023

Same here... And exactly same story, even after restoring previous version it seems to report "garbage or failed response"

@Adrian57
Copy link
Author

Adrian57 commented Jul 30, 2023

Not quite the same... after restoring mine is fine. Perhaps check it has really restored and also try a reboot?

@slip83
Copy link

slip83 commented Jul 30, 2023

Ahh, thanks, I tried again... And indeed it did resolve the issue. I think you're right and I needed a full reboot instead of reload.

@Chobnob
Copy link

Chobnob commented Jul 30, 2023

Confirmed V2.3.0 wont connect with the server as above. Unfortunately as a newbie I don't know how to revert to a previous version.

@slip83
Copy link

slip83 commented Jul 30, 2023

Go to settings -> system -> backups and look for givtcp 2.2.4 and then click restore... Fingers crossed you have previously set your system to backup before any update.

@Chobnob
Copy link

Chobnob commented Jul 30, 2023

slip83 Thank you. Doing it now.

@russdan
Copy link

russdan commented Jul 30, 2023

Confirmed, restoring from backup to v2.2.24 and restarting resolves the problem for me. Looks like v2.3.0 is broken - I also have a Gen 1 Inverter (GIV-HY3.6) so not sure if that's relevant to the issue?

@CaptSB
Copy link

CaptSB commented Jul 30, 2023 via email

@Yorkie71
Copy link

Had this issue also. Restored 2.2.4 and all came back online. Confirmed that Setting the old firmware switch resolves this even though I have a hybrid and not AC. Running 451 inverter firmware here. I notice that 2.3.1 has been released overnight addressing the semantics of the configuration text wording so I'm guessing this can be closed now. Great work!

@CaptSB
Copy link

CaptSB commented Jul 31, 2023 via email

@Yorkie71
Copy link

2.3.1 has completely messed up my HA now. All of the entities are unknown. Could this go right back to the issue with all entities appended with _2? I just accepted that issue an updated HA to match this. Looks like I have some work to do here!!
On Mon, 31 Jul 2023 at 06:59, Yorkie71 @.> wrote: Had this issue also. Restored 2.2.4 and all came back online. Confirmed that Setting the old firmware switch resolves this even though I have a hybrid and not AC. Running 451 inverter firmware here. I notice that 2.3.1 has been released overnight addressing the semantics of the configuration text wording so I'm guessing this can be closed now. Great work! — Reply to this email directly, view it on GitHub <#90 (comment)>, or unsubscribe https://github.com/notifications/unsubscribe-auth/A64N7OVTGJAIIJFLJTX6IMTXS5CTNANCNFSM6AAAAAA25IGEVQ . You are receiving this because you commented.Message ID: @.>
-- Sent from Gmail Mobile

Make sure you enable "Inverter 1 - Is it on old firmware?" in the configuration, that should get you back up and running.

@CaptSB
Copy link

CaptSB commented Jul 31, 2023 via email

@CaptSB
Copy link

CaptSB commented Jul 31, 2023 via email

@pay4property
Copy link

pay4property commented Aug 1, 2023

I had exactly the same issue after 2.3.0 auto-updated. Installing 2.3.2 also made no difference.

Following the guidance here I turned off the auto-update and restored from the 2.2.4 backup then did a full reboot of HA. Mysteriously when HA came back it still said it's running GivTCP 2.3.2 and the error persisted.

I then tried setting the "old firmware" option on all 3 inverters, restarted GivTCP and hey-presto everything seems to be working again :-)

@russdan
Copy link

russdan commented Aug 1, 2023

Now I've gone the other way, after issues with 2.3.0/1/2 I restored back to 2.2.4 which was working until this morning when I restarted my HA instance and got:

2023-08-01 08:11:56,304 - startup - [CRITICAL] - HA MQTT Service has been found at core-mosquitto
2023-08-01 08:11:57,658 - startup - [CRITICAL] - We have found the following invertors: {1: '192.168.0.9'}
2023-08-01 08:11:57,658 - startup - [CRITICAL] - GivTCP isAddon: True
2023-08-01 08:11:57,659 - startup - [CRITICAL] - Config directory already exists
2023-08-01 08:11:57,661 - startup - [CRITICAL] - Running Redis
2023-08-01 08:11:57,662 - startup - [CRITICAL] - Running RQ Dashboard on port 9181
2023-08-01 08:11:57,663 - startup - [CRITICAL] - Setting up invertor: 1 of 1
2023-08-01 08:11:57,845 - startup - [CRITICAL] - Recreating settings.py for invertor 1
2023-08-01 08:11:57,847 - startup - [CRITICAL] - Removing old invertor data cache
2023-08-01 08:11:57,848 - startup - [CRITICAL] - Removing old battery data cache
2023-08-01 08:11:57,849 - startup - [CRITICAL] - Old rate data cache not updated today, so deleting
2023-08-01 08:11:57,850 - startup - [CRITICAL] - Running RQ worker to queue and process givernergy-modbus calls
2023-08-01 08:11:57,850 - startup - [CRITICAL] - Running Invertor read loop every 5s
2023-08-01 08:11:57,890 - startup - [CRITICAL] - Subscribing MQTT Broker for control
2023-08-01 08:11:57,898 - startup - [CRITICAL] - Starting Gunicorn on port 6345
RQ Dashboard version 0.6.0
[2023-08-01 08:12:00 +0100] [35] [INFO] Starting gunicorn 20.1.0
[2023-08-01 08:12:00 +0100] [35] [INFO] Listening at: http://0.0.0.0:6345 (35)
[2023-08-01 08:12:00 +0100] [35] [INFO] Using worker: sync
[2023-08-01 08:12:00 +0100] [38] [INFO] Booting worker with pid: 38
 * Running on 0.0.0.0:9181
 * Serving Flask app 'rq_dashboard.cli'
 * Debug mode: off
[2023-08-01 08:12:00 +0100] [39] [INFO] Booting worker with pid: 39
[2023-08-01 08:12:00 +0100] [40] [INFO] Booting worker with pid: 40
2023-08-01 08:12:03,258 - Inv1 - mqtt_client -  [CRITICAL] - Connecting to MQTT broker for control- core-mosquitto
Traceback (most recent call last):
  File "/app/GivTCP_1/read.py", line 64, in getData
    raise Exception ("Garbage or failed inverter Response: "+ str(plant.result))
Exception: Garbage or failed inverter Response: ERROR:-(<class 'KeyError'>, KeyError(HR:113), <traceback object at 0x7f09ac6c0d80>)
During handling of the above exception, another exception occurred:
Traceback (most recent call last):
  File "/app/GivTCP_1/read.py", line 1085, in <module>
    globals()[sys.argv[1]]()
  File "/app/GivTCP_1/read.py", line 705, in self_run2
    runAll("True")
  File "/app/GivTCP_1/read.py", line 667, in runAll
    result=getData(full_refresh)
  File "/app/GivTCP_1/read.py", line 79, in getData
    consecFails(e)
  File "/app/GivTCP_1/read.py", line 643, in consecFails
    oldDataCount= pickle.load(inp)
EOFError: Ran out of input

updated to 2.3.2 and still see the same:

2023-08-01 09:36:28,590 - startup - [CRITICAL] - HA MQTT Service has been found at core-mosquitto
2023-08-01 09:36:28,595 - startup - [INFO] - Supervisor Timezone: Europe/London
2023-08-01 09:36:30,602 - startup - [INFO] - Networks available for scanning are: {0: '192.168.0.1'}
2023-08-01 09:36:30,602 - startup - [CRITICAL] - Scanning network for inverters...
2023-08-01 09:36:30,603 - startup - [INFO] - Scanning network (1):192.168.0.1
2023-08-01 09:36:31,925 - startup - [INFO] - 1 Inverters found on 192.168.0.1 - {1: '192.168.0.9'}
2023-08-01 09:36:32,133 - startup - [CRITICAL] - Inverter SAXXXXXXX which is a Gen 1 - Hybrid has been found at: 192.168.0.9
2023-08-01 09:36:32,135 - startup - [CRITICAL] - GivTCP isAddon: True
2023-08-01 09:36:32,135 - startup - [CRITICAL] - Config directory already exists
2023-08-01 09:36:32,138 - startup - [CRITICAL] - Running Redis
2023-08-01 09:36:32,139 - startup - [CRITICAL] - Setting up invertor: 1 of 1
2023-08-01 09:36:32,178 - startup - [CRITICAL] - Recreating settings.py for invertor 1
2023-08-01 09:36:32,179 - startup - [CRITICAL] - Running RQ worker to queue and process givernergy-modbus calls
2023-08-01 09:36:32,179 - startup - [CRITICAL] - Running Invertor read loop every 5s
2023-08-01 09:36:32,179 - startup - [CRITICAL] - Subscribing MQTT Broker for control
2023-08-01 09:36:32,192 - startup - [CRITICAL] - Starting Gunicorn on port 6345
[2023-08-01 09:36:32 +0100] [35] [INFO] Starting gunicorn 21.2.0
[2023-08-01 09:36:32 +0100] [35] [INFO] Listening at: http://0.0.0.0:6345 (35)
[2023-08-01 09:36:32 +0100] [35] [INFO] Using worker: sync
[2023-08-01 09:36:32 +0100] [36] [INFO] Booting worker with pid: 36
[2023-08-01 09:36:32 +0100] [39] [INFO] Booting worker with pid: 39
[2023-08-01 09:36:32 +0100] [40] [INFO] Booting worker with pid: 40
2023-08-01 09:34:34,592 - Inv1 - mqtt_client -  [CRITICAL] - Connecting to MQTT broker for control- core-mosquitto
Traceback (most recent call last):
  File "/app/GivTCP_1/read.py", line 64, in getData
    raise Exception ("Garbage or failed inverter Response: "+ str(plant.result))
Exception: Garbage or failed inverter Response: ERROR:-(<class 'KeyError'>, KeyError(HR:243), <traceback object at 0x7f376dfef400>)
During handling of the above exception, another exception occurred:
Traceback (most recent call last):
  File "/app/GivTCP_1/read.py", line 1159, in <module>
    globals()[sys.argv[1]]()
  File "/app/GivTCP_1/read.py", line 787, in self_run2
    runAll("True")
  File "/app/GivTCP_1/read.py", line 749, in runAll
    result=getData(full_refresh)
  File "/app/GivTCP_1/read.py", line 77, in getData
    consecFails(e)
  File "/app/GivTCP_1/read.py", line 725, in consecFails
    oldDataCount= pickle.load(inp)
EOFError: Ran out of input

Setting Old Firmware makes no difference for me with 2.3.2.

In the end I had to restore the 2.2.4 backup from 2 days ago, stop/start the add-in and now it's working again.

My Node-Red jobs (running on separate Node-Red instance not under HA) which direct call the Giv_TCP REST endpoints are working fine, so what's changed with the add-on to cause such a massive breakage?? Is it related to the MQTT changes introduced in 2.3?? What's the best way to debug now?

@mogusbi
Copy link

mogusbi commented Aug 6, 2023

Any updates on this? I'm also having issues connecting to my Gen 1 inverter with the old firmware option ticked

2023-08-05 23:42:48,819 - Inv1 - sync        -  [ERROR   ] - Connection to (192.168.X.XXX, 8899) failed: timed out
2023-08-05 23:44:56,324 - Inv1 - sync        -  [ERROR   ] - Connection to (192.168.X.XXX, 8899) failed: timed out
2023-08-06 00:00:51,087 - Inv1 - mqtt        -  [ERROR   ] - MQTT error trying to send a <class 'list'> to the MQTT broker for: GivEnergy/SDXXXXXXXX/Energy/Today/Battery_Discharge_Energy_Today_kWh
2023-08-06 00:00:51,088 - Inv1 - mqtt        -  [ERROR   ] - MQTT error trying to send a <class 'list'> to the MQTT broker for: GivEnergy/SDXXXXXXXX/Energy/Today/Battery_Throughput_Today_kWh
2023-08-06 00:00:51,092 - Inv1 - mqtt        -  [ERROR   ] - MQTT error trying to send a <class 'list'> to the MQTT broker for: GivEnergy/SDXXXXXXXX/Energy/Rates/Import_ppkwh_Today
2023-08-06 00:14:00,834 - Inv1 - sync        -  [ERROR   ] - Connection to (192.168.X.XXX, 8899) failed: timed out
2023-08-06 05:46:59,927 - Inv1 - read        -  [ERROR   ] - Battery Object empty so skipping
2023-08-06 07:02:27,389 - Inv1 - read        -  [ERROR   ] - Battery Object empty so skipping
2023-08-06 08:28:01,085 - Inv1 - read        -  [ERROR   ] - Battery Object empty so skipping
2023-08-06 13:09:43,872 - Inv1 - read        -  [ERROR   ] - Battery Object empty so skipping
2023-08-06 13:13:36,305 - Inv1 - sync        -  [ERROR   ] - Connection to (192.168.X.XXX, 8899) failed: timed out
2023-08-06 13:13:39,902 - Inv1 - read        -  [ERROR   ] - Consecutive failure count= 4 -- (<class 'Exception'>, Exception("Garbage or failed inverter Response: ERROR:-(<class 'KeyError'>, KeyError(HR:113), <traceback object at 0x7f878f1840>)"), <traceback object at 0x7facca6600>)
2023-08-06 13:14:01,147 - Inv1 - read        -  [ERROR   ] - Consecutive failure count= 5 -- (<class 'Exception'>, Exception("Garbage or failed inverter Response: ERROR:-(<class 'KeyError'>, KeyError(IR:110), <traceback object at 0x7f878f1980>)"), <traceback object at 0x7fab6d0380>)
2023-08-06 13:19:47,630 - Inv1 - read        -  [ERROR   ] - Battery Object empty so skipping
2023-08-06 13:20:06,509 - Inv1 - sync        -  [ERROR   ] - Connection to (192.168.X.XXX, 8899) failed: timed out
2023-08-06 14:14:28,079 - Inv1 - sync        -  [ERROR   ] - Connection to (192.168.X.XXX, 8899) failed: timed out

Updating to 2.3.3 seems to have improved things a bit but I am still getting some errors

2023-08-07 00:00:50,268 - Inv1 - mqtt        -  [ERROR   ] - MQTT error trying to send a <class 'list'> to the MQTT broker for: GivEnergy/SDXXXXXXXX/Energy/Rates/Import_ppkwh_Today
2023-08-07 05:10:44,929 - Inv1 - read        -  [ERROR   ] - Battery Object empty so skipping
2023-08-07 05:34:26,482 - Inv1 - write       -  [INFO    ] - Setting dayRate via external trigger
2023-08-07 05:34:44,827 - Inv1 - read        -  [INFO    ] - Saving current energy stats at start of day rate tariff (Dynamic)
2023-08-07 06:36:15,190 - Inv1 - read        -  [ERROR   ] - Battery Object empty so skipping
2023-08-07 08:21:53,847 - Inv1 - read        -  [ERROR   ] - Battery Object empty so skipping
2023-08-07 08:31:57,692 - Inv1 - read        -  [ERROR   ] - Battery Object empty so skipping
2023-08-07 09:25:46,228 - Inv1 - sync        -  [ERROR   ] - Connection to (192.168.x.xxx, 8899) failed: timed out
2023-08-07 10:07:34,447 - Inv1 - read        -  [ERROR   ] - Consecutive failure count= 4 -- (<class 'Exception'>, Exception("Garbage or failed inverter Response: ERROR:-(<class 'KeyError'>, KeyError(HR:013), <traceback object at 0x7f99fb9880>)"), <traceback object at 0x7fa1f90d40>)
2023-08-07 10:24:45,733 - Inv1 - sync        -  [ERROR   ] - Connection to (192.168.x.xxx, 8899) failed: timed out

@russdan
Copy link

russdan commented Aug 8, 2023

I think I might be almost OK now - I went back and re-pulled my docker image of 2.3.3, then I updated the 2.2.4 HA add-in to 2.3.3 and seems to be broadly OK now (this is both with and without "Old firmware" set - I believe I'm not on an old firmware (Inverter Firmware Version D0.450-A0.451, Battery Firmware Version 3013, Last Update Time 2023-07-30 18:02:24). There are still a key failure errors, look to be the same keys as @mogusbi, which appear every few minutes, but the general data pull from the inverter (power, SOC etc) is now working in HA....

2023-08-08T09:02:13.684638961Z [2023-08-08 10:02:13 +0100] [56] [INFO] Starting gunicorn 21.2.0
2023-08-08T09:02:13.685355119Z [2023-08-08 10:02:13 +0100] [56] [INFO] Listening at: http://0.0.0.0:6345 (56)
2023-08-08T09:02:13.685433007Z [2023-08-08 10:02:13 +0100] [56] [INFO] Using worker: sync
2023-08-08T09:02:13.690582766Z [2023-08-08 10:02:13 +0100] [59] [INFO] Booting worker with pid: 59
2023-08-08T09:02:13.717142995Z [2023-08-08 10:02:13 +0100] [60] [INFO] Booting worker with pid: 60
2023-08-08T09:02:13.734193404Z [2023-08-08 10:02:13 +0100] [61] [INFO] Booting worker with pid: 61
2023-08-08T09:02:14.662112624Z 2023-08-08 10:02:14,661 - Inv1 - mqtt_client -  [CRITICAL] - Connecting to MQTT broker for control- 127.0.0.1
2023-08-08T09:02:22.979916269Z 2023-08-08 10:02:22,979 - Inv1 - read        -  [ERROR   ] - Consecutive failure count= 4 -- (<class 'Exception'>, Exception("Garbage or failed inverter Response: ERROR:-(<class 'KeyError'>, KeyError(HR:113), <traceback object at 0x7f31cdc2b4c0>)"), <traceback object at 0x7fa93ea1b840>)
2023-08-08T09:02:26.482795572Z 2023-08-08 10:02:26,482 - Inv1 - read        -  [ERROR   ] - Consecutive failure count= 5 -- (<class 'Exception'>, Exception("Garbage or failed inverter Response: ERROR:-(<class 'KeyError'>, KeyError(HR:013), <traceback object at 0x7f31cdc288c0>)"), <traceback object at 0x7f9898e9c2c0>)
2023-08-08T09:02:31.311634631Z 2023-08-08 10:02:31,311 - Inv1 - read        -  [CRITICAL] - First time running so saving AC Charge status
2023-08-08T09:02:31.314222503Z 2023-08-08 10:02:31,313 - Inv1 - read        -  [CRITICAL] - Publishing Home Assistant Discovery messages
2023-08-08T09:03:38.173083271Z 2023-08-08 10:03:38,172 - Inv1 - read        -  [ERROR   ] - Consecutive failure count= 4 -- (<class 'Exception'>, Exception("Garbage or failed inverter Response: ERROR:-(<class 'KeyError'>, KeyError(IR:110), <traceback object at 0x7f31cdc30980>)"), <traceback object at 0x7fa93ea1b9c0>)
2023-08-08T09:05:51.269642288Z 2023-08-08 10:05:51,269 - Inv1 - read        -  [ERROR   ] - Consecutive failure count= 4 -- (<class 'Exception'>, Exception("Garbage or failed inverter Response: ERROR:-(<class 'KeyError'>, KeyError(HR:113), <traceback object at 0x7f31cdc30140>)"), <traceback object at 0x7fa93f3dd900>)
2023-08-08T09:15:58.829991819Z 2023-08-08 10:15:58,829 - Inv1 - read        -  [ERROR   ] - Consecutive failure count= 7 -- (<class 'Exception'>, Exception("Garbage or failed inverter Response: ERROR:-(<class 'KeyError'>, KeyError(IR:110), <traceback object at 0x7f31cdc248c0>)"), <traceback object at 0x7fa93fd51180>)
2023-08-08T09:20:21.446750885Z 2023-08-08 10:20:21,446 - Inv1 - read        -  [ERROR   ] - Consecutive failure count= 6 -- (<class 'Exception'>, Exception("Garbage or failed inverter Response: ERROR:-(<class 'KeyError'>, KeyError(HR:013), <traceback object at 0x7f31cdc1cb40>)"), <traceback object at 0x7fa93fd51180>)
2023-08-08T09:22:36.093092070Z 2023-08-08 10:22:36,092 - Inv1 - read        -  [ERROR   ] - Consecutive failure count= 11 -- (<class 'Exception'>, Exception("Garbage or failed inverter Response: ERROR:-(<class 'KeyError'>, KeyError(HR:013), <traceback object at 0x7f31cdc1c980>)"), <traceback object at 0x7fa93ea62ac0>)
2023-08-08T09:22:36.093305149Z 2023-08-08 10:22:36,093 - Inv1 - read        -  [ERROR   ] - 10 failed inverter reads in a row so removing regCache to force update...
2023-08-08T09:23:09.512169560Z 2023-08-08 10:23:09,511 - Inv1 - read        -  [ERROR   ] - Consecutive failure count= 4 -- (<class 'Exception'>, Exception("Garbage or failed inverter Response: ERROR:-(<class 'KeyError'>, KeyError(HR:013), <traceback object at 0x7f31cdc1c7c0>)"), <traceback object at 0x7f9898f4e900>)
2023-08-08T09:23:27.758639464Z 2023-08-08 10:23:27,758 - Inv1 - read        -  [ERROR   ] - Consecutive failure count= 5 -- (<class 'Exception'>, Exception("Garbage or failed inverter Response: ERROR:-(<class 'KeyError'>, KeyError(HR:013), <traceback object at 0x7f31cdc1c140>)"), <traceback object at 0x7f9898914500>)
2023-08-08T09:23:34.283769394Z 2023-08-08 10:23:34,283 - Inv1 - read        -  [ERROR   ] - Consecutive failure count= 6 -- (<class 'Exception'>, Exception("Garbage or failed inverter Response: ERROR:-(<class 'KeyError'>, KeyError(IR:183), <traceback object at 0x7f31cdc18980>)"), <traceback object at 0x7fa93ea62d80>)
2023-08-08T09:23:44.334981199Z 2023-08-08 10:23:44,334 - Inv1 - read        -  [ERROR   ] - Consecutive failure count= 7 -- (<class 'Exception'>, Exception("Garbage or failed inverter Response: ERROR:-(<class 'KeyError'>, KeyError(HR:113), <traceback object at 0x7f31cdc18940>)"), <traceback object at 0x7f9898cddd40>)
2023-08-08T09:23:47.783759991Z 2023-08-08 10:23:47,783 - Inv1 - read        -  [ERROR   ] - Consecutive failure count= 8 -- (<class 'Exception'>, Exception("Garbage or failed inverter Response: ERROR:-(<class 'KeyError'>, KeyError(HR:013), <traceback object at 0x7f31cdc18800>)"), <traceback object at 0x7f98989583c0>)
2023-08-08T09:23:52.624889642Z 2023-08-08 10:23:52,624 - Inv1 - read        -  [CRITICAL] - First time running so saving AC Charge status

The regCache clear doesn't seem to make any difference, the key errors persist after that....

@russdan
Copy link

russdan commented Aug 8, 2023

I increased logging to debug and see the following...

2023-08-08T09:48:49.353834874Z 2023-08-08 10:48:49,353 - Inv1 - transaction -  [DEBUG   ] - Current transaction state - TRANSACTION_COMPLETE
2023-08-08T09:48:49.354113303Z 2023-08-08 10:48:49,353 - Inv1 - transaction -  [DEBUG   ] - Running transaction 5
2023-08-08T09:48:49.355896382Z 2023-08-08 10:48:49,355 - Inv1 - sync        -  [DEBUG   ] - New Transaction state 'SENDING'
2023-08-08T09:48:51.358308620Z 2023-08-08 10:48:51,357 - Inv1 - transaction -  [DEBUG   ] - No response received, Expected 164 bytes Recieved 0 bytes !!!!
2023-08-08T09:48:51.358571174Z 2023-08-08 10:48:51,358 - Inv1 - transaction -  [DEBUG   ] - Changing transaction state from 'WAITING FOR REPLY' to 'PROCESSING REPLY'
2023-08-08T09:48:51.359035200Z 2023-08-08 10:48:51,358 - Inv1 - transaction -  [DEBUG   ] - Changing transaction state from 'PROCESSING REPLY' to 'TRANSACTION_COMPLETE'
2023-08-08T09:48:51.865001703Z 2023-08-08 10:48:51,864 - Inv1 - sync        -  [DEBUG   ] - Connection to Modbus server established. Socket ('172.26.0.2', 48629)
2023-08-08T09:48:51.865218521Z 2023-08-08 10:48:51,864 - Inv1 - transaction -  [DEBUG   ] - Current transaction state - TRANSACTION_COMPLETE
2023-08-08T09:48:51.865477830Z 2023-08-08 10:48:51,865 - Inv1 - transaction -  [DEBUG   ] - Running transaction 6
2023-08-08T09:48:51.866180298Z 2023-08-08 10:48:51,865 - Inv1 - sync        -  [DEBUG   ] - New Transaction state 'SENDING'
2023-08-08T09:48:53.867831572Z 2023-08-08 10:48:53,867 - Inv1 - transaction -  [DEBUG   ] - No response received, Expected 164 bytes Recieved 0 bytes !!!!
2023-08-08T09:48:53.869546765Z 2023-08-08 10:48:53,867 - Inv1 - transaction -  [DEBUG   ] - Changing transaction state from 'WAITING FOR REPLY' to 'PROCESSING REPLY'
2023-08-08T09:48:53.869584629Z 2023-08-08 10:48:53,868 - Inv1 - transaction -  [DEBUG   ] - Changing transaction state from 'PROCESSING REPLY' to 'TRANSACTION_COMPLETE'
2023-08-08T09:48:54.389226858Z 2023-08-08 10:48:54,388 - Inv1 - queue       -  [DEBUG   ] - Starting BLMOVE operation for rq:queue:GivTCP_1 with timeout of 405
2023-08-08T09:48:54.404085225Z 2023-08-08 10:48:54,403 - Inv1 - read        -  [ERROR   ] - Consecutive failure count= 9 -- (<class 'Exception'>, Exception("Garbage or failed inverter Response: ERROR:-(<class 'KeyError'>, KeyError(HR:113), <traceback object at 0x7f6329d9c540>)"), <traceback object at 0x7f669b42b280>)
2023-08-08T09:48:54.457921846Z 2023-08-08 10:48:54,457 - Inv1 - read        -  [DEBUG   ] - Dealt with Power

The keyErrors always appear immediately after the Starting BLMOVE operation ... also there are frequent No response received, Expected 164 bytes Recieved 0 bytes !!!!

Not sure if this helps with identifying the issue?

@russdan
Copy link

russdan commented Aug 8, 2023

OK, so having spent more time trying to debug this from what I can see it's the givenergy_modbus client which throws these keyErrors: dewet22/givenergy-modbus#19

They look therefore like noise....... would it be possible @britkat1980 if they were trapped in the code so they didn't cause the 10 failed inverter reads in a row processing, as it looks unnecessary I think for these "stability-related" errors?

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

No branches or pull requests

9 participants