[bug] zwavejs2mqtt does not reconnect if the serial port (TCP socket) is closed

[andyboeh]

Version

Checklist:

• I am not using HomeAssistant. Or: a developer has told me to come here.
• I have checked the troubleshooting section and my problem is not described there.
• I have read the changelog problem was not mentioned there.

Build/Run method

• Docker
• PKG
• Snap package
• Manually built (git clone - yarn install - yarn run build )

zwavejs2mqtt version: 4.3.0
zwave-js version: 7.5.0

Describe the bug

In #1167, a problem with detecting a dropped TCP socket connection to the serial device was reported and fixed in zwave-js/node-zwave-js#2601. However, the application needs to handle the lost connection. For now, the state is "Driver: The socket closed unexpectedly". IMHO, zwavejs2mqtt should try to auto-reconnect in this case, as the connection might become available (this could also be a configuration option, like auto-reconnect interval).

It finally reconnects if I go to Settings and click on "Save".

To Reproduce

Steps to reproduce the behavior:

1. Connect the Z-Wave dongle via ser2net
2. Stop ser2net
3. Wait for the lost connection in zwavejs2mqtt
4. Restart ser2net

Expected behavior

After 4., the connection should be auto-restored.

Additional context

Add any other context about the problem here.

[robertsLando]

@AlCalzone Shouldn't the reconnection be handled by zwave-js once it comes back?

[AlCalzone]

zwave-js/node-zwave-js#2601

Because the driver and controller state may go out of sync in this case, a closed socket will destroy the driver instance, which must be handled by the application - e.g. by restarting or shutting down.

The driver currently has no way of restarting itself.

[robertsLando]

@andyboeh Could you check with master?

[andyboeh]

@robertsLando It does reconnect, but reports a bunch of errors about nodes added twice:

2021-05-22 23:12:06.540 INFO ZWAVE: Controller status: Driver: connect ECONNREFUSED 192.168.17.235:5000
2021-05-22 23:12:06.540 WARN ZWAVE: Retry connection in 3 seconds...
2021-05-22 23:12:09.551 INFO ZWAVE: Connecting to tcp://sczubau.lan:5000
2021-05-22 23:12:09.846 INFO ZWAVE: Next update scheduled for: Sun May 23 2021 00:00:00 GMT+0200 (Central European Summer Time)
2021-05-22 23:12:12.061 INFO ZWAVE: Zwave driver is ready
2021-05-22 23:12:12.062 INFO ZWAVE: Controller status: Driver ready
2021-05-22 23:12:12.063 ERROR ZWAVE: Error while adding node 1 node has been added twice
Error: node has been added twice
at ZwaveClient._addNode (/usr/src/app/lib/ZwaveClient.js:2463:9)
at ZwaveClient._onDriverReady (/usr/src/app/lib/ZwaveClient.js:1732:12)
at Object.onceWrapper (node:events:484:28)
at Driver.emit (node:events:378:20)
at Driver.EventEmitter.emit (node:domain:470:12)
at Driver.initializeControllerAndNodes (/usr/src/app/node_modules/zwave-js/src/lib/driver/Driver.ts:805:8)
at processTicksAndRejections (node:internal/process/task_queues:94:5)
at Immediate.<anonymous> (/usr/src/app/node_modules/zwave-js/src/lib/driver/Driver.ts:700:5)
2021-05-22 23:12:12.064 ERROR ZWAVE: Error while adding node 2 node has been added twice
Error: node has been added twice
at ZwaveClient._addNode (/usr/src/app/lib/ZwaveClient.js:2463:9)
at ZwaveClient._onDriverReady (/usr/src/app/lib/ZwaveClient.js:1732:12)
at Object.onceWrapper (node:events:484:28)
at Driver.emit (node:events:378:20)
at Driver.EventEmitter.emit (node:domain:470:12)
at Driver.initializeControllerAndNodes (/usr/src/app/node_modules/zwave-js/src/lib/driver/Driver.ts:805:8)
at processTicksAndRejections (node:internal/process/task_queues:94:5)
at Immediate.<anonymous> (/usr/src/app/node_modules/zwave-js/src/lib/driver/Driver.ts:700:5)

[...]

2021-05-22 23:12:12.074 INFO ZWAVE: Scanning network with homeid: xxxxxx
2021-05-22 23:12:12.100 INFO ZWAVE-SERVER: ZwaveJS server listening on port 3000
2021-05-22 23:12:19.771 INFO ZWAVE: Controller status: Scan completed
2021-05-22 23:12:19.773 INFO ZWAVE: Network scan complete. Found: 10 nodes

Afterwards, events from the devices are reported to Home Assistant, but aren't visible in the control panel or in the log file!?

[robertsLando]

Thanks for the feedback @andyboeh will try to fix it in a new PR

[andyboeh]

Thanks for the quick fix, much appreciated - I tested it again with the latest master docker container and it is working properly now!

[robertsLando]

Great! Thanks for your feedback @andyboeh