0

Sometimes I get an error response immediately when I read from a Modbus device at the first time, but when I try again this responded as the expected result.

This is the error message at first time:

pymodbus.exceptions.ModbusIOException(pymodbus.exceptions.InvalidMessageReceivedException('Incomplete message received, expected at least 8 bytes (0 received)'), 3)

Here's the simplified snippet code in IPython console:

In [1]: from pymodbus.client.sync import ModbusTcpClient
In [2]: cli = ModbusTcpClient('192.168.1.152', port=502)
In [3]: cli.connect()
Out[3]: True
In [4]: req = cli.read_holding_registers(0x1e, 2, unit=21)  # First try.
In [5]: req.isError()
Out[5]: True
In [6]: req
Out[6]: pymodbus.exceptions.ModbusIOException(pymodbus.exceptions.InvalidMessageReceivedException('Incomplete message received, expected at least 8 bytes (0 received)'), 3)
In [7]: req = cli.read_holding_registers(0x1e, 2, unit=21)  # Second try.
In [8]: req.isError()
Out[8]: False
In [9]: req.registers  # As expected.
Out[9]: [16091, 15697]

What's the reason?


[UPDATE]:

I activated the ModbusClient logging:

import logging
from pymodbus.client.sync import ModbusTcpClient as ModbusClient

logging.basicConfig()
log = logging.getLogger()
log.setLevel(logging.DEBUG)

client = ModbusClient('192.168.1.152', port=502)
client.connect() 

print('First Try: ')
res = client.read_holding_registers(0x1e, 2, unit=21)
print('isError = {}'.format(res.isError()))

print('Second Try: ')
res = client.read_holding_registers(0x1e, 2, unit=21)
print('isError = {}'.format(res.isError()))

client.close() 

Out:

First Try: 
DEBUG:pymodbus.transaction:Current transaction state - IDLE
DEBUG:pymodbus.transaction:Running transaction 1
DEBUG:pymodbus.transaction:SEND: 0x0 0x1 0x0 0x0 0x0 0x6 0x15 0x3 0x0 0x1e 0x0 0x2
DEBUG:pymodbus.client.sync:New Transaction state 'SENDING'
DEBUG:pymodbus.transaction:Changing transaction state from 'SENDING' to 'WAITING FOR REPLY'
DEBUG:pymodbus.transaction:Transaction failed. (Modbus Error: [Invalid Message] Incomplete message received, expected at least 8 bytes (0 received)) 
DEBUG:pymodbus.framer.socket_framer:Processing: 
DEBUG:pymodbus.transaction:Getting transaction 1
DEBUG:pymodbus.transaction:Changing transaction state from 'PROCESSING REPLY' to 'TRANSACTION_COMPLETE'
isError = True
Second Try: 
DEBUG:pymodbus.transaction:Current transaction state - TRANSACTION_COMPLETE
DEBUG:pymodbus.transaction:Running transaction 2
DEBUG:pymodbus.transaction:SEND: 0x0 0x2 0x0 0x0 0x0 0x6 0x15 0x3 0x0 0x1e 0x0 0x2
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 0x7 0x15 0x3 0x4 0x3f 0x99 0x8 0xe8
DEBUG:pymodbus.framer.socket_framer:Processing: 0x0 0x2 0x0 0x0 0x0 0x7 0x15 0x3 0x4 0x3f 0x99 0x8 0xe8
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'
isError = False

As you can see, on the first try I got an error but on the second try, I got a proper result.

Benyamin Jafari
  • 27,880
  • 26
  • 135
  • 150
  • It could be that your slave is slow to process the incoming requests. You can also set read timeout on your client and see if that helps. Some logs would be helpful to analyze. – Sanju Nov 21 '18 at 02:33
  • @Sanju The timeout is set to 3 sec as default, but at the first try, it doesn't wait for the timeout, and immediately throw a result that has an error. The error log in the above code has been shown. – Benyamin Jafari Nov 21 '18 at 19:58
  • I mean the transaction logs not just the error message and does this happen with all the slaves or just one model of slave you are having? – Sanju Nov 22 '18 at 06:05
  • @Sanju ok I will check it. – Benyamin Jafari Nov 22 '18 at 06:06
  • @Sanju I updated my answer with the Modbus slave logging. – Benyamin Jafari Nov 26 '18 at 05:53
  • There is no response received for the first transaction with in the given read timeout and hence the error. This could be just an issue with the particular slave you are having. – Sanju Nov 26 '18 at 07:19
  • @Sanju Is there any approach to pass a retries value when I want to create a `.ModbusClient()` object by its argument or anything else? – Benyamin Jafari Jan 19 '21 at 12:07
  • You can use `retries` kwarg to set the retry count. Refer https://github.com/riptideio/pymodbus/blob/efb90fb05882d606933a97435dd37ae87ead5449/pymodbus/transaction.py#L69 – Sanju Jan 21 '21 at 03:36
  • @Sanju Thank you for your response. I used to use `from pymodbus.constants import Defaults` to set retries through `Defaults.Retries = 2, Defaults.RetryOnEmpty = True` and I didn't know there is a `kwarg` for this purpose. – Benyamin Jafari Jan 21 '21 at 06:16
  • @Sanju But I have another question, is this `retires` applies to connect method or to read methods only? In fact, I have a modbus device which I sometimes have trouble with its connection, and I implemented a reconnection in my code if it missed. But the strange thing is that I have no problem to connect to that device in Windows, and the problem is in Linux OS only which I solved it by some reconnections ... – Benyamin Jafari Jan 21 '21 at 06:20
  • 1
    its for the reads, connects needs to be handled manually – Sanju Jan 21 '21 at 07:44

2 Answers2

1

I had the same issue on a Keba heatpump controller. As mentioned by other, my problem was solved by increasing the timeout to 10 seconds, in your example by

client = ModbusClient('192.168.1.152', port=502, timeout=10)

10 seconds had for me some margin, I observed in wireshark always around 5 seconds. Starting from the second request, the responses always come easily within fractions of a second.

The reason given by my heatpump vendor was that the controller is short on memory and the modbus server is only started at the first incoming request for a connection.

@pymodbus developers: I suggest to increase the Default.timeout to 10 seconds.

RDorsch
  • 11
  • 2
  • The timeout is set to 3 sec as default, but at the first try, it doesn't wait for the timeout, and immediately throw a result that has an error even with the `timout=10` produce exactly the same result. But in the second try, I haven't any problem. – Benyamin Jafari Nov 29 '18 at 07:05
  • That is clearly different from what I see here. With 3 seconds timeout, my first request always fails, with 10 seconds they pass. This applies both to pymodbus 2.1.0 and 1.5.2. Are you using an outdated version of pymodbus? – RDorsch Nov 30 '18 at 19:05
  • I test it with pymodbus 1.5.2 and 2.1.0 also. – Benyamin Jafari Nov 30 '18 at 19:20
  • 1
    Weird, I am running out of ideas. Wireshark helped me to debug my problem. This might help you, in particular you should be able to see, when the response from the server arrives.... – RDorsch Dec 01 '18 at 20:44
0

To make a client-client connection filling the kwarg source_address was needed, but there is no way to unbind the port, socket.setsockopt(socket.SOL_SOCKET, socket.SO_REUSEADDR, 1) needs to be done before bind(), this means that after a execution the os needs to catch the port to have it bindable again.

from pymodbus.client.sync import ModbusTcpClient
import logging

logging.basicConfig()
log = logging.getLogger()
log.setLevel(logging.DEBUG)

def pymodbus_tcp_client(address, port):
    client = ModbusTcpClient(address, port=port, source_address=(address, port))
    client.set_debug(True)
    client.connect()
    if client.is_socket_open():
        client.socket.setsockopt(65535, 4, 1)   # Adds no effect (!)
        res_1 = client.read_holding_registers(0x1e, 5, unit=21)
        res_2 = client.write_register(0x1e, 10, unit=21)
        res_3 = client.read_holding_registers(0x1e, 5, unit=21)
        print(res_1.registers, res_2, res_3.registers)

    client.close()

if __name__ == '__main__':
    pymodbus_tcp_client('127.0.0.1', 5020)

SrPanda
  • 854
  • 1
  • 5
  • 9