huawei_solar
huawei_solar copied to clipboard
wlcrs
[Bug]: Wrong values from battery sensor
System Health details
System Information
| version | core-2022.10.5 |
|---|---|
| installation_type | Home Assistant OS |
| dev | false |
| hassio | true |
| docker | true |
| user | root |
| virtualenv | false |
| python_version | 3.10.5 |
| os_name | Linux |
| os_version | 5.15.72 |
| arch | x86_64 |
| timezone | Europe/Rome |
| config_dir | /config |
Home Assistant Community Store
| GitHub API | ok |
|---|---|
| GitHub Content | failed to load: unreachable |
| GitHub Web | ok |
| GitHub API Calls Remaining | 4888 |
| Installed Version | 1.28.3 |
| Stage | running |
| Available Repositories | 1198 |
| Downloaded Repositories | 25 |
Home Assistant Cloud
| logged_in | false |
|---|---|
| can_reach_cert_server | ok |
| can_reach_cloud_auth | ok |
| can_reach_cloud | ok |
Home Assistant Supervisor
| host_os | Home Assistant OS 9.2 |
|---|---|
| update_channel | stable |
| supervisor_version | supervisor-2022.10.0 |
| agent_version | 1.4.1 |
| docker_version | 20.10.17 |
| disk_total | 30.8 GB |
| disk_used | 17.9 GB |
| healthy | true |
| supported | true |
| board | ova |
| supervisor_api | ok |
| version_api | ok |
| installed_addons | Network UPS Tools (0.11.0), TasmoAdmin (0.20.0), SSH & Web Terminal (12.0.2), Samba share (10.0.0), Studio Code Server (5.4.0), File editor (5.4.1) |
Dashboards
| dashboards | 2 |
|---|---|
| resources | 13 |
| views | 15 |
| mode | storage |
Recorder
| oldest_recorder_run | 15 ottobre 2022 09:04 |
|---|---|
| current_recorder_run | 24 ottobre 2022 20:58 |
| estimated_db_size | 2499.09 MiB |
| database_engine | sqlite |
| database_version | 3.38.5 |
Xiaomi Miot Auto
| component_version | 0.7.0 |
|---|---|
| can_reach_server | ok |
| can_reach_spec | ok |
| logged_accounts | 0 |
| total_devices | 0 |
Huawei Solar Setup
Inverter Type: 10KTL-M1 Inverter Firmware version: SPC146 SDongle present: yes (FW SPC130) Power meter present: three phase DTSU-666H Battery: LUNA2000 2x10kWh
How do you connect to the inverter?
Via the SDongle, wired connection
Describe the issue
Sometimes i have these spikes from sensor.battery_charge_discharge_power that messes my statistics. The last one started from 03:45:30 to 03:45:41
Relevant debug logs
https://gist.github.com/xm4rcell0x/a0d703168001ba1ab65a49205209befe
Thank you for the debugging logs. It looks like the problem is situated in the underlying pyModbus library, as it is returning values that correspond with another read request.
Correct reading before:
2022-10-25 03:45:20.241 DEBUG (MainThread) [huawei_solar.huawei_solar] Reading register 37760
2022-10-25 03:45:20.241 DEBUG (MainThread) [pymodbus.client.asynchronous.async_io] send: 0x43 0x18 0x0 0x0 0x0 0x6 0x1 0x3 0x93 0x80 0x0 0x1c
2022-10-25 03:45:20.241 DEBUG (MainThread) [pymodbus.transaction] Adding transaction 17176
2022-10-25 03:45:21.061 DEBUG (MainThread) [pymodbus.client.asynchronous.async_io] recv: 0x43 0x18 0x0 0x0 0x0 0x3b 0x1 0x3 0x38 0x1 0xd6 0x0 0x0 0x0 0x2 0x18 0x51 0xff 0xf6 0xff 0xff 0xfd 0xc8 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x7f 0x2e 0x0 0x0 0x86 0x5d 0x0 0x0 0x0 0x2 0x0 0x0 0x1 0x36
2022-10-25 03:45:21.061 DEBUG (MainThread) [pymodbus.framer.socket_framer] Processing: 0x43 0x18 0x0 0x0 0x0 0x3b 0x1 0x3 0x38 0x1 0xd6 0x0 0x0 0x0 0x2 0x18 0x51 0xff 0xf6 0xff 0xff 0xfd 0xc8 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x7f 0x2e 0x0 0x0 0x86 0x5d 0x0 0x0 0x0 0x2 0x0 0x0 0x1 0x36
2022-10-25 03:45:21.061 DEBUG (MainThread) [pymodbus.factory] Factory Response[ReadHoldingRegistersResponse: 3]
2022-10-25 03:45:21.061 DEBUG (MainThread) [pymodbus.transaction] Getting transaction 17176
2022-10-25 03:45:21.112 DEBUG (MainThread) [pymodbus.payload] [470, 0, 2, 6225, 65526, 65535, 64968, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 32558, 0, 34397, 0, 2, 0, 310]
Incorrect reading:
2022-10-25 03:45:28.862 DEBUG (MainThread) [huawei_solar.huawei_solar] Reading register 37760
2022-10-25 03:45:28.862 DEBUG (MainThread) [pymodbus.client.asynchronous.async_io] send: 0x43 0x1d 0x0 0x0 0x0 0x6 0x1 0x3 0x93 0x80 0x0 0x1c
2022-10-25 03:45:28.862 DEBUG (MainThread) [pymodbus.transaction] Adding transaction 17181
2022-10-25 03:45:30.635 DEBUG (MainThread) [pymodbus.client.asynchronous.async_io] recv: 0x43 0x1d 0x0 0x0 0x0 0x4d 0x1 0x3 0x4a 0x0 0x0 0x9 0x6f 0x0 0x0 0x9 0x3d 0x0 0x0 0x9 0x36 0x0 0x0 0x0 0x51 0xff 0xff 0xff 0x96 0xff 0xff 0xff 0x1d 0xff 0xff 0xff 0xf4 0x0 0x0 0x2 0xc3 0xff 0xec 0x13 0x85 0x0 0x0 0x47 0xc7 0x0 0x0 0xec 0x35 0x0 0x0 0x0 0x0 0x0 0x1 0x0 0x0 0x10 0x2a 0x0 0x0 0xf 0xfb 0x0 0x0 0x10 0x25 0x0 0x0 0x0 0xc2 0xff 0xff 0xff 0xd4 0xff 0xff 0xff 0x5f
2022-10-25 03:45:30.635 DEBUG (MainThread) [pymodbus.framer.socket_framer] Processing: 0x43 0x1d 0x0 0x0 0x0 0x4d 0x1 0x3 0x4a 0x0 0x0 0x9 0x6f 0x0 0x0 0x9 0x3d 0x0 0x0 0x9 0x36 0x0 0x0 0x0 0x51 0xff 0xff 0xff 0x96 0xff 0xff 0xff 0x1d 0xff 0xff 0xff 0xf4 0x0 0x0 0x2 0xc3 0xff 0xec 0x13 0x85 0x0 0x0 0x47 0xc7 0x0 0x0 0xec 0x35 0x0 0x0 0x0 0x0 0x0 0x1 0x0 0x0 0x10 0x2a 0x0 0x0 0xf 0xfb 0x0 0x0 0x10 0x25 0x0 0x0 0x0 0xc2 0xff 0xff 0xff 0xd4 0xff 0xff 0xff 0x5f
2022-10-25 03:45:30.635 DEBUG (MainThread) [pymodbus.factory] Factory Response[ReadHoldingRegistersResponse: 3]
2022-10-25 03:45:30.635 DEBUG (MainThread) [pymodbus.transaction] Getting transaction 17181
2022-10-25 03:45:30.686 DEBUG (MainThread) [pymodbus.payload] [0, 2415, 0, 2365, 0, 2358, 0, 81, 65535, 65430, 65535, 65309, 65535, 65524, 0, 707, 65516, 4997, 0, 18375, 0, 60469, 0, 0, 1, 0, 4138, 0, 4091, 0, 4133, 0, 194, 65535, 65492, 65535, 65375]
Correct reading after:
2022-10-25 03:45:40.866 DEBUG (MainThread) [huawei_solar.huawei_solar] Reading register 37760
2022-10-25 03:45:40.866 DEBUG (MainThread) [pymodbus.client.asynchronous.async_io] send: 0x43 0x22 0x0 0x0 0x0 0x6 0x1 0x3 0x93 0x80 0x0 0x1c
2022-10-25 03:45:40.867 DEBUG (MainThread) [pymodbus.transaction] Adding transaction 17186
2022-10-25 03:45:41.474 DEBUG (MainThread) [pymodbus.client.asynchronous.async_io] recv: 0x43 0x22 0x0 0x0 0x0 0x3b 0x1 0x3 0x38 0x1 0xd6 0x0 0x0 0x0 0x2 0x18 0x54 0xff 0xfa 0xff 0xff 0xfd 0xa5 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x7f 0x2e 0x0 0x0 0x86 0x5d 0x0 0x0 0x0 0x2 0x0 0x0 0x1 0x36
2022-10-25 03:45:41.475 DEBUG (MainThread) [pymodbus.framer.socket_framer] Processing: 0x43 0x22 0x0 0x0 0x0 0x3b 0x1 0x3 0x38 0x1 0xd6 0x0 0x0 0x0 0x2 0x18 0x54 0xff 0xfa 0xff 0xff 0xfd 0xa5 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x7f 0x2e 0x0 0x0 0x86 0x5d 0x0 0x0 0x0 0x2 0x0 0x0 0x1 0x36
2022-10-25 03:45:41.475 DEBUG (MainThread) [pymodbus.factory] Factory Response[ReadHoldingRegistersResponse: 3]
2022-10-25 03:45:41.475 DEBUG (MainThread) [pymodbus.transaction] Getting transaction 17186
2022-10-25 03:45:41.525 DEBUG (MainThread) [pymodbus.payload] [470, 0, 2, 6228, 65530, 65535, 64933, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 32558, 0, 34397, 0, 2, 0, 310]
Note that just before the incorrect reading, we need to do a retry for reading other registers:
2022-10-25 03:45:23.561 DEBUG (MainThread) [huawei_solar.huawei_solar] Reading register 37101
2022-10-25 03:45:23.561 DEBUG (MainThread) [pymodbus.client.asynchronous.async_io] send: 0x43 0x1b 0x0 0x0 0x0 0x6 0x1 0x3 0x90 0xed 0x0 0x25
2022-10-25 03:45:23.561 DEBUG (MainThread) [pymodbus.transaction] Adding transaction 17179
2022-10-25 03:45:26.563 INFO (MainThread) [backoff] Backing off _do_read(...) for 2.0s (asyncio.exceptions.TimeoutError)
2022-10-25 03:45:26.563 DEBUG (MainThread) [huawei_solar.huawei_solar] Backing off reading for 2.0 seconds after 1 tries
2022-10-25 03:45:28.563 DEBUG (MainThread) [pymodbus.client.asynchronous.async_io] send: 0x43 0x1c 0x0 0x0 0x0 0x6 0x1 0x3 0x90 0xed 0x0 0x25
2022-10-25 03:45:28.564 DEBUG (MainThread) [pymodbus.transaction] Adding transaction 17180
2022-10-25 03:45:28.809 DEBUG (MainThread) [pymodbus.client.asynchronous.async_io] recv: 0x43 0x1c 0x0 0x0 0x0 0x4d 0x1 0x3 0x4a 0x0 0x0 0x9 0x6f 0x0 0x0 0x9 0x3d 0x0 0x0 0x9 0x36 0x0 0x0 0x0 0x51 0xff 0xff 0xff 0x96 0xff 0xff 0xff 0x1e 0xff 0xff 0xff 0xf5 0x0 0x0 0x2 0xc2 0xff 0xf4 0x13 0x85 0x0 0x0 0x47 0xc7 0x0 0x0 0xec 0x35 0x0 0x0 0x0 0x0 0x0 0x1 0x0 0x0 0x10 0x2a 0x0 0x0 0xf 0xfa 0x0 0x0 0x10 0x24 0x0 0x0 0x0 0xc0 0xff 0xff 0xff 0xd0 0xff 0xff 0xff 0x65
2022-10-25 03:45:28.809 DEBUG (MainThread) [pymodbus.framer.socket_framer] Processing: 0x43 0x1c 0x0 0x0 0x0 0x4d 0x1 0x3 0x4a 0x0 0x0 0x9 0x6f 0x0 0x0 0x9 0x3d 0x0 0x0 0x9 0x36 0x0 0x0 0x0 0x51 0xff 0xff 0xff 0x96 0xff 0xff 0xff 0x1e 0xff 0xff 0xff 0xf5 0x0 0x0 0x2 0xc2 0xff 0xf4 0x13 0x85 0x0 0x0 0x47 0xc7 0x0 0x0 0xec 0x35 0x0 0x0 0x0 0x0 0x0 0x1 0x0 0x0 0x10 0x2a 0x0 0x0 0xf 0xfa 0x0 0x0 0x10 0x24 0x0 0x0 0x0 0xc0 0xff 0xff 0xff 0xd0 0xff 0xff 0xff 0x65
2022-10-25 03:45:28.809 DEBUG (MainThread) [pymodbus.factory] Factory Response[ReadHoldingRegistersResponse: 3]
2022-10-25 03:45:28.809 DEBUG (MainThread) [pymodbus.transaction] Getting transaction 17180
2022-10-25 03:45:28.861 DEBUG (MainThread) [pymodbus.payload] [0, 2415, 0, 2365, 0, 2358, 0, 81, 65535, 65430, 65535, 65310, 65535, 65525, 0, 706, 65524, 4997, 0, 18375, 0, 60469, 0, 0, 1, 0, 4138, 0, 4090, 0, 4132, 0, 192, 65535, 65488, 65535, 65381]
I know that a few days ago, a new version of the pyModbus-library was released: 3.0.0 . I'll start by upgrading from the current pyModbus version (2.5.3) to this new major version. As this is a new major version, I expect that some changes/testing will be necessary.
However, I'm not sure that this will actually fix the error as looking into the raw data shows that the incorrect data is really transmitted with the transaction-id of the query for the battery values. Maybe I can detect the wrong values by comparing the number of received registers with the number of requested ones?
In the meantime: You seem to have changed the update frequency from 30 to 10 seconds, which is really the upper limit of how fast we can query the inverter. Does the problem still show when reverting to the original update frequency?
Thank you for the explanation! For the last question i have edited the update frequency with this method (from default to 1s) [https://community.home-assistant.io/t/integration-solar-inverter-huawei-2000l/132350/2116?u=xm4rcell0x] . I wanna first try with 10s with your official method (trough the automation) and monitoring the situation.
So...do you think that the update frequency is also related to my random disconnections? I'll update you in next days
Hi, downloaded and installed 1.1.4.b1 and i have this error (i'm on 2022.10.5, OS 9.3)
`Logger: homeassistant.setup Source: setup.py:184 First occurred: 12:50:32 (1 occurrences) Last logged: 12:50:32
Setup failed for custom integration huawei_solar: Requirements for huawei_solar not found: ['huawei-solar==2.1.4b2'].`
after reverting back to 1.1.2 (I simply re-downloaded the 1.1.2 without a wipe of the integration) i have these errors
`Logger: homeassistant.components.number Source: custom_components/huawei_solar/number.py:185 Integration: Numero (documentation, issues) First occurred: 13:04:05 (1 occurrences) Last logged: 13:04:05
Error while setting up huawei_solar platform for number Traceback (most recent call last): File "/usr/src/homeassistant/homeassistant/helpers/entity_platform.py", line 281, in _async_setup_platform await asyncio.shield(task) File "/config/custom_components/huawei_solar/number.py", line 120, in async_setup_entry await HuaweiSolarNumberEntity.create( File "/config/custom_components/huawei_solar/number.py", line 185, in create initial_value = (await bridge.client.get(description.key)).value File "/usr/local/lib/python3.10/site-packages/huawei_solar/huawei_solar.py", line 245, in get return (await self.get_multiple([name], slave))[0] File "/usr/local/lib/python3.10/site-packages/huawei_solar/huawei_solar.py", line 295, in get_multiple result = [await self._decode_response(registers[0], decoder)] File "/usr/local/lib/python3.10/site-packages/huawei_solar/huawei_solar.py", line 237, in _decode_response result = reg.decode(decoder, self) File "/usr/local/lib/python3.10/site-packages/huawei_solar/registers.py", line 70, in decode result = getattr(decoder, self._decode_function_name)() File "/usr/local/lib/python3.10/site-packages/pymodbus/payload.py", line 411, in decode_32bit_uint handle = self._unpack_words(fstring, handle) File "/usr/local/lib/python3.10/site-packages/pymodbus/payload.py", line 361, in _unpack_words handle = unpack(up, handle) struct.error: unpack requires a buffer of 4 bytes `
`Logger: huawei_solar.huawei_solar Source: /usr/local/lib/python3.10/site-packages/huawei_solar/huawei_solar.py:156 First occurred: 12:58:17 (1 occurrences) Last logged: 12:58:17
Aborting client creation due to error. Traceback (most recent call last): File "/usr/local/lib/python3.10/site-packages/huawei_solar/huawei_solar.py", line 150, in create await huawei_solar._initialize() File "/usr/local/lib/python3.10/site-packages/huawei_solar/huawei_solar.py", line 115, in _initialize self.time_zone = (await self.get(rn.TIME_ZONE)).value File "/usr/local/lib/python3.10/site-packages/huawei_solar/huawei_solar.py", line 245, in get return (await self.get_multiple([name], slave))[0] File "/usr/local/lib/python3.10/site-packages/huawei_solar/huawei_solar.py", line 287, in get_multiple response = await self._read_registers( File "/usr/local/lib/python3.10/site-packages/huawei_solar/huawei_solar.py", line 378, in _read_registers result = await _do_read() File "/usr/local/lib/python3.10/site-packages/backoff/_async.py", line 133, in retry ret = await target(*args, **kwargs) File "/usr/local/lib/python3.10/site-packages/huawei_solar/huawei_solar.py", line 360, in _do_read raise ReadException( huawei_solar.exceptions.ReadException: Got error while reading from register 43006 with length 1: Exception Response(131, 3, IllegalAddress) `
Can you retry installing 1.1.4b1 ? It is a common caching issue on PyPI that install fails on the first try.
Those errors that you're sending me from 1.1.2 are pretty strange to be honest.
Op do 27 okt. 2022 om 13:08 schreef xm4rcell0x @.***>:
after reverting back to 1.1.2 (I simply re-downloaded the 1.1.2 without a wipe of the integration) i have these errors
`Logger: homeassistant.components.number Source: custom_components/huawei_solar/number.py:185 Integration: Numero (documentation, issues) First occurred: 13:04:05 (1 occurrences) Last logged: 13:04:05
Error while setting up huawei_solar platform for number Traceback (most recent call last): File "/usr/src/homeassistant/homeassistant/helpers/entity_platform.py", line 281, in _async_setup_platform await asyncio.shield(task) File "/config/custom_components/huawei_solar/number.py", line 120, in async_setup_entry await HuaweiSolarNumberEntity.create( File "/config/custom_components/huawei_solar/number.py", line 185, in create initial_value = (await bridge.client.get(description.key)).value File "/usr/local/lib/python3.10/site-packages/huawei_solar/huawei_solar.py", line 245, in get return (await self.get_multiple([name], slave))[0] File "/usr/local/lib/python3.10/site-packages/huawei_solar/huawei_solar.py", line 295, in get_multiple result = [await self._decode_response(registers[0], decoder)] File "/usr/local/lib/python3.10/site-packages/huawei_solar/huawei_solar.py", line 237, in _decode_response result = reg.decode(decoder, self) File "/usr/local/lib/python3.10/site-packages/huawei_solar/registers.py", line 70, in decode result = getattr(decoder, self._decode_function_name)() File "/usr/local/lib/python3.10/site-packages/pymodbus/payload.py", line 411, in decode_32bit_uint handle = self._unpack_words(fstring, handle) File "/usr/local/lib/python3.10/site-packages/pymodbus/payload.py", line 361, in _unpack_words handle = unpack(up, handle) struct.error: unpack requires a buffer of 4 bytes `
`Logger: huawei_solar.huawei_solar Source: /usr/local/lib/python3.10/site-packages/huawei_solar/huawei_solar.py:156 First occurred: 12:58:17 (1 occurrences) Last logged: 12:58:17
Aborting client creation due to error. Traceback (most recent call last): File "/usr/local/lib/python3.10/site-packages/huawei_solar/huawei_solar.py", line 150, in create await huawei_solar._initialize() File "/usr/local/lib/python3.10/site-packages/huawei_solar/huawei_solar.py", line 115, in _initialize self.time_zone = (await self.get(rn.TIME_ZONE)).value File "/usr/local/lib/python3.10/site-packages/huawei_solar/huawei_solar.py", line 245, in get return (await self.get_multiple([name], slave))[0] File "/usr/local/lib/python3.10/site-packages/huawei_solar/huawei_solar.py", line 287, in get_multiple response = await self._read_registers( File "/usr/local/lib/python3.10/site-packages/huawei_solar/huawei_solar.py", line 378, in _read_registers result = await _do_read() File "/usr/local/lib/python3.10/site-packages/backoff/_async.py", line 133, in retry ret = await target(*args, **kwargs) File "/usr/local/lib/python3.10/site-packages/huawei_solar/huawei_solar.py", line 360, in _do_read raise ReadException( huawei_solar.exceptions.ReadException: Got error while reading from register 43006 with length 1: Exception Response(131, 3, IllegalAddress) `
— Reply to this email directly, view it on GitHub https://github.com/wlcrs/huawei_solar/issues/162#issuecomment-1293363196, or unsubscribe https://github.com/notifications/unsubscribe-auth/AAQM5LAZL6T5IEYWAX3QZBTWFJPC3ANCNFSM6AAAAAAROG2AMY . You are receiving this because you commented.Message ID: @.***>
Ok, I know what's going on. This morning I also got a lot of complaints that the integration was broken in 2022.11.0b0 . This is caused by the backoff-dependency that was forced in home assistant to be <2.0 before, but is now >=2.0 in the new beta version.
If you want to test, you'll need to upgrade to the beta version for now. I'm going to file an issue on the HASS issue tracker, because this will break a lot of integrations otherwise.
I've created the issue upstream https://github.com/home-assistant/core/issues/81085, and have released a new beta-version that is compatible with both 2022.11.x and 2022.10.x (and below).
Can you try again with 1.1.4b2?
No, you can disregard my post saying that you would need to use 2022.11.0b0. Just upgrade to beta version 1.1.4b2 and report back your findings.
I have these type of errors:
Logger: custom_components.huawei_solar
Source: helpers/update_coordinator.py:151
Integration: Huawei Solar
First occurred: 16:14:00 (6 occurrences)
Last logged: 16:49:08
Timeout fetching HV2240335957_data_update_coordinator data`
in homeassistant log i found this:
2022-10-27 16:49:07.815 DEBUG (SyncWorker_1) [pymodbus.transaction] Running transaction 10496
2022-10-27 16:49:07.815 DEBUG (SyncWorker_1) [pymodbus.transaction] SEND: 0x29 0x0 0x0 0x0 0x0 0x6 0x0 0x3 0x0 0x13 0x0 0x1
2022-10-27 16:49:07.815 DEBUG (SyncWorker_1) [pymodbus.client.sync] New Transaction state 'SENDING'
2022-10-27 16:49:07.815 DEBUG (SyncWorker_1) [pymodbus.transaction] Changing transaction state from 'SENDING' to 'WAITING FOR REPLY'
2022-10-27 16:49:07.921 DEBUG (SyncWorker_1) [pymodbus.transaction] Changing transaction state from 'WAITING FOR REPLY' to 'PROCESSING REPLY'
2022-10-27 16:49:07.921 DEBUG (SyncWorker_1) [pymodbus.transaction] RECV: 0x29 0x0 0x0 0x0 0x0 0x5 0x0 0x3 0x2 0x6 0xd4
2022-10-27 16:49:07.921 DEBUG (SyncWorker_1) [pymodbus.framer.socket_framer] Processing: 0x29 0x0 0x0 0x0 0x0 0x5 0x0 0x3 0x2 0x6 0xd4
2022-10-27 16:49:07.921 DEBUG (SyncWorker_1) [pymodbus.factory] Factory Response[ReadHoldingRegistersResponse: 3]
2022-10-27 16:49:07.921 DEBUG (SyncWorker_1) [pymodbus.transaction] Adding transaction 10496
2022-10-27 16:49:07.921 DEBUG (SyncWorker_1) [pymodbus.transaction] Getting transaction 10496
2022-10-27 16:49:07.921 DEBUG (SyncWorker_1) [pymodbus.transaction] Changing transaction state from 'PROCESSING REPLY' to 'TRANSACTION_COMPLETE'
2022-10-27 16:49:07.922 DEBUG (SyncWorker_5) [pymodbus.transaction] Current transaction state - TRANSACTION_COMPLETE
2022-10-27 16:49:07.922 DEBUG (SyncWorker_5) [pymodbus.transaction] Running transaction 10497
2022-10-27 16:49:07.922 DEBUG (SyncWorker_5) [pymodbus.transaction] SEND: 0x29 0x1 0x0 0x0 0x0 0x6 0x0 0x3 0x0 0x1e 0x0 0x2
2022-10-27 16:49:07.922 DEBUG (SyncWorker_5) [pymodbus.client.sync] New Transaction state 'SENDING'
2022-10-27 16:49:07.923 DEBUG (SyncWorker_5) [pymodbus.transaction] Changing transaction state from 'SENDING' to 'WAITING FOR REPLY'
2022-10-27 16:49:08.002 ERROR (MainThread) [custom_components.huawei_solar] Timeout fetching HV2240335957_data_update_coordinator data
2022-10-27 16:49:08.023 DEBUG (SyncWorker_5) [pymodbus.transaction] Changing transaction state from 'WAITING FOR REPLY' to 'PROCESSING REPLY'
2022-10-27 16:49:08.023 DEBUG (SyncWorker_5) [pymodbus.transaction] RECV: 0x29 0x1 0x0 0x0 0x0 0x7 0x0 0x3 0x4 0x0 0x0 0x1 0x17
2022-10-27 16:49:08.023 DEBUG (SyncWorker_5) [pymodbus.framer.socket_framer] Processing: 0x29 0x1 0x0 0x0 0x0 0x7 0x0 0x3 0x4 0x0 0x0 0x1 0x17
2022-10-27 16:49:08.023 DEBUG (SyncWorker_5) [pymodbus.factory] Factory Response[ReadHoldingRegistersResponse: 3]
2022-10-27 16:49:08.023 DEBUG (SyncWorker_5) [pymodbus.transaction] Adding transaction 10497
2022-10-27 16:49:08.023 DEBUG (SyncWorker_5) [pymodbus.transaction] Getting transaction 10497
2022-10-27 16:49:08.023 DEBUG (SyncWorker_5) [pymodbus.transaction] Changing transaction state from 'PROCESSING REPLY' to 'TRANSACTION_COMPLETE'
2022-10-27 16:49:08.023 DEBUG (SyncWorker_2) [pymodbus.transaction] Current transaction state - TRANSACTION_COMPLETE
------------------------------------------------------------
2022-10-27 16:48:56.855 DEBUG (SyncWorker_6) [pymodbus.transaction] Running transaction 10447
2022-10-27 16:48:56.855 DEBUG (SyncWorker_6) [pymodbus.transaction] SEND: 0x28 0xcf 0x0 0x0 0x0 0x6 0x0 0x3 0x0 0xf 0x0 0x2
2022-10-27 16:48:56.855 DEBUG (SyncWorker_6) [pymodbus.client.sync] New Transaction state 'SENDING'
2022-10-27 16:48:56.855 DEBUG (SyncWorker_6) [pymodbus.transaction] Changing transaction state from 'SENDING' to 'WAITING FOR REPLY'
2022-10-27 16:48:57.011 INFO (MainThread) [backoff] Backing off _do_read(...) for 4.0s (asyncio.exceptions.TimeoutError)
2022-10-27 16:48:57.011 DEBUG (MainThread) [huawei_solar.huawei_solar] Backing off reading for 4.0 seconds after 3 tries
2022-10-27 16:48:57.352 DEBUG (SyncWorker_6) [pymodbus.transaction] Changing transaction state from 'WAITING FOR REPLY' to 'PROCESSING REPLY'
2022-10-27 16:48:57.352 DEBUG (SyncWorker_6) [pymodbus.transaction] RECV: 0x28 0xcf 0x0 0x0 0x0 0x7 0x0 0x3 0x4 0x0 0xcd 0x64 0x4c
2022-10-27 16:48:57.353 DEBUG (SyncWorker_6) [pymodbus.framer.socket_framer] Processing: 0x28 0xcf 0x0 0x0 0x0 0x7 0x0 0x3 0x4 0x0 0xcd 0x64 0x4c
2022-10-27 16:48:57.353 DEBUG (SyncWorker_6) [pymodbus.factory] Factory Response[ReadHoldingRegistersResponse: 3]
2022-10-27 16:48:57.353 DEBUG (SyncWorker_6) [pymodbus.transaction] Adding transaction 10447
2022-10-27 16:48:57.353 DEBUG (SyncWorker_6) [pymodbus.transaction] Getting transaction 10447
2022-10-27 16:48:57.353 DEBUG (SyncWorker_6) [pymodbus.transaction] Changing transaction state from 'PROCESSING REPLY' to 'TRANSACTION_COMPLETE'
2022-10-27 16:48:57.354 DEBUG (SyncWorker_3) [pymodbus.transaction] Current transaction state - TRANSACTION_COMPLETE
------------------------------------------------------------
2022-10-27 16:48:51.774 DEBUG (SyncWorker_0) [pymodbus.transaction] Running transaction 10424
2022-10-27 16:48:51.774 DEBUG (SyncWorker_0) [pymodbus.transaction] SEND: 0x28 0xb8 0x0 0x0 0x0 0x6 0x0 0x3 0x0 0xf 0x0 0x2
2022-10-27 16:48:51.775 DEBUG (SyncWorker_0) [pymodbus.client.sync] New Transaction state 'SENDING'
2022-10-27 16:48:51.775 DEBUG (SyncWorker_0) [pymodbus.transaction] Changing transaction state from 'SENDING' to 'WAITING FOR REPLY'
2022-10-27 16:48:52.003 DEBUG (MainThread) [pymodbus.client.asynchronous.async_io] send: 0x1 0x59 0x0 0x0 0x0 0x6 0x1 0x3 0x7d 0x40 0x0 0x34
2022-10-27 16:48:52.003 DEBUG (MainThread) [pymodbus.transaction] Adding transaction 345
2022-10-27 16:48:52.009 DEBUG (MainThread) [pymodbus.client.asynchronous.async_io] recv: 0x1 0x59 0x0 0x0 0x0 0x3 0x1 0x83 0x6
2022-10-27 16:48:52.009 DEBUG (MainThread) [pymodbus.framer.socket_framer] Processing: 0x1 0x59 0x0 0x0 0x0 0x3 0x1 0x83 0x6
2022-10-27 16:48:52.009 DEBUG (MainThread) [pymodbus.factory] Factory Response[131]
2022-10-27 16:48:52.009 DEBUG (MainThread) [pymodbus.transaction] Getting transaction 345
2022-10-27 16:48:52.009 INFO (MainThread) [backoff] Backing off _do_read(...) for 2.0s (huawei_solar.exceptions.SlaveBusyException)
2022-10-27 16:48:52.009 DEBUG (MainThread) [huawei_solar.huawei_solar] Backing off reading for 2.0 seconds after 2 tries
2022-10-27 16:48:52.232 DEBUG (SyncWorker_0) [pymodbus.transaction] Changing transaction state from 'WAITING FOR REPLY' to 'PROCESSING REPLY'
2022-10-27 16:48:52.233 DEBUG (SyncWorker_0) [pymodbus.transaction] RECV: 0x28 0xb8 0x0 0x0 0x0 0x7 0x0 0x3 0x4 0x0 0xcd 0x64 0x4c
2022-10-27 16:48:52.233 DEBUG (SyncWorker_0) [pymodbus.framer.socket_framer] Processing: 0x28 0xb8 0x0 0x0 0x0 0x7 0x0 0x3 0x4 0x0 0xcd 0x64 0x4c
2022-10-27 16:48:52.233 DEBUG (SyncWorker_0) [pymodbus.factory] Factory Response[ReadHoldingRegistersResponse: 3]
2022-10-27 16:48:52.233 DEBUG (SyncWorker_0) [pymodbus.transaction] Adding transaction 10424
2022-10-27 16:48:52.233 DEBUG (SyncWorker_0) [pymodbus.transaction] Getting transaction 10424
2022-10-27 16:48:52.233 DEBUG (SyncWorker_0) [pymodbus.transaction] Changing transaction state from 'PROCESSING REPLY' to 'TRANSACTION_COMPLETE'
2022-10-27 16:48:52.234 DEBUG (SyncWorker_5) [pymodbus.transaction] Current transaction state - TRANSACTION_COMPLETE
In case I receive wrong values, I now do a retry. This can cause timeouts if you're trying to read too fast from the inverter, as the update-requests come too fast and the modbus-interface gets clogged up.
Ok I'm trying with default values for the first error. I'll update you in next days for the Topic Errors
Hi! i've updated to 1.1.4.b3 and now integration doesn't work anymore (reverting back to b2 works again) here the logs:
Logger: huawei_solar.huawei_solar
Source: /usr/local/lib/python3.10/site-packages/huawei_solar/huawei_solar.py:160
First occurred: 09:05:44 (1 occurrences)
Last logged: 09:05:44
Aborting client creation due to error.
Traceback (most recent call last):
File "/usr/local/lib/python3.10/site-packages/huawei_solar/huawei_solar.py", line 154, in create
await huawei_solar._initialize()
File "/usr/local/lib/python3.10/site-packages/huawei_solar/huawei_solar.py", line 121, in _initialize
self.battery_type = (await self.get(rn.STORAGE_UNIT_1_PRODUCT_MODEL)).value
File "/usr/local/lib/python3.10/site-packages/huawei_solar/huawei_solar.py", line 251, in get
return (await self.get_multiple([name], slave))[0]
File "/usr/local/lib/python3.10/site-packages/huawei_solar/huawei_solar.py", line 301, in get_multiple
result = [await self._decode_response(registers[0], decoder)]
File "/usr/local/lib/python3.10/site-packages/huawei_solar/huawei_solar.py", line 243, in _decode_response
result = reg.decode(decoder, self)
File "/usr/local/lib/python3.10/site-packages/huawei_solar/registers.py", line 78, in decode
result = self.unit(result)
File "/usr/local/lib/python3.10/enum.py", line 385, in __call__
return cls.__new__(cls, value)
File "/usr/local/lib/python3.10/enum.py", line 710, in __new__
raise ve_exc
ValueError: 60 is not a valid StorageProductModel
`
-------------------------------------------------------------------------------------------------
`Questo errore ha avuto origine da un'integrazione personalizzata.
Logger: homeassistant.config_entries
Source: custom_components/huawei_solar/__init__.py:63
Integration: Huawei Solar
First occurred: 09:05:44 (1 occurrences)
Last logged: 09:05:44
Error setting up entry SUN2000-10KTL-M1`
In the core this was caused by the same problem: the integration receives an answer to another query than the one it made, resulting in wrong values being processed. It is not possible for me to detect that his has happened.
Hopefully this is a bug in the modbus-library that I'm using: I will be upgrading to the latest pyModbus version from the moment https://github.com/riptideio/pymodbus/issues/1146 has been resolved. However, I can't give any guarantees that this will fix the problem.
i don't want to say too loud, but it's seems the problem has been fixed with your update ! i'll test it for another week from now so we can confirm that's been resolved.
I don't see wrong values from 2 weeks. So I can say that the issue is resolved. Thank you so much @wlcrs for your great job!