Async client not working when sync client is.

hectovs commented 4 months ago

Versions

Python: 3.9.2
OS: Raspbian 11 (Bullseye)
Pymodbus: 3.6.4
Modbus Hardware (if used): Raspberry Pi 4B GPIO Pins 14,15 (using UART port) to a non-pymodbus device.

Pymodbus Specific

Client: rtu - async serial

Description

I have successfully run the client with the synchronous client but when I switch to the asynchronous client it no longer works. On viewing the logs, it looks like there's a mismatch between the transaction numbers and the asynchronous client is perceiving the response to be an unrequested message. How can I fix this

Code

# code and logs here.
```python

client = ModbusClient.AsyncModbusSerialClient(
        port="/dev/ttyS0",
        method="rtu", 
        baudrate=9600,
        bytesize=8,
        parity="N",
        stopbits=1
)

await client.connect()
response1 = await async_client.read_holding_registers(address=124, count=4,unit=0)

Logs

2024-02-15 14:16:38,974 DEBUG logging:103 Connecting to /dev/ttyS0.
2024-02-15 14:16:38,975 DEBUG logging:103 Connecting comm
2024-02-15 14:16:38,976 DEBUG logging:103 Connected to comm
2024-02-15 14:16:38,976 DEBUG logging:103 callback_connected called
2024-02-15 14:16:38,977 DEBUG logging:103 Adding transaction 0
2024-02-15 14:16:38,977 DEBUG logging:103 send: 0x0 0x3 0x0 0x7c 0x0 0x4 0x84 0x0
2024-02-15 14:16:39,048 DEBUG logging:103 recv: 0x1 old_data:  addr=None
2024-02-15 14:16:39,048 DEBUG logging:103 Processing: 0x1
2024-02-15 14:16:39,049 DEBUG logging:103 recv: 0x3 old_data:  addr=None
2024-02-15 14:16:39,049 DEBUG logging:103 Processing: 0x3
2024-02-15 14:16:39,050 DEBUG logging:103 recv: 0x8 old_data:  addr=None
2024-02-15 14:16:39,050 DEBUG logging:103 Processing: 0x8
2024-02-15 14:16:39,051 DEBUG logging:103 recv: 0x0 old_data:  addr=None
2024-02-15 14:16:39,051 DEBUG logging:103 Processing: 0x0
2024-02-15 14:16:39,051 DEBUG logging:103 Frame - not ready
2024-02-15 14:16:39,052 DEBUG logging:103 recv: 0x5 old_data:  addr=None
2024-02-15 14:16:39,052 DEBUG logging:103 Processing: 0x5
2024-02-15 14:16:39,052 DEBUG logging:103 Frame - not ready
2024-02-15 14:16:39,053 DEBUG logging:103 recv: 0x0 old_data:  addr=None
2024-02-15 14:16:39,053 DEBUG logging:103 Processing: 0x0
2024-02-15 14:16:39,053 DEBUG logging:103 Frame - not ready
2024-02-15 14:16:39,054 DEBUG logging:103 recv: 0x5 old_data:  addr=None
2024-02-15 14:16:39,054 DEBUG logging:103 Processing: 0x5
2024-02-15 14:16:39,054 DEBUG logging:103 Frame - not ready
2024-02-15 14:16:39,055 DEBUG logging:103 recv: 0x0 old_data:  addr=None
2024-02-15 14:16:39,055 DEBUG logging:103 Processing: 0x0
2024-02-15 14:16:39,055 DEBUG logging:103 Frame - not ready
2024-02-15 14:16:39,056 DEBUG logging:103 recv: 0x0 old_data:  addr=None
2024-02-15 14:16:39,056 DEBUG logging:103 Processing: 0x0
2024-02-15 14:16:39,057 DEBUG logging:103 Frame - not ready
2024-02-15 14:16:39,057 DEBUG logging:103 recv: 0x0 old_data:  addr=None
2024-02-15 14:16:39,057 DEBUG logging:103 Processing: 0x0
2024-02-15 14:16:39,057 DEBUG logging:103 Frame - not ready
2024-02-15 14:16:39,058 DEBUG logging:103 recv: 0x0 old_data:  addr=None
2024-02-15 14:16:39,058 DEBUG logging:103 Processing: 0x0
2024-02-15 14:16:39,058 DEBUG logging:103 Frame - not ready
2024-02-15 14:16:39,059 DEBUG logging:103 recv: 0xc old_data:  addr=None
2024-02-15 14:16:39,059 DEBUG logging:103 Processing: 0xc
2024-02-15 14:16:39,060 DEBUG logging:103 Frame - not ready
2024-02-15 14:16:39,061 DEBUG logging:103 recv: 0xd7 old_data:  addr=None
2024-02-15 14:16:39,061 DEBUG logging:103 Processing: 0xd7
2024-02-15 14:16:39,061 DEBUG logging:103 Getting Frame - 0x3 0x8 0x0 0x5 0x0 0x5 0x0 0x0 0x0 0x0
2024-02-15 14:16:39,062 DEBUG logging:103 Factory Response[ReadHoldingRegistersResponse': 3]
2024-02-15 14:16:39,062 DEBUG logging:103 Frame advanced, resetting header!!
2024-02-15 14:16:39,062 DEBUG logging:103 Getting transaction 1
2024-02-15 14:16:39,062 DEBUG logging:103 Unrequested message: ReadHoldingRegistersResponse (4)

janiversen commented 4 months ago

What does "unit=0" mean ???? that is not a parameter we have, nor is it documented

You got a response from an unexpected device.

Please look at our examples or documentation to see the correct parameter usage.

hectovs commented 4 months ago

Apologies, I appreciate that is not the correct parameter usage, I have now changed it and I still get the same logs and error. I am specifying the slave as zero now, as follows:

response1 = await async_client.read_holding_registers(address=124, count=4, slave=0)

janiversen commented 4 months ago

slave=0 means broadcast, as pr documentation, is that really what you want ?

Anyhow that is most likely the reason why the response is rejected.

janiversen commented 4 months ago

There are however a part of the log that disturbs, I will try to simulate your call

janiversen commented 4 months ago

Interesting I cannot reproduce your problem even with slave=0.

The only difference I see is that you receive the package a byte at a time, that is something we have not tested, but I will a new test and see if that shows the problem.

hectovs commented 4 months ago

Thanks for your help, switching away from broadcast with slave=0 fixes this problem in this specific case for me. I am still receiving the response a byte at a time but it no longer throws an error. There is only one other device on the modbus network in my set up - is there a reason this broadcast mode throws up an issue only on the async client?

janiversen commented 4 months ago

I am looking into that, because it should motivate happen.

janiversen commented 4 months ago

Thanks! your description and logs helped us nail down a year old bug.

pymodbus-dev / pymodbus