sunsynk icon indicating copy to clipboard operation
sunsynk copied to clipboard

Integration hangs regularly on reading/writing data

Open raulliive opened this issue 11 months ago • 17 comments

Issue related to the Python sunsynk library

Describe the issue/bug

The SunSyk HA add-on is hanging regularly, once in a day or two. HA watchdog is not catching it and I'll need to manually restart the add-on to get it to work again.

Expected behavior

I don't expect integration to hang.

Add-on configuration

DRIVER: solarman
INVERTERS:
  - SERIAL_NR: "XXX"
    HA_PREFIX: SS
    MODBUS_ID: 1
    DONGLE_SERIAL_NUMBER: "XXX"
    PORT: tcp://XXX:8899
SENSOR_DEFINITIONS: three-phase
SENSORS:
  - energy_management
  - power_flow_card
  - pv2_power
  - use_timer
  - Battery temperature
  - Inverter L3 power
  - Inverter L2 power
  - Inverter L1 power
  - Grid L1 power
  - Grid L2 power
  - Grid L3 power
  - Grid L1 voltage
  - Grid L2 voltage
  - Grid L3 voltage
  - Grid CT L1 power
  - Grid CT L2 power
  - Grid CT L3 power
  - DC transformer temperature
  - Radiator temperature
  - Grid Charge Battery current
  - Grid Charge enabled
  - Solar Export
  - Export Limit power
  - Battery Max Charge current
  - Battery Max Discharge current
  - Battery Capacity current
  - Battery Shutdown Capacity
  - Battery Restart Capacity
  - Battery Low Capacity
  - Grid Peak Shaving power
  - Grid Peak Shaving
SENSORS_FIRST_INVERTER:
  - settings
MANUFACTURER: Deye
READ_ALLOW_GAP: 2
READ_SENSORS_BATCH_SIZE: 20
SCHEDULES:
  - KEY: W
    READ_EVERY: 15
    REPORT_EVERY: 15
    CHANGE_ANY: false
    CHANGE_BY: 40
    CHANGE_PERCENT: 0
  - KEY: any_unit
    READ_EVERY: 30
    REPORT_EVERY: 60
    CHANGE_ANY: true
    CHANGE_BY: 40
  - KEY: RW
    READ_EVERY: 15
    REPORT_EVERY: 60
    CHANGE_ANY: true
NUMBER_ENTITY_MODE: auto
MQTT_HOST: XXX
MQTT_PORT: 1883
MQTT_USERNAME: YYY
MQTT_PASSWORD: "ZZZ

Logs (if applicable)

 File "/usr/local/lib/python3.11/site-packages/sunsynk/solarmansunsynk.py", line 72, in read_holding_registers
    return await self.client.read_holding_registers(start, length)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.11/site-packages/pysolarmanv5/pysolarmanv5_async.py", line 263, in read_holding_registers
    modbus_values = await self._get_modbus_response(mb_request_frame)
                    ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.11/site-packages/pysolarmanv5/pysolarmanv5_async.py", line 226, in _get_modbus_response
    mb_response_frame = await self._send_receive_modbus_frame(mb_request_frame)
                        ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.11/site-packages/pysolarmanv5/pysolarmanv5_async.py", line 213, in _send_receive_modbus_frame
    v5_response_frame = await self._send_receive_v5_frame(v5_request_frame)
                        ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.11/site-packages/pysolarmanv5/pysolarmanv5_async.py", line 184, in _send_receive_v5_frame
    await self.writer.drain()
  File "/usr/local/lib/python3.11/asyncio/streams.py", line 366, in drain
    raise exc
  File "/usr/local/lib/python3.11/site-packages/sunsynk/solarmansunsynk.py", line 76, in read_holding_registers
    return await self.client.read_holding_registers(start, length)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.11/site-packages/pysolarmanv5/pysolarmanv5_async.py", line 263, in read_holding_registers
    modbus_values = await self._get_modbus_response(mb_request_frame)
                    ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.11/site-packages/pysolarmanv5/pysolarmanv5_async.py", line 226, in _get_modbus_response
    mb_response_frame = await self._send_receive_modbus_frame(mb_request_frame)
                        ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.11/site-packages/pysolarmanv5/pysolarmanv5_async.py", line 213, in _send_receive_modbus_frame
    v5_response_frame = await self._send_receive_v5_frame(v5_request_frame)
                        ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.11/site-packages/pysolarmanv5/pysolarmanv5_async.py", line 184, in _send_receive_v5_frame
    await self.writer.drain()
  File "/usr/local/lib/python3.11/asyncio/streams.py", line 366, in drain
    raise exc

raulliive avatar Mar 20 '24 06:03 raulliive

solarman probably needs to close/re-establish on any error

kellerza avatar Mar 20 '24 17:03 kellerza

Please try the latest dev version of the addon

kellerza avatar Mar 20 '24 18:03 kellerza

sunsynk-1  | 19:48:48 INFO    Reading startup sensors Prog4 Time, Prog6 Time, Prog1 Time, Rated power, Prog5 Time, Prog2 Time, Battery Low Capacity, Serial, Prog3 Time
sunsynk-1  | 19:48:48 ERROR   Error reading: Connection already closed (retry 1)
sunsynk-1  | 19:48:50 ERROR   Error reading: Connection already closed (retry 2)
sunsynk-1  | 19:48:52 ERROR   Error reading: Connection already closed (retry 3)
sunsynk-1  | 19:48:54 ERROR   Error reading: Connection already closed (retry 4)
sunsynk-1  | 19:48:56 ERROR   Error reading: Connection already closed (retry 5)
sunsynk-1  | 19:48:56 ERROR   Error reading: Connection already closed (retry 1)
sunsynk-1  | 19:48:58 ERROR   Error reading: Connection already closed (retry 2)
sunsynk-1  | 19:49:00 ERROR   Error reading: Connection already closed (retry 3)
sunsynk-1  | 19:49:02 ERROR   Error reading: Connection already closed (retry 4)
sunsynk-1  | 19:49:04 ERROR   Error reading: Connection already closed (retry 5)
sunsynk-1  | 19:49:04 ERROR   Error reading: Connection already closed (retry 1)

rixxxx avatar Mar 20 '24 19:03 rixxxx

I have the same issue @raulliive repored. I implemented ugly workaround so sunsynk crashes and lets docker to restart it again. Never got around to fix it properly.

It probably has no value but you never know.

--- a/src/sunsynk/solarmansunsynk.py
+++ b/src/sunsynk/solarmansunsynk.py
@@ -78,6 +78,9 @@ class SolarmanSunsynk(Sunsynk):
                     _LOGGER.info("Frame error retry attempt(%s): %s", attempt, err)
                 except Exception as err:  # pylint: disable=broad-except
                     _LOGGER.error("Error retry attempt(%s): %s", attempt, err)
+                    if attempt == RETRY_ATTEMPTS-1:
+                        _LOGGER.error("Error retry attempts exceeded")
+                        exit(1)
                 await asyncio.sleep(2)
                 continue
             raise IOError(f"Failed to read register {start}") from exc

rixxxx avatar Mar 20 '24 20:03 rixxxx

@kellerza dev version does not work right now.

I'm getting the same error what @rixxxx posted here.

22:14:14 ERROR   Error reading: Connection already closed (retry 1)
22:14:16 ERROR   Error reading: Connection already closed (retry 2)
22:14:18 ERROR   Error reading: Connection already closed (retry 3)
22:14:20 ERROR   Error reading: Connection already closed (retry 4)
22:14:22 ERROR   Error reading: Connection already closed (retry 5)
22:14:22 ERROR   Error reading: Connection already closed (retry 1)

raulliive avatar Mar 20 '24 22:03 raulliive

Hopefully it is better now!

kellerza avatar Mar 21 '24 10:03 kellerza

Yes, at least it connects and works. We have to wait few days to be sure if it fixes the initial issue.

rixxxx avatar Mar 21 '24 11:03 rixxxx

Thank you.

Edge version now runs, but I get wrong data on SUN-12K-SG04LP3-EU (LV inverter).

Could this be related to the merging of LV and HV inverter definitions?

I'm seeing in log:

14:37:28 WARNING grid_charge_enabled: Unknown register value 65535
14:37:28 WARNING solar_export: Unknown register value 65535
14:37:28 WARNING priority_load: Unknown register value 65535
14:37:28 WARNING load_limit: Unknown register value 65535
14:37:28 WARNING Cannot publish Grid Charge enabled: value is None
14:37:28 WARNING Cannot publish Solar Export: value is None
14:37:28 WARNING Cannot publish Priority Load: value is None
14:37:28 WARNING Cannot publish Load Limit: value is None
14:37:31 WARNING grid_charge_enabled: Unknown register value 65535
14:37:31 WARNING solar_export: Unknown register value 65535
14:37:31 WARNING priority_load: Unknown register value 65535
14:37:31 WARNING load_limit: Unknown register value 65535
14:37:45 WARNING grid_charge_enabled: Unknown register value 65535
14:37:45 WARNING solar_export: Unknown register value 65535
14:37:45 WARNING priority_load: Unknown register value 65535
14:37:45 WARNING load_limit: Unknown register value 65535

Deye

raulliive avatar Mar 21 '24 14:03 raulliive

Its still hanging but now without anything in the log.

rixxxx avatar Mar 22 '24 17:03 rixxxx

Thank you.

Edge version now runs, but I get wrong data on SUN-12K-SG04LP3-EU (LV inverter).

Could this be related to the merging of LV and HV inverter definitions?

I'm seeing in log:

14:37:28 WARNING grid_charge_enabled: Unknown register value 65535

I have exactly the same issue on brand new setup, similar inverter SUN-10K-SG04LP3-EU, 3-phase, LV., could it be related? all read data are 65535... image

My target plan is to use RS485 and modbus, but wanted to try solarman for start first

EDIT: connected over RS485 and same thing image

marekorok avatar Mar 30 '24 09:03 marekorok

I used to use latest table version in docker compose which was commit on 9th of december 2023 https://github.com/kellerza/sunsynk/commit/655ce5c0a2a5fe8edd6139398ee02a4ccb6156b0

When i switched to edge i had same errors like @raulliive and @marekorok. I have the same inverter as them

I tried different versions/commits and seems that something went broken with adding HV inverter support on 29th of december, because next version (https://github.com/kellerza/sunsynk/commit/605e0f4498b19a66149fcb61cb65c5768a430ca5) is already broken for LV.

06:19:49 WARNING load_limit: Unknown register value 65535 06:19:49 WARNING grid_charge_enabled: Unknown register value 65535 06:19:49 WARNING priority_load: Unknown register value 65535 06:19:49 WARNING solar_export: Unknown register value 65535 06:19:49 WARNING Cannot publish Load Limit: value is None 06:19:49 WARNING Cannot publish Grid Charge enabled: value is None 06:19:49 WARNING Cannot publish Priority Load: value is None 06:19:49 WARNING Cannot publish Solar Export: value is None 06:19:50 WARNING load_limit: Unknown register value 65535 06:19:50 WARNING grid_charge_enabled: Unknown register value 65535 06:19:50 WARNING priority_load: Unknown register value 65535 06:19:50 WARNING solar_export: Unknown register value 65535 06:19:55 WARNING load_limit: Unknown register value 65535 06:19:55 WARNING grid_charge_enabled: Unknown register value 65535 06:19:55 WARNING priority_load: Unknown register value 65535 06:19:55 WARNING solar_export: Unknown register value 65535 06:20:00 WARNING load_limit: Unknown register value 65535 06:20:00 WARNING grid_charge_enabled: Unknown register value 65535 06:20:00 WARNING priority_load: Unknown register value 65535 06:20:00 WARNING solar_export: Unknown register value 65535 06:20:00 WARNING Cannot publish Load Limit: value is None 06:20:00 WARNING Cannot publish Grid Charge enabled: value is None 06:20:00 WARNING Cannot publish Priority Load: value is None 06:20:00 WARNING Cannot publish Solar Export: value is No

Maybe the options.yaml changed and i have wrong values there? I have SENSOR_DEFINITIONS: three-phase, which should be LV sensors conf

`--- DRIVER: solarman INVERTERS:

  • SERIAL_NR: 'xxxxx' HA_PREFIX: SS MODBUS_ID: 1 PORT: tcp://192.168.1.154:8899 DONGLE_SERIAL_NUMBER: 'xxxxx' SENSOR_DEFINITIONS: three-phase SENSORS:
  • energy_management
  • load_limit
  • battery_max_charge_current
  • battery_max_discharge_current
  • battery_capacity_current
  • grid_charge_battery_current
  • grid_charge_enabled
  • power_flow_card
  • battery_current
  • battery_power
  • battery_soc
  • battery_voltage
  • battery_temperature
  • day_battery_charge
  • day_battery_discharge
  • day_grid_export
  • day_grid_import
  • day_load_energy
  • day_pv_energy
  • grid_connected
  • grid_ct_power
  • grid_frequency
  • grid_power
  • grid_current
  • grid_l1_power
  • grid_l2_power
  • grid_l3_power
  • overall_state
  • priority_load
  • pv1_current
  • pv1_power
  • pv1_voltage
  • pv2_current
  • pv2_power
  • pv2_voltage
  • load_power
  • load_l1_power
  • load_l2_power
  • load_l3_power
  • date_time
  • inverter_power
  • inverter_l1_power
  • inverter_l2_power
  • inverter_l3_power
  • inverter_voltage
  • inverter_frequency
  • radiator_temperature
  • dc_transformer_temperature
  • solar_export SENSORS_FIRST_INVERTER:
    • settings MANUFACTURER: Deye READ_SENSORS_BATCH_SIZE: 60 SCHEDULES:
    • KEY: W READ_EVERY: 5 REPORT_EVERY: 60 CHANGE_ANY: false CHANGE_BY: 80 CHANGE_PERCENT: 0 NUMBER_ENTITY_MODE: auto MQTT_HOST: 192.168.1.35 MQTT_PORT: 1883 MQTT_USERNAME: hass MQTT_PASSWORD: '' DEBUG: 0 DEBUG_DEVICE: "/dev/ttyAMA0" `

martinarva avatar Apr 09 '24 06:04 martinarva

After talking with people I'm pretty sure we have 2 separate issues here. One of them is hanging.This affects both LV and HV inverters and what this issue actually was related to. And then we have separate issue where LV inverter gets wrong values all the time. I think it makes sense to split the 2. I'm working on the 2nd issue where the LV numbers are wrong.

rixxxx avatar Apr 09 '24 07:04 rixxxx

@kellerza , could you please commit https://github.com/kellerza/sunsynk/pull/269 pull request )

martinarva avatar Apr 09 '24 11:04 martinarva

After talking with people I'm pretty sure we have 2 separate issues here. One of them is hanging.This affects both LV and HV inverters and what this issue actually was related to. And then we have separate issue where LV inverter gets wrong values all the time. I think it makes sense to split the 2. I'm working on the 2nd issue where the LV numbers are wrong.

Can confirm that https://github.com/kellerza/sunsynk/pull/269 fixed the issue. Thanks @rixxxx

CC @raulliive @marekorok

martinarva avatar Apr 09 '24 18:04 martinarva

Can confirm that #269 fixed the issue. Thanks @rixxxx

CC @raulliive @marekorok

ok, I was trying to test it and updated the file sensors_options.py within the docker image

but no effect, still have this double definitions in log, restarted docker of course.

Can you help @martinarva? What am I missing?

marekorok avatar Apr 09 '24 20:04 marekorok

@marekorok If you want to go the hard way then you should patch the /usr/local/lib/python3.11/site-packages/ha_addon_sunsynk_multi/sensor_options.py and then restart the container.

rixxxx avatar Apr 09 '24 21:04 rixxxx

@marekorok If you want to go the hard way then you should patch the /usr/local/lib/python3.11/site-packages/ha_addon_sunsynk_multi/sensor_options.py and then restart the container.

Thank you! tested and works on my side, I see all data properly

marekorok avatar Apr 10 '24 08:04 marekorok

#287 fixed the hanging for me

rixxxx avatar Jun 03 '24 09:06 rixxxx