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

[Bug]: Serial port becomes unusable until node-red restart w/ newer versions #288

Closed
svdasein opened this issue Dec 10, 2023 · 9 comments
Closed
Assignees
Labels
bug Something isn't working upstream origin of bug is upstream

Comments

@svdasein
Copy link

svdasein commented Dec 10, 2023

What happened?

A few days ago I updated nodejs and node-red on a raspi4. Prior to the upgrade all was well. Subsequent to the upgrade I'm seeing an issue that I believe I've narrowed down to serial port logic in node-red-contrib-zwave-js:

If I leave the zwave js controller node enabled when I do a "deploy" or "restart nodes", that port will subsequently become unavailable due to some problem with port locking. The controller node emits messages about being unable to lock the usb port.

ZWaveError: Failed to open the serial port: Error Resource temporarily unavailable Cannot lock port (ZW0100)

The only way I have found to recover from this is to restart node-red itself. Once I do that, the controller node works properly again.

I have managed to work around this by being sure to disable + deploy the disable before doing other work. If I do that I can reliably bring the controller back up by enabling the controller node + deploy.

I looked at a LOT of stuff tracking this down, so I'm pretty sure it's somewhere in your stuff. Briefly:

  • I ensured that nothing else is competing for access to the port (using lsof etc)
  • I upgraded raspian to the latest - everything at the os level is up to date
  • I upgraded all node modules in node-red and did an npm rebuild. same for node red itself.
  • At one point I was seeing an identical looking problem with the the serial port thing that comes with node-red (I think it does anyway). I installed several versions of node-red-node-serialport and found that the problem was gone after I installed 2.0.2. When I say "identical" I mean "I got a message about failing to lock a port that was only correctable by restarting node-red" which went away after the nod-red-node-serialport upgrade
  • Looking at your stuff - it looks like you're bundling your own serial logic
  • I get a sense (I'm not a nodejs coder - I just plink around a bit) that there was some kind of breaking change that might be related directly or indirectly to what's going on with your serial logic. I got rather deep into that such that at one point I was looking at some stuff about what looked like a google contribution to nodejs, but I can't seem to find it in my browser history - my apologies. It was C++ stuff and they were talking about deprecating something for a couple of versions - and it looks like by nodejs 20 they had removed it.

I'm just guessing, but it seems like the issue might be sort of in one of these ballparks:

  • A lock that used to get released on deploy no longer gets released
  • A lock that is presumed to have been let go no longer needs to be treated as such

Versions:

PRETTY_NAME="Raspbian GNU/Linux 11 (bullseye)"
NAME="Raspbian GNU/Linux"
VERSION_ID="11"
VERSION="11 (bullseye)"

Linux nodered 6.1.21-v8+ #1642 SMP PREEMPT Mon Apr  3 17:24:16 BST 2023 aarch64 GNU/Linux

root@nodered:/usr/lib/node_modules# node --version
v20.5.1
root@nodered:/usr/lib/node_modules# npm ls
/usr/lib
├── [email protected] extraneous
├── [email protected] extraneous
└── [email protected] extraneous

nodered@nodered:~/.node-red $ npm ls
[email protected] /home/nodered/.node-red
├── @flowforge/[email protected]
├── @meowwolf/[email protected]
├── @node-red-contrib-themes/[email protected]
├── @studiobox/[email protected]
├── [email protected]
├── [email protected]
├── [email protected]
├── [email protected]
├── [email protected]
├── [email protected]
├── [email protected]
├── [email protected]
├── [email protected]
├── [email protected]
├── [email protected]
├── [email protected]
├── [email protected]
├── [email protected]
├── [email protected]
├── [email protected]
├── [email protected]
├── [email protected]
├── [email protected]
├── [email protected]
├── [email protected]
├── [email protected]
├── [email protected]
├── [email protected]
├── [email protected]
├── [email protected]
├── [email protected]
├── [email protected]
├── [email protected]
├── [email protected]
├── [email protected]
├── [email protected]
├── [email protected]
├── [email protected]
├── [email protected]
├── [email protected]
├── [email protected]
├── [email protected]
├── [email protected]
├── [email protected]
├── [email protected]
├── [email protected]
├── [email protected]
├── [email protected]
├── [email protected]
├── [email protected]
├── [email protected]
├── [email protected]
├── [email protected]
├── [email protected]
├── [email protected]
├── [email protected]
├── [email protected]
├── [email protected]
├── [email protected]
├── [email protected]
├── [email protected]
├── [email protected]
├── [email protected]
├── [email protected]
├── [email protected]
├── [email protected]
├── [email protected]
├── [email protected]
└── [email protected]

How to reproduce?

  • Upgrade to latest raspian
  • Upgrade node-red to latest
  • Upgrade all node modules to latest
  • Modify a flow and deploy it

Version

9.0.3

Node-RED Version

3.1.3

What hardware are you seeing the problem on?

Raspberry Pi

Relevant Z-Wave-JS log as a text file

ZWaveError: Failed to open the serial port: Error Resource temporarily unavailable Cannot lock port (ZW0100)

@svdasein svdasein added the bug Something isn't working label Dec 10, 2023
@marcus-j-davies
Copy link
Member

marcus-j-davies commented Dec 10, 2023

@svdasein

Looking at your stuff - it looks like you're bundling your own serial logic

This package doesn't do anything with the serial port - other then list what's available on the system- it's all managed by the zwave-js library, that this module uses, and zwave-js is using the popular serialnode package for all serial interaction.

ZWaveError: Failed to open the serial port: Error Resource temporarily unavailable Cannot lock port (ZW0100)

Log file please to capture all events leading up to and including this event - you can enable logging in the Controller Node (set to File, Debug) - the log will be in ~/.node-red

Please don't edit the log file - just upload the file as is.

whilst I wait for the log file, I'll ping @AlCalzone, to see if he has any immediate input with any known issues with Node 20 and the serilaport package - But he is on parental leave currently - so please allow some time

This module will bring down the driver (and in doing so, will release the serial port - see below) - so my guess is, this is an issue with serilaport and node 20 - its already been reported by another user -> serialport/node-serialport#2735

Driver.destroy().then(() => {

@marcus-j-davies marcus-j-davies added upstream origin of bug is upstream waiting-for-info Waiting for further info/outcome labels Dec 10, 2023
@svdasein
Copy link
Author

zwave-js.log

@AlCalzone
Copy link
Member

No known issues from my side, but the linked issue seems to be a reasonable explanation for the behavior. Does the node-red serialport plug in also use this library?

@marcus-j-davies
Copy link
Member

it does

@marcus-j-davies marcus-j-davies removed the waiting-for-info Waiting for further info/outcome label Dec 10, 2023
@marcus-j-davies
Copy link
Member

marcus-j-davies commented Dec 10, 2023

Everything is being closed down according to log.

2023-12-10T20:32:19.536Z DRIVER   all queues idle
2023-12-10T20:32:26.757Z NDERED   [SHUTDOWN] [RESTART] Cleaning up...
2023-12-10T20:32:26.759Z DRIVER   destroying driver instance...
2023-12-10T20:32:26.901Z DRIVER   driver instance destroyed
2023-12-10T20:32:27.671Z NDERED   [options] [interview.queryAllUserCodes] Disabled
2023-12-10T20:32:27.672Z NDERED   [options] [disableOptimisticValueUpdate] Disabled
2023-12-10T20:32:27.672Z NDERED   [options] [enableSoftReset] Disabled
2023-12-10T20:32:27.672Z NDERED   [options] [storage.cacheDir] /home/nodered/.node-red/zwave-js-cache
2023-12-10T20:32:27.672Z NDERED   [options] [storage.throttle] normal
2023-12-10T20:32:27.672Z NDERED   [options] [preferences.scales.temperature] 0x00
2023-12-10T20:32:27.673Z NDERED   [options] [preferences.scales.humidity] 0x00
2023-12-10T20:32:27.673Z NDERED   [FWUS] Open source license applied
2023-12-10T20:32:27.673Z NDERED   Initializing driver...
2023-12-10T20:32:27.678Z NDERED   [TELEMETRY] Disabling...
2023-12-10T20:32:27.678Z NDERED   Starting driver...
2023-12-10T20:32:27.679Z DRIVER   ███████╗        ██╗    ██╗  █████╗  ██╗   ██╗ ███████╗          ██╗ ███████╗
                                  ╚══███╔╝        ██║    ██║ ██╔══██╗ ██║   ██║ ██╔════╝          ██║ ██╔════╝
                                    ███╔╝  █████╗ ██║ █╗ ██║ ███████║ ██║   ██║ █████╗            ██║ ███████╗
                                   ███╔╝   ╚════╝ ██║███╗██║ ██╔══██║ ╚██╗ ██╔╝ ██╔══╝       ██   ██║ ╚════██║
                                  ███████╗        ╚███╔███╔╝ ██║  ██║  ╚████╔╝  ███████╗     ╚█████╔╝ ███████║
                                  ╚══════╝         ╚══╝╚══╝  ╚═╝  ╚═╝   ╚═══╝   ╚══════╝      ╚════╝  ╚══════╝
2023-12-10T20:32:27.679Z DRIVER   version 12.4.0
2023-12-10T20:32:27.679Z DRIVER   
2023-12-10T20:32:27.679Z DRIVER   starting driver...
2023-12-10T20:32:27.679Z DRIVER   opening serial port /dev/serial/by-id/usb-Silicon_Labs_CP2102N_USB_to_UART_Bri
                                  dge_Controller_a42420fe1da4eb118cc928259da30875-if00-port0
2023-12-10T20:32:37.031Z DRIVER   Failed to open the serial port: Error Resource temporarily unavailable Cannot 
                                  lock port
2023-12-10T20:32:37.033Z DRIVER   destroying driver instance...
2023-12-10T20:32:37.034Z NDERED   [ERROR] [DRIVER] Failed to open the serial port: Error Resource temporarily un
                                  available Cannot lock port (ZW0100)
2023-12-10T20:32:37.037Z DRIVER   driver instance destroyed

@svdasein
Copy link
Author

It may be the case that whatever is wrong is something that was fixed by whoever maintains node-red-node-serialport - as I mentioned, when I upgraded that the problem with port locks that use that node went away.

├── [email protected]

fyi I actually walked the version of node-red-node-serialport upwards 'til the problem went away. I believe 2.0.2 is the very latest version.

@marcus-j-davies
Copy link
Member

@svdasein

My suggestion is to downgrade to Node 18 for the time being (its still preferred for Node RED at this stage)
Or if you don't want to do that - Just only publish modified nodes - instead of a full deploy, to stop everything re-starting

Nothing in this module will be responsible for the error, as I believe it to be upstream somewhere.

@svdasein
Copy link
Author

@marcus-j-davies - thanks - I will try that.

@svdasein
Copy link
Author

After a downgrade to node v18.17.1 the problem no longer occurs. Thanks for your help!

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
bug Something isn't working upstream origin of bug is upstream
Projects
None yet
Development

No branches or pull requests

3 participants