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

Node-RED (Docker) crashes when /dev/ttyACM0 is configured in flow - Raspberry Pi 4 #3461

Closed
jansenmarc1998 opened this issue Feb 27, 2022 · 16 comments

Comments

@jansenmarc1998
Copy link

jansenmarc1998 commented Feb 27, 2022

Current Behavior

Node-RED crashes during startup and/or deployment with no details or log (log level trace)


27 Feb 22:50:49 - [info] 

Welcome to Node-RED
===================

27 Feb 22:50:49 - [info] Node-RED version: v2.2.2
27 Feb 22:50:49 - [info] Node.js  version: v14.18.2
27 Feb 22:50:49 - [info] Linux 5.10.92-v8+ arm64 LE
27 Feb 22:50:50 - [info] Loading palette nodes
27 Feb 22:50:50 - [debug] Module: node-red-dashboard 3.1.6 /data/node_modules/node-red-dashboard
27 Feb 22:50:50 - [debug] Module: node-red-node-serialport 1.0.1 /data/node_modules/node-red-node-serialport
27 Feb 22:50:51 - [info] Dashboard version 3.1.6 started at /ui
27 Feb 22:50:52 - [info] Settings file  : /data/settings.js
27 Feb 22:50:52 - [info] Context store  : 'default' [module=memory]
27 Feb 22:50:52 - [info] User directory : /data
27 Feb 22:50:52 - [warn] Projects disabled : editorTheme.projects.enabled=false
27 Feb 22:50:52 - [info] Flows file     : /data/flows.json
27 Feb 22:50:52 - [info] Server now running at http://127.0.0.1:1880/
27 Feb 22:50:52 - [debug] loaded flow revision: 333da4663a7709aaa4ac6deaf3733db4
27 Feb 22:50:52 - [debug] red/runtime/nodes/credentials.load : no user key present
27 Feb 22:50:52 - [debug] red/runtime/nodes/credentials.load : using default key
27 Feb 22:50:52 - [debug] red/runtime/nodes/credentials.load : keyType=system
27 Feb 22:50:52 - [warn] 

---------------------------------------------------------------------
Your flow credentials file is encrypted using a system-generated key.

If the system-generated key is lost for any reason, your credentials
file will not be recoverable, you will have to delete it and re-enter
your credentials.

You should set your own key using the 'credentialSecret' option in
your settings file. Node-RED will then re-encrypt your credentials
file using your chosen key the next time you deploy a change.
---------------------------------------------------------------------

27 Feb 22:50:52 - [trace] runtime event: {"id":"runtime-state","retain":true}
27 Feb 22:50:52 - [trace] runtime event: {"id":"runtime-deploy","payload":{"revision":"333da4663a7709aaa4ac6deaf3733db4"},"retain":true}
27 Feb 22:50:52 - [info] Starting flows
27 Feb 22:50:52 - [debug] red/nodes/flows.start : starting flow : global
27 Feb 22:50:52 - [debug] red/nodes/flows.start : starting flow : f6f2187d.f17ca8
27 Feb 22:50:52 - [trace] [flow:global] start flow [global]
27 Feb 22:50:52 - [trace] [flow:global] ------------------|--------------|-----------------
27 Feb 22:50:52 - [trace] [flow:global]  id               | type         | alias
27 Feb 22:50:52 - [trace] [flow:global] ------------------|--------------|-----------------
27 Feb 22:50:52 - [trace] [flow:global]  c2b029082d2f328a | ui_base      | 
27 Feb 22:50:52 - [trace] [flow:global]  daf5fb664ded84a4 | ui_tab       | 
27 Feb 22:50:52 - [trace] [flow:global]  dca3bea54c493eb4 | ui_group     | 
27 Feb 22:50:52 - [trace] [flow:global]  5df552a8698cbe93 | ui_group     | 
27 Feb 22:50:52 - [trace] [flow:global]  c2ab819cc6fb5f96 | ui_group     | 
27 Feb 22:50:52 - [trace] [flow:global]  28ef3f98b07f5827 | serial-port  | 
27 Feb 22:50:52 - [trace] [flow:global] ------------------|--------------|-----------------
27 Feb 22:50:52 - [trace] [flow:f6f2187d.f17ca8] start flow [f6f2187d.f17ca8]
27 Feb 22:50:52 - [debug] [inject:timestamp] repeat = 900000
27 Feb 22:50:52 - [trace] [flow:f6f2187d.f17ca8] ------------------|--------------|-----------------
27 Feb 22:50:52 - [trace] [flow:f6f2187d.f17ca8]  id               | type         | alias
27 Feb 22:50:52 - [trace] [flow:f6f2187d.f17ca8] ------------------|--------------|-----------------
27 Feb 22:50:52 - [trace] [flow:f6f2187d.f17ca8]  4ed85eebb0a06cd1 | inject       | 
27 Feb 22:50:52 - [trace] [flow:f6f2187d.f17ca8]  33884147330d3569 | debug        | 

Here it just stops.
It starts normally when I disconnect my device which is plugged in at /dev/ttyACM0 (Adruino)

This also happens when I disconnect my device, delete the flow, connect the device again and create and deploy the flow.

Expected Behavior

Node-RED not crashing and receiving data from /dev/ttyACM0

Steps To Reproduce

Raspberry Pi 4

Docker.io installed via apt and using nodered/node-red image.

Mounted the device either with -v /dev:/dev or --device /dev/ttyACM0:/dev/ttyACM0

Added /etc/udev/rules.d/99-serial.rules on host machine
KERNEL=="ttyACM[0-9]*",MODE="0666"
so the node-red user can read

Example flow

No response

Environment

  • Node-RED version: latest nodered/node-red docker image
  • Node.js version: latest nodered/node-red docker image
  • npm version: latest nodered/node-red docker image
  • Platform/OS: Linux raspberrypi 5.10.92-v8+ # 1514 SMP PREEMPT Mon Jan 17 17:39:38 GMT 2022 aarch64 GNU/Linux
  • Browser: -
@hardillb
Copy link
Member

Anything in the host os logs (run sudo journalctl -f) at the point it hangs?

@jansenmarc1998
Copy link
Author

jansenmarc1998 commented Feb 27, 2022

Feb 27 23:24:58 raspberrypi systemd[1]: run-docker-runtime\x2drunc-moby-0c0b777ea0a04966fa90e79c90df79d3093e9f6d1d10420cbdebb3ae49da9722-runc.2a4RCI.mount: Succeeded.
Feb 27 23:24:58 raspberrypi systemd[313227]: run-docker-runtime\x2drunc-moby-0c0b777ea0a04966fa90e79c90df79d3093e9f6d1d10420cbdebb3ae49da9722-runc.2a4RCI.mount: Succeeded.
Feb 27 23:25:28 raspberrypi kernel: usb 1-1.3: new full-speed USB device number 15 using xhci_hcd
Feb 27 23:25:28 raspberrypi kernel: usb 1-1.3: New USB device found, idVendor=2341, idProduct=0043, bcdDevice= 0.01
Feb 27 23:25:28 raspberrypi kernel: usb 1-1.3: New USB device strings: Mfr=1, Product=2, SerialNumber=220
Feb 27 23:25:28 raspberrypi kernel: usb 1-1.3: Manufacturer: Arduino (www.arduino.cc)
Feb 27 23:25:28 raspberrypi kernel: usb 1-1.3: SerialNumber: 950343031363512112A2
Feb 27 23:25:28 raspberrypi kernel: cdc_acm 1-1.3:1.0: ttyACM0: USB ACM device
Feb 27 23:25:28 raspberrypi mtp-probe[348334]: checking bus 1, device 15: "/sys/devices/platform/scb/fd500000.pcie/pci0000:00/0000:00:00.0/0000:01:00.0/usb1/1-1/1-1.3"
Feb 27 23:25:28 raspberrypi mtp-probe[348334]: bus: 1, device: 15 was not an MTP device
Feb 27 23:25:28 raspberrypi mtp-probe[348336]: checking bus 1, device 15: "/sys/devices/platform/scb/fd500000.pcie/pci0000:00/0000:00:00.0/0000:01:00.0/usb1/1-1/1-1.3"
Feb 27 23:25:28 raspberrypi mtp-probe[348336]: bus: 1, device: 15 was not an MTP device
Feb 27 23:25:37 raspberrypi systemd[1]: docker-0c0b777ea0a04966fa90e79c90df79d3093e9f6d1d10420cbdebb3ae49da9722.scope: Succeeded.
Feb 27 23:25:37 raspberrypi systemd[1]: docker-0c0b777ea0a04966fa90e79c90df79d3093e9f6d1d10420cbdebb3ae49da9722.scope: Consumed 16.757s CPU time.
Feb 27 23:25:37 raspberrypi dockerd[2065]: time="2022-02-27T23:25:37.670603073Z" level=info msg="ignoring event" container=0c0b777ea0a04966fa90e79c90df79d3093e9f6d1d10420cbdebb3ae49da9722 module=libcontainerd namespace=moby topic=/tasks/delete type="*events.TaskDelete"
Feb 27 23:25:37 raspberrypi containerd[1923]: time="2022-02-27T23:25:37.670931176Z" level=info msg="shim disconnected" id=0c0b777ea0a04966fa90e79c90df79d3093e9f6d1d10420cbdebb3ae49da9722
Feb 27 23:25:38 raspberrypi dhcpcd[783]: veth4cc5ddd: carrier lost
Feb 27 23:25:38 raspberrypi kernel: docker0: port 1(veth4cc5ddd) entered disabled state
Feb 27 23:25:38 raspberrypi kernel: vetha74d34d: renamed from eth0
Feb 27 23:25:38 raspberrypi dhcpcd[783]: veth4cc5ddd: deleting address fe80::4f43:6845:4d89:7287
Feb 27 23:25:38 raspberrypi avahi-daemon[330482]: Withdrawing address record for fe80::4f43:6845:4d89:7287 on veth4cc5ddd.
Feb 27 23:25:38 raspberrypi avahi-daemon[330482]: Leaving mDNS multicast group on interface veth4cc5ddd.IPv6 with address fe80::4f43:6845:4d89:7287.
Feb 27 23:25:38 raspberrypi avahi-daemon[330482]: Interface veth4cc5ddd.IPv6 no longer relevant for mDNS.
Feb 27 23:25:38 raspberrypi avahi-daemon[330482]: Interface veth4cc5ddd.IPv4 no longer relevant for mDNS.
Feb 27 23:25:38 raspberrypi avahi-daemon[330482]: Leaving mDNS multicast group on interface veth4cc5ddd.IPv4 with address 169.254.136.85.
Feb 27 23:25:38 raspberrypi kernel: docker0: port 1(veth4cc5ddd) entered disabled state
Feb 27 23:25:38 raspberrypi kernel: device veth4cc5ddd left promiscuous mode
Feb 27 23:25:38 raspberrypi kernel: docker0: port 1(veth4cc5ddd) entered disabled state
Feb 27 23:25:38 raspberrypi avahi-daemon[330482]: Withdrawing address record for 169.254.136.85 on veth4cc5ddd.
Feb 27 23:25:38 raspberrypi dhcpcd[783]: veth4cc5ddd: deleting route to 169.254.0.0/16
Feb 27 23:25:38 raspberrypi systemd-udevd[348387]: vetha74d34d: Failed to query device driver: No such device
Feb 27 23:25:38 raspberrypi systemd-udevd[348387]: vetha74d34d: Failed to get link config: No such device
Feb 27 23:25:38 raspberrypi systemd[313227]: run-docker-netns-fd7f84060e99.mount: Succeeded.
Feb 27 23:25:38 raspberrypi systemd[1]: run-docker-netns-fd7f84060e99.mount: Succeeded.
Feb 27 23:25:38 raspberrypi systemd[313227]: var-lib-docker-overlay2-349857e4018eb55ecea37d0ef76deb579213fadac989b25bc4dacc092e7de9e7-merged.mount: Succeeded.
Feb 27 23:25:38 raspberrypi systemd[1]: var-lib-docker-overlay2-349857e4018eb55ecea37d0ef76deb579213fadac989b25bc4dacc092e7de9e7-merged.mount: Succeeded.
Feb 27 23:25:38 raspberrypi dhcpcd[783]: veth4cc5ddd: removing interface

Everything since I plugged in the device and deployed the flow @hardillb

@hardillb
Copy link
Member

As a test, what happens if you add the --privileged flag?

@jansenmarc1998
Copy link
Author

jansenmarc1998 commented Feb 28, 2022

The --privileged flag is already added. But it doesn't matter. It happens with and without it.

docker run -p 1880:1880 -v node_red_data:/data -v /iotlogs:/iotlogs -v /dev:/dev --privileged --name nodered -d nodered/node-red

@csmale
Copy link

csmale commented Mar 19, 2022

@hardillb I am seeing this as well. I just upgraded node-red-node-serialport from 0.8.8 to 1.0.1 and now it just crashes on startup IF there's a device connected to the serial device referenced from the config node. It is not specific to /dev/ttyACM0 - I changed the device and the flow to use /dev/ttyACM9 as an experiment and that crashes as well. If I try to use a port with no device, lets say /dev/ttyACM8, then everything starts up but of course the serial port doesn't work. If I then change the config to use the actual port, it crashes.
I want to revert to serialport@0.8.8 but how do I do that?

@hardillb
Copy link
Member

To downgrade you will need to do it manually with npm in the /data directory.

If you have mounted a host directory then you may be able to just run npm install node-red-node-serialport@0.8.8 in that mounted directory. You will need to make sure that you run the command as a user with the same id as the node-red user in the container.

If it's a docker volume then you will need to start the container with node-red in safe mode (add the env var NODE_RED_ENABLE_SAFE_MODE=true to the run command) so it doesn't start the flow and crash. Then you can use docker exec -it <name of running container> /bin/sh to get a live shell in the container.

@csmale
Copy link

csmale commented Mar 21, 2022

Thanks @hardillb . Unfortunately I couldn't get either version to install with npm within the container - both give C++ compilation errors. In the end I had to restore a backup which is using version 0.15.0 of node-red-node-serialport. That's working fine for me, and I just have to remember not to update it.
An update from within Manage Palette to 1.0.1 completes without obvious errors however, but it crashes NR whenever it successfully connects to a device, as noted earlier.

@joaquimBS
Copy link

Hi @hardillb I am in the same position as @csmale, and I already filed an issue in node-red/node-red-nodes#894
Unfortunately for me, I do not have a backup with older versions, so I am stuck with NR 2.2.2 and serialport 1.0.1. If I try to manually npm install an older version of serialport I face the same C++ already pointed out by @csmale
Do you have other suggestion as how to go back to a working state?

@hardillb
Copy link
Member

It would be useful to see the C++ errors then we have a chance to work out what's going wrong.

@hardillb
Copy link
Member

OK, I've just managed to reproduce this and tested downgrading the node-red-node-serialport appears to work as expected

Downgrading does depend on you having a volume mounted on the /data directory so the flows are preserved. The following instructions assume that the Node-RED docker container is currently stopped as a result of the crash on starting the flows.

  1. delete the current container docker rm [container name]
  2. Start a new version of the container in safe mode docker run -d --rm --device /dev/ttyACM0:/dev/ttyACM0 -v /path/to/volume:/data -p 1880:1880 -e NODE_RED_ENABLE_SAFE_MODE=true nodered/node-red
  3. Start a shell in the container docker exec -it [container name] /bin/sh
  4. Run the following commands in order
cd /data
npm install node-red-node-serialport@0.15.0
exit
  1. Stop the safe mode container docker stop [container name]
  2. Restart the container as originally docker run -d --device /dev/ttyACM0:/dev/ttyACM0 -v /path/to/volume:/data -p 1880:1880 nodered/node-red

The node-red-node-serialport install does output a bunch of warnings, this is somewhat expected and it does finish cleanly.

I'll try and look at why it's crashing with v1.0.1 , but there is very little information to work with.

I will also get this moved to the node-red-docker project where it belongs (@knolleary can you do the move please)

@hardillb
Copy link
Member

This looks relevant serialport/node-serialport#2438

@hardillb
Copy link
Member

hardillb commented Mar 23, 2022

OK, better fix that works with v1.0.1

Follow the same process as earlier but swap step 4 for

cd /data
npm rebuild --build-from-source
exit

This looks to be a problem with the pre-complied binaries from the upstream serialport node.

@joaquimBS
Copy link

OK, better fix that works with v1.0.1

Follow the same process as earlier but swap step 4 for

cd /data
npm rebuild --build-from-source
exit

This looks to be a problem with the pre-complied binaries from the upstream serialport node.

I confirm this fixes the issue in my RPi4 setup using /dev/ttyUSB0 device.
I imagine next steps are to rebuild some binaries and push new version of serialport node?

Thanks!

@hardillb
Copy link
Member

Next steps are with the serialport node maintainers, nothing we (node-red) can do at the moment.

@dceejay
Copy link
Member

dceejay commented Mar 23, 2022

Closing here as not a core node - see node-red/node-red-nodes#894 (comment)

@dceejay dceejay closed this as completed Mar 23, 2022
@Roaders
Copy link

Roaders commented Jul 1, 2022

thanks so much for this thread and the fix @hardillb - I've spent too long trying to figure this out and was just posting a long boring thread hoping to get help with this but I've not got it working!

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Projects
None yet
Development

No branches or pull requests

6 participants