rfxcom / node-rfxcom

Node.js client for talking to an RFXtrx433 device
MIT License
61 stars 45 forks source link

Cannot receive data after cold boot #103

Closed av01d closed 5 months ago

av01d commented 3 years ago

I am experiencing a weird problem. I'm running node on a Raspberry Pi 3B and use node-rfxcom to control my blinds and read data from temperature/humidity sensors and, some cheap motion sensors, a few 433MHz remotes etc. It all works beautifully. When I start my test-script after a cold boot, it can send messages just fine, but I don't receive anything at all. The test script is very simple:

const rfxcom = require('rfxcom');
const rfxtrx = new rfxcom.RfxCom("/dev/ttyUSB-RFX433", {debug: true});
rfxtrx.on("temperaturehumidity1", function(e) {
   console.log('-> temperaturehumidity1', e);
});
rfxtrx.on("lighting4", function (e) {
   console.log('-> lighting4', e);
});

Running this script does not show any incoming messages. However, if I run the old rfxcmd script (python rfxcmd.py -l -o /opt/rfxcmd/config.xml) in another terminal window, the test script starts receiving messages.

The rfxcmd.py script only needs to run for a very short time, after it has ran, node-rfxcom works fine until I reboot.

Is there some kind of initialization sequence I need to do before I can listen to incoming messages? What am I missing?

maxwellhadley commented 3 years ago

You need to call rfxtrx.initialise() to start the receiver properly - are you doing that?

av01d commented 3 years ago

Yes, I am:

const rfxcom = require('rfxcom');
const rfxtrx = new rfxcom.RfxCom("/dev/ttyUSB-RFX433", {debug: true});

rfxtrx.initialise(function() {

   rfxtrx.on("temperaturehumidity1", function(e) {
      console.log('-> temperaturehumidity1', e);
   });

   rfxtrx.on("lighting4", function (e) {
      console.log('-> lighting4', e);
   });

});

(Apologies for not including that part in my original message).

I also tried running this test script as root: no difference.

av01d commented 3 years ago

Here's the output of the test script:

2021-03-12 18:25:13.528 [rfxcom] on /dev/ttyUSB-RFX433 - Sent    : 0D,00,00,00,00,00,00,00,00,00,00,00,00,00
2021-03-12 18:25:14.045 [rfxcom] on /dev/ttyUSB-RFX433 - Sent    : 0D,00,00,01,02,00,00,00,00,00,00,00,00,00
2021-03-12 18:25:14.069 [rfxcom] on /dev/ttyUSB-RFX433 - Received: 14,01,00,01,02,53,0D,00,00,27,00,01,03,1C,05,61,46,58,43,4F,4D
2021-03-12 18:25:14.079 [rfxcom] on /dev/ttyUSB-RFX433 - Sent    : 0D,00,00,02,07,00,00,00,00,00,00,00,00,00
2021-03-12 18:25:14.224 [rfxcom] on /dev/ttyUSB-RFX433 - Received: 14,01,07,02,07,43,6F,70,79,72,69,67,68,74,20,52,46,58,43,4F,4D
2021-03-12 18:25:14.225 [rfxcom] on /dev/ttyUSB-RFX433 - Copyright RFXCOM
2021-03-12 18:25:14.228 [rfxcom] on /dev/ttyUSB-RFX433 - Started command message queue

// Here, I start the rfxcmd python script

2021-03-12 18:26:22.001 [rfxcom] on /dev/ttyUSB-RFX433 - Received: 14,01,00,00,02,53,0D,00,00,27,00,01,03,1C,05,62,46,58,43,4F,4D
2021-03-12 18:26:22.005 [rfxcom] on /dev/ttyUSB-RFX433 - Sent    : 0D,00,00,03,07,00,00,00,00,00,00,00,00,00
2021-03-12 18:26:22.160 [rfxcom] on /dev/ttyUSB-RFX433 - Received: 14,01,07,03,07,43,6F,70,79,72,69,67,68,74,20,52,46,58,43,4F,4D
2021-03-12 18:26:22.161 [rfxcom] on /dev/ttyUSB-RFX433 - Copyright RFXCOM
2021-03-12 18:26:23.274 [rfxcom] on /dev/ttyUSB-RFX433 - Received: 14,01,00,00,03,53,0D,08,04,06,00,01,03,00,05,62,46,58,43,4F,4D
2021-03-12 18:26:23.278 [rfxcom] on /dev/ttyUSB-RFX433 - Sent    : 0D,00,00,04,07,00,00,00,00,00,00,00,00,00
2021-03-12 18:26:23.424 [rfxcom] on /dev/ttyUSB-RFX433 - Received: 14,01,07,04,07,43,6F,70,79,72,69,67,68,74,20,52,46,58,43,4F,4D
2021-03-12 18:26:23.425 [rfxcom] on /dev/ttyUSB-RFX433 - Copyright RFXCOM
2021-03-12 18:26:23.567 [rfxcom] on /dev/ttyUSB-RFX433 - Received: 0A,52,07,00,67,0E,00,D7,27,02,79
-> temperaturehumidity1 {
  subtype: 7,
  id: '0x670E',
  seqnbr: 0,
  temperature: 21.5,
  humidity: 39,
  humidityStatus: 2,
  batteryLevel: 9,
  rssi: 7
}
....
maxwellhadley commented 3 years ago

Please can you try starting from a cold boot, starting your NodeJS application, and sending a command to the blinds. I'd like to see what the debug output looks like for that. I'm also puzzled because it sounds like both your NodeJS application and the Python script are able to open the same serial port at the same time - is that right?

av01d commented 3 years ago

Here you go. Test script:

const rfxcom = require('rfxcom');
const rfxtrx = new rfxcom.RfxCom("/dev/ttyUSB-RFX433", {debug: true});

rfxtrx.initialise(function() {
   console.log('rfxtrx initialised');
   rfxtrx.on("temperaturehumidity1", function(e) {
      console.log('Received temperaturehumidity1 message', e);
   });

   rfxtrx.on("lighting4", function (e) {
      console.log('Received lighting4 message', e);
   });

   var rfy = new rfxcom.Rfy(rfxtrx, rfxcom.rfy.RFY, {venetianBlindsMode: "EU"});

   console.log("Sending 'blinds down' signal");
   rfy.down(["0x10234", "1"])

   setTimeout(function() {
      console.log("Sending 'blinds up' signal");
      rfy.up(["0x10234", "1"])
   }, 5000);
});

Output:

2021-03-16 10:27:30.723 [rfxcom] on /dev/ttyUSB-RFX433 - Sent    : 0D,00,00,00,00,00,00,00,00,00,00,00,00,00
2021-03-16 10:27:31.240 [rfxcom] on /dev/ttyUSB-RFX433 - Sent    : 0D,00,00,01,02,00,00,00,00,00,00,00,00,00
2021-03-16 10:27:31.263 [rfxcom] on /dev/ttyUSB-RFX433 - Received: 14,01,00,01,02,53,0D,00,00,27,00,01,03,1C,05,66,46,58,43,4F,4D
2021-03-16 10:27:31.272 [rfxcom] on /dev/ttyUSB-RFX433 - Sent    : 0D,00,00,02,07,00,00,00,00,00,00,00,00,00
2021-03-16 10:27:31.416 [rfxcom] on /dev/ttyUSB-RFX433 - Received: 14,01,07,02,07,43,6F,70,79,72,69,67,68,74,20,52,46,58,43,4F,4D
2021-03-16 10:27:31.418 [rfxcom] on /dev/ttyUSB-RFX433 - Copyright RFXCOM
2021-03-16 10:27:31.420 [rfxcom] on /dev/ttyUSB-RFX433 - Started command message queue
rfxtrx initialised
Sending 'blinds down' signal
2021-03-16 10:27:31.427 [rfxcom] on /dev/ttyUSB-RFX433 - Queued  : 0C,1A,00,03,01,02,34,01,03,00,00,00,00
2021-03-16 10:27:31.432 [rfxcom] on /dev/ttyUSB-RFX433 - Sent    : 0C,1A,00,03,01,02,34,01,03,00,00,00,00
2021-03-16 10:27:32.009 [rfxcom] on /dev/ttyUSB-RFX433 - Received: 04,02,01,03,00
2021-03-16 10:27:32.013 [rfxcom] on /dev/ttyUSB-RFX433 - Response: Command message 03, ACK - transmit OK
Sending 'blinds up' signal
2021-03-16 10:27:36.434 [rfxcom] on /dev/ttyUSB-RFX433 - Queued  : 0C,1A,00,04,01,02,34,01,01,00,00,00,00
2021-03-16 10:27:36.438 [rfxcom] on /dev/ttyUSB-RFX433 - Sent    : 0C,1A,00,04,01,02,34,01,01,00,00,00,00
2021-03-16 10:27:37.010 [rfxcom] on /dev/ttyUSB-RFX433 - Received: 04,02,01,04,00
2021-03-16 10:27:37.011 [rfxcom] on /dev/ttyUSB-RFX433 - Response: Command message 04, ACK - transmit OK

// Here, I start the rfxcmd python script

2021-03-16 10:27:59.415 [rfxcom] on /dev/ttyUSB-RFX433 - Received: 14,01,00,00,02,53,0D,00,00,27,00,01,03,1C,05,65,46,58,43,4F,4D
2021-03-16 10:27:59.419 [rfxcom] on /dev/ttyUSB-RFX433 - Sent    : 0D,00,00,05,07,00,00,00,00,00,00,00,00,00
2021-03-16 10:27:59.574 [rfxcom] on /dev/ttyUSB-RFX433 - Received: 14,01,07,05,07,43,6F,70,79,72,69,67,68,74,20,52,46,58,43,4F,4D
2021-03-16 10:27:59.575 [rfxcom] on /dev/ttyUSB-RFX433 - Copyright RFXCOM
2021-03-16 10:28:00.687 [rfxcom] on /dev/ttyUSB-RFX433 - Received: 14,01,00,00,03,53,0D,08,04,06,00,01,03,00,05,66,46,58,43,4F,4D
2021-03-16 10:28:00.690 [rfxcom] on /dev/ttyUSB-RFX433 - Sent    : 0D,00,00,06,07,00,00,00,00,00,00,00,00,00
2021-03-16 10:28:00.887 [rfxcom] on /dev/ttyUSB-RFX433 - Received: 0A,52,07,00,50,0E,00,47,4D,03,79
Received temperaturehumidity1 message {
  subtype: 7,
  id: '0x500E',
  seqnbr: 0,
  temperature: 7.1,
  humidity: 77,
  humidityStatus: 3,
  batteryLevel: 9,
  rssi: 7
}
2021-03-16 10:28:00.916 [rfxcom] on /dev/ttyUSB-RFX433 - Received: 14,01,07,06,07,43,6F,70,79,72,69,67,68,74,20,52,46,58,43,4F,4D
2021-03-16 10:28:00.917 [rfxcom] on /dev/ttyUSB-RFX433 - Copyright RFXCOM

(please note that my blinds do go up and down as a result of this script)

Your remark on opening the same serial port: I'm not sure what is happening when I run rfxcmd.py, but indeed it seems you could be correct.

av01d commented 3 years ago

Any update on this? I could give you ssh access to the RaspPi if that helps?

maxwellhadley commented 9 months ago

Did this ever get sorted? I have been unable to reproduce the symptoms you saw.

av01d commented 9 months ago

I still use the workaround.... which works for me. I'll close this issue, as I don't have time to properly test this. Thanks!

maxwellhadley commented 9 months ago

One odd thing that strikes me is you are adding the event handlers in the initialise callback. I don't see why that wouldn't work, but I generally install the handlers first, before the call to initialise()

av01d commented 5 months ago

Today I tested whether the problem at hand still exists. It does not (yay!), after a cold boot, everything works without issues. I also moved the event handlers out of the initialise callback (which works), but attaching them inside the initialise callback works just as well. I don't know why my problem seems to have disappeared (maybe an npm update or an apt-get uprade?), but it has and I'm glad it did. Case closed, thanks for your help!