Reading input registers in a loop [serial]

[palorenz]

Hi,

I have a small script that reads input registers (sensor data) in a loop.

pymodbus: 3.8.0 (and also current dev)
serial synchronous communication 9600,8,n,1

The configured read timeout always elapses between two read operations:

DEBUG:pymodbus.logging:Sleeping
DEBUG:pymodbus.logging:Sleeping
DEBUG:pymodbus.logging:Spent more time than the read time out, resetting the transaction to IDLE
DEBUG:pymodbus.logging:New Transaction state "SENDING"
DEBUG:pymodbus.logging:Processing: 0x1 0x4 0xba 0x0 0x0 0x0 0x0 0x11 0x1a 0x0 0x0 0x0 0x0 0x0 0x0 0x11 0x31 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x1 0x2 0x5 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 0x0 0x0 0x0
DEBUG:pymodbus.logging:Frame - not ready
DEBUG:pymodbus.logging:Processing: 0x1 0x4 0xba 0x0 0x0 0x0 0x0 0x11 0x1a 0x0 0x0 0x0 0x0 0x0 0x0 0x11 0x31 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x1 0x2 0x5 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 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x4 0xc3 0x13 0x8a 0xf 0xe8 0x0 0x6 0x0 0x0 0x11 0xfa 0x10 0x5 0x0 0x6 0x0 0x0 0x0 0x0 0xf 0xde 0x0 0x6 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x33 0x0 0x2 0xb6 0x32 0x6 0x40 0xbc 0x71 0x0 0x0 0x0 0x0 0x0
DEBUG:pymodbus.logging:Frame - not ready
DEBUG:pymodbus.logging:Processing: 0x1 0x4 0xba 0x0 0x0 0x0 0x0 0x11 0x1a 0x0 0x0 0x0 0x0 0x0 0x0 0x11 0x31 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x1 0x2 0x5 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 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x4 0xc3 0x13 0x8a 0xf 0xe8 0x0 0x6 0x0 0x0 0x11 0xfa 0x10 0x5 0x0 0x6 0x0 0x0 0x0 0x0 0xf 0xde 0x0 0x6 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x33 0x0 0x2 0xb6 0x32 0x6 0x40 0xbc 0x71 0x0 0x0 0x0 0x0 0x0 0x1 0x3b 0xf8 0x0 0x0 0x0 0x0 0x0 0x1 0x2f 0x58 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 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x2 0x6b
DEBUG:pymodbus.logging:Frame - not ready
DEBUG:pymodbus.logging:Processing: 0x1 0x4 0xba 0x0 0x0 0x0 0x0 0x11 0x1a 0x0 0x0 0x0 0x0 0x0 0x0 0x11 0x31 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x1 0x2 0x5 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 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x4 0xc3 0x13 0x8a 0xf 0xe8 0x0 0x6 0x0 0x0 0x11 0xfa 0x10 0x5 0x0 0x6 0x0 0x0 0x0 0x0 0xf 0xde 0x0 0x6 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x33 0x0 0x2 0xb6 0x32 0x6 0x40 0xbc 0x71 0x0 0x0 0x0 0x0 0x0 0x1 0x3b 0xf8 0x0 0x0 0x0 0x0 0x0 0x1 0x2f 0x58 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 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x2 0x6b 0x50 0x1 0x50 0x7d 0x89
DEBUG:pymodbus.logging:decoded PDU function_code(4 sub -1) -> ReadInputRegistersResponse(dev_id=0, transaction_id=0, address=0, count=0, bits=[], registers=[0, 0, 4378, 0, 0, 0, 4401, 0, 0, 0, 1, 517, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 1219, 5002, 4072, 6, 0, 4602, 4101, 6, 0, 0, 4062, 6, 0, 0, 0, 0, 0, 0, 51, 2, 46642, 1600, 48241, 0, 0, 1, 15352, 0, 0, 1, 12120, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 2, 27472, 336], status=1) 
DEBUG:pymodbus.logging:Frame advanced, resetting header!!
DEBUG:pymodbus.logging:Sleeping
DEBUG:pymodbus.logging:Sleeping
DEBUG:pymodbus.logging:Sleeping

[...]

DEBUG:pymodbus.logging:Sleeping
DEBUG:pymodbus.logging:Sleeping
DEBUG:pymodbus.logging:Sleeping
DEBUG:pymodbus.logging:Sleeping
DEBUG:pymodbus.logging:Sleeping
DEBUG:pymodbus.logging:Spent more time than the read time out, resetting the transaction to IDLE
DEBUG:pymodbus.logging:New Transaction state "SENDING"
DEBUG:pymodbus.logging:Processing: 0x1 0x4 0x3c 0x0 0x0 0x3 0x20 0x0 0x0 0x0 0x0 0x6 0xa 0x0 0xc 0x0 0x0 0x0 0x0 0x0 0x11 0xff 0xe2 0x0 0xa 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x44 0xff 0xff 0x0 0x34 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x3 0x20 0x0 0x0 0x0 0x33 0x0 0x1d 0x0 0x2a 0x0 0x0 0x3
DEBUG:pymodbus.logging:Frame - not ready
DEBUG:pymodbus.logging:Processing: 0x1 0x4 0x3c 0x0 0x0 0x3 0x20 0x0 0x0 0x0 0x0 0x6 0xa 0x0 0xc 0x0 0x0 0x0 0x0 0x0 0x11 0xff 0xe2 0x0 0xa 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x44 0xff 0xff 0x0 0x34 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x3 0x20 0x0 0x0 0x0 0x33 0x0 0x1d 0x0 0x2a 0x0 0x0 0x3 0x20 0xf4 0x24
DEBUG:pymodbus.logging:decoded PDU function_code(4 sub -1) -> ReadInputRegistersResponse(dev_id=0, transaction_id=0, address=0, count=0, bits=[], registers=[0, 800, 0, 0, 1546, 12, 0, 0, 17, 65506, 10, 0, 0, 0, 0, 0, 68, 65535, 52, 0, 0, 0, 0, 800, 0, 51, 29, 42, 0, 800], status=1) 
DEBUG:pymodbus.logging:Frame advanced, resetting header!!

It looks to me as if the ModbusTransactionSate.TRANSACTION_COMPLETE is never set, but the send method of the ModbusSerialClient waits for this state.

I have set the state to TRANSACTION_COMPLETE at the end of ModbusSerialClient::recv. This works for me, but it doesn't feel right:

DEBUG:pymodbus.logging:New Transaction state "SENDING"
DEBUG:pymodbus.logging:Processing: 0x1 0x3 0x3c 0x0 0x1 0xa9 0x48 0x0 0x0 0x0 0x64 0x0 0x64 0x27 0x10 0x0 0x0 0x27 0x10 0xe 0x10 0x59 0x41 0x31 0x2e 0x30 0x0 0x5a 0x44 0x41 0x41 0x0 0x8 0x0 0x2 0x0 0x0 0x0 0x0 0x0 0x46 0x0 0x46 0x0 0x5a 0x0 0x5a 0x0 0x0 0x54 0x50 0x4a 0x34 0x43 0x48 0x57 0x30 0x4a 0x4c 0x1 0x3 0xf8
DEBUG:pymodbus.logging:Frame - not ready
DEBUG:pymodbus.logging:Processing: 0x1 0x3 0x3c 0x0 0x1 0xa9 0x48 0x0 0x0 0x0 0x64 0x0 0x64 0x27 0x10 0x0 0x0 0x27 0x10 0xe 0x10 0x59 0x41 0x31 0x2e 0x30 0x0 0x5a 0x44 0x41 0x41 0x0 0x8 0x0 0x2 0x0 0x0 0x0 0x0 0x0 0x46 0x0 0x46 0x0 0x5a 0x0 0x5a 0x0 0x0 0x54 0x50 0x4a 0x34 0x43 0x48 0x57 0x30 0x4a 0x4c 0x1 0x3 0xf8 0xa1 0x5f 0x13
DEBUG:pymodbus.logging:decoded PDU function_code(3 sub -1) -> ReadHoldingRegistersResponse(dev_id=0, transaction_id=0, address=0, count=0, bits=[], registers=[1, 43336, 0, 100, 100, 10000, 0, 10000, 3600, 22849, 12590, 12288, 23108, 16705, 8, 2, 0, 0, 70, 70, 90, 90, 0, 21584, 18996, 17224, 22320, 19020, 259, 63649], status=1) 
DEBUG:pymodbus.logging:Frame advanced, resetting header!!
DEBUG:pymodbus.logging:Changing state to IDLE - Last Frame End - 1734435147.0969 Current Time stamp - 1734435147.097328
DEBUG:pymodbus.logging:Waiting for 3.5 char before next send - 3.646 ms
DEBUG:pymodbus.logging:New Transaction state "SENDING"
DEBUG:pymodbus.logging:Processing: 0x1 0x4 0xba 0x0 0x0 0x0 0x45 0x11 0x32 0x0 0x0 0x0 0x0 0x0 0x45 0x11 0x4a 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x1 0x2 0x5 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 0x0 0x0 0x0
DEBUG:pymodbus.logging:Frame - not ready

I have seen that there is work being done in that area. Hence the question: Is this a known problem, or am I doing something wrong? Where should the state be set correctly?

Thanks in advance,

Patrick

[janiversen]

hmmm this looks like a serious bug, I wonder why our test harness did not catch it....I will investigate.

[janiversen]

Bug confirmed (still do not understand how it passed the test harness).

It is actually working, but very slow (because it's sleeping a lot)....so it is a serious bug, which we will fix fast, and then release as v3.8.1.

[palorenz]

Thanks a lot! I also was looking for tests regarding the send-method of ModbusSerialClient. Seems that it is tested in context of high level examples only and these work, but might be slow.

[janiversen]

Fix is available on dev, please test and confirm that it works.

#2510

[palorenz]

Wow, that was fast :-) Works fine for me. Thanks a lot!!