pymodbus icon indicating copy to clipboard operation
pymodbus copied to clipboard

updated time.sleep to 0.02s in _wait_for_data() under sync.py

Open balaARR opened this issue 2 years ago • 21 comments

This pull request is created mainly to increase the "time.sleep" from 0.01 to 0.02s in _wait_for_data() under sync.py(line:766) since the function code 43/14 - Read Device Identification executed for Modbus RTU is getting failed when the time.sleep is 0.01s.

The following image shows the result of function code 43/14 execution when the time.sleep is 0.01 image The above image shows that while executing the function code 43 there seem to be some incomplete bytes at the receiving end and which breaks the execution. While analyzing the flow of the function code 43 execution in pymodbus, we have ended up at one function named _wait_for_data() which is available under pymodbus/client/sync.py.

In that when we increase the sleep time from 0.01 to 0.02, the same function code 43/14 is getting executed successfully as shown in the following image

image Hence, I am raising this pull request with the above-mentioned change. Kindly review this fix and provide your valuable suggestions.

the sample code I have used to execute the function code 43 is as follows: ' from pymodbus.client.sync import ModbusTcpClient as ModbusTCPClient from pymodbus.client.sync import ModbusSerialClient as ModbusClient from pymodbus.payload import BinaryPayloadBuilder from pymodbus.mei_message import * from pymodbus.diag_message import * from pymodbus.constants import * from pymodbus.pdu import ExceptionResponse from pymodbus.framer.socket_framer import * from pymodbus.framer.rtu_framer import * from pymodbus.factory import ClientDecoder from pymodbus.transaction import ModbusTransactionManager from pymodbus.payload import BinaryPayloadBuilder from pymodbus.pdu import ModbusExceptions from pymodbus.exceptions import ModbusException #from utility.logger import Logger import re import struct from pymodbus.bit_read_message import * from pymodbus.bit_write_message import * from pymodbus.register_read_message import * from pymodbus.register_write_message import * from pymodbus.utilities import computeCRC from pymodbus.transaction import ModbusTransactionManager from pymodbus.payload import BinaryPayloadBuilder from pymodbus.mei_message import ReadDeviceInformationRequest from pymodbus.pdu import ExceptionResponse from pymodbus.pdu import ModbusExceptions from pymodbus.exceptions import ModbusException import time

class ModbusRTU(): def init(self): self.connection = None def connect(self, method, port): self.connection = ModbusClient(method=method, port=port, baudrate=19200, parity='E', strict=False) if self.connection.connect(): print("RTU Connected")

def read_device_information(self):
    request = ReadDeviceInformationRequest(0, 1, unit=1)
    result = self.connection.execute(request)
    print(result)

modbusrtu = ModbusRTU() modbusrtu.connect('rtu', 'COM4') modbusrtu.read_device_information()

balaARR avatar Jun 07 '22 10:06 balaARR

@janiversen @dhoomakethu Could you please review this pull request?

balaARR avatar Jun 07 '22 10:06 balaARR

Of course we can, but you need to have patience.

Why do you think that 0,02 is universally true, when 0,01 is not?

This is in a loop is you use timeout (see condition function), so the sleep should not really matter.

janiversen avatar Jun 07 '22 10:06 janiversen

@balaARR thanks for the PR.

We should not be hardcoding any values in my opinion and my idea was to use the default as 0.01 and provide an option to override this sleep time via env variables. I am not keen on adding another argument to client initialization as it gets confusing with so many args.

dhoomakethu avatar Jun 07 '22 14:06 dhoomakethu

I thought the 0,01 was to allow other threads to run. If you use timeout in the call it will loop automatically.

I am looking at replacing these short sleeps with “yield” to avoid confusion about why there are there.

janiversen avatar Jun 07 '22 14:06 janiversen

**Of course we can, but you need to have patience.

Why do you think that 0,02 is universally true, when 0,01 is not?

This is in a loop is you use timeout (see condition function), so the sleep should not really matter**

@janiversen

We have just tried to increase the timing and given as 0.02. Since with time.sleep(0.02) it is passing, my pull request contains this change. Here, we are not specifying any values, where as the intention is to execute the function code 43 without any error.

balaARR avatar Jun 07 '22 16:06 balaARR

But because it works for you, does not mean it is a general solution at least you have not convinced me (e.g. for lower BPS it surely needs to be longer).

Did you try with timeout, because if not it is understandable why you need sleep to be bigger. With timeout active the size of the sleep do not matter.

Anyhow, this time.sleep will be converted to a yield (which was not available in python 2.x) because the intention is to allow the reading thread to work.

janiversen avatar Jun 07 '22 17:06 janiversen

Did you try with timeout, because if not it is understandable why you need sleep to be bigger. With timeout active the size of the sleep do not matter. @janiversen I have tried out with specifying timeout value in the "connect" method. And still facing the same issue. image image

Could you please suggest me any other way through which we can activate the timeout apart from specifying it in the connect method?

balaARR avatar Jun 07 '22 17:06 balaARR

For example read the documentation.

As you can see the stack trace is not initiated by the while loop, so are you sure the while loop is actually run multiple times?

What you do is to make a test case (see directory test) that proves 0.01 is wrong and 0.02 always work.

janiversen avatar Jun 07 '22 17:06 janiversen

Right now both @dhoomakethu and myself believes this PR is not correct even though it works in your case.

janiversen avatar Jun 07 '22 17:06 janiversen

As you can see the stack trace is not initiated by the while loop, so are you sure the while loop is actually run multiple times? @janiversen
In my case the while loop is running for two times and at the second time it breaks for the following condition if (more_data and not avaialble) or (more_data and avaialble == size)

What you do is to make a test case (see directory test) that proves 0.01 is wrong and 0.02 always work. Yes. We will try to make test case for this under the test directory.

balaARR avatar Jun 07 '22 18:06 balaARR

**Why do you think that 0,02 is universally true, when 0,01 is not?

This is in a loop is you use timeout (see condition function), so the sleep should not really matter**

@janiversen @dhoomakethu

The actual reason behind this update is that, when the time.sleep is 0.01s in _wait_for_data(), it is not enough to read new data, and meanwhile, timeout while loop breaks if there is no new data read in this 0.01 sec sleep for the following "IF" condition at the second iteration itself. if (more_data and not avaialble) or (more_data and avaialble == size):

The following image shows the breakage in the while loop after the 2nd iteration for the above-mentioned IF condition, so that the time.sleep(0.01) is getting executed only once and that time is not enough to read the complete device information using function code 43.(incomplete RECV bytes have been highlighted in the image) image

Here 0.01 sec == 10ms and In this particular test scenario I am expecting 82 byte long response and @19200 baudrate which takes around 47ms.

Hence, by increasing time.sleep we get enough to receive new response bytes and above mentioned if condition doesn't fail. We have tried out another method to address this fix. Instead of increasing sleep time, we can retry more than once if we don't receive any new response bytes after 0.01 sec sleep

The updated _wait_for_data() will be looking as follows:

def _wait_for_data(self):
    size = 0
    more_data = False
    retry_count = 0
    if self.timeout is not None and self.timeout != 0:
        condition = partial(lambda start, timeout:
                            (time.time() - start) <= timeout,
                            timeout=self.timeout)
    else:
        condition = partial(lambda dummy1, dummy2: True, dummy2=None)
    start = time.time()
    index = 1
    print("****While loop iteration count***")
    while condition(start):
        avaialble = self._in_waiting()
        print("Iteration:", index)
        print("Available Byte size:", avaialble)
        print(retry_count)

        **if ((more_data and not avaialble) or (more_data and avaialble == size)):
            retry_count+=1

        if retry_count >= 2:
            break**

        if avaialble and avaialble != size:
            more_data = True
            size = avaialble

        index += 1            
        time.sleep(0.01)
    return size

image

The highlighted text in the output image indicates the received bytes which are available at each iteration and in our scenario the required 80 bytes were completely getting received at the 5th iteration only.

Here, the retry_count will not break the while loop until it reaches its specified value and in that way, we are increasing the usage of time.sleep without modifying the default value of 0.01. Hence using this way, increase the sleep time so the complete data can be read using Modbus function code 43/14

With this solution, we just don't break out of this while loop if we don't have any new bytes after 10 ms. We retry 2 more times before concluding there is no new data. And this will remove the need to increase sleep time.

Could please provide your valuable suggestions after going through this comment?

balaARR avatar Jun 08 '22 11:06 balaARR

@balaARR can you share more info on the list of modbus slaves for which this fix was required to get it working. With the limited devices I have for testing 0.01 was sufficient enough. I am not denying the fact that 0.01 sec is still not foolproof but it works for the majority of the cases. The ideal solution would be to somehow move away from timeouts/sleeps to fetch the data in a better way,which unfortunately I do not have time to sit and design.

dhoomakethu avatar Jun 08 '22 11:06 dhoomakethu

Also please note, the behavior changes from slave to slave and the way the read/write buffers are handled a d the implementation of different function codes on the slave. 0.02 might still not work for other slaves out there and keeping on bumping the sleep time is not just sustainable.

dhoomakethu avatar Jun 08 '22 11:06 dhoomakethu

can you share more info on the list of modbus slaves for which this fix was required to get it working. With the limited devices I have for testing 0.01 was sufficient enough.

@dhoomakethu We are using only one slave device and that contains its own device information available in it. Now we are trying to use Modbus Function Code 43/14 to read the slave device information through Modbus RTU. We have tried the following 3 types of requests for verifying Function Code 43/14

  1. Basic Request - Read Device ID =>1
  2. Regular Request - Read Device ID =>2
  3. Individual Request - Read Device ID =>4

(Note: We have not tried Extended Request - Read Device ID => 4) Our automated test cases fetch the required objects based on the read device ID and the Object ID that we are specifying as an input to the function code 43/14

image

balaARR avatar Jun 08 '22 12:06 balaARR

Thank you , that is exactly what I am trying to say, it makes no sense to change something because it's not working for one hardware. My suggestion to you would be to use your patched version for your need for now.

dhoomakethu avatar Jun 08 '22 13:06 dhoomakethu

Thank you, that is exactly what I am trying to say, it makes no sense to change something because it's not working for one hardware. My suggestion to you would be to use your patched version for your need for now.

@dhoomakethu But we have tried with other hardware also(i.e., tried with different hardware and used that hardware as slaves. But during the run time there is going to be only one slave). And, still we were facing the same issue. (i.e receiving incomplete bytes)

balaARR avatar Jun 08 '22 13:06 balaARR

Please create an issue with the details of the hardware, it's specs and logs, so that it can be analysed. Thanks for your interest in the project

dhoomakethu avatar Jun 08 '22 13:06 dhoomakethu

Please create an issue with the details of the hardware, its specs, and logs, so that it can be analyzed.

@dhoomakethu Yeah sure. Thank you so much for the guidance.

balaARR avatar Jun 08 '22 13:06 balaARR

@balaARR I Think you are forgetting a couple of Modbus restriccions.

0.01 is too fast for your setup running, and 0.02 is just perfect. But you are using 19.200Bps what happens it you run 2.400Bps, do we then need to bump it again (at least that would be logical).

My System runs 115.000Bps (and experimental 240.000Bps), and my System runs in listen Mode (debugging everything). Modbus demands a pause of 3.5 Char between messagees, and with 0.02 you are hitting that limit, meaning sometimes 2 messagees are seen as one, which surely not is what you wanted.

I am aware that @dhoomakethu do not have a lot of time at the moment, but the transport layer is being rewritten as we speak especially due to the many problems we see with broken messagees. This work is Something I hope to finalize and integrate next month (@dhoomakethu this is the real reason why my flow of commits have been lower lately).

janiversen avatar Jun 08 '22 13:06 janiversen

This PR is stale because it has been open 45 days with no activity. Remove stale label or comment or this will be closed in 10 days.

github-actions[bot] avatar Jul 24 '22 03:07 github-actions[bot]

Are you still working on a generic solution ?

janiversen avatar Jul 26 '22 21:07 janiversen

This PR is stale because it has been open 45 days with no activity. Remove stale label or comment or this will be closed in 10 days.

github-actions[bot] avatar Sep 10 '22 03:09 github-actions[bot]

closing

janiversen avatar Sep 10 '22 05:09 janiversen