Skip to content

Serial forwarder demo doesnt work with write single register #2660

New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom
Open
sthome-cz opened this issue May 3, 2025 · 10 comments
Open

Serial forwarder demo doesnt work with write single register #2660

sthome-cz opened this issue May 3, 2025 · 10 comments

Comments

@sthome-cz
Copy link

Steps to reproduce

Evidences

  • Communication on RTU side is as expected, enable (on) the switch
    • Request: 0xf7 0x6 0xb9 0xec 0x0 0x1 0xb8 0x35
    • Response: 0xf7 0x6 0xb9 0xec 0x0 0x1 0xb8 0x35
    • Critical section is tuple 0x0 0x1 starting on the 5th byte
  • Communication on TCP side is corrupted, as the packet is encoded like
    • Request: 0x82 0xcc 0x0 0x0 0x0 0x6 0xf7 0x6 0xb9 0xec 0x0 0x1
    • Response: 0x82 0xcc 0x0 0x0 0x0 0x6 0xf7 0x6 0xb9 0xec 0x0 0x0
    • Critical section is also 0x0 0x1 in request, two bytes from the end of the packet
    • And the corrupted section is 0x0 0x0 in the response, the last two bytes

The reason (in the code), why pymodbus works like this is in the code, where the condition makes to always return [0].

pymodbus/pymodbus/datastore/remote.py

Lines 34 to 41 in b4cecc3

def getValues(self, fc_as_hex, _address, _count=1):
"""Get values from remote device."""
if fc_as_hex in self._write_fc:
return [0]
group_fx = self.decode(fc_as_hex)
func_fc = self.__get_callbacks[group_fx]
self.result = func_fc(_address, _count)
return self.__extract_result(self.decode(fc_as_hex), self.result)

Datastore is called during the execution of the execute in WriteSingleRegisterRequest object.

pymodbus/pymodbus/pdu/register_message.py

Lines 181 to 194 in b4cecc3

class WriteSingleRegisterRequest(WriteSingleRegisterResponse):
"""WriteSingleRegisterRequest."""
async def update_datastore(self, context: ModbusDeviceContext) -> ModbusPDU:
"""Run a write single register request against a datastore."""
if not 0 <= self.registers[0] <= 0xFFFF:
return ExceptionResponse(self.function_code, ExceptionResponse.ILLEGAL_VALUE)
rc = await context.async_setValues(
self.function_code, self.address, self.registers
)
if rc:
return ExceptionResponse(self.function_code, rc)
values = await context.async_getValues(self.function_code, self.address, 1)
return WriteSingleRegisterResponse(address=self.address, registers=cast(list[int], values))

Due to the condition above, the returned value after the WriteSingleRegisterRequest is always 0 and this will fail the command in the management application.

What is the correct way to fix this issue ? I have removed the condition for the test and the command is now executed successfully. Unfortunately I dont think, this is correct, because the program now executes the command to write the register value, then read its state back. AFAIK this shouldnt be necessary and the current state of the register is contained in the response on the RTU side.

Am I missing something, or is it a bug ?
@janiversen
Copy link
Collaborator

please add a debug log (using the pymodbus call) so we can see what happens.

The serial forwarder should forward the requests and pass the responses, however this is a very limited forwarder a real forwarder works at frame level and passes frames back and forth. We have for a long time wanted to make a real forwarder but never had the time to do so.

@janiversen
Copy link
Collaborator

calling the datastore during execute is correct and will not always return zero but the current value.

@janiversen
Copy link
Collaborator

janiversen commented May 4, 2025 •
edited
Loading

pull requests are always welcome.

it do looks as if the "if" in get values are wrong.

@sthome-cz
Copy link
Author

Here is the log, which shows the data traffic, when the if is commented out.

I have put empty lines to the points, where I believe is happening something interesting.

DEBUG:pymodbus.logging:Connected to server
DEBUG:pymodbus.logging:recv: 0x5b 0xe7 0x0 0x0 0x0 0x6 0xf7 0x6 0xb9 0xec 0x0 0x0 old_data:  addr=None
DEBUG:pymodbus.logging:Handling data: 0x5b 0xe7 0x0 0x0 0x0 0x6 0xf7 0x6 0xb9 0xec 0x0 0x0
DEBUG:pymodbus.logging:Processing: 0x5b 0xe7 0x0 0x0 0x0 0x6 0xf7 0x6 0xb9 0xec 0x0 0x0
DEBUG:pymodbus.logging:Factory Request[WriteSingleRegisterRequest': 6]
DEBUG:__main__:Request tracer WriteRegisterRequest 47596
INFO:pymodbus.logging:Writing 0 to 47596
INFO:pymodbus.logging:Pre write - context Remote Slave Context(ModbusSerialClient /dev/ttyAMA0:0)
INFO:pymodbus.logging:set values 6 47596 [0]
DEBUG:pymodbus.logging:Current transaction state - TRANSACTION_COMPLETE
DEBUG:pymodbus.logging:Running transaction 107
DEBUG:pymodbus.logging:SEND: 0xf7 0x6 0xb9 0xec 0x0 0x0 0x79 0xf5
DEBUG:pymodbus.logging:Resetting frame - Current Frame in buffer -
DEBUG:pymodbus.logging:Changing state to IDLE - Last Frame End - 1746696051.870166 Current Time stamp - DEBUG:pymodbus.logging:New Transaction state "SENDING"
DEBUG:pymodbus.logging:Changing transaction state from "SENDING" to "WAITING FOR REPLY"
DEBUG:pymodbus.logging:Changing transaction state from "WAITING FOR REPLY" to "PROCESSING REPLY"
DEBUG:pymodbus.logging:RECV: 0xf7 0x6 0xb9 0xec 0x0 0x0 0x79 0xf5
DEBUG:pymodbus.logging:Processing: 0xf7 0x6 0xb9 0xec 0x0 0x0 0x79 0xf5
DEBUG:pymodbus.logging:Getting Frame - 0x6 0xb9 0xec 0x0 0x0
DEBUG:pymodbus.logging:Factory Response[WriteSingleRegisterResponse': 6]
DEBUG:pymodbus.logging:Frame advanced, resetting header!!
DEBUG:pymodbus.logging:Adding transaction 0
DEBUG:pymodbus.logging:Getting transaction 0
DEBUG:pymodbus.logging:Changing transaction state from "PROCESSING REPLY" to "TRANSACTION_COMPLETE"
INFO:pymodbus.logging:get values 6 47596

DEBUG:pymodbus.logging:Current transaction state - TRANSACTION_COMPLETE
DEBUG:pymodbus.logging:Running transaction 108
DEBUG:pymodbus.logging:SEND: 0xf7 0x3 0xb9 0xec 0x0 0x1 0x74 0x35
DEBUG:pymodbus.logging:Resetting frame - Current Frame in buffer -
DEBUG:pymodbus.logging:Changing state to IDLE - Last Frame End - 1746696071.649988 Current Time stamp - DEBUG:pymodbus.logging:New Transaction state "SENDING"
DEBUG:pymodbus.logging:Changing transaction state from "SENDING" to "WAITING FOR REPLY"
DEBUG:pymodbus.logging:Changing transaction state from "WAITING FOR REPLY" to "PROCESSING REPLY"
DEBUG:pymodbus.logging:RECV: 0xf7 0x3 0x2 0x0 0x0 0x70 0x51
DEBUG:pymodbus.logging:Processing: 0xf7 0x3 0x2 0x0 0x0 0x70 0x51
DEBUG:pymodbus.logging:Getting Frame - 0x3 0x2 0x0 0x0
DEBUG:pymodbus.logging:Factory Response[ReadHoldingRegistersResponse': 3]
DEBUG:pymodbus.logging:Frame advanced, resetting header!!
DEBUG:pymodbus.logging:Adding transaction 0
DEBUG:pymodbus.logging:Getting transaction 0
DEBUG:pymodbus.logging:Changing transaction state from "PROCESSING REPLY" to "TRANSACTION_COMPLETE"
INFO:pymodbus.logging:result: ReadHoldingRegistersResponse (1)

INFO:pymodbus.logging:Written values [0]
INFO:pymodbus.logging:Post write - context Remote Slave Context(ModbusSerialClient /dev/ttyAMA0:0)
DEBUG:pymodbus.logging:send: 0x5b 0xe7 0x0 0x0 0x0 0x6 0xf7 0x6 0xb9 0xec 0x0 0x0
DEBUG:pymodbus.logging:-> transport: received eof
DEBUG:pymodbus.logging:Connection lost server due to None
DEBUG:pymodbus.logging:Handler for stream [server] has been canceled

There is a log for the same request, but with the if branch active.

In this particular action, the requested state is 0, so even the returned value from the if condition is correct. This is not correct in case of setting 1, what I think is obvious.

DEBUG:pymodbus.logging:Connected to server
DEBUG:pymodbus.logging:recv: 0x5c 0x43 0x0 0x0 0x0 0x6 0xf7 0x6 0xb9 0xec 0x0 0x0 old_data:  addr=None
DEBUG:pymodbus.logging:Handling data: 0x5c 0x43 0x0 0x0 0x0 0x6 0xf7 0x6 0xb9 0xec 0x0 0x0
DEBUG:pymodbus.logging:Processing: 0x5c 0x43 0x0 0x0 0x0 0x6 0xf7 0x6 0xb9 0xec 0x0 0x0
DEBUG:pymodbus.logging:Factory Request[WriteSingleRegisterRequest': 6]
DEBUG:__main__:Request tracer WriteRegisterRequest 47596
INFO:pymodbus.logging:Writing 0 to 47596
INFO:pymodbus.logging:Pre write - context Remote Slave Context(ModbusSerialClient /dev/ttyAMA0:0)
INFO:pymodbus.logging:Pre write - context Remote Slave Context(ModbusSerialClient /dev/ttyAMA0:0)
INFO:pymodbus.logging:set values 6 47596 [0]
DEBUG:pymodbus.logging:Current transaction state - TRANSACTION_COMPLETE
DEBUG:pymodbus.logging:Running transaction 2
DEBUG:pymodbus.logging:SEND: 0xf7 0x6 0xb9 0xec 0x0 0x0 0x79 0xf5
DEBUG:pymodbus.logging:Resetting frame - Current Frame in buffer -
DEBUG:pymodbus.logging:Changing state to IDLE - Last Frame End - 1746697950.01195 Current Time stamp - 1746697954.959848
DEBUG:pymodbus.logging:New Transaction state "SENDING"
DEBUG:pymodbus.logging:Changing transaction state from "SENDING" to "WAITING FOR REPLY"
DEBUG:pymodbus.logging:Changing transaction state from "WAITING FOR REPLY" to "PROCESSING REPLY"
DEBUG:pymodbus.logging:RECV: 0xf7 0x6 0xb9 0xec 0x0 0x0 0x79 0xf5
DEBUG:pymodbus.logging:Processing: 0xf7 0x6 0xb9 0xec 0x0 0x0 0x79 0xf5
DEBUG:pymodbus.logging:Getting Frame - 0x6 0xb9 0xec 0x0 0x0
DEBUG:pymodbus.logging:Factory Response[WriteSingleRegisterResponse': 6]
DEBUG:pymodbus.logging:Frame advanced, resetting header!!
DEBUG:pymodbus.logging:Adding transaction 0
DEBUG:pymodbus.logging:Getting transaction 0
DEBUG:pymodbus.logging:Changing transaction state from "PROCESSING REPLY" to "TRANSACTION_COMPLETE"
INFO:pymodbus.logging:get values 6 47596
INFO:pymodbus.logging:result - 0 as condition
INFO:pymodbus.logging:Written values [0]
INFO:pymodbus.logging:Post write - context Remote Slave Context(ModbusSerialClient /dev/ttyAMA0:0)
DEBUG:pymodbus.logging:send: 0x5c 0x43 0x0 0x0 0x0 0x6 0xf7 0x6 0xb9 0xec 0x0 0x0
DEBUG:pymodbus.logging:-> transport: received eof
DEBUG:pymodbus.logging:Connection lost server due to None
DEBUG:pymodbus.logging:Handler for stream [server] has been canceled

@janiversen
Copy link
Collaborator

looks as if it works as it should without the "if".

@sthome-cz
Copy link
Author

sthome-cz commented May 8, 2025 •
edited
Loading

One last problem, which I just found out. Sometimes it takes more time for the inverter to apply the updated value. I added sleep of 1 second, as a temporary solution.

Log.info("Writing {} to {}", self.value, self.address)                     
Log.info("Pre write - context {}", context)                                
await context.async_setValues(                                             
    self.function_code, self.address, [self.value]                                             
)                                                                          
Log.info("Sleep for 1 second, to apply the data")                          
await asyncio.sleep(1)                                                     
values = await context.async_getValues(self.function_code, self.address, 1)
Log.info("Written values {}", values)                                            
Log.info("Post write - context {}", context)

This issue will be highly dependent on the target device.

@janiversen
Copy link
Collaborator

ok. Feel free to submit a pull request.

@janiversen
Copy link
Collaborator

The sleep is wrong, because if the device was connected directly the app would get the result of the write not a following read.

In the remote datastore the write (set values) returns with the result, this result should be returned and the get values should be bypassed.

@sthome-cz
Copy link
Author

this result should be returned and the get values should be bypassed.

Absolutely agree, its event mentioned in the original description. Unfortunately I dont know the project well enough to write such change. Is it easy enough, to share within this discussion ? I believe such change would be much better, than any other changes mentioned before.

@janiversen
Copy link
Collaborator

It is only changes in the file you already patched, writing the changes here instead of just merging and updated file, would be kind of doble work.

You do not need to know a lot about the project, you have all the information needed in one file.

sthome-cz pushed a commit to sthome-cz/pymodbus that referenced this issue May 9, 2025
@rac-mar-vys
Fix pymodbus TCP / RTU forwarder
89153e6 
Getting response of WriteSingleRegister is read correctly.

Problem described at <pymodbus-dev#2660>
@sthome-cz sthome-cz mentioned this issue May 9, 2025
Closed
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
None yet
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
2 participants
@janiversen @sthome-cz