maxwellhadley / node-red-contrib-rfxcom

node-RED nodes to access an RFXtrx433 transceiver
BSD 2-Clause "Simplified" License
22 stars 13 forks source link

No commands received under Docker / Synology #109

Open matz33 opened 3 years ago

matz33 commented 3 years ago

Hello

I'm using nodered under last image of Nodered Docker, in Synology. I created the container with the following command :

docker run -it --net=host -v /volume1/docker/nodered2/data:/data -v /volume1/docker/nodered2:/syno -v /etc/localtime:/etc/localtime:ro -v /etc/TZ:/etc/timezone:ro -d --restart always --privileged=true -e DSM_HOSTNAME=synology -e TZ=Europe/Paris --device /dev/ttyUSB0 -name nodered nodered/node-red

I used the parameter --device /dev/ttyUSB0 as indicated in the docker page of nodered, in order tobe able to access to the port.

I'm using last version of node-red-contrib-rfxcom (2.11.2, I upgraded the rfxcom to last fimrware (1025). Here is what i have :

I add a rfx-lights node, serial port / dev/ttyUSB0, with option "listen for commands sent to any address", I connect it to a debug node with complete msg object. I deploy. The node has this message under it : "OK (v1025 ext 2)". I push a button on a command, I can see the little yellow led light on then light off on the rfxcom, but nothing happens in nodered. When I push the same button when the rfxcom is plugged to my computer running windows, I see the message coming in rfxmgr.

Here is a grep rfxcom of the nodered logs :

25 Oct 10:57:40 - [debug] Module: node-red-contrib-rfxcom 2.11.2 25 Oct 10:57:40 - [debug] /data/node_modules/node-red-contrib-rfxcom 2020-10-25 10:57:57.613 [rfxcom] on /dev/ttyUSB0 - Sent : 0D,00,00,00,00,00,00,00,00,00,00,00,00,00 2020-10-25 10:57:58.127 [rfxcom] on /dev/ttyUSB0 - Sent : 0D,00,00,01,02,00,00,00,00,00,00,00,00,00 2020-10-25 10:59:02.391 [rfxcom] on /dev/ttyUSB0 - RFXtrx433 disconnected from /dev/ttyUSB0 2020-10-25 10:59:02.392 [rfxcom] on /dev/ttyUSB0 - Cleared command message queue 2020-10-25 10:59:13.901 [rfxcom] on /dev/ttyUSB0 - Sent : 0D,00,00,00,00,00,00,00,00,00,00,00,00,00 2020-10-25 10:59:14.506 [rfxcom] on /dev/ttyUSB0 - Sent : 0D,00,00,01,02,00,00,00,00,00,00,00,00,00 2020-10-25 10:59:14.525 [rfxcom] on /dev/ttyUSB0 - Received: 14,01,00,01,02,53,19,63,DF,FF,03,01,03,1C,04,00,00,00,00,00,00 2020-10-25 10:59:14.529 [rfxcom] on /dev/ttyUSB0 - Sent : 0D,00,00,02,07,00,00,00,00,00,00,00,00,00 2020-10-25 10:59:14.861 [rfxcom] on /dev/ttyUSB0 - Received: 14,01,07,02,07,43,6F,70,79,72,69,67,68,74,20,52,46,58,43,4F,4D 2020-10-25 10:59:14.862 [rfxcom] on /dev/ttyUSB0 - Copyright RFXCOM 2020-10-25 10:59:14.862 [rfxcom] on /dev/ttyUSB0 - Started command message queue 2020-10-25 10:59:32.931 [rfxcom] on /dev/ttyUSB0 - Received: 14,01,07,07,07,43,6F,70,79,72,69,67,68,74,20,52,46,58,43,4F,4D 2020-10-25 10:59:32.932 [rfxcom] on /dev/ttyUSB0 - Copyright RFXCOM 2020-10-25 10:59:33.007 [rfxcom] on /dev/ttyUSB0 - Received: 14,01,00,08,02,53,19,63,DF,FF,03,01,03,1C,04,52,46,58,43,4F,4D 2020-10-25 10:59:33.009 [rfxcom] on /dev/ttyUSB0 - Sent : 0D,00,00,03,07,00,00,00,00,00,00,00,00,00

Can you help me ?

Regards

Matz

maxwellhadley commented 3 years ago

The start-up handshake of the RFXCOM is not happening correctly. The node sends the handshake sequence starting at 10:57:57.613, but there is no reply: instead the RFX seems to disconnect (at 10:59:02.391). The node tries again to reconnect starting at 10:59:13.901 and this time it succeeds, so the message queue is started. But then at 10:59:32.931, the 'Copyright RFXCOM' message appears again, this time with a different message sequence number of 07. instead of 02 What happened to messages 03 to 06? They don't appear in the debug log. It's the RFX firmware that is generating these sequence numbers so it (presumably) sent the corresponding messages out, but they never reached Node-RED.

Furthermore, the copyright message is the reply to the 'start receiver' command (first sent at 10:59:14.529) and the firmware should only ever send it in reply to such a command.

So it looks like something in the USB Docker stack is going wrong - disconnecting oddly, missing and/or repeating messages, or something like that.

But there also seems to be another problem, where the node-red-contrib-rfxcom node is getting confused by an unsolicited 'copyright' message. Understandable, but I will see if I can make it more robust.

matz33 commented 3 years ago

It sounds like it will be impossible to make it work under Docker ?

maxwellhadley commented 3 years ago

If it is a Docker problem, I can't really help - sorry. Try the Docker and/or serialport package support channels.

matz33 commented 3 years ago

Hi Max

I don't know if it is a docker problem. I changed an option reading channels : i changed the user and add it to dialout group with this option : -u node-red:dialout.

When nodered starts, nodes are in yellow "Connecting...". Then i unplug the rfxcom module, and replug it. The nodes says "OK (v1025 ext 2)" in green. Then I can use a 433mhz light remote controller and it is working. I used it several time (hit buttons) until it stopped working, after receiving the "Copyright RFXCOM" message in logs here :

synology> docker logs -f nodered | grep rfx 27 Oct 13:44:53 - [debug] Module: node-red-contrib-rfxcom 2.11.2 27 Oct 13:44:53 - [debug] /data/node_modules/node-red-contrib-rfxcom 27 Oct 13:44:59 - [info] [rfx-lights-in:Téléc Salon neutre AC/0x02468000] connecting to /dev/ttyUSB0 27 Oct 13:45:05 - [debug] Module: node-red-contrib-rfxcom 2.11.2 27 Oct 13:45:05 - [debug] /data/node_modules/node-red-contrib-rfxcom 27 Oct 13:45:11 - [info] [rfx-lights-in:Téléc Salon neutre AC/0x02468000] connecting to /dev/ttyUSB0 2020-10-27 13:45:16.581 [rfxcom] on /dev/ttyUSB0 - Sent : 0D,00,00,00,00,00,00,00,00,00,00,00,00,00 2020-10-27 13:45:17.086 [rfxcom] on /dev/ttyUSB0 - Sent : 0D,00,00,01,02,00,00,00,00,00,00,00,00,00 2020-10-27 13:45:39.173 [rfxcom] on /dev/ttyUSB0 - RFXtrx433 disconnected from /dev/ttyUSB0 2020-10-27 13:45:39.174 [rfxcom] on /dev/ttyUSB0 - Cleared command message queue 27 Oct 13:45:39 - [info] [rfx-lights-in:Téléc Salon neutre AC/0x02468000] disconnected: bad file descriptor 27 Oct 13:45:45 - [info] [rfx-lights-in:Téléc Salon neutre AC/0x02468000] connecting to /dev/ttyUSB0 2020-10-27 13:45:50.679 [rfxcom] on /dev/ttyUSB0 - Sent : 0D,00,00,00,00,00,00,00,00,00,00,00,00,00 2020-10-27 13:45:51.180 [rfxcom] on /dev/ttyUSB0 - Sent : 0D,00,00,01,02,00,00,00,00,00,00,00,00,00 2020-10-27 13:45:51.190 [rfxcom] on /dev/ttyUSB0 - Received: 14,01,00,01,02,53,19,63,DF,FF,03,01,03,1C,04,00,00,00,00,00,00 2020-10-27 13:45:51.194 [rfxcom] on /dev/ttyUSB0 - Sent : 0D,00,00,02,07,00,00,00,00,00,00,00,00,00 2020-10-27 13:45:51.238 [rfxcom] on /dev/ttyUSB0 - Received: 14,01,07,02,07,43,6F,70,79,72,69,67,68,74,20,52,46,58,43,4F,4D 2020-10-27 13:45:51.238 [rfxcom] on /dev/ttyUSB0 - Copyright RFXCOM 2020-10-27 13:45:51.239 [rfxcom] on /dev/ttyUSB0 - Started command message queue 27 Oct 13:45:51 - [info] [rfx-lights-in:Téléc Salon neutre AC/0x02468000] connected: Serial port /dev/ttyUSB0 2020-10-27 13:45:51.317 [rfxcom] on /dev/ttyUSB0 - Received: 0B,11,00,00,02,46,80,00,02,01,0F,70 2020-10-27 13:45:51.807 [rfxcom] on /dev/ttyUSB0 - Received: 0B,11,00,01,02,46,80,00,02,00,00,70 2020-10-27 13:45:52.856 [rfxcom] on /dev/ttyUSB0 - Received: 0B,11,00,02,02,46,80,00,02,01,0F,70 2020-10-27 13:45:54.650 [rfxcom] on /dev/ttyUSB0 - Received: 0B,11,00,03,02,46,80,00,02,00,00,70 2020-10-27 13:45:54.650 [rfxcom] on /dev/ttyUSB0 - Received: 0B,11,00,04,02,46,80,00,02,01,0F,70 2020-10-27 13:45:55.533 [rfxcom] on /dev/ttyUSB0 - Received: 0B,11,00,05,02,46,80,00,02,00,00,70 2020-10-27 13:45:56.516 [rfxcom] on /dev/ttyUSB0 - Received: 0B,11,00,06,02,46,80,00,02,01,0F,70 2020-10-27 13:45:57.604 [rfxcom] on /dev/ttyUSB0 - Received: 0B,11,00,07,02,46,80,00,02,00,00,70 2020-10-27 13:45:58.983 [rfxcom] on /dev/ttyUSB0 - Received: 0B,11,00,08,02,46,80,00,02,01,0F,70 2020-10-27 13:45:59.531 [rfxcom] on /dev/ttyUSB0 - Received: 0B,11,00,09,02,46,80,00,02,00,00,70 2020-10-27 13:46:00.397 [rfxcom] on /dev/ttyUSB0 - Received: 0B,11,00,0A,02,46,80,00,02,01,0F,70 2020-10-27 13:46:01.209 [rfxcom] on /dev/ttyUSB0 - Received: 0B,11,00,0B,02,46,80,00,02,00,00,70 2020-10-27 13:46:02.224 [rfxcom] on /dev/ttyUSB0 - Received: 0B,11,00,0C,02,46,80,00,02,01,0F,70 2020-10-27 13:46:04.075 [rfxcom] on /dev/ttyUSB0 - Received: 0B,11,00,0D,02,46,80,00,02,01,0F,70 2020-10-27 13:46:05.026 [rfxcom] on /dev/ttyUSB0 - Received: 0B,11,00,0E,02,46,80,00,02,00,00,70 2020-10-27 13:46:06.423 [rfxcom] on /dev/ttyUSB0 - Received: 0B,11,00,0F,02,46,80,00,02,01,0F,70 2020-10-27 13:46:06.881 [rfxcom] on /dev/ttyUSB0 - Received: 0B,11,00,10,02,46,80,00,02,00,00,70 2020-10-27 13:46:08.174 [rfxcom] on /dev/ttyUSB0 - Received: 0B,11,00,11,02,46,80,00,02,01,0F,70 2020-10-27 13:46:09.469 [rfxcom] on /dev/ttyUSB0 - Received: 14,01,07,22,07,43,6F,70,79,72,69,67,68,74,20,52,46,58,43,4F,4D 2020-10-27 13:46:09.470 [rfxcom] on /dev/ttyUSB0 - Copyright RFXCOM 2020-10-27 13:46:09.546 [rfxcom] on /dev/ttyUSB0 - Received: 14,01,00,23,02,53,19,63,DF,FF,03,01,03,1C,04,52,46,58,43,4F,4D 2020-10-27 13:46:09.548 [rfxcom] on /dev/ttyUSB0 - Sent : 0D,00,00,03,07,00,00,00,00,00,00,00,00,00

All commands like "Received: 0B,11,00,10,02,46,80,00,02,00,00,70" works and has an action on nodered. After the 2nd copyright message, nothing happens when i use the light remote controller

Do you have an idea ?

Regards

Matz

matz33 commented 3 years ago

Any idea Max ? Maybe you need more info from me ?

maxwellhadley commented 3 years ago

Sorry - I've been really busy lately. I intend to try simulating an unsolicited copyright message and seeing what happens (which is one part of the issue).

zonk-git commented 3 years ago

I faced a problem similar to the logs shown above with erratic behaviour with Hass.io on raspberry 4 where I did install both the "rfxtrx integration" + "NodeRed Addon with node-red-contrib-rfxcom component". In my case the issue seems to be related to the fact that both the integration AND the addon want to access /dev/ttyUSB0 in parallel and it seems to confuse something, generating a conflict (Docker ? RfxComm module ? I don't know). This issue is talked about here.

When I unplug the rfxcom module in that situation, it changes its port to /dev/ttyUSB1 when I plug it back and if I try to correct my configuration in NodeRed with /dev/ttyUSB1 it starts working just because the rfxtrx integration is dealing with the old /dev/ttyUSB0. I finally removed the rfxtrx integration from my configuration and now everything is OK with /dev/ttyUSB0 (after rebooting the OS to restore it from /dev/ttyUSB1 to /dev/ttyUSB0).

Perhaps you should check on your system if nothings tries to access /dev/ttyUSB0 in parallel with your NodeRed configuration ?

matz33 commented 3 years ago

@zonk-git I don't think it is related. I have nothing on my system trying to access to /dev/ttyUSB0, and even if it were the case, I don't see why it could conflict with rfxcom node.

matz33 commented 3 years ago

Hi @maxwellhadley ,

I presume you are very busy, but do you think you will have time to check what's hapenning ? How can I help ?

Regards

Matz

maxwellhadley commented 3 years ago

Finally got round to simulating the unsolicited copyright message. It doesn't cause any problems for me. It looks like the problem lies with Docker. When it hangs up, what is the displayed node status?

(sorry this has all taken so long)

Strixx76 commented 3 years ago

I changed to running Node-RED in Docker a couple of days ago, and it work perfectly. This is my compose-file:

version: "2"

services:
  node-red:
    container_name: node-red
    image: nodered/node-red:latest
    volumes:
      - /home/strixx/docker/volumes/node-red:/data
    devices:
      # RFXtrx433E
      - /dev/ttyUSB0:/dev/ttyUSB0
    environment:
      - TZ=Europe/Stockholm
    ports:
      - 1880:1880
    group_add:
      - dialout
    restart: unless-stopped

Edit: Just remembered that I had some serious problems getting my weather station to appear in another container, and had to solve it by running the container with extended privileges. For compose you add privileged: true or with docker run you add --privileged.

And as mentioned above, Home Assistant (https://www.home-assistant.io/) has an Node-RED add-on (https://community.home-assistant.io/t/home-assistant-community-add-on-node-red/55023), and all add-on's is Docker containers. So if this is a Docker issue, I would think you could find some solution in the HA forum.