Something broke in 2024.10.08

[Pigi-102]

Describe the bug After the update I get plenty of error in logs.

Attach the debug log 2024-10-09 20:24:45.472 ERROR (MainThread) [homeassistant] Error doing job: Task exception was never retrieved (None) Traceback (most recent call last): File "/usr/src/homeassistant/homeassistant/helpers/update_coordinator.py", line 258, in _handle_refresh_interval await self._async_refresh(log_failures=True, scheduled=True) File "/usr/src/homeassistant/homeassistant/helpers/update_coordinator.py", line 453, in _async_refresh self.async_update_listeners() File "/usr/src/homeassistant/homeassistant/helpers/update_coordinator.py", line 168, in async_update_listeners update_callback() File "/config/custom_components/solarman/entity.py", line 43, in _handle_coordinator_update self.async_write_ha_state() File "/usr/src/homeassistant/homeassistant/helpers/entity.py", line 1005, in async_write_ha_state self._async_write_ha_state() File "/usr/src/homeassistant/homeassistant/helpers/entity.py", line 1130, in _async_write_ha_state self.async_calculate_state() File "/usr/src/homeassistant/homeassistant/helpers/entity.py", line 1067, in async_calculate_state state = self._stringify_state(available) ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ File "/usr/src/homeassistant/homeassistant/helpers/entity.py", line 1011, in _stringify_state if (state := self.state) is None: ^^^^^^^^^^ File "/usr/src/homeassistant/homeassistant/components/sensor/init.py", line 636, in state raise ValueError( ValueError: Sensor sensor.solarman_inverter_status provides state value '', which is not in the list of options provided

As a file or using the 'code' formatting.

To Reproduce Steps to reproduce the behavior: upgrade to latest, restart home assistant

Expected behavior A clear and concise description of what you expected to happen.

Screenshots If applicable, add screenshots to help explain your problem.

Metadata: Version: [v2024.10.08]

[davidrapan]

What profile it is?

[Pigi-102]

my custom one ( as usual ) The sofar_g3hyd.yaml with all S and T phases removed. It was working on previous version.

[davidrapan]

Can you please enable debug logging, run it for at least 15 minutes and attach it here?

Don't forget to obfuscate the serial number.

[Pigi-102]

At the moment I have reverted. With the v24.09.27 I ( almost ) don't have trouble. I have a shorter one I've done before downgrading, but it only last few minutes. home-assistant_solarman_2024-10-09T18-17-37.821Z.log

[Pigi-102]

Must say that during this tests I also had the problem like last time with an high latency to the stick ( that's why I have tried to upgrade ) . Now I have the old version and have rebooted the stick.

[davidrapan]

There were changes which alters modbus response processing but they should be rather improving than worsening performance.

I'll try to dig into it...

Other than that you should ofc use version which works for you the best, that's a no brainer. 😉

[davidrapan]

Can I see your profile?

[Pigi-102]

Here you are. I have renamed as .txt otherwise it was impossible to upload. sofar_g1hyd.yaml.txt

[davidrapan]

While I'm working on this issue, I have a few suggestions for you:

• Add into your file to default section min_span: 30, it will lover the number of requests by one.
• And maybe you could try to set different update_intervals to the entities by their respective expected change rate? For example update_interval: 5 to the PV Power or update_interval: 300 to the static values like device serial number.

Both of them will drastically reduce the traffic. 😉

[Pigi-102]

Would 86400 be a valid value ? For some I don't need more than a check by day.

Moreover, once modified, it's enough a "reload all yaml" or I need a restart ?

Thx

Pierluigi

[davidrapan]

Would 86400 be a valid value ? For some I don't need more than a check by day.

It should be.

Moreover, once modified, it's enough a "reload all yaml" or I need a restart ?

Devices >> Solarman >> "Your device" >> 3 dots menu >> Reload should be enough but I'm really not 100% sure about that.

[Pigi-102]

just to let you know, min_span is not working and I get something like "failed to reload ". In the log is plenty of crc error. Removed the min_span from the defaults, leaving the update_interval it works correctly. I attach the log. home-assistant_solarman_2024-10-10T20-33-21.697Z.log

[davidrapan]

Ah okay, there are maybe some registers between first two request sets which need different code for reading...

[gedger]

I'm seeing something very similar, I think it may be associated with the inverter going off line? I'm investigation and will add logs and profile when it happens again.

[gedger]

Here's a debug log, definitely looks like when the inverter goes off-line. The integration no longer detects this and keeps polling for data.

home-assistant_solarman_2024-10-12T19-28-08.557Z.log

[davidrapan]

Thanks! fix: Returning new values even when disconnected

[gedger]

will test once the sun rises, unfortunately you can't reboot integration whilst the inverter is off-line.

home-assistant_solarman_2024-10-13T06-15-14.295Z.log

[davidrapan]

I kinda suspect this has to be a fluke and not fault of the integration... I've already seen that with zeroconf too.

[Pigi-102]

Thanks! fix: Returning new values even when disconnected

Works for me ( as now, after 6 hours )! No timeout error, No other errors. Pressure still a bit high on inverter ( some ping lost ) but definitivelly better ! Thanks

[Pigi-102]

I have checked now and it happened 4 time in 13 hours: 2024-10-13 14:31:47.607 ERROR (MainThread) [homeassistant] Error doing job: Task exception was never retrieved (None) Traceback (most recent call last): File "/usr/src/homeassistant/homeassistant/helpers/update_coordinator.py", line 258, in _handle_refresh_interval await self._async_refresh(log_failures=True, scheduled=True) File "/usr/src/homeassistant/homeassistant/helpers/update_coordinator.py", line 453, in _async_refresh self.async_update_listeners() File "/usr/src/homeassistant/homeassistant/helpers/update_coordinator.py", line 168, in async_update_listeners update_callback() File "/config/custom_components/solarman/entity.py", line 42, in _handle_coordinator_update self.update() File "/config/custom_components/solarman/entity.py", line 61, in update if self.sensor_name in self.coordinator.data and (data := self.coordinator.data[self.sensor_name]): ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ TypeError: argument of type 'NoneType' is not iterable 2024-10-13 16:04:41.608 ERROR (MainThread) [homeassistant] Error doing job: Task exception was never retrieved (None) Traceback (most recent call last): File "/usr/src/homeassistant/homeassistant/helpers/update_coordinator.py", line 258, in _handle_refresh_interval await self._async_refresh(log_failures=True, scheduled=True) File "/usr/src/homeassistant/homeassistant/helpers/update_coordinator.py", line 453, in _async_refresh self.async_update_listeners() File "/usr/src/homeassistant/homeassistant/helpers/update_coordinator.py", line 168, in async_update_listeners update_callback() File "/config/custom_components/solarman/entity.py", line 42, in _handle_coordinator_update self.update() File "/config/custom_components/solarman/entity.py", line 61, in update if self.sensor_name in self.coordinator.data and (data := self.coordinator.data[self.sensor_name]): ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ TypeError: argument of type 'NoneType' is not iterable 2024-10-13 17:51:43.161 ERROR (MainThread) [homeassistant.components.mqtt.models] Exception raised while updating state of sensor.umidita_esterna, topic: 'homeassistant/fuori_uno/humidity' with payload: b'nan' Traceback (most recent call last): File "/usr/src/homeassistant/homeassistant/components/mqtt/models.py", line 366, in process_write_state_requests entity.async_write_ha_state() File "/usr/src/homeassistant/homeassistant/helpers/entity.py", line 1005, in async_write_ha_state self._async_write_ha_state() File "/usr/src/homeassistant/homeassistant/helpers/entity.py", line 1130, in _async_write_ha_state self.__async_calculate_state() File "/usr/src/homeassistant/homeassistant/helpers/entity.py", line 1067, in __async_calculate_state state = self._stringify_state(available) ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ File "/usr/src/homeassistant/homeassistant/helpers/entity.py", line 1011, in _stringify_state if (state := self.state) is None: ^^^^^^^^^^ File "/usr/src/homeassistant/homeassistant/components/sensor/__init__.py", line 675, in state raise ValueError( ValueError: Sensor sensor.umidita_esterna has device class 'humidity', state class 'None' unit '%' and suggested precision 'None' thus indicating it has a numeric value; however, it has the non-finite value: 'nan' 2024-10-13 19:04:35.608 ERROR (MainThread) [homeassistant] Error doing job: Task exception was never retrieved (None) Traceback (most recent call last): File "/usr/src/homeassistant/homeassistant/helpers/update_coordinator.py", line 258, in _handle_refresh_interval await self._async_refresh(log_failures=True, scheduled=True) File "/usr/src/homeassistant/homeassistant/helpers/update_coordinator.py", line 453, in _async_refresh self.async_update_listeners() File "/usr/src/homeassistant/homeassistant/helpers/update_coordinator.py", line 168, in async_update_listeners update_callback() File "/config/custom_components/solarman/entity.py", line 42, in _handle_coordinator_update self.update() File "/config/custom_components/solarman/entity.py", line 61, in update if self.sensor_name in self.coordinator.data and (data := self.coordinator.data[self.sensor_name]): ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ TypeError: argument of type 'NoneType' is not iterable

Quite hard to get a log as it should collect of several hours.

Hope this could be usefull. I must say that I'm loogisng some ping to the stick, but not that much. Here the smokeping image from the last 12 hours.

[gedger]

I'm still seeing some issues too, sorry no debug log. Unfortunately I'm probably not going be able to follow this up for a few days but will get some better logs then.

home-assistant_2024-10-13T20-37-00.036Z.log

[davidrapan]

It's also tracked in #211 and I'm already on it. 😉

[davidrapan]

fix: Coordinator returned NoneType on timeout

Should be finally good now! 😉

[Pigi-102]

It works for me, and this time seems to last longer :D It' 12 hours and so far not a simgle error. I'll keep informed till I close.

Thanks for your great job!

[gedger]

Me too, thanks.

I do wonder if the connection error message should be classed as warning though? I think HA uses errors for things that are broken, like configuration, exceptions and use warnings for things that are unexpected.

[davidrapan]

Hey @gedger, What do you mean? Which message in particular?

[Pigi-102]

Unfortunally after almost 24 hour we are back on the too high pressure on inverter like my other problem. I had to reset the stick to make it working again. When this happens the symptom is that ping get lost and rtt becomes high.

[davidrapan]

Can you like show me debug log from around that time when it happens?

[Pigi-102]

Sorry no. I had to reset the stick. I have the log from HA only: 2024-10-15 19:58:42.597 ERROR (MainThread) [custom_components.solarman.coordinator] Timeout fetching solarman data 2024-10-15 20:02:01.598 ERROR (MainThread) [custom_components.solarman.coordinator] Timeout fetching solarman data 2024-10-15 20:18:15.596 ERROR (MainThread) [custom_components.solarman.coordinator] Timeout fetching solarman data 2024-10-15 20:25:29.597 ERROR (MainThread) [custom_components.solarman.coordinator] Timeout fetching solarman data 2024-10-15 20:31:03.597 ERROR (MainThread) [custom_components.solarman.coordinator] Timeout fetching solarman data 2024-10-15 20:33:46.599 ERROR (MainThread) [custom_components.solarman.coordinator] Timeout fetching solarman data 2024-10-15 20:37:38.598 ERROR (MainThread) [custom_components.solarman.coordinator] Timeout fetching solarman data 2024-10-15 21:13:40.597 ERROR (MainThread) [custom_components.solarman.coordinator] Timeout fetching solarman data 2024-10-15 21:15:59.596 ERROR (MainThread) [custom_components.solarman.coordinator] Timeout fetching solarman data 2024-10-15 21:21:20.595 ERROR (MainThread) [custom_components.solarman.coordinator] Timeout fetching solarman data 2024-10-15 21:33:40.596 ERROR (MainThread) [custom_components.solarman.coordinator] Timeout fetching solarman data and the ping problem from smokeping: this never happened with the old integration.

[Pigi-102]

I have rolledback to the old integration, but will continue the tests to check if I get the same errors and the same problems with the ping times and timeout. I'll keep you informed as I like more your integration.

[gedger]

Hey @gedger, What do you mean? Which message in particular?

This one.

2024-10-15 18:30:21.465 ERROR (MainThread) [custom_components.solarman.coordinator] Error fetching Solis data: [1234567890] NoSocketAvailableError: Cannot open connection to 192.168.1.40

[davidrapan]

The log level of this message is outside of integration control. HA assigns it.