BiancoRoyal / node-red-contrib-modbus

maintained by PLUS for Node-RED - https://plus4nodered.com
https://www.npmjs.com/package/node-red-contrib-modbus
BSD 3-Clause "New" or "Revised" License
278 stars 107 forks source link

Flex Getter does not reconnect to serial port after redeploy #436

Closed serpent213 closed 1 month ago

serpent213 commented 5 months ago

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

5.28.0

What happened?

Log during redeploy:

2024-01-29T08:12:11.405Z contribModbus:queue:core queue serial lock command node name: Modbus RS485 id: e39ff271e27b2afe
2024-01-29T08:12:11.415Z contribModbus:queue:core sequential de-queue command
2024-01-29T08:12:11.417Z modbus-serial {
  action: 'send serial rtu buffered',
  data: <Buffer 02 03 00 04 00 01 c5 f8>,
  unitid: 2,
  functionCode: 3,
  length: 7
}
2024-01-29T08:12:11.452Z modbus-serial {
  action: 'receive serial rtu buffered port',
  data: <Buffer 02 03 02 00 89 3d e2>,
  buffer: <Buffer 02 03 02 00 89 3d e2>
}
2024-01-29T08:12:11.452Z modbus-serial {
  action: 'emit data serial rtu buffered port',
  buffer: <Buffer 02 03 02 00 89 3d e2>
}
2024-01-29T08:12:11.453Z contribModbus:queue:core queue serial unlock command node name: Modbus RS485 id: e39ff271e27b2afe
2024-01-29T08:12:11.514Z contribModbus:queue:core queue serial lock command node name: Modbus RS485 id: e39ff271e27b2afe
2024-01-29T08:12:11.620Z contribModbus:queue:core sequential de-queue command
2024-01-29T08:12:11.623Z modbus-serial {
  action: 'send serial rtu buffered',
  data: <Buffer 01 0f 00 00 00 08 01 01 3f 55>,
  unitid: 1,
  functionCode: 15,
  length: 8
}
29 Jan 09:12:11 - [debug] saved flow revision: 2b39acde3730fc9777f701abe39d70f4
29 Jan 09:12:11 - [info] Stopping modified flows
29 Jan 09:12:11 - [debug] red/nodes/flows.stop : stopping flow : b7fd3cfd8418de99
29 Jan 09:12:11 - [debug] red/nodes/flows.stop : stopping flow : dc8b2f6a2286fcc4
29 Jan 09:12:11 - [debug] red/nodes/flows.stop : stopping flow : 1fa0281e7267a0a1
29 Jan 09:12:11 - [debug] red/nodes/flows.stop : stopping flow : global
29 Jan 09:12:11 - [info] Stopped modified flows
29 Jan 09:12:11 - [info] Updated flows
2024-01-29T08:12:11.655Z modbus-serial {
  action: 'receive serial rtu buffered port',
  data: <Buffer 01 0f 00 00 00 08>,
  buffer: <Buffer 01 0f 00 00 00 08>
}
29 Jan 09:12:11 - [info] Starting modified flows
29 Jan 09:12:11 - [debug] [inject:Zyklus] repeat = 2500
29 Jan 09:12:11 - [info] Started modified flows
2024-01-29T08:12:11.669Z modbus-serial {
  action: 'receive serial rtu buffered port',
  data: <Buffer 54 0d>,
  buffer: <Buffer 01 0f 00 00 00 08 54 0d>
}
2024-01-29T08:12:11.669Z modbus-serial {
  action: 'emit data serial rtu buffered port',
  buffer: <Buffer 01 0f 00 00 00 08 54 0d>
}
2024-01-29T08:12:11.669Z contribModbus:queue:core queue serial unlock command node name: Modbus RS485 id: e39ff271e27b2afe
2024-01-29T08:12:13.667Z modbus-serial {
  action: 'port open error',
  error: [Error: Error Resource temporarily unavailable Cannot lock port]
}
2024-01-29T08:12:13.667Z contribModbus:queue:core queue serial unlock command node name: Modbus RS485 id: e39ff271e27b2afe
2024-01-29T08:12:13.667Z modbus-serial modbusSerialErrorHandling:Error Resource temporarily unavailable Cannot lock port
2024-01-29T08:12:13.668Z contribModbus:queue:core queue serial lock command node name: Modbus RS485 id: e39ff271e27b2afe
29 Jan 09:12:16 - [debug] [exec:trigger watchdog] cgctl wdog -t
2024-01-29T08:12:17.673Z modbus-serial {
  action: 'port open error',
  error: [Error: Error Resource temporarily unavailable Cannot lock port]
}
2024-01-29T08:12:17.673Z contribModbus:queue:core queue serial unlock command node name: Modbus RS485 id: e39ff271e27b2afe
2024-01-29T08:12:17.673Z modbus-serial modbusSerialErrorHandling:Error Resource temporarily unavailable Cannot lock port

Maybe some kind of race condition when closing the port...?

Server

None/This is related to a node that doesn't connect to a server

How can this be reproduced?

Difficult, I guess. Here's the

flow ```json [ { "id": "dc8b2f6a2286fcc4", "type": "tab", "label": "Modbus HAL", "disabled": false, "info": "", "env": [] }, { "id": "29831c0a24a3478e", "type": "modbus-flex-getter", "z": "dc8b2f6a2286fcc4", "name": "", "showStatusActivities": true, "showErrors": true, "showWarnings": true, "logIOActivities": false, "server": "e39ff271e27b2afe", "useIOFile": false, "ioFile": "", "useIOForPayload": false, "emptyMsgOnFail": false, "keepMsgProperties": true, "delayOnStart": false, "startDelayTime": "", "x": 520, "y": 400, "wires": [ [ "e81ac0403ed1ce83" ], [] ] }, { "id": "c68fee669608f8e9", "type": "inject", "z": "dc8b2f6a2286fcc4", "name": "Zyklus", "props": [ { "p": "payload" }, { "p": "topic", "vt": "str" } ], "repeat": "2.5", "crontab": "", "once": false, "onceDelay": 0.1, "topic": "", "payload": "", "payloadType": "date", "x": 300, "y": 240, "wires": [ [ "51209fbee52f7afa", "e73d2d18abf8642b" ] ] }, { "id": "51209fbee52f7afa", "type": "change", "z": "dc8b2f6a2286fcc4", "name": "Abfrage Digital I/O", "rules": [ { "t": "set", "p": "payload", "pt": "msg", "to": "{\"fc\":2,\"unitid\":1,\"address\":0,\"quantity\":8}", "tot": "json" } ], "action": "", "property": "", "from": "", "to": "", "reg": false, "x": 510, "y": 200, "wires": [ [ "29831c0a24a3478e" ] ] }, { "id": "e73d2d18abf8642b", "type": "change", "z": "dc8b2f6a2286fcc4", "name": "Abfrage Wasserstand", "rules": [ { "t": "set", "p": "payload", "pt": "msg", "to": "{\"fc\":3,\"unitid\":2,\"address\":4,\"quantity\":1}", "tot": "json" } ], "action": "", "property": "", "from": "", "to": "", "reg": false, "x": 520, "y": 280, "wires": [ [ "29831c0a24a3478e" ] ] }, { "id": "e81ac0403ed1ce83", "type": "switch", "z": "dc8b2f6a2286fcc4", "name": "Quelle", "property": "modbusRequest.unitid", "propertyType": "msg", "rules": [ { "t": "eq", "v": "1", "vt": "num" }, { "t": "eq", "v": "2", "vt": "num" } ], "checkall": "false", "repair": false, "outputs": 2, "x": 730, "y": 400, "wires": [ [ "e4ec8356e59a029f", "32b6291084dd8310" ], [ "74b93b4276ab9bf0" ] ] }, { "id": "7260588c1ac760d7", "type": "link out", "z": "dc8b2f6a2286fcc4", "name": "Eingang 3", "mode": "link", "links": [], "x": 1145, "y": 280, "wires": [] }, { "id": "011469eb233606d1", "type": "debug", "z": "dc8b2f6a2286fcc4", "name": "Wasserstand", "active": true, "tosidebar": false, "console": false, "tostatus": true, "complete": "true", "targetType": "full", "statusVal": "payload", "statusType": "msg", "x": 950, "y": 580, "wires": [] }, { "id": "e40f0fd2755e802b", "type": "link out", "z": "dc8b2f6a2286fcc4", "name": "Wasserstand", "mode": "link", "links": [ "3f8a8670023a2b58" ], "x": 1145, "y": 520, "wires": [] }, { "id": "e4ec8356e59a029f", "type": "change", "z": "dc8b2f6a2286fcc4", "name": "Schwimmschalter", "rules": [ { "t": "set", "p": "payload", "pt": "msg", "to": "payload[0]", "tot": "msg" } ], "action": "", "property": "", "from": "", "to": "", "reg": false, "x": 970, "y": 400, "wires": [ [ "5ff326b7d93448de", "20147aee2d7c0360" ] ] }, { "id": "32b6291084dd8310", "type": "change", "z": "dc8b2f6a2286fcc4", "name": "Eingang 3", "rules": [ { "t": "set", "p": "payload", "pt": "msg", "to": "payload[2]", "tot": "msg" } ], "action": "", "property": "", "from": "", "to": "", "reg": false, "x": 940, "y": 280, "wires": [ [ "61e9664c980b01b7", "7260588c1ac760d7" ] ] }, { "id": "61e9664c980b01b7", "type": "debug", "z": "dc8b2f6a2286fcc4", "name": "Digital Eingang 3", "active": true, "tosidebar": false, "console": false, "tostatus": true, "complete": "true", "targetType": "full", "statusVal": "payload", "statusType": "msg", "x": 970, "y": 340, "wires": [] }, { "id": "5ff326b7d93448de", "type": "debug", "z": "dc8b2f6a2286fcc4", "name": "Schwimmschalter", "active": true, "tosidebar": false, "console": false, "tostatus": true, "complete": "true", "targetType": "full", "statusVal": "payload", "statusType": "msg", "x": 970, "y": 460, "wires": [] }, { "id": "20147aee2d7c0360", "type": "link out", "z": "dc8b2f6a2286fcc4", "name": "Schwimmschalter", "mode": "link", "links": [], "x": 1145, "y": 400, "wires": [] }, { "id": "74b93b4276ab9bf0", "type": "change", "z": "dc8b2f6a2286fcc4", "name": "Wasserstand", "rules": [ { "t": "set", "p": "payload", "pt": "msg", "to": "payload[0]", "tot": "msg" } ], "action": "", "property": "", "from": "", "to": "", "reg": false, "x": 950, "y": 520, "wires": [ [ "011469eb233606d1", "e40f0fd2755e802b" ] ] }, { "id": "4b58abf1891a1caa", "type": "link in", "z": "dc8b2f6a2286fcc4", "name": "Pumpe 1", "links": [ "cb85373556d72833" ], "x": 235, "y": 800, "wires": [ [ "1688a1e6fe0c0a29", "9809d9487ae6dd2b" ] ] }, { "id": "5b1f3b556c08a25f", "type": "link in", "z": "dc8b2f6a2286fcc4", "name": "Pumpe 2", "links": [ "5dc200c453ab751c" ], "x": 235, "y": 880, "wires": [ [ "19aa6c36b7474f6a", "9809d9487ae6dd2b" ] ] }, { "id": "9809d9487ae6dd2b", "type": "trigger", "z": "dc8b2f6a2286fcc4", "name": "Zyklusende", "op1": "", "op2": "OutputBuffer", "op1type": "nul", "op2type": "flow", "duration": "50", "extend": true, "overrideDelay": false, "units": "ms", "reset": "", "bytopic": "all", "topic": "topic", "outputs": 1, "x": 390, "y": 720, "wires": [ [ "90f5261277bd73e8" ] ] }, { "id": "1688a1e6fe0c0a29", "type": "change", "z": "dc8b2f6a2286fcc4", "name": "Ausgang 1", "rules": [ { "t": "set", "p": "payload", "pt": "msg", "to": "[0, msg.payload]", "tot": "jsonata" } ], "action": "", "property": "", "from": "", "to": "", "reg": false, "x": 390, "y": 800, "wires": [ [ "d87b4247f8720531" ] ] }, { "id": "19aa6c36b7474f6a", "type": "change", "z": "dc8b2f6a2286fcc4", "name": "Ausgang 2", "rules": [ { "t": "set", "p": "payload", "pt": "msg", "to": "[1, msg.payload]", "tot": "jsonata" } ], "action": "", "property": "", "from": "", "to": "", "reg": false, "x": 390, "y": 880, "wires": [ [ "d87b4247f8720531" ] ] }, { "id": "d87b4247f8720531", "type": "function", "z": "dc8b2f6a2286fcc4", "name": "Ausgangspuffer", "func": "let outputs = flow.get(\"OutputBuffer\");\n\nconst index = msg.payload[0];\nconst value = msg.payload[1];\noutputs[index] = value;\n\nflow.set(\"OutputBuffer\", outputs);\nmsg.payload = outputs;\nreturn msg;\n", "outputs": 1, "timeout": 150, "noerr": 0, "initialize": "// Code added here will be run once\n// whenever the node is started.\nflow.set(\"OutputBuffer\", [false, false, false, false, false, false, false, false]);\n", "finalize": "", "libs": [], "x": 600, "y": 840, "wires": [ [] ] }, { "id": "da0723da06fe4e7d", "type": "modbus-flex-write", "z": "dc8b2f6a2286fcc4", "name": "", "showStatusActivities": true, "showErrors": true, "showWarnings": true, "server": "e39ff271e27b2afe", "emptyMsgOnFail": false, "keepMsgProperties": false, "delayOnStart": false, "startDelayTime": "", "x": 1050, "y": 840, "wires": [ [], [] ] }, { "id": "90f5261277bd73e8", "type": "change", "z": "dc8b2f6a2286fcc4", "name": "Setzen Digital I/O", "rules": [ { "t": "set", "p": "payload", "pt": "msg", "to": "{\"fc\":15,\"unitid\":1,\"address\":0,\"quantity\":8, \"value\":msg.payload}", "tot": "jsonata" } ], "action": "", "property": "", "from": "", "to": "", "reg": false, "x": 830, "y": 840, "wires": [ [ "da0723da06fe4e7d", "86e2de90a1eca8a8" ] ] }, { "id": "86e2de90a1eca8a8", "type": "debug", "z": "dc8b2f6a2286fcc4", "name": "Ausgänge", "active": true, "tosidebar": false, "console": false, "tostatus": true, "complete": "payload.value", "targetType": "msg", "statusVal": "payload.value", "statusType": "auto", "x": 1020, "y": 780, "wires": [] }, { "id": "e39ff271e27b2afe", "type": "modbus-client", "name": "Modbus RS485", "clienttype": "simpleser", "bufferCommands": true, "stateLogEnabled": false, "queueLogEnabled": false, "failureLogEnabled": true, "tcpHost": "127.0.0.1", "tcpPort": "502", "tcpType": "DEFAULT", "serialPort": "/dev/ttyRS485", "serialType": "RTU-BUFFERD", "serialBaudrate": "9600", "serialDatabits": "8", "serialStopbits": "1", "serialParity": "none", "serialConnectionDelay": "100", "serialAsciiResponseStartDelimiter": "0x3A", "unit_id": "", "commandDelay": "10", "clientTimeout": "1000", "reconnectOnTimeout": true, "reconnectTimeout": "2000", "parallelUnitIdsAllowed": false, "showWarnings": true, "showLogs": true } ] ```

What did you expect to happen?

Reconnect immediately.

Other Information

/dev/ttyRS485 is a symlink to /dev/ttyUSB0 which connects to a typical FTDI RS-485 interface.

NodeRED v3.1.0, NodeJS v18.18.2, Linux v6.1.71 (NixOS)

Which type of OPC UA Server are you connected to?

Not sure what this module has to do with OPC UA...?

biancode commented 4 months ago

Hi, port closing problems are mostly in the combination of serialport as the underlying lib and the nodejs version, which has a very strict binding between both. Some OS' have a some lock time on serial ports or TTY's. That is the reason to have some reconnect timeout in the config node for control.

image
serpent213 commented 4 months ago

I don't know, I'm running the default settings as in your screenshot. Looks fine so far in production, redeploying only single nodes now as necessary. Will keep an eye on it.

Feel free to close this issue. Also happy to help with debugging or testing.

github-actions[bot] commented 2 months ago

This issue is stale because it has been open 60 days with no activity. It will be closed in 30 days, but can be saved by removing the stale label or commenting.