Decoder exceptions ufter updating 3.4.3->3.6.4 using server #2018
Comments
|
At a first glance the packet you receive looks ok, let me add it to our test cases and see what happens. |
janiversen
changed the title
janiversen
changed the title
janiversen
changed the title
|
You have strange overlapping calls: Here you do a read_coils and get a response. But then: You get a response from a read_holding, which was issued much earlier (transaction 0x8 0xa4 version 0xf 0x3c) Please make a short code part that isolates the problem, then I can simulate it. If you cannot make a short code example, then I need to see the code where you call pymodbus together with a full log (until the problem occurs). |
|
I just analyzed the frame that causes the problems: The MBAP header says length = 0x0 0x6 and 0x1 which is slave=1, the response is: Funcion = 0x3, length in bytes = 0x0, and then 2 registers (4 bytes). So your device responds with a wrong count. The next frame have a corrupted MBAP header (missing 1 byte) and the response again have byte count = 0, but there are 4 bytes. This can happen because you have overlapping calls, a lot of devices do not support that. And between 3.4.1 and 3.6.2 we added a faster transport, that might be the reason why you see it. Between 3.6.2 and 3.6.4 we corrected the length, but that does not really affect your problem, since the packets we receive are wrong. |
may be that is because (as I wrote upper) in my project one task reads devices and another task is Modbus Server that responce requests from client. and in logs all recieves and sends are mixed
may be it is wrong, but as i see we get 2 frames here: pymodbus/pymodbus/framer/socket_framer.py Lines 145 to 146 in b4490ab must be 0x3 0x0 0x16 0x0 0x2 but decoder receives 0x3 0x0 0x16 0x0 0x2 0x8 (+ first byte of next transuction number) this exception is rare and I haven't stable conditions to repeate it now (just working on it). |
|
The MBAP header is 7 bytes, and the length = 0x0 0x06, giving a packet length 0f 13 bytes. length = 6 is 0x3 0x0 0x16 0x0 0x2 0x8, remark a register is 2 bytes there are 2 registers in the response. 0x3 0x0 0x16 0x0 0x2, is not a valid response, because registers are always 2 bytes so it missed a byte. It is correct it looks a lot like the device did not send the last byte and instead started a new packet....but that is a device problem. This response is <byte length * 2>....data (2 bytes for each register) So in total it seems your device have 2 problems:
both problems are outside our control. |
|
Sorry I can't understand why you don't count Unit identifier byte in length? In my case i dont read device here, Modbus server receive read data request (and we see receive log string) from another programm that use pymodbus too to read data from it |
|
You are right, the length is the remaining data, but Unit identifier is part of the MBAP header, if you do not believe me then please read the the standard. Anyhow second problem is in the frame itself, where byte count is wrong. |
|
the log must be from a pymodbus client, because you see a request being sent, the server sends responses. Your last sentence is very confusing, please clarify exactly from where is the log. And you were right that the unit identifier is not part of the header, but the frame is even more wrong:
So in any case the frame is wrong ! and pymodbus correctly identifies that. |
|
please be a bit more specific about from where the log comes, I think there are a number of misunderstandings here (and it might be my misunderstandings). And I also think I need a bit more log, so I can follow the flow. If the log is from a pymodbus server and the client is also pymodbus, then please provide both logs so it's possible to follow a complete flow. |
|
Thanks for reply |
|
This are separate programs: pymodbus reader and pymodbus server with their own logs I joined logs in order to sea processes in conjunction so, I put here 2 logs |
|
Thanks it look ore understandable, I have a closer look but not today |
|
A couple of observations, about the 3.6.4 logs:
If you still have the logs, please amend first reader, with the send that caused the Frame check failure when returned, and please amend first server, with the receive of the request that leads to the frame check failure. |
|
ok, I make test stands from client and server examples server: import logging
FORMAT = ('%(asctime)-15s %(message)s')
logging.basicConfig(format=FORMAT)
log = logging.getLogger()
log.setLevel(logging.DEBUG)
from pymodbus.datastore import (ModbusSequentialDataBlock, ModbusServerContext,
ModbusSlaveContext)
from pymodbus.server.async_io import StartTcpServer
from threading import Thread
import time
def updating_writer(con):
time.sleep(1)
context = con['con']
context[0].setValues(3, 0, [777])
def run_server():
store = ModbusSlaveContext(
hr=ModbusSequentialDataBlock(0, [3]*1)
)
context = ModbusServerContext(slaves=store, single=True)
updating_writer_thread = Thread(target = updating_writer, args = [{'con':context}])
updating_writer_thread.daemon=True
updating_writer_thread.start()
StartTcpServer(context=context, address=("127.0.0.1", 5021))
if __name__ == "__main__":
run_server()reader: from pymodbus.client.tcp import AsyncModbusTcpClient
import asyncio
import logging
FORMAT = ('%(asctime)-15s %(message)s')
logging.basicConfig(format=FORMAT)
log = logging.getLogger()
log.setLevel(logging.DEBUG)
N = 3
async def main():
c = AsyncModbusTcpClient('127.0.0.1', 5021)
await c.connect()
tasks = []
for _ in range(N):
tasks.append(c.read_holding_registers(0, 1, 1))
# r = await c.connection.read_holding_registers(0, 1, 1)
read_result = await asyncio.gather(*tasks)
for i, r in enumerate(read_result):
print(f'result {i}: {r.registers}')
if __name__ == "__main__":
asyncio.run(main())full logs of 3.6.4 logs from 3.6.2 |
|
sorry, in reader I imported client from my project P.S. correct previous comment to use only pymodbus lib |
|
Hmmm that is very good hint, let me build that into the simulation of your bug. |
Versions
Pymodbus Specific
Description
First, great thanks fot that product!!
In my project I use sevetal conponents wiht pymodbus
one read data from sources, process it and exports through MBServer
another read it, send to UI and so on.
All worked at 3.4.3 for several month
till I try to update to latest ver 3.6.4
so MB Server sometimes begin to rise
'Unknown exception "unpack requires a buffer of 4 bytes" on stream server forcing disconnect'
so I repeat update step by step from 3.4.3 to trace beginning of problem
it begins from 3.6.2->3.63 update
exception is rising here:
pymodbus/pymodbus/register_read_message.py
Lines 43 to 48 in b4490ab
debug shows that data is 5 bytes sometimes
maybe it related to "solve Socket_framer problem with Exception response (#1925)"
I view logs and see strange packets like this:
2024-02-14 17:35:57,574 MainThread DEBUG logging :103 Processing: 0x8 0xa4 0x0 0x0 0x0 0x6 0x1 0x3 0x0 0x16 0x0 0x2 0x8 0xa3 0x0 0x0 0x0 0x6 0x1 0x3 0x0 0x16 0x0 0x2
Is it correct?
when process such packet socet framer send 5 bytes data to decoder from here:
pymodbus/pymodbus/framer/socket_framer.py
Lines 145 to 146 in b4490ab
and self.getFrame() frame length is what was changed at 3.6.3 (#1925)
Here is log part of 3.6.3 with
2024-02-14 17:35:57,355 - normal packet
2024-02-14 17:35:57,574 - ''double'' packet
2024-02-14 17:35:58,305 - next normal packet
Code and Logs
The text was updated successfully, but these errors were encountered: