wills106 / homeassistant-solax-modbus

SolaX Power Modbus custom_component for Home Assistant (Supports some AlphaESS, Growatt, Sofar, Solinteg, Solis, SRNE, Swatten)
317 stars 101 forks source link

[Bug]: Remote power control gets "stuck" #828

Closed wonko closed 7 months ago

wonko commented 7 months ago

Describe the bug

Up until an upgrade to the latest version last week, remote power control was working fine with the scripts I had.

When using the remote power control with the latest version of the solax modbus plugin, it gets stuck. The script stays in a "running" state after the "button press" to activate remote power control.

Any script gets stuck, but only after the second time any script is used. The first time, it triggers the right mode on the inverter, and everything works as expected. Before the upgrade, I could change some settings, and run the script again, and it would just update to reflect the latest settings.

In the most minimal format, I have the following set:

alias: Charge from grid (1 hour, 3kW)
sequence:
  - service: number.set_value
    data:
      value: "3000"
    target:
      entity_id: number.solax_remotecontrol_active_power
  - service: number.set_value
    data:
      value: "3600"
    target:
      entity_id: number.solax_remotecontrol_autorepeat_duration
  - service: select.select_option
    metadata: {}
    data:
      option: Enabled Battery Control
    target:
      entity_id: select.solax_remotecontrol_power_control
  - service: button.press
    metadata: {}
    data: {}
    target:
      entity_id: button.solax_remotecontrol_trigger
mode: single
icon: mdi:battery

When I enabled debugging logging, I can see the loop every X seconds to fetch all the values. Once I press the button, it will set all the values, and enable the right mode. If I then re-run the script (or any other script using the button), it will get stuck.

It seems that it actually gets stuck after the first button press, as the loop to renew the values no longer happens. A snippet from the logs below.

The settings also no longer update in any entity, the graphs become flat lines at the last value. A reboot of home assistant puts it back in a usable state, but only for 1 update again.

Integration Version

2024.03.7

Homeassistant core version

2024.2.5

Inverter brand

Solax

Plugin used

plugin_solax.py

Serial prefix

H34A06

Inverter firmware versions

DSP 2.07, ASM 2.03

Connection Method

Pocket Wifi, Modbus TCP

Dongle firmware

unknown, where can i find this?

Detailed Error Log

... 2024-03-29 15:53:02.468 DEBUG (MainThread) [custom_components.solax_modbus] treating register 0xba : battery_temperature_high ... 2024-03-29 15:53:02.560 DEBUG (MainThread) [custom_components.solax_modbus] treating register 0x116 : chargeable_battery_capacity 2024-03-29 15:53:02.560 DEBUG (MainThread) [custom_components.solax_modbus] treating register 0x118 : remaining_battery_capacity 2024-03-29 15:53:11.999 INFO (MainThread) [custom_components.solax_modbus.number] local data written remotecontrol_active_power: 3000.0 2024-03-29 15:53:12.004 INFO (MainThread) [custom_components.solax_modbus.number] local data written remotecontrol_autorepeat_duration: 3600 2024-03-29 15:53:12.007 INFO (MainThread) [custom_components.solax_modbus.select] local data written remotecontrol_power_control: 12 2024-03-29 15:53:12.011 DEBUG (MainThread) [custom_components.solax_modbus.plugin_solax] Evaluated remotecontrol_trigger: corrected/clamped values: [('remotecontrol_power_control', 'Enabled Power Control'), ('remotecontrol_set_type', 'Set'), ('remotecontrol_active_power', 1532.0), ('remotecontrol_reactive_power', 0), ('remotecontrol_duration', 20)] 2024-03-29 15:53:12.012 DEBUG (MainThread) [custom_components.solax_modbus] Ready to write multiple registers at 0x7c: [1, 1, 1532, 0, 0, 0, 20] 2024-03-29 15:53:13.112 WARNING (MainThread) [homeassistant.helpers.entity] Update of number.operational_mode is taking over 10 seconds 2024-03-29 15:53:20.314 INFO (MainThread) [custom_components.solax_modbus] saved modified persistent date: {'_version': 1, 'remotecontrol_active_power': 3000.0, 'remotecontrol_reactive_power': 0, 'remotecontrol_duration': 20, 'remotecontrol_autorepeat_duration': 3600.0, 'remotecontrol_import_limit': 20000, 'config_export_control_limit_readscale': None, 'config_max_export': None, 'remotecontrol_power_control': 'Enabled Battery Control', 'remotecontrol_set_type': 'Set'} 2024-03-29 15:53:20.314 INFO (MainThread) [custom_components.solax_modbus.plugin_solax] local data update callback 2024-03-29 15:53:20.315 DEBUG (MainThread) [custom_components.solax_modbus.plugin_solax] Evaluated remotecontrol_trigger: corrected/clamped values: [('remotecontrol_power_control', 'Enabled Power Control'), ('remotecontrol_set_type', 'Set'), ('remotecontrol_active_power', 1548.0), ('remotecontrol_reactive_power', 0), ('remotecontrol_duration', 20)] 2024-03-29 15:53:20.316 DEBUG (MainThread) [custom_components.solax_modbus] ready to repeat button remotecontrol_trigger data: [('remotecontrol_power_control', 'Enabled Power Control'), ('remotecontrol_set_type', 'Set'), ('remotecontrol_active_power', 1548.0), ('remotecontrol_reactive_power', 0), ('remotecontrol_duration', 20)] 2024-03-29 15:54:43.195 WARNING (MainThread) [homeassistant.helpers.entity] Update of number.operational_mode is taking over 10 seconds 2024-03-29 15:54:52.094 INFO (MainThread) [custom_components.solax_modbus.number] local data written remotecontrol_active_power: 4000.0 2024-03-29 15:54:52.102 INFO (MainThread) [custom_components.solax_modbus.number] local data written remotecontrol_autorepeat_duration: 3600 2024-03-29 15:54:52.105 INFO (MainThread) [custom_components.solax_modbus.select] local data written remotecontrol_power_control: 12 2024-03-29 15:54:52.107 DEBUG (MainThread) [custom_components.solax_modbus.plugin_solax] Evaluated remotecontrol_trigger: corrected/clamped values: [('remotecontrol_power_control', 'Enabled Power Control'), ('remotecontrol_set_type', 'Set'), ('remotecontrol_active_power', 2548.0), ('remotecontrol_reactive_power', 0), ('remotecontrol_duration', 20)] 2024-03-29 15:56:13.216 WARNING (MainThread) [homeassistant.helpers.entity] Update of number.operational_mode is taking over 10 seconds 2024-03-29 15:56:23.777 INFO (MainThread) [custom_components.solax_modbus.number] local data written remotecontrol_active_power: 0.0 2024-03-29 15:56:23.784 INFO (MainThread) [custom_components.solax_modbus.number] local data written remotecontrol_autorepeat_duration: 60 2024-03-29 15:56:23.792 INFO (MainThread) [custom_components.solax_modbus.select] *** local data written remotecontrol_power_control: 12 2024-03-29 15:56:23.795 DEBUG (MainThread) [custom_components.solax_modbus.plugin_solax] Evaluated remotecontrol_trigger: corrected/clamped values: [('remotecontrol_power_control', 'Enabled Power Control'), ('remotecontrol_set_type', 'Set'), ('remotecontrol_active_power', -1452.0), ('remotecontrol_reactive_power', 0), ('remotecontrol_duration', 20)]



### Additional context

It worked fine up until the upgrade. I honestly can't remember what version I was coming from. If you know a way on how to find out what my previous version was in HACS, let me know, and I'll check it. 
wonko commented 7 months ago

Additional info, the log actually contains the following upon home-assistant reboot (to unstuck the situation):

2024-03-29 16:31:41.061 WARNING (MainThread) [homeassistant.core] Task <Task pending name='track time interval 15.0' coro=<SolaXModbusHub.async_refresh_modbus_data() running at /config/custom_components/solax_modbus/__init__.py:324> wait_for=<Future pending cb=[Task.task_wakeup()]> cb=[set.remove()]> was still running after final writes shutdown stage; Integrations should cancel non-critical tasks when receiving the stop event to prevent delaying shutdown
2024-03-29 16:31:41.062 WARNING (MainThread) [homeassistant.core] Task <Task pending name='track time interval 15.0' coro=<SolaXModbusHub.async_refresh_modbus_data() running at /config/custom_components/solax_modbus/__init__.py:324> wait_for=<Future pending cb=[Task.task_wakeup()]> cb=[set.remove()]> was still running after final writes shutdown stage; Integrations should cancel non-critical tasks when receiving the stop event to prevent delaying shutdown
2024-03-29 16:31:41.062 WARNING (MainThread) [homeassistant.core] Task <Task pending name='track time interval 10.0' coro=<EntityPlatform._update_entity_states() running at /usr/src/homeassistant/homeassistant/helpers/entity_platform.py:911> wait_for=<Future pending cb=[Task.task_wakeup()]> cb=[set.remove()]> was still running after final writes shutdown stage; Integrations should cancel non-critical tasks when receiving the stop event to prevent delaying shutdown

Don't know if this gives additional insight...

I also checked on the inverter itself, and it switches to the "Normal (R)" mode for about 20 seconds, and then goes back to "Normal", so it seems the autorepeat is also stuck.

adamhf commented 7 months ago

@wonko Try the latest pre-release version that got pushed around an hour ago 2024.03.8b1. I was having a similar issue where the plugin would lock up the moment Power Control was activated and this version resolved it.

infradom commented 7 months ago

I cannot reproduce this bug yet. In the past, I did a lot of work on remote control power, so I will try to help

wonko commented 7 months ago

Confirmed, it is fixed with the latest beta (2024.03.8b1). I can run the scripts multiple times, adjusted settings are used and the entities keep updating. Thx for the fix!

And thanks for this integration!

wills106 commented 7 months ago

I'm closing this down now as it's fixed and released in 2024.03.8