search

kellerza / sunsynk

Deye/Sunsynk Inverter Python library and Home Assistant OS Addon
https://kellerza.github.io/sunsynk/
MIT License
229 stars 95 forks source link

Timeouts when using usr-tcp232-410s, but not when using USB #139

Closed zit501 closed 9 months ago

zit501 commented 1 year ago

Issue related to

Sunsynk Home Assistant Add-On

Describe the issue/bug

I had the addon running 100% using a USB RS485 adapter (this one) via mbusd.

I decided to switch to a usr-tcp232-410s as it will be better for my cabling setup. After setting it up as per the settings for the HF5142B, and setting the READ_SENSORS_BATCH_SIZE to 8, it works well and seemingly without issue. However, I can see on the activity lights on the USR that it's reading fine every second or so for about 20 seconds, then the activity stops, the following error is posted in the log, then a few seconds later the activity starts again and so on.

Looking at the data on the HA dashboard, one won't notice this unless you're looking for the sensor data being updated. During the period of timeout during the error below there are obviously no updates to the sensor data in MQTT.

But otherwise this connection link is working fine.

I've tried turning flow control on and off. Tried various other settings on the USR. Tried decreasing and increasing the READ_SENSORS_BATCH_SIZE. I'm using using umodbus. Tried pymodbus and it doesn't work at all really.

Expected behavior I expect it to keep updating without timing out every 30 seconds or so.

Your environment

Logs

[s6-init] making user provided files available at /var/run/s6/etc...exited 0.
[s6-init] ensuring user provided files have correct perms...exited 0.
[fix-attrs.d] applying ownership & permissions fixes...
[fix-attrs.d] done.
[cont-init.d] executing container initialization scripts...
[cont-init.d] done.
[services.d] starting services
[services.d] done.
2023-05-17 14:31:24,228 INFO    options Loading HASS OS configuration
2023-05-17 14:31:24,253 INFO    Using Single phase sensor definitions.
2023-05-17 14:31:24,256 INFO    Connecting to tcp://192.168.88.14:26
2023-05-17 14:31:24,263 INFO    Reading startup sensors rated_power, serial
2023-05-17 14:31:24,384 INFO    ############################################################
2023-05-17 14:31:24,384 INFO                Inverter serial number '2301069881'
2023-05-17 14:31:24,386 INFO    ############################################################
2023-05-17 14:31:24,397 INFO    MQTT: Connecting to sunsynkmqtt@core-mosquitto:1883
2023-05-17 14:31:24,430 INFO    MQTT: Connection successful
2023-05-17 14:32:02,466 ERROR   Read Error: <class 'Exception'>: (1,175,1) readexactly call timeout on '192.168.88.14:26'
2023-05-17 14:32:18,833 ERROR   Read Error: <class 'Exception'>: (1,190,1) readexactly call timeout on '192.168.88.14:26'
2023-05-17 14:32:42,954 ERROR   Read Error: <class 'Exception'>: (1,166,2) readexactly call timeout on '192.168.88.14:26'
2023-05-17 14:32:52,991 ERROR   Read Error: <class 'Exception'>: (1,79,1) readexactly call timeout on '192.168.88.14:26'
2023-05-17 14:33:34,335 ERROR   Read Error: <class 'Exception'>: (1,175,1) readexactly call timeout on '192.168.88.14:26'
2023-05-17 14:34:02,417 ERROR   Read Error: <class 'Exception'>: (1,79,1) readexactly call timeout on '192.168.88.14:26'
2023-05-17 14:34:22,581 ERROR   Read Error: <class 'Exception'>: (1,169,1) readexactly call timeout on '192.168.88.14:26'
2023-05-17 14:34:33,718 ERROR   Read Error: <class 'Exception'>: (1,169,1) readexactly call timeout on '192.168.88.14:26'
2023-05-17 14:34:52,151 ERROR   Read Error: <class 'Exception'>: (1,193,1) readexactly call timeout on '192.168.88.14:26'
2023-05-17 14:35:31,623 ERROR   Read Error: <class 'Exception'>: (1,193,1) readexactly call timeout on '192.168.88.14:26'
kellerza commented 1 year ago

What does the USR logs show? It seems like it stops responding to the TCP requests for a while...

kellerza commented 1 year ago

btw, I've been using pymodbus toward mbusd for a couple of weeks now and seems just as stable as umodbus

zit501 commented 1 year ago

I've checked the USR web options, doesn't look like I can access a log. Not sure if there's an option on the config software for one.

I can't redirect the connection via mbusd can I? Am I mistaken that mbusd can't point to the TCP server on the USR?

kellerza commented 1 year ago

These smaller web gateways do not seem to be very reliable. The wave one was unable to issue writes (their support confirmed this)

you could try routing it via mbusd, but it will likely require a custom config file. If the upstream server disappears I’m not sure it will help.

might help to contact the USR support team as well

zit501 commented 1 year ago

I'm running the Pace BMS addon for my Hubble AM-2's via the rs232 interface on the same USR, running without issue. I've also got a single rs232 USR interfacing my Russound multiroom audio controller with no issue. But I guess the data transfer on both of those is less demanding.

I'll see if I can ask the Pusr folks about logs. thanks!

zit501 commented 1 year ago

For interest, here's the log when I switch to pymodbus:

[s6-init] making user provided files available at /var/run/s6/etc...exited 0.
[s6-init] ensuring user provided files have correct perms...exited 0.
[fix-attrs.d] applying ownership & permissions fixes...
[fix-attrs.d] done.
[cont-init.d] executing container initialization scripts...
[cont-init.d] done.
[services.d] starting services
[services.d] done.
2023-05-18 08:07:49,063 INFO    options Loading HASS OS configuration
2023-05-18 08:07:49,182 INFO    Using Single phase sensor definitions.
2023-05-18 08:07:49,185 INFO    Connecting to tcp://192.168.88.14:26
2023-05-18 08:07:49,186 INFO    PyModbus 3.2.2 TCP: 192.168.88.14:26
2023-05-18 08:07:49,189 INFO    Protocol made connection.
2023-05-18 08:07:49,190 INFO    Connected to 192.168.88.14:26.
2023-05-18 08:07:49,190 INFO    Reading startup sensors rated_power, serial
2023-05-18 08:07:49,308 INFO    ############################################################
2023-05-18 08:07:49,308 INFO                Inverter serial number '2301069881'
2023-05-18 08:07:49,309 INFO    ############################################################
2023-05-18 08:07:49,323 INFO    MQTT: Connecting to sunsynkmqtt@core-mosquitto:1883
2023-05-18 08:07:49,362 INFO    MQTT: Connection successful
2023-05-18 08:07:54,361 INFO    Protocol lost connection.
2023-05-18 08:07:54,362 INFO    Protocol lost connection.
2023-05-18 08:07:54,362 WARNING Ignoring launch of delayed reconnection, another is in progress
2023-05-18 08:07:54,363 ERROR   timeout reading register 166 (2)
2023-05-18 08:07:54,368 INFO    Protocol made connection.
2023-05-18 08:07:54,369 INFO    Connected to 192.168.88.14:26.
2023-05-18 08:07:54,466 INFO    Protocol made connection.
2023-05-18 08:07:54,467 ERROR   Factory protocol connect callback called while connected.
2023-05-18 08:07:54,468 INFO    Connected to 192.168.88.14:26.
2023-05-18 08:07:57,423 INFO    Protocol lost connection.
2023-05-18 08:07:57,424 INFO    Protocol lost connection.
2023-05-18 08:07:57,424 WARNING Ignoring launch of delayed reconnection, another is in progress
2023-05-18 08:07:57,425 ERROR   timeout reading register 166 (2)
2023-05-18 08:07:57,428 INFO    Protocol made connection.
2023-05-18 08:07:57,429 INFO    Connected to 192.168.88.14:26.
2023-05-18 08:07:57,528 INFO    Protocol made connection.
2023-05-18 08:07:57,528 ERROR   Factory protocol connect callback called while connected.
2023-05-18 08:07:57,529 INFO    Connected to 192.168.88.14:26.
2023-05-18 08:08:00,487 INFO    Protocol lost connection.
kellerza commented 1 year ago

So pymodbus is a bit more verbose, but you can see the connection to the USR seems to disappear for some reason - you also saw this with umodbus

zit501 commented 1 year ago

Yes, although with pymodbus it doesn't populate any data at all. With umodbus it works fine for a minute, then times out, reconnects, and repeats.

kellerza commented 1 year ago

Have a look at #96 - is your unit similar?

zit501 commented 1 year ago

It is the same unit. I've asked if they're experiencing the same timeouts in their log and isn't aware of it. Like I was before looking at the logs.

kellerza commented 1 year ago

I've asked if they're experiencing the same timeouts in their log and isn't aware of it.

Hopefully they can help out, as I don't have access to any of this to help any further. Have you tried swapping units (you mentioned you had a couple of them?)

Btw, it seems you can read the AM2 data vie RS485 as well... Maybe using both RS232&RS485 is a bit much for the USR?

Maybe also contact the USR guys for help?

zit501 commented 1 year ago

Thanks for your help though, I appreciate it. I'll wait to hear from the other guys. I only have another rs232 one, not 485. I've tried unplugging the AM-2 from the 232 port, no change. But the pace BMS addon only reads the BMS data every 30 seconds, and it's very quick, so I don't think it's particularly resource intensive.

I've also logged a support ticket with Pusr. I'll let you know if I learn anything more.

jacekowski commented 1 year ago

I've been using USR-TCP232-304 and it has been rock solid for me, 410s seems to be very similar so i would expect similar levels of reliability.

How is yours configured?

zit501 commented 1 year ago

I've been using USR-TCP232-304 and it has been rock solid for me, 410s seems to be very similar so i would expect similar levels of reliability.

How is yours configured?

Interesting. So no Read Errors in the log at all?

Here's my config of the 410s:

image

jacekowski commented 1 year ago

The one i'm using is a dumb ethernet to serial converter, it can't convert modbus tcp to modbus rtu like yours (so i'm using serial-tcp:// instead of just tcp:// ) and i'm using umodbus driver. Try doing the same (change your work mode to just be a tcp server)

image image

zit501 commented 1 year ago

The one i'm using is a dumb ethernet to serial converter, it can't convert modbus tcp to modbus rtu like yours (so i'm using serial-tcp:// instead of just tcp:// ) and i'm using umodbus driver. Try doing the same (change your work mode to just be a tcp server)

image image

Thanks for the tip. I've configured as you say, and it first seemed to be erroring less. But I think it's actually much the same. I think I might try change my network topology to see if that has any effect (there's currently two switches in the chain).

" [s6-init] making user provided files available at /var/run/s6/etc...exited 0. [s6-init] ensuring user provided files have correct perms...exited 0. [fix-attrs.d] applying ownership & permissions fixes... [fix-attrs.d] done. [cont-init.d] executing container initialization scripts... [cont-init.d] done. [services.d] starting services [services.d] done. 2023-06-03 09:56:19,223 INFO options Loading HASS OS configuration 2023-06-03 09:56:19,247 INFO Using Single phase sensor definitions. 2023-06-03 09:56:19,251 INFO Connecting to serial-tcp://192.168.88.14:26 2023-06-03 09:56:19,271 INFO Reading startup sensors rated_power, serial 2023-06-03 09:56:19,392 INFO ############################################################ 2023-06-03 09:56:19,393 INFO Inverter serial number '2301069881' 2023-06-03 09:56:19,393 INFO ############################################################ 2023-06-03 09:56:19,405 INFO MQTT: Connecting to sunsynkmqtt@core-mosquitto:1883 2023-06-03 09:56:19,440 INFO MQTT: Connection successful 2023-06-03 09:56:58,439 ERROR Read Error: <class 'Exception'>: (1,172,1) read call timeout on '192.168.88.14:26' 2023-06-03 09:57:12,472 ERROR Read Error: <class 'Exception'>: (1,79,1) read call timeout on '192.168.88.14:26' 2023-06-03 09:57:22,679 ERROR Read Error: <class 'Exception'>: (1,172,1) read call timeout on '192.168.88.14:26' 2023-06-03 09:58:12,147 ERROR Read Error: <class 'Exception'>: (1,190,1) read call timeout on '192.168.88.14:26' 2023-06-03 09:59:01,583 ERROR Read Error: <class 'Exception'>: (1,190,1) read call timeout on '192.168.88.14:26' 2023-06-03 09:59:46,916 ERROR Read Error: <class 'Exception'>: (1,172,1) unpack requires a buffer of 1 bytes 2023-06-03 09:59:47,718 ERROR Read Error: <class 'Exception'>: (1,79,1) 0 2023-06-03 09:59:58,731 ERROR Read Error: <class 'Exception'>: (1,166,2) read call timeout on '192.168.88.14:26' 2023-06-03 10:01:00,991 ERROR Read Error: <class 'Exception'>: (1,166,2) read call timeout on '192.168.88.14:26' 2023-06-03 10:01:20,366 ERROR Read Error: <class 'Exception'>: (1,190,1) read call timeout on '192.168.88.14:26' 2023-06-03 10:01:30,671 ERROR Read Error: <class 'Exception'>: (1,186,2) read call timeout on '192.168.88.14:26'"

snaven1 commented 1 year ago

Similar to Zit501, I have essentially the same problem without resolution. I however, have done a lot of experimentation with three different interfaces. I have a 3 phase 8K SunSynk inverter.

Interface 1: Direct serial cable from Synsynk Inverter to RS485-USB adapter direct into laptop. Used Windows based software QModmaster to interrogate the inverter. This worked flawlessly, returned correct data without issue and was completely repeatable. Due to cable considerations, I can not use this method to integrate with home assistant.

Interface 2: Serial cable from inverter to a Serial to TCP unit that handles modbus conversions "pusr usr-w610" This unit integrates into my home network over tcp. Using QModmaster software to interrogate the interface, I have partial success. On some interrogations get data coming back, on other interrogations I get timeout errors. See Below.

Capture1

Capture2

When using the Kellerza Integration for home assistant, using either umodbus or pymodbus both fail with timeout errors. The software connects to the USR-W610 unit, from this point forward it is all down hill with timeout errors. See error output below using the umodbus interface. I get no data from this interfacing due to constant timeout errors.

Error Log (umodbus interface) s6-rc: info: service s6rc-oneshot-runner: starting s6-rc: info: service s6rc-oneshot-runner successfully started s6-rc: info: service fix-attrs: starting s6-rc: info: service fix-attrs successfully started s6-rc: info: service legacy-cont-init: starting s6-rc: info: service legacy-cont-init successfully started s6-rc: info: service legacy-services: starting services-up: info: copying legacy longrun sunsynk (no readiness notification) s6-rc: info: service legacy-services successfully started 03:51:21 INFO Loading configuration: /data/options.json 03:51:21 INFO sunsynk library version: 0.6.4 03:51:22 INFO Schedules: +-----------+-----+------+--------+-----------+----------+------------+ | Key | src | Read | Report | Change by | Change % | Change any | +-----------+-----+------+--------+-----------+----------+------------+ | date_time | | 60 | 60 | | | True | | rw | | 5 | 300 | | | True | | w | * | 5 | 60 | 80 | | | | kwh | | 300 | 300 | | | | | any_unit | | 15 | 300 | | | | | no_unit | | 15 | 300 | | | True | +-----------+-----+------+--------+-----------+----------+------------+ 03:51:22 INFO Using three phase sensor definitions. 03:51:22 ERROR Unknown sensor specified: aux_power 03:51:22 ERROR Unknown sensor specified: essential_power 03:51:22 ERROR Unknown sensor specified: grid_connected 03:51:22 ERROR Unknown sensor specified: inverter_current 03:51:22 ERROR Unknown sensor specified: load_frequency 03:51:22 ERROR Unknown sensor specified: non_essential_power 03:51:22 INFO Added hidden sensors as other sensors depend on it: Rated power, Serial 03:51:22 INFO Connecting to tcp://192.168.100.123:502 03:51:22 INFO Reading startup sensors Prog4 Time, Prog3 Time, Serial, Rated power, Prog5 Time, Prog2 Time, Prog6 Time, Battery Low Capacity, Prog1 Time 03:52:13 ERROR ConnectionTimeoutError reading 1 registers from 5: readexactly call timeout on '192.168.100.123:502'; error reading 1 registers from 7: unpack requires a buffer of 3 bytes; ConnectionTimeoutError reading 1 registers from 20: readexactly call timeout on '192.168.100.123:502'; ConnectionTimeoutError reading 1 registers from 117: readexactly call timeout on '192.168.100.123:502'; ConnectionTimeoutError reading 1 registers from 148: readexactly call timeout on '192.168.100.123:502'; KeyError reading 1 registers from 150: 175; KeyError reading 1 registers from 151: 0; ConnectionTimeoutError reading 1 registers from 152: readexactly call timeout on '192.168.100.123:502' 03:53:04 ERROR KeyError reading 1 registers from 3: 196; KeyError reading 1 registers from 4: 50; ConnectionTimeoutError reading 1 registers from 5: readexactly call timeout on '192.168.100.123:502'; error reading 1 registers from 7: unpack requires a buffer of 3 bytes; ConnectionTimeoutError reading 1 registers from 20: readexactly call timeout on '192.168.100.123:502'; ConnectionTimeoutError reading 1 registers from 117: readexactly call timeout on '192.168.100.123:502'; ConnectionTimeoutError reading 1 registers from 149: readexactly call timeout on '192.168.100.123:502'; error reading 1 registers from 151: unpack requires a buffer of 3 bytes; ConnectionTimeoutError reading 1 registers from 152: readexactly call timeout on '192.168.100.123:502'

Error Log (pymodbus interface)

s6-rc: info: service s6rc-oneshot-runner: starting s6-rc: info: service s6rc-oneshot-runner successfully started s6-rc: info: service fix-attrs: starting s6-rc: info: service fix-attrs successfully started s6-rc: info: service legacy-cont-init: starting s6-rc: info: service legacy-cont-init successfully started s6-rc: info: service legacy-services: starting services-up: info: copying legacy longrun sunsynk (no readiness notification) s6-rc: info: service legacy-services successfully started 05:01:00 INFO Loading configuration: /data/options.json 05:01:00 INFO sunsynk library version: 0.6.4 05:01:00 INFO Schedules: +-----------+-----+------+--------+-----------+----------+------------+ | Key | src | Read | Report | Change by | Change % | Change any | +-----------+-----+------+--------+-----------+----------+------------+ | date_time | | 60 | 60 | | | True | | rw | | 5 | 300 | | | True | | w | * | 5 | 60 | 80 | | | | kwh | | 300 | 300 | | | | | any_unit | | 15 | 300 | | | | | no_unit | | 15 | 300 | | | True | +-----------+-----+------+--------+-----------+----------+------------+ 05:01:00 INFO Using three phase sensor definitions. 05:01:00 ERROR Unknown sensor specified: aux_power 05:01:00 ERROR Unknown sensor specified: essential_power 05:01:00 ERROR Unknown sensor specified: grid_connected 05:01:00 ERROR Unknown sensor specified: inverter_current 05:01:00 ERROR Unknown sensor specified: load_frequency 05:01:00 ERROR Unknown sensor specified: non_essential_power 05:01:00 INFO Added hidden sensors as other sensors depend on it: Rated power, Serial 05:01:00 INFO Connecting to tcp://192.168.100.123:502 05:01:00 INFO PyModbus 3.4.1 tcp: 192.168.100.123:502 05:01:00 INFO Reading startup sensors Serial, Prog5 Time, Prog6 Time, Battery Low Capacity, Prog2 Time, Prog3 Time, Rated power, Prog1 Time, Prog4 Time 05:01:10 ERROR Unable to decode response Modbus Error: Unknown response 10 05:01:10 ERROR Fatal error: protocol.data_received() call failed. protocol: <pymodbus.client.tcp.AsyncModbusTcpClient object at 0x7ff85ba19410> transport: <_SelectorSocketTransport fd=8 read=polling write=<idle, bufsize=0>> Traceback (most recent call last): File "/usr/local/lib/python3.11/asyncio/selector_events.py", line 1009, in _read_readydata_received self._protocol.data_received(data) File "/usr/local/lib/python3.11/site-packages/pymodbus/transport/transport.py", line 289, in data_received self.datagram_received(data, None) File "/usr/local/lib/python3.11/site-packages/pymodbus/transport/transport.py", line 303, in datagram_received cut = self.callback_data(self.recv_buffer, addr=addr) ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ File "/usr/local/lib/python3.11/site-packages/pymodbus/client/base.py", line 219, in callback_data self.framer.processIncomingPacket(data, self._handle_response, slave=0) File "/usr/local/lib/python3.11/site-packages/pymodbus/framer/base.py", line 137, in processIncomingPacket self.frameProcessIncomingPacket(single, callback, slave, **kwargs) File "/usr/local/lib/python3.11/site-packages/pymodbus/framer/socket_framer.py", line 147, in frameProcessIncomingPacket self._process(callback, tid) File "/usr/local/lib/python3.11/site-packages/pymodbus/framer/socket_framer.py", line 154, in _process raise ModbusIOException("Unable to decode request") pymodbus.exceptions.ModbusIOException: Modbus Error: [Input/Output] Unable to decode request 05:01:10 ERROR Unable to decode response Modbus Error: Unknown response 10 05:01:10 ERROR Fatal error: protocol.data_received() call failed. protocol: <pymodbus.client.tcp.AsyncModbusTcpClient object at 0x7ff85ba19410> transport: <_SelectorSocketTransport fd=9 read=polling write=<idle, bufsize=0>> Traceback (most recent call last): File "/usr/local/lib/python3.11/asyncio/selector_events.py", line 1009, in _read_readydata_received self._protocol.data_received(data) File "/usr/local/lib/python3.11/site-packages/pymodbus/transport/transport.py", line 289, in data_received self.datagram_received(data, None) File "/usr/local/lib/python3.11/site-packages/pymodbus/transport/transport.py", line 303, in datagram_received cut = self.callback_data(self.recv_buffer, addr=addr) ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ File "/usr/local/lib/python3.11/site-packages/pymodbus/client/base.py", line 219, in callback_data self.framer.processIncomingPacket(data, self._handle_response, slave=0) File "/usr/local/lib/python3.11/site-packages/pymodbus/framer/base.py", line 137, in processIncomingPacket self.frameProcessIncomingPacket(single, callback, slave, kwargs) File "/usr/local/lib/python3.11/site-packages/pymodbus/framer/socket_framer.py", line 147, in frameProcessIncomingPacket self._process(callback, tid) File "/usr/local/lib/python3.11/site-packages/pymodbus/framer/socket_framer.py", line 154, in _process raise ModbusIOException("Unable to decode request") pymodbus.exceptions.ModbusIOException: Modbus Error: [Input/Output] Unable to decode request 05:01:10 ERROR ConnectionException reading 1 registers from 152: Modbus Error: [Connection] Connection lost during request Prog5 Time 05:01:10 ERROR General exception: unpack requires a buffer of 4 bytes 05:01:10 ERROR Fatal error: protocol.data_received() call failed. protocol: <pymodbus.client.tcp.AsyncModbusTcpClient object at 0x7ff85ba19410> transport: <_SelectorSocketTransport fd=8 read=polling write=<idle, bufsize=0>> Traceback (most recent call last): File "/usr/local/lib/python3.11/asyncio/selector_events.py", line 1009, in _read_ready__data_received self._protocol.data_received(data) File "/usr/local/lib/python3.11/site-packages/pymodbus/transport/transport.py", line 289, in data_received self.datagram_received(data, None) File "/usr/local/lib/python3.11/site-packages/pymodbus/transport/transport.py", line 303, in datagram_received cut = self.callback_data(self.recv_buffer, addr=addr) ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ File "/usr/local/lib/python3.11/site-packages/pymodbus/client/base.py", line 219, in callback_data self.framer.processIncomingPacket(data, self._handle_response, slave=0) File "/usr/local/lib/python3.11/site-packages/pymodbus/framer/base.py", line 137, in processIncomingPacket self.frameProcessIncomingPacket(single, callback, slave, kwargs) File "/usr/local/lib/python3.11/site-packages/pymodbus/framer/socket_framer.py", line 147, in frameProcessIncomingPacket self._process(callback, tid) File "/usr/local/lib/python3.11/site-packages/pymodbus/framer/socket_framer.py", line 154, in _process raise ModbusIOException("Unable to decode request") pymodbus.exceptions.ModbusIOException: Modbus Error: [Input/Output] Unable to decode request 05:01:10 ERROR ConnectionException reading 1 registers from 152: Modbus Error: [Connection] Connection lost during request Prog5 Time 05:01:13 ERROR Timeout Prog6 Time 05:01:16 ERROR Timeout Battery Low Capacity 05:01:20 ERROR Timeout Prog2 Time 05:01:23 ERROR Timeout Prog3 Time 05:01:26 ERROR Timeout Rated power 05:01:26 ERROR General exception: index out of range 05:01:26 ERROR Fatal error: protocol.data_received() call failed. protocol: <pymodbus.client.tcp.AsyncModbusTcpClient object at 0x7ff85ba19410> transport: <_SelectorSocketTransport fd=8 read=polling write=<idle, bufsize=0>> Traceback (most recent call last): File "/usr/local/lib/python3.11/asyncio/selector_events.py", line 1009, in _read_ready__data_received self._protocol.data_received(data) File "/usr/local/lib/python3.11/site-packages/pymodbus/transport/transport.py", line 289, in data_received self.datagram_received(data, None) File "/usr/local/lib/python3.11/site-packages/pymodbus/transport/transport.py", line 303, in datagram_received cut = self.callback_data(self.recv_buffer, addr=addr) ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ File "/usr/local/lib/python3.11/site-packages/pymodbus/client/base.py", line 219, in callback_data self.framer.processIncomingPacket(data, self._handle_response, slave=0) File "/usr/local/lib/python3.11/site-packages/pymodbus/framer/base.py", line 137, in processIncomingPacket self.frameProcessIncomingPacket(single, callback, slave, **kwargs) File "/usr/local/lib/python3.11/site-packages/pymodbus/framer/socket_framer.py", line 147, in frameProcessIncomingPacket self._process(callback, tid) File "/usr/local/lib/python3.11/site-packages/pymodbus/framer/socket_framer.py", line 154, in _process raise ModbusIOException("Unable to decode request") pymodbus.exceptions.ModbusIOException: Modbus Error: [Input/Output] Unable to decode request 05:01:26 ERROR ConnectionException reading 1 registers from 148: Modbus Error: [Connection] Connection lost during request Prog1 Time 05:01:29 ERROR Timeout Prog1 Time 05:01:33 ERROR Timeout Prog1 Time 05:01:33 CRITICAL Could not read sensors: ['Prog1 Time'] 05:01:33 INFO ############################################################ 05:01:33 INFO No response on the Modbus interface tcp://192.168.100.123:502, see https://kellerza.github.io/sunsynk/guide/fault-finding 05:01:33 INFO ############################################################ 05:01:33 CRITICAL This Add-On will terminate in 30 seconds, use the Supervisor Watchdog to restart automatically.

Interface 3: Serial cable from inverter to a Serial to TCP unit that handles modbus conversions "High Flying HF5111A" This is essentially the same unit as mentioned in the installation notes per the Kellerza Integration. This unit integrates into my home network over tcp. Using QModmaster software to interrogate the interface, I had total failure, with no ability to extract any data from the inverter. Given this situation, running the Kellerza Integration was just a complete waste of time.

Point of interest: I am using the same serial cat 5 cable from inverter to all 3 devices, noting that interface 1 returned zero errors and worked well. Given this, it dismisses the cable as being an issue. The PUSR device has a lot of settings which obviously I have played with, with no success. The High Flying Device has very little settings, and simply just did not work at all. Both devices do not have any display logs, though I believe that both devices have cmdline options to log into these boxes. This I have not investigated yet.

Any suggestions would be greatly appreciated!

zit501 commented 1 year ago

Similar to Zit501, I have essentially the same problem without resolution. I however, have done a lot of experimentation with three different interfaces. I have a 3 phase 8K SunSynk inverter.

Interface 1: Direct serial cable from Synsynk Inverter to RS485-USB adapter direct into laptop. Used Windows based software QModmaster to interrogate the inverter. This worked flawlessly, returned correct data without issue and was completely repeatable. Due to cable considerations, I can not use this method to integrate with home assistant.

Interface 2: Serial cable from inverter to a Serial to TCP unit that handles modbus conversions "pusr usr-w610" This unit integrates into my home network over tcp. Using QModmaster software to interrogate the interface, I have partial success. On some interrogations get data coming back, on other interrogations I get timeout errors. See Below.

Capture1

Capture2

When using the Kellerza Integration for home assistant, using either umodbus or pymodbus both fail with timeout errors. The software connects to the USR-W610 unit, from this point forward it is all down hill with timeout errors. See error output below using the umodbus interface. I get no data from this interfacing due to constant timeout errors.

Error Log (umodbus interface) s6-rc: info: service s6rc-oneshot-runner: starting s6-rc: info: service s6rc-oneshot-runner successfully started s6-rc: info: service fix-attrs: starting s6-rc: info: service fix-attrs successfully started s6-rc: info: service legacy-cont-init: starting s6-rc: info: service legacy-cont-init successfully started s6-rc: info: service legacy-services: starting services-up: info: copying legacy longrun sunsynk (no readiness notification) s6-rc: info: service legacy-services successfully started 03:51:21 INFO Loading configuration: /data/options.json 03:51:21 INFO sunsynk library version: 0.6.4 03:51:22 INFO Schedules: +-----------+-----+------+--------+-----------+----------+------------+ | Key | src | Read | Report | Change by | Change % | Change any | +-----------+-----+------+--------+-----------+----------+------------+ | date_time | | 60 | 60 | | | True | | rw | | 5 | 300 | | | True | | w | * | 5 | 60 | 80 | | | | kwh | | 300 | 300 | | | | | any_unit | | 15 | 300 | | | | | no_unit | | 15 | 300 | | | True | +-----------+-----+------+--------+-----------+----------+------------+ 03:51:22 INFO Using three phase sensor definitions. 03:51:22 ERROR Unknown sensor specified: aux_power 03:51:22 ERROR Unknown sensor specified: essential_power 03:51:22 ERROR Unknown sensor specified: grid_connected 03:51:22 ERROR Unknown sensor specified: inverter_current 03:51:22 ERROR Unknown sensor specified: load_frequency 03:51:22 ERROR Unknown sensor specified: non_essential_power 03:51:22 INFO Added hidden sensors as other sensors depend on it: Rated power, Serial 03:51:22 INFO Connecting to tcp://192.168.100.123:502 03:51:22 INFO Reading startup sensors Prog4 Time, Prog3 Time, Serial, Rated power, Prog5 Time, Prog2 Time, Prog6 Time, Battery Low Capacity, Prog1 Time 03:52:13 ERROR ConnectionTimeoutError reading 1 registers from 5: readexactly call timeout on '192.168.100.123:502'; error reading 1 registers from 7: unpack requires a buffer of 3 bytes; ConnectionTimeoutError reading 1 registers from 20: readexactly call timeout on '192.168.100.123:502'; ConnectionTimeoutError reading 1 registers from 117: readexactly call timeout on '192.168.100.123:502'; ConnectionTimeoutError reading 1 registers from 148: readexactly call timeout on '192.168.100.123:502'; KeyError reading 1 registers from 150: 175; KeyError reading 1 registers from 151: 0; ConnectionTimeoutError reading 1 registers from 152: readexactly call timeout on '192.168.100.123:502' 03:53:04 ERROR KeyError reading 1 registers from 3: 196; KeyError reading 1 registers from 4: 50; ConnectionTimeoutError reading 1 registers from 5: readexactly call timeout on '192.168.100.123:502'; error reading 1 registers from 7: unpack requires a buffer of 3 bytes; ConnectionTimeoutError reading 1 registers from 20: readexactly call timeout on '192.168.100.123:502'; ConnectionTimeoutError reading 1 registers from 117: readexactly call timeout on '192.168.100.123:502'; ConnectionTimeoutError reading 1 registers from 149: readexactly call timeout on '192.168.100.123:502'; error reading 1 registers from 151: unpack requires a buffer of 3 bytes; ConnectionTimeoutError reading 1 registers from 152: readexactly call timeout on '192.168.100.123:502'

Error Log (pymodbus interface)

s6-rc: info: service s6rc-oneshot-runner: starting s6-rc: info: service s6rc-oneshot-runner successfully started s6-rc: info: service fix-attrs: starting s6-rc: info: service fix-attrs successfully started s6-rc: info: service legacy-cont-init: starting s6-rc: info: service legacy-cont-init successfully started s6-rc: info: service legacy-services: starting services-up: info: copying legacy longrun sunsynk (no readiness notification) s6-rc: info: service legacy-services successfully started 05:01:00 INFO Loading configuration: /data/options.json 05:01:00 INFO sunsynk library version: 0.6.4 05:01:00 INFO Schedules: +-----------+-----+------+--------+-----------+----------+------------+ | Key | src | Read | Report | Change by | Change % | Change any | +-----------+-----+------+--------+-----------+----------+------------+ | date_time | | 60 | 60 | | | True | | rw | | 5 | 300 | | | True | | w | * | 5 | 60 | 80 | | | | kwh | | 300 | 300 | | | | | any_unit | | 15 | 300 | | | | | no_unit | | 15 | 300 | | | True | +-----------+-----+------+--------+-----------+----------+------------+ 05:01:00 INFO Using three phase sensor definitions. 05:01:00 ERROR Unknown sensor specified: aux_power 05:01:00 ERROR Unknown sensor specified: essential_power 05:01:00 ERROR Unknown sensor specified: grid_connected 05:01:00 ERROR Unknown sensor specified: inverter_current 05:01:00 ERROR Unknown sensor specified: load_frequency 05:01:00 ERROR Unknown sensor specified: non_essential_power 05:01:00 INFO Added hidden sensors as other sensors depend on it: Rated power, Serial 05:01:00 INFO Connecting to tcp://192.168.100.123:502 05:01:00 INFO PyModbus 3.4.1 tcp: 192.168.100.123:502 05:01:00 INFO Reading startup sensors Serial, Prog5 Time, Prog6 Time, Battery Low Capacity, Prog2 Time, Prog3 Time, Rated power, Prog1 Time, Prog4 Time 05:01:10 ERROR Unable to decode response Modbus Error: Unknown response 10 05:01:10 ERROR Fatal error: protocol.data_received() call failed. protocol: <pymodbus.client.tcp.AsyncModbusTcpClient object at 0x7ff85ba19410> transport: <_SelectorSocketTransport fd=8 read=polling write=<idle, bufsize=0>> Traceback (most recent call last): File "/usr/local/lib/python3.11/asyncio/selector_events.py", line 1009, in _read_readydata_received self._protocol.data_received(data) File "/usr/local/lib/python3.11/site-packages/pymodbus/transport/transport.py", line 289, in data_received self.datagram_received(data, None) File "/usr/local/lib/python3.11/site-packages/pymodbus/transport/transport.py", line 303, in datagram_received cut = self.callback_data(self.recv_buffer, addr=addr) ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ File "/usr/local/lib/python3.11/site-packages/pymodbus/client/base.py", line 219, in callback_data self.framer.processIncomingPacket(data, self._handle_response, slave=0) File "/usr/local/lib/python3.11/site-packages/pymodbus/framer/base.py", line 137, in processIncomingPacket self.frameProcessIncomingPacket(single, callback, slave, **kwargs) File "/usr/local/lib/python3.11/site-packages/pymodbus/framer/socket_framer.py", line 147, in frameProcessIncomingPacket self._process(callback, tid) File "/usr/local/lib/python3.11/site-packages/pymodbus/framer/socket_framer.py", line 154, in _process raise ModbusIOException("Unable to decode request") pymodbus.exceptions.ModbusIOException: Modbus Error: [Input/Output] Unable to decode request 05:01:10 ERROR Unable to decode response Modbus Error: Unknown response 10 05:01:10 ERROR Fatal error: protocol.data_received() call failed. protocol: <pymodbus.client.tcp.AsyncModbusTcpClient object at 0x7ff85ba19410> transport: <_SelectorSocketTransport fd=9 read=polling write=<idle, bufsize=0>> Traceback (most recent call last): File "/usr/local/lib/python3.11/asyncio/selector_events.py", line 1009, in _read_readydata_received self._protocol.data_received(data) File "/usr/local/lib/python3.11/site-packages/pymodbus/transport/transport.py", line 289, in data_received self.datagram_received(data, None) File "/usr/local/lib/python3.11/site-packages/pymodbus/transport/transport.py", line 303, in datagram_received cut = self.callback_data(self.recv_buffer, addr=addr) ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ File "/usr/local/lib/python3.11/site-packages/pymodbus/client/base.py", line 219, in callback_data self.framer.processIncomingPacket(data, self._handle_response, slave=0) File "/usr/local/lib/python3.11/site-packages/pymodbus/framer/base.py", line 137, in processIncomingPacket self.frameProcessIncomingPacket(single, callback, slave, kwargs) File "/usr/local/lib/python3.11/site-packages/pymodbus/framer/socket_framer.py", line 147, in frameProcessIncomingPacket self._process(callback, tid) File "/usr/local/lib/python3.11/site-packages/pymodbus/framer/socket_framer.py", line 154, in _process raise ModbusIOException("Unable to decode request") pymodbus.exceptions.ModbusIOException: Modbus Error: [Input/Output] Unable to decode request 05:01:10 ERROR ConnectionException reading 1 registers from 152: Modbus Error: [Connection] Connection lost during request Prog5 Time 05:01:10 ERROR General exception: unpack requires a buffer of 4 bytes 05:01:10 ERROR Fatal error: protocol.data_received() call failed. protocol: <pymodbus.client.tcp.AsyncModbusTcpClient object at 0x7ff85ba19410> transport: <_SelectorSocketTransport fd=8 read=polling write=<idle, bufsize=0>> Traceback (most recent call last): File "/usr/local/lib/python3.11/asyncio/selector_events.py", line 1009, in _read_ready__data_received self._protocol.data_received(data) File "/usr/local/lib/python3.11/site-packages/pymodbus/transport/transport.py", line 289, in data_received self.datagram_received(data, None) File "/usr/local/lib/python3.11/site-packages/pymodbus/transport/transport.py", line 303, in datagram_received cut = self.callback_data(self.recv_buffer, addr=addr) ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ File "/usr/local/lib/python3.11/site-packages/pymodbus/client/base.py", line 219, in callback_data self.framer.processIncomingPacket(data, self._handle_response, slave=0) File "/usr/local/lib/python3.11/site-packages/pymodbus/framer/base.py", line 137, in processIncomingPacket self.frameProcessIncomingPacket(single, callback, slave, kwargs) File "/usr/local/lib/python3.11/site-packages/pymodbus/framer/socket_framer.py", line 147, in frameProcessIncomingPacket self._process(callback, tid) File "/usr/local/lib/python3.11/site-packages/pymodbus/framer/socket_framer.py", line 154, in _process raise ModbusIOException("Unable to decode request") pymodbus.exceptions.ModbusIOException: Modbus Error: [Input/Output] Unable to decode request 05:01:10 ERROR ConnectionException reading 1 registers from 152: Modbus Error: [Connection] Connection lost during request Prog5 Time 05:01:13 ERROR Timeout Prog6 Time 05:01:16 ERROR Timeout Battery Low Capacity 05:01:20 ERROR Timeout Prog2 Time 05:01:23 ERROR Timeout Prog3 Time 05:01:26 ERROR Timeout Rated power 05:01:26 ERROR General exception: index out of range 05:01:26 ERROR Fatal error: protocol.data_received() call failed. protocol: <pymodbus.client.tcp.AsyncModbusTcpClient object at 0x7ff85ba19410> transport: <_SelectorSocketTransport fd=8 read=polling write=<idle, bufsize=0>> Traceback (most recent call last): File "/usr/local/lib/python3.11/asyncio/selector_events.py", line 1009, in _read_ready__data_received self._protocol.data_received(data) File "/usr/local/lib/python3.11/site-packages/pymodbus/transport/transport.py", line 289, in data_received self.datagram_received(data, None) File "/usr/local/lib/python3.11/site-packages/pymodbus/transport/transport.py", line 303, in datagram_received cut = self.callback_data(self.recv_buffer, addr=addr) ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ File "/usr/local/lib/python3.11/site-packages/pymodbus/client/base.py", line 219, in callback_data self.framer.processIncomingPacket(data, self._handle_response, slave=0) File "/usr/local/lib/python3.11/site-packages/pymodbus/framer/base.py", line 137, in processIncomingPacket self.frameProcessIncomingPacket(single, callback, slave, **kwargs) File "/usr/local/lib/python3.11/site-packages/pymodbus/framer/socket_framer.py", line 147, in frameProcessIncomingPacket self._process(callback, tid) File "/usr/local/lib/python3.11/site-packages/pymodbus/framer/socket_framer.py", line 154, in _process raise ModbusIOException("Unable to decode request") pymodbus.exceptions.ModbusIOException: Modbus Error: [Input/Output] Unable to decode request 05:01:26 ERROR ConnectionException reading 1 registers from 148: Modbus Error: [Connection] Connection lost during request Prog1 Time 05:01:29 ERROR Timeout Prog1 Time 05:01:33 ERROR Timeout Prog1 Time 05:01:33 CRITICAL Could not read sensors: ['Prog1 Time'] 05:01:33 INFO ############################################################ 05:01:33 INFO No response on the Modbus interface tcp://192.168.100.123:502, see https://kellerza.github.io/sunsynk/guide/fault-finding 05:01:33 INFO ############################################################ 05:01:33 CRITICAL This Add-On will terminate in 30 seconds, use the Supervisor Watchdog to restart automatically.

Interface 3: Serial cable from inverter to a Serial to TCP unit that handles modbus conversions "High Flying HF5111A" This is essentially the same unit as mentioned in the installation notes per the Kellerza Integration. This unit integrates into my home network over tcp. Using QModmaster software to interrogate the interface, I had total failure, with no ability to extract any data from the inverter. Given this situation, running the Kellerza Integration was just a complete waste of time.

Point of interest: I am using the same serial cat 5 cable from inverter to all 3 devices, noting that interface 1 returned zero errors and worked well. Given this, it dismisses the cable as being an issue. The PUSR device has a lot of settings which obviously I have played with, with no success. The High Flying Device has very little settings, and simply just did not work at all. Both devices do not have any display logs, though I believe that both devices have cmdline options to log into these boxes. This I have not investigated yet.

Any suggestions would be greatly appreciated!

Hi @snaven1 ,

I'm no longer getting any issued since @kellerza revised the code with the scheduled reading of sensor batches, and at a similar time I noticed that the pymodbus driver was noted as being best for an RS485/TCP adapter (not sure if this was a similar time). I'm using pymodbus without any errors in the log like I used to have. And there seems to be no irregularity in the reading of sensors like there used to be. I used to have long 60 second odd gaps after the timeouts, but otherwise working fine. Now it's perfect, although I do want to increase the frequency of some of my sensors being read.

snaven1 commented 1 year ago

Hi Zit501, Thanks for the quick response. Unlike your case, using the Kellerza integration (latest version), I get connectivity, however I return no modbus data due to the constant timeouts. It is only through the windows software (QModmaster) that I get some sort of connectivity, with partial timeouts occurring. Additionally, I have attempted to use the direct modbus interface built into Home Assistant which uses the pymodbus interface. It also gives me constant timeout errors. Additionally, I note that you are using a High Flying product, but is RS232 based where what I am using is RS485 based. I will keep investigating!!! Thanks

snaven1 commented 1 year ago

Further Update, after constant attempts of changing all setting possible on the RS485/Tcp units, I have not improved my situation with partial timeout occurrences. I have moved successfully to a new solution that involves running ESP32 chip hooked to a RS485 interface chip and downloaded ESPHOME on home assistant. To that end, I am now obtaining all data from my 3 phase Sunsynk Inverter without issue. An additional advantage of this solution, is that the ESP32 chip allows for an internal website to be deployed which displays all coded parameters in a nicely formatted box. To that end, it is a bit like having a website deployed to your inverter which Sunsynk/Deye does not deploy. I have provided a display of web output from the esp32 chip. The output has been chopped. Maybe this will give some help to those who are having the same timeout issues that I have experienced when using these RS485/TCP units.

Capture