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

3.0.4 KeyError Traceback on startup: setts["evc_ip_address"]=evcList[1][0] #327

Open
sOckhamSter opened this issue Jan 7, 2025 · 7 comments

Comments

@sOckhamSter
Copy link

This issue has been present for a while but I had multiple issues and wasn't certain which ones were related or not. I'm now certain that this issue is unique and related to detecting the EVC. I am running v3.0.4 in a test virtual machine (VirtualBox) for the moment, I haven't moved from 2.4.9 on my 'production' installation yet due to this issue.

  • I install giv_tcp as normal and start it
  • It detects everything fine and starts the configuration interface
  • I run through the configuration interface adding my batteries, MQTT, and it makes no difference to the upcoming error whether or not I then configure the EVC page or not.
  • Save and restart and the Traceback appears in the logs on the restart:
2025-01-07 09:28:35,032 - GivTCP - write       -  [CRITICAL] - Restarting the GivTCP Addon in 2s...
2025-01-07 09:28:37,811 - startup     -  [INFO    ] - ==================== STARTING GivTCP==========================
2025-01-07 09:28:37,845 - startup     -  [INFO    ] - Network Found: 192.168.0.1/22
2025-01-07 09:28:39,847 - startup     -  [INFO    ] - Searching for Inverters
2025-01-07 09:28:39,847 - startup     -  [INFO    ] - Scanning network for GivEnergy Devices...
2025-01-07 09:28:44,961 - startup     -  [INFO    ] - GivEVC 11288853545979 found at: 192.168.1.187
2025-01-07 09:28:44,961 - startup     -  [INFO    ] - INV- Scanning network (1):192.168.0.1/22
2025-01-07 09:29:34,081 - client      -  [INFO    ] - Connection established to 192.168.1.62:8899
2025-01-07 09:29:34,082 - client      -  [INFO    ] - Detecting plant
2025-01-07 09:29:35,331 - client      -  [INFO    ] - Plant Detected
2025-01-07 09:29:41,352 - startup     -  [INFO    ] - Inverter CE2122G257 which is a Gen1 - Ac with 1 batteries has been found at: 192.168.1.62
2025-01-07 09:29:41,356 - client      -  [INFO    ] - Connection established to 192.168.1.81:8899
2025-01-07 09:29:41,356 - client      -  [INFO    ] - Detecting plant
2025-01-07 09:29:42,518 - client      -  [INFO    ] - Plant Detected
2025-01-07 09:29:47,546 - startup     -  [INFO    ] - Inverter CH2315G086 which is a Gen1 - All_in_one with 4 batteries has been found at: 192.168.1.81
2025-01-07 09:29:47,551 - client      -  [INFO    ] - Connection established to 192.168.1.241:8899
2025-01-07 09:29:47,551 - client      -  [INFO    ] - Detecting plant
2025-01-07 09:29:48,718 - client      -  [INFO    ] - Plant Detected
2025-01-07 09:29:48,720 - startup     -  [INFO    ] - Inverter GW2314G032 which is a Gen1 - Gateway with 0 batteries has been found at: 192.168.1.241
2025-01-07 09:29:48,729 - startup     -  [INFO    ] - evcList: {2: ['192.168.1.187', '11288853545979']}
Traceback (most recent call last):
  File "/app/startup.py", line 500, in <module>
    setts["evc_ip_address"]=evcList[1][0]
                            ~~~~~~~^^^
KeyError: 1
KeyError: 1
@britkat1980
Copy link
Owner

Ok, something is amiss here. I’ll need to make you a special dev version with some extra debugging added. I’ll dm you

@sOckhamSter
Copy link
Author

So really strangely GivTCP started working ok on my test VM so I restarted HA a few times and it carried on working. So I then decided to try and reproduce the whole thing by wiping the GivTCP folder. Second time around it now just gives me the traceback error on every start of GivTCP for the evcList. Really annoying because I can't find a consistency in its behaviour, but 99% of the time it failed with the same error on startup so at least I'm guaranteed to reproduce the error once you have a debug version available.

@britkat1980
Copy link
Owner

My feeling is that this is driven by networking/subnets etc... Will try and get you a dev test version in the next day or so.

@britkat1980
Copy link
Owner

Actually, I've just seen what I think the the issue is... evclist is a collection of found EVCs, I want to check the first item in the list and get details, but in your example above the first item in the list is numbered 2. I bet this is a python indexing thing. I might need to index an enumerated list... let me try a fix and let you know.

Could you post the same log as above with the working test VM (which i suspect finds the evc on the first listed subnet!)

@sOckhamSter
Copy link
Author

Sounds promising thank you :) Unfortunately I didn't snapshot the VM before wiping the GivTCP config so now I can't get it to work. I'll try several more times this evening and if it eventually decides to work I'll grab the log.

@sOckhamSter
Copy link
Author

Ok, so I've managed to get it running again after many dozens of startup attempts. So firstly, this is a failed startup log:

2025-01-16 08:34:48,195 - startup     -  [INFO    ] - ==================== STARTING GivTCP==========================
2025-01-16 08:34:48,207 - startup     -  [INFO    ] - Network Found: 192.168.0.1/22
2025-01-16 08:34:50,210 - startup     -  [INFO    ] - Searching for Inverters
2025-01-16 08:34:50,211 - startup     -  [INFO    ] - Scanning network for GivEnergy Devices...
2025-01-16 08:34:55,359 - startup     -  [INFO    ] - GivEVC 11288853545979 found at: 192.168.1.187
2025-01-16 08:34:55,359 - startup     -  [INFO    ] - INV- Scanning network (1):192.168.0.1/22
2025-01-16 08:35:44,484 - client      -  [INFO    ] - Connection established to 192.168.1.62:8899
2025-01-16 08:35:44,486 - client      -  [INFO    ] - Detecting plant
2025-01-16 08:35:45,735 - client      -  [INFO    ] - Plant Detected
2025-01-16 08:35:48,498 - startup     -  [INFO    ] - Inverter CE2122G257 which is a Gen1 - Ac with 1 batteries has been found at: 192.168.1.62
2025-01-16 08:35:48,503 - client      -  [INFO    ] - Connection established to 192.168.1.81:8899
2025-01-16 08:35:48,504 - client      -  [INFO    ] - Detecting plant
2025-01-16 08:35:53,175 - client      -  [INFO    ] - Plant Detected
2025-01-16 08:35:58,236 - startup     -  [INFO    ] - Inverter CH2315G086 which is a Gen1 - All_in_one with 4 batteries has been found at: 192.168.1.81
2025-01-16 08:35:58,239 - client      -  [INFO    ] - Connection established to 192.168.1.241:8899
2025-01-16 08:35:58,239 - client      -  [INFO    ] - Detecting plant
2025-01-16 08:35:59,404 - client      -  [INFO    ] - Plant Detected
2025-01-16 08:35:59,406 - startup     -  [INFO    ] - Inverter GW2314G032 which is a Gen1 - Gateway with 0 batteries has been found at: 192.168.1.241
2025-01-16 08:35:59,413 - startup     -  [INFO    ] - Inverter CE2122G257 not in settings file
2025-01-16 08:35:59,413 - startup     -  [INFO    ] - Adding Inverter CE2122G257 to slot 3
2025-01-16 08:35:59,413 - startup     -  [INFO    ] - evcList: {3: ['192.168.1.187', '11288853545979']}
Traceback (most recent call last):
  File "/app/startup.py", line 500, in <module>
    setts["evc_ip_address"]=evcList[1][0]
                            ~~~~~~~^^^
KeyError: 1

It started once and allowed me to run the web config, but then failed again a lot after that. But then after many more attempts it suddenly burst into life! No mention of the EVC in the working startup though (.187) so I'm wondering if it just didn't notice it in the scan on this occasion which is why it worked?

2025-01-16 09:06:34,423 - startup     -  [INFO    ] - ==================== STARTING GivTCP==========================
2025-01-16 09:06:34,439 - startup     -  [INFO    ] - Network Found: 192.168.0.1/22
2025-01-16 09:06:36,443 - startup     -  [INFO    ] - Searching for Inverters
2025-01-16 09:06:36,443 - startup     -  [INFO    ] - Scanning network for GivEnergy Devices...
2025-01-16 09:06:46,711 - startup     -  [INFO    ] - INV- Scanning network (1):192.168.0.1/22
2025-01-16 09:07:36,876 - client      -  [INFO    ] - Connection established to 192.168.1.62:8899
2025-01-16 09:07:36,876 - client      -  [INFO    ] - Detecting plant
2025-01-16 09:07:38,129 - client      -  [INFO    ] - Plant Detected
2025-01-16 09:07:47,146 - startup     -  [INFO    ] - Inverter CE2122G257 which is a Gen1 - Ac with 1 batteries has been found at: 192.168.1.62
2025-01-16 09:07:47,151 - client      -  [INFO    ] - Connection established to 192.168.1.81:8899
2025-01-16 09:07:47,152 - client      -  [INFO    ] - Detecting plant
2025-01-16 09:07:48,315 - client      -  [INFO    ] - Plant Detected
2025-01-16 09:07:58,432 - client      -  [INFO    ] - Connection established to 192.168.1.81:8899
2025-01-16 09:07:58,432 - client      -  [INFO    ] - Detecting plant
2025-01-16 09:08:02,096 - client      -  [INFO    ] - Plant Detected
2025-01-16 09:08:07,139 - startup     -  [INFO    ] - Inverter CH2315G086 which is a Gen1 - All_in_one with 4 batteries has been found at: 192.168.1.81
2025-01-16 09:08:07,144 - client      -  [INFO    ] - Connection established to 192.168.1.241:8899
2025-01-16 09:08:07,144 - client      -  [INFO    ] - Detecting plant
2025-01-16 09:08:08,309 - client      -  [INFO    ] - Plant Detected
2025-01-16 09:08:08,312 - startup     -  [INFO    ] - Inverter GW2314G032 which is a Gen1 - Gateway with 0 batteries has been found at: 192.168.1.241
2025-01-16 09:08:08,324 - startup     -  [INFO    ] - Inverter CE2122G257 not in settings file
2025-01-16 09:08:08,325 - startup     -  [INFO    ] - Adding Inverter CE2122G257 to slot 3
2025-01-16 09:08:08,343 - startup     -  [INFO    ] - Setting up invertor: 1
2025-01-16 09:08:08,467 - startup     -  [INFO    ] - ==============================================================
2025-01-16 09:08:08,467 - startup     -  [INFO    ] - ====             Web Gui Config is at                     ====
2025-01-16 09:08:08,467 - startup     -  [INFO    ] - ====     http://192.168.1.14:8099/config.html             ====
2025-01-16 09:08:08,467 - startup     -  [INFO    ] - ==============================================================
2025-01-16 09:08:08,469 - startup     -  [INFO    ] - Running Invertor 1 (CH2315G086) read loop every 30/120s
2025-01-16 09:08:08,475 - startup     -  [INFO    ] - Setting up invertor: 2
2025-01-16 09:08:08,554 - startup     -  [INFO    ] - ==============================================================
2025-01-16 09:08:08,565 - startup     -  [INFO    ] - ====             Web Gui Config is at                     ====
2025-01-16 09:08:08,566 - startup     -  [INFO    ] - ====     http://192.168.1.14:8099/config.html             ====
2025-01-16 09:08:08,568 - startup     -  [INFO    ] - ==============================================================
2025-01-16 09:08:08,585 - startup     -  [INFO    ] - Running Invertor 2 (GW2314G032) read loop every 30/120s
2025-01-16 09:08:08,635 - startup     -  [INFO    ] - Setting up invertor: 3
[2025-01-16 09:08:08 +0000] [70] [INFO] Starting gunicorn 23.0.0
[2025-01-16 09:08:08 +0000] [70] [INFO] Listening at: http://0.0.0.0:6350 (70)
[2025-01-16 09:08:08 +0000] [70] [INFO] Using worker: sync
[2025-01-16 09:08:08 +0000] [82] [INFO] Booting worker with pid: 82
2025-01-16 09:08:08,761 - startup     -  [INFO    ] - ==============================================================
2025-01-16 09:08:08,805 - startup     -  [INFO    ] - ====             Web Gui Config is at                     ====
2025-01-16 09:08:08,805 - startup     -  [INFO    ] - ====     http://192.168.1.14:8099/config.html             ====
2025-01-16 09:08:08,806 - startup     -  [INFO    ] - ==============================================================
2025-01-16 09:08:08,835 - startup     -  [INFO    ] - Running Invertor 3 (CE2122G257) read loop every 30/120s
[2025-01-16 09:08:09 +0000] [78] [INFO] Starting gunicorn 23.0.0
[2025-01-16 09:08:09 +0000] [78] [INFO] Listening at: http://0.0.0.0:6345 (78)
[2025-01-16 09:08:09 +0000] [78] [INFO] Using worker: sync
[2025-01-16 09:08:09 +0000] [86] [INFO] Booting worker with pid: 86
[2025-01-16 09:08:09 +0000] [87] [INFO] Booting worker with pid: 87
[2025-01-16 09:08:09 +0000] [81] [INFO] Starting gunicorn 23.0.0
[2025-01-16 09:08:09 +0000] [81] [INFO] Listening at: http://0.0.0.0:6346 (81)
[2025-01-16 09:08:09 +0000] [81] [INFO] Using worker: sync
[2025-01-16 09:08:09 +0000] [88] [INFO] Booting worker with pid: 88
[2025-01-16 09:08:09 +0000] [89] [INFO] Booting worker with pid: 89
[2025-01-16 09:08:09 +0000] [90] [INFO] Booting worker with pid: 90
[2025-01-16 09:08:09 +0000] [91] [INFO] Booting worker with pid: 91
[2025-01-16 09:08:09 +0000] [85] [INFO] Starting gunicorn 23.0.0
[2025-01-16 09:08:09 +0000] [85] [INFO] Listening at: http://0.0.0.0:6347 (85)
[2025-01-16 09:08:09 +0000] [85] [INFO] Using worker: sync
[2025-01-16 09:08:09 +0000] [94] [INFO] Booting worker with pid: 94
[2025-01-16 09:08:09 +0000] [95] [INFO] Booting worker with pid: 95
[2025-01-16 09:08:09 +0000] [96] [INFO] Booting worker with pid: 96
2025-01-16 09:08:11,490 - GivTCP2 - read        -  [INFO    ] - Starting watch_plant loop...
2025-01-16 09:08:11,497 - GivTCP2 - GivLUT      -  [CRITICAL] - Opening Modbus Connection to 192.168.1.241
2025-01-16 09:08:11,510 - GivTCP - read        -  [INFO    ] - Starting watch_plant loop...
2025-01-16 09:08:11,510 - GivTCP2 - read        -  [CRITICAL] - Detecting inverter characteristics...
2025-01-16 09:08:11,537 - GivTCP - GivLUT      -  [CRITICAL] - Opening Modbus Connection to 192.168.1.81
2025-01-16 09:08:11,548 - GivTCP - read        -  [CRITICAL] - Detecting inverter characteristics...
2025-01-16 09:08:11,815 - GivTCP3 - read        -  [INFO    ] - Starting watch_plant loop...
2025-01-16 09:08:11,815 - GivTCP3 - GivLUT      -  [CRITICAL] - Opening Modbus Connection to 192.168.1.62
2025-01-16 09:08:11,875 - GivTCP3 - read        -  [CRITICAL] - Detecting inverter characteristics...
2025-01-16 09:08:18,303 - GivTCP2 - read        -  [INFO    ] - Publishing Home Assistant Discovery messages
2025-01-16 09:08:18,951 - GivTCP3 - read        -  [INFO    ] - Dynamic Tariff enabled so defaulting to Day Rate and waiting external control
2025-01-16 09:08:18,956 - GivTCP3 - read        -  [INFO    ] - Publishing Home Assistant Discovery messages
2025-01-16 09:08:23,570 - GivTCP - read        -  [INFO    ] - Dynamic Tariff enabled so defaulting to Day Rate and waiting external control
2025-01-16 09:08:23,574 - GivTCP - read        -  [INFO    ] - Publishing Home Assistant Discovery messages

@m47een
Copy link

m47een commented Jan 17, 2025

Having a similar issue here.

2025-01-17 13:40:54,814 - startup     -  [INFO    ] - ==================== STARTING GivTCP==========================
2025-01-17 13:40:54,824 - startup     -  [INFO    ] - Network Found: 192.168.30.1/24
2025-01-17 13:40:56,825 - startup     -  [INFO    ] - Searching for Inverters
2025-01-17 13:40:56,825 - startup     -  [INFO    ] - Scanning network for GivEnergy Devices...
2025-01-17 13:40:58,075 - startup     -  [INFO    ] - GivEVC 87023906844969 found at: 192.168.30.144
2025-01-17 13:40:58,076 - startup     -  [INFO    ] - INV- Scanning network (1):192.168.30.1/24
2025-01-17 13:41:07,229 - client      -  [INFO    ] - Connection established to 192.168.30.141:8899
2025-01-17 13:41:07,229 - client      -  [INFO    ] - Detecting plant
2025-01-17 13:41:08,384 - client      -  [INFO    ] - Plant Detected
2025-01-17 13:41:13,405 - startup     -  [INFO    ] - Inverter CH2316G179 which is a Gen1 - All_in_one with 4 batteries has been found at: 192.168.30.141
2025-01-17 13:41:13,406 - client      -  [INFO    ] - Connection established to 192.168.30.142:8899
2025-01-17 13:41:13,406 - client      -  [INFO    ] - Detecting plant
2025-01-17 13:41:14,571 - client      -  [INFO    ] - Plant Detected
2025-01-17 13:41:14,571 - startup     -  [INFO    ] - Inverter GW2316G059 which is a Gen1 - Gateway with 0 batteries has been found at: 192.168.30.142
2025-01-17 13:41:14,573 - startup     -  [INFO    ] - evcList: {2: ['192.168.30.144', '87023906844969']}
Traceback (most recent call last):
  File "/app/startup.py", line 502, in <module>
    setts["serial_number_evc"]=evcList[1][1]
                               ~~~~~~~^^^
KeyError: 1

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

3 participants