davidrapan / ha-solarman

⚡ Solarman Stick Logger integration for 🏠 Home Assistant
MIT License
100 stars 22 forks source link

ZCS Azzurro 1PH HYD 6000 w/ edited sofar_g3hyd - frequent requesting or wrong registers lead to unavailability #156

Closed Pigi-102 closed 1 month ago

Pigi-102 commented 1 month ago

Describe the bug Problem is that using this integration the inverter goes under pression and stops responding. I hadn't had a single disconnect in the last year with the old solarman integration, while since this morning ( after migration ) I had quite a lot of them and the inverter also stopped responding to ping sometimes.

Attach the debug log As a file or using the 'code' formatting.

2024-09-14 17:37:11.590 ERROR (MainThread) [custom_components.solarman.coordinator] Timeout fetching solarman data 2024-09-14 17:38:56.589 DEBUG (MainThread) [custom_components.solarman.api] [23984xxxxx] Request failed. [Previous State: Disconnected (-1)] 2024-09-14 17:38:56.590 INFO (MainThread) [custom_components.solarman.api] [23984xxxxx] Disconnecting from 192.168.2.240:8899 2024-09-14 17:39:01.587 DEBUG (MainThread) [custom_components.solarman.api] [23984xxxxx] Scheduling 8 query requests. #0 2024-09-14 17:39:01.588 DEBUG (MainThread) [custom_components.solarman.api] [23984xxxxx] Querying 1028 - 1067 | 0x0404 - 0x042B # 040 ... 2024-09-14 17:39:01.588 INFO (MainThread) [custom_components.solarman.api] [23984xxxxx] Connecting to 192.168.2.240:8899 2024-09-14 17:39:31.590 DEBUG (MainThread) [custom_components.solarman.api] [23984xxxxx] Request failed. [Previous State: Disconnected (-1)] 2024-09-14 17:39:31.590 INFO (MainThread) [custom_components.solarman.api] [23984xxxxx] Disconnecting from 192.168.2.240:8899 2024-09-14 17:39:31.590 DEBUG (MainThread) [custom_components.solarman.coordinator] Finished fetching solarman data in 30.004 seconds (success: False) 2024-09-14 17:39:36.588 DEBUG (MainThread) [custom_components.solarman.api] [23984xxxxx] Scheduling 8 query requests. #0 2024-09-14 17:39:36.589 DEBUG (MainThread) [custom_components.solarman.api] [23984xxxxx] Querying 1028 - 1067 | 0x0404 - 0x042B # 040 ... 2024-09-14 17:39:36.589 INFO (MainThread) [custom_components.solarman.api] [23984xxxxx] Connecting to 192.168.2.240:8899 2024-09-14 17:40:06.591 DEBUG (MainThread) [custom_components.solarman.api] [23984xxxxx] Request failed. [Previous State: Disconnected (-1)] 2024-09-14 17:40:06.591 INFO (MainThread) [custom_components.solarman.api] [23984xxxxx] Disconnecting from 192.168.2.240:8899 2024-09-14 17:40:06.591 DEBUG (MainThread) [custom_components.solarman.coordinator] Finished fetching solarman data in 30.005 seconds (success: False) 2024-09-14 17:40:11.588 DEBUG (MainThread) [custom_components.solarman.api] [23984xxxxx] Scheduling 8 query requests. #0 2024-09-14 17:40:11.589 DEBUG (MainThread) [custom_components.solarman.api] [23984xxxxx] Querying 1028 - 1067 | 0x0404 - 0x042B # 040 ... 2024-09-14 17:40:11.589 INFO (MainThread) [custom_components.solarman.api] [23984xxxxx] Connecting to 192.168.2.240:8899 2024-09-14 17:40:41.590 DEBUG (MainThread) [custom_components.solarman.api] [23984xxxxx] Request failed. [Previous State: Disconnected (-1)] 2024-09-14 17:40:41.591 INFO (MainThread) [custom_components.solarman.api] [23984xxxxx] Disconnecting from 192.168.2.240:8899 2024-09-14 17:40:41.591 DEBUG (MainThread) [custom_components.solarman.coordinator] Finished fetching solarman data in 30.005 seconds (success: False) 2024-09-14 17:40:46.588 DEBUG (MainThread) [custom_components.solarman.api] [23984xxxxx] Scheduling 8 query requests. #0 2024-09-14 17:40:46.588 DEBUG (MainThread) [custom_components.solarman.api] [23984xxxxx] Querying 1028 - 1067 | 0x0404 - 0x042B # 040 ... 2024-09-14 17:40:46.589 INFO (MainThread) [custom_components.solarman.api] [23984xxxxx] Connecting to 192.168.2.240:8899 2024-09-14 17:41:16.590 DEBUG (MainThread) [custom_components.solarman.api] [23984xxxxx] Request failed. [Previous State: Disconnected (-1)] 2024-09-14 17:41:16.590 INFO (MainThread) [custom_components.solarman.api] [23984xxxxx] Disconnecting from 192.168.2.240:8899 2024-09-14 17:41:16.591 DEBUG (MainThread) [custom_components.solarman.coordinator] Finished fetching solarman data in 30.004 seconds (success: False) 2024-09-14 17:41:21.589 DEBUG (MainThread) [custom_components.solarman.api] [23984xxxxx] Scheduling 8 query requests. #0 2024-09-14 17:41:21.590 DEBUG (MainThread) [custom_components.solarman.api] [23984xxxxx] Querying 1028 - 1067 | 0x0404 - 0x042B # 040 ... 2024-09-14 17:41:21.590 INFO (MainThread) [custom_components.solarman.api] [23984xxxxx] Connecting to 192.168.2.240:8899 2024-09-14 17:41:51.591 DEBUG (MainThread) [custom_components.solarman.api] [23984xxxxx] Request failed. [Previous State: Disconnected (-1)] 2024-09-14 17:41:51.591 INFO (MainThread) [custom_components.solarman.api] [23984xxxxx] Disconnecting from 192.168.2.240:8899 2024-09-14 17:41:51.591 DEBUG (MainThread) [custom_components.solarman.coordinator] Finished fetching solarman data in 30.005 seconds (success: False) 2024-09-14 17:41:56.586 DEBUG (MainThread) [custom_components.solarman.api] [23984xxxxx] Scheduling 8 query requests. #0 2024-09-14 17:41:56.587 DEBUG (MainThread) [custom_components.solarman.api] [23984xxxxx] Querying 1028 - 1067 | 0x0404 - 0x042B # 040 ... 2024-09-14 17:41:56.587 INFO (MainThread) [custom_components.solarman.api] [23984xxxxx] Connecting to 192.168.2.240:8899 2024-09-14 17:42:15.086 DEBUG (MainThread) [custom_components.solarman.api] [23984xxxxx] Querying 1028 - 1067 | 0x0404 - 0x042B # 040 failed. [NoSocketAvailableError: Cannot open connection to 192.168.2.240] 2024-09-14 17:42:15.287 DEBUG (MainThread) [custom_components.solarman.api] [23984xxxxx] Querying 1028 - 1067 | 0x0404 - 0x042B # 040 attempts left: 4 2024-09-14 17:42:15.287 INFO (MainThread) [custom_components.solarman.api] [23984xxxxx] Connecting to 192.168.2.240:8899 2024-09-14 17:42:18.350 DEBUG (MainThread) [custom_components.solarman.api] [23984xxxxx] Querying 1028 - 1067 | 0x0404 - 0x042B # 040 failed. [NoSocketAvailableError: Cannot open connection to 192.168.2.240] 2024-09-14 17:42:18.751 DEBUG (MainThread) [custom_components.solarman.api] [23984xxxxx] Querying 1028 - 1067 | 0x0404 - 0x042B # 040 attempts left: 3 2024-09-14 17:42:18.751 INFO (MainThread) [custom_components.solarman.api] [23984xxxxx] Connecting to 192.168.2.240:8899 2024-09-14 17:42:21.646 DEBUG (MainThread) [custom_components.solarman.api] [23984xxxxx] Querying 1028 - 1067 | 0x0404 - 0x042B # 040 failed. [NoSocketAvailableError: Cannot open connection to 192.168.2.240] 2024-09-14 17:42:22.247 DEBUG (MainThread) [custom_components.solarman.api] [23984xxxxx] Querying 1028 - 1067 | 0x0404 - 0x042B # 040 attempts left: 2 2024-09-14 17:42:22.247 INFO (MainThread) [custom_components.solarman.api] [23984xxxxx] Connecting to 192.168.2.240:8899 2024-09-14 17:42:24.717 DEBUG (MainThread) [custom_components.solarman.api] [23984xxxxx] Querying 1028 - 1067 | 0x0404 - 0x042B # 040 failed. [NoSocketAvailableError: Cannot open connection to 192.168.2.240] 2024-09-14 17:42:25.519 DEBUG (MainThread) [custom_components.solarman.api] [23984xxxxx] Querying 1028 - 1067 | 0x0404 - 0x042B # 040 attempts left: 1 2024-09-14 17:42:25.520 INFO (MainThread) [custom_components.solarman.api] [23984xxxxx] Connecting to 192.168.2.240:8899 2024-09-14 17:42:26.588 DEBUG (MainThread) [custom_components.solarman.api] [23984xxxxx] Request failed. [Previous State: Disconnected (-1)] 2024-09-14 17:42:26.589 INFO (MainThread) [custom_components.solarman.api] [23984xxxxx] Disconnecting from 192.168.2.240:8899 2024-09-14 17:42:26.589 DEBUG (MainThread) [custom_components.solarman.coordinator] Finished fetching solarman data in 30.004 seconds (success: False) 2024-09-14 17:42:31.587 DEBUG (MainThread) [custom_components.solarman.api] [23984xxxxx] Scheduling 8 query requests. #0 2024-09-14 17:42:31.587 DEBUG (MainThread) [custom_components.solarman.api] [23984xxxxx] Querying 1028 - 1067 | 0x0404 - 0x042B # 040 ...

To Reproduce Steps to reproduce the behavior: Quite easy: simply enable the integration and wait few minutes.

Expected behavior Expected behaviour is that it does not hangs the stick .

Metadata: Version: 24.09.08

Additional context I'm not sure if the problem is the pression ( too much request ) or some register but as far as I can see there are not much differences between old integration yaml I'm using and this one, after my cleaning. I use sofar_g3hyd.yaml and remove every entity for the two phases no availables ( _S and _T ) I've added the screen of last update with the "hole" for the time I've had the integration. Screenshot_20240914_183751

davidrapan commented 1 month ago

Hi @Pigi-102, could you please provide log file from HA restart procedure? I need to see some state transition in the log to be able to determine the root cause of your issue and log snipped just contains dc period.

Thanks.

lcavalli commented 1 month ago

Hi, it seems similar to what I experienced and reported here https://github.com/davidrapan/ha-solarman/issues/21#issuecomment-2298052842. In my case after a couple of days the inverter was back online

davidrapan commented 1 month ago

Damn...

And did it ever happened to you again, @lcavalli?

lcavalli commented 1 month ago

Damn...

And did it ever happened to you again, @lcavalli?

Nope 👍🏻

davidrapan commented 1 month ago

@Pigi-102 have you thought to try zcs_azzurro-hyd-zss-hp.yaml for example? At first glance, it looks like a more suitable profile for your device. 😉

Pigi-102 commented 1 month ago

Hello, and sorry for the late reply. As for the logs there is nothing more, in docker logs, than what I've put here. At the moment I have reverted to solarman thus I can't get more info, but my understanding is that if on the solarman my yaml was fine, it should be a good starting point here, am I right ? As I've told, at the start from your integration everything was fine and all the sensor from the yaml I'm using were "filled" and fine. The only problem was that after some ( little ) time the inverter stopped answering to the query, but also to a simple ping. Maybe I should try to increase the polling frequncy ( if there is a parameter in yaml ). The solarman integration seems to poll the inverter every one minute, and is the same interval the inverter use to send data to their external servers. What is your frequency ? Is it possible to change ?

davidrapan commented 1 month ago

it should be a good starting point here, am I right ?

No, cause register values are always fetched dynamically. And bc you are using "wrong" profile it can try to read registers which are out of scope of your device and cripple it down.

Maybe I should try to increase the polling frequency ( if there is a parameter in yaml ).

I'm like 99.99% sure it's not cause of that. 😉 The stick can handle requests even once a second with no issues. But yes you can change it in the file.

Pigi-102 commented 1 month ago

As far as you can tell, can I have both integration installed and configured ? I mean I would like to try the profile you say, but still I have some automation based on values from inverter that are working and would like to keep for now. If I install this integration and configure the save inverter stick would it work ?

Pigi-102 commented 1 month ago

I will reply by my self: no ithey cannot be installed both. They have the same name in the custom_component directory. I have to find a way to rename the entity for ZCS profile so I can test it. I don't want to loose all my historical data, if I can.

davidrapan commented 1 month ago

But it's all up to you.

Have fun!

Pigi-102 commented 1 month ago

I have just now installed this integration but, just to be on the safe side, I have replaced every occurence of "solarman" with solarman_new so I should be able to catch any error I eventually get from this one and not from the "old" one. I choosed the zcs_azzurro-hyd-zss-hp.yaml profile, as per your suggestion, but after few minutes I started to get the "became unknown" message and started loosing ping to it. Screenshot_20240922_090409 Screenshot_20240922_091610

Moreover I'd like to say that on "my" ( my just because I've modified it :) ) profile, that starts from sofar_g3dhyd.yaml, I did a cleanup of every entity that reported "unknown" as state so all the register are fine, working, and with a value. I think this "should" mean there are no register that could lead to some trouble on the stick ( if I'm correct ). "My" sofar profile has 63 entities, while the zcs are 49 ( reading from the integration page )

In the HA logs there are no errors at the moment, after several "become unknown" message. Do you want me to do some more tests ( or eventualy activate the debug ) ?

Let me know.

davidrapan commented 1 month ago

Hi, can you please also enable debug logging and try to catch the point when it becomes unavailable? It looks like it happens rather quickly so maybe it won't be that hard? It would be really helpful!

Thanks!

Pigi-102 commented 1 month ago

home-assistant_solarman_new_2024-09-22T07-43-16.313Z.log Here the log that tracks down completely a "disconnected" event. The event started at 9.41.23 and ended at 9.41.28

As told before, with the previous one I never had a disconnect/connect event. When using the sofar_g1hyd ( mine profile ) with this integration the disconnection time is way longer. Moreover, "my" profile on this integration is the sofar_g3hyd.yaml, with entity names changed ( as per documentation ) to keep history and all the "unknown" entities removed ( basically the entities about the two unavailable phases being my a single phase inverter). Hope you can find something usefull as I really like this one better than the old one.

davidrapan commented 1 month ago

Thanks! I'll look into it.

In a meanwhile could you try add into your custom profile requests_fine_control: right above the requests: so it looks something like this:

requests_fine_control:
requests:
  ...

That should restore the original behavior and could potentially reveal if the issue is cause of the wrong registers or not.

Pigi-102 commented 1 month ago

At the moment I'm not using my custom profile on your integration. As per you suggestion I'm using zcs_azzurro-hyd-zss-hp.yaml. Should I change to my custom and try again ?

davidrapan commented 1 month ago

Yes, cause zcs_azzurro-hyd-zss-hp.yaml does not have full request sets.

Pigi-102 commented 1 month ago

Best would be to try both to be honest.

Yeah, I know, but my HA is not a test environment and it's hard for me to do all the tests. I can do some tests and have to choose which one. I would like to help so it's up to you to choose which profile you want. If I had to choose I'll go with sofar, as there are more entities ( 63 vs 49 ) thus probably I can pull more infos but if you prefer the zcs I'll do the tests for you.

davidrapan commented 1 month ago

That was a bad call from me cause you would have to also use that profile with full requests sets so do it only with your custom one (sofar). 😉

Pigi-102 commented 1 month ago

I think that when entity names are indentical, in different integrations, something weird happens. I have renamed all enetity names in my custom sofar and restarted, just to be on the safe side. I'll let you know what happen now.

Pigi-102 commented 1 month ago

It's funny how now it's working flawlessy. I would give a try again by removing the "old" solarman, renaming the entities and getting this new one, but it will not happen before next w.e.

Pigi-102 commented 1 month ago

It seems that now it's well working. It's four days i'm using the new integration and so far I haven't had the issue. I'll close this one. I will eventually open a new one in case there are other problems. Thank you very much.