pymodbus-dev / pymodbus

A full modbus protocol written in python
Other
2.21k stars 907 forks source link

examples not working #2231

Closed zockerforever closed 1 month ago

zockerforever commented 1 month ago

Versions

Pymodbus Specific

Description

i started the example async server and tried the example clients. sync and async. i expected that to work as the example code was cloned (git clone....) i was trying to watch what happens using the debug log level, output attached below. With the sinc client not much happens, with async clients alot of frame check failed/ frame not ready problems

Code and Logs

# code and logs here.
server logs:
python3 server_async.py -c serial -f rtu -p /dev/ttyUSB0 --baudrate 19200 -l debug 
2024-07-14 22:09:32,192 DEBUG logging:103 Awaiting connections server_listener
2024-07-14 22:09:32,193 INFO  logging:97 Server listening.
2024-07-14 22:09:32,193 DEBUG logging:103 Connected to server
2024-07-14 22:09:49,567 DEBUG logging:103 recv: 0x1 0x40 0x20 0x0 0x40 old_data:  addr=None
2024-07-14 22:09:49,568 DEBUG logging:103 Handling data: 0x1 0x40 0x20 0x0 0x40
2024-07-14 22:09:49,568 DEBUG logging:103 Processing: 0x1 0x40 0x20 0x0 0x40
2024-07-14 22:12:10,680 DEBUG logging:103 recv: 0x1 0x1 0x0 0x2 0x1 0xfc 0x0 old_data:  addr=None
2024-07-14 22:12:10,680 DEBUG logging:103 Handling data: 0x1 0x1 0x0 0x2 0x1 0xfc 0x0
2024-07-14 22:12:10,680 DEBUG logging:103 Processing: 0x20 0x0 0x40 0x1 0x1 0x0 0x2 0x1 0xfc 0x0
2024-07-14 22:12:10,680 DEBUG logging:103 Frame check failed, ignoring!!
2024-07-14 22:12:10,681 DEBUG logging:103 Resetting frame - Current Frame in buffer - 0x40 0x1 0x1 0x0 0x2 0x1 0xfc 0x0
2024-07-14 22:12:10,681 DEBUG logging:103 Frame - not ready
2024-07-14 22:12:20,688 DEBUG logging:103 recv: 0x1 0x1 0x20 0x0 0x1 0xfc 0x0 old_data:  addr=None
2024-07-14 22:12:20,689 DEBUG logging:103 Handling data: 0x1 0x1 0x20 0x0 0x1 0xfc 0x0
2024-07-14 22:12:20,689 DEBUG logging:103 Processing: 0x1 0x1 0x0 0x2 0x1 0xfc 0x0 0x1 0x1 0x20 0x0 0x1 0xfc 0x0
2024-07-14 22:12:20,689 DEBUG logging:103 Frame check failed, ignoring!!
2024-07-14 22:12:20,689 DEBUG logging:103 Resetting frame - Current Frame in buffer - 0x1 0x1 0x0 0x2 0x1 0xfc 0x0 0x1 0x1 0x20 0x0 0x1 0xfc 0x0
2024-07-14 22:12:20,689 DEBUG logging:103 Frame check failed, ignoring!!
2024-07-14 22:12:20,689 DEBUG logging:103 Resetting frame - Current Frame in buffer - 0x0 0x2 0x1 0xfc 0x0 0x1 0x1 0x20 0x0 0x1 0xfc 0x0
2024-07-14 22:12:20,689 DEBUG logging:103 Frame check failed, ignoring!!
2024-07-14 22:12:20,689 DEBUG logging:103 Resetting frame - Current Frame in buffer - 0x2 0x1 0xfc 0x0 0x1 0x1 0x20 0x0 0x1 0xfc 0x0
2024-07-14 22:12:20,689 DEBUG logging:103 Frame check failed, ignoring!!
2024-07-14 22:12:20,689 DEBUG logging:103 Resetting frame - Current Frame in buffer - 0x0 0x1 0x1 0x20 0x0 0x1 0xfc 0x0
2024-07-14 22:12:20,689 DEBUG logging:103 Frame - not ready
2024-07-14 22:12:30,698 DEBUG logging:103 recv: 0x1 0x1 0x0 0x2 0x1 0xfc 0x0 old_data:  addr=None
2024-07-14 22:12:30,699 DEBUG logging:103 Handling data: 0x1 0x1 0x0 0x2 0x1 0xfc 0x0
2024-07-14 22:12:30,699 DEBUG logging:103 Processing: 0x1 0x1 0x20 0x0 0x1 0xfc 0x0 0x1 0x1 0x0 0x2 0x1 0xfc 0x0
2024-07-14 22:12:30,699 DEBUG logging:103 Frame check failed, ignoring!!
2024-07-14 22:12:30,699 DEBUG logging:103 Resetting frame - Current Frame in buffer - 0x1 0x1 0x20 0x0 0x1 0xfc 0x0 0x1 0x1 0x0 0x2 0x1 0xfc 0x0
2024-07-14 22:12:30,700 DEBUG logging:103 Frame check failed, ignoring!!
2024-07-14 22:12:30,700 DEBUG logging:103 Resetting frame - Current Frame in buffer - 0x0 0x1 0xfc 0x0 0x1 0x1 0x0 0x2 0x1 0xfc 0x0
2024-07-14 22:12:30,700 DEBUG logging:103 Frame check failed, ignoring!!
2024-07-14 22:12:30,700 DEBUG logging:103 Resetting frame - Current Frame in buffer - 0x0 0x1 0x1 0x0 0x2 0x1 0xfc 0x0
2024-07-14 22:12:30,700 DEBUG logging:103 Frame - not ready
2024-07-14 22:12:40,708 DEBUG logging:103 recv: 0x40 0x40 0x2 0x1 0xfc old_data:  addr=None
2024-07-14 22:12:40,709 DEBUG logging:103 Handling data: 0x40 0x40 0x2 0x1 0xfc
2024-07-14 22:12:40,709 DEBUG logging:103 Processing: 0x1 0x1 0x0 0x2 0x1 0xfc 0x0 0x40 0x40 0x2 0x1 0xfc
2024-07-14 22:12:40,709 DEBUG logging:103 Frame check failed, ignoring!!
2024-07-14 22:12:40,709 DEBUG logging:103 Resetting frame - Current Frame in buffer - 0x1 0x1 0x0 0x2 0x1 0xfc 0x0 0x40 0x40 0x2 0x1 0xfc
2024-07-14 22:12:40,709 DEBUG logging:103 Frame check failed, ignoring!!
2024-07-14 22:12:40,709 DEBUG logging:103 Resetting frame - Current Frame in buffer - 0x0 0x2 0x1 0xfc 0x0 0x40 0x40 0x2 0x1 0xfc
2024-07-14 22:12:40,709 DEBUG logging:103 Frame check failed, ignoring!!
2024-07-14 22:12:40,710 DEBUG logging:103 Resetting frame - Current Frame in buffer - 0x2 0x1 0xfc 0x0 0x40 0x40 0x2 0x1 0xfc
2024-07-14 22:12:40,710 DEBUG logging:103 Frame - not ready

client sync:
python3 client_sync.py -c serial -f rtu -p /dev/ttyUSB1 --baudrate 19200 -l debug
2024-07-14 22:17:31,596 DEBUG logging:103 Current transaction state - IDLE
2024-07-14 22:17:31,596 DEBUG logging:103 Running transaction 1
2024-07-14 22:17:31,596 DEBUG logging:103 SEND: 0x1 0x1 0x0 0x20 0x0 0x1 0xfc 0x0
2024-07-14 22:17:31,596 DEBUG logging:103 Resetting frame - Current Frame in buffer - 
2024-07-14 22:17:31,596 DEBUG logging:103 New Transaction state "SENDING"
2024-07-14 22:17:31,596 DEBUG logging:103 Changing transaction state from "SENDING" to "WAITING FOR REPLY"
2024-07-14 22:17:51,609 DEBUG logging:103 Transaction failed. (Modbus Error: [Invalid Message] No response received, expected at least 4 bytes (0 received)) 
2024-07-14 22:17:51,610 DEBUG logging:103 Processing: 
2024-07-14 22:17:51,610 DEBUG logging:103 Getting transaction 0
2024-07-14 22:17:51,610 DEBUG logging:103 Changing transaction state from "PROCESSING REPLY" to "TRANSACTION_COMPLETE"
Traceback (most recent call last):
  File "/home/henri/code/modbusquick/pymodbus/examples/client_sync.py", line 155, in <module>
    main()
  File "/home/henri/code/modbusquick/pymodbus/examples/client_sync.py", line 151, in main
    run_sync_client(testclient, modbus_calls=run_a_few_calls)
  File "/home/henri/code/modbusquick/pymodbus/examples/client_sync.py", line 130, in run_sync_client
    modbus_calls(client)
  File "/home/henri/code/modbusquick/pymodbus/examples/client_sync.py", line 139, in run_a_few_calls
    assert len(rr.bits) == 8
               ^^^^^^^
AttributeError: 'ModbusIOException' object has no attribute 'bits'

client async:
python3 client_async.py -c serial -f rtu -p /dev/ttyUSB1 --baudrate 19200 -l debug
2024-07-14 22:18:55,045 DEBUG logging:103 Connecting to /dev/ttyUSB1.
2024-07-14 22:18:55,045 DEBUG logging:103 Connecting comm
2024-07-14 22:18:55,048 DEBUG logging:103 Connected to comm
2024-07-14 22:18:55,049 DEBUG logging:103 Resetting frame - Current Frame in buffer - 
2024-07-14 22:18:55,049 DEBUG logging:103 Adding transaction 0
2024-07-14 22:18:55,049 DEBUG logging:103 Resetting frame - Current Frame in buffer - 
2024-07-14 22:18:55,049 DEBUG logging:103 send: 0x1 0x1 0x0 0x20 0x0 0x1 0xfc 0x0
2024-07-14 22:19:05,062 DEBUG logging:103 Adding transaction 0
2024-07-14 22:19:05,062 DEBUG logging:103 Resetting frame - Current Frame in buffer - 
2024-07-14 22:19:05,062 DEBUG logging:103 send: 0x1 0x1 0x0 0x20 0x0 0x1 0xfc 0x0
2024-07-14 22:19:15,074 DEBUG logging:103 Adding transaction 0
2024-07-14 22:19:15,074 DEBUG logging:103 Resetting frame - Current Frame in buffer - 
2024-07-14 22:19:15,074 DEBUG logging:103 send: 0x1 0x1 0x0 0x20 0x0 0x1 0xfc 0x0
2024-07-14 22:19:25,086 DEBUG logging:103 Adding transaction 0
2024-07-14 22:19:25,086 DEBUG logging:103 Resetting frame - Current Frame in buffer - 
2024-07-14 22:19:25,086 DEBUG logging:103 send: 0x1 0x1 0x0 0x20 0x0 0x1 0xfc 0x0
2024-07-14 22:19:25,105 DEBUG logging:103 recv: 0x1 0x1 0x1 0x1 0x90 0x48 old_data:  addr=None
2024-07-14 22:19:25,106 DEBUG logging:103 Processing: 0x1 0x1 0x1 0x1 0x90 0x48
2024-07-14 22:19:25,106 DEBUG logging:103 Getting Frame - 0x1 0x1 0x1
2024-07-14 22:19:25,106 DEBUG logging:103 Factory Response[ReadCoilsResponse': 1]
2024-07-14 22:19:25,106 DEBUG logging:103 Frame advanced, resetting header!!
2024-07-14 22:19:25,106 DEBUG logging:103 Getting transaction 0
2024-07-14 22:19:25,106 DEBUG logging:103 Adding transaction 0
2024-07-14 22:19:25,106 DEBUG logging:103 Resetting frame - Current Frame in buffer - 
2024-07-14 22:19:25,107 DEBUG logging:103 send: 0x1 0x3 0x0 0x4 0x0 0x2 0x85 0xca
2024-07-14 22:19:35,110 DEBUG logging:103 Adding transaction 0
2024-07-14 22:19:35,110 DEBUG logging:103 Resetting frame - Current Frame in buffer - 
2024-07-14 22:19:35,110 DEBUG logging:103 send: 0x1 0x3 0x0 0x4 0x0 0x2 0x85 0xca
2024-07-14 22:19:45,124 DEBUG logging:103 Adding transaction 0
2024-07-14 22:19:45,124 DEBUG logging:103 Resetting frame - Current Frame in buffer - 
2024-07-14 22:19:45,124 DEBUG logging:103 send: 0x1 0x3 0x0 0x4 0x0 0x2 0x85 0xca
2024-07-14 22:19:55,134 DEBUG logging:103 Adding transaction 0
2024-07-14 22:19:55,134 DEBUG logging:103 Resetting frame - Current Frame in buffer - 
2024-07-14 22:19:55,134 DEBUG logging:103 send: 0x1 0x3 0x0 0x4 0x0 0x2 0x85 0xca
2024-07-14 22:20:05,147 DEBUG logging:103 Connection lost comm due to Server not responding
2024-07-14 22:20:05,149 DEBUG logging:103 callback_disconnected called: Server not responding

# please use the following to format logs when posting them here
import pymodbus

pymodbus.pymodbus_apply_logging_config("DEBUG")
janiversen commented 1 month ago

The examples are working, seems a lot like you have a cabling problem, did you e.g. remember the minimum length and pull up resistors.

janiversen commented 1 month ago

Please have a look at what the client sends and what the server receives....that should be identical and is not controlled by pymodbus