Skip to content
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.

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

When trying to read several registers I get error: "fsm failed state after sending" #493

Open
Kaiteki666 opened this issue Sep 12, 2024 · 0 comments
Assignees
Labels
community could be done by the community problem unexpected behaviour

Comments

@Kaiteki666
Copy link

Kaiteki666 commented Sep 12, 2024

Which node-red-contrib-modbus version are you using?

5.30.0

What happened?

Until a certain moment, node-red worked normally, without errors or complaints, reading a maximum of 27 registers at once, after some time of continuous operation, without touching node-red at all, the following problem arose:

When trying to read several registers at once, I get the error "fsm failed state after sending" and after that "Error: Timed out". Also less often, but it happens that an error occurs when trying to read 1 register at a time, the reasons are unknown.
I try to read the registers with Modbus Read and Modbus Sequencer nodes, their behavior is identical, it all depends on the number of registers.
When I read one register everything can be fine and after a few tries I can also get an error.
After restarting node-red, when I try to read 10 registers at a time, the error does not occur for a while, but at some point it appears again and does not go away until I restart node-red. I can't read more than 10 registers at a time, I immediately get an error.
I tried changing the node-red version from older to newer, but that didn't help.
Node-red is running on an Orange pi 3LTS board, restarting the board did nothing.

Here's the output I got when running node-red in debug mode with DEBUG=contribModbus*,modbus-serial node-red -v :

1. Here is the output just after starting node-red:
Welcome to Node-RED

12 Sep 16:22:40 - [info] Node-RED version: v3.1.3
12 Sep 16:22:40 - [info] Node.js version: v18.19.0
12 Sep 16:22:40 - [info] Linux 6.1.63-current-sunxi64 arm64 LE
12 Sep 16:22:42 - [info] Loading palette nodes
12 Sep 16:22:47 - [info] Dashboard version 3.6.2 started at /ui
12 Sep 16:22:48 - [info] Settings file : /root/.node-red/settings.js
12 Sep 16:22:48 - [info] Context store : 'memoryOnly' [module=memory]
12 Sep 16:22:48 - [info] Context store : 'file' [module=localfilesystem]
12 Sep 16:22:49 - [info] User directory : /root/.node-red
12 Sep 16:22:49 - [warn] Projects disabled : editorTheme.projects.enabled=false
12 Sep 16:22:49 - [info] Flows file : /root/.node-red/flows.json
12 Sep 16:22:49 - [info] Server now running at http://127.0.0.1:1880/
12 Sep 16:22:49 - [warn] Using unencrypted credentials
12 Sep 16:22:49 - [info] Starting flows
contribModbus:queue:core queue serial lock command node name: Serial Switch USB0 to S0 id: f515fc0db2b361bf +0ms
contribModbus:core:client Client -> new +0ms
contribModbus:core:client Client -> initialized +1ms
12 Sep 16:22:49 - [warn] [modbus-read:545ad5d163805081] Read -> open node 545ad5d163805081 address: 0
contribModbus:core:client Client -> new +10ms
contribModbus:core:client Client -> init +2ms
12 Sep 16:22:49 - [warn] [modbus-client:Serial Switch USB0 to S0] Client -> fsm init state after new Serial@/dev/ttyUSB0:115200bit/s default Unit-Id: 1
12 Sep 16:22:49 - [warn] [modbus-client:Serial Switch USB0 to S0] Client -> first fsm init in 500 ms Serial@/dev/ttyUSB0:115200bit/s default Unit-Id: 1
contribModbus:core:client Client -> init Serial@/dev/ttyUSB0:115200bit/s default Unit-Id: 1 +14ms
contribModbus:core:client Client -> init Serial@/dev/ttyUSB0:115200bit/s default Unit-Id: 1 +1ms
12 Sep 16:22:49 - [warn] [modbus-flex-sequencer:b69c1bbc1dbeb2b4] Flex-Sequencer -> initialize input delay timer node b69c1bbc1dbeb2b4
contribModbus:core:client Client -> init Serial@/dev/ttyUSB0:115200bit/s default Unit-Id: 1 +4ms
contribModbus:core:client Client -> init Serial@/dev/ttyUSB0:115200bit/s default Unit-Id: 1 +1ms
12 Sep 16:22:49 - [warn] [modbus-flex-sequencer:5627e60862f79b54] Flex-Sequencer -> initialize input delay timer node 5627e60862f79b54
12 Sep 16:22:49 - [warn] [modbus-read:80d0ec0fab64436e] Read -> open node 80d0ec0fab64436e address: 0
contribModbus:core:client Client -> init Serial@/dev/ttyUSB0:115200bit/s default Unit-Id: 1 +6ms
contribModbus:core:client Client -> init Serial@/dev/ttyUSB0:115200bit/s default Unit-Id: 1 +1ms
12 Sep 16:22:49 - [warn] [modbus-read:1d6b652aeb2ba950] Read -> open node 1d6b652aeb2ba950 address: 0
contribModbus:core:client Client -> init Serial@/dev/ttyUSB0:115200bit/s default Unit-Id: 1 +5ms
contribModbus:core:client Client -> init Serial@/dev/ttyUSB0:115200bit/s default Unit-Id: 1 +1ms
contribModbus:core:client Client -> init Serial@/dev/ttyUSB0:115200bit/s default Unit-Id: 1 +4ms
contribModbus:core:client Client -> init Serial@/dev/ttyUSB0:115200bit/s default Unit-Id: 1 +1ms
12 Sep 16:22:49 - [warn] [modbus-flex-sequencer:26d5497fbef3890c] Flex-Sequencer -> initialize input delay timer node 26d5497fbef3890c
12 Sep 16:22:49 - [info] Started flows
contribModbus:core:client Client -> RTU buffered port serial Serial@/dev/ttyUSB0:115200bit/s default Unit-Id: 1 +470ms
contribModbus:core:client Client -> opened Serial@/dev/ttyUSB0:115200bit/s default Unit-Id: 1 +19ms
contribModbus:queue:core queue serial unlock command node name: Serial Switch USB0 to S0 id: f515fc0db2b361bf +544ms
contribModbus:core:client Client -> time to open Unit 1 Serial@/dev/ttyUSB0:115200bit/s default Unit-Id: 1 +103ms
modbus-serial modbus connection opened +0ms
contribModbus:core:client Client -> connected Serial@/dev/ttyUSB0:115200bit/s default Unit-Id: 1 +2ms
12 Sep 16:22:50 - [warn] [modbus-client:Serial Switch USB0 to S0] Client -> fsm connected after state opened Get More About It By Logging Serial@/dev/ttyUSB0:115200bit/s default Unit-Id: 1
contribModbus:queue:core queue serial unlock command node name: Serial Switch USB0 to S0 id: f515fc0db2b361bf +106ms
12 Sep 16:22:50 - [warn] [modbus-read:545ad5d163805081] Read -> startIntervalReading node 545ad5d163805081 address: 0
12 Sep 16:22:50 - [warn] [modbus-read:80d0ec0fab64436e] Read -> startIntervalReading node 80d0ec0fab64436e address: 0
12 Sep 16:22:50 - [warn] [modbus-read:1d6b652aeb2ba950] Read -> startIntervalReading node 1d6b652aeb2ba950 address: 0

2. In this part, I use the Modbus Read node to read one register, the reading was successful, no errors were received

contribModbus:core:client Client -> {"info":"will push to Queue by Unit-Id","message":{"unitid":"1","fc":3,"address":"0","quantity":"1","messageId":"66e2eb7d0bb57df8b0f276e5"},"unitId":1} Serial@/dev/ttyUSB0:115200bit/s default Unit-Id: 1 +1m
contribModbus:core:client Client -> {"info":"pushed to Queue by Unit-Id","message":{"unitid":"1","fc":3,"address":"0","quantity":"1","messageId":"66e2eb7d0bb57df8b0f276e5"},"unitId":1} Serial@/dev/ttyUSB0:115200bit/s default Unit-Id: 1 +3ms
contribModbus:core:client Client -> {"info":"queued read msg","message":{"unitid":"1","fc":3,"address":"0","quantity":"1","messageId":"66e2eb7d0bb57df8b0f276e5"},"state":"connected","queueLength":1} Serial@/dev/ttyUSB0:115200bit/s default Unit-Id: 1 +39ms
contribModbus:core:client Client -> queueing Serial@/dev/ttyUSB0:115200bit/s default Unit-Id: 1 +2ms
contribModbus:queue:core queue serial lock command node name: Serial Switch USB0 to S0 id: f515fc0db2b361bf +1m
contribModbus:core:client Client -> sending Serial@/dev/ttyUSB0:115200bit/s default Unit-Id: 1 +2ms
contribModbus:queue:core sequential de-queue command +203ms
contribModbus:core:client Client -> {"type":"sequential dequeue command","unitId":1,"isValidUnitId":true,"sendingAllowed":true,"serialSendingAllowed":false} Serial@/dev/ttyUSB0:115200bit/s default Unit-Id: 1 +203ms
contribModbus:core:client Client -> {"type":"send queue data to Modbus","unitId":1,"queueLength":1,"sendingAllowed":true,"serialSendingAllowed":false} Serial@/dev/ttyUSB0:115200bit/s default Unit-Id: 1 +1ms
contribModbus:core:client Client -> {"state":"sending","message":"dequeue command done serial","delay":200} Serial@/dev/ttyUSB0:115200bit/s default Unit-Id: 1 +2ms
contribModbus:core:client Client -> {"info":"read msg via Modbus","message":{"unitid":"1","fc":3,"address":"0","quantity":"1","messageId":"66e2eb7d0bb57df8b0f276e5"},"queueUnitId":1,"timeout":1000,"state":"sending"} Serial@/dev/ttyUSB0:115200bit/s default Unit-Id: 1 +2ms
modbus-serial {
modbus-serial action: 'send serial rtu buffered',
modbus-serial data: <Buffer 01 03 00 00 00 01 84 0a>,
modbus-serial unitid: 1,
modbus-serial functionCode: 3,
modbus-serial length: 7
modbus-serial } +0ms
modbus-serial {
modbus-serial action: 'receive serial rtu buffered port',
modbus-serial data: <Buffer 01 03 02 00 37 f9 92>,
modbus-serial buffer: <Buffer 01 03 02 00 37 f9 92>
modbus-serial } +15ms
modbus-serial {
modbus-serial action: 'emit data serial rtu buffered port',
modbus-serial buffer: <Buffer 01 03 02 00 37 f9 92>
modbus-serial } +2ms
contribModbus:queue:core queue serial unlock command node name: Serial Switch USB0 to S0 id: f515fc0db2b361bf +34ms
contribModbus:core:client Client -> {"info":"queue response activate sending","sendingAllowed":true,"serialSendingAllowed":true,"queueUnitId":1} Serial@/dev/ttyUSB0:115200bit/s default Unit-Id: 1 +29ms
contribModbus:core:client Client -> sending Serial@/dev/ttyUSB0:115200bit/s default Unit-Id: 1 +1ms
contribModbus:core:client Client -> activated Serial@/dev/ttyUSB0:115200bit/s default Unit-Id: 1 +5ms

3. In this part, I use the Modbus Read node to read 27 registers, the reading was not successful, I did not receive a response, only an error

contribModbus:core:client Client -> {"info":"will push to Queue by Unit-Id","message":{"unitid":"1","fc":3,"address":"0","quantity":"27","messageId":"66e2ebf00bb57df8b0f276e6"},"unitId":1} Serial@/dev/ttyUSB0:115200bit/s default Unit-Id: 1 +2m
contribModbus:core:client Client -> {"info":"pushed to Queue by Unit-Id","message":{"unitid":"1","fc":3,"address":"0","quantity":"27","messageId":"66e2ebf00bb57df8b0f276e6"},"unitId":1} Serial@/dev/ttyUSB0:115200bit/s default Unit-Id: 1 +2ms
contribModbus:core:client Client -> {"info":"queued read msg","message":{"unitid":"1","fc":3,"address":"0","quantity":"27","messageId":"66e2ebf00bb57df8b0f276e6"},"state":"activated","queueLength":1} Serial@/dev/ttyUSB0:115200bit/s default Unit-Id: 1 +7ms
contribModbus:core:client Client -> queueing Serial@/dev/ttyUSB0:115200bit/s default Unit-Id: 1 +1ms
contribModbus:queue:core queue serial lock command node name: Serial Switch USB0 to S0 id: f515fc0db2b361bf +2m
contribModbus:core:client Client -> sending Serial@/dev/ttyUSB0:115200bit/s default Unit-Id: 1 +2ms
contribModbus:queue:core sequential de-queue command +202ms
contribModbus:core:client Client -> {"type":"sequential dequeue command","unitId":1,"isValidUnitId":true,"sendingAllowed":true,"serialSendingAllowed":false} Serial@/dev/ttyUSB0:115200bit/s default Unit-Id: 1 +202ms
contribModbus:core:client Client -> {"type":"send queue data to Modbus","unitId":1,"queueLength":1,"sendingAllowed":true,"serialSendingAllowed":false} Serial@/dev/ttyUSB0:115200bit/s default Unit-Id: 1 +1ms
contribModbus:core:client Client -> {"state":"sending","message":"dequeue command done serial","delay":200} Serial@/dev/ttyUSB0:115200bit/s default Unit-Id: 1 +1ms
contribModbus:core:client Client -> {"info":"read msg via Modbus","message":{"unitid":"1","fc":3,"address":"0","quantity":"27","messageId":"66e2ebf00bb57df8b0f276e6"},"queueUnitId":1,"timeout":1000,"state":"sending"} Serial@/dev/ttyUSB0:115200bit/s default Unit-Id: 1 +1ms
modbus-serial {
modbus-serial action: 'send serial rtu buffered',
modbus-serial data: <Buffer 01 03 00 00 00 1b 05 c1>,
modbus-serial unitid: 1,
modbus-serial functionCode: 3,
modbus-serial length: 59
modbus-serial } +2m
modbus-serial {
modbus-serial action: 'receive serial rtu buffered port',
modbus-serial data: <Buffer 01 03 36 00 37 00 08 00 02 00 1e 00 03 00 00 01 00 00 00 00 06 00 17 00 00 02 00 05 00 03 00 01>,
modbus-serial buffer: <Buffer 01 03 36 00 37 00 08 00 02 00 1e 00 03 00 00 01 00 00 00 00 06 00 17 00 00 02 00 05 00 03 00 01>
modbus-serial } +8ms
modbus-serial {
modbus-serial action: 'receive serial rtu buffered port',
modbus-serial data: <Buffer 00 00 00 00 00 12 00 00 00 06 00 06 00 06 00 01 00 01 00 0d 00 0a 31 88>,
modbus-serial buffer: <Buffer 01 03 36 00 37 00 08 00 02 00 1e 00 03 00 00 01 00 00 00 00 06 00 17 00 00 02 00 05 00 03 00 01 00 00 00 00 00 12 00 00 00 06 00 06 00 06 00 01 00 01 ... 6 more bytes>
modbus-serial } +5ms
contribModbus:queue:core queue serial unlock command node name: Serial Switch USB0 to S0 id: f515fc0db2b361bf +1s
contribModbus:core:client Client -> {"info":"queue response activate sending","sendingAllowed":true,"serialSendingAllowed":true,"queueUnitId":1} Serial@/dev/ttyUSB0:115200bit/s default Unit-Id: 1 +1s
contribModbus:core:client Client -> sending Serial@/dev/ttyUSB0:115200bit/s default Unit-Id: 1 +0ms
contribModbus:queue:core queue serial unlock command node name: Serial Switch USB0 to S0 id: f515fc0db2b361bf +2ms
modbus-serial modbusErrorHandling:Timed out +3m
contribModbus:core:client Client -> failed Serial@/dev/ttyUSB0:115200bit/s default Unit-Id: 1 +3ms
12 Sep 16:26:10 - [warn] [modbus-client:Serial Switch USB0 to S0] Client -> fsm failed state after sending Get More About It By Logging Serial@/dev/ttyUSB0:115200bit/s default Unit-Id: 1
12 Sep 16:26:10 - [warn] [modbus-read:545ad5d163805081] Read -> resetIntervalToRead node 545ad5d163805081 address: 0
12 Sep 16:26:10 - [warn] [modbus-read:545ad5d163805081] Modbus Failure On State sending Get More About It By Logging
12 Sep 16:26:10 - [warn] [modbus-read:80d0ec0fab64436e] Read -> resetIntervalToRead node 80d0ec0fab64436e address: 0
12 Sep 16:26:10 - [warn] [modbus-read:80d0ec0fab64436e] Modbus Failure On State sending Get More About It By Logging
12 Sep 16:26:10 - [warn] [modbus-read:1d6b652aeb2ba950] Read -> resetIntervalToRead node 1d6b652aeb2ba950 address: 0
12 Sep 16:26:10 - [warn] [modbus-read:1d6b652aeb2ba950] Modbus Failure On State sending Get More About It By Logging
contribModbus:core:client Client -> broken Serial@/dev/ttyUSB0:115200bit/s default Unit-Id: 1 +12ms
12 Sep 16:26:10 - [warn] [modbus-client:Serial Switch USB0 to S0] Client -> fsm broken state after failed Get More About It By Logging Serial@/dev/ttyUSB0:115200bit/s default Unit-Id: 1
contribModbus:core:client Client -> reconnecting Serial@/dev/ttyUSB0:115200bit/s default Unit-Id: 1 +4ms
12 Sep 16:26:10 - [warn] [modbus-client:Serial Switch USB0 to S0] Client -> fsm reconnect state after broken Get More About It By Logging Serial@/dev/ttyUSB0:115200bit/s default Unit-Id: 1
contribModbus:queue:core queue serial lock command node name: Serial Switch USB0 to S0 id: f515fc0db2b361bf +19ms
contribModbus:read Timed out +0ms
12 Sep 16:26:10 - [error] [modbus-read:545ad5d163805081] Error: Timed out
at /root/.node-red/node_modules/node-red-contrib-modbus/modbus/maps/core/core/modbus-client-core.js:79:156
contribModbus:core:client Client -> reconnecting Serial@/dev/ttyUSB0:115200bit/s default Unit-Id: 1 +135ms
contribModbus:core:client Client -> init Serial@/dev/ttyUSB0:115200bit/s default Unit-Id: 1 +2s
12 Sep 16:26:12 - [warn] [modbus-client:Serial Switch USB0 to S0] Client -> fsm init state after reconnecting Serial@/dev/ttyUSB0:115200bit/s default Unit-Id: 1
12 Sep 16:26:12 - [warn] [modbus-client:Serial Switch USB0 to S0] Client -> fsm init in 2000 ms Serial@/dev/ttyUSB0:115200bit/s default Unit-Id: 1
contribModbus:core:client Client -> connection close sent Serial@/dev/ttyUSB0:115200bit/s default Unit-Id: 1 +2s
contribModbus:core:client Client -> RTU buffered port serial Serial@/dev/ttyUSB0:115200bit/s default Unit-Id: 1 +1ms
contribModbus:core:client Client -> connection closed Serial@/dev/ttyUSB0:115200bit/s default Unit-Id: 1 +5ms
contribModbus:core:client Client -> opened Serial@/dev/ttyUSB0:115200bit/s default Unit-Id: 1 +3ms
contribModbus:queue:core queue serial unlock command node name: Serial Switch USB0 to S0 id: f515fc0db2b361bf +4s
contribModbus:core:client Client -> time to open Unit 1 Serial@/dev/ttyUSB0:115200bit/s default Unit-Id: 1 +101ms
modbus-serial modbus connection opened +4s
contribModbus:core:client Client -> connected Serial@/dev/ttyUSB0:115200bit/s default Unit-Id: 1 +1ms
12 Sep 16:26:14 - [warn] [modbus-client:Serial Switch USB0 to S0] Client -> fsm connected after state opened Get More About It By Logging Serial@/dev/ttyUSB0:115200bit/s default Unit-Id: 1
contribModbus:queue:core queue serial unlock command node name: Serial Switch USB0 to S0 id: f515fc0db2b361bf +105ms
12 Sep 16:26:14 - [warn] [modbus-read:545ad5d163805081] Read -> startIntervalReading node 545ad5d163805081 address: 0
12 Sep 16:26:14 - [warn] [modbus-read:80d0ec0fab64436e] Read -> startIntervalReading node 80d0ec0fab64436e address: 0
12 Sep 16:26:14 - [warn] [modbus-read:1d6b652aeb2ba950] Read -> startIntervalReading node 1d6b652aeb2ba950 address: 0

Server

Other/External server

How can this be reproduced?

I don't think my problem can be reproduced, but here is my flow:

[
{
"id": "545ad5d163805081",
"type": "modbus-read",
"z": "3a8762fd13672cde",
"name": "",
"topic": "",
"showStatusActivities": true,
"logIOActivities": false,
"showErrors": true,
"showWarnings": true,
"unitid": "1",
"dataType": "HoldingRegister",
"adr": "0",
"quantity": "27",
"rate": "1",
"rateUnit": "h",
"delayOnStart": false,
"startDelayTime": "",
"server": "f515fc0db2b361bf",
"useIOFile": false,
"ioFile": "",
"useIOForPayload": false,
"emptyMsgOnFail": false,
"x": 220,
"y": 340,
"wires": [
[
"505df65f5b578d9f"
],
[]
]
},
{
"id": "f515fc0db2b361bf",
"type": "modbus-client",
"name": "Serial Switch USB0 to S0",
"clienttype": "serial",
"bufferCommands": true,
"stateLogEnabled": true,
"queueLogEnabled": true,
"failureLogEnabled": true,
"tcpHost": "127.0.0.1",
"tcpPort": "502",
"tcpType": "DEFAULT",
"serialPort": "/dev/ttyUSB0",
"serialType": "RTU-BUFFERD",
"serialBaudrate": "115200",
"serialDatabits": "8",
"serialStopbits": "1",
"serialParity": "none",
"serialConnectionDelay": "100",
"serialAsciiResponseStartDelimiter": "0x3A",
"unit_id": "1",
"commandDelay": "200",
"clientTimeout": "1000",
"reconnectOnTimeout": true,
"reconnectTimeout": "2000",
"parallelUnitIdsAllowed": false,
"showErrors": false,
"showWarnings": true,
"showLogs": true
}
]

What did you expect to happen?

I was expecting a successful read of multiple registers, with no errors

Other Information

No response

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
community could be done by the community problem unexpected behaviour
Projects
None yet
Development

No branches or pull requests

3 participants