MickMake / GoSungrow

GoLang implementation to access the iSolarCloud API updated by SunGrow inverters.

https://mickmake.com/

GNU General Public License v2.0

183 stars 48 forks source link

Error: unknown error 'Repeated request' #111

Open Triky101 opened 7 months ago

Triky101 commented 7 months ago

Hi, I had Sungrow addon working fine for a while, even after the encryption issue.

However a few weeks ago, it stopped working, and no matter how many times I try to fix/re-install it, I now keep getting this error.

Error: unknown error 'Repeated request'

Can anyone point me in the right direction ?

The Log: ---------------------------------+ [11:07:33] INFO: Login to iSolarCloud using gateway https://augateway.isolarcloud.com ... Email: xxxxxx@gmail.com Create Date: Sun May 05 10:19:10 CST 2019 Login Last Date: 2024-04-15 19:05:09 Login Last IP:
Login State: 1 User Account: hs0831qc User Id: 74334 User Name: A1902250988 Is Online: false Token: 74334_0dd0b55f2d62487395fbb88cdf4f1424 Token File: /data/.GoSungrow/AppService_login.json Email: xxxxxx@gmail.com Create Date: Sun May 05 10:19:10 CST 2019 Login Last Date: 2024-04-15 19:07:33 Login Last IP:
Login State: 1 User Account: hs0831qc User Id: 74334 User Name: A1902250988 Is Online: false Token: 74334_13618dddf69644f0acd62d0c57227fca Token File: /data/.GoSungrow/AppService_login.json [11:07:33] INFO: Syncing data from gateway https://augateway.isolarcloud.com ... 2024/04/15 11:07:33 INFO: Connecting to MQTT HASSIO Service... 2024/04/15 11:07:33 INFO: Connecting to SunGrow... Email: Mtrikilis@gmail.com Create Date: Sun May 05 10:19:10 CST 2019 Login Last Date: 2024-04-15 19:07:33 Login Last IP:
Login State: 1 User Account: hs0831qc User Id: 74334 User Name: A1902250988 Is Online: false Token: 74334_13618dddf69644f0acd62d0c57227fca Token File: /data/.GoSungrow/AppService_login.json 2024/04/15 11:07:33 INFO: Found SunGrow 5 devices 2024/04/15 11:07:33 INFO: Option[loglevel] set to 'error' PsId: required JSON request: {"ps_id":1335646}

2024/04/15 11:07:33 ERROR: unknown error 'Repeated request' Error: unknown error 'Repeated request' Usage: GoSungrow mqtt run [flags]

Aliases: run,

Examples: GoSungrow mqtt run

Flags: Use "GoSungrow help flags" for more info.

Additional help topics:

ERROR: unknown error 'Repeated request' s6-rc: info: service legacy-services: stopping s6-rc: info: service legacy-services successfully stopped s6-rc: info: service legacy-cont-init: stopping s6-rc: info: service legacy-cont-init successfully stopped s6-rc: info: service fix-attrs: stopping s6-rc: info: service fix-attrs successfully stopped s6-rc: info: service s6rc-oneshot-runner: stopping s6-rc: info: service s6rc-oneshot-runner successfully stopped

Paraphraser commented 7 months ago

This is what I see. My instance of GoSungrow is working so I think we can treat this as a known-good pattern:

[13:18:01] INFO: Login to iSolarCloud using gateway https://augateway.isolarcloud.com ...
Email:  someone@domain.com
Create Date:    Thu Feb 09 13:14:55 CST 2023
Login Last Date:    2024-04-15 21:18:01
Login Last IP:  
Login State:    1
User Account:   aabbccddee
User Id:    374058
User Name:  Moi
Is Online:  false
Token:  374058_c69afcfdd8724fecac720247087c3522
Token File: /data/.GoSungrow/AppService_login.json
[13:18:01] INFO: Syncing data from gateway https://augateway.isolarcloud.com ...
2024/04/15 13:18:01 INFO: Connecting to MQTT HASSIO Service...
2024/04/15 13:18:01 INFO: Connecting to SunGrow...
2024/04/15 13:18:01 INFO: Found SunGrow 3 devices
2024/04/15 13:18:02 INFO: Caching Sungrow metadata...
2024/04/15 13:18:02 INFO: Cached 975 Sungrow data points...
2024/04/15 13:18:03 INFO: Syncing 461 entries with HASSIO from queryDeviceList.
2024/04/15 13:18:03 INFO: Syncing 148 entries with HASSIO from getPsList.
CU-CUCU-----CUCU--CU-CUCUCUCUCUCU-CUCUCUCUCU----CU-CU-CUCU-CU
2024/04/15 13:18:03 INFO: Syncing 205 entries with HASSIO from getPsDetail.
CUCUCUCUCUCUCUCU?CUCUCUCU?CUCUCUCUCUCUCUCUCUCUCUCUCUCUCUCUCUCU?CUCUCUCUCUCU?CUCUCUCUCUCUCUCUCUCUCUCUCUCUCUCUCUCUCUCU?CUCUCUCUCUCUCUCUCUCUCUCUCUCUCU?CUCUCUCUCUCUCUCUCUCUCUCUCUCUCUCUCUCUCUCUCUCUCUCUCUCUCUCUCUCUCUCUCUCUCUCUCUCUCUCUCUCUCUCUCUCUCUCUCUCUCUCUCUCUCU?CUCUCUCUCUCUCUCUCUCUCUCUCUCUCU
2024/04/15 13:18:03 INFO: Starting ticker...
2024/04/15 13:18:03 INFO: Fetch Schedule: 5m
2024/04/15 13:18:03 INFO: Sleep Delay:    40s
CUCU?CUCUCUCUCU??CUCUCUCUCUCUCU???CUCUCUCUCUCU?CUCUCUCUCU?CU?CUCUCUCUCU??CUCUCUCUCUCUCUCU?CUCU?CU??CUCUCU?CUCUCUCUCU?CUCUCUCUCU?CUCU??CUCUCUCU?CUCUCUCU?CUCUCU?CU?CUCUCUCUCUCUCUCUCUCU?CU?CUCU?CUCUCU?CU?CU?CU?CUCUCUCUCU?CU?CUCU?CUCU???CUCUCUCUCU??CU??CUCUCUCUCUCUCUCUCUCU??CUCU??CUCUCU??CUCUCU?CUCU??CUCU?CUCUCUCU?CUCUCU?CUCUCU?CUCUCUCU?CUCUCUCUCUCUCUCUCUCU

Now, in comparison with mine, your output shows three cycles where the starting point of each cycle is:

Email:  someone@domain.com

The second cycle starts after:

Token File: /data/.GoSungrow/AppService_login.json

and the third after:

yyyy/mm/hh hh:mm:ss INFO: Connecting to SunGrow...

Then, in that third cycle, the sequence skips over:

[hh:mm:ss] INFO: Syncing data from gateway https://augateway.isolarcloud.com ...
yyyy/mm/dd hh:mm:ss INFO: Connecting to MQTT HASSIO Service...
yyyy/mm/dd hh:mm:ss INFO: Connecting to SunGrow...

Another thing of note is three distinct values for the Token line. A token would usually be the product of a login so three distinct tokens probably implies three successful logins.

Internally, the GoSungrow Docker container uses the s6 process manager. That means the manager tends to restart any internal processes that fail.

s6 also manages logging such that a bunch of processes running in parallel, each of which is writing log messages, will result in those messages being interwoven in the log you see in the Home Assistant API.

What I'm about to say is based more on instinct than anything I can point to as hard fact so please take it with a few grains of salt.

My instinct is that the variability in the log messages and the multiplicity of tokens likely implies that the GoSungrow mqtt run command is running at least two and perhaps three copies in parallel inside the GoSungrow container.

If I'm right then, from the perspective of augateway.isolarcloud.com, it will look like the same remote machine is making parallel requests. It's probably not geared for that, which may well explain the "repeated request".

So, why...

I have never been able to replicate this particular "repeated request" problem but I have been able to make GoSungrow misbehave by deliberately mucking-up the linkage to the MQTT broker.

And that leads me to a couple of questions:

Are you using an MQTT broker that is being managed by Home Assistant (ie an "add-on") or are you using an external broker such as Mosquitto running on another machine?
If you're using an add-on, is it "Mosquitto broker" or "EMQX"?

I'm using the "Mosquitto broker" add-on. Only one user is defined on my HA instance and, of course, it has admin privileges. It's those admin credentials which I provide to GoSungrow via the mqtt_user and mqtt_password fields.

How close is your setup to that?

Triky101 commented 7 months ago

thanks for your response, it was interesting..

to answer your question.. my setup is the same as yours

HA is using mosquito broker within the same HA PC

I went into mosquito broker to share the log file (pasted below).

What is very weird is that i went into mosquito broker to view the logs so I could post them here.. and then back to the sungrow app to check it had crashed (usually lasts about 2-3 mins then crashes).. it had not crashed.

After a few more minutes it finally crashed..

Sungrow Log:

s6-rc: info: service legacy-cont-init: starting s6-rc: info: service legacy-cont-init successfully started s6-rc: info: service legacy-services: starting s6-rc: info: service legacy-services successfully started [00:08:00] INFO: Setting up GoSungrow config ... [00:08:01] INFO: Writing GoSungrow config ... Using config file '/data/.GoSungrow/config.json' New config: +-------------------+------------+---------------------------+--------------------------------+------------------------------------------------------------------+ | FLAG | SHORT FLAG | ENVIRONMENT | DESCRIPTION | VALUE ( = DEFAULT) | +-------------------+------------+---------------------------+--------------------------------+------------------------------------------------------------------+ | --config | | GOSUNGROW_CONFIG | GoSungrow: config file. | /data/.GoSungrow/config.json | | --debug | | GOSUNGROW_DEBUG | GoSungrow: Debug mode. | true | | --quiet | | GOSUNGROW_QUIET | GoSungrow: Silence all | false | | | | | messages. | | | --timeout | | GOSUNGROW_TIMEOUT | Web timeout. | 1m0s | | --user | -u | GOSUNGROW_USER | SunGrow: api username. | mtrikilis@gmail.com | | --password | -p | GOSUNGROW_PASSWORD | SunGrow: api password. | Bondicatisar1 | | --appkey | | GOSUNGROW_APPKEY | SunGrow: api application key. | B0455FBE7AA0328DB57B59AA729F05D8 | | --host | | GOSUNGROW_HOST | SunGrow: Provider API URL. | https://augateway.isolarcloud.com | | | | | | | | --token-expiry | | GOSUNGROW_TOKEN_EXPIRY | SunGrow: last login. | 2024-04-16T08:07:55 | | --save | -s | GOSUNGROW_SAVE | Save output as a file. | false | | --dir | | GOSUNGROW_DIR | Save output base directory. | | | --mqtt-user | | GOSUNGROW_MQTT_USER | HASSIO: mqtt username. | homeassistant | | --mqtt-password | | GOSUNGROW_MQTT_PASSWORD | HASSIO: mqtt password. | isie4Eechae7iapu5en8Gad8Queep5Ahxah7eegahshoom6Theizahteephei6Ph | | --mqtt-host | | GOSUNGROW_MQTT_HOST | HASSIO: mqtt host. | core-mosquitto | | --mqtt-port | | GOSUNGROW_MQTT_PORT | HASSIO: mqtt port. | 1883 | | --modbus-user | | GOSUNGROW_MODBUS_USER | Modbus username. | | | --modbus-password | | GOSUNGROW_MODBUS_PASSWORD | Modbus password. | | | --modbus-host | | GOSUNGROW_MODBUS_HOST | Modbus host. | | | --modbus-port | | GOSUNGROW_MODBUS_PORT | Modbus port. | 502 * | +-------------------+------------+---------------------------+--------------------------------+------------------------------------------------------------------+ [00:08:01] INFO: Login to iSolarCloud using gateway https://augateway.isolarcloud.com ... Email: Mtrikilis@gmail.com Create Date: Sun May 05 10:19:10 CST 2019 Login Last Date: 2024-04-16 08:07:55 Login Last IP:
Login State: 1 User Account: hs0831qc User Id: 74334 User Name: A1902250988 Is Online: false Token: 74334_b4652257ae3b4e7b8094c7faaf311784 Token File: /data/.GoSungrow/AppService_login.json Email: Mtrikilis@gmail.com Create Date: Sun May 05 10:19:10 CST 2019 Login Last Date: 2024-04-16 08:08:01 Login Last IP:
Login State: 1 User Account: hs0831qc User Id: 74334 User Name: A1902250988 Is Online: false Token: 74334_16dab949a3d44c97829e754531242a67 Token File: /data/.GoSungrow/AppService_login.json [00:08:01] INFO: Syncing data from gateway https://augateway.isolarcloud.com ... 2024/04/16 00:08:01 INFO: Connecting to MQTT HASSIO Service... 2024/04/16 00:08:01 INFO: Connecting to SunGrow... Email: Mtrikilis@gmail.com Create Date: Sun May 05 10:19:10 CST 2019 Login Last Date: 2024-04-16 08:08:01 Login Last IP:
Login State: 1 User Account: hs0831qc User Id: 74334 User Name: A1902250988 Is Online: false Token: 74334_16dab949a3d44c97829e754531242a67 Token File: /data/.GoSungrow/AppService_login.json 2024/04/16 00:08:01 INFO: Found SunGrow 5 devices 2024/04/16 00:08:01 INFO: Option[loglevel] set to 'error' PsId: required JSON request: {"ps_id":1335646}

2024/04/16 00:10:32 ERROR: unknown error 'Repeated request' Error: unknown error 'Repeated request' Usage: GoSungrow mqtt run [flags]

Aliases: run,

Examples: GoSungrow mqtt run

Flags: Use "GoSungrow help flags" for more info.

Additional help topics:

Mosquito broker log:

Mosquitto broker s6-rc: info: service s6rc-oneshot-runner: starting s6-rc: info: service s6rc-oneshot-runner successfully started s6-rc: info: service fix-attrs: starting s6-rc: info: service fix-attrs successfully started s6-rc: info: service legacy-cont-init: starting cont-init: info: running /etc/cont-init.d/mosquitto.sh [10:04:59] INFO: SSL is not enabled cont-init: info: /etc/cont-init.d/mosquitto.sh exited 0 cont-init: info: running /etc/cont-init.d/nginx.sh cont-init: info: /etc/cont-init.d/nginx.sh exited 0 s6-rc: info: service legacy-cont-init successfully started s6-rc: info: service legacy-services: starting services-up: info: copying legacy longrun mosquitto (no readiness notification) services-up: info: copying legacy longrun nginx (no readiness notification) [10:04:59] INFO: Starting NGINX for authentication handling... s6-rc: info: service legacy-services successfully started [10:05:00] INFO: Starting mosquitto MQTT broker... 2024-04-16 10:05:00: Warning: Mosquitto should not be run as root/administrator. 2024-04-16 10:05:00: mosquitto version 2.0.18 starting 2024-04-16 10:05:00: Config loaded from /etc/mosquitto/mosquitto.conf. 2024-04-16 10:05:00: Loading plugin: /usr/share/mosquitto/go-auth.so 2024-04-16 10:05:00: ├── Username/password checking enabled. 2024-04-16 10:05:00: ├── TLS-PSK checking enabled. 2024-04-16 10:05:00: └── Extended authentication not enabled. 2024-04-16 10:05:00: Opening ipv4 listen socket on port 1883. 2024-04-16 10:05:00: Opening ipv6 listen socket on port 1883. 2024-04-16 10:05:00: Opening websockets listen socket on port 1884. 2024-04-16 10:05:00: mosquitto version 2.0.18 running 2024-04-16 10:05:00: New connection from 127.0.0.1:59960 on port 1883. 2024-04-16 10:05:00: Client disconnected due to protocol error. [10:05:00] INFO: Successfully send discovery information to Home Assistant. [10:05:00] INFO: Successfully send service information to the Supervisor. 2024-04-16 10:05:01: New connection from 172.30.32.1:37065 on port 1883. 2024-04-16 10:05:01: New client connected from 172.30.32.1:37065 as 6IN5PBKXtKDqJbkZNM92ik (p2, c1, k60, u'homeassistant'). 2024-04-16 10:05:01: New connection from 172.30.33.5:48386 on port 1883. 2024-04-16 10:05:01: New client connected from 172.30.33.5:48386 as GoSungrow (p2, c1, k30, u'homeassistant'). 2024-04-16 10:05:01: Outgoing messages are being dropped for client 6IN5PBKXtKDqJbkZNM92ik. 2024-04-16 10:05:08: Client GoSungrow closed its connection. 2024-04-16 10:05:13: New connection from 172.30.33.5:46266 on port 1883. 2024-04-16 10:05:13: New client connected from 172.30.33.5:46266 as GoSungrow (p2, c1, k30, u'homeassistant'). 2024-04-16 10:05:14: Client GoSungrow closed its connection. 2024-04-16 10:05:19: New connection from 172.30.33.5:46270 on port 1883. 2024-04-16 10:05:19: New client connected from 172.30.33.5:46270 as GoSungrow (p2, c1, k30, u'homeassistant'). 2024-04-16 10:05:30: New connection from 172.30.32.2:35892 on port 1883. 2024-04-16 10:05:30: Client closed its connection. 2024-04-16 10:07:30: New connection from 172.30.32.2:60402 on port 1883. 2024-04-16 10:07:30: Client closed its connection. 2024-04-16 10:07:50: Client GoSungrow closed its connection. 2024-04-16 10:07:55: New connection from 172.30.33.5:37488 on port 1883. 2024-04-16 10:07:55: New client connected from 172.30.33.5:37488 as GoSungrow (p2, c1, k30, u'homeassistant'). 2024-04-16 10:07:56: Client GoSungrow closed its connection. 2024-04-16 10:08:01: New connection from 172.30.33.5:37494 on port 1883. 2024-04-16 10:08:01: New client connected from 172.30.33.5:37494 as GoSungrow (p2, c1, k30, u'homeassistant'). 2024-04-16 10:09:30: New connection from 172.30.32.2:34190 on port 1883. 2024-04-16 10:09:30: Client closed its connection. 2024-04-16 10:10:32: Client GoSungrow closed its connection. 2024-04-16 10:11:30: New connection from 172.30.32.2:47156 on port 1883. 2024-04-16 10:11:30: Client closed its connection.

Paraphraser commented 7 months ago

Well, at the risk of telling you things you already know, I'm a bit leery of placing too much reliance on what I see in any Log tab in Home Assistant. That's because HA seems to have its own ideas of how much of a container's log it will show.

And that's on top of the fact that a container's log is usually ephemeral anyway. In most cases old logs disappear when the container (ie an add-on) is recreated.

What I have found with the GoSungrow add-on is that the container can be in a restart loop, and that the only way to discern that from the add-on's Log tab is to go out and come back in a few times, paying careful attention to any timestamps in the log entries.

That said, after stopping and then starting the GoSungrow and Mosquitto containers (so as to get clean slates) this is my Mosquitto log:

s6-rc: info: service s6rc-oneshot-runner: starting
s6-rc: info: service s6rc-oneshot-runner successfully started
s6-rc: info: service fix-attrs: starting
s6-rc: info: service fix-attrs successfully started
s6-rc: info: service legacy-cont-init: starting
cont-init: info: running /etc/cont-init.d/mosquitto.sh
[13:38:06] INFO: [32mSSL is not enabled[0m
cont-init: info: /etc/cont-init.d/mosquitto.sh exited 0
cont-init: info: running /etc/cont-init.d/nginx.sh
cont-init: info: /etc/cont-init.d/nginx.sh exited 0
s6-rc: info: service legacy-cont-init successfully started
s6-rc: info: service legacy-services: starting
services-up: info: copying legacy longrun mosquitto (no readiness notification)
services-up: info: copying legacy longrun nginx (no readiness notification)
[13:38:07] INFO: [32mStarting NGINX for authentication handling...[0m
s6-rc: info: service legacy-services successfully started
[13:38:07] INFO: [32mStarting mosquitto MQTT broker...[0m
2024-04-16 13:38:07: Warning: Mosquitto should not be run as root/administrator.
2024-04-16 13:38:07: mosquitto version 2.0.18 starting
2024-04-16 13:38:07: Config loaded from /etc/mosquitto/mosquitto.conf.
2024-04-16 13:38:07: Loading plugin: /usr/share/mosquitto/go-auth.so
2024-04-16 13:38:07:  ├── Username/password checking enabled.
2024-04-16 13:38:07:  ├── TLS-PSK checking enabled.
2024-04-16 13:38:07:  └── Extended authentication not enabled.
2024-04-16 13:38:07: Opening ipv4 listen socket on port 1883.
2024-04-16 13:38:07: Opening ipv6 listen socket on port 1883.
2024-04-16 13:38:07: Opening websockets listen socket on port 1884.
2024-04-16 13:38:07: mosquitto version 2.0.18 running
2024-04-16 13:38:08: New connection from 127.0.0.1:51204 on port 1883.
2024-04-16 13:38:08: Client <unknown> disconnected due to protocol error.
[13:38:08] INFO: [32mSuccessfully send discovery information to Home Assistant.[0m
[13:38:09] INFO: [32mSuccessfully send service information to the Supervisor.[0m
2024-04-16 13:38:14: New connection from 172.30.32.1:56437 on port 1883.
2024-04-16 13:38:14: New client connected from 172.30.32.1:56437 as 7sj36Z9YiT3ew2nc49vGrf (p2, c1, k60, u'homeassistant').
2024-04-16 13:38:15: New connection from 172.30.33.1:52512 on port 1883.
2024-04-16 13:38:15: New client connected from 172.30.33.1:52512 as GoSungrow (p2, c1, k30, u'moi').
2024-04-16 13:39:16: New connection from 172.30.32.2:44700 on port 1883.
2024-04-16 13:39:16: Client <unknown> closed its connection.
2024-04-16 13:41:16: New connection from 172.30.32.2:38328 on port 1883.
2024-04-16 13:41:16: Client <unknown> closed its connection.
2024-04-16 13:43:16: New connection from 172.30.32.2:52650 on port 1883.
2024-04-16 13:43:16: Client <unknown> closed its connection.
2024-04-16 13:45:16: New connection from 172.30.32.2:59296 on port 1883.
2024-04-16 13:45:16: Client <unknown> closed its connection.
2024-04-16 13:47:16: New connection from 172.30.32.2:39912 on port 1883.
2024-04-16 13:47:16: Client <unknown> closed its connection.
2024-04-16 13:49:16: New connection from 172.30.32.2:47908 on port 1883.
2024-04-16 13:49:16: Client <unknown> closed its connection.
2024-04-16 13:51:16: New connection from 172.30.32.2:51770 on port 1883.
2024-04-16 13:51:16: Client <unknown> closed its connection.
2024-04-16 13:53:16: New connection from 172.30.32.2:54334 on port 1883.
2024-04-16 13:53:16: Client <unknown> closed its connection.
2024-04-16 13:55:16: New connection from 172.30.32.2:48818 on port 1883.
2024-04-16 13:55:16: Client <unknown> closed its connection.
2024-04-16 13:57:16: New connection from 172.30.32.2:44730 on port 1883.
2024-04-16 13:57:16: Client <unknown> closed its connection.
2024-04-16 13:59:16: New connection from 172.30.32.2:45130 on port 1883.
2024-04-16 13:59:16: Client <unknown> closed its connection.
2024-04-16 14:01:16: New connection from 172.30.32.2:45496 on port 1883.
2024-04-16 14:01:16: Client <unknown> closed its connection.

For the record, I captured that log in the CLI via:

$ docker logs addon_core_mosquitto

When I compare/contrast your log with mine, everything's the same up until mosquitto version 2.0.18 running.

Then we both get some bogus connection from localhost which is "disconnected due to protocol error". No idea what that means (it might be an internal health-check which is failing).

Then, in mine, exactly two clients get mentioned:

172.30.32.2/23 = hassio_supervisor
172.30.33.1/23 = addon_ba22da74_gosungrow

Your log, on the other hand, has three clients:

172.30.32.1
172.30.32.2
172.30.33.5

Do you have another add-on which is an MQTT client (publisher and/or subscriber)? You can map IP addresses back to containers by wading through the output from:

$ docker network inspect hassio

I find it can be useful to pipe to grep:

$ docker network inspect hassio | grep -B 3 172.30.32.2
                "Name": "hassio_supervisor",
                "EndpointID": "b559102b65087bf15af8c6672b72d6a31d87b0707f42bd9af52d1bd2acf69b60",
                "MacAddress": "02:42:ac:1e:20:02",
                "IPv4Address": "172.30.32.2/23",

I'm not all that hopeful this gets us any closer to figuring out why mine works and yours doesn't.

Maybe also run:

$ docker images

Paraphraser commented 7 months ago

Also, why do you say "usually lasts about 2-3 mins then crashes"? The timestamps in your original log are all 11:07:33 (the second log all 00:08:01) so it seems to be crashing as soon as it starts.

Paraphraser commented 7 months ago

Maybe also run:

$ docker ps -a --format "table {{.Names}}\t{{.RunningFor}}\t{{.Status}}\t{{.Size}}"

Triky101 commented 7 months ago

Hi,

thanks for all your assistance.. I'll work through it and paste the results.

**Do you have another add-on which is an MQTT client (publisher and/or subscriber)? You can map IP addresses back to containers by wading through the output from:

$ docker network inspect hassio**

output:

docker network inspect hassio

[ { "Name": "hassio", "Id": "e1624d0cee54dcae8f1c9cdf61c2719ef0991979b49ae0d605087f2767f4d91d", "Created": "2024-03-07T07:18:28.394885767Z", "Scope": "local", "Driver": "bridge", "EnableIPv6": false, "IPAM": { "Driver": "default", "Options": null, "Config": [ { "Subnet": "172.30.32.0/23", "IPRange": "172.30.33.0/24", "Gateway": "172.30.32.1" } ] }, "Internal": false, "Attachable": false, "Ingress": false, "ConfigFrom": { "Network": "" }, "ConfigOnly": false, "Containers": { "2d5cd08bce2a042e75cb5f86a59a5e3e330e10a13762eabee47987b912680af6": { "Name": "addon_core_configurator", "EndpointID": "1d4383f2d7e29dc8bfac0eee06f7d85c8157434fe1b57e11d7f0de6874c388f4", "MacAddress": "02:42:ac:1e:21:04", "IPv4Address": "172.30.33.4/23", "IPv6Address": "" }, "2f7ccc881ed77d7c4ec37bab44d01f082e9f123e69c9898898cd34dfe5db32ed": { "Name": "addon_f4f71350_ewelink_smart_home_slug", "EndpointID": "3f7489dd1f48afa4c1aba8217f6e05f6f138d09c617d6eedd2150950e165a755", "MacAddress": "02:42:ac:1e:21:03", "IPv4Address": "172.30.33.3/23", "IPv6Address": "" }, "37810dda1c0a57d8554aa995c45b8731a661c3bcb08bdaf587f56564864c86e0": { "Name": "hassio_observer", "EndpointID": "2534d4c55a1add0c342dadd778a1b227e79aade78aeaffc04c9485786e2b969a", "MacAddress": "02:42:ac:1e:20:06", "IPv4Address": "172.30.32.6/23", "IPv6Address": "" }, "5cc268af4d2aaee6471674b1fa2fd38d27b679dc4dddd52a139e49c239dd110d": { "Name": "hassio_dns", "EndpointID": "a9305ebe942e5cf00051d6b24ce541f1d609e9c94b199766a514e0e233246859", "MacAddress": "02:42:ac:1e:20:03", "IPv4Address": "172.30.32.3/23", "IPv6Address": "" }, "826928578af7ed14ecc8a8095c5416dc33111d49f6afd86b6309d35a29ecc826": { "Name": "addon_core_vlc", "EndpointID": "e8f366393bb4777422fa1598a01c74a8dfbff4655f6446b9790481331f4c5acd", "MacAddress": "02:42:ac:1e:21:01", "IPv4Address": "172.30.33.1/23", "IPv6Address": "" }, "a8b12fd55009003f43affa02bf7b0f31e57954ba23c44d91600d4321dcb29c43": { "Name": "hassio_audio", "EndpointID": "3709b772dde57d909547d2ac859c3788f481474a09b47b267a74ef8457b0ed99", "MacAddress": "02:42:ac:1e:20:04", "IPv4Address": "172.30.32.4/23", "IPv6Address": "" }, "a9197838a7c851d9896fc4c75fa450ad7747c9abe2a34f7299014ddeace22f7e": { "Name": "hassio_cli", "EndpointID": "1f119a56deb668c5b8fb3beefb0230b9e9f0a03894c193d5c0ae037afe460c4c", "MacAddress": "02:42:ac:1e:20:05", "IPv4Address": "172.30.32.5/23", "IPv6Address": "" }, "aba156374443484026533653fd150a027bc0717db500d3792aca792cbf6ef974": { "Name": "hassio_supervisor", "EndpointID": "f2320eff2acf8ee08612bd6b92880a298a44765c04f3846f3cb6ef0a0763bc8a", "MacAddress": "02:42:ac:1e:20:02", "IPv4Address": "172.30.32.2/23", "IPv6Address": "" }, "b5a8a3c9c2ea769ee6f7465f5c75c015c22000cd6291f6bdd5dd2004508bc37c": { "Name": "addon_a0d7b954_vscode", "EndpointID": "8b24c3537a2846d09bf615e4c96cea2b6ac481f411078e3e2f2fae47ec3e32ce", "MacAddress": "02:42:ac:1e:21:02", "IPv4Address": "172.30.33.2/23", "IPv6Address": "" }, "ee95bdaa252091ccb9887b009083b01171344dc7873792533a3143b97f24881d": { "Name": "addon_core_mosquitto", "EndpointID": "74e882da26fe13886fec92d937da888b73dfc327eff26f64da9fdcb611770af6", "MacAddress": "02:42:ac:1e:21:00", "IPv4Address": "172.30.33.0/23", "IPv6Address": "" } }, "Options": { "com.docker.network.bridge.name": "hassio" }, "Labels": {} } ] ~ #

===================

docker network inspect hassio | grep -B 3 172.30.32.2

"Name": "hassio_supervisor", "EndpointID": "f2320eff2acf8ee08612bd6b92880a298a44765c04f3846f3cb6ef0a0763bc8a", "MacAddress": "02:42:ac:1e:20:02", "IPv4Address": "172.30.32.2/23",

===========================

docker images REPOSITORY ba22da74/amd64-addon-gosungrow ghcr.io/home-assistant/generic-x86-6 ghcr.io/home-assistant/amd64-hassio-cli ghcr.io/home-assistant/amd64-hassio-dns ghcr.io/home-assistant/amd64-hassio-supervisor ghcr.io/home-assistant/amd64-hassio-supervisor ghcr.io/hassio-addons/node-red/amd64 ghcr.io/home-assistant/amd64-base ghcr.io/hassio-addons/node-red/amd64 ghcr.io/hassio-addons/node-red/amd64 ghcr.io/home-assistant/amd64-hassio-multicast homeassistant/amd64-addon-samba ghcr.io/hassio-addons/ssh/amd64 f4f71350/amd64-addon-ewelink_smart_home_slug homeassistant/amd64-addon-configurator homeassistant/amd64-addon-configurator ghcr.io/hassio-addons/vscode/amd64 ghcr.io/hassio-addons/vscode/amd64 homeassistant/amd64-addon-vlc ghcr.io/home-assistant/amd64-hassio-audio ba22da74/amd64-addon-gosungrow triamazikamno/amd64-addon-gosungrow homeassistant/amd64-addon-mosquitto homeassistant/amd64-addon-mosquitto ghcr.io/home-assistant/amd64-hassio-observer TAG IMAGE ID CREATED SIZE 3.0.7-backup 14a0fbba75e8 2 days ago 118MB 4-homeassistant 2024.4.3 7b07b415b725 5 days ago 1.57GB 2024.04.0 1f37eea30227 9 days ago 52.5MB 2024.04.0 5c3e729cba11 13 days ago 58.7MB 2024.04.0 229c04b9b560 2 weeks ago 335MB latest 229c04b9b560 2 weeks ago 335MB 17.0.11 4bf77671cf78 2 weeks ago 488MB 3.16 3d5bcac5f23e 4 weeks ago 37.8MB 17.0.10 21203477cf10 4 weeks ago 488MB latest 21203477cf10 4 weeks ago 488MB 2024.03.0 73c70d06ef84 5 weeks ago 42.4MB 12.3.1 979b8c974ade 5 weeks ago 84.3MB 17.2.0 383b7eef123b 5 weeks ago 308MB 1.4.3 5a40b0ad7338 6 weeks ago 471MB 5.8.0 5b6b5dab6789 2 months ago 117MB latest 5b6b5dab6789 2 months ago 117MB 5.15.0 7a9dd14f8e3f 3 months ago 943MB latest 7a9dd14f8e3f 3 months ago 943MB 0.3.0 e71e27086964 3 months ago 238MB 2023.12.0 0446586f35b1 4 months ago 71.4MB 3.0.7 f2cbc9418287 4 months ago 161MB 3.0.7 f2cbc9418287 4 months ago 161MB 6.4.0 e65d4ff7d911 4 months ago 209MB latest e65d4ff7d911 4 months ago 209MB 2023.06.0 5a1f2299c4fa 9 months ago 7.76MB

=========================

Also, why do you say "usually lasts about 2-3 mins then crashes"? The timestamps in your original log are all 11:07:33 (the second log all 00:08:01) so it seems to be crashing as soon as it starts.

oddly it usually crashes fairly early on, but sometimes does appear to last a bit longer.. the addon appearing to stay green and the log low to update (or at least show me it has crashed).

I agree.. looking at the timestamps, it crashes pretty early.

===========================

~ # docker ps -a --format "table {{.Names}}\t{{.RunningFor}}\t{{.Status}}\t{{.Size}}" NAMES CREATED STATUS SIZE addon_ba22da74_gosungrow 2 days ago Exited (1) 2 days ago 13.2kB (virtual 161MB) addon_core_mosquitto 2 days ago Up 2 days 18.8kB (virtual 209MB) homeassistant 5 days ago Up 5 days 36.5MB (virtual 1.6GB) addon_a0d7b954_nodered 5 days ago Up 5 days (healthy) 2.43MB (virtual 490MB) addon_core_configurator 5 days ago Up 5 days (healthy) 17.9kB (virtual 117MB) addon_f4f71350_ewelink_smart_home_slug 5 days ago Up 5 days 20.9MB (virtual 492MB) addon_a0d7b954_vscode 5 days ago Up 5 days (healthy) 493kB (virtual 944MB) addon_core_vlc 5 days ago Up 5 days 18.3kB (virtual 238MB) addon_a0d7b954_ssh 5 days ago Up 5 days 26.4MB (virtual 334MB) addon_core_samba 5 days ago Up 5 days (healthy) 19.8MB (virtual 104MB) hassio_multicast 5 days ago Up 5 days 13.7kB (virtual 42.4MB) hassio_audio 5 days ago Up 5 days 17.2kB (virtual 71.4MB) hassio_dns 5 days ago Up 5 days 14.6kB (virtual 58.7MB) hassio_cli 5 days ago Up 5 days 12.9kB (virtual 52.6MB) hassio_supervisor 5 days ago Up 5 days 15.4kB (virtual 335MB) hassio_observer 6 weeks ago Up 5 days 0B (virtual 7.76MB)

Paraphraser commented 7 months ago

Unfortunately, the spurious IP address 172.30.33.5 we were chasing doesn't appear in your network inspect output but my guess is it will turn out to be the Node-RED add-on. That's a logical candidate for another MQTT client.

In your docker ps output is:

addon_ba22da74_gosungrow 2 days ago Exited (1) 2 days ago 13.2kB (virtual 161MB)

From that pattern, I'm guessing that you don't have the "Watchdog" switch enabled in the "Info" tab of the GoSungrow add-on.

What might be going on is the container has been left it in a kind of dangling state where, if it's resumed, it will inherit any gremlins from the previous invocation.

I stress that I don't know this for a certain fact and I have no real means of proving it one way or another in the HA context. It's really just a wild guess. Eliminating it as a possibility involves:

Go into the Advanced SSH & Web Terminal.

Run these commands:

$ docker stop addon_ba22da74_gosungrow
$ docker rm -f addon_ba22da74_gosungrow
$ docker system prune -f

Go back into the GoSungrow add-on GUI and start it.

The docker stop is probably redundant (and may throw an error) but the rm -f should cause full termination. Then, when HA starts the container again, it should be instantiated from the pristine image.

The prune is a general-purpose Docker garbage collection command. Most of the time it does nothing but, occasionally, can be effective.

If that doesn't work then I suppose you could try uninstalling and re-installing the GoSungrow add-on.

For all I know, you've done this several times already

To do it thoroughly, you need to do some work in both the GUI and Terminal.

In the GUI:

Stop the container.
Make a note of all the settings.
Uninstall.

In the Terminal:

Run:

$ docker images | grep -e "REPO" -e "gosungrow"

For each item, in the list, note its Image ID then substitute that into:
```
$ docker rmi «imageID»
```
Repeat steps 1 and 2 until there are no more GoSungrow images.
Finish off with:
```
$ docker system prune -f
```

In the GUI:

Reinstall GoSungrow.
Re-apply the settings as they were before. That includes the updated AppKey.

At this point, if you were to start the container you would get "Request is not encrypted" so now we need to fix that.

In Terminal:

Do the steps in Gist Part 2.

In the GUI:

Start the container.

Other odds and ends you could consider trying:

In the sungrow_user field of the Configuration tab, you can use either an email address or a iSolarCloud username. I've been using the username rather than the email address. Earlier in the thread it looked like you were using a gmail email address. Perhaps substitute your username (which appears to be hs0831qc and perhaps shouldn't really appear in GitHub issues). I don't hold out much hope for this but it is a difference I've noticed so it might be worth a whirl.
I spend a fair bit of time tinkering with Docker containers and helping people with problems.

One fairly common problem I run into has its root cause in the DNS.

One common setup for home routers is your router is also your DHCP server. When a client boots and asks for an IP address, the "lease" issued by the router includes the IP addresses of DNS servers that the client should use. Fairly often, those DNS server IP addresses are learned from the ISP when the router boots and the IP addresses point to DNS servers managed by the ISP.

The "fairly common problem" I mentioned can be traced to how many (not all) ISPs configure their DNS servers.

The solution is to change your router's configuration to use Google's DNS servers 8.8.8.8 and 8.8.4.4. In most routers you need to make the change in two places (a) the DNS servers the router hands out in DHCP leases, and (b) the DNS servers the router itself uses when it needs to resolve something.

If you're using an internal DNS server (eg Pi-hole, AdguardHome, BIND9) then, presumably, you've told your DHCP server to send your clients to that internal DNS server and, in turn, that internal DNS server has been configured with upstream DNS servers where it should relay queries it can't answer itself. If those upstream DNS servers are your ISP's servers then try changing that to 8.8.8.8 etc.

I hope that makes sense.
I make a habit of clobbering IPv6 as soon as I see it. I don't have any particular objection to IPv6 but I don't have it enabled on my ISP connection so I don't see the sense in having all that multicast traffic flying about wasting bandwidth. If you're running IPv6 at home then I suppose there's a non-zero possibility that the behaviour you're seeing could be traced to that.

If none of that gets anywhere then ... dunno. Sorry.

Triky101 commented 7 months ago

I really appreciate the time you are putting into helping me here. Some really sage advice there which swamps my veneer thin understanding of unix, HAOS, dockers and HA itself... luckily hitting problems like this has forced me to blow cobwebs off my previous knowledge and DYOR onto all of that.

Not in any specific order.. I have altered my isolar login from email to account ID (good thinking and certainly worth a try)

yes, I turned off the watchdog wondering if it related to the error.. it was on for dozens of previous attempts.

I have reinstalled heaps of times, but only removed the dock files via the method you proposed (GUI + command prompt) once before (recently) in the hope that a fresh install would not have these issues... none the less, your instructions are far better than the ones I used so I will repeat it and might get a better result.

After my attempted removal, I applied the 'fix' for encryption key and found the same error appear.

Just to be sure, I have also removed rednode as the failure seemed to happen around the time of that addon install (despite me not actually having set anything up in it as yet).

============

edit. ok it's been a few hours of trying stuff.. I am still getting the same problem of that error despite trying everything except for the DNS stuff.. I'll play around with that another day but at this stage am ready to give it a rest before I thrown the MicroPC against a wall .

I actually did notice that somewhere during my tinkering my isolar connection to the Sungrow inverter was lost.. a bit weird.. got it reconnected to the wifi network but then got paranoid the modbus connection I was using had caused this issue (remember someone saying ages ago that modbus can interrupt the wifi connection).

So i've also pulled the ethernet conneciton to the inverter and am going to sulk until Sungrow make their own addon ;)

Paraphraser commented 7 months ago

I see two main obstacles to getting a handle on this "repeated request" problem:

Information about it is scattered across multiple issues; and
Contributions mostly focus on reporting the existence of the error and typically don't contain much about the environment in which the error is occurring.

My goals in writing this post are:

To try to draw together all the threads. GitHub will provide automatic cross-references in the linked issues I've mentioned and, with luck, that will send everyone to this issue.
To try to encourage the provision of more environmental information when people say "I'm hitting this problem too".

Over at Issue 101 @grechi-diego wrote about striking "repeated request":

… both in HA and when running the GoSungrow binary

This is very interesting. To my recollection, this is the first time anyone has mentioned seeing the "repeated request" problem outside of the HA environment.

I have never seen the "repeated request" problem. I suspect it'd be a heck-of-a-lot easier to diagnose if it was happening to me too. In my case, I run GoSungrow:

As the standalone binary, triggered once a day by a cron job, to download "yesterday's" 5-minute data and load the results into an SQLite database. The specific command I use is:
```
$ GoSungrow show point data 
```
where the arguments are the date range followed by a dozen point identifiers. It's a one-shot command (ie it doesn't loop like the HA add-on).
In Home Assistant using the replacement add-on image distributed by @triamazikamno. I do not rely on this and don't use any of the data it collects. I only set it up in the first place to confirm that the gist part 2 instructions work.

Rolling all this together, I've been guilty of making an implicit assumption that the "repeated request" problem is somehow related to Home Assistant, or the implementation of the GoSungrow add-on as a Docker container, or some combinatorial issue.

But now we have evidence that it can also happen to the standalone binary, which means we can eliminate everything except the GoSungrow application.

We are left with the basic conundrum of why some people see "repeated request" while others (like me) are completely unaffected.

I have a theory.

I've done a survey of all the issues on this repo (open or closed).

I can't claim my survey methods are 100% effective because I was using GitHub to look for keywords and expressions. GitHub is never going to find hits if the information is buried in screen-shots. But with that caveat…

The interesting hits on "repeated request" are:

@Triky101 at the very start of this issue (111).
@illuzn Issue 107

In both cases, what jumped out at me was the mention of "Found SunGrow 5 devices" and, more specifically, the "5".

In the #107 link, @illuzn includes the results of running show ps list and remarks on the difference in behaviour between invoking mqtt run with the first or second psid. To quote:

Running ./GoSungrow mqtt run psid1 generates the strconv.Atoi error which I'm encountering above.

Running ./GoSungrow mqtt run psid2 generates the "Repeated request" error I was encountering previously.

The strconv.Atoi error was a separate problem and I believe that was fixed in the work done by @triamazikamno.

Now, for my sins, I have exactly one Sungrow inverter (key details sanitised):

$ GoSungrow show ps list
┏━━━━━━━━━━━━━━━━━━┳━━━━━━━━━┳━━━━━━━━━━━━━┳━━━━━━━━━━━━━┳━━━━━━━━━━━━┳━━━━━━━━━━━━━┳━━━━━━━━━━━━━━┳━━━━━━━━━━━━━━━━┓
┃ Ps Key           ┃ Ps Id   ┃ Device Type ┃ Device Code ┃ Channel Id ┃ Serial #    ┃ Factory Name ┃ Device Model   ┃
┣━━━━━━━━━━━━━━━━━━╇━━━━━━━━━╇━━━━━━━━━━━━━╇━━━━━━━━━━━━━╇━━━━━━━━━━━━╇━━━━━━━━━━━━━╇━━━━━━━━━━━━━━╇━━━━━━━━━━━━━━━━┫
┃ 9999999_1_1_1    │ 9999999 │ 1           │ 1           │ 1          │ B2222334445 │ SUNGROW      │ SG5.0RS        ┃
┃ 9999999_22_247_1 │ 9999999 │ 22          │ 247         │ 1          │ B2222334445 │ SUNGROW      │ WiNet-S        ┃
┃ 9999999_7_1_1    │ 9999999 │ 7           │ 1           │ 1          │ B2222334445 │ SUNGROW      │ SG Smart Meter ┃
┗━━━━━━━━━━━━━━━━━━┷━━━━━━━━━┷━━━━━━━━━━━━━┷━━━━━━━━━━━━━┷━━━━━━━━━━━━┷━━━━━━━━━━━━━┷━━━━━━━━━━━━━━┷━━━━━━━━━━━━━━━━┛

So, I have three devices - all with the same PSID - and log entries to match, for example:

2024/04/21 02:38:12 INFO: Found SunGrow 3 devices

However, the two people who have reported the "repeated request" problem, and who have given sufficient information for their device-count to be known, have five devices.

Plus we have @illuzn with an interesting experiment using different PsIds.

I did another survey to try to gain some feeling for "numbers of devices" and whether they were correlated with problem reports:

Error: identifier rejected:
- 18 Found SunGrow 0 devices
- 19 Found SunGrow 2 devices
- 54 Found SunGrow 0 devices
- 59 Found SunGrow 2 devices
I have no idea what triggers this. For #18 there was some interaction with @MickMake but no obvious resolution. Same with #19. For #54 @hboltz reported solving the problem but didn't say how. And #59 is open with no comments and no resolution.
Error: strconv.Atoi: parsing "«digits»_«digits»": invalid syntax:
- 38 Found SunGrow [3, 4 and 13] devices
- 41 Found SunGrow 2 devices
- 45 Found SunGrow 2 devices
- 92 Found SunGrow 4 devices
- 107 Found SunGrow [2 and 5] devices
As noted earlier, I think this problem was fixed by @triamazikamno.
Error: network Error : dial tcp: lookup Core-mosquitto: no such host:
- 45 Found SunGrow 2 devices
This error is caused by not having installed and started the "Mosquitto broker" add-on for Home Assistant.
Error: network Error : dial tcp: lookup «something» on 127.0.0.11:53: no such host:
- 64 Found SunGrow 2 devices
- 67 Found SunGrow 3 devices
- 80 Found SunGrow 2 devices
- 83 Found SunGrow 3 devices
This error is caused by having an incorrect host name in the host_name field in the GoSungrow add-on's "Configuration" tab.
Error: not Authorized:
- 94 Found SunGrow 3 devices
- 101 Found SunGrow 6 devices
Caused by the credentials set in the mqtt_user and mqtt_password fields in GoSungrow add-on's "Configuration" tab being rejected by the MQTT broker.
panic runtime error: invalid memory address or nil pointer dereference:
- 62 Found SunGrow 2 devices
No idea. Probably a glitch.
Error: No results found:
- 54 Found SunGrow 0 devices
- 70 Found SunGrow 0 devices
My guess is this is the result of incorrect iSolarCloud credentials.

To summarise:

there's probably (just) enough data to support the conclusion that problems other than "repeated request" aren't correlated with the numbers of devices in the ps list; but
while n=2 is not enough data to support a conclusion that "repeated request" is correlated with either:
- more than 3 devices in the ps list; or
- multiple distinct PsIds in the ps list,
it's a glint of a possible theory.

I just thought I'd throw all that on the table in the hope that the people who are experiencing the "repeated request" problem can provide a little more information about their environments.

In particular, please start including your ps list.

If you are running GoSungrow from the command line, just:
```
$ GoSungrow show ps list
```
If your only copy of GoSungrow is the add-on installed in Home Assistant, you can get the information by going into the "Advanced SSH & Web Terminal" and running:
```
$ docker exec addon_ba22da74_gosungrow GoSungrow --config /data/.GoSungrow/config.json show ps list
```

Triky101 commented 7 months ago

Thanks for doing all the hard work investigating this.

I have a nice rainy day today so will do what you recommend and post now.. I have added descriptions of the 5 items listed.

docker exec addon_ba22da74_gosungrow GoSungrow --config /data/.GoSungrow/con fig.json show ps list

┏━━━━━━━━━━━━━━━━━━┳━━━━━━━━━┳━━━━━━━━━━━━━┳━━━━━━━━━━━━━┳━━━━━━━━━━━━┳━━━━━━━━━ ━━━━┳━━━━━━━━━━━━━━┳━━━━━━━━━━━━━━┓ ┃ Ps Key ┃ Ps Id ┃ Device Type ┃ Device Code ┃ Channel Id ┃ Serial # ┃ Factory Name ┃ Device Model ┃ ┣━━━━━━━━━━━━━━━━━━╇━━━━━━━━━╇━━━━━━━━━━━━━╇━━━━━━━━━━━━━╇━━━━━━━━━━━━╇━━━━━━━━━ ━━━━╇━━━━━━━━━━━━━━╇━━━━━━━━━━━━━━┫ ┃ 918497_1_1_1 │ 918497 │ 1 │ 1 │ 1 │ B1902232 002 │ SUNGROW │ SG5K-D ┃ My old Inverter that is no longer in operation but still part of my isolar account ┃ 918497_22_247_1 │ 918497 │ 22 │ 247 │ 1 │ B1902232 002 │ SUNGROW │ WiFi V25 ┃ wifi module of old inverter, not in use any more ┃ 1335646_14_1_1 │ 1335646 │ 14 │ 1 │ 1 │ B23A1117 555 │ SUNGROW │ SH10RT-V112 ┃ New Inverter ┃ 1335646_22_247_1 │ 1335646 │ 22 │ 247 │ 1 │ B23A1117 555 │ SUNGROW │ WiNet-S ┃wifi module of new inverter ┃ 1335646_43_2_1 │ 1335646 │ 43 │ 2 │ 1 │ B23A1117 555 │ SUNGROW │ SBR128 ┃ new sungrow battery system * ┗━━━━━━━━━━━━━━━━━━┷━━━━━━━━━┷━━━━━━━━━━━━━┷━━━━━━━━━━━━━┷━━━━━━━━━━━━┷━━━━━━━━

The found items are 👍 .. nothing weird there as obviously isolar keeps account of new (current) and old equipment attached to the account.

Paraphraser commented 7 months ago

In #107 the commands shown assume GoSungrow mqtt run {PSID} is a supported syntax. I can't find any other evidence that this is true. I did a quick scan of GoSungrow/cmd/cmd_mqtt.go and it looks to me like it discovers the PSID list, then iterates it. When I test on my own system, I can pass any old value after run and it behaves the same as it does if I omit the parameter entirely.

I was going to suggest trying it but I doubt it will work.

Hmmm...

Edit: still, it will be interesting if everyone encountering the duplicate request problem has a PSID list with more than one distinct PSID.

grechi-diego commented 7 months ago

Basterebbe un video dimostrativo su come risolvere i vari problemi.cosi per semplificare e capire le operazioni da EseguireIl 21 apr 2024 05:14, Phill @.***> ha scritto: I see two main obstacles to getting a handle on this "repeated request" problem: Information about it is scattered across multiple issues; andContributions mostly focus on reporting the existence of the error and typically don't contain much about the environment in which the error is occurring. My goals in writing this post are: To try to draw together all the threads. GitHub will provide automatic cross-references in the linked issues I've mentioned and, with luck, that will send everyone to this issue.To try to encourage the provision of more environmental information when people say "I'm hitting this problem too".

Over at Issue 101 @grechi-diego wrote about striking "repeated request":

… both in HA and when running the GoSungrow binary

This is very interesting. To my recollection, this is the first time anyone has mentioned seeing the "repeated request" problem outside of the HA environment. I have never seen the "repeated request" problem. I suspect it'd be a heck-of-a-lot easier to diagnose if it was happening to me too. In my case, I run GoSungrow:

As the standalone binary, triggered once a day by a cron job, to download "yesterday's" 5-minute data and load the results into an SQLite database. The specific command I use is: $ GoSungrow show point data

where the arguments are the date range followed by a dozen point identifiers. It's a one-shot command (ie it doesn't loop like the HA add-on).

In Home Assistant using the replacement add-on image distributed by @triamazikamno. I do not rely on this and don't use any of the data it collects. I only set it up in the first place to confirm that the gist part 2 instructions work.

I run Home Assistant as a guest VM in a Proxmox-VE instance on an old Intel MacMini. I don't actually use Home Assistant for anything else. The only reason I have left it and the GoSungrow add-on running is the faint hope that I, too, will start to see the "repeated request" problem. Rolling all this together, I've been guilty of making an implicit assumption that the "repeated request" problem is somehow related to Home Assistant, or the implementation of the GoSungrow add-on as a Docker container, or some combinatorial issue. But now we have evidence that it can also happen to the standalone binary, which means we can eliminate everything except the GoSungrow application. We are left with the basic conundrum of why some people see "repeated request" while others (like me) are completely unaffected. I have a theory. I've done a survey of all the issues on this repo (open or closed).

I can't claim my survey methods are 100% effective because I was using GitHub to look for keywords and expressions. GitHub is never going to find hits if the information is buried in screen-shots. But with that caveat…

The interesting hits on "repeated request" are: @Triky101 at the very start of this issue @.*** Issue 107 In both cases, what jumped out at me was the mention of "Found SunGrow 5 devices" and, more specifically, the "5". In the #107 link, @illuzn includes the results of running show ps list and remarks on the difference in behaviour between invoking mqtt run with the first or second psid. To quote:

Running ./GoSungrow mqtt run psid1 generates the strconv.Atoi error which I'm encountering above. Running ./GoSungrow mqtt run psid2 generates the "Repeated request" error I was encountering previously.

The strconv.Atoi error was a separate problem and I believe that was fixed in the work done by @triamazikamno. Now, for my sins, I have exactly one Sungrow inverter (key details sanitised): $ GoSungrow show ps list ┏━━━━━━━━━━━━━━━━━━┳━━━━━━━━━┳━━━━━━━━━━━━━┳━━━━━━━━━━━━━┳━━━━━━━━━━━━┳━━━━━━━━━━━━━┳━━━━━━━━━━━━━━┳━━━━━━━━━━━━━━━━┓ ┃ Ps Key ┃ Ps Id ┃ Device Type ┃ Device Code ┃ Channel Id ┃ Serial # ┃ Factory Name ┃ Device Model ┃ ┣━━━━━━━━━━━━━━━━━━╇━━━━━━━━━╇━━━━━━━━━━━━━╇━━━━━━━━━━━━━╇━━━━━━━━━━━━╇━━━━━━━━━━━━━╇━━━━━━━━━━━━━━╇━━━━━━━━━━━━━━━━┫ ┃ 9999999_1_1_1 │ 9999999 │ 1 │ 1 │ 1 │ B2222334445 │ SUNGROW │ SG5.0RS ┃ ┃ 9999999_22_247_1 │ 9999999 │ 22 │ 247 │ 1 │ B2222334445 │ SUNGROW │ WiNet-S ┃ ┃ 9999999_7_1_1 │ 9999999 │ 7 │ 1 │ 1 │ B2222334445 │ SUNGROW │ SG Smart Meter ┃ ┗━━━━━━━━━━━━━━━━━━┷━━━━━━━━━┷━━━━━━━━━━━━━┷━━━━━━━━━━━━━┷━━━━━━━━━━━━┷━━━━━━━━━━━━━┷━━━━━━━━━━━━━━┷━━━━━━━━━━━━━━━━┛

So, I have three devices and log entries to match, for example: 2024/04/21 02:38:12 INFO: Found SunGrow 3 devices

However, the two people who have reported the "repeated request" problem, and who have given sufficient information for their device-count to be known, have five devices. Plus we have @illuzn with an interesting experiment using different PsIds. I did another survey to try to gain some feeling for "numbers of devices" and whether they were correlated with problem reports:

Error: identifier rejected:

18 Found SunGrow 0 devices#19 Found SunGrow 2 devices#54 Found SunGrow 0 devices#59 Found SunGrow 2 devices

I have no idea what triggers this. For #18 there was some interaction with @MickMake but no obvious resolution. Same with #19. For #54 @hboltz reported solving the problem but didn't say how. And #59 is open with no comments and no resolution.

Error: strconv.Atoi: parsing "«digits»_«digits»": invalid syntax:

38 Found SunGrow [3, 4 and 13] devices#41 Found SunGrow 2 devices#45 Found SunGrow 2 devices#92 Found SunGrow 4 devices#107 Found SunGrow [2 and 5] devices

As noted earlier, I think this problem was fixed by @triamazikamno.

Error: network Error : dial tcp: lookup Core-mosquitto: no such host:

45 Found SunGrow 2 devices

This error is caused by not having installed and started the "Mosquitto broker" add-on for Home Assistant.

Error: network Error : dial tcp: lookup «something» on 127.0.0.11:53: no such host :

64 Found SunGrow 2 devices#67 Found SunGrow 3 devices#80 Found SunGrow 2 devices#83 Found SunGrow 3 devices

This error is caused by having an incorrect host name in the host_name field in the GoSungrow add-on's "Configuration" tab.

Error: not Authorized:

94 Found SunGrow 3 devices#101 Found SunGrow 6 devices

Caused by the credentials set in the mqtt_user and mqtt_password fields in GoSungrow add-on's "Configuration" tab being rejected by the MQTT broker.

panic runtime error: invalid memory address or nil pointer dereference:

62 Found SunGrow 2 devices

No idea. Probably a glitch.

Error: No results found:

54 Found SunGrow 0 devices#70 Found SunGrow 0 devices

My guess is this is the result of incorrect iSolarCloud credentials.

To summarise:

there's probably (just) enough data to support the conclusion that problems other than "repeated request" aren't correlated with the numbers of devices in the ps list; but

while n=2 is not enough data to support a conclusion that "repeated request" is correlated with either: more than 3 devices in the ps list; ormultiple distinct PsIds in the ps list, it's a glint of a possible theory.

I just thought I'd throw all that on the table in the hope that the people who are experiencing the "repeated request" problem can provide a little more information about their environments. In particular, please start including your ps list.

If you are running GoSungrow from the command line, just: $ GoSungrow show ps list

If your only copy of GoSungrow is the add-on installed in Home Assistant, you can get the information by going into the "Advanced SSH & Web Terminal" and running: $ docker exec addon_ba22da74_gosungrow GoSungrow --config /data/.GoSungrow/config.json show ps list

—Reply to this email directly, view it on GitHub, or unsubscribe.You are receiving this because you were mentioned.Message ID: @.***>

igoratencompass commented 7 months ago

@Paraphraser this is my contribution for now, will try to collect some more info later in after work hours. Running the binary from my PC in the LAN:

~/GoSungrow$ ./GoSungrow mqtt run --mqtt-host homeassistant.local --mqtt-user <my_mqtt_user> --mqtt-password <password> --mqtt-port 1883
2024/04/23 13:32:30 INFO: Connecting to MQTT HASSIO Service...
2024/04/23 13:32:30 INFO: Connecting to SunGrow...
2024/04/23 13:32:30 INFO: Found SunGrow 2 devices
2024/04/23 13:32:30 INFO: Caching Sungrow metadata...
2024/04/23 13:32:30 INFO: Cached 841 Sungrow data points...
PsId: required
JSON request:   {"ps_id":<snip>}

2024/04/23 13:32:31 ERROR: unknown error 'Repeated request'
Error: unknown error 'Repeated request'
Usage:
  GoSungrow mqtt run [flags]

Aliases:
  run, 

Examples:
    GoSungrow mqtt run  

Flags: Use "GoSungrow help flags" for more info.

Additional help topics:

ERROR: unknown error 'Repeated request'

and no indication in the MQTT broker plugin logs that anything dogie is happening on its side:

2024-04-23 14:05:30: New connection from <my_pc_lan_ip>:41186 on port 1883.
2024-04-23 14:05:30: New client connected from <my_pc_lan_ip>:41186 as GoSungrow (p2, c1, k30, u'<my_mqtt_user>').
2024-04-23 14:05:30: Client GoSungrow closed its connection.

Interesting observation I have is when I run the same command with --debug I do not see the problem, it's kinda this case prevents something to get executed twice maybe? Here is the output in that case:

Email:  <snip>
Create Date:    Thu Dec 07 10:13:26 CST 2023
Login Last Date:    2024-04-23 11:57:15
Login Last IP:  
Login State:    1
User Account:   <snip>
User Id:    <snip>
User Name:  <snip>
Is Online:  false
Token:  <snip>
Token File: /home/user/.GoSungrow/AppService_login.json
2024/04/23 14:00:09 INFO: Connecting to MQTT HASSIO Service...
2024/04/23 14:00:09 INFO: Connecting to SunGrow...
2024/04/23 14:00:09 INFO: Found SunGrow 2 devices
2024/04/23 14:00:09 INFO: Caching Sungrow metadata...
2024/04/23 14:00:09 INFO: Cached 841 Sungrow data points...
2024/04/23 14:00:10 INFO: Syncing 6 entries with HASSIO from queryDeviceList.
C2024/04/23 14:00:10 Unknown parentDevice: 1349127 - will ignore.
UC2024/04/23 14:00:10 Unknown parentDevice: 1349127 - will ignore.
UC2024/04/23 14:00:10 Unknown parentDevice: 1349127 - will ignore.
UC2024/04/23 14:00:10 Unknown parentDevice: 1349127 - will ignore.
UC2024/04/23 14:00:10 Unknown parentDevice: 1349127 - will ignore.
UC2024/04/23 14:00:10 Unknown parentDevice: 1349127 - will ignore.
U
2024/04/23 14:00:10 INFO: Syncing 164 entries with HASSIO from queryDeviceList.
CU-CUCUCUCU-CU-CUCU-CUCU-
2024/04/23 14:00:10 INFO: Syncing 295 entries with HASSIO from getPsList.
CUCUCUCUCUCUCUCUCUCUCUCUCUCUCUCUCUCUCUCUCUCUCUCUCUCUCUCUCUCUCUCUCU??CUCUCUCUCUCUCUCUCUCUCUCUCUCUCUCUCU??CUCUCUCUCUCUCUCUCUCUCUCU?CUCUCUCUCUCUCUCUCU?CUCUCUCUCUCUCUCUCUCUCUCUCUCUCUCUCUCUCUCUCUCUCUCUCUCUCUCUCUCUCUCUCU?CUCUCU??CUCUCUCUCUCUCUCUCUCU?CUCUCUCUCUCU?CUCUCUCUCUCUCUCUCUCUCUCUCUCUCUCUCUCU??CUCUCUCUCUCUCUCU?CUCU?CUCUCUCUCUCUCUCUCUCUCU?CUCUCUCUCUCUCUCUCUCUCUCU?CUCUCUCUCUCUCUCUCUCUCUCUCU?CUCU?CUCUCUCU?CUCUCUCUCUCUCUCUCUCUCUCUCUCUCUCU?CUCUCUCUCUCUCUCUCUCUCUCUCU??CUCUCUCUCUCUCUCUCUCU?CUCUCUCUCUCUCUCUCUCUCUCUCUCUCUCUCUCUCUCUCUCUCUCUCU?CUCUCUCUCUCUCUCUCUCUCU?CU
2024/04/23 14:00:10 INFO: Syncing 205 entries with HASSIO from getPsDetail.
C2024/04/23 14:00:10 Unknown parentDevice: 1349127 - will ignore.
UC2024/04/23 14:00:10 Unknown parentDevice: 1349127 - will ignore.
U?C2024/04/23 14:00:10 Unknown parentDevice: 1349127 - will ignore.

<snip - lots of above 'Unknown parentDevice' messages>

UC2024/04/23 14:00:10 Unknown parentDevice: 1349127 - will ignore.
UC2024/04/23 14:00:10 Unknown parentDevice: 1349127 - will ignore.
UC2024/04/23 14:00:10 Unknown parentDevice: 1349127 - will ignore.
UC2024/04/23 14:00:10 Unknown parentDevice: 1349127 - will ignore.
U?????C2024/04/23 14:00:10 Unknown parentDevice: 1349127 - will ignore.
U?????C2024/04/23 14:00:10 Unknown parentDevice: 1349127 - will ignore.
U
2024/04/23 14:00:10 INFO: Syncing 205 entries with HASSIO from getPsDetail.
CUCUCU??CUCU??CU??CU?CU??CUCU???CUCU?CUCUCUCUCUCUCU????CUCUCUCUCUCUCUCUCUCUCUCUCU??CUCUCUCUCU???CUCUCUCU?CU???CUCUCU?CUCUCUCUCU?CU????CUCU?CUCUCUCUCU?CUCUCU?CUCUCUCUCUCU?CUCU?CU?CUCUCUCUCUCUCUCUCU?CUCUCUCUCUCUCUCU???CUCUCUCU?CUCUCUCUCU??CU??CU?CU?CU????CU?CUCU??CUCUCUCU?CUCUCUCUCUCUCU?CU?CUCUCUCU??CUCU??CUCUCUCU???CUCUCUCUCU??CU?CUCU?CUCU
2024/04/23 14:00:10 INFO: Starting ticker...
2024/04/23 14:00:10 INFO: Fetch Schedule: 5m
2024/04/23 14:00:10 INFO: Sleep Delay:    40s

<NO MORE OUTPUT, IT STOPS HERE>

My devices list:

~/GoSungrow$ ./GoSungrow show ps list

┏━━━━━━━━━━━━━━━━━━┳━━━━━━━━━┳━━━━━━━━━━━━━┳━━━━━━━━━━━━━┳━━━━━━━━━━━━┳━━━━━━━━━━━━━┳━━━━━━━━━━━━━━┳━━━━━━━━━━━━━━┓
┃ Ps Key           ┃ Ps Id   ┃ Device Type ┃ Device Code ┃ Channel Id ┃ Serial #    ┃ Factory Name ┃ Device Model ┃
┣━━━━━━━━━━━━━━━━━━╇━━━━━━━━━╇━━━━━━━━━━━━━╇━━━━━━━━━━━━━╇━━━━━━━━━━━━╇━━━━━━━━━━━━━╇━━━━━━━━━━━━━━╇━━━━━━━━━━━━━━┫
┃ xxxxxxx_1_1_1    │ xxxxxxx │ 1           │ 1           │ 1          │ YYYYYYYYYYY │ SUNGROW      │ SG5.0RS      ┃
┃ xxxxxxx_22_247_1 │ xxxxxxx │ 22          │ 247         │ 1          │ YYYYYYYYYYY │ SUNGROW      │ WiNet-S      ┃
┗━━━━━━━━━━━━━━━━━━┷━━━━━━━━━┷━━━━━━━━━━━━━┷━━━━━━━━━━━━━┷━━━━━━━━━━━━┷━━━━━━━━━━━━━┷━━━━━━━━━━━━━━┷━━━━━━━━━━━━━━┛

NOTE: The unknown device 1349127 showing in the debug output is NOT equal to the xxxxxxx one in the above output.

Paraphraser commented 7 months ago

@igoratencompass very very interesting!

In your show ps list are those two "xxxxxxx" values in the "Ps Id" column the same or are they different? I realise that's the likely meaning of your last sentence but I wanted to be sure.

In mine, the PsID is the same on all three lines (SG5.0RS, WiNet-S, SG Smart Meter), and the PsID is the prefix to each value in the "Ps Key" column. In other words, all my "xxxxxxx" are identical.

When I run:

$ GoSungrow show ps tree

I seem to get two repeats of each:

+   PsId:9999999    PsName:Street   PsKey:9999999_11_0_0    DeviceName:Street   Uuid:1367847
+-- PsId:9999999    PsName:Street   PsKey:9999999_22_247_1  DeviceName:Communication Module1    Uuid:1367849
+-- PsId:9999999    PsName:Street   PsKey:9999999_1_1_1 DeviceName:Inverter1    Uuid:1367850
+   PsId:9999999    PsName:Street   PsKey:9999999_11_0_0    DeviceName:Street   Uuid:1367847
+-- PsId:9999999    PsName:Street   PsKey:9999999_22_247_1  DeviceName:Communication Module1    Uuid:1367849
+-- PsId:9999999    PsName:Street   PsKey:9999999_1_1_1 DeviceName:Inverter1    Uuid:1367850
+----   PsId:9999999    PsName:Street   PsKey:9999999_7_1_1 DeviceName:Meter1   Uuid:1367851

but they are still consistent in that all my 9999999 are the same. Ditto if I run:

$ GoSungrow show ps points

The only value in the "Ps Id" column is that same 9999999.

What happens if you run those commands? Does 1349127 turn up anywhere?

I hadn't tried the --debug command before. It will be interesting to see what happens if people (eg @Triky101) running GoSungrow as the add-on enable Debug in the Configuration tab. Maybe the problem will go away. I've just done a quick test and the flag definitely makes it into /data/.GoSungrow/config.json so it should apply when the mqtt run command is invoked by the container.

As an aside, and just out of curiosity, should I conclude that your system has a CT rather than a meter? Was that your decision or something the installer wanted to do?

igoratencompass commented 7 months ago

Hi @Paraphraser, first thanks for spending time ooking into this it's appreciated.

In your show ps list are those two "xxxxxxx" values in the "Ps Id" column the same or are they different? I realise that's the likely meaning of your last sentence but I wanted to be sure.

Yes the xxxxxxx is the real ID just obfuscated and it is the same for all columns.

What happens if you run those commands? Does 1349127 turn up anywhere?

Yes,

~/GoSungrow$ ./GoSungrow show ps tree
+   PsId:<Ps_ID_1>  PsName:<Ps_Name_1>  PsKey:<Ps_ID_1>_11_0_0      DeviceName:<Ps_Name_1>            Uuid:<Uuid_1>
+-- PsId:<Ps_ID_1>  PsName:<Ps_Name_1>  PsKey:<Ps_ID_1>_22_247_1    DeviceName:Communication Module1  Uuid:<Uuid_2>
+   PsId:<Ps_ID_1>  PsName:<Ps_Name_1>  PsKey:<Ps_ID_1>_11_0_0      DeviceName:<Ps_Name_1>        Uuid:<Uuid_1>
+-- PsId:<Ps_ID_1>  PsName:<Ps_Name_1>  PsKey:<Ps_ID_1>_22_247_1    DeviceName:Communication Module1  Uuid:<Uuid_2>
+-- PsId:<Ps_ID_1>  PsName:<Ps_Name_1>  PsKey:<Ps_ID_1>_1_1_1       DeviceName:Inverter1          Uuid:<Uuid_3>
+   PsId:1349127    PsName:<Ps_Name_2>  PsKey:1349127_11_0_0        DeviceName:<Ps_Name_2>        Uuid:<Uuid_4>

~/GoSungrow$ ./GoSungrow show ps points | grep 1349127 | wc -l
147

and I owe you some explanation here in terms of what and how was provisioned on my site here in Australia. And what was unfortunately messed up during the Plant provisioning :-/

First this is a single phase dwelling with single phase Smart Meter. What I purchased, apart from the panels of course, is a Sungrow Inverter SG5.0RS, WiFi module and an additional Consumption Meter that connects to the Smart Meter and is need to see consumption and export to the greed (otherwise I can only see what the system produces).

The installation was done in coordination with the power supplier who first converted the Smart Meter into Solar enabled one (not sure what that means).

Now about the mess up. After the installation, the technician had a hard time registering the meter and connecting the meter to my WiFi LAN, had to call SunGrow support etc. In the process a Plant was created in the iSolarCloud (on his device) that was never configured properly and left dangling -- after I installed iSolarCloud myself I could not do anything with it, the solar company went unresponsive and I couldn't make any progress in terms of provisioning. I can't even delete it, I don't get that option in the app assuming because the tech guy is the one who provisioned the meter first time? (P.S. Please let me know if you know about a way to delete this Plant, that might solve my problem)

This is what produced that bogus 1349127 ID. From the debug logs we can see GoSungrow ignoring this one and rightfully so.

What I did then is created another Plant which was provisioned all the way to the end and that's the real one with the xxxxxxx ID.

I wander if the people that get the same error have done something similar, by accident or intentionally because they legit have multiple Invertes, causing the problem for the app.

UPDATE: Problem fixed! Just after posting this I thought why not trying the Web version of the app and see if I get elevated permissions there ... and I did. Just deleted the bogus Plant and the GoSungrow plugin is working now.

Paraphraser commented 7 months ago

@igoratencompass brilliant!

With the benefit of hindsight, I think I probably had a lucky escape. My installer started to set things up but I saw what he was doing and, based on my pre-research reading Sungrow documentation and watching their YouTube videos, I was pretty sure he was wrong. I said, "please stop and let me do all that myself, please". The site just came up with all three devices, first time, no fuss.

Paraphraser commented 6 months ago