node-zwave-js: [bug] tcp://ip:port connection ETIMEDOUT error doesn't match `ZWaveErrorCodes.Driver_Failed`

Checklist:

[ X ] I am not using Home Assistant.
[ X ] I have checked the troubleshooting section and my problem is not described there.
[ X ] I have read the changelog and my problem is not mentioned there.

Build/Run method

[ X ] Docker
PKG
Snap package
Manually built (git clone - yarn install - yarn run build )

Zwavejs2Mqtt version: 5.8.0 Z-Wave JS version: 8.4.1

Describe the bug

I am using a tcp connection for zwave, in the form of tcp://192.168.1.5:7676
on the other end of the connection there’s a ser2net server
everything works great until the network device reboot

After reboot, the web interface shows Driver: read ETIMEDOUT and in MQTT I have (topic and value) service/zwave_01/_EVENTS/ZWAVE_GATEWAY-zwave_01/driver/driver_error {"data":[{"errno":-110,"code":"ETIMEDOUT","syscall":"read"}]}

and it never works again unless i restart the zwave2mqtt docker image or i save setting again in the web interface

To Reproduce

Steps to reproduce the behavior:

Go to setting -> zwave, set tcp://<ip>:<port> for ser2net server attached to a zwave stick on a network device
Save setting
Check zwave works by turning a device/on/off
Reboot network device that runs ser2net or pull network cable
see in web interface “Driver: read ETIMEDOUT”
see in mqtt service/zwave_01/_EVENTS/ZWAVE_GATEWAY-zwave_01/driver/driver_error {"data":[{"errno":-110,"code":"ETIMEDOUT","syscall":"read"}]}

Expected behavior

When zwave driver enter that specific error state i expect it to be restarted after some amount of time.

Additional context

I don’t think it matters but my network device is a vera edge with all it’s vera software turned off and ser2net being started automatically
I am using docker image with :latest tag pulled one hour ago and i did a zwave config updates then restarted everything

How do i clean up my logs of any private data ? I’d like to post them here but i want to make sure i don’t leak any keys or other information.

Thank you for your time! This is great software!

About this issue

Original URL
State: closed
Created 3 years ago
Comments: 37 (15 by maintainers)

Most upvoted comments

Regarding the initial issue in the ticket: @robertsLando @AlCalzone i have zwave still working since yesterday (about 18 hours) with multiple reboots and ser2net restarts (more than 200 probably). It seems pretty stable.

vladbabii on Oct 14, 2021

2021-10-13 12:36:30.682 INFO ZWAVE: Next update scheduled for: Thu Oct 14 2021 00:00:00 GMT+0300 (Eastern European Summer Time)
2021-10-13 12:36:44.832 INFO ZWAVE: Controller status: Driver: Serial port errored: read ETIMEDOUT
2021-10-13 12:36:44.833 DEBUG MQTT: Publishing to service/zwave_01/_EVENTS/ZWAVE_GATEWAY-zwave_01/driver/driver_error: {
  data: [
    ZWaveError: Serial port errored: read ETIMEDOUT
        at ZWaveSocket.<anonymous> (/usr/src/app/node_modules/zwave-js/src/lib/driver/Driver.ts:702:19)
        at ZWaveSocket.emit (node:events:394:28)
        at ZWaveSocket.emit (node:domain:470:12)
        at Socket.<anonymous> (/usr/src/app/node_modules/@zwave-js/serial/src/ZWaveSerialPortBase.ts:112:9)
        at Socket.emit (node:events:394:28)
        at Socket.emit (node:domain:470:12)
        at emitErrorNT (node:internal/streams/destroy:193:8)
        at emitErrorCloseNT (node:internal/streams/destroy:158:3)
        at processTicksAndRejections (node:internal/process/task_queues:83:21) {
      [stack]: 'ZWaveError: Serial port errored: read ETIMEDOUT\n' +
        '    at ZWaveSocket.<anonymous> (/usr/src/app/node_modules/zwave-js/src/lib/driver/Driver.ts:702:19)\n' +
        '    at ZWaveSocket.emit (node:events:394:28)\n' +
        '    at ZWaveSocket.emit (node:domain:470:12)\n' +
        '    at Socket.<anonymous> (/usr/src/app/node_modules/@zwave-js/serial/src/ZWaveSerialPortBase.ts:112:9)\n' +
        '    at Socket.emit (node:events:394:28)\n' +
        '    at Socket.emit (node:domain:470:12)\n' +
        '    at emitErrorNT (node:internal/streams/destroy:193:8)\n' +
        '    at emitErrorCloseNT (node:internal/streams/destroy:158:3)\n' +
        '    at processTicksAndRejections (node:internal/process/task_queues:83:21)',
      [message]: 'Serial port errored: read ETIMEDOUT',
      code: 5,
      context: undefined,
      transactionSource: undefined,
      name: 'ZWaveError'
    },
    [length]: 1
  ]
} with options { qos: 1, retain: false }
2021-10-13 12:36:44.836 INFO ZWAVE-SERVER: Server closed
2021-10-13 12:36:44.840 INFO ZWAVE: Client closed
2021-10-13 12:36:44.843 INFO ZWAVE: Connecting to tcp://10.11.8.88:7676
Logging to file:
        /usr/src/app/store/zwavejs_2021-10-13.log

Then if it fails i see the retry

2021-10-13 12:37:22.375 WARN ZWAVE: Retry connection in 3 seconds...
2021-10-13 12:37:25.380 INFO ZWAVE: Connecting to tcp://10.11.8.88:7676

And then it seems to be working fine. I’ll do some testing over the next 1-2 hours to make sure it’s stable

vladbabii on Oct 13, 2021

@AlCalzone @robertsLando please let me know when i can test with any docker image to validate the fix. Also, if you have any other bugs that need docker testing please let me know, i have a couple zwave devices, zwave sticks and other zwave-related things.

vladbabii on Oct 13, 2021