Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Issue with read_input_registers in version 2.1.0 #353

Closed
mpf82 opened this issue Oct 16, 2018 · 19 comments
Closed

Issue with read_input_registers in version 2.1.0 #353

mpf82 opened this issue Oct 16, 2018 · 19 comments

Comments

@mpf82
Copy link
Contributor

mpf82 commented Oct 16, 2018

Versions

  • Python: 3.4, 64
  • OS: Windows 10, 64
  • Pymodbus: 2.1.0
  • Modbus Hardware (if used): PM-3133

Pymodbus Specific

  • Client: rtu - sync

Description

Since upgrading to version 2.1.0 I cannot read the whole input registers as I could with other versions.
Instead I receive an error:

{'message': '[Input/Output] No Response received from the remote unit/Unable to decode response', 'fcode': 4, 'string': '[Input/Output] No Response received from the remote unit/Unable to decode response'}

Code and Logs

import logging
from pymodbus.constants import Defaults as ModbusDefaults
from pymodbus.client.sync import ModbusTcpClient, ModbusUdpClient, ModbusSerialClient

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

def pymodbus_issue():
    params  = dict(
        method      = "rtu",
        port        = "COM4",
        stopbits    = ModbusDefaults.Stopbits,
        bytesize    = ModbusDefaults.Bytesize,
        parity      = ModbusDefaults.Parity,
        baudrate    = ModbusDefaults.Baudrate,
        timeout     = ModbusDefaults.Timeout,
    )
    client = ModbusSerialClient( **params )
    client.connect()
    rr = client.read_input_registers(0x1100, 18, unit=1)
    print(rr.__dict__)
    client.close()

pymodbus_issue()

Log with pymodbus version 2.0.1

DEBUG:pymodbus.transaction:Current transaction state - IDLE
DEBUG:pymodbus.transaction:Running transaction 1
DEBUG:pymodbus.transaction:SEND: 0x1 0x4 0x11 0x0 0x0 0x12 0x75 0x3b
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: 0x1 0x4 0x24 0x0 0x0 0x0 0x0 0x57 0xa 0x3d 0x1c 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0xe8 0x69 0x3d 0x47 0x9b 0x40 0x3a 0xa9 0xf4 0x3d 0x3d 0x48 0xff 0xd0
DEBUG:pymodbus.framer.rtu_framer:Getting Frame - 0x4 0x24 0x0 0x0 0x0 0x0 0x57 0xa 0x3d 0x1c 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0xe8 0x69 0x3d 0x47 0x9b 0x40 0x3a 0xa9 0xf4 0x3d 0x3d 0x48
DEBUG:pymodbus.factory:Factory Response[ReadInputRegistersResponse: 4]
DEBUG:pymodbus.framer.rtu_framer:Frame advanced, resetting header!!
DEBUG:pymodbus.transaction:Adding transaction 1
DEBUG:pymodbus.transaction:Changing transaction state from 'PROCESSING REPLY' to 'TRANSACTION_COMPLETE'
{'transaction_id': 0, 'protocol_id': 0, 'registers': [0, 0, 22282, 15644, 0, 0, 0, 0, 0, 0, 0, 0, 59497, 15687, 39744, 15017, 62525, 15688], 'check': 0, 'unit_id': 1, 'skip_encode': False}

Log with pymodbus version 2.1.0

DEBUG:pymodbus.transaction:Current transaction state - IDLE
DEBUG:pymodbus.transaction:Running transaction 1
DEBUG:pymodbus.transaction:SEND: 0x1 0x4 0x11 0x0 0x0 0x12 0x75 0x3b
DEBUG:pymodbus.client.sync:New Transaction state 'SENDING'
DEBUG:pymodbus.transaction:Changing transaction state from 'SENDING' to 'WAITING FOR REPLY'
DEBUG:pymodbus.transaction:Incomplete message received, Expected 41 bytes Recieved 16 bytes !!!!
DEBUG:pymodbus.transaction:Changing transaction state from 'WAITING FOR REPLY' to 'PROCESSING REPLY'
DEBUG:pymodbus.transaction:RECV: 0x1 0x4 0x24 0x0 0x0 0x0 0x0 0xaf 0x8c 0x3d 0x1c 0x0 0x0 0x0 0x0 0x0
DEBUG:pymodbus.transaction:Changing transaction state from 'PROCESSING REPLY' to 'TRANSACTION_COMPLETE'
{'message': '[Input/Output] No Response received from the remote unit/Unable to decode response', 'fcode': 4, 'string': '[Input/Output] No Response received from the remote unit/Unable to decode response'}

This might be related to issue #328 - however my code runs fine with pymodbus version 1.5.2 - that's why I have created a new issue.

Actually, I tested pretty much all pymodbus versions from 1.2.0 onwards, but the code "breaks" with version 2.1.0

If I change the numer of registers to read (currently 18) to something smaller it works. To be more specific, everything from 1 to 6 works, for everything else I get the mentioned error.

I have also tried with a third party Modbus viewer - also no problems there when trying to read 18 registers starting at 0x1100.

@dhoomakethu
Copy link
Contributor

@mpf82 Thanks for the report, I tried the latest (v2.1.0) from pypi , as well as on dev and master branches. I was not able to reproduce this issue (against simulator). I was able to read the maximum permissible register count (125) with out any issues. From the logs it seems that the response received is partial. If you could add the below log format and paste the logs again (both with 2.1.0 and 2.0.1) we can compare the timings and see if something is going wrong there.

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

@mpf82
Copy link
Contributor Author

mpf82 commented Oct 16, 2018

Thanks for the fast reply.

2.0.1

[pymodbus, version 2.0.1]
2018-10-16 14:54:21,005 MainThread      DEBUG    transaction    :112      Current transaction state - IDLE
2018-10-16 14:54:21,005 MainThread      DEBUG    transaction    :116      Running transaction 1
2018-10-16 14:54:21,005 MainThread      DEBUG    transaction    :206      SEND: 0x1 0x4 0x11 0x0 0x0 0x12 0x75 0x3b
2018-10-16 14:54:21,006 MainThread      DEBUG    sync           :75       New Transaction state 'SENDING'
2018-10-16 14:54:21,006 MainThread      DEBUG    transaction    :209      Changing transaction state from 'SENDING' to 'WAITING FOR REPLY'
2018-10-16 14:54:21,036 MainThread      DEBUG    transaction    :284      Changing transaction state from 'WAITING FOR REPLY' to 'PROCESSING REPLY'
2018-10-16 14:54:21,036 MainThread      DEBUG    transaction    :214      RECV: 0x1 0x4 0x24 0x0 0x0 0x0 0x0 0x8 0xe 0x3d 0x1d 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0xe8 0x69 0x3d 0x47 0x9b 0x40 0x3a 0xa9 0xf4 0x3d 0x3d 0x48 0x55 0xf7
2018-10-16 14:54:21,036 MainThread      DEBUG    rtu_framer     :175      Getting Frame - 0x4 0x24 0x0 0x0 0x0 0x0 0x8 0xe 0x3d 0x1d 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0xe8 0x69 0x3d 0x47 0x9b 0x40 0x3a 0xa9 0xf4 0x3d 0x3d 0x48
2018-10-16 14:54:21,036 MainThread      DEBUG    factory        :246      Factory Response[ReadInputRegistersResponse: 4]
2018-10-16 14:54:21,036 MainThread      DEBUG    rtu_framer     :110      Frame advanced, resetting header!!
2018-10-16 14:54:21,036 MainThread      DEBUG    transaction    :418      Adding transaction 1
2018-10-16 14:54:21,037 MainThread      DEBUG    transaction    :180      Changing transaction state from 'PROCESSING REPLY' to 'TRANSACTION_COMPLETE'
{'transaction_id': 0, 'check': 0, 'protocol_id': 0, 'unit_id': 1, 'skip_encode': False, 'registers': [0, 0, 2062, 15645, 0, 0, 0, 0, 0, 0, 0, 0, 59497, 15687, 39744, 15017, 62525, 15688]}

2.1.0

[pymodbus, version 2.1.0]
2018-10-16 14:56:13,637 MainThread      DEBUG    transaction    :111      Current transaction state - IDLE
2018-10-16 14:56:13,638 MainThread      DEBUG    transaction    :115      Running transaction 1
2018-10-16 14:56:13,638 MainThread      DEBUG    transaction    :206      SEND: 0x1 0x4 0x11 0x0 0x0 0x12 0x75 0x3b
2018-10-16 14:56:13,638 MainThread      DEBUG    sync           :75       New Transaction state 'SENDING'
2018-10-16 14:56:13,638 MainThread      DEBUG    transaction    :209      Changing transaction state from 'SENDING' to 'WAITING FOR REPLY'
2018-10-16 14:56:13,653 MainThread      DEBUG    transaction    :282      Incomplete message received, Expected 41 bytes Recieved 16 bytes !!!!
2018-10-16 14:56:13,653 MainThread      DEBUG    transaction    :284      Changing transaction state from 'WAITING FOR REPLY' to 'PROCESSING REPLY'
2018-10-16 14:56:13,653 MainThread      DEBUG    transaction    :214      RECV: 0x1 0x4 0x24 0x0 0x0 0x0 0x0 0x20 0x98 0x3d 0x1a 0x0 0x0 0x0 0x0 0x0
2018-10-16 14:56:13,653 MainThread      DEBUG    transaction    :180      Changing transaction state from 'PROCESSING REPLY' to 'TRANSACTION_COMPLETE'
{'message': '[Input/Output] No Response received from the remote unit/Unable to decode response', 'string': '[Input/Output] No Response received from the remote unit/Unable to decode response', 'fcode': 4}

And for what it's worth, this is how I am switching between the pymodbus versions:

pip.exe install -I pymodbus==2.0.1
pip.exe install -I pymodbus==2.1.0

@dhoomakethu
Copy link
Contributor

dhoomakethu commented Oct 16, 2018

@mpf82 Thanks for the quick response, Could you please execute your test against this branch ? I have just added the debug logs nothing else, just to see whats happening. You could also edit pymodbus/client/sync.py and add _logger.debug("Available in read buffer - {}".format(avaialble)) after line 536.

@mpf82
Copy link
Contributor Author

mpf82 commented Oct 16, 2018

I changed _wait_for_data() but it seems the function is never called.

Thus I changed _recv:

    def _recv(self, size):
        if not self.socket:
            raise ConnectionException(self.__str__())
        if size is None:
            size = self._wait_for_data()
        print("size", size) # added print
        result = self.socket.read(size)
        return result

and this seems to be executed twice:

...
2018-10-16 15:18:40,459 MainThread      DEBUG    transaction    :209      Changing transaction state from 'SENDING' to 'WAITING FOR REPLY'
size 2
size 39
2018-10-16 15:18:40,473 MainThread      DEBUG    transaction    :282      Incomplete message received, Expected 41 bytes Recieved 15 bytes !!!!
...

So if I do the math, 39+2 is 41 - and that equals the expected 41 bytes, right?!? But the module complains that only 15 bytes have been received.

@dhoomakethu
Copy link
Contributor

dhoomakethu commented Oct 16, 2018

My bad, thats correct it's not called for register reads, sorry for that. The socket read is for some reason not reading the full data , If you print len(result) after result = self.socket.read(size). You would see that the read is incomplete (13 bytes). Interesting part is the read timeout is 3 secs but the actual socket read is timing out with in 30ms.

Are you running these tests in separate virtualenv and is the pyserial version same for both 2.0.1 and 2.1.0 ? Please share the pyserial version.

@mpf82
Copy link
Contributor Author

mpf82 commented Oct 16, 2018

Yes, the tests are in a separate venv.

print(serial.__version__) outputs 3.4 for both 2.01 and 2.1.0

which would match the output of pip:

pip.exe install -I pymodbus==2.0.1
Collecting pymodbus==2.0.1
Collecting pyserial>=3.4 (from pymodbus==2.0.1)
Collecting six==1.11.0 (from pymodbus==2.0.1)
Successfully installed pymodbus-2.1.0 pyserial-3.4 six-1.11.0

(Yes, it really print "pymodbus-2.1.0" when installing 2.0.1, but I can tell by version.py and the behaviour that the version really changed.)

pip.exe install -I pymodbus==2.1.0
Collecting pymodbus==2.1.0
Collecting pyserial>=3.4 (from pymodbus==2.1.0)
Collecting six==1.11.0 (from pymodbus==2.1.0)
Successfully installed pymodbus-2.1.0 pyserial-3.4 six-1.11.0

And yes, you are right, even though 39 bytes should be read, result has fewer bytes:

    def _recv(self, size):
        if not self.socket:
            raise ConnectionException(self.__str__())
        if size is None:
            size = self._wait_for_data()
        result = self.socket.read(size)
        print("size", size, "result", result)
        return result

size 39 result b'$\x00\x00\x00\x00*\x1d=\x1b\x00\x00\x00\x00\x00'

@mpf82
Copy link
Contributor Author

mpf82 commented Oct 16, 2018

As a quick fix, this works for me:

    def _recv(self, size):
        """ Reads data from the underlying descriptor

        :param size: The number of bytes to read
        :return: The bytes read
        """
        if not self.socket:
            raise ConnectionException(self.__str__())
        if size is None:
            size = self._wait_for_data()
        result = self.socket.read(size)
        while len(result)<size: # keep reading
            remaining_size = size-len(result)
            result += self.socket.read(remaining_size)
        return result

But it does not explain why it's working in 2.0.1 and is broken (at least for me) in 2.1.0

@dhoomakethu
Copy link
Contributor

dhoomakethu commented Oct 16, 2018

Could you please share the logs with timing info with this patch? Ideally , the response should be ready within in the read timeout. If possible and time permits, could you please also run the tests with out this fix but with bigger timeout (say 6 sec) ?. Thanks.

@mpf82
Copy link
Contributor Author

mpf82 commented Oct 17, 2018

Increasing the timeout to e.g. 10 or even more seems to have no effect at all. I also tested with a timeout of 1000, but it really makes no difference and I always get the afore mentioned error when I run the sample program w/o my fix.

The response of the self.socket.read(...) is almost immediate, no matter the timeout value.

Maybe it's worth noting that I'm connected to the device using an USB adapter, similar to this one.

But still, everything works out-of-the-box with version 2.0.1

I have added debugging information to my quick fix:

    def _recv(self, size):
        if not self.socket:
            raise ConnectionException(self.__str__())
        if size is None:
            size = self._wait_for_data()
        _logger.debug("Before first read. Expected size: {}".format( size ))
        result = self.socket.read(size)
        _logger.debug("After first read. Actual result size: {}".format( len(result) ))
        while len(result)<size:
            remaining_size = size-len(result)
            _logger.debug("Keep reading: {}".format(remaining_size))
            result += self.socket.read(remaining_size)
            _logger.debug("New result size: {}".format( len(result) ))
        return result

Here's the log:

[pymodbus, version 2.1.0]
2018-10-17 09:05:53,688 MainThread      DEBUG    transaction    :111      Current transaction state - IDLE
2018-10-17 09:05:53,688 MainThread      DEBUG    transaction    :115      Running transaction 1
2018-10-17 09:05:53,688 MainThread      DEBUG    transaction    :206      SEND: 0x1 0x4 0x11 0x0 0x0 0x12 0x75 0x3b
2018-10-17 09:05:53,688 MainThread      DEBUG    sync           :75       New Transaction state 'SENDING'
2018-10-17 09:05:53,688 MainThread      DEBUG    transaction    :209      Changing transaction state from 'SENDING' to 'WAITING FOR REPLY'
2018-10-17 09:05:53,689 MainThread      DEBUG    sync           :555      Before first read. Expected size: 2
2018-10-17 09:05:53,700 MainThread      DEBUG    sync           :557      After first read. Actual result size: 2
2018-10-17 09:05:53,701 MainThread      DEBUG    sync           :555      Before first read. Expected size: 39
2018-10-17 09:05:53,702 MainThread      DEBUG    sync           :557      After first read. Actual result size: 12
2018-10-17 09:05:53,702 MainThread      DEBUG    sync           :560      Keep reading: 27
2018-10-17 09:05:53,716 MainThread      DEBUG    sync           :562      New result size: 39
2018-10-17 09:05:53,717 MainThread      DEBUG    transaction    :284      Changing transaction state from 'WAITING FOR REPLY' to 'PROCESSING REPLY'
2018-10-17 09:05:53,717 MainThread      DEBUG    transaction    :214      RECV: 0x1 0x4 0x24 0x0 0x0 0x0 0x0 0x24 0xde 0x3d 0x86 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0xe8 0x69 0x3d 0x47 0x9b 0x40 0x3a 0xa9 0xf4 0x3d 0x3d 0x48 0x1 0x32
2018-10-17 09:05:53,717 MainThread      DEBUG    rtu_framer     :175      Getting Frame - 0x4 0x24 0x0 0x0 0x0 0x0 0x24 0xde 0x3d 0x86 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0xe8 0x69 0x3d 0x47 0x9b 0x40 0x3a 0xa9 0xf4 0x3d 0x3d 0x48
2018-10-17 09:05:53,717 MainThread      DEBUG    factory        :246      Factory Response[ReadInputRegistersResponse: 4]
2018-10-17 09:05:53,717 MainThread      DEBUG    rtu_framer     :110      Frame advanced, resetting header!!
2018-10-17 09:05:53,717 MainThread      DEBUG    transaction    :418      Adding transaction 1
2018-10-17 09:05:53,717 MainThread      DEBUG    transaction    :180      Changing transaction state from 'PROCESSING REPLY' to 'TRANSACTION_COMPLETE'
{'skip_encode': False, 'protocol_id': 0, 'check': 0, 'unit_id': 1, 'registers': [0, 0, 9438, 15750, 0, 0, 0, 0, 0, 0, 0, 0, 59497, 15687, 39744, 15017, 62525, 15688], 'transaction_id': 0}

I've run the sample like 20 times, and the first time the function attempts to read the 39 bytes, the actual size is something between 12 and 15 bytes, most of the time 13.

After entering the while loop, the other bytes are read in one go. So far I didn't encounter a case where the loop was executed more then once - at least not when reading 18 registers.

If I attempt to read all 125 register at once, the log looks like this (timeout set to 1000):

2018-10-17 09:11:52,521 MainThread      DEBUG    transaction    :111      Current transaction state - IDLE
2018-10-17 09:11:52,521 MainThread      DEBUG    transaction    :115      Running transaction 1
2018-10-17 09:11:52,522 MainThread      DEBUG    transaction    :206      SEND: 0x1 0x4 0x11 0x0 0x0 0x7d 0x35 0x17
2018-10-17 09:11:52,522 MainThread      DEBUG    sync           :75       New Transaction state 'SENDING'
2018-10-17 09:11:52,522 MainThread      DEBUG    transaction    :209      Changing transaction state from 'SENDING' to 'WAITING FOR REPLY'
2018-10-17 09:11:52,522 MainThread      DEBUG    sync           :555      Before first read. Expected size: 2
2018-10-17 09:11:52,535 MainThread      DEBUG    sync           :557      After first read. Actual result size: 2
2018-10-17 09:11:52,535 MainThread      DEBUG    sync           :555      Before first read. Expected size: 253
2018-10-17 09:11:52,537 MainThread      DEBUG    sync           :557      After first read. Actual result size: 13
2018-10-17 09:11:52,537 MainThread      DEBUG    sync           :560      Keep reading: 240
2018-10-17 09:11:52,554 MainThread      DEBUG    sync           :562      New result size: 43
2018-10-17 09:11:52,554 MainThread      DEBUG    sync           :560      Keep reading: 210
2018-10-17 09:11:52,569 MainThread      DEBUG    sync           :562      New result size: 74
2018-10-17 09:11:52,569 MainThread      DEBUG    sync           :560      Keep reading: 179
2018-10-17 09:11:52,585 MainThread      DEBUG    sync           :562      New result size: 104
2018-10-17 09:11:52,585 MainThread      DEBUG    sync           :560      Keep reading: 149
2018-10-17 09:11:52,601 MainThread      DEBUG    sync           :562      New result size: 135
2018-10-17 09:11:52,601 MainThread      DEBUG    sync           :560      Keep reading: 118
2018-10-17 09:11:52,617 MainThread      DEBUG    sync           :562      New result size: 165
2018-10-17 09:11:52,617 MainThread      DEBUG    sync           :560      Keep reading: 88
2018-10-17 09:11:52,633 MainThread      DEBUG    sync           :562      New result size: 196
2018-10-17 09:11:52,633 MainThread      DEBUG    sync           :560      Keep reading: 57
2018-10-17 09:11:52,649 MainThread      DEBUG    sync           :562      New result size: 226
2018-10-17 09:11:52,649 MainThread      DEBUG    sync           :560      Keep reading: 27
2018-10-17 09:11:52,663 MainThread      DEBUG    sync           :562      New result size: 253
2018-10-17 09:11:52,663 MainThread      DEBUG    transaction    :284      Changing transaction state from 'WAITING FOR REPLY' to 'PROCESSING REPLY'
2018-10-17 09:11:52,663 MainThread      DEBUG    transaction    :214      RECV: 0x1 0x4 0xfa 0x0 0x0 0x0 0x0 0xff 0x24 0x3d 0x6b 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0xe8 0x69 0x3d 0x47 0x9b 0x40 0x3a 0xa9 0xf4 0x3d 0x3d 0x48 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x2d 0x20 0x3d 0x48 0x73 0x99 0x3a 0x96 0x30 0xba 0x3d 0x49 0x0 0x0 0x0 0x0 0x8e 0x3 0x3d 0x6b 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x3f 0xdf 0x3d 0x48 0xad 0xf9 0x3a 0x8c 0x3b 0xa2 0x3d 0x49 0x0 0x0 0x0 0x0 0xc6 0x94 0x3d 0x6b 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x15 0x5a 0x3e 0x16 0x8c 0xda 0x3b 0xce 0xd8 0x26 0x3e 0x16 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0xb 0x71 0x43 0x2b 0xce 0xa4 0x42 0xf4 0xb9 0xe1 0x43 0x0 0xc1 0xca 0x42 0xa7 0x6b 0xf 0x43 0x61 0x66 0x87 0x43 0x81 0xaa 0x9 0x43 0x1f 0x9c 0x5d 0x42 0xc6 0x3d 0x21 0x42 0x43 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x15 0x5a 0x3e 0x16 0x0 0x0 0x0 0x0 0x15 0x5a 0x3e 0x16 0x15 0x5a 0x3e 0x16 0xc4 0x19 0x3a 0xe2 0xf8 0xb9 0x3a 0xe9 0x93 0xf1 0xb8 0x66 0x5e 0x69 0x75 0x48
2018-10-17 09:11:52,664 MainThread      DEBUG    rtu_framer     :175      Getting Frame - 0x4 0xfa 0x0 0x0 0x0 0x0 0xff 0x24 0x3d 0x6b 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0xe8 0x69 0x3d 0x47 0x9b 0x40 0x3a 0xa9 0xf4 0x3d 0x3d 0x48 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x2d 0x20 0x3d 0x48 0x73 0x99 0x3a 0x96 0x30 0xba 0x3d 0x49 0x0 0x0 0x0 0x0 0x8e 0x3 0x3d 0x6b 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x3f 0xdf 0x3d 0x48 0xad 0xf9 0x3a 0x8c 0x3b 0xa2 0x3d 0x49 0x0 0x0 0x0 0x0 0xc6 0x94 0x3d 0x6b 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x15 0x5a 0x3e 0x16 0x8c 0xda 0x3b 0xce 0xd8 0x26 0x3e 0x16 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0xb 0x71 0x43 0x2b 0xce 0xa4 0x42 0xf4 0xb9 0xe1 0x43 0x0 0xc1 0xca 0x42 0xa7 0x6b 0xf 0x43 0x61 0x66 0x87 0x43 0x81 0xaa 0x9 0x43 0x1f 0x9c 0x5d 0x42 0xc6 0x3d 0x21 0x42 0x43 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x15 0x5a 0x3e 0x16 0x0 0x0 0x0 0x0 0x15 0x5a 0x3e 0x16 0x15 0x5a 0x3e 0x16 0xc4 0x19 0x3a 0xe2 0xf8 0xb9 0x3a 0xe9 0x93 0xf1 0xb8 0x66 0x5e 0x69
2018-10-17 09:11:52,664 MainThread      DEBUG    factory        :246      Factory Response[ReadInputRegistersResponse: 4]
2018-10-17 09:11:52,664 MainThread      DEBUG    rtu_framer     :110      Frame advanced, resetting header!!
2018-10-17 09:11:52,664 MainThread      DEBUG    transaction    :418      Adding transaction 1
2018-10-17 09:11:52,664 MainThread      DEBUG    transaction    :180      Changing transaction state from 'PROCESSING REPLY' to 'TRANSACTION_COMPLETE'

@dhoomakethu
Copy link
Contributor

Thanks for the logs, interesting to know that socket.read() is not waiting for the complete data till read timeout. I have tried with almost all the modbus devices we have here (on linux) and the issue is not reproducible. The only major diff between 2.0.1 and 2.1.0 is introduction of interCharTimeout (refer line ). Could you please comment out that line and run tests one more time (with and with out your patch)?

@mpf82
Copy link
Contributor Author

mpf82 commented Oct 17, 2018

That line seems to be the culprit.

If I comment it out, the whole data gets read in one go:

2018-10-17 09:45:12,895 MainThread      DEBUG    transaction    :209      Changing transaction state from 'SENDING' to 'WAITING FOR REPLY'
2018-10-17 09:45:12,895 MainThread      DEBUG    sync           :555      Before first read. Expected size: 2
2018-10-17 09:45:12,909 MainThread      DEBUG    sync           :557      After first read. Actual result size: 2
2018-10-17 09:45:12,909 MainThread      DEBUG    sync           :555      Before first read. Expected size: 253
2018-10-17 09:45:13,037 MainThread      DEBUG    sync           :557      After first read. Actual result size: 253
2018-10-17 09:45:13,037 MainThread      DEBUG    transaction    :284      Changing transaction state from 'WAITING FOR REPLY' to 'PROCESSING REPLY'

Edit: Here's the value self.inter_char_timeout 0.000859375 - seems pretty low, maybe that's the problem?

@dhoomakethu
Copy link
Contributor

So my guess was correct, I went through the serial implementation for windows and found this line in serialwin32.py

        if self._timeout != 0 and self._inter_byte_timeout is not None:
            timeouts.ReadIntervalTimeout = max(int(self._inter_byte_timeout * 1000), 1)

The windows documentation for COMTIMEOUT has this description for ReadIntervalTimeout

ReadIntervalTimeout

The maximum time allowed to elapse before the arrival of the next byte on the communications line, in milliseconds. If the interval between the arrival of any two bytes exceeds this amount, the ReadFile operation is completed and any buffered data is returned. A value of zero indicates that interval time-outs are not used.

So it looks like the data is being received slower than expected (which basically does not adhere with modbus specs, refer image below ).
image

@mpf82
Copy link
Contributor Author

mpf82 commented Oct 17, 2018

Like I said, I'm connected via an USB adapter, maybe that's slowing down the communication?

And a timeout of 0.000859375 still seems pretty low to me - is that an "OK" value?

@dhoomakethu
Copy link
Contributor

Hmm, that 859.375 micro seconds is still ok as per modbus spec per-say but yes, using an external USB-RS485 can impose its own limitations. How about providing an option to disable this timeout during client creation ? By default it is enabled but for cases like yours , one could choose to turnoff it .

@mpf82
Copy link
Contributor Author

mpf82 commented Oct 17, 2018

I tested around, and the "sweet spot" in my case seems to be

self.socket.interCharTimeout = 0.016 # self.inter_char_timeout

where the communication would sometimes fail and sometimes succeed.

As in 0.015 -> always fail
and 0.017 -> always succeed

But yeah, an option to disable it completely would be nice.

Or maybe an option to override the default?

Edit:

Ok, so as a work-around, I could create the client like so:

client = ModbusSerialClient( **params )
client.inter_char_timeout = 0.05

and maybe you could add inter_char_timeout to the kwargs of the ModbusSerialClient.

That way, one could disable it by setting it to None or one can decide to override it with any other value.

        if self.method == "rtu":
            if self.baudrate > 19200:
                self.silent_interval = 1.75 / 1000  # ms
            else:
                self._t0 = float((1 + 8 + 2)) / self.baudrate
                self.inter_char_timeout = kwargs.get('inter_char_timeout', 1.5 * self._t0)
                self.silent_interval = 3.5 * self._t0
            self.silent_interval = round(self.silent_interval, 6)

@dhoomakethu
Copy link
Contributor

dhoomakethu commented Oct 17, 2018

I am planning to introduce another kwarg strict which is True by default and use inter_char_timeout based on the value.

 :param strict:  Use Inter char timeout for baudrates <= 19200 (adhere
        to modbus standards)
....
self._strict = kwargs.get("strict", True)

....
        if self.method == "rtu":
            if self._strict:
                self.socket.interCharTimeout = self.inter_char_timeout

@dhoomakethu
Copy link
Contributor

Fix Now part of branch pymodbus-2.2.0, please give it a try and feedback

@mpf82
Copy link
Contributor Author

mpf82 commented Jan 28, 2019

Sorry for the late reply.

Yes, I can confirm that with version 2.2.0rc1 setting strict = False, will fix the issue.

dhoomakethu added a commit that referenced this issue Apr 18, 2019
* Rebase to dev3.7

* Adding 3.7 to travis configuration

* Updated documentation to resolve warnings introduced with the longer names
Updated requirements-docs.txt to include missing modules

* Fixed reference to deprecated asynchronous

* Adding gmp disable to fix pypy build issues

* Adding gmp disable to fix pypy build issues

* Removing travis python 3.7 configuration

Commenting out python3.7 from Travis while waiting for support. You can run teh 3.7 tests with tox without issues

* Adding asserts for Payload Endianness

* Fixing example of Payload. Same Endianness for builder and decoder.

* Fix Sql db slave context validate and get methods - #139

* #353 - debugging, Add debug logs to check size of avaialble data in read buffer

* #353 Provide an option to disable inter char timeouts

* #353 Bump version, update changelog

* check self.socket (#354)

* check self.socket

self.socket might be None at this point

* Update pymodbus/client/sync.py

Co-Authored-By: mpf82 <[email protected]>

* Fix typo (#378)

* Pymodbus 2.2.0 (#375)

* #357 Support registration of custom requests

* #368 Fixes write to broadcast address

When writing to broadcast address (unit_id=0) there should be no response according to the Modbus spec. This fix changes expected_response_length to 0 when writing to unit_id=0. This will break any existing code that is improperly using unit_id 0 for a slave address.

* Bump version to 2.2.0

Fix #366 Update failures in sql context

Update Changelog

Fix major minor version in example codes

* Fix #371 pymodbus repl on python3

* 1. Fix tornado async serial client `TypeError` while processing incoming packet.
2. Fix asyncio examples.
3. Minor update in factory.py, now server logs prints received request instead of only function cod

* [fix v3] poprawa sprawdzania timeout

* Release candidate for pymodbus 2.2.0

*  Fix #377 when invalid port is supplied and minor updates in logging

* #368 adds broadcast support for sync client and server

Adds broadcast_enable parameter to client and server, default value is False. When true it will treat unit_id 0 as broadcast and execute requests on all server slave contexts and not send a response and on the client side will send the request and not try to receive a response.

* #368 Fixes minor bug in broadcast support code

* Fixed erronous CRC handling

If the CRC recieved is not correct in my case my slave got caught in a deadlock, not taking any new requests. This addition fixed that.

* Update Changelog

* Fix test coverage

* Fix #387 Transactions failing on 2.2.0rc2.

* Task Cancellation and CRC Errors

Alternate solution for #356 and #360.

Changes the RTU to make the transaction ID as the unit ID instead of an ever incrementing number.

Previously this transaction ID was always 0 on the receiving end but was the unique transaction ID on sending.

As such the FIFO buffer made the most sense. By tying it to the unit ID, we can recover from failure modes such as: -
- Asyncio task cancellations (eg. timeouts) #360
- Skipped responses from slaves. (hangs on master #360)
- CRC Errors #356
- Busy response

* Cherry pick commit from PR #367 , Update changelog , bump version to 2.2.0rc4

* #389 Support passing all serial port parameters to asynchronous server

* Fix BinaryPayloadDecoder and Builder wrt to coils

* Misc updates, bump version to 2.2.0

* ReportSlaveIdResponse now tries to get slave id based on server identity for pymodbus servers

* Update missing bcrypt requirement for testing
dhoomakethu added a commit that referenced this issue Apr 19, 2019
* Rebase to dev3.7

* Adding 3.7 to travis configuration

* Updated documentation to resolve warnings introduced with the longer names
Updated requirements-docs.txt to include missing modules

* Fixed reference to deprecated asynchronous

* Adding gmp disable to fix pypy build issues

* Adding gmp disable to fix pypy build issues

* Removing travis python 3.7 configuration

Commenting out python3.7 from Travis while waiting for support. You can run teh 3.7 tests with tox without issues

* Adding asserts for Payload Endianness

* Fixing example of Payload. Same Endianness for builder and decoder.

* Fix Sql db slave context validate and get methods - #139

* #353 - debugging, Add debug logs to check size of avaialble data in read buffer

* #353 Provide an option to disable inter char timeouts

* #353 Bump version, update changelog

* check self.socket (#354)

* check self.socket

self.socket might be None at this point

* Update pymodbus/client/sync.py

Co-Authored-By: mpf82 <[email protected]>

* Fix typo (#378)

* Pymodbus 2.2.0 (#375)

* #357 Support registration of custom requests

* #368 Fixes write to broadcast address

When writing to broadcast address (unit_id=0) there should be no response according to the Modbus spec. This fix changes expected_response_length to 0 when writing to unit_id=0. This will break any existing code that is improperly using unit_id 0 for a slave address.

* Bump version to 2.2.0

Fix #366 Update failures in sql context

Update Changelog

Fix major minor version in example codes

* Fix #371 pymodbus repl on python3

* 1. Fix tornado async serial client `TypeError` while processing incoming packet.
2. Fix asyncio examples.
3. Minor update in factory.py, now server logs prints received request instead of only function cod

* [fix v3] poprawa sprawdzania timeout

* Release candidate for pymodbus 2.2.0

*  Fix #377 when invalid port is supplied and minor updates in logging

* #368 adds broadcast support for sync client and server

Adds broadcast_enable parameter to client and server, default value is False. When true it will treat unit_id 0 as broadcast and execute requests on all server slave contexts and not send a response and on the client side will send the request and not try to receive a response.

* #368 Fixes minor bug in broadcast support code

* Fixed erronous CRC handling

If the CRC recieved is not correct in my case my slave got caught in a deadlock, not taking any new requests. This addition fixed that.

* Update Changelog

* Fix test coverage

* Fix #387 Transactions failing on 2.2.0rc2.

* Task Cancellation and CRC Errors

Alternate solution for #356 and #360.

Changes the RTU to make the transaction ID as the unit ID instead of an ever incrementing number.

Previously this transaction ID was always 0 on the receiving end but was the unique transaction ID on sending.

As such the FIFO buffer made the most sense. By tying it to the unit ID, we can recover from failure modes such as: -
- Asyncio task cancellations (eg. timeouts) #360
- Skipped responses from slaves. (hangs on master #360)
- CRC Errors #356
- Busy response

* Cherry pick commit from PR #367 , Update changelog , bump version to 2.2.0rc4

* #389 Support passing all serial port parameters to asynchronous server

* Fix BinaryPayloadDecoder and Builder wrt to coils

* Misc updates, bump version to 2.2.0

* ReportSlaveIdResponse now tries to get slave id based on server identity for pymodbus servers

* Update missing bcrypt requirement for testing

* Fix docs (#407)

* Fix document generation

* Formatting updates in Changelog
dhoomakethu added a commit that referenced this issue Oct 29, 2019
* Rebase to dev3.7

* Adding 3.7 to travis configuration

* Updated documentation to resolve warnings introduced with the longer names
Updated requirements-docs.txt to include missing modules

* Fixed reference to deprecated asynchronous

* Adding gmp disable to fix pypy build issues

* Adding gmp disable to fix pypy build issues

* Removing travis python 3.7 configuration

Commenting out python3.7 from Travis while waiting for support. You can run teh 3.7 tests with tox without issues

* Adding asserts for Payload Endianness

* Fixing example of Payload. Same Endianness for builder and decoder.

* Fix Sql db slave context validate and get methods - #139

* #353 - debugging, Add debug logs to check size of avaialble data in read buffer

* #353 Provide an option to disable inter char timeouts

* #353 Bump version, update changelog

* check self.socket (#354)

* check self.socket

self.socket might be None at this point

* Update pymodbus/client/sync.py

Co-Authored-By: mpf82 <[email protected]>

* Fix typo (#378)

* Pymodbus 2.2.0 (#375)

* #357 Support registration of custom requests

* #368 Fixes write to broadcast address

When writing to broadcast address (unit_id=0) there should be no response according to the Modbus spec. This fix changes expected_response_length to 0 when writing to unit_id=0. This will break any existing code that is improperly using unit_id 0 for a slave address.

* Bump version to 2.2.0

Fix #366 Update failures in sql context

Update Changelog

Fix major minor version in example codes

* Fix #371 pymodbus repl on python3

* 1. Fix tornado async serial client `TypeError` while processing incoming packet.
2. Fix asyncio examples.
3. Minor update in factory.py, now server logs prints received request instead of only function cod

* [fix v3] poprawa sprawdzania timeout

* Release candidate for pymodbus 2.2.0

*  Fix #377 when invalid port is supplied and minor updates in logging

* #368 adds broadcast support for sync client and server

Adds broadcast_enable parameter to client and server, default value is False. When true it will treat unit_id 0 as broadcast and execute requests on all server slave contexts and not send a response and on the client side will send the request and not try to receive a response.

* #368 Fixes minor bug in broadcast support code

* Fixed erronous CRC handling

If the CRC recieved is not correct in my case my slave got caught in a deadlock, not taking any new requests. This addition fixed that.

* Update Changelog

* Fix test coverage

* Fix #387 Transactions failing on 2.2.0rc2.

* Task Cancellation and CRC Errors

Alternate solution for #356 and #360.

Changes the RTU to make the transaction ID as the unit ID instead of an ever incrementing number.

Previously this transaction ID was always 0 on the receiving end but was the unique transaction ID on sending.

As such the FIFO buffer made the most sense. By tying it to the unit ID, we can recover from failure modes such as: -
- Asyncio task cancellations (eg. timeouts) #360
- Skipped responses from slaves. (hangs on master #360)
- CRC Errors #356
- Busy response

* Cherry pick commit from PR #367 , Update changelog , bump version to 2.2.0rc4

* #389 Support passing all serial port parameters to asynchronous server

* Fix BinaryPayloadDecoder and Builder wrt to coils

* Misc updates, bump version to 2.2.0

* ReportSlaveIdResponse now tries to get slave id based on server identity for pymodbus servers

* Update missing bcrypt requirement for testing

* Fix docs (#407)

* Fix document generation

* Formatting updates in Changelog

* Remove pycrypto dep (#411)

It has not been needed by Twisted for a long time, and has been unmaintained
for a long time.

* Fix --upgrade option in install dependencies (#413)

* Fix document generation

* Formatting updates in Changelog

* Fix --upgrade option in install dependencies

* Padding for odd sized responses (#425)

If the response is odd size the buffer needs to be padded with an additional byte.

* README update: REPL stands for Read Evaluate **Print** Loop (#426)

* Drop python 3.4 support (#440)

Python 3.4 is EoL and has an easy upgrade path to 3.5+. Support was
dropped in Twisted 19.7.0, which is causing Travis to fail pymodbus
tests for 3.4.

* Re-enable travis python 3.7 builds (#441)

* Update __init__.py (#436)

* Use SPDX identifier to specify the exact license type (#427)

* asyncio server implementation (#400)

* #357 Support registration of custom requests

* #368 Fixes write to broadcast address

When writing to broadcast address (unit_id=0) there should be no response according to the Modbus spec. This fix changes expected_response_length to 0 when writing to unit_id=0. This will break any existing code that is improperly using unit_id 0 for a slave address.

* Bump version to 2.2.0

Fix #366 Update failures in sql context

Update Changelog

Fix major minor version in example codes

* Fix #371 pymodbus repl on python3

* 1. Fix tornado async serial client `TypeError` while processing incoming packet.
2. Fix asyncio examples.
3. Minor update in factory.py, now server logs prints received request instead of only function cod

* [fix v3] poprawa sprawdzania timeout

* Release candidate for pymodbus 2.2.0

*  Fix #377 when invalid port is supplied and minor updates in logging

* #368 adds broadcast support for sync client and server

Adds broadcast_enable parameter to client and server, default value is False. When true it will treat unit_id 0 as broadcast and execute requests on all server slave contexts and not send a response and on the client side will send the request and not try to receive a response.

* #368 Fixes minor bug in broadcast support code

* Fixed erronous CRC handling

If the CRC recieved is not correct in my case my slave got caught in a deadlock, not taking any new requests. This addition fixed that.

* Update Changelog

* Fix test coverage

* Fix #387 Transactions failing on 2.2.0rc2.

* Task Cancellation and CRC Errors

Alternate solution for #356 and #360.

Changes the RTU to make the transaction ID as the unit ID instead of an ever incrementing number.

Previously this transaction ID was always 0 on the receiving end but was the unique transaction ID on sending.

As such the FIFO buffer made the most sense. By tying it to the unit ID, we can recover from failure modes such as: -
- Asyncio task cancellations (eg. timeouts) #360
- Skipped responses from slaves. (hangs on master #360)
- CRC Errors #356
- Busy response

* Cherry pick commit from PR #367 , Update changelog , bump version to 2.2.0rc4

* native asyncio implementation of ModbusTcpServer and ModbusUdpServer

* preliminary asyncio server examples

* move serial module dependency into class instantiation

* unittests for asyncio based server implementation

* induce exception in execute method by mock patching the request object's execute method

* move serial module dependency into class instantiation

* added asynctest depency to requirements-tests.txt

* add unittest skip condition for unsupported targets, remove failing assertion from unsupported targets, use lower asynctest version

* remove logger setLevel call since doing so may override library consumers' already set log level

* remove async def/await keywords from unittest so that the ast can be loaded in py2 even if the test is to be skipped

* Add option to repl allowing Modbus RTU framing on a TCP socket (#447)

* repl: Allow Modbus RTU framing on a TCP socket

* repl: Update README for framing option

* Fix asynci server test failures on python3.6 and below

* Bump version to 2.2.0rc1, update six requirements and Changelog

* Support multiple Python versions to fix test error from PR #400 (#444)

* client/sync.py: Fix missing serial module dependency

The serial.connect failed in PR riptideio#400 with "NameError: name
'serial' is not defined" [1]:

self = <ModbusSerialClient at 0x7fcda4009b00 socket=None, method=ascii, timeout=3>

    def connect(self):
        """ Connect to the modbus serial server

        :returns: True if connection succeeded, False otherwise
        """
        if self.socket:
            return True
        try:
>           self.socket = serial.Serial(port=self.port,
                                        timeout=self.timeout,
                                        bytesize=self.bytesize,
                                        stopbits=self.stopbits,
                                        baudrate=self.baudrate,
                                        parity=self.parity)
E                                       NameError: name 'serial' is not defined

pymodbus/client/sync.py:476: NameError

This patch moves the serial import back to the head.

[1] https://travis-ci.org/riptideio/pymodbus/jobs/566009109

Fixes: commit e6da559 asyncio server implementation (#400)

* server/asyncio.py: Create server with appropriate args and environment

If Python is older than 3.7, the create_server will fail like PR
riptideio#400 with "unexpected keyword argument 'start_serving'" [1]
which is new in Python version 3.7:

self.server_factory = self.loop.create_server(lambda :self.handler(self),
                                              *self.address,
                                              reuse_address=allow_reuse_address,
                                              reuse_port=allow_reuse_port,
                                              backlog=backlog,
>                                             start_serving=not defer_start)

E       TypeError: create_server() got an unexpected keyword argument 'start_serving'

pymodbus/server/asyncio.py:400: TypeError

This patch creates server according to Python environment.

[1] https://travis-ci.org/starnight/pymodbus/jobs/584178484

Fixes: commit e6da559 asyncio server implementation (#400)

* Create asyncio task with appropriate method and environment

If Python is older than 3.7, the asyncio.create_task will fail like PR
riptideio#400 with "AttributeError: module 'asyncio' has no attribute
'create_task'" [1] which is new in Python version 3.7 [2]:

@asyncio.coroutine

def testTcpServerCloseActiveConnection(self):
    ''' Test server_close() while there are active TCP connections'''
    data = b"\x01\x00\x00\x00\x00\x06\x01\x01\x00\x00\x00\x01"
    server = yield from StartTcpServer(context=self.context,address=("127.0.0.1", 0),loop=self.loop)
>   server_task = asyncio.create_task(server.serve_forever())
E   AttributeError: module 'asyncio' has no attribute 'create_task'

test/test_server_asyncio.py:205: AttributeError

This patch creates task according to Python environment.

[1] https://travis-ci.org/starnight/pymodbus/jobs/584193587
[2] https://docs.python.org/3/library/asyncio-task.html#creating-tasks

Fixes: commit e6da559 asyncio server implementation (#400)

* server/asyncio.py: Fix format string for older Python

If Python is older than 3.6, f-Strings will fail like PR riptideio#400
with "SyntaxError: invalid syntax" [1] which is new in Python version
3.6 with PEP 498 -- Literal String Interpolation [2]:

test/test_server_asyncio.py:14: in <module>
    from pymodbus.server.asyncio import StartTcpServer, StartUdpServer, StartSerialServer, StopServer, ModbusServerFactory
E     File "/home/travis/build/starnight/pymodbus/pymodbus/server/asyncio.py", line 424
E       _logger.warning(f"aborting active session {k}")
E                                                    ^
E   SyntaxError: invalid syntax

This patch fixes the format string with traditional format string
syntax.

[1] https://travis-ci.org/starnight/pymodbus/jobs/584427976
[2] https://www.python.org/dev/peps/pep-0498/

Fixes: commit e6da559 asyncio server implementation (#400)

* test: Make assert_called_once() test only with Python 3.6+

If Python is older than 3.6, unittest.mock.assert_called_once() will
fail like PR riptideio#400 with "AttributeError: assert_called_once" [1]
which is new in Python version 3.6 [2]:

>       self.loop.create_server.assert_called_once()

test/test_server_asyncio.py:76:

_ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _

self = <CoroutineMock name='mock.create_server' id='139638313234784'>
name = 'assert_called_once'

    def __getattr__(self, name):
        if name in {'_mock_methods', '_mock_unsafe'}:
            raise AttributeError(name)
        elif self._mock_methods is not None:
            if name not in self._mock_methods or name in _all_magics:
                raise AttributeError("Mock object has no attribute %r" % name)
        elif _is_magic(name):
            raise AttributeError(name)
        if not self._mock_unsafe:
            if name.startswith(('assert', 'assret')):
>               raise AttributeError(name)
E               AttributeError: assert_called_once

/opt/python/3.5.6/lib/python3.5/unittest/mock.py:585: AttributeError

This patch skips the tests if they are not in Python 3.6+.

[1] https://travis-ci.org/starnight/pymodbus/jobs/584431003
[2] https://docs.python.org/3/library/unittest.mock.html#unittest.mock.Mock.assert_called_once

Fixes: commit e6da559 asyncio server implementation (#400)

* test: Make serve_forever() test only with Python 3.7+

If Python is older than 3.7, asyncio.base_events.Server.serve_forever
will fail like PR riptideio#400 with "AttributeError: <class
'asyncio.base_events.Server'> does not have the attribute
'serve_forever'" [1] which is new in Python version 3.7 [2]:

@asyncio.coroutine
def testTcpServerServeNoDefer(self):
    ''' Test StartTcpServer without deferred start (immediate execution of server) '''
>   with patch('asyncio.base_events.Server.serve_forever', new_callable=asynctest.CoroutineMock) as serve:

test/test_server_asyncio.py:81:

...

if not self.create and original is DEFAULT:
    raise AttributeError(
>       "%s does not have the attribute %r" % (target, name)
    )
E   AttributeError: <class 'asyncio.base_events.Server'> does not have the attribute 'serve_forever'

This patch skips the tests if they are not in Python 3.7+.

[1] https://travis-ci.org/starnight/pymodbus/jobs/584212511
[2] https://docs.python.org/3/library/asyncio-eventloop.html#asyncio.Server.serve_forever

Fixes: commit e6da559 asyncio server implementation (#400)

* Add TLS feature for Modbus synchronous (#446)

* Add TLS feature for Modbus synchronous

Modbus.org released MODBUS/TCP Security Protocol Specification [1],
which focuses variant of the Mobdbus/TCP protocol utilizing Transport
Layer Security (TLS). This patch enables the Modbus over TLS feature as
ModbusTlsClient with the Python builtin module ssl - TLS/SSL wrapper for
socket objects.

[1]: http://modbus.org/docs/MB-TCP-Security-v21_2018-07-24.pdf

* Implement MODBUS TLS synchronous server

Since we have the MODBUS TLS synchronous client, we can also have the
MODBUS TLS synchronous server.

* Fix #461 - Udp client/server , Fix #401 - package license with source, #457 Fix typo's in docstrings, #455-Support float16

* Fix examples, Merge #431

* #401 Move license to root folder from docs
dhoomakethu added a commit that referenced this issue Sep 11, 2020
* Rebase to dev3.7

* Adding 3.7 to travis configuration

* Updated documentation to resolve warnings introduced with the longer names
Updated requirements-docs.txt to include missing modules

* Fixed reference to deprecated asynchronous

* Adding gmp disable to fix pypy build issues

* Adding gmp disable to fix pypy build issues

* Removing travis python 3.7 configuration

Commenting out python3.7 from Travis while waiting for support. You can run teh 3.7 tests with tox without issues

* Adding asserts for Payload Endianness

* Fixing example of Payload. Same Endianness for builder and decoder.

* Fix Sql db slave context validate and get methods - #139

* #353 - debugging, Add debug logs to check size of avaialble data in read buffer

* #353 Provide an option to disable inter char timeouts

* #353 Bump version, update changelog

* check self.socket (#354)

* check self.socket

self.socket might be None at this point

* Update pymodbus/client/sync.py

Co-Authored-By: mpf82 <[email protected]>

* Fix typo (#378)

* Pymodbus 2.2.0 (#375)

* #357 Support registration of custom requests

* #368 Fixes write to broadcast address

When writing to broadcast address (unit_id=0) there should be no response according to the Modbus spec. This fix changes expected_response_length to 0 when writing to unit_id=0. This will break any existing code that is improperly using unit_id 0 for a slave address.

* Bump version to 2.2.0

Fix #366 Update failures in sql context

Update Changelog

Fix major minor version in example codes

* Fix #371 pymodbus repl on python3

* 1. Fix tornado async serial client `TypeError` while processing incoming packet.
2. Fix asyncio examples.
3. Minor update in factory.py, now server logs prints received request instead of only function cod

* [fix v3] poprawa sprawdzania timeout

* Release candidate for pymodbus 2.2.0

*  Fix #377 when invalid port is supplied and minor updates in logging

* #368 adds broadcast support for sync client and server

Adds broadcast_enable parameter to client and server, default value is False. When true it will treat unit_id 0 as broadcast and execute requests on all server slave contexts and not send a response and on the client side will send the request and not try to receive a response.

* #368 Fixes minor bug in broadcast support code

* Fixed erronous CRC handling

If the CRC recieved is not correct in my case my slave got caught in a deadlock, not taking any new requests. This addition fixed that.

* Update Changelog

* Fix test coverage

* Fix #387 Transactions failing on 2.2.0rc2.

* Task Cancellation and CRC Errors

Alternate solution for #356 and #360.

Changes the RTU to make the transaction ID as the unit ID instead of an ever incrementing number.

Previously this transaction ID was always 0 on the receiving end but was the unique transaction ID on sending.

As such the FIFO buffer made the most sense. By tying it to the unit ID, we can recover from failure modes such as: -
- Asyncio task cancellations (eg. timeouts) #360
- Skipped responses from slaves. (hangs on master #360)
- CRC Errors #356
- Busy response

* Cherry pick commit from PR #367 , Update changelog , bump version to 2.2.0rc4

* #389 Support passing all serial port parameters to asynchronous server

* Fix BinaryPayloadDecoder and Builder wrt to coils

* Misc updates, bump version to 2.2.0

* ReportSlaveIdResponse now tries to get slave id based on server identity for pymodbus servers

* Update missing bcrypt requirement for testing

* Fix docs (#407)

* Fix document generation

* Formatting updates in Changelog

* Remove pycrypto dep (#411)

It has not been needed by Twisted for a long time, and has been unmaintained
for a long time.

* Fix --upgrade option in install dependencies (#413)

* Fix document generation

* Formatting updates in Changelog

* Fix --upgrade option in install dependencies

* Padding for odd sized responses (#425)

If the response is odd size the buffer needs to be padded with an additional byte.

* README update: REPL stands for Read Evaluate **Print** Loop (#426)

* Drop python 3.4 support (#440)

Python 3.4 is EoL and has an easy upgrade path to 3.5+. Support was
dropped in Twisted 19.7.0, which is causing Travis to fail pymodbus
tests for 3.4.

* Re-enable travis python 3.7 builds (#441)

* Update __init__.py (#436)

* Use SPDX identifier to specify the exact license type (#427)

* asyncio server implementation (#400)

* #357 Support registration of custom requests

* #368 Fixes write to broadcast address

When writing to broadcast address (unit_id=0) there should be no response according to the Modbus spec. This fix changes expected_response_length to 0 when writing to unit_id=0. This will break any existing code that is improperly using unit_id 0 for a slave address.

* Bump version to 2.2.0

Fix #366 Update failures in sql context

Update Changelog

Fix major minor version in example codes

* Fix #371 pymodbus repl on python3

* 1. Fix tornado async serial client `TypeError` while processing incoming packet.
2. Fix asyncio examples.
3. Minor update in factory.py, now server logs prints received request instead of only function cod

* [fix v3] poprawa sprawdzania timeout

* Release candidate for pymodbus 2.2.0

*  Fix #377 when invalid port is supplied and minor updates in logging

* #368 adds broadcast support for sync client and server

Adds broadcast_enable parameter to client and server, default value is False. When true it will treat unit_id 0 as broadcast and execute requests on all server slave contexts and not send a response and on the client side will send the request and not try to receive a response.

* #368 Fixes minor bug in broadcast support code

* Fixed erronous CRC handling

If the CRC recieved is not correct in my case my slave got caught in a deadlock, not taking any new requests. This addition fixed that.

* Update Changelog

* Fix test coverage

* Fix #387 Transactions failing on 2.2.0rc2.

* Task Cancellation and CRC Errors

Alternate solution for #356 and #360.

Changes the RTU to make the transaction ID as the unit ID instead of an ever incrementing number.

Previously this transaction ID was always 0 on the receiving end but was the unique transaction ID on sending.

As such the FIFO buffer made the most sense. By tying it to the unit ID, we can recover from failure modes such as: -
- Asyncio task cancellations (eg. timeouts) #360
- Skipped responses from slaves. (hangs on master #360)
- CRC Errors #356
- Busy response

* Cherry pick commit from PR #367 , Update changelog , bump version to 2.2.0rc4

* native asyncio implementation of ModbusTcpServer and ModbusUdpServer

* preliminary asyncio server examples

* move serial module dependency into class instantiation

* unittests for asyncio based server implementation

* induce exception in execute method by mock patching the request object's execute method

* move serial module dependency into class instantiation

* added asynctest depency to requirements-tests.txt

* add unittest skip condition for unsupported targets, remove failing assertion from unsupported targets, use lower asynctest version

* remove logger setLevel call since doing so may override library consumers' already set log level

* remove async def/await keywords from unittest so that the ast can be loaded in py2 even if the test is to be skipped

* Add option to repl allowing Modbus RTU framing on a TCP socket (#447)

* repl: Allow Modbus RTU framing on a TCP socket

* repl: Update README for framing option

* Fix asynci server test failures on python3.6 and below

* Bump version to 2.2.0rc1, update six requirements and Changelog

* Support multiple Python versions to fix test error from PR #400 (#444)

* client/sync.py: Fix missing serial module dependency

The serial.connect failed in PR riptideio#400 with "NameError: name
'serial' is not defined" [1]:

self = <ModbusSerialClient at 0x7fcda4009b00 socket=None, method=ascii, timeout=3>

    def connect(self):
        """ Connect to the modbus serial server

        :returns: True if connection succeeded, False otherwise
        """
        if self.socket:
            return True
        try:
>           self.socket = serial.Serial(port=self.port,
                                        timeout=self.timeout,
                                        bytesize=self.bytesize,
                                        stopbits=self.stopbits,
                                        baudrate=self.baudrate,
                                        parity=self.parity)
E                                       NameError: name 'serial' is not defined

pymodbus/client/sync.py:476: NameError

This patch moves the serial import back to the head.

[1] https://travis-ci.org/riptideio/pymodbus/jobs/566009109

Fixes: commit e6da559 asyncio server implementation (#400)

* server/asyncio.py: Create server with appropriate args and environment

If Python is older than 3.7, the create_server will fail like PR
riptideio#400 with "unexpected keyword argument 'start_serving'" [1]
which is new in Python version 3.7:

self.server_factory = self.loop.create_server(lambda :self.handler(self),
                                              *self.address,
                                              reuse_address=allow_reuse_address,
                                              reuse_port=allow_reuse_port,
                                              backlog=backlog,
>                                             start_serving=not defer_start)

E       TypeError: create_server() got an unexpected keyword argument 'start_serving'

pymodbus/server/asyncio.py:400: TypeError

This patch creates server according to Python environment.

[1] https://travis-ci.org/starnight/pymodbus/jobs/584178484

Fixes: commit e6da559 asyncio server implementation (#400)

* Create asyncio task with appropriate method and environment

If Python is older than 3.7, the asyncio.create_task will fail like PR
riptideio#400 with "AttributeError: module 'asyncio' has no attribute
'create_task'" [1] which is new in Python version 3.7 [2]:

@asyncio.coroutine

def testTcpServerCloseActiveConnection(self):
    ''' Test server_close() while there are active TCP connections'''
    data = b"\x01\x00\x00\x00\x00\x06\x01\x01\x00\x00\x00\x01"
    server = yield from StartTcpServer(context=self.context,address=("127.0.0.1", 0),loop=self.loop)
>   server_task = asyncio.create_task(server.serve_forever())
E   AttributeError: module 'asyncio' has no attribute 'create_task'

test/test_server_asyncio.py:205: AttributeError

This patch creates task according to Python environment.

[1] https://travis-ci.org/starnight/pymodbus/jobs/584193587
[2] https://docs.python.org/3/library/asyncio-task.html#creating-tasks

Fixes: commit e6da559 asyncio server implementation (#400)

* server/asyncio.py: Fix format string for older Python

If Python is older than 3.6, f-Strings will fail like PR riptideio#400
with "SyntaxError: invalid syntax" [1] which is new in Python version
3.6 with PEP 498 -- Literal String Interpolation [2]:

test/test_server_asyncio.py:14: in <module>
    from pymodbus.server.asyncio import StartTcpServer, StartUdpServer, StartSerialServer, StopServer, ModbusServerFactory
E     File "/home/travis/build/starnight/pymodbus/pymodbus/server/asyncio.py", line 424
E       _logger.warning(f"aborting active session {k}")
E                                                    ^
E   SyntaxError: invalid syntax

This patch fixes the format string with traditional format string
syntax.

[1] https://travis-ci.org/starnight/pymodbus/jobs/584427976
[2] https://www.python.org/dev/peps/pep-0498/

Fixes: commit e6da559 asyncio server implementation (#400)

* test: Make assert_called_once() test only with Python 3.6+

If Python is older than 3.6, unittest.mock.assert_called_once() will
fail like PR riptideio#400 with "AttributeError: assert_called_once" [1]
which is new in Python version 3.6 [2]:

>       self.loop.create_server.assert_called_once()

test/test_server_asyncio.py:76:

_ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _

self = <CoroutineMock name='mock.create_server' id='139638313234784'>
name = 'assert_called_once'

    def __getattr__(self, name):
        if name in {'_mock_methods', '_mock_unsafe'}:
            raise AttributeError(name)
        elif self._mock_methods is not None:
            if name not in self._mock_methods or name in _all_magics:
                raise AttributeError("Mock object has no attribute %r" % name)
        elif _is_magic(name):
            raise AttributeError(name)
        if not self._mock_unsafe:
            if name.startswith(('assert', 'assret')):
>               raise AttributeError(name)
E               AttributeError: assert_called_once

/opt/python/3.5.6/lib/python3.5/unittest/mock.py:585: AttributeError

This patch skips the tests if they are not in Python 3.6+.

[1] https://travis-ci.org/starnight/pymodbus/jobs/584431003
[2] https://docs.python.org/3/library/unittest.mock.html#unittest.mock.Mock.assert_called_once

Fixes: commit e6da559 asyncio server implementation (#400)

* test: Make serve_forever() test only with Python 3.7+

If Python is older than 3.7, asyncio.base_events.Server.serve_forever
will fail like PR riptideio#400 with "AttributeError: <class
'asyncio.base_events.Server'> does not have the attribute
'serve_forever'" [1] which is new in Python version 3.7 [2]:

@asyncio.coroutine
def testTcpServerServeNoDefer(self):
    ''' Test StartTcpServer without deferred start (immediate execution of server) '''
>   with patch('asyncio.base_events.Server.serve_forever', new_callable=asynctest.CoroutineMock) as serve:

test/test_server_asyncio.py:81:

...

if not self.create and original is DEFAULT:
    raise AttributeError(
>       "%s does not have the attribute %r" % (target, name)
    )
E   AttributeError: <class 'asyncio.base_events.Server'> does not have the attribute 'serve_forever'

This patch skips the tests if they are not in Python 3.7+.

[1] https://travis-ci.org/starnight/pymodbus/jobs/584212511
[2] https://docs.python.org/3/library/asyncio-eventloop.html#asyncio.Server.serve_forever

Fixes: commit e6da559 asyncio server implementation (#400)

* Add TLS feature for Modbus synchronous (#446)

* Add TLS feature for Modbus synchronous

Modbus.org released MODBUS/TCP Security Protocol Specification [1],
which focuses variant of the Mobdbus/TCP protocol utilizing Transport
Layer Security (TLS). This patch enables the Modbus over TLS feature as
ModbusTlsClient with the Python builtin module ssl - TLS/SSL wrapper for
socket objects.

[1]: http://modbus.org/docs/MB-TCP-Security-v21_2018-07-24.pdf

* Implement MODBUS TLS synchronous server

Since we have the MODBUS TLS synchronous client, we can also have the
MODBUS TLS synchronous server.

* Fix #461 - Udp client/server , Fix #401 - package license with source, #457 Fix typo's in docstrings, #455-Support float16

* Fix examples, Merge #431

* #401 Move license to root folder from docs

* rtu_framer: fix processing of incomplete frames (#466)

* rtu_framer: fix processing of incomplete frames

* rtu_framer: fix test case

* Add handle local echo option

* Update constants.py

Added RetryOnInvalid flag and Backoff delay.

* Update transaction.py

Added retry on invalid data received and exponetial backoff delay between retries.

* Add TLS feature for Modbus asynchronous (#470)

* Add TLS feature for Modbus asynchronous client

Since we have Modbus TLS client in synchronous mode, we can also
implement Modbus TLS client in asynchronous mode with ASYNC_IO.

* Add TLS feature for Modbus asynchronous server

Since we have Modbus TLS server in synchronous mode, we can also
implement Modbus TLS server in asynchronous mode with ASYNC_IO.

* PR #471 Fix transaction tests

* Fix failing tests

* Add "Python" trove classifier

Previously only generic "Python" support (without a version) was announced.

* Merge PR's , bump version to 2.4.0

* closes #481, #482, #483, #484

* Closes  #491

* Asyncio bug fixes (#517)

* Closes  #491

* 1. update requirements
2. Fix examples
3. Fix #494 - handle_local_echo
4. Fix #500 -- asyncio serial client with already running loop
5. Fix #486 - Pass serial args for asyncio serial client
6. Fix #490 - Typo in decode_data for socker_framer
7. Fix #385 - Support timeouts to break out of responspe await when server goes offline
8. Misc updates

* #516 custom data block fix

* Update Changelogs , bump version to 2.4.0

* #515 fix repl broadcast (#531)

* 1. update requirements
2. Fix examples
3. Fix #494 - handle_local_echo
4. Fix #500 -- asyncio serial client with already running loop
5. Fix #486 - Pass serial args for asyncio serial client
6. Fix #490 - Typo in decode_data for socker_framer
7. Fix #385 - Support timeouts to break out of responspe await when server goes offline
8. Misc updates

* #516 custom data block fix

* Fix broadcast error  with REPL client #515

* Fix #509 Wrong unit ID referenced in framers

* Update documentation for serial forwarder example. Fixes #525

* Fix unit tests, support python 3.8 for tests, renamed:    pymodbus/server/asyncio.py -> pymodbus/server/async_io.py and pymodbus/client/asynchronous/asyncio -> pymodbus/client/asynchronous/async_io

* Ignore python3 code syntax while reporting coverage

* Fix tests failing on python 3.6 and osx

* Fix typo in makefile

* Fix test execution errors specific to python3.6

* Osx travis issue - Fix trial 1

* Travis reverting xcode to 8.x for mac osx

* Pymodbus v2.4.0

Co-authored-by: dices <[email protected]>
Co-authored-by: Eric Duminil <[email protected]>
Co-authored-by: Mike <[email protected]>
Co-authored-by: Kim Hansen <[email protected]>
Co-authored-by: Michael Corcoran <[email protected]>
Co-authored-by: Andrea Canidio <[email protected]>
Co-authored-by: tcplomp <[email protected]>
Co-authored-by: alecjohanson <[email protected]>
Co-authored-by: hackerboygn <[email protected]>
Co-authored-by: Yegor Yefremov <[email protected]>
Co-authored-by: Memet Bilgin <[email protected]>
Co-authored-by: Sekenre <[email protected]>
Co-authored-by: sanjay <[email protected]>
Co-authored-by: Jian-Hong Pan <[email protected]>
Co-authored-by: Steffen Vogel <[email protected]>
Co-authored-by: Alexey Andreyev <[email protected]>
Co-authored-by: Wild Stray <[email protected]>
Co-authored-by: Lars Kruse <[email protected]>
@f-steff
Copy link

f-steff commented Nov 19, 2020

Two year later, "client.inter_char_timeout = 0.05" just saved my ass. :-)
It took me ages to discover this thread and find mpf82's comment. :-(

Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Projects
None yet
Development

No branches or pull requests

3 participants