ModbusTcpClient - Second Request always fails

[vpetrovych]

Versions

• Python: 3.8.7
• OS: HomeAssistant
• Pymodbus: 2.5.0
• Modbus Hardware (if used): http://www.raut-automatic.kiev.ua/free-programming-controllers/freemax-mini.html

Pymodbus Specific

• Client: tcp - sync

Description

What were you trying, what has happened, what went wrong, and what did you expect?
When trying to send 2nd request, an error is returned
[Connection] ModbusTcpClient(192.168.0.15:502): Connection unexpectedly closed 0.000886 seconds into read of 8 bytes without response from unit before it closed connection

It doesn't matter if I read first input and second holding, or vice versa. It always fails the second request.
Removing the ClearCountersRequest also doesn't help
This worked correctly in Node.JS using jsmodbus package, so I have a feeling there could be a bug here.

Code and Logs

try:
            client = ModbusClient(self.args['modbus_host'], port=self.args['modbus_port'], timeout= 20)
            client.connect()
            self.log('connected')


            # client.connect()
            # self.log('connected 2')

            self.log('read input')
            rq = client.read_input_registers(address=0, count=5)
            self.log(rq)
            self.log(rq.isError())
            # self.log(input_registers.registers)
            # client.close()

            self.log('reset')
            rq = ClearCountersRequest()
            rr = client.execute(rq)
            self.log(rr)
            
            self.log('read holding')
            # client = ModbusClient(self.args['modbus_host'], port=self.args['modbus_port'])
            # client.connect()
            holding_registers = client.read_holding_registers(address=0, count=3)
            # self.log(holding_registers.registers)

            client.close()
            # self.mqtt_publish("homeassistant/bedroom/light", "ON")

        except Exception as inst:
            self.error('Modbus error {}'.format(inst))

            rq = ReadExceptionStatusRequest(unit=255)
            rr = client.execute(rq)
            self.log(rr)
            self.log(rr.isError())

logs

DEBUG:pymodbus.client.sync:Connection to Modbus server established. Socket ('172.30.33.3', 33633)
2021-03-05 12:46:18.023444 INFO vent: connected
2021-03-05 12:46:18.026330 INFO vent: read input
DEBUG:pymodbus.transaction:Current transaction state - IDLE
DEBUG:pymodbus.transaction:Running transaction 1
DEBUG:pymodbus.transaction:SEND: 0x0 0x1 0x0 0x0 0x0 0x6 0x0 0x4 0x0 0x0 0x0 0x5
DEBUG:pymodbus.client.sync:New Transaction state 'SENDING'
DEBUG:pymodbus.transaction:Changing transaction state from 'SENDING' to 'WAITING FOR REPLY'
DEBUG:pymodbus.transaction:Changing transaction state from 'WAITING FOR REPLY' to 'PROCESSING REPLY'
DEBUG:pymodbus.transaction:RECV: 0x0 0x1 0x0 0x0 0x0 0xd 0x0 0x4 0xa 0x0 0xe8 0x0 0xc1 0x5 0xdb 0x0 0x0 0x0 0x0
DEBUG:pymodbus.framer.socket_framer:Processing: 0x0 0x1 0x0 0x0 0x0 0xd 0x0 0x4 0xa 0x0 0xe8 0x0 0xc1 0x5 0xdb 0x0 0x0 0x0 0x0
DEBUG:pymodbus.factory:Factory Response[ReadInputRegistersResponse: 4]
DEBUG:pymodbus.transaction:Adding transaction 1
DEBUG:pymodbus.transaction:Getting transaction 1
DEBUG:pymodbus.transaction:Changing transaction state from 'PROCESSING REPLY' to 'TRANSACTION_COMPLETE'
2021-03-05 12:46:18.102485 INFO vent: ReadInputRegistersResponse (5)
2021-03-05 12:46:18.104008 INFO vent: False
2021-03-05 12:46:18.106786 INFO vent: reset
DEBUG:pymodbus.client.sync:Connection to Modbus server established. Socket ('172.30.33.3', 36917)
DEBUG:pymodbus.transaction:Current transaction state - TRANSACTION_COMPLETE
DEBUG:pymodbus.transaction:Running transaction 2
DEBUG:pymodbus.transaction:SEND: 0x0 0x2 0x0 0x0 0x0 0x6 0x0 0x8 0x0 0xa 0x0 0x0
DEBUG:pymodbus.client.sync:New Transaction state 'SENDING'
DEBUG:pymodbus.transaction:Changing transaction state from 'SENDING' to 'WAITING FOR REPLY'
2021-03-05 12:46:18.318106 INFO vent: Modbus error Modbus Error: [Connection] ModbusTcpClient(192.168.0.15:502): Connection unexpectedly closed 0.000886 seconds into read of 8 bytes without response from unit before it closed connection
DEBUG:pymodbus.client.sync:Connection to Modbus server established. Socket ('172.30.33.3', 45947)
DEBUG:pymodbus.transaction:Current transaction state - WAITING_FOR_REPLY
DEBUG:pymodbus.transaction:Running transaction 3
DEBUG:pymodbus.transaction:SEND: 0x0 0x3 0x0 0x0 0x0 0x2 0xff 0x7
DEBUG:pymodbus.client.sync:New Transaction state 'SENDING'
DEBUG:pymodbus.transaction:Changing transaction state from 'SENDING' to 'WAITING FOR REPLY'
DEBUG:pymodbus.transaction:Changing transaction state from 'WAITING FOR REPLY' to 'PROCESSING REPLY'
DEBUG:pymodbus.transaction:RECV: 0x0 0x3 0x0 0x0 0x0 0x3 0xff 0x87 0x1
DEBUG:pymodbus.framer.socket_framer:Processing: 0x0 0x3 0x0 0x0 0x0 0x3 0xff 0x87 0x1
DEBUG:pymodbus.factory:Factory Response[135]
DEBUG:pymodbus.transaction:Adding transaction 3
DEBUG:pymodbus.transaction:Getting transaction 3
DEBUG:pymodbus.transaction:Changing transaction state from 'PROCESSING REPLY' to 'TRANSACTION_COMPLETE'
2021-03-05 12:46:18.390142 INFO vent: Exception Response(135, 7, IllegalFunction)
2021-03-05 12:46:18.391457 INFO vent: True

[vpetrovych]

To add more information for debugging. The issue is not present in 2.4.0 version.

Code:

        try:
            client = ModbusClient(self.args['modbus_host'], port=self.args['modbus_port'], timeout= 20)
            client.connect()
            self.log('connected')

            self.log('read input')
            input_registers = client.read_input_registers(address=0, count=5)
            self.log(input_registers.registers)
            # self.log(input_registers.registers)
            # client.close()

            # self.log('reset')
            # rq = ClearCountersRequest()
            # rr = client.execute(rq)
            # self.log(rr)
            
            self.log('read holding')
            # client = ModbusClient(self.args['modbus_host'], port=self.args['modbus_port'])
            # client.connect()
            holding_registers = client.read_holding_registers(address=0, count=3)
            self.log(holding_registers.registers)

            client.close()
            # self.mqtt_publish("homeassistant/bedroom/light", "ON")

        except Exception as inst:
            self.error('Modbus error {}'.format(inst))

            rq = ReadExceptionStatusRequest(unit=255)
            rr = client.execute(rq)
            self.log(rr)
            self.log(rr.isError())

Logs:

2021-03-05 13:06:52.247491 INFO vent: connected
2021-03-05 13:06:52.250768 INFO vent: read input
DEBUG:pymodbus.transaction:Current transaction state - IDLE
DEBUG:pymodbus.transaction:Running transaction 1
DEBUG:pymodbus.transaction:SEND: 0x0 0x1 0x0 0x0 0x0 0x6 0x0 0x4 0x0 0x0 0x0 0x5
DEBUG:pymodbus.client.sync:New Transaction state 'SENDING'
DEBUG:pymodbus.transaction:Changing transaction state from 'SENDING' to 'WAITING FOR REPLY'
DEBUG:pymodbus.transaction:Changing transaction state from 'WAITING FOR REPLY' to 'PROCESSING REPLY'
DEBUG:pymodbus.transaction:RECV: 0x0 0x1 0x0 0x0 0x0 0xd 0x0 0x4 0xa 0x0 0xe8 0x0 0xa2 0x5 0xdb 0x0 0x0 0x0 0x0
DEBUG:pymodbus.framer.socket_framer:Processing: 0x0 0x1 0x0 0x0 0x0 0xd 0x0 0x4 0xa 0x0 0xe8 0x0 0xa2 0x5 0xdb 0x0 0x0 0x0 0x0
DEBUG:pymodbus.factory:Factory Response[ReadInputRegistersResponse: 4]
DEBUG:pymodbus.transaction:Adding transaction 1
DEBUG:pymodbus.transaction:Getting transaction 1
DEBUG:pymodbus.transaction:Changing transaction state from 'PROCESSING REPLY' to 'TRANSACTION_COMPLETE'
2021-03-05 13:06:52.317569 INFO vent: [232, 162, 1499, 0, 0]
2021-03-05 13:06:52.320277 INFO vent: read holding
DEBUG:pymodbus.transaction:Current transaction state - TRANSACTION_COMPLETE
DEBUG:pymodbus.transaction:Running transaction 2
DEBUG:pymodbus.transaction:SEND: 0x0 0x2 0x0 0x0 0x0 0x6 0x0 0x3 0x0 0x0 0x0 0x3
DEBUG:pymodbus.client.sync:New Transaction state 'SENDING'
DEBUG:pymodbus.transaction:Changing transaction state from 'SENDING' to 'WAITING FOR REPLY'
DEBUG:pymodbus.transaction:Changing transaction state from 'WAITING FOR REPLY' to 'PROCESSING REPLY'
DEBUG:pymodbus.transaction:RECV: 0x0 0x2 0x0 0x0 0x0 0x9 0x0 0x3 0x6 0x0 0xdc 0x0 0x0 0x0 0x0
DEBUG:pymodbus.framer.socket_framer:Processing: 0x0 0x2 0x0 0x0 0x0 0x9 0x0 0x3 0x6 0x0 0xdc 0x0 0x0 0x0 0x0
DEBUG:pymodbus.factory:Factory Response[ReadHoldingRegistersResponse: 3]
DEBUG:pymodbus.transaction:Adding transaction 2
DEBUG:pymodbus.transaction:Getting transaction 2
DEBUG:pymodbus.transaction:Changing transaction state from 'PROCESSING REPLY' to 'TRANSACTION_COMPLETE'
2021-03-05 13:06:52.387857 INFO vent: [220, 0, 0]

So this is something within 2.5.0 version. Here's the log for the same code in 2.5.0:

EBUG:pymodbus.client.sync:Connection to Modbus server established. Socket ('172.30.33.3', 41631)
2021-03-05 13:09:39.034153 INFO vent: connected
2021-03-05 13:09:39.037313 INFO vent: read input
DEBUG:pymodbus.transaction:Current transaction state - IDLE
DEBUG:pymodbus.transaction:Running transaction 1
DEBUG:pymodbus.transaction:SEND: 0x0 0x1 0x0 0x0 0x0 0x6 0x0 0x4 0x0 0x0 0x0 0x5
DEBUG:pymodbus.client.sync:New Transaction state 'SENDING'
DEBUG:pymodbus.transaction:Changing transaction state from 'SENDING' to 'WAITING FOR REPLY'
DEBUG:pymodbus.transaction:Changing transaction state from 'WAITING FOR REPLY' to 'PROCESSING REPLY'
DEBUG:pymodbus.transaction:RECV: 0x0 0x1 0x0 0x0 0x0 0xd 0x0 0x4 0xa 0x0 0xe8 0x0 0xa2 0x5 0xdb 0x0 0x0 0x0 0x0
DEBUG:pymodbus.framer.socket_framer:Processing: 0x0 0x1 0x0 0x0 0x0 0xd 0x0 0x4 0xa 0x0 0xe8 0x0 0xa2 0x5 0xdb 0x0 0x0 0x0 0x0
DEBUG:pymodbus.factory:Factory Response[ReadInputRegistersResponse: 4]
DEBUG:pymodbus.transaction:Adding transaction 1
DEBUG:pymodbus.transaction:Getting transaction 1
DEBUG:pymodbus.transaction:Changing transaction state from 'PROCESSING REPLY' to 'TRANSACTION_COMPLETE'
2021-03-05 13:09:39.112175 INFO vent: [232, 162, 1499, 0, 0]
2021-03-05 13:09:39.117512 INFO vent: read holding
DEBUG:pymodbus.client.sync:Connection to Modbus server established. Socket ('172.30.33.3', 39143)
DEBUG:pymodbus.transaction:Current transaction state - TRANSACTION_COMPLETE
DEBUG:pymodbus.transaction:Running transaction 2
DEBUG:pymodbus.transaction:SEND: 0x0 0x2 0x0 0x0 0x0 0x6 0x0 0x3 0x0 0x0 0x0 0x3
DEBUG:pymodbus.client.sync:New Transaction state 'SENDING'
DEBUG:pymodbus.transaction:Changing transaction state from 'SENDING' to 'WAITING FOR REPLY'
2021-03-05 13:09:39.320210 INFO vent: Modbus error Modbus Error: [Connection] ModbusTcpClient(192.168.0.15:502): Connection unexpectedly closed 0.000095 seconds into read of 8 bytes without response from unit before it closed connection
DEBUG:pymodbus.client.sync:Connection to Modbus server established. Socket ('172.30.33.3', 40841)
DEBUG:pymodbus.transaction:Current transaction state - WAITING_FOR_REPLY
DEBUG:pymodbus.transaction:Running transaction 3
DEBUG:pymodbus.transaction:SEND: 0x0 0x3 0x0 0x0 0x0 0x2 0xff 0x7
DEBUG:pymodbus.client.sync:New Transaction state 'SENDING'
DEBUG:pymodbus.transaction:Changing transaction state from 'SENDING' to 'WAITING FOR REPLY'
DEBUG:pymodbus.transaction:Changing transaction state from 'WAITING FOR REPLY' to 'PROCESSING REPLY'
DEBUG:pymodbus.transaction:RECV: 0x0 0x3 0x0 0x0 0x0 0x3 0xff 0x87 0x1
DEBUG:pymodbus.framer.socket_framer:Processing: 0x0 0x3 0x0 0x0 0x0 0x3 0xff 0x87 0x1
DEBUG:pymodbus.factory:Factory Response[135]
DEBUG:pymodbus.transaction:Adding transaction 3
DEBUG:pymodbus.transaction:Getting transaction 3
DEBUG:pymodbus.transaction:Changing transaction state from 'PROCESSING REPLY' to 'TRANSACTION_COMPLETE'
2021-03-05 13:09:39.390724 INFO vent: Exception Response(135, 7, IllegalFunction)
2021-03-05 13:09:39.392252 INFO vent: True

[dhoomakethu]

@vpetrovych Can you call the requests in a loop and share the logs please? I am not able to reproduce this on my local setup.
Also please add the formatter to log FORMAT = ('%(asctime)-15s %(threadName)-15s ' '%(levelname)-8s %(module)-15s:%(lineno)-8s %(message)s') to get the timing information.

[dhoomakethu]

Just for your reference

✗ pymodbus.console --verbose tcp --port 5020

----------------------------------------------------------------------------
__________          _____             .___  __________              .__
\______   \___.__. /     \   ____   __| _/  \______   \ ____ ______ |  |
 |     ___<   |  |/  \ /  \ /  _ \ / __ |    |       _// __ \\____ \|  |
 |    |    \___  /    Y    (  <_> ) /_/ |    |    |   \  ___/|  |_> >  |__
 |____|    / ____\____|__  /\____/\____ | /\ |____|_  /\___  >   __/|____/
           \/            \/            \/ \/        \/     \/|__|
                                        v1.3.0 - [pymodbus, version 2.5.0]
----------------------------------------------------------------------------

> client.read_input_registers address=0 count=5
2021-03-05 18:59:41,122 MainThread      DEBUG    sync           :216      Connection to Modbus server established. Socket ('127.0.0.1', 62816)
2021-03-05 18:59:41,122 MainThread      DEBUG    transaction    :139      Current transaction state - IDLE
2021-03-05 18:59:41,122 MainThread      DEBUG    transaction    :144      Running transaction 1
2021-03-05 18:59:41,123 MainThread      DEBUG    transaction    :268      SEND: 0x0 0x1 0x0 0x0 0x0 0x6 0x0 0x4 0x0 0x0 0x0 0x5
2021-03-05 18:59:41,123 MainThread      DEBUG    sync           :76       New Transaction state 'SENDING'
2021-03-05 18:59:41,123 MainThread      DEBUG    transaction    :282      Changing transaction state from 'SENDING' to 'WAITING FOR REPLY'
2021-03-05 18:59:41,124 MainThread      DEBUG    transaction    :369      Changing transaction state from 'WAITING FOR REPLY' to 'PROCESSING REPLY'
2021-03-05 18:59:41,125 MainThread      DEBUG    transaction    :292      RECV: 0x0 0x1 0x0 0x0 0x0 0xd 0x0 0x4 0xa 0x0 0x11 0x0 0x11 0x0 0x11 0x0 0x11 0x0 0x11
2021-03-05 18:59:41,125 MainThread      DEBUG    socket_framer  :147      Processing: 0x0 0x1 0x0 0x0 0x0 0xd 0x0 0x4 0xa 0x0 0x11 0x0 0x11 0x0 0x11 0x0 0x11 0x0 0x11
2021-03-05 18:59:41,125 MainThread      DEBUG    factory        :266      Factory Response[ReadInputRegistersResponse: 4]
2021-03-05 18:59:41,125 MainThread      DEBUG    transaction    :448      Adding transaction 1
2021-03-05 18:59:41,125 MainThread      DEBUG    transaction    :459      Getting transaction 1
2021-03-05 18:59:41,125 MainThread      DEBUG    transaction    :221      Changing transaction state from 'PROCESSING REPLY' to 'TRANSACTION_COMPLETE'
{
    "registers": [
        17,
        17,
        17,
        17,
        17
    ]
}

> client.read_holding_registers address=0 count=3
2021-03-05 19:00:02,377 MainThread      DEBUG    sync           :216      Connection to Modbus server established. Socket ('127.0.0.1', 62820)
2021-03-05 19:00:02,377 MainThread      DEBUG    transaction    :139      Current transaction state - TRANSACTION_COMPLETE
2021-03-05 19:00:02,377 MainThread      DEBUG    transaction    :144      Running transaction 2
2021-03-05 19:00:02,377 MainThread      DEBUG    transaction    :268      SEND: 0x0 0x2 0x0 0x0 0x0 0x6 0x0 0x3 0x0 0x0 0x0 0x3
2021-03-05 19:00:02,378 MainThread      DEBUG    sync           :76       New Transaction state 'SENDING'
2021-03-05 19:00:02,378 MainThread      DEBUG    transaction    :282      Changing transaction state from 'SENDING' to 'WAITING FOR REPLY'
2021-03-05 19:00:02,379 MainThread      DEBUG    transaction    :369      Changing transaction state from 'WAITING FOR REPLY' to 'PROCESSING REPLY'
2021-03-05 19:00:02,379 MainThread      DEBUG    transaction    :292      RECV: 0x0 0x2 0x0 0x0 0x0 0x9 0x0 0x3 0x6 0x0 0x11 0x0 0x11 0x0 0x11
2021-03-05 19:00:02,380 MainThread      DEBUG    socket_framer  :147      Processing: 0x0 0x2 0x0 0x0 0x0 0x9 0x0 0x3 0x6 0x0 0x11 0x0 0x11 0x0 0x11
2021-03-05 19:00:02,380 MainThread      DEBUG    factory        :266      Factory Response[ReadHoldingRegistersResponse: 3]
2021-03-05 19:00:02,380 MainThread      DEBUG    transaction    :448      Adding transaction 2
2021-03-05 19:00:02,380 MainThread      DEBUG    transaction    :459      Getting transaction 2
2021-03-05 19:00:02,380 MainThread      DEBUG    transaction    :221      Changing transaction state from 'PROCESSING REPLY' to 'TRANSACTION_COMPLETE'
{
    "registers": [
        17,
        17,
        17
    ]
}

> client.read_exception_status unit=255
2021-03-05 19:00:27,424 MainThread      DEBUG    sync           :216      Connection to Modbus server established. Socket ('127.0.0.1', 62826)
2021-03-05 19:00:27,425 MainThread      DEBUG    transaction    :139      Current transaction state - TRANSACTION_COMPLETE
2021-03-05 19:00:27,425 MainThread      DEBUG    transaction    :144      Running transaction 3
2021-03-05 19:00:27,425 MainThread      DEBUG    transaction    :268      SEND: 0x0 0x3 0x0 0x0 0x0 0x2 0xff 0x7
2021-03-05 19:00:27,425 MainThread      DEBUG    sync           :76       New Transaction state 'SENDING'
2021-03-05 19:00:27,425 MainThread      DEBUG    transaction    :282      Changing transaction state from 'SENDING' to 'WAITING FOR REPLY'
2021-03-05 19:00:27,426 MainThread      DEBUG    transaction    :369      Changing transaction state from 'WAITING FOR REPLY' to 'PROCESSING REPLY'
2021-03-05 19:00:27,427 MainThread      DEBUG    transaction    :292      RECV: 0x0 0x3 0x0 0x0 0x0 0x3 0xff 0x7 0x0
2021-03-05 19:00:27,427 MainThread      DEBUG    socket_framer  :147      Processing: 0x0 0x3 0x0 0x0 0x0 0x3 0xff 0x7 0x0
2021-03-05 19:00:27,427 MainThread      DEBUG    factory        :266      Factory Response[ReadExceptionStatusResponse: 7]
2021-03-05 19:00:27,427 MainThread      DEBUG    transaction    :448      Adding transaction 3
2021-03-05 19:00:27,427 MainThread      DEBUG    transaction    :459      Getting transaction 3
2021-03-05 19:00:27,427 MainThread      DEBUG    transaction    :221      Changing transaction state from 'PROCESSING REPLY' to 'TRANSACTION_COMPLETE'
{
    "status": 0
}

[aetasoul]

Same problem here reported on stackoverflow.

Code:

import pymodbus     
from pymodbus.client.sync import ModbusTcpClient   
from time import sleep

import logging
FORMAT = ('%(asctime)-15s %(threadName)-15s '
          '%(levelname)-8s %(module)-15s:%(lineno)-8s %(message)s')
logging.basicConfig(format=FORMAT)
log = logging.getLogger()
log.setLevel(logging.DEBUG)

connection = False
data = {}
while True:
        if not connection:
            client = ModbusTcpClient(host="176.219.185.16", port="502")
            connection = client.connect()
            if connection:
                print("connected")
        else:
            if not client.is_socket_open():
                print("connection is broken")    
                connection = False
        data = client.read_holding_registers(address=150,count=10,unit=1).registers
        sleep(2)
        print(data)

pymodbus 2.5.0 LOG

2021-03-11 13:21:06,392 MainThread      DEBUG    sync           :215      Connection to Modbus server established. Socket ('172.17.0.2', 36525)
connected
2021-03-11 13:21:06,393 MainThread      DEBUG    transaction    :138      Current transaction state - IDLE
2021-03-11 13:21:06,393 MainThread      DEBUG    transaction    :143      Running transaction 1
2021-03-11 13:21:06,394 MainThread      DEBUG    transaction    :268      SEND: 0x0 0x1 0x0 0x0 0x0 0x6 0x1 0x3 0x0 0x96 0x0 0xa
2021-03-11 13:21:06,394 MainThread      DEBUG    sync           :76       New Transaction state 'SENDING'
2021-03-11 13:21:06,394 MainThread      DEBUG    transaction    :282      Changing transaction state from 'SENDING' to 'WAITING FOR REPLY'
2021-03-11 13:21:06,543 MainThread      DEBUG    transaction    :369      Changing transaction state from 'WAITING FOR REPLY' to 'PROCESSING REPLY'
2021-03-11 13:21:06,543 MainThread      DEBUG    transaction    :292      RECV: 0x0 0x1 0x0 0x0 0x0 0x17 0x1 0x3 0x14 0xd 0xb3 0xd 0x81 0x0 0x0 0x0 0x0 0xd 0xaa 0x0 0x0 0x1b 0xcc 0xd 0x82 0x1 0xf4 0x1 0x6
2021-03-11 13:21:06,543 MainThread      DEBUG    socket_framer  :147      Processing: 0x0 0x1 0x0 0x0 0x0 0x17 0x1 0x3 0x14 0xd 0xb3 0xd 0x81 0x0 0x0 0x0 0x0 0xd 0xaa 0x0 0x0 0x1b 0xcc 0xd 0x82 0x1 0xf4 0x1 0x6
2021-03-11 13:21:06,544 MainThread      DEBUG    factory        :266      Factory Response[ReadHoldingRegistersResponse: 3]
2021-03-11 13:21:06,544 MainThread      DEBUG    transaction    :448      Adding transaction 1
2021-03-11 13:21:06,545 MainThread      DEBUG    transaction    :459      Getting transaction 1
2021-03-11 13:21:06,545 MainThread      DEBUG    transaction    :221      Changing transaction state from 'PROCESSING REPLY' to 'TRANSACTION_COMPLETE'
[3507, 3457, 0, 0, 3498, 0, 7116, 3458, 500, 262]
connection is broken
2021-03-11 13:21:08,698 MainThread      DEBUG    sync           :215      Connection to Modbus server established. Socket ('172.17.0.2', 33431)
2021-03-11 13:21:08,698 MainThread      DEBUG    transaction    :138      Current transaction state - TRANSACTION_COMPLETE
2021-03-11 13:21:08,698 MainThread      DEBUG    transaction    :143      Running transaction 2
2021-03-11 13:21:08,699 MainThread      DEBUG    transaction    :268      SEND: 0x0 0x2 0x0 0x0 0x0 0x6 0x1 0x3 0x0 0x96 0x0 0xa
2021-03-11 13:21:08,699 MainThread      DEBUG    sync           :76       New Transaction state 'SENDING'
2021-03-11 13:21:08,699 MainThread      DEBUG    transaction    :282      Changing transaction state from 'SENDING' to 'WAITING FOR REPLY'
2021-03-11 13:21:08,861 MainThread      DEBUG    transaction    :369      Changing transaction state from 'WAITING FOR REPLY' to 'PROCESSING REPLY'
2021-03-11 13:21:08,861 MainThread      DEBUG    transaction    :292      RECV: 0x0 0x2 0x0 0x0 0x0 0x17 0x1 0x3 0x14 0xd 0x95 0xd 0x64 0x0 0x0 0x0 0x0 0xd 0x8c 0x0 0x0 0x1b 0xcc 0xd 0x82 0x1 0xf4 0x1 0x6
2021-03-11 13:21:08,861 MainThread      DEBUG    socket_framer  :147      Processing: 0x0 0x2 0x0 0x0 0x0 0x17 0x1 0x3 0x14 0xd 0x95 0xd 0x64 0x0 0x0 0x0 0x0 0xd 0x8c 0x0 0x0 0x1b 0xcc 0xd 0x82 0x1 0xf4 0x1 0x6
2021-03-11 13:21:08,861 MainThread      DEBUG    factory        :266      Factory Response[ReadHoldingRegistersResponse: 3]
2021-03-11 13:21:08,861 MainThread      DEBUG    transaction    :448      Adding transaction 2
2021-03-11 13:21:08,861 MainThread      DEBUG    transaction    :459      Getting transaction 2
2021-03-11 13:21:08,862 MainThread      DEBUG    transaction    :221      Changing transaction state from 'PROCESSING REPLY' to 'TRANSACTION_COMPLETE'

pymodbus 2.4.0 LOG

2021-03-11 13:20:11,372 MainThread      DEBUG    transaction    :117      Current transaction state - IDLE
2021-03-11 13:20:11,373 MainThread      DEBUG    transaction    :122      Running transaction 1
2021-03-11 13:20:11,373 MainThread      DEBUG    transaction    :230      SEND: 0x0 0x1 0x0 0x0 0x0 0x6 0x1 0x3 0x0 0x96 0x0 0xa
2021-03-11 13:20:11,374 MainThread      DEBUG    sync           :75       New Transaction state 'SENDING'
2021-03-11 13:20:11,374 MainThread      DEBUG    transaction    :239      Changing transaction state from 'SENDING' to 'WAITING FOR REPLY'
2021-03-11 13:20:11,511 MainThread      DEBUG    transaction    :319      Changing transaction state from 'WAITING FOR REPLY' to 'PROCESSING REPLY'
2021-03-11 13:20:11,512 MainThread      DEBUG    transaction    :248      RECV: 0x0 0x1 0x0 0x0 0x0 0x17 0x1 0x3 0x14 0xd 0x82 0xd 0x4e 0x0 0x0 0x0 0x0 0xd 0x7a 0x0 0x0 0x1b 0xcc 0xd 0x82 0x1 0xf4 0x1 0x6
2021-03-11 13:20:11,512 MainThread      DEBUG    socket_framer  :147      Processing: 0x0 0x1 0x0 0x0 0x0 0x17 0x1 0x3 0x14 0xd 0x82 0xd 0x4e 0x0 0x0 0x0 0x0 0xd 0x7a 0x0 0x0 0x1b 0xcc 0xd 0x82 0x1 0xf4 0x1 0x6
2021-03-11 13:20:11,512 MainThread      DEBUG    factory        :266      Factory Response[ReadHoldingRegistersResponse: 3]
2021-03-11 13:20:11,512 MainThread      DEBUG    transaction    :398      Adding transaction 1
2021-03-11 13:20:11,513 MainThread      DEBUG    transaction    :409      Getting transaction 1
2021-03-11 13:20:11,513 MainThread      DEBUG    transaction    :204      Changing transaction state from 'PROCESSING REPLY' to 'TRANSACTION_COMPLETE'
[3458, 3406, 0, 0, 3450, 0, 7116, 3458, 500, 262]
2021-03-11 13:20:13,516 MainThread      DEBUG    transaction    :117      Current transaction state - TRANSACTION_COMPLETE
2021-03-11 13:20:13,516 MainThread      DEBUG    transaction    :122      Running transaction 2
2021-03-11 13:20:13,516 MainThread      DEBUG    transaction    :230      SEND: 0x0 0x2 0x0 0x0 0x0 0x6 0x1 0x3 0x0 0x96 0x0 0xa
2021-03-11 13:20:13,516 MainThread      DEBUG    sync           :75       New Transaction state 'SENDING'
2021-03-11 13:20:13,517 MainThread      DEBUG    transaction    :239      Changing transaction state from 'SENDING' to 'WAITING FOR REPLY'
2021-03-11 13:20:13,643 MainThread      DEBUG    transaction    :319      Changing transaction state from 'WAITING FOR REPLY' to 'PROCESSING REPLY'
2021-03-11 13:20:13,643 MainThread      DEBUG    transaction    :248      RECV: 0x0 0x2 0x0 0x0 0x0 0x17 0x1 0x3 0x14 0xd 0x93 0xd 0x60 0x0 0x0 0x0 0x0 0xd 0x8b 0x0 0x0 0x1b 0xcc 0xd 0x82 0x1 0xf4 0x1 0x6
2021-03-11 13:20:13,643 MainThread      DEBUG    socket_framer  :147      Processing: 0x0 0x2 0x0 0x0 0x0 0x17 0x1 0x3 0x14 0xd 0x93 0xd 0x60 0x0 0x0 0x0 0x0 0xd 0x8b 0x0 0x0 0x1b 0xcc 0xd 0x82 0x1 0xf4 0x1 0x6
2021-03-11 13:20:13,643 MainThread      DEBUG    factory        :266      Factory Response[ReadHoldingRegistersResponse: 3]
2021-03-11 13:20:13,644 MainThread      DEBUG    transaction    :398      Adding transaction 2
2021-03-11 13:20:13,644 MainThread      DEBUG    transaction    :409      Getting transaction 2
2021-03-11 13:20:13,644 MainThread      DEBUG    transaction    :204      Changing transaction state from 'PROCESSING REPLY' to 'TRANSACTION_COMPLETE'
[3475, 3424, 0, 0, 3467, 0, 7116, 3458, 500, 262]
2021-03-11 13:20:15,647 MainThread      DEBUG    transaction    :117      Current transaction state - TRANSACTION_COMPLETE
2021-03-11 13:20:15,647 MainThread      DEBUG    transaction    :122      Running transaction 3
2021-03-11 13:20:15,648 MainThread      DEBUG    transaction    :230      SEND: 0x0 0x3 0x0 0x0 0x0 0x6 0x1 0x3 0x0 0x96 0x0 0xa
2021-03-11 13:20:15,648 MainThread      DEBUG    sync           :75       New Transaction state 'SENDING'
2021-03-11 13:20:15,648 MainThread      DEBUG    transaction    :239      Changing transaction state from 'SENDING' to 'WAITING FOR REPLY'
2021-03-11 13:20:15,756 MainThread      DEBUG    transaction    :319      Changing transaction state from 'WAITING FOR REPLY' to 'PROCESSING REPLY'
2021-03-11 13:20:15,756 MainThread      DEBUG    transaction    :248      RECV: 0x0 0x3 0x0 0x0 0x0 0x17 0x1 0x3 0x14 0xd 0x8d 0xd 0x5b 0x0 0x0 0x0 0x0 0xd 0x87 0x0 0x0 0x1b 0xcc 0xd 0x82 0x1 0xf4 0x1 0x6
2021-03-11 13:20:15,756 MainThread      DEBUG    socket_framer  :147      Processing: 0x0 0x3 0x0 0x0 0x0 0x17 0x1 0x3 0x14 0xd 0x8d 0xd 0x5b 0x0 0x0 0x0 0x0 0xd 0x87 0x0 0x0 0x1b 0xcc 0xd 0x82 0x1 0xf4 0x1 0x6
2021-03-11 13:20:15,757 MainThread      DEBUG    factory        :266      Factory Response[ReadHoldingRegistersResponse: 3]
2021-03-11 13:20:15,757 MainThread      DEBUG    transaction    :398      Adding transaction 3
2021-03-11 13:20:15,757 MainThread      DEBUG    transaction    :409      Getting transaction 3
2021-03-11 13:20:15,757 MainThread      DEBUG    transaction    :204      Changing transaction state from 'PROCESSING REPLY' to 'TRANSACTION_COMPLETE'

[dhoomakethu]

@aetasoul and @vpetrovych Refer #614 . This is a basically because 2.5.0 closes connection on each read/write and opens the connection again on the next transaction. If this connect/disconnect is too quick and if the slave is not happy or is still in the process of cleaning up previous connection you get the connection refused. The workaround is to introduce a small sleep between the reads to get the things rolling as expected

[aetasoul]

Has you can see in the code there is a sleep of two seconds:

while True:
        if not connection:
            client = ModbusTcpClient(host="176.219.185.16", port="502")
            connection = client.connect()
            if connection:
                print("connected")
        else:
            if not client.is_socket_open():
                print("connection is broken")    
                connection = False
        data = client.read_holding_registers(address=150,count=10,unit=1).registers
        sleep(2)
        print(data)

Just to be sure that the problem is not here, I add infinite sleep in the code:

import pymodbus     
from pymodbus.client.sync import ModbusTcpClient   
from time import sleep

import logging
FORMAT = ('%(asctime)-15s %(threadName)-15s '
          '%(levelname)-8s %(module)-15s:%(lineno)-8s %(message)s')
logging.basicConfig(format=FORMAT)
log = logging.getLogger()
log.setLevel(logging.DEBUG)

connection = False
data = {}
while True:
    sleep(1)
    if not connection:
        sleep(1)
        client = ModbusTcpClient(host="176.219.185.16", port="502")
        sleep(1)
        connection = client.connect()
        sleep(1)
        if connection:
            sleep(1)
            print("connected")
        sleep(1)
    else:
        sleep(1)
        if not client.is_socket_open():
            sleep(1)
            print("connection is broken")
            sleep(1)
            connection = False
    
    sleep(2)
    data = client.read_holding_registers(address=150,count=10,unit=1).registers
    sleep(2)
    print(data)

LOG:

2021-03-11 14:24:47,716 MainThread      DEBUG    sync           :215      Connection to Modbus server established. Socket ('172.17.0.2', 58151)
connected
2021-03-11 14:24:52,722 MainThread      DEBUG    transaction    :138      Current transaction state - IDLE
2021-03-11 14:24:52,722 MainThread      DEBUG    transaction    :143      Running transaction 1
2021-03-11 14:24:52,723 MainThread      DEBUG    transaction    :268      SEND: 0x0 0x1 0x0 0x0 0x0 0x6 0x1 0x3 0x0 0x96 0x0 0xa
2021-03-11 14:24:52,723 MainThread      DEBUG    sync           :76       New Transaction state 'SENDING'
2021-03-11 14:24:52,723 MainThread      DEBUG    transaction    :282      Changing transaction state from 'SENDING' to 'WAITING FOR REPLY'
2021-03-11 14:24:52,836 MainThread      DEBUG    transaction    :369      Changing transaction state from 'WAITING FOR REPLY' to 'PROCESSING REPLY'
2021-03-11 14:24:52,836 MainThread      DEBUG    transaction    :292      RECV: 0x0 0x1 0x0 0x0 0x0 0x17 0x1 0x3 0x14 0xd 0xf1 0xd 0xa0 0x0 0x0 0x0 0x0 0xd 0xdb 0x0 0x0 0x1b 0xcc 0xd 0xc4 0x1 0xf4 0x1 0x6
2021-03-11 14:24:52,836 MainThread      DEBUG    socket_framer  :147      Processing: 0x0 0x1 0x0 0x0 0x0 0x17 0x1 0x3 0x14 0xd 0xf1 0xd 0xa0 0x0 0x0 0x0 0x0 0xd 0xdb 0x0 0x0 0x1b 0xcc 0xd 0xc4 0x1 0xf4 0x1 0x6
2021-03-11 14:24:52,837 MainThread      DEBUG    factory        :266      Factory Response[ReadHoldingRegistersResponse: 3]
2021-03-11 14:24:52,837 MainThread      DEBUG    transaction    :448      Adding transaction 1
2021-03-11 14:24:52,837 MainThread      DEBUG    transaction    :459      Getting transaction 1
2021-03-11 14:24:52,837 MainThread      DEBUG    transaction    :221      Changing transaction state from 'PROCESSING REPLY' to 'TRANSACTION_COMPLETE'
[3569, 3488, 0, 0, 3547, 0, 7116, 3524, 500, 262]
connection is broken
2021-03-11 14:25:00,962 MainThread      DEBUG    sync           :215      Connection to Modbus server established. Socket ('172.17.0.2', 49661)
2021-03-11 14:25:00,962 MainThread      DEBUG    transaction    :138      Current transaction state - TRANSACTION_COMPLETE
2021-03-11 14:25:00,963 MainThread      DEBUG    transaction    :143      Running transaction 2
2021-03-11 14:25:00,963 MainThread      DEBUG    transaction    :268      SEND: 0x0 0x2 0x0 0x0 0x0 0x6 0x1 0x3 0x0 0x96 0x0 0xa
2021-03-11 14:25:00,963 MainThread      DEBUG    sync           :76       New Transaction state 'SENDING'
2021-03-11 14:25:00,963 MainThread      DEBUG    transaction    :282      Changing transaction state from 'SENDING' to 'WAITING FOR REPLY'
2021-03-11 14:25:01,078 MainThread      DEBUG    transaction    :369      Changing transaction state from 'WAITING FOR REPLY' to 'PROCESSING REPLY'
2021-03-11 14:25:01,078 MainThread      DEBUG    transaction    :292      RECV: 0x0 0x2 0x0 0x0 0x0 0x17 0x1 0x3 0x14 0xd 0xfc 0xd 0xa8 0x0 0x0 0x0 0x0 0xd 0xe3 0x0 0x0 0x1b 0xcc 0xd 0xc4 0x1 0xf4 0x1 0x6
2021-03-11 14:25:01,079 MainThread      DEBUG    socket_framer  :147      Processing: 0x0 0x2 0x0 0x0 0x0 0x17 0x1 0x3 0x14 0xd 0xfc 0xd 0xa8 0x0 0x0 0x0 0x0 0xd 0xe3 0x0 0x0 0x1b 0xcc 0xd 0xc4 0x1 0xf4 0x1 0x6
2021-03-11 14:25:01,079 MainThread      DEBUG    factory        :266      Factory Response[ReadHoldingRegistersResponse: 3]
2021-03-11 14:25:01,079 MainThread      DEBUG    transaction    :448      Adding transaction 2
2021-03-11 14:25:01,079 MainThread      DEBUG    transaction    :459      Getting transaction 2
2021-03-11 14:25:01,079 MainThread      DEBUG    transaction    :221      Changing transaction state from 'PROCESSING REPLY' to 'TRANSACTION_COMPLETE'
[3580, 3496, 0, 0, 3555, 0, 7116, 3524, 500, 262]
2021-03-11 14:25:06,199 MainThread      DEBUG    sync           :215      Connection to Modbus server established. Socket ('172.17.0.2', 37269)
connected
2021-03-11 14:25:11,206 MainThread      DEBUG    transaction    :138      Current transaction state - IDLE
2021-03-11 14:25:11,207 MainThread      DEBUG    transaction    :143      Running transaction 1
2021-03-11 14:25:11,207 MainThread      DEBUG    transaction    :268      SEND: 0x0 0x1 0x0 0x0 0x0 0x6 0x1 0x3 0x0 0x96 0x0 0xa
2021-03-11 14:25:11,207 MainThread      DEBUG    sync           :76       New Transaction state 'SENDING'
2021-03-11 14:25:11,207 MainThread      DEBUG    transaction    :282      Changing transaction state from 'SENDING' to 'WAITING FOR REPLY'
2021-03-11 14:25:11,334 MainThread      DEBUG    transaction    :369      Changing transaction state from 'WAITING FOR REPLY' to 'PROCESSING REPLY'
2021-03-11 14:25:11,334 MainThread      DEBUG    transaction    :292      RECV: 0x0 0x1 0x0 0x0 0x0 0x17 0x1 0x3 0x14 0xe 0x8 0xd 0xaf 0x0 0x0 0x0 0x0 0xd 0xef 0x0 0x0 0x1b 0xcc 0xd 0xc4 0x1 0xf4 0x1 0x6
2021-03-11 14:25:11,334 MainThread      DEBUG    socket_framer  :147      Processing: 0x0 0x1 0x0 0x0 0x0 0x17 0x1 0x3 0x14 0xe 0x8 0xd 0xaf 0x0 0x0 0x0 0x0 0xd 0xef 0x0 0x0 0x1b 0xcc 0xd 0xc4 0x1 0xf4 0x1 0x6
2021-03-11 14:25:11,334 MainThread      DEBUG    factory        :266      Factory Response[ReadHoldingRegistersResponse: 3]
2021-03-11 14:25:11,334 MainThread      DEBUG    transaction    :448      Adding transaction 1
2021-03-11 14:25:11,335 MainThread      DEBUG    transaction    :459      Getting transaction 1
2021-03-11 14:25:11,335 MainThread      DEBUG    transaction    :221      Changing transaction state from 'PROCESSING REPLY' to 'TRANSACTION_COMPLETE'
[3592, 3503, 0, 0, 3567, 0, 7116, 3524, 500, 262]
connection is broken

[dhoomakethu]

@aetasoul can you share the specs for your modbus slave? Also with pymodbus 2.4.0, if you explictly close the connection after each read what is the behaviour ? can you share the logs please ?

....
data = client.read_holding_registers(address=150,count=10,unit=1).registers
client.close()

[aetasoul]

Specs: let me check if I can find it

With pymodbus 2.4.0 if I close the connection after the read the problem is the same as the 2.5.0. But it seems to not be a delay issue, I set the sleep to 10 seconds

data = client.read_holding_registers(address=150,count=10,unit=1).registers
client.close()
sleep(10)

LOG:

connected
2021-03-11 14:34:11,144 MainThread      DEBUG    transaction    :117      Current transaction state - IDLE
2021-03-11 14:34:11,145 MainThread      DEBUG    transaction    :122      Running transaction 1
2021-03-11 14:34:11,146 MainThread      DEBUG    transaction    :230      SEND: 0x0 0x1 0x0 0x0 0x0 0x6 0x1 0x3 0x0 0x96 0x0 0xa
2021-03-11 14:34:11,146 MainThread      DEBUG    sync           :75       New Transaction state 'SENDING'
2021-03-11 14:34:11,146 MainThread      DEBUG    transaction    :239      Changing transaction state from 'SENDING' to 'WAITING FOR REPLY'
2021-03-11 14:34:11,342 MainThread      DEBUG    transaction    :319      Changing transaction state from 'WAITING FOR REPLY' to 'PROCESSING REPLY'
2021-03-11 14:34:11,343 MainThread      DEBUG    transaction    :248      RECV: 0x0 0x1 0x0 0x0 0x0 0x17 0x1 0x3 0x14 0xe 0x15 0xd 0xcc 0x0 0x0 0x0 0x0 0xe 0x2 0x0 0x0 0x1b 0xcc 0xd 0xd5 0x1 0xf4 0x1 0x6
2021-03-11 14:34:11,343 MainThread      DEBUG    socket_framer  :147      Processing: 0x0 0x1 0x0 0x0 0x0 0x17 0x1 0x3 0x14 0xe 0x15 0xd 0xcc 0x0 0x0 0x0 0x0 0xe 0x2 0x0 0x0 0x1b 0xcc 0xd 0xd5 0x1 0xf4 0x1 0x6
2021-03-11 14:34:11,343 MainThread      DEBUG    factory        :266      Factory Response[ReadHoldingRegistersResponse: 3]
2021-03-11 14:34:11,343 MainThread      DEBUG    transaction    :398      Adding transaction 1
2021-03-11 14:34:11,343 MainThread      DEBUG    transaction    :409      Getting transaction 1
2021-03-11 14:34:11,344 MainThread      DEBUG    transaction    :204      Changing transaction state from 'PROCESSING REPLY' to 'TRANSACTION_COMPLETE'
[3605, 3532, 0, 0, 3586, 0, 7116, 3541, 500, 262]
connection is broken
2021-03-11 14:34:13,591 MainThread      DEBUG    transaction    :117      Current transaction state - TRANSACTION_COMPLETE
2021-03-11 14:34:13,591 MainThread      DEBUG    transaction    :122      Running transaction 2
2021-03-11 14:34:13,591 MainThread      DEBUG    transaction    :230      SEND: 0x0 0x2 0x0 0x0 0x0 0x6 0x1 0x3 0x0 0x96 0x0 0xa
2021-03-11 14:34:13,591 MainThread      DEBUG    sync           :75       New Transaction state 'SENDING'
2021-03-11 14:34:13,591 MainThread      DEBUG    transaction    :239      Changing transaction state from 'SENDING' to 'WAITING FOR REPLY'
2021-03-11 14:34:13,831 MainThread      DEBUG    transaction    :319      Changing transaction state from 'WAITING FOR REPLY' to 'PROCESSING REPLY'
2021-03-11 14:34:13,831 MainThread      DEBUG    transaction    :248      RECV: 0x0 0x2 0x0 0x0 0x0 0x17 0x1 0x3 0x14 0xd 0xf0 0xd 0xa7 0x0 0x0 0x0 0x0 0xd 0xda 0x0 0x0 0x1b 0xcc 0xd 0xd5 0x1 0xf4 0x1 0x6
2021-03-11 14:34:13,831 MainThread      DEBUG    socket_framer  :147      Processing: 0x0 0x2 0x0 0x0 0x0 0x17 0x1 0x3 0x14 0xd 0xf0 0xd 0xa7 0x0 0x0 0x0 0x0 0xd 0xda 0x0 0x0 0x1b 0xcc 0xd 0xd5 0x1 0xf4 0x1 0x6
2021-03-11 14:34:13,831 MainThread      DEBUG    factory        :266      Factory Response[ReadHoldingRegistersResponse: 3]
2021-03-11 14:34:13,831 MainThread      DEBUG    transaction    :398      Adding transaction 2
2021-03-11 14:34:13,831 MainThread      DEBUG    transaction    :409      Getting transaction 2
2021-03-11 14:34:13,832 MainThread      DEBUG    transaction    :204      Changing transaction state from 'PROCESSING REPLY' to 'TRANSACTION_COMPLETE'
[3568, 3495, 0, 0, 3546, 0, 7116, 3541, 500, 262]
connected
2021-03-11 14:34:16,093 MainThread      DEBUG    transaction    :117      Current transaction state - IDLE
2021-03-11 14:34:16,093 MainThread      DEBUG    transaction    :122      Running transaction 1
2021-03-11 14:34:16,093 MainThread      DEBUG    transaction    :230      SEND: 0x0 0x1 0x0 0x0 0x0 0x6 0x1 0x3 0x0 0x96 0x0 0xa
2021-03-11 14:34:16,093 MainThread      DEBUG    sync           :75       New Transaction state 'SENDING'
2021-03-11 14:34:16,093 MainThread      DEBUG    transaction    :239      Changing transaction state from 'SENDING' to 'WAITING FOR REPLY'
2021-03-11 14:34:16,207 MainThread      DEBUG    transaction    :319      Changing transaction state from 'WAITING FOR REPLY' to 'PROCESSING REPLY'
2021-03-11 14:34:16,208 MainThread      DEBUG    transaction    :248      RECV: 0x0 0x1 0x0 0x0 0x0 0x17 0x1 0x3 0x14 0xe 0xa 0xd 0xc4 0x0 0x0 0x0 0x0 0xd 0xf7 0x0 0x0 0x1b 0xcc 0xd 0xd5 0x1 0xf4 0x1 0x6
2021-03-11 14:34:16,208 MainThread      DEBUG    socket_framer  :147      Processing: 0x0 0x1 0x0 0x0 0x0 0x17 0x1 0x3 0x14 0xe 0xa 0xd 0xc4 0x0 0x0 0x0 0x0 0xd 0xf7 0x0 0x0 0x1b 0xcc 0xd 0xd5 0x1 0xf4 0x1 0x6
2021-03-11 14:34:16,208 MainThread      DEBUG    factory        :266      Factory Response[ReadHoldingRegistersResponse: 3]
2021-03-11 14:34:16,208 MainThread      DEBUG    transaction    :398      Adding transaction 1
2021-03-11 14:34:16,208 MainThread      DEBUG    transaction    :409      Getting transaction 1
2021-03-11 14:34:16,209 MainThread      DEBUG    transaction    :204      Changing transaction state from 'PROCESSING REPLY' to 'TRANSACTION_COMPLETE'
[3594, 3524, 0, 0, 3575, 0, 7116, 3541, 500, 262]
connection is broken
2021-03-11 14:34:18,325 MainThread      DEBUG    transaction    :117      Current transaction state - TRANSACTION_COMPLETE
2021-03-11 14:34:18,325 MainThread      DEBUG    transaction    :122      Running transaction 2
2021-03-11 14:34:18,325 MainThread      DEBUG    transaction    :230      SEND: 0x0 0x2 0x0 0x0 0x0 0x6 0x1 0x3 0x0 0x96 0x0 0xa
2021-03-11 14:34:18,325 MainThread      DEBUG    sync           :75       New Transaction state 'SENDING'
2021-03-11 14:34:18,325 MainThread      DEBUG    transaction    :239      Changing transaction state from 'SENDING' to 'WAITING FOR REPLY'
2021-03-11 14:34:18,518 MainThread      DEBUG    transaction    :319      Changing transaction state from 'WAITING FOR REPLY' to 'PROCESSING REPLY'
2021-03-11 14:34:18,519 MainThread      DEBUG    transaction    :248      RECV: 0x0 0x2 0x0 0x0 0x0 0x17 0x1 0x3 0x14 0xe 0x1 0xd 0xba 0x0 0x0 0x0 0x0 0xd 0xee 0x0 0x0 0x1b 0xcc 0xd 0xd5 0x1 0xf4 0x1 0x6
2021-03-11 14:34:18,519 MainThread      DEBUG    socket_framer  :147      Processing: 0x0 0x2 0x0 0x0 0x0 0x17 0x1 0x3 0x14 0xe 0x1 0xd 0xba 0x0 0x0 0x0 0x0 0xd 0xee 0x0 0x0 0x1b 0xcc 0xd 0xd5 0x1 0xf4 0x1 0x6
2021-03-11 14:34:18,519 MainThread      DEBUG    factory        :266      Factory Response[ReadHoldingRegistersResponse: 3]
2021-03-11 14:34:18,519 MainThread      DEBUG    transaction    :398      Adding transaction 2
2021-03-11 14:34:18,520 MainThread      DEBUG    transaction    :409      Getting transaction 2
2021-03-11 14:34:18,520 MainThread      DEBUG    transaction    :204      Changing transaction state from 'PROCESSING REPLY' to 'TRANSACTION_COMPLETE'
[3585, 3514, 0, 0, 3566, 0, 7116, 3541, 500, 262]
connected
2021-03-11 14:34:20,664 MainThread      DEBUG    transaction    :117      Current transaction state - IDLE
2021-03-11 14:34:20,665 MainThread      DEBUG    transaction    :122      Running transaction 1
2021-03-11 14:34:20,665 MainThread      DEBUG    transaction    :230      SEND: 0x0 0x1 0x0 0x0 0x0 0x6 0x1 0x3 0x0 0x96 0x0 0xa
2021-03-11 14:34:20,665 MainThread      DEBUG    sync           :75       New Transaction state 'SENDING'
2021-03-11 14:34:20,665 MainThread      DEBUG    transaction    :239      Changing transaction state from 'SENDING' to 'WAITING FOR REPLY'
2021-03-11 14:34:20,782 MainThread      DEBUG    transaction    :319      Changing transaction state from 'WAITING FOR REPLY' to 'PROCESSING REPLY'
2021-03-11 14:34:20,782 MainThread      DEBUG    transaction    :248      RECV: 0x0 0x1 0x0 0x0 0x0 0x17 0x1 0x3 0x14 0xe 0x9 0xd 0xc0 0x0 0x0 0x0 0x0 0xd 0xf6 0x0 0x0 0x1b 0xcc 0xd 0xd5 0x1 0xf4 0x1 0x6
2021-03-11 14:34:20,782 MainThread      DEBUG    socket_framer  :147      Processing: 0x0 0x1 0x0 0x0 0x0 0x17 0x1 0x3 0x14 0xe 0x9 0xd 0xc0 0x0 0x0 0x0 0x0 0xd 0xf6 0x0 0x0 0x1b 0xcc 0xd 0xd5 0x1 0xf4 0x1 0x6
2021-03-11 14:34:20,782 MainThread      DEBUG    factory        :266      Factory Response[ReadHoldingRegistersResponse: 3]
2021-03-11 14:34:20,783 MainThread      DEBUG    transaction    :398      Adding transaction 1
2021-03-11 14:34:20,783 MainThread      DEBUG    transaction    :409      Getting transaction 1
2021-03-11 14:34:20,783 MainThread      DEBUG    transaction    :204      Changing transaction state from 'PROCESSING REPLY' to 'TRANSACTION_COMPLETE'

[dhoomakethu]

@aetasoul Thanks for the experiments, looks like the slave doesn't like the disconnections. Let me make the disconnects optional after a succesfull read. You can expect 2.5.1rc1 in sometime with a patch.

[dhoomakethu]

@aetasoul @vpetrovych
Please give a try with 2.5.1rc1 .
Release notes: https://github.com/riptideio/pymodbus/releases/tag/v2.5.1rc1
Pypi: https://pypi.org/project/pymodbus/2.5.1rc1/