Skip to content

Conversation

@sfarbotka
Copy link

This change fixes errors in processing of incomplete frames. Some of them lead to the situation where the framer starts raising exception for all future frames. For example, when only first byte is added to self._buffer, self.populateHeader() adds unit ID to self._header only, and self.isFrameReady() starts raising exceptions until framer instance is re-created.

On the other hand, the code of RTU framer now is consistent with implementation of other framer (same function do the same).

Additionally, to be sure that all changes work, more test module was populated with some new tests, which also improves coverage.

Copy link
Author

@sfarbotka sfarbotka left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Please, find my comments in the code to speed up the process of code review

:param decoder: The decoder factory implementation to use
"""
self._buffer = b''
self._header = {'uid': 0x00, 'len': 0, 'crc': '0000'}
Copy link
Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Other parts of the code expect that crc is bytes object

self.populateHeader()
frame_size = self._header['len']
data = self._buffer[:frame_size - 2]
crc = self._buffer[frame_size - 2:frame_size]
Copy link
Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

crc is already extracted from message and can be accessed as self._header['len'], no need to extract it again

# Error response, no header len found
self.resetFrame()

self._buffer = self._buffer[self._header['len']:]
Copy link
Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

In this pull request self._header now always populated with len key (as in other framer classes - binary, ascii, socket, etc). That's why try/catch is not required anymore.

self._buffer = self._buffer[self._header['len']:]
_logger.debug("Frame advanced, resetting header!!")
self._header = {}
self._header = {'uid': 0x00, 'len': 0, 'crc': b'\x00\x00'}
Copy link
Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

This change makes self._header content consistent with other framer classes, and resolves issues when some functions expect that this dict always contain some keys.

"buffer - {}".format(hexlify_packets(self._buffer)))
self._buffer = b''
self._header = {}
self._header = {'uid': 0x00, 'len': 0, 'crc': b'\x00\x00'}
Copy link
Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

This change makes self._header content consistent with other framer classes, and resolves issues when some functions expect that this dict always contain some keys.

size = pdu_class.calculateRtuFrameSize(data)
self._header['len'] = size

if len(data) < size:
Copy link
Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Slice operation data[size - 2:size] doesn't raise IndexError if there is not enough data in array. But other functions in this module expects that this method raises exception in case of incomplete frame. That's why this if is added

@pytest.mark.parametrize("data", [b'', b'abcd'])
def test_advance_framer(rtu_framer, data):
rtu_framer._buffer = data
@pytest.mark.parametrize("data", [
Copy link
Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Useless tests (which do not test anything but only improve code coverage) are replaced with new tests.

data, expected = data
rtu_framer._buffer = data
rtu_framer.advanceFrame()
# rtu_framer.advanceFrame()
Copy link
Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

This function is useless here and only adds some complexity to the code. It is removed, and some additional test cases are added to be sure that this function works in other cases

b'\x11\x03\x06',
b'\x11\x03\x06\xAE\x41\x56\x52\x43\x40\x43',
])
def test_rtu_populate_header_fail(rtu_framer, data):
Copy link
Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Ensure that populateHeader() properly deals with incomplete frames

(b'\x11\x03\x06\xAE\x41\x56\x52\x43\x40\x49\xAD', 16, True, False), # incorrect unit id
(b'\x11\x03\x06\xAE\x41\x56\x52\x43\x40\x49\xAD\x11\x03', 17, False, True), # good frame + part of next frame
])
def test_rtu_process_incoming_packet(rtu_framer, data):
Copy link
Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Improve coverage and ensure that RTU framer properly deals with incomplete frames

@sonarqubecloud
Copy link

Kudos, SonarCloud Quality Gate passed!

Bug A 0 Bugs
Vulnerability A 0 Vulnerabilities
Security Hotspot A 0 Security Hotspots
Code Smell A 0 Code Smells

No Coverage information No Coverage information
0.0% 0.0% Duplication

@sfarbotka
Copy link
Author

It looks like all failed tests are not related to my changes

@dhoomakethu
Copy link
Contributor

@sfarbotka Thanks for the PR. I will take a look in to this.

@sfarbotka sfarbotka marked this pull request as ready for review February 26, 2021 10:40
@sfarbotka
Copy link
Author

Tested the fix using real RTU MODBUS connection, I didn't see any stack traces as before, and didn't found any regressions.

@dhoomakethu
Copy link
Contributor

@sfarbotka Thanks for the PR, this is now merged as part of PR #605. I will be closing this PR

@dhoomakethu dhoomakethu closed this Mar 2, 2021
@olddudealex
Copy link

olddudealex commented Mar 9, 2021

@sfarbotka This fix perfectly works in synchronous mode, but fails when asyncio used. The _validate_unit_id returns False inside processIncomingPacket function. The reason is difference between calling arguments of processIncomingPacket function in sync and async backend.
In transaction.py the call looks like (sync mode):
self.client.framer.processIncomingPacket(response, addTransaction, request.unit_id)
and it make sense to compare the request and response slave id.
In async_io\__init__.py (async mode):
unit = self.framer.decode_data(data).get("unit", 0)
self.framer.processIncomingPacket(data, self._handleResponse, unit=unit)

At best (if message is received full) the unit tries to be extracted from response and then compare with itself in processIncomingPacket/_validate_unit_id.
At worst (if message is received partly) the last portion of message is passed to decode_data and unit start to be incorrect. And then _validate_unit_id returns False.

Don't know a good way to fix this, just comment out the call to _validate_unit_id.

@dhoomakethu
Copy link
Contributor

@olddudealex that seems to be the expected behaviour right? If there is an incomplete data and unit id is not extracted the validation should fail . With async client, it's hard to keep track of the requests and map it to the response incoming. I will take a look but if you have logs of your failing cases that could help us more with coming up with a proper solution.

@olddudealex
Copy link

@dhoomakethu, sorry for long response. Below is the log file of failing unit id validation.

2021-03-25 23:47:13,091 MainThread      DEBUG    selector_events:53       Using selector: SelectSelector
2021-03-25 23:47:13,097 MainThread      DEBUG    __init__       :789      Connecting.
2021-03-25 23:47:13,106 MainThread      DEBUG    __init__       :106      Client connected to modbus server
2021-03-25 23:47:13,106 MainThread      INFO     __init__       :806      Protocol made connection.
2021-03-25 23:47:13,106 MainThread      INFO     __init__       :798      Connected to COM57
2021-03-25 23:47:13,107 MainThread      DEBUG    mdbs_master    :27       Read input registers
2021-03-25 23:47:13,107 MainThread      DEBUG    __init__       :140      send: 0x1 0x4 0x0 0x1 0x0 0xe 0x20 0xe
2021-03-25 23:47:13,107 MainThread      DEBUG    transaction    :448      Adding transaction 1
2021-03-25 23:47:13,148 MainThread      DEBUG    __init__       :149      recv: 0x1 0x4 0x1c 0x55 0x55 0x55
2021-03-25 23:47:13,149 MainThread      DEBUG    rtu_framer     :240      Frame - [b'\x01\x04\x1cUUU'] not ready
2021-03-25 23:47:13,164 MainThread      DEBUG    __init__       :149      recv: 0x55 0x55 0x55 0x55 0x55 0x55 0x55 0x55
2021-03-25 23:47:13,164 MainThread      DEBUG    rtu_framer     :240      Frame - [b'UUUUUUUU'] not ready
2021-03-25 23:47:13,181 MainThread      DEBUG    __init__       :149      recv: 0x55 0x55 0x55 0x55 0x55 0x55 0x55
2021-03-25 23:47:13,181 MainThread      DEBUG    rtu_framer     :240      Frame - [b'UUUUUUU'] not ready
2021-03-25 23:47:13,196 MainThread      DEBUG    __init__       :149      recv: 0x55 0x55 0x55 0x55 0x55 0x55 0x55 0x55
2021-03-25 23:47:13,196 MainThread      DEBUG    rtu_framer     :240      Frame - [b'UUUUUUUU'] not ready
2021-03-25 23:47:13,213 MainThread      DEBUG    __init__       :149      recv: 0x55 0x55 0xf3 0xbf
2021-03-25 23:47:27,496 MainThread      DEBUG    rtu_framer     :234      Not a valid unit id - 1, ignoring!!
2021-03-25 23:47:32,495 MainThread      DEBUG    rtu_framer     :120      Resetting frame - Current Frame in buffer - 0x1 0x4 0x1c 0x55 0x55 0x55 0x55 0x55 0x55 0x55 0x55 0x55 0x55 0x55 0x55 0x55 0x55 0x55 0x55 0x55 0x55 0x55 0x55 0x55 0x55 0x55 0x55 0x55 0x55 0x55 0x55 0xf3 0xbf

If in the line 230 in pymodbus/framer/rtu_framer.py remove unit validation:

                if True: #if self._validate_unit_id(unit, single):

messages will start to receive correctly.
The reason, as I said, in pymodbus/client/asynchronous/async_io/init.py code:

        # here decode_data assigns unit to the first byte of last part of message, 0x55 in the example above
        unit = self.framer.decode_data(data).get("unit", 0)  
        self.framer.processIncomingPacket(data, self._handleResponse, unit=unit)

@github-actions github-actions bot locked as resolved and limited conversation to collaborators Apr 21, 2023
Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.

Projects

None yet

Development

Successfully merging this pull request may close these issues.

4 participants