Fixes for malformed stream #356 #363

pazzarpj · 2018-12-03T23:42:36Z

Changing processIncomingPacket in RTU framer so that if a frame is ready but fails the self.checkFrame(), it will reset the frame.
Tests as per below see comments

Test Setup.
Simulator - Modbus Slave Windows 10
com0com - Serial port loopback
Client - Modbus RTU Async
pip install async_timeout

19200 Baud
8 Data bits
None Parity
1 Stop bit
RTU

Slave 1:
Unit ID 1:
Address 0
Value 1

Slave 2:
Unit ID 1:
Address 0-9
Value 1-10

Slave 3:
Unit ID 3:
Address 0-10
Value 0-0

Periodic poll using this setup

import async_timeout
import asyncio
from pymodbus.client.async.serial import AsyncModbusSerialClient
from pymodbus.client.async.schedulers import ASYNC_IO
import logging

logging.basicConfig(level=logging.DEBUG)

log = logging.getLogger(__file__)

loop, client = AsyncModbusSerialClient(ASYNC_IO, method='rtu', port='COM10', parity='N', baudrate=19200, stopbits=1)


async def spam():
    while True:
        # Slave 1
        try:
            with async_timeout.timeout(1):
                resp = await client.protocol.read_holding_registers(0, 1, unit=1)
                if resp.isError():
                    log.debug("{}".format(resp))
        except asyncio.TimeoutError:
            log.debug("Timeout on Slave 1")
        # Slave 2
        try:
            with async_timeout.timeout(1):
                resp = await client.protocol.read_holding_registers(0, 10, unit=2)
                if resp.isError():
                    log.debug("{}".format(resp))
        except asyncio.TimeoutError:
            log.debug("Timeout on Slave 2")

        # Slave 3
        try:
            with async_timeout.timeout(1):
                resp = await client.protocol.read_holding_registers(0, 10, unit=3)
                if resp.isError():
                    log.debug("{}".format(resp))
        except asyncio.TimeoutError:
            log.debug("Timeout on Slave 3")


if __name__ == "__main__":
    import logging

    loop.run_until_complete(spam())
    loop.close()

Reset frame when checkframe fails as it is impossible to know what is a valid start packet if CRC or mid frame is in buffer.

I Had it one level too deep. This alongside with pymodbus-dev#361 Tested. Task cancellation due to async timeout. Recovers correctly Malformed RTU packets with CRC errors now recover. Only issue I can see with this is if the serial stream is so continuous that you always are pulling mid stream and the discarding of the buffer will create a perpetual discarding of the buffer. But as it is a call and response, I can't see this happening in any real world examples but my modbus knowledge is a bit low for this.

pazzarpj · 2018-12-04T00:05:56Z

The following tests also have to do with PR #361

pazzarpj · 2018-12-04T00:06:15Z

Dev branch.
Fail Condition, Skip a random response on slave 3. Happens at transaction 30.
Packets will process but will not awake the task. and return from await, only the timeout breaks the infinite await.
#360 issue.

DEBUG:pymodbus.transaction:Adding transaction 27
DEBUG:pymodbus.client.async.asyncio:recv: 0x3 0x3 0x14 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x3a 0x1e
DEBUG:pymodbus.framer.rtu_framer:Getting Frame - 0x3 0x14 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0
DEBUG:pymodbus.factory:Factory Response[ReadHoldingRegistersResponse: 3]
DEBUG:pymodbus.framer.rtu_framer:Frame advanced, resetting header!!
DEBUG:pymodbus.client.async.asyncio:send: 0x1 0x3 0x0 0x0 0x0 0x1 0x84 0xa
DEBUG:pymodbus.transaction:Adding transaction 28
DEBUG:pymodbus.client.async.asyncio:recv: 0x1 0x3 0x2 0x0 0x1 0x79 0x84
DEBUG:pymodbus.framer.rtu_framer:Getting Frame - 0x3 0x2 0x0 0x1
DEBUG:pymodbus.factory:Factory Response[ReadHoldingRegistersResponse: 3]
DEBUG:pymodbus.framer.rtu_framer:Frame advanced, resetting header!!
DEBUG:pymodbus.client.async.asyncio:send: 0x2 0x3 0x0 0x0 0x0 0xa 0xc5 0xfe
DEBUG:pymodbus.transaction:Adding transaction 29
DEBUG:pymodbus.client.async.asyncio:recv: 0x2 0x3 0x14 0x0 0x1 0x0 0x2 0x0 0x3 0x0 0x4 0x0 0x5 0x0 0x6 0x0 0x7 0x0 0x8 0x0 0x9 0x0 0xa 0xdb 0xf3
DEBUG:pymodbus.framer.rtu_framer:Getting Frame - 0x3 0x14 0x0 0x1 0x0 0x2 0x0 0x3 0x0 0x4 0x0 0x5 0x0 0x6 0x0 0x7 0x0 0x8 0x0 0x9 0x0 0xa
DEBUG:pymodbus.factory:Factory Response[ReadHoldingRegistersResponse: 3]
DEBUG:pymodbus.framer.rtu_framer:Frame advanced, resetting header!!
DEBUG:pymodbus.client.async.asyncio:send: 0x3 0x3 0x0 0x0 0x0 0xa 0xc4 0x2f
DEBUG:pymodbus.transaction:Adding transaction 30
DEBUG:C:/dev/Bitbucket/gatewaysoftware/MobusRTU-IBMWatson/basic_reproduce/issue.py:Timeout on Slave 3
DEBUG:pymodbus.client.async.asyncio:send: 0x1 0x3 0x0 0x0 0x0 0x1 0x84 0xa
DEBUG:pymodbus.transaction:Adding transaction 31
DEBUG:pymodbus.client.async.asyncio:recv: 0x1 0x3 0x2 0x0 0x1 0x79 0x84
DEBUG:pymodbus.framer.rtu_framer:Getting Frame - 0x3 0x2 0x0 0x1
DEBUG:pymodbus.factory:Factory Response[ReadHoldingRegistersResponse: 3]
DEBUG:pymodbus.framer.rtu_framer:Frame advanced, resetting header!!
DEBUG:C:/dev/Bitbucket/gatewaysoftware/MobusRTU-IBMWatson/basic_reproduce/issue.py:Timeout on Slave 1
DEBUG:pymodbus.client.async.asyncio:send: 0x2 0x3 0x0 0x0 0x0 0xa 0xc5 0xfe
DEBUG:pymodbus.transaction:Adding transaction 32
DEBUG:pymodbus.client.async.asyncio:recv: 0x2 0x3 0x14 0x0 0x1 0x0 0x2 0x0 0x3 0x0 0x4 0x0 0x5 0x0 0x6 0x0 0x7 0x0 0x8 0x0 0x9 0x0 0xa 0xdb 0xf3
DEBUG:pymodbus.framer.rtu_framer:Getting Frame - 0x3 0x14 0x0 0x1 0x0 0x2 0x0 0x3 0x0 0x4 0x0 0x5 0x0 0x6 0x0 0x7 0x0 0x8 0x0 0x9 0x0 0xa
DEBUG:pymodbus.factory:Factory Response[ReadHoldingRegistersResponse: 3]
DEBUG:pymodbus.framer.rtu_framer:Frame advanced, resetting header!!
DEBUG:C:/dev/Bitbucket/gatewaysoftware/MobusRTU-IBMWatson/basic_reproduce/issue.py:Timeout on Slave 2
DEBUG:pymodbus.client.async.asyncio:send: 0x3 0x3 0x0 0x0 0x0 0xa 0xc4 0x2f
DEBUG:pymodbus.transaction:Adding transaction 33
DEBUG:pymodbus.client.async.asyncio:recv: 0x3 0x3 0x14 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x3a 0x1e
DEBUG:pymodbus.framer.rtu_framer:Getting Frame - 0x3 0x14 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0
DEBUG:pymodbus.factory:Factory Response[ReadHoldingRegistersResponse: 3]
DEBUG:pymodbus.framer.rtu_framer:Frame advanced, resetting header!!
DEBUG:C:/dev/Bitbucket/gatewaysoftware/MobusRTU-IBMWatson/basic_reproduce/issue.py:Timeout on Slave 3
DEBUG:pymodbus.client.async.asyncio:send: 0x1 0x3 0x0 0x0 0x0 0x1 0x84 0xa
DEBUG:pymodbus.transaction:Adding transaction 34
DEBUG:pymodbus.client.async.asyncio:recv: 0x1 0x3 0x2 0x0 0x1 0x79 0x84
DEBUG:pymodbus.framer.rtu_framer:Getting Frame - 0x3 0x2 0x0 0x1
DEBUG:pymodbus.factory:Factory Response[ReadHoldingRegistersResponse: 3]
DEBUG:pymodbus.framer.rtu_framer:Frame advanced, resetting header!!
DEBUG:C:/dev/Bitbucket/gatewaysoftware/MobusRTU-IBMWatson/basic_reproduce/issue.py:Timeout on Slave 1
DEBUG:pymodbus.client.async.asyncio:send: 0x2 0x3 0x0 0x0 0x0 0xa 0xc5 0xfe
DEBUG:pymodbus.transaction:Adding transaction 35
DEBUG:pymodbus.client.async.asyncio:recv: 0x2 0x3 0x14 0x0 0x1 0x0 0x2 0x0 0x3 0x0 0x4 0x0 0x5 0x0 0x6 0x0 0x7 0x0 0x8 0x0 0x9 0x0 0xa 0xdb 0xf3
DEBUG:pymodbus.framer.rtu_framer:Getting Frame - 0x3 0x14 0x0 0x1 0x0 0x2 0x0 0x3 0x0 0x4 0x0 0x5 0x0 0x6 0x0 0x7 0x0 0x8 0x0 0x9 0x0 0xa
DEBUG:pymodbus.factory:Factory Response[ReadHoldingRegistersResponse: 3]
DEBUG:pymodbus.framer.rtu_framer:Frame advanced, resetting header!!

pazzarpj · 2018-12-04T00:18:11Z

PR #361 branch.
Fail Condition, Skip a random response on slave 3. Happens at transaction 27
Recovers from timeout and discards that transaction

DEBUG:pymodbus.client.async.asyncio:recv: 0x1 0x3 0x2 0x0 0x1 0x79 0x84
DEBUG:pymodbus.framer.rtu_framer:Getting Frame - 0x3 0x2 0x0 0x1
DEBUG:pymodbus.factory:Factory Response[ReadHoldingRegistersResponse: 3]
DEBUG:pymodbus.framer.rtu_framer:Frame advanced, resetting header!!
DEBUG:pymodbus.client.async.asyncio:send: 0x2 0x3 0x0 0x0 0x0 0xa 0xc5 0xfe
DEBUG:pymodbus.transaction:Adding transaction 26
DEBUG:pymodbus.client.async.asyncio:recv: 0x2 0x3 0x14 0x0 0x1 0x0 0x2 0x0 0x3 0x0 0x4 0x0 0x5 0x0 0x6 0x0 0x7 0x0 0x8 0x0 0x9 0x0 0xa 0xdb 0xf3
DEBUG:pymodbus.framer.rtu_framer:Getting Frame - 0x3 0x14 0x0 0x1 0x0 0x2 0x0 0x3 0x0 0x4 0x0 0x5 0x0 0x6 0x0 0x7 0x0 0x8 0x0 0x9 0x0 0xa
DEBUG:pymodbus.factory:Factory Response[ReadHoldingRegistersResponse: 3]
DEBUG:pymodbus.framer.rtu_framer:Frame advanced, resetting header!!
DEBUG:pymodbus.client.async.asyncio:send: 0x3 0x3 0x0 0x0 0x0 0xa 0xc4 0x2f
DEBUG:pymodbus.transaction:Adding transaction 27
DEBUG:C:/dev/Bitbucket/gatewaysoftware/MobusRTU-IBMWatson/basic_reproduce/issue.py:Timeout on Slave 3
DEBUG:pymodbus.client.async.asyncio:send: 0x1 0x3 0x0 0x0 0x0 0x1 0x84 0xa
DEBUG:pymodbus.transaction:Adding transaction 28
DEBUG:pymodbus.client.async.asyncio:recv: 0x1 0x3 0x2 0x0 0x1 0x79 0x84
DEBUG:pymodbus.framer.rtu_framer:Getting Frame - 0x3 0x2 0x0 0x1
DEBUG:pymodbus.factory:Factory Response[ReadHoldingRegistersResponse: 3]
DEBUG:pymodbus.framer.rtu_framer:Frame advanced, resetting header!!
DEBUG:pymodbus.client.async.asyncio:send: 0x2 0x3 0x0 0x0 0x0 0xa 0xc5 0xfe
DEBUG:pymodbus.transaction:Adding transaction 29
DEBUG:pymodbus.client.async.asyncio:recv: 0x2 0x3 0x14 0x0 0x1 0x0 0x2 0x0 0x3 0x0 0x4 0x0 0x5 0x0 0x6 0x0 0x7 0x0 0x8 0x0 0x9 0x0 0xa 0xdb 0xf3
DEBUG:pymodbus.framer.rtu_framer:Getting Frame - 0x3 0x14 0x0 0x1 0x0 0x2 0x0 0x3 0x0 0x4 0x0 0x5 0x0 0x6 0x0 0x7 0x0 0x8 0x0 0x9 0x0 0xa
DEBUG:pymodbus.factory:Factory Response[ReadHoldingRegistersResponse: 3]
DEBUG:pymodbus.framer.rtu_framer:Frame advanced, resetting header!!
DEBUG:pymodbus.client.async.asyncio:send: 0x3 0x3 0x0 0x0 0x0 0xa 0xc4 0x2f
DEBUG:pymodbus.transaction:Adding transaction 30
DEBUG:pymodbus.client.async.asyncio:recv: 0x3 0x3 0x14 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x3a 0x1e
DEBUG:pymodbus.framer.rtu_framer:Getting Frame - 0x3 0x14 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0
DEBUG:pymodbus.factory:Factory Response[ReadHoldingRegistersResponse: 3]
DEBUG:pymodbus.framer.rtu_framer:Frame advanced, resetting header!!
DEBUG:pymodbus.client.async.asyncio:send: 0x1 0x3 0x0 0x0 0x0 0x1 0x84 0xa
DEBUG:pymodbus.transaction:Adding transaction 31
DEBUG:pymodbus.client.async.asyncio:recv: 0x1 0x3 0x2 0x0 0x1 0x79 0x84
DEBUG:pymodbus.framer.rtu_framer:Getting Frame - 0x3 0x2 0x0 0x1
DEBUG:pymodbus.factory:Factory Response[ReadHoldingRegistersResponse: 3]
DEBUG:pymodbus.framer.rtu_framer:Frame advanced, resetting header!!
DEBUG:pymodbus.client.async.asyncio:send: 0x2 0x3 0x0 0x0 0x0 0xa 0xc5 0xfe

pazzarpj · 2018-12-04T00:20:18Z

PR #356 Doesn't change the outcome of Timeout Error. Doesn't work with Dev branch but works with PR #361.

pazzarpj · 2018-12-04T00:23:52Z

Dev Branch:
CRC Error: Random CRC Error on Slave 3. Happens on transaction 18.
Buffer fills indefinitely, doesn't advance frame. Doesn't awake from await.

DEBUG:pymodbus.transaction:Adding transaction 17
DEBUG:pymodbus.client.async.asyncio:recv: 0x2 0x3 0x14 0x0 0x1 0x0 0x2 0x0 0x3 0x0 0x4 0x0 0x5 0x0 0x6 0x0 0x7 0x0 0x8 0x0 0x9 0x0 0xa 0xdb 0xf3
DEBUG:pymodbus.framer.rtu_framer:Getting Frame - 0x3 0x14 0x0 0x1 0x0 0x2 0x0 0x3 0x0 0x4 0x0 0x5 0x0 0x6 0x0 0x7 0x0 0x8 0x0 0x9 0x0 0xa
DEBUG:pymodbus.factory:Factory Response[ReadHoldingRegistersResponse: 3]
DEBUG:pymodbus.framer.rtu_framer:Frame advanced, resetting header!!
DEBUG:pymodbus.client.async.asyncio:send: 0x3 0x3 0x0 0x0 0x0 0xa 0xc4 0x2f
DEBUG:pymodbus.transaction:Adding transaction 18
DEBUG:pymodbus.client.async.asyncio:recv: 0x3 0x3 0x14 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x63 0x1e
DEBUG:C:/dev/Bitbucket/gatewaysoftware/MobusRTU-IBMWatson/basic_reproduce/issue.py:Timeout on Slave 3
DEBUG:pymodbus.client.async.asyncio:send: 0x1 0x3 0x0 0x0 0x0 0x1 0x84 0xa
DEBUG:pymodbus.transaction:Adding transaction 19
DEBUG:pymodbus.client.async.asyncio:recv: 0x1 0x3 0x2 0x0 0x1 0x79 0x84
DEBUG:C:/dev/Bitbucket/gatewaysoftware/MobusRTU-IBMWatson/basic_reproduce/issue.py:Timeout on Slave 1
DEBUG:pymodbus.client.async.asyncio:send: 0x2 0x3 0x0 0x0 0x0 0xa 0xc5 0xfe
DEBUG:pymodbus.transaction:Adding transaction 20
DEBUG:pymodbus.client.async.asyncio:recv: 0x2 0x3 0x14 0x0 0x1 0x0 0x2 0x0 0x3 0x0 0x4 0x0 0x5 0x0 0x6 0x0 0x7 0x0 0x8 0x0 0x9 0x0 0xa 0xdb 0xf3
DEBUG:C:/dev/Bitbucket/gatewaysoftware/MobusRTU-IBMWatson/basic_reproduce/issue.py:Timeout on Slave 2
DEBUG:pymodbus.client.async.asyncio:send: 0x3 0x3 0x0 0x0 0x0 0xa 0xc4 0x2f
DEBUG:pymodbus.transaction:Adding transaction 21
DEBUG:pymodbus.client.async.asyncio:recv: 0x3 0x3 0x14 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x3a 0x1e
DEBUG:C:/dev/Bitbucket/gatewaysoftware/MobusRTU-IBMWatson/basic_reproduce/issue.py:Timeout on Slave 3
DEBUG:pymodbus.client.async.asyncio:send: 0x1 0x3 0x0 0x0 0x0 0x1 0x84 0xa
DEBUG:pymodbus.transaction:Adding transaction 22
DEBUG:pymodbus.client.async.asyncio:recv: 0x1 0x3 0x2 0x0 0x1 0x79 0x84
DEBUG:C:/dev/Bitbucket/gatewaysoftware/MobusRTU-IBMWatson/basic_reproduce/issue.py:Timeout on Slave 1
DEBUG:pymodbus.client.async.asyncio:send: 0x2 0x3 0x0 0x0 0x0 0xa 0xc5 0xfe
DEBUG:pymodbus.transaction:Adding transaction 23
DEBUG:pymodbus.client.async.asyncio:recv: 0x2 0x3 0x14 0x0 0x1 0x0 0x2 0x0 0x3 0x0 0x4 0x0 0x5 0x0 0x6 0x0 0x7 0x0 0x8 0x0 0x9 0x0 0xa 0xdb 0xf3
DEBUG:C:/dev/Bitbucket/gatewaysoftware/MobusRTU-IBMWatson/basic_reproduce/issue.py:Timeout on Slave 2
DEBUG:pymodbus.client.async.asyncio:send: 0x3 0x3 0x0 0x0 0x0 0xa 0xc4 0x2f
DEBUG:pymodbus.transaction:Adding transaction 24
DEBUG:pymodbus.client.async.asyncio:recv: 0x3 0x3 0x14 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x3a 0x1e
DEBUG:C:/dev/Bitbucket/gatewaysoftware/MobusRTU-IBMWatson/basic_reproduce/issue.py:Timeout on Slave 3
DEBUG:pymodbus.client.async.asyncio:send: 0x1 0x3 0x0 0x0 0x0 0x1 0x84 0xa
DEBUG:pymodbus.transaction:Adding transaction 25
DEBUG:pymodbus.client.async.asyncio:recv: 0x1 0x3 0x2 0x0 0x1 0x79 0x84
DEBUG:C:/dev/Bitbucket/gatewaysoftware/MobusRTU-IBMWatson/basic_reproduce/issue.py:Timeout on Slave 1
DEBUG:pymodbus.client.async.asyncio:send: 0x2 0x3 0x0 0x0 0x0 0xa 0xc5 0xfe
DEBUG:pymodbus.transaction:Adding transaction 26
DEBUG:pymodbus.client.async.asyncio:recv: 0x2 0x3 0x14 0x0 0x1 0x0 0x2 0x0 0x3 0x0 0x4 0x0 0x5 0x0 0x6 0x0 0x7 0x0 0x8 0x0 0x9 0x0 0xa 0xdb 0xf3
DEBUG:C:/dev/Bitbucket/gatewaysoftware/MobusRTU-IBMWatson/basic_reproduce/issue.py:Timeout on Slave 2
DEBUG:pymodbus.client.async.asyncio:send: 0x3 0x3 0x0 0x0 0x0 0xa 0xc4 0x2f
DEBUG:pymodbus.transaction:Adding transaction 27
DEBUG:pymodbus.client.async.asyncio:recv: 0x3 0x3 0x14 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x3a 0x1e
DEBUG:C:/dev/Bitbucket/gatewaysoftware/MobusRTU-IBMWatson/basic_reproduce/issue.py:Timeout on Slave 3
DEBUG:pymodbus.client.async.asyncio:send: 0x1 0x3 0x0 0x0 0x0 0x1 0x84 0xa
DEBUG:pymodbus.transaction:Adding transaction 28
DEBUG:pymodbus.client.async.asyncio:recv: 0x1 0x3 0x2 0x0 0x1 0x79 0x84

pazzarpj · 2018-12-04T00:29:00Z

PR #356 Branch:
CRC Error: Random CRC error on slave 3. Happens at transaction 21.
Frames now advance but the timeout still causes it to not awake from timeout.


DEBUG:pymodbus.transaction:Adding transaction 19
DEBUG:pymodbus.client.async.asyncio:recv: 0x1 0x3 0x2 0x0 0x1 0x79 0x84
DEBUG:pymodbus.framer.rtu_framer:Getting Frame - 0x3 0x2 0x0 0x1
DEBUG:pymodbus.factory:Factory Response[ReadHoldingRegistersResponse: 3]
DEBUG:pymodbus.framer.rtu_framer:Frame advanced, resetting header!!
DEBUG:pymodbus.client.async.asyncio:send: 0x2 0x3 0x0 0x0 0x0 0xa 0xc5 0xfe
DEBUG:pymodbus.transaction:Adding transaction 20
DEBUG:pymodbus.client.async.asyncio:recv: 0x2 0x3 0x14 0x0 0x1 0x0 0x2 0x0 0x3 0x0 0x4 0x0 0x5 0x0 0x6 0x0 0x7 0x0 0x8 0x0 0x9 0x0 0xa 0xdb 0xf3
DEBUG:pymodbus.framer.rtu_framer:Getting Frame - 0x3 0x14 0x0 0x1 0x0 0x2 0x0 0x3 0x0 0x4 0x0 0x5 0x0 0x6 0x0 0x7 0x0 0x8 0x0 0x9 0x0 0xa
DEBUG:pymodbus.factory:Factory Response[ReadHoldingRegistersResponse: 3]
DEBUG:pymodbus.framer.rtu_framer:Frame advanced, resetting header!!
DEBUG:pymodbus.client.async.asyncio:send: 0x3 0x3 0x0 0x0 0x0 0xa 0xc4 0x2f
DEBUG:pymodbus.transaction:Adding transaction 21
DEBUG:pymodbus.client.async.asyncio:recv: 0x3 0x3 0x14 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x5d 0x66
DEBUG:pymodbus.framer.rtu_framer:Resetting frame - Current Frame in buffer - 0x3 0x3 0x14 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x5d 0x66
DEBUG:C:/dev/Bitbucket/gatewaysoftware/MobusRTU-IBMWatson/basic_reproduce/issue.py:Timeout on Slave 3
DEBUG:pymodbus.client.async.asyncio:send: 0x1 0x3 0x0 0x0 0x0 0x1 0x84 0xa
DEBUG:pymodbus.transaction:Adding transaction 22
DEBUG:pymodbus.client.async.asyncio:recv: 0x1 0x3 0x2 0x0 0x1 0x79 0x84
DEBUG:pymodbus.framer.rtu_framer:Getting Frame - 0x3 0x2 0x0 0x1
DEBUG:pymodbus.factory:Factory Response[ReadHoldingRegistersResponse: 3]
DEBUG:pymodbus.framer.rtu_framer:Frame advanced, resetting header!!
DEBUG:C:/dev/Bitbucket/gatewaysoftware/MobusRTU-IBMWatson/basic_reproduce/issue.py:Timeout on Slave 1
DEBUG:pymodbus.client.async.asyncio:send: 0x2 0x3 0x0 0x0 0x0 0xa 0xc5 0xfe
DEBUG:pymodbus.transaction:Adding transaction 23
DEBUG:pymodbus.client.async.asyncio:recv: 0x2 0x3 0x14 0x0 0x1 0x0 0x2 0x0 0x3 0x0 0x4 0x0 0x5 0x0 0x6 0x0 0x7 0x0 0x8 0x0 0x9 0x0 0xa 0xdb 0xf3
DEBUG:pymodbus.framer.rtu_framer:Getting Frame - 0x3 0x14 0x0 0x1 0x0 0x2 0x0 0x3 0x0 0x4 0x0 0x5 0x0 0x6 0x0 0x7 0x0 0x8 0x0 0x9 0x0 0xa
DEBUG:pymodbus.factory:Factory Response[ReadHoldingRegistersResponse: 3]
DEBUG:pymodbus.framer.rtu_framer:Frame advanced, resetting header!!
DEBUG:C:/dev/Bitbucket/gatewaysoftware/MobusRTU-IBMWatson/basic_reproduce/issue.py:Timeout on Slave 2
DEBUG:pymodbus.client.async.asyncio:send: 0x3 0x3 0x0 0x0 0x0 0xa 0xc4 0x2f
DEBUG:pymodbus.transaction:Adding transaction 24
DEBUG:pymodbus.client.async.asyncio:recv: 0x3 0x3 0x14 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x3a 0x1e
DEBUG:pymodbus.framer.rtu_framer:Getting Frame - 0x3 0x14 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0
DEBUG:pymodbus.factory:Factory Response[ReadHoldingRegistersResponse: 3]
DEBUG:pymodbus.framer.rtu_framer:Frame advanced, resetting header!!
DEBUG:C:/dev/Bitbucket/gatewaysoftware/MobusRTU-IBMWatson/basic_reproduce/issue.py:Timeout on Slave 3
DEBUG:pymodbus.client.async.asyncio:send: 0x1 0x3 0x0 0x0 0x0 0x1 0x84 0xa
DEBUG:pymodbus.transaction:Adding transaction 25
DEBUG:pymodbus.client.async.asyncio:recv: 0x1 0x3 0x2 0x0 0x1 0x79 0x84
DEBUG:pymodbus.framer.rtu_framer:Getting Frame - 0x3 0x2 0x0 0x1
DEBUG:pymodbus.factory:Factory Response[ReadHoldingRegistersResponse: 3]
DEBUG:pymodbus.framer.rtu_framer:Frame advanced, resetting header!!
DEBUG:C:/dev/Bitbucket/gatewaysoftware/MobusRTU-IBMWatson/basic_reproduce/issue.py:Timeout on Slave 1
DEBUG:pymodbus.client.async.asyncio:send: 0x2 0x3 0x0 0x0 0x0 0xa 0xc5 0xfe
DEBUG:pymodbus.transaction:Adding transaction 26
DEBUG:pymodbus.client.async.asyncio:recv: 0x2 0x3 0x14 0x0 0x1 0x0 0x2 0x0 0x3 0x0 0x4 0x0 0x5 0x0 0x6 0x0 0x7 0x0 0x8 0x0 0x9 0x0 0xa 0xdb 0xf3
DEBUG:pymodbus.framer.rtu_framer:Getting Frame - 0x3 0x14 0x0 0x1 0x0 0x2 0x0 0x3 0x0 0x4 0x0 0x5 0x0 0x6 0x0 0x7 0x0 0x8 0x0 0x9 0x0 0xa
DEBUG:pymodbus.factory:Factory Response[ReadHoldingRegistersResponse: 3]
DEBUG:pymodbus.framer.rtu_framer:Frame advanced, resetting header!!
DEBUG:C:/dev/Bitbucket/gatewaysoftware/MobusRTU-IBMWatson/basic_reproduce/issue.py:Timeout on Slave 2
DEBUG:pymodbus.client.async.asyncio:send: 0x3 0x3 0x0 0x0 0x0 0xa 0xc4 0x2f
DEBUG:pymodbus.transaction:Adding transaction 27

pazzarpj · 2018-12-04T00:32:26Z

PR #361 + PR #356
CRC Error: Random CRC error on slave 3. Happens transaction 24.
Recovers from malformed packet and the timeout error.

DEBUG:pymodbus.client.async.asyncio:send: 0x1 0x3 0x0 0x0 0x0 0x1 0x84 0xa
DEBUG:pymodbus.transaction:Adding transaction 22
DEBUG:pymodbus.client.async.asyncio:recv: 0x1 0x3 0x2 0x0 0x1 0x79 0x84
DEBUG:pymodbus.framer.rtu_framer:Getting Frame - 0x3 0x2 0x0 0x1
DEBUG:pymodbus.factory:Factory Response[ReadHoldingRegistersResponse: 3]
DEBUG:pymodbus.framer.rtu_framer:Frame advanced, resetting header!!
DEBUG:pymodbus.client.async.asyncio:send: 0x2 0x3 0x0 0x0 0x0 0xa 0xc5 0xfe
DEBUG:pymodbus.transaction:Adding transaction 23
DEBUG:pymodbus.client.async.asyncio:recv: 0x2 0x3 0x14 0x0 0x1 0x0 0x2 0x0 0x3 0x0 0x4 0x0 0x5 0x0 0x6 0x0 0x7 0x0 0x8 0x0 0x9 0x0 0xa 0xdb 0xf3
DEBUG:pymodbus.framer.rtu_framer:Getting Frame - 0x3 0x14 0x0 0x1 0x0 0x2 0x0 0x3 0x0 0x4 0x0 0x5 0x0 0x6 0x0 0x7 0x0 0x8 0x0 0x9 0x0 0xa
DEBUG:pymodbus.factory:Factory Response[ReadHoldingRegistersResponse: 3]
DEBUG:pymodbus.framer.rtu_framer:Frame advanced, resetting header!!
DEBUG:pymodbus.client.async.asyncio:send: 0x3 0x3 0x0 0x0 0x0 0xa 0xc4 0x2f
DEBUG:pymodbus.transaction:Adding transaction 24
DEBUG:pymodbus.client.async.asyncio:recv: 0x3 0x3 0x14 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0xf8 0x36
DEBUG:pymodbus.framer.rtu_framer:Resetting frame - Current Frame in buffer - 0x3 0x3 0x14 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0xf8 0x36
DEBUG:C:/dev/Bitbucket/gatewaysoftware/MobusRTU-IBMWatson/basic_reproduce/issue.py:Timeout on Slave 3
DEBUG:pymodbus.client.async.asyncio:send: 0x1 0x3 0x0 0x0 0x0 0x1 0x84 0xa
DEBUG:pymodbus.transaction:Adding transaction 25
DEBUG:pymodbus.client.async.asyncio:recv: 0x1 0x3 0x2 0x0 0x1 0x79 0x84
DEBUG:pymodbus.framer.rtu_framer:Getting Frame - 0x3 0x2 0x0 0x1
DEBUG:pymodbus.factory:Factory Response[ReadHoldingRegistersResponse: 3]
DEBUG:pymodbus.framer.rtu_framer:Frame advanced, resetting header!!
DEBUG:pymodbus.client.async.asyncio:send: 0x2 0x3 0x0 0x0 0x0 0xa 0xc5 0xfe
DEBUG:pymodbus.transaction:Adding transaction 26
DEBUG:pymodbus.client.async.asyncio:recv: 0x2 0x3 0x14 0x0 0x1 0x0 0x2 0x0 0x3 0x0 0x4 0x0 0x5 0x0 0x6 0x0 0x7 0x0 0x8 0x0 0x9 0x0 0xa 0xdb 0xf3
DEBUG:pymodbus.framer.rtu_framer:Getting Frame - 0x3 0x14 0x0 0x1 0x0 0x2 0x0 0x3 0x0 0x4 0x0 0x5 0x0 0x6 0x0 0x7 0x0 0x8 0x0 0x9 0x0 0xa
DEBUG:pymodbus.factory:Factory Response[ReadHoldingRegistersResponse: 3]
DEBUG:pymodbus.framer.rtu_framer:Frame advanced, resetting header!!
DEBUG:pymodbus.client.async.asyncio:send: 0x3 0x3 0x0 0x0 0x0 0xa 0xc4 0x2f
DEBUG:pymodbus.transaction:Adding transaction 27
DEBUG:pymodbus.client.async.asyncio:recv: 0x3 0x3 0x14 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x3a 0x1e
DEBUG:pymodbus.framer.rtu_framer:Getting Frame - 0x3 0x14 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0
DEBUG:pymodbus.factory:Factory Response[ReadHoldingRegistersResponse: 3]
DEBUG:pymodbus.framer.rtu_framer:Frame advanced, resetting header!!
DEBUG:pymodbus.client.async.asyncio:send: 0x1 0x3 0x0 0x0 0x0 0x1 0x84 0xa
DEBUG:pymodbus.transaction:Adding transaction 28
DEBUG:pymodbus.client.async.asyncio:recv: 0x1 0x3 0x2 0x0 0x1 0x79 0x84
DEBUG:pymodbus.framer.rtu_framer:Getting Frame - 0x3 0x2 0x0 0x1
DEBUG:pymodbus.factory:Factory Response[ReadHoldingRegistersResponse: 3]
DEBUG:pymodbus.framer.rtu_framer:Frame advanced, resetting header!!
DEBUG:pymodbus.client.async.asyncio:send: 0x2 0x3 0x0 0x0 0x0 0xa 0xc5 0xfe
DEBUG:pymodbus.transaction:Adding transaction 29
DEBUG:pymodbus.client.async.asyncio:recv: 0x2 0x3 0x14 0x0 0x1 0x0 0x2 0x0 0x3 0x0 0x4 0x0 0x5 0x0 0x6 0x0 0x7 0x0 0x8 0x0 0x9 0x0 0xa 0xdb 0xf3
DEBUG:pymodbus.framer.rtu_framer:Getting Frame - 0x3 0x14 0x0 0x1 0x0 0x2 0x0 0x3 0x0 0x4 0x0 0x5 0x0 0x6 0x0 0x7 0x0 0x8 0x0 0x9 0x0 0xa
DEBUG:pymodbus.factory:Factory Response[ReadHoldingRegistersResponse: 3]
DEBUG:pymodbus.framer.rtu_framer:Frame advanced, resetting header!!
DEBUG:pymodbus.client.async.asyncio:send: 0x3 0x3 0x0 0x0 0x0 0xa 0xc4 0x2f
DEBUG:pymodbus.transaction:Adding transaction 30
DEBUG:pymodbus.client.async.asyncio:recv: 0x3 0x3 0x14 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x3a 0x1e
DEBUG:pymodbus.framer.rtu_framer:Getting Frame - 0x3 0x14 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0
DEBUG:pymodbus.factory:Factory Response[ReadHoldingRegistersResponse: 3]
DEBUG:pymodbus.framer.rtu_framer:Frame advanced, resetting header!!
DEBUG:pymodbus.client.async.asyncio:send: 0x1 0x3 0x0 0x0 0x0 0x1 0x84 0xa
DEBUG:pymodbus.transaction:Adding transaction 31
DEBUG:pymodbus.client.async.asyncio:recv: 0x1 0x3 0x2 0x0 0x1 0x79 0x84
DEBUG:pymodbus.framer.rtu_framer:Getting Frame - 0x3 0x2 0x0 0x1
DEBUG:pymodbus.factory:Factory Response[ReadHoldingRegistersResponse: 3]
DEBUG:pymodbus.framer.rtu_framer:Frame advanced, resetting header!!

dhoomakethu · 2018-12-04T03:27:16Z

@pazzarpj Thanks for the PR and the detailed testing, I will give it a try this week and update.

dhoomakethu · 2018-12-06T06:22:27Z

Looks like the changes in this PR is also part of #361 . I will be closing this for the time being.

pazzarpj · 2018-12-06T06:32:45Z

Whoops, looks like for the first PR I used my forked master branch which polluted this PR with the other changes. Sorry.

pazzarpj added 2 commits December 4, 2018 09:05

Fix for pymodbus-dev#356

77abfa9

Reset frame when checkframe fails as it is impossible to know what is a valid start packet if CRC or mid frame is in buffer.

This was referenced Dec 4, 2018

Modbus RTU client never recovers if bad serial line. Filling buffer. #356

Closed

Async Serial Client Cancel Task Error #361

Closed

dhoomakethu closed this Dec 6, 2018

github-actions bot locked as resolved and limited conversation to collaborators Apr 21, 2023

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Fixes for malformed stream #356 #363

Fixes for malformed stream #356 #363

pazzarpj commented Dec 3, 2018

pazzarpj commented Dec 4, 2018

pazzarpj commented Dec 4, 2018 •

edited

Loading

pazzarpj commented Dec 4, 2018

pazzarpj commented Dec 4, 2018

pazzarpj commented Dec 4, 2018 •

edited

Loading

pazzarpj commented Dec 4, 2018 •

edited

Loading

pazzarpj commented Dec 4, 2018

dhoomakethu commented Dec 4, 2018

dhoomakethu commented Dec 6, 2018

pazzarpj commented Dec 6, 2018

Fixes for malformed stream #356 #363

Fixes for malformed stream #356 #363

Conversation

pazzarpj commented Dec 3, 2018

pazzarpj commented Dec 4, 2018

pazzarpj commented Dec 4, 2018 • edited Loading

pazzarpj commented Dec 4, 2018

pazzarpj commented Dec 4, 2018

pazzarpj commented Dec 4, 2018 • edited Loading

pazzarpj commented Dec 4, 2018 • edited Loading

pazzarpj commented Dec 4, 2018

dhoomakethu commented Dec 4, 2018

dhoomakethu commented Dec 6, 2018

pazzarpj commented Dec 6, 2018

pazzarpj commented Dec 4, 2018 •

edited

Loading

pazzarpj commented Dec 4, 2018 •

edited

Loading

pazzarpj commented Dec 4, 2018 •

edited

Loading