bohdan-s / SunGather

GNU General Public License v3.0
149 stars 62 forks source link

index out of range & unable to decode request - But lot's of values are received successfully #106

Closed FrederikP closed 1 year ago

FrederikP commented 1 year ago

Hi I'm getting errors on every scan, and I'm wondering why.

My setup: SH10RT-V112, latest docker image (0.5.0), WiNet-S dongle - Wifi

connection: modbus -> port 502

Lot's of registers are actually successfully read and sent to mqtt. But I'm wondering why these errors come upon every scan.

sungather_1  | 2023-02-14 22:42:42 ERROR    Modbus Error: [Input/Output] Unable to decode request
sungather_1  | Traceback (most recent call last):
sungather_1  |   File "/usr/local/lib/python3.11/site-packages/pymodbus/transaction.py", line 208, in execute
sungather_1  |     self.client.framer.processIncomingPacket(response,
sungather_1  |   File "/usr/local/lib/python3.11/site-packages/pymodbus/framer/socket_framer.py", line 153, in processIncomingPacket
sungather_1  |     self._process(callback)
sungather_1  |   File "/usr/local/lib/python3.11/site-packages/pymodbus/framer/socket_framer.py", line 175, in _process
sungather_1  |     raise ModbusIOException("Unable to decode request")
sungather_1  | pymodbus.exceptions.ModbusIOException: Modbus Error: [Input/Output] Unable to decode request
sungather_1  | Modbus Error: [Input/Output] Unable to decode request
sungather_1  | Traceback (most recent call last):
sungather_1  |   File "/usr/local/lib/python3.11/site-packages/pymodbus/transaction.py", line 208, in execute
sungather_1  |     self.client.framer.processIncomingPacket(response,
sungather_1  |   File "/usr/local/lib/python3.11/site-packages/pymodbus/framer/socket_framer.py", line 153, in processIncomingPacket
sungather_1  |     self._process(callback)
sungather_1  |   File "/usr/local/lib/python3.11/site-packages/pymodbus/framer/socket_framer.py", line 175, in _process
sungather_1  |     raise ModbusIOException("Unable to decode request")
sungather_1  | pymodbus.exceptions.ModbusIOException: Modbus Error: [Input/Output] Unable to decode request
sungather_1  | 2023-02-14 22:42:42 WARNING  Modbus connection failed
sungather_1  | Modbus connection failed
sungather_1  | 2023-02-14 22:42:43 ERROR    index out of range
sungather_1  | index out of range
sungather_1  | 2023-02-14 22:42:43 ERROR    Modbus Error: [Input/Output] Unable to decode request
sungather_1  | Traceback (most recent call last):
sungather_1  |   File "/usr/local/lib/python3.11/site-packages/pymodbus/transaction.py", line 208, in execute
sungather_1  |     self.client.framer.processIncomingPacket(response,
sungather_1  |   File "/usr/local/lib/python3.11/site-packages/pymodbus/framer/socket_framer.py", line 153, in processIncomingPacket
sungather_1  |     self._process(callback)
sungather_1  |   File "/usr/local/lib/python3.11/site-packages/pymodbus/framer/socket_framer.py", line 175, in _process
sungather_1  |     raise ModbusIOException("Unable to decode request")
sungather_1  | pymodbus.exceptions.ModbusIOException: Modbus Error: [Input/Output] Unable to decode request
sungather_1  | Modbus Error: [Input/Output] Unable to decode request
sungather_1  | Traceback (most recent call last):
sungather_1  |   File "/usr/local/lib/python3.11/site-packages/pymodbus/transaction.py", line 208, in execute
sungather_1  |     self.client.framer.processIncomingPacket(response,
sungather_1  |   File "/usr/local/lib/python3.11/site-packages/pymodbus/framer/socket_framer.py", line 153, in processIncomingPacket
sungather_1  |     self._process(callback)
sungather_1  |   File "/usr/local/lib/python3.11/site-packages/pymodbus/framer/socket_framer.py", line 175, in _process
sungather_1  |     raise ModbusIOException("Unable to decode request")
sungather_1  | pymodbus.exceptions.ModbusIOException: Modbus Error: [Input/Output] Unable to decode request
sungather_1  | 2023-02-14 22:42:43 WARNING  Modbus connection failed
sungather_1  | Modbus connection failed
sungather_1  | 2023-02-14 22:42:43 ERROR    index out of range
sungather_1  | index out of range
sungather_1  | 2023-02-14 22:42:43 ERROR    Modbus Error: [Input/Output] Unable to decode request
sungather_1  | Traceback (most recent call last):
sungather_1  |   File "/usr/local/lib/python3.11/site-packages/pymodbus/transaction.py", line 208, in execute
sungather_1  |     self.client.framer.processIncomingPacket(response,
sungather_1  |   File "/usr/local/lib/python3.11/site-packages/pymodbus/framer/socket_framer.py", line 153, in processIncomingPacket
sungather_1  |     self._process(callback)
sungather_1  |   File "/usr/local/lib/python3.11/site-packages/pymodbus/framer/socket_framer.py", line 175, in _process
sungather_1  |     raise ModbusIOException("Unable to decode request")
sungather_1  | pymodbus.exceptions.ModbusIOException: Modbus Error: [Input/Output] Unable to decode request
sungather_1  | Modbus Error: [Input/Output] Unable to decode request
sungather_1  | Traceback (most recent call last):
sungather_1  |   File "/usr/local/lib/python3.11/site-packages/pymodbus/transaction.py", line 208, in execute
sungather_1  |     self.client.framer.processIncomingPacket(response,
sungather_1  |   File "/usr/local/lib/python3.11/site-packages/pymodbus/framer/socket_framer.py", line 153, in processIncomingPacket
sungather_1  |     self._process(callback)
sungather_1  |   File "/usr/local/lib/python3.11/site-packages/pymodbus/framer/socket_framer.py", line 175, in _process
sungather_1  |     raise ModbusIOException("Unable to decode request")
sungather_1  | pymodbus.exceptions.ModbusIOException: Modbus Error: [Input/Output] Unable to decode request
sungather_1  | 2023-02-14 22:42:43 WARNING  Modbus connection failed
sungather_1  | Modbus connection failed
sungather_1  | 2023-02-14 22:42:43 ERROR    index out of range
sungather_1  | index out of range
sungather_1  | 2023-02-14 22:42:43 ERROR    Modbus Error: [Input/Output] Unable to decode request
sungather_1  | Traceback (most recent call last):
sungather_1  |   File "/usr/local/lib/python3.11/site-packages/pymodbus/transaction.py", line 208, in execute
sungather_1  |     self.client.framer.processIncomingPacket(response,
sungather_1  |   File "/usr/local/lib/python3.11/site-packages/pymodbus/framer/socket_framer.py", line 153, in processIncomingPacket
sungather_1  |     self._process(callback)
sungather_1  |   File "/usr/local/lib/python3.11/site-packages/pymodbus/framer/socket_framer.py", line 175, in _process
sungather_1  |     raise ModbusIOException("Unable to decode request")
sungather_1  | pymodbus.exceptions.ModbusIOException: Modbus Error: [Input/Output] Unable to decode request
sungather_1  | Modbus Error: [Input/Output] Unable to decode request
sungather_1  | Traceback (most recent call last):
sungather_1  |   File "/usr/local/lib/python3.11/site-packages/pymodbus/transaction.py", line 208, in execute
sungather_1  |     self.client.framer.processIncomingPacket(response,
sungather_1  |   File "/usr/local/lib/python3.11/site-packages/pymodbus/framer/socket_framer.py", line 153, in processIncomingPacket
sungather_1  |     self._process(callback)
sungather_1  |   File "/usr/local/lib/python3.11/site-packages/pymodbus/framer/socket_framer.py", line 175, in _process
sungather_1  |     raise ModbusIOException("Unable to decode request")
sungather_1  | pymodbus.exceptions.ModbusIOException: Modbus Error: [Input/Output] Unable to decode request
sungather_1  | 2023-02-14 22:42:43 WARNING  Modbus connection failed
sungather_1  | Modbus connection failed
sungather_1  | 2023-02-14 22:42:43 ERROR    index out of range
sungather_1  | index out of range
sungather_1  | 2023-02-14 22:42:43 ERROR    Modbus Error: [Input/Output] Unable to decode request
sungather_1  | Traceback (most recent call last):
sungather_1  |   File "/usr/local/lib/python3.11/site-packages/pymodbus/transaction.py", line 208, in execute
sungather_1  |     self.client.framer.processIncomingPacket(response,
sungather_1  |   File "/usr/local/lib/python3.11/site-packages/pymodbus/framer/socket_framer.py", line 153, in processIncomingPacket
sungather_1  |     self._process(callback)
sungather_1  |   File "/usr/local/lib/python3.11/site-packages/pymodbus/framer/socket_framer.py", line 175, in _process
sungather_1  |     raise ModbusIOException("Unable to decode request")
sungather_1  | pymodbus.exceptions.ModbusIOException: Modbus Error: [Input/Output] Unable to decode request
sungather_1  | Modbus Error: [Input/Output] Unable to decode request
sungather_1  | Traceback (most recent call last):
sungather_1  |   File "/usr/local/lib/python3.11/site-packages/pymodbus/transaction.py", line 208, in execute
sungather_1  |     self.client.framer.processIncomingPacket(response,
sungather_1  |   File "/usr/local/lib/python3.11/site-packages/pymodbus/framer/socket_framer.py", line 153, in processIncomingPacket
sungather_1  |     self._process(callback)
sungather_1  |   File "/usr/local/lib/python3.11/site-packages/pymodbus/framer/socket_framer.py", line 175, in _process
sungather_1  |     raise ModbusIOException("Unable to decode request")
sungather_1  | pymodbus.exceptions.ModbusIOException: Modbus Error: [Input/Output] Unable to decode request
sungather_1  | 2023-02-14 22:42:43 WARNING  Modbus connection failed
sungather_1  | Modbus connection failed

Here is the output of one scrape with debug logging enabled: https://gist.github.com/FrederikP/349dcbbd5566f0f959f6de19eb5727eb

Is this a bug or did I misconfigure something? I will gladly provide more info if needed. Thank you very much

bohdan-s commented 1 year ago

The modbus implementation on the WiNet-S dongle is buggy at best. Try the HTTP option.

FrederikP commented 1 year ago

Wow, quick answer. Thanks!

With

 connection: http 

it says that model detection fails. When I additionally set

  model: "SH10RT-V112" 

Then I'm getting the errors below:

sungather_1  | 2023-02-14 22:58:27 DEBUG    Checking Modbus Connection
sungather_1  | 2023-02-14 22:58:27 INFO     Modbus client is not connected, attempting to reconnect
sungather_1  | 2023-02-14 22:58:27 INFO     Connection: SungrowModbusWebClient_0.3.2(192.168.2.21:8082)
sungather_1  | 2023-02-14 22:58:27 DEBUG    Connection to websocket server failed: ws://192.168.2.21:8082/ws/home/overview, Message: [Errno 104] Connection reset by peer
sungather_1  | 2023-02-14 22:58:30 DEBUG    Scraping: read, 4949:50
sungather_1  | 2023-02-14 22:58:30 DEBUG    load_registers: read, 4949:50
sungather_1  | 2023-02-14 22:58:30 DEBUG    Connection to websocket server failed: ws://192.168.2.21:8082/ws/home/overview, Message: [Errno 104] Connection reset by peer
sungather_1  | 2023-02-14 22:58:30 WARNING  No data returned for read, 4949:50
sungather_1  | No data returned for read, 4949:50
sungather_1  | 2023-02-14 22:58:30 DEBUG    Modbus Error: [Connection] Failed to connect[SungrowModbusWebClient_0.3.2(192.168.2.21:8082)]')
sungather_1  | 2023-02-14 22:58:30 DEBUG    Scraping: read, 5000:38
sungather_1  | 2023-02-14 22:58:30 DEBUG    load_registers: read, 5000:38
sungather_1  | 2023-02-14 22:58:30 DEBUG    Connection to websocket server failed: ws://192.168.2.21:8082/ws/home/overview, Message: [Errno 111] Connection refused
sungather_1  | 2023-02-14 22:58:30 WARNING  No data returned for read, 5000:38
sungather_1  | No data returned for read, 5000:38
sungather_1  | 2023-02-14 22:58:30 DEBUG    Modbus Error: [Connection] Failed to connect[SungrowModbusWebClient_0.3.2(192.168.2.21:8082)]')
sungather_1  | 2023-02-14 22:58:30 DEBUG    Scraping: read, 5039:61
sungather_1  | 2023-02-14 22:58:30 DEBUG    load_registers: read, 5039:61
sungather_1  | 2023-02-14 22:58:30 DEBUG    Connection to websocket server failed: ws://192.168.2.21:8082/ws/home/overview, Message: [Errno 104] Connection reset by peer
sungather_1  | 2023-02-14 22:58:30 WARNING  No data returned for read, 5039:61
sungather_1  | No data returned for read, 5039:61
sungather_1  | 2023-02-14 22:58:30 DEBUG    Modbus Error: [Connection] Failed to connect[SungrowModbusWebClient_0.3.2(192.168.2.21:8082)]')
sungather_1  | 2023-02-14 22:58:30 DEBUG    Scraping: read, 5100:100
sungather_1  | 2023-02-14 22:58:30 DEBUG    load_registers: read, 5100:100
sungather_1  | 2023-02-14 22:58:30 DEBUG    Connection to websocket server failed: ws://192.168.2.21:8082/ws/home/overview, Message: [Errno 104] Connection reset by peer
sungather_1  | 2023-02-14 22:58:30 WARNING  No data returned for read, 5100:100
sungather_1  | No data returned for read, 5100:100
sungather_1  | 2023-02-14 22:58:30 DEBUG    Modbus Error: [Connection] Failed to connect[SungrowModbusWebClient_0.3.2(192.168.2.21:8082)]')
sungather_1  | 2023-02-14 22:58:30 DEBUG    Scraping: read, 5600:100
sungather_1  | 2023-02-14 22:58:30 DEBUG    load_registers: read, 5600:100
sungather_1  | 2023-02-14 22:58:30 DEBUG    Connection to websocket server failed: ws://192.168.2.21:8082/ws/home/overview, Message: [Errno 104] Connection reset by peer
sungather_1  | 2023-02-14 22:58:30 WARNING  No data returned for read, 5600:100
sungather_1  | No data returned for read, 5600:100
sungather_1  | 2023-02-14 22:58:30 DEBUG    Modbus Error: [Connection] Failed to connect[SungrowModbusWebClient_0.3.2(192.168.2.21:8082)]')
sungather_1  | 2023-02-14 22:58:30 DEBUG    Scraping: read, 6099:100
sungather_1  | 2023-02-14 22:58:30 DEBUG    load_registers: read, 6099:100
sungather_1  | 2023-02-14 22:58:30 DEBUG    Connection to websocket server failed: ws://192.168.2.21:8082/ws/home/overview, Message: [Errno 111] Connection refused
sungather_1  | 2023-02-14 22:58:30 WARNING  No data returned for read, 6099:100
sungather_1  | No data returned for read, 6099:100
sungather_1  | 2023-02-14 22:58:30 DEBUG    Modbus Error: [Connection] Failed to connect[SungrowModbusWebClient_0.3.2(192.168.2.21:8082)]')
sungather_1  | 2023-02-14 22:58:30 DEBUG    Scraping: read, 6199:100
sungather_1  | 2023-02-14 22:58:30 DEBUG    load_registers: read, 6199:100
sungather_1  | 2023-02-14 22:58:30 DEBUG    Connection to websocket server failed: ws://192.168.2.21:8082/ws/home/overview, Message: [Errno 104] Connection reset by peer
sungather_1  | 2023-02-14 22:58:30 WARNING  No data returned for read, 6199:100
sungather_1  | No data returned for read, 6199:100
sungather_1  | 2023-02-14 22:58:30 DEBUG    Modbus Error: [Connection] Failed to connect[SungrowModbusWebClient_0.3.2(192.168.2.21:8082)]')
sungather_1  | 2023-02-14 22:58:30 DEBUG    Scraping: read, 6299:100
sungather_1  | 2023-02-14 22:58:30 DEBUG    load_registers: read, 6299:100
sungather_1  | 2023-02-14 22:58:30 DEBUG    Connection to websocket server failed: ws://192.168.2.21:8082/ws/home/overview, Message: [Errno 104] Connection reset by peer
sungather_1  | 2023-02-14 22:58:30 WARNING  No data returned for read, 6299:100
sungather_1  | No data returned for read, 6299:100
sungather_1  | 2023-02-14 22:58:30 DEBUG    Modbus Error: [Connection] Failed to connect[SungrowModbusWebClient_0.3.2(192.168.2.21:8082)]')
sungather_1  | 2023-02-14 22:58:30 DEBUG    Scraping: read, 6399:100
sungather_1  | 2023-02-14 22:58:30 DEBUG    load_registers: read, 6399:100
sungather_1  | 2023-02-14 22:58:30 DEBUG    Connection to websocket server failed: ws://192.168.2.21:8082/ws/home/overview, Message: [Errno 104] Connection reset by peer
sungather_1  | 2023-02-14 22:58:30 WARNING  No data returned for read, 6399:100
sungather_1  | No data returned for read, 6399:100
sungather_1  | 2023-02-14 22:58:30 DEBUG    Modbus Error: [Connection] Failed to connect[SungrowModbusWebClient_0.3.2(192.168.2.21:8082)]')
sungather_1  | 2023-02-14 22:58:30 DEBUG    Scraping: read, 6499:100
sungather_1  | 2023-02-14 22:58:30 DEBUG    load_registers: read, 6499:100
sungather_1  | 2023-02-14 22:58:30 DEBUG    Connection to websocket server failed: ws://192.168.2.21:8082/ws/home/overview, Message: [Errno 111] Connection refused
sungather_1  | 2023-02-14 22:58:30 WARNING  No data returned for read, 6499:100
sungather_1  | No data returned for read, 6499:100
sungather_1  | 2023-02-14 22:58:30 DEBUG    Modbus Error: [Connection] Failed to connect[SungrowModbusWebClient_0.3.2(192.168.2.21:8082)]')
sungather_1  | 2023-02-14 22:58:30 DEBUG    Scraping: read, 6599:100
sungather_1  | 2023-02-14 22:58:30 DEBUG    load_registers: read, 6599:100
sungather_1  | 2023-02-14 22:58:30 DEBUG    Connection to websocket server failed: ws://192.168.2.21:8082/ws/home/overview, Message: [Errno 104] Connection reset by peer
sungather_1  | 2023-02-14 22:58:30 WARNING  No data returned for read, 6599:100
sungather_1  | No data returned for read, 6599:100
sungather_1  | 2023-02-14 22:58:30 DEBUG    Modbus Error: [Connection] Failed to connect[SungrowModbusWebClient_0.3.2(192.168.2.21:8082)]')
sungather_1  | 2023-02-14 22:58:30 DEBUG    Scraping: read, 6699:100
sungather_1  | 2023-02-14 22:58:30 DEBUG    load_registers: read, 6699:100
sungather_1  | 2023-02-14 22:58:30 DEBUG    Connection to websocket server failed: ws://192.168.2.21:8082/ws/home/overview, Message: [Errno 111] Connection refused
sungather_1  | 2023-02-14 22:58:30 WARNING  No data returned for read, 6699:100
sungather_1  | No data returned for read, 6699:100
sungather_1  | 2023-02-14 22:58:30 DEBUG    Modbus Error: [Connection] Failed to connect[SungrowModbusWebClient_0.3.2(192.168.2.21:8082)]')
sungather_1  | 2023-02-14 22:58:30 DEBUG    Scraping: read, 12999:125
sungather_1  | 2023-02-14 22:58:30 DEBUG    load_registers: read, 12999:125
sungather_1  | 2023-02-14 22:58:31 DEBUG    Connection to websocket server failed: ws://192.168.2.21:8082/ws/home/overview, Message: [Errno 104] Connection reset by peer
sungather_1  | 2023-02-14 22:58:31 WARNING  No data returned for read, 12999:125
sungather_1  | No data returned for read, 12999:125
sungather_1  | 2023-02-14 22:58:31 DEBUG    Modbus Error: [Connection] Failed to connect[SungrowModbusWebClient_0.3.2(192.168.2.21:8082)]')
sungather_1  | 2023-02-14 22:58:31 DEBUG    Scraping: hold, 4999:10
sungather_1  | 2023-02-14 22:58:31 DEBUG    load_registers: hold, 4999:10
sungather_1  | 2023-02-14 22:58:31 DEBUG    Connection to websocket server failed: ws://192.168.2.21:8082/ws/home/overview, Message: [Errno 104] Connection reset by peer
sungather_1  | 2023-02-14 22:58:31 WARNING  No data returned for hold, 4999:10
sungather_1  | No data returned for hold, 4999:10
sungather_1  | 2023-02-14 22:58:31 DEBUG    Modbus Error: [Connection] Failed to connect[SungrowModbusWebClient_0.3.2(192.168.2.21:8082)]')
sungather_1  | 2023-02-14 22:58:31 DEBUG    Scraping: hold, 5009:10
sungather_1  | 2023-02-14 22:58:31 DEBUG    load_registers: hold, 5009:10
sungather_1  | 2023-02-14 22:58:31 DEBUG    Connection to websocket server failed: ws://192.168.2.21:8082/ws/home/overview, Message: [Errno 104] Connection reset by peer
sungather_1  | 2023-02-14 22:58:31 WARNING  No data returned for hold, 5009:10
sungather_1  | No data returned for hold, 5009:10
sungather_1  | 2023-02-14 22:58:31 DEBUG    Modbus Error: [Connection] Failed to connect[SungrowModbusWebClient_0.3.2(192.168.2.21:8082)]')
sungather_1  | 2023-02-14 22:58:31 DEBUG    Scraping: hold, 5034:10
sungather_1  | 2023-02-14 22:58:31 DEBUG    load_registers: hold, 5034:10
sungather_1  | 2023-02-14 22:58:31 DEBUG    Connection to websocket server failed: ws://192.168.2.21:8082/ws/home/overview, Message: [Errno 104] Connection reset by peer
sungather_1  | 2023-02-14 22:58:31 WARNING  No data returned for hold, 5034:10
sungather_1  | No data returned for hold, 5034:10
sungather_1  | 2023-02-14 22:58:31 DEBUG    Modbus Error: [Connection] Failed to connect[SungrowModbusWebClient_0.3.2(192.168.2.21:8082)]')
sungather_1  | 2023-02-14 22:58:31 DEBUG    Scraping: hold, 13000:100
sungather_1  | 2023-02-14 22:58:31 DEBUG    load_registers: hold, 13000:100
sungather_1  | 2023-02-14 22:58:31 DEBUG    Connection to websocket server failed: ws://192.168.2.21:8082/ws/home/overview, Message: [Errno 104] Connection reset by peer
sungather_1  | 2023-02-14 22:58:31 WARNING  No data returned for hold, 13000:100
sungather_1  | No data returned for hold, 13000:100
sungather_1  | 2023-02-14 22:58:31 DEBUG    Modbus Error: [Connection] Failed to connect[SungrowModbusWebClient_0.3.2(192.168.2.21:8082)]')
sungather_1  | 2023-02-14 22:58:31 INFO     Disconnecting: SungrowModbusWebClient_0.3.2(192.168.2.21:8082)
sungather_1  | 2023-02-14 22:58:31 INFO     Disconnecting: None
sungather_1  | 2023-02-14 22:58:31 WARNING  Data collection failed, skipped exporting data. Retying in 10 secs
sungather_1  | Data collection failed, skipped exporting data. Retying in 10 secs
sungather_1  | 2023-02-14 22:58:31 DEBUG    Processing Time: 3.81 secs
sungather_1  | 2023-02-14 22:58:31 INFO     Next scrape in 6 secs

I also tried other ports (e.g. 80) without success. It still attempted 8082. Anything I'm missing?

bohdan-s commented 1 year ago

"Anything I'm missing?" yes, better documentation from me :P Can you load the web ui via http://192.168.2.21 ? it seems like the dongle may have crashed, and need to be restarted / unplugged & re plugged in again

FrederikP commented 1 year ago

You are absolutely correct. Something crashed and after unplugging and replugging in again, it works with connection: http. Thank you very much. One more thing I noticed is that, even though my WiNet-S dongle is connected to my wifi, it's also in hotspot mode and I can't seem to find a way to deactivate it. Do you know how by any chance? Not really a problem with your tool though ;)

Thanks for this great open source project.

bohdan-s commented 1 year ago

The AP mode still on it a bug in the later firmware. It used to be off. Hopefully they fix it in a new release.