RelayActuator message not going threw

frencho

here we go the gateway log

03/11/2016 21:12:31	INFO	Connected to COM12
03/11/2016 21:12:33	RX	0;255;3;0;9;MCO:BGN:INIT GW,CP=RRNGA--,VER=2.0.1-beta
03/11/2016 21:12:33	RX	0;255;3;0;9;TSM:INIT
03/11/2016 21:12:33	RX	0;255;3;0;9;TSM:INIT:TSP OK
03/11/2016 21:12:33	RX	0;255;3;0;9;TSM:INIT:GW MODE
03/11/2016 21:12:33	RX	0;255;3;0;9;TSM:READY
03/11/2016 21:12:33	RX	0;255;3;0;14;Gateway startup complete.
03/11/2016 21:12:33	DEBUG	Update child id=255, type=ARDUINO_RELAY
03/11/2016 21:12:33	RX	0;255;0;0;18;2.0.1-beta
03/11/2016 21:12:33	RX	0;255;3;0;9;MCO:REG:NOT NEEDED
03/11/2016 21:12:33	RX	0;255;3;0;9;MCO:BGN:STP
03/11/2016 21:12:33	RX	0;255;3;0;9;MCO:BGN:INIT OK,ID=0,PAR=0,DIS=0,REG=1
03/11/2016 21:12:48	RX	0;255;3;0;9;TSF:MSG:READ,65-65-255,s=255,c=3,t=7,pt=0,l=0,sg=0:
03/11/2016 21:12:48	RX	0;255;3;0;9;TSF:MSG:BC
03/11/2016 21:12:48	RX	0;255;3;0;9;TSF:MSG:FPAR REQ,ID=65
03/11/2016 21:12:48	RX	0;255;3;0;9;TSF:PNG:SEND,TO=0
03/11/2016 21:12:48	RX	0;255;3;0;9;TSF:CKU:OK
03/11/2016 21:12:48	RX	0;255;3;0;9;TSF:MSG:GWL OK
03/11/2016 21:12:49	RX	0;255;3;0;9;TSF:MSG:SEND,0-0-65-65,s=255,c=3,t=8,pt=1,l=1,sg=0,ft=0,st=OK:0
03/11/2016 21:12:50	RX	0;255;3;0;9;TSF:MSG:READ,65-65-0,s=255,c=3,t=24,pt=1,l=1,sg=0:1
03/11/2016 21:12:50	RX	0;255;3;0;9;TSF:MSG:PINGED,ID=65,HP=1
03/11/2016 21:12:50	RX	0;255;3;0;9;TSF:MSG:SEND,0-0-65-65,s=255,c=3,t=25,pt=1,l=1,sg=0,ft=0,st=OK:1
03/11/2016 21:12:50	RX	0;255;3;0;9;TSF:MSG:READ,65-65-0,s=255,c=3,t=15,pt=6,l=2,sg=0:0100
03/11/2016 21:12:50	RX	0;255;3;0;9;!TSF:MSG:SEND,0-0-65-65,s=255,c=3,t=15,pt=6,l=2,sg=0,ft=0,st=NACK:0100
03/11/2016 21:12:50	RX	0;255;3;0;9;MCO:BGN:INIT GW,CP=RRNGA--,VER=2.0.1-beta
03/11/2016 21:12:50	RX	0;255;3;0;9;TSM:INIT
03/11/2016 21:12:50	RX	0;255;3;0;9;TSM:INIT:TSP OK
03/11/2016 21:12:50	RX	0;255;3;0;9;TSM:INIT:GW MODE
03/11/2016 21:12:50	RX	0;255;3;0;9;TSM:READY
03/11/2016 21:12:50	RX	0;255;3;0;14;Gateway startup complete.
03/11/2016 21:12:50	DEBUG	Update child id=255, type=ARDUINO_RELAY
03/11/2016 21:12:50	RX	0;255;0;0;18;2.0.1-beta
03/11/2016 21:12:50	RX	0;255;3;0;9;MCO:REG:NOT NEEDED
03/11/2016 21:12:50	RX	0;255;3;0;9;MCO:BGN:STP
03/11/2016 21:12:51	RX	0;255;3;0;9;MCO:BGN:INIT OK,ID=0,PAR=0,DIS=0,REG=1
03/11/2016 21:12:51	RX	0;255;3;0;9;TSF:MSG:READ,65-65-0,s=255,c=3,t=6,pt=1,l=1,sg=0:0
03/11/2016 21:12:51	TX	65;255;3;0;6;M
03/11/2016 21:12:51	RX	65;255;3;0;6;0
03/11/2016 21:12:52	RX	0;255;3;0;9;TSF:MSG:READ,65-65-0,s=255,c=3,t=11,pt=0,l=5,sg=0:Relay
03/11/2016 21:12:52	RX	65;255;3;0;11;Relay
03/11/2016 21:12:52	RX	0;255;3;0;9;TSF:MSG:READ,65-65-0,s=255,c=3,t=12,pt=0,l=3,sg=0:1.0
03/11/2016 21:12:52	RX	65;255;3;0;12;1.0
03/11/2016 21:12:52	RX	0;255;3;0;9;TSF:MSG:READ,65-65-0,s=1,c=0,t=3,pt=0,l=0,sg=0:
03/11/2016 21:12:52	DEBUG	Update child id=1, type=LIGHT
03/11/2016 21:12:52	RX	65;1;0;0;3;
03/11/2016 21:12:53	RX	0;255;3;0;9;TSF:MSG:READ,65-65-0,s=2,c=0,t=3,pt=0,l=0,sg=0:
03/11/2016 21:12:53	DEBUG	Update child id=2, type=LIGHT
03/11/2016 21:12:53	RX	65;2;0;0;3;
03/11/2016 21:12:53	RX	0;255;3;0;9;TSF:MSG:READ,65-65-0,s=3,c=0,t=3,pt=0,l=0,sg=0:
03/11/2016 21:12:53	DEBUG	Update child id=3, type=LIGHT
03/11/2016 21:12:53	RX	65;3;0;0;3;
03/11/2016 21:12:53	RX	0;255;3;0;9;TSF:MSG:READ,65-65-0,s=4,c=0,t=3,pt=0,l=0,sg=0:
03/11/2016 21:12:53	DEBUG	Update child id=4, type=LIGHT
03/11/2016 21:12:53	RX	65;4;0;0;3;
03/11/2016 21:12:53	RX	0;255;3;0;9;TSF:MSG:READ,65-65-0,s=255,c=3,t=26,pt=1,l=1,sg=0:2
03/11/2016 21:12:53	RX	0;255;3;0;9;TSF:MSG:SEND,0-0-65-65,s=255,c=3,t=27,pt=1,l=1,sg=0,ft=0,st=OK:1
03/11/2016 21:13:02	TX	65;4;1;1;2;0
03/11/2016 21:13:47	TX	65;3;1;1;2;0
03/11/2016 21:13:52	TX	65;2;1;1;2;0
03/11/2016 21:13:56	TX	65;1;1;1;2;0

If you need anything else ....

I was actually hoping it would be some set up I would have forgotten or some like that !

tekka

@frencho Looks like the GW does not receive your message (debug output missing after sending). Describe your GW HW (type, connection, speed) & upload the GW sketch.

frencho

@tekka thanks for the analysis !

I have tryied two different GW : one was with gertsanders arduino module, one with a arduino pro mini 3.3V/8Mhz ATM328
they are connected with FTDI to the computer / domotic box
the speed is set to 115200 baud

here is the GW sketch

// Enable debug prints to serial monitor
#define MY_DEBUG


// Enable and select radio type attached
//#define MY_RADIO_NRF24
#define MY_RADIO_RFM69

// Set LOW transmit power level as default, if you have an amplified NRF-module and
// power your radio separately with a good regulator you can turn up PA level.
#define MY_RF24_PA_LEVEL RF24_PA_LOW

// Enable serial gateway
#define MY_GATEWAY_SERIAL



// Enable inclusion mode
#define MY_INCLUSION_MODE_FEATURE
// Enable Inclusion mode button on gateway
#define MY_INCLUSION_BUTTON_FEATURE

// Inverses behavior of inclusion button (if using external pullup)
//#define MY_INCLUSION_BUTTON_EXTERNAL_PULLUP

// Set inclusion mode duration (in seconds)
#define MY_INCLUSION_MODE_DURATION 60
// Digital pin used for inclusion mode button
//#define MY_INCLUSION_MODE_BUTTON_PIN  3

// Set blinking period
#define MY_DEFAULT_LED_BLINK_PERIOD 300

// Inverses the behavior of leds
//#define MY_WITH_LEDS_BLINKING_INVERSE

// Flash leds on rx/tx/err
// Uncomment to override default HW configurations
//#define MY_DEFAULT_ERR_LED_PIN 4  // Error led pin
//#define MY_DEFAULT_RX_LED_PIN  6  // Receive led pin
//#define MY_DEFAULT_TX_LED_PIN  5  // the PCB, on board LED

#include <MySensors.h>

void setup() {
 // Setup locally attached sensors
}

void presentation() {
// Present locally attached sensors
}

void loop() {
 // Send locally attached sensor data here
}

tekka

@frencho Hmm, sketch looks fine - what surprises me are the two GW init messages:

03/11/2016 21:12:33 RX  0;255;3;0;9;MCO:BGN:INIT GW,CP=RRNGA--,VER=2.0.1-beta
03/11/2016 21:12:33 RX  0;255;3;0;9;TSM:INIT
03/11/2016 21:12:33 RX  0;255;3;0;9;TSM:INIT:TSP OK
03/11/2016 21:12:33 RX  0;255;3;0;9;TSM:INIT:GW MODE
03/11/2016 21:12:33 RX  0;255;3;0;9;TSM:READY
03/11/2016 21:12:33 RX  0;255;3;0;14;Gateway startup complete.
...
03/11/2016 21:12:50 RX  0;255;3;0;9;!TSF:MSG:SEND,0-0-65-65,s=255,c=3,t=15,pt=6,l=2,sg=0,ft=0,st=NACK:0100
03/11/2016 21:12:50 RX  0;255;3;0;9;MCO:BGN:INIT GW,CP=RRNGA--,VER=2.0.1-beta
03/11/2016 21:12:50 RX  0;255;3;0;9;TSM:INIT
03/11/2016 21:12:50 RX  0;255;3;0;9;TSM:INIT:TSP OK
03/11/2016 21:12:50 RX  0;255;3;0;9;TSM:INIT:GW MODE
03/11/2016 21:12:50 RX  0;255;3;0;9;TSM:READY
03/11/2016 21:12:50 RX  0;255;3;0;14;Gateway startup complete.
...

You should try with a different FTDI adapter or power your GW with a good power supply.

frencho

@tekka thanks again. Which two init message are unusual ?

I just tried an other FDTI adapter nothing changed.
The gateway is power via the FDTI/USB !! this thing is driving me crazy !

I'll try also tonight to power GW with 2 AA bat, and read Serial only with the FDTI

I think I'm going to buy a moteino, I hope it will solve my problems.

tekka

@frencho

These two, of particular interest is the second init message...

...
03/11/2016 21:12:33 RX  0;255;3;0;9;MCO:BGN:INIT GW,CP=RRNGA--,VER=2.0.1-beta
...
03/11/2016 21:12:50 RX  0;255;3;0;9;MCO:BGN:INIT GW,CP=RRNGA--,VER=2.0.1-beta
...

...as it appears right after


03/11/2016 21:12:50 RX  0;255;3;0;9;!TSF:MSG:SEND,0-0-65-65,s=255,c=3,t=15,pt=6,l=2,sg=0,ft=0,st=NACK:0100

What Arduino IDE version and AVR board def version are you using?

frencho

@tekka arduino 1.6.11 and AVRISP mkII

It looks like the Tx serial from PC to GW is not working ! when I send a command, I see the Tx from FDTI blinking, ...

I posted other msg on the forum previously, beacause I can't get ride of the fail debug below

03/11/2016 21:12:50 RX  0;255;3;0;9;!TSF:MSG:SEND,0-0-65-65,s=255,c=3,t=15,pt=6,l=2,sg=0,ft=0,st=NACK:0100

I'll try today to program the gateway from my Mac

tekka · @tekka arduino 1.6.11 and AVRISP mkII

@frencho regarding the NACK: this has been addressed here: https://github.com/mysensors/MySensors/pull/630

frencho

@tekka I recompiled everything with the latest Dev Branch, the init problem of the GW is solved.

On GW Side :

06/11/2016 14:56:51	INFO	Connected to COM10
06/11/2016 14:56:52	RX	0;255;3;0;9;MCO:BGN:INIT GW,CP=RRNGA--,VER=2.0.1-beta
06/11/2016 14:56:52	RX	0;255;3;0;9;TSM:INIT
06/11/2016 14:56:52	RX	0;255;3;0;9;TSM:INIT:TSP OK
06/11/2016 14:56:52	RX	0;255;3;0;9;TSM:INIT:GW MODE
06/11/2016 14:56:52	RX	0;255;3;0;9;TSM:READY
06/11/2016 14:56:52	RX	0;255;3;0;14;Gateway startup complete.
06/11/2016 14:56:52	DEBUG	Update child id=255, type=ARDUINO_RELAY
06/11/2016 14:56:52	RX	0;255;0;0;18;2.0.1-beta
06/11/2016 14:56:52	RX	0;255;3;0;9;MCO:REG:NOT NEEDED
06/11/2016 14:56:53	RX	0;255;3;0;9;MCO:BGN:STP
06/11/2016 14:56:53	RX	0;255;3;0;9;MCO:BGN:INIT OK,ID=0,PAR=0,DIS=0,REG=1
06/11/2016 14:57:25	RX	0;255;3;0;9;TSF:MSG:READ,65-65-255,s=255,c=3,t=7,pt=0,l=0,sg=0:
06/11/2016 14:57:25	RX	0;255;3;0;9;TSF:MSG:BC
06/11/2016 14:57:25	RX	0;255;3;0;9;TSF:MSG:FPAR REQ,ID=65
06/11/2016 14:57:25	RX	0;255;3;0;9;TSF:PNG:SEND,TO=0
06/11/2016 14:57:25	RX	0;255;3;0;9;TSF:CKU:OK
06/11/2016 14:57:25	RX	0;255;3;0;9;TSF:MSG:GWL OK
06/11/2016 14:57:25	RX	0;255;3;0;9;TSF:MSG:SEND,0-0-65-65,s=255,c=3,t=8,pt=1,l=1,sg=0,ft=0,st=OK:0
06/11/2016 14:57:27	RX	0;255;3;0;9;TSF:MSG:READ,65-65-0,s=255,c=3,t=24,pt=1,l=1,sg=0:1
06/11/2016 14:57:27	RX	0;255;3;0;9;TSF:MSG:PINGED,ID=65,HP=1
06/11/2016 14:57:27	RX	0;255;3;0;9;TSF:MSG:SEND,0-0-65-65,s=255,c=3,t=25,pt=1,l=1,sg=0,ft=0,st=OK:1
06/11/2016 14:57:27	RX	0;255;3;0;9;TSF:MSG:READ,65-65-0,s=255,c=3,t=15,pt=6,l=2,sg=0:0100
06/11/2016 14:57:27	RX	0;255;3;0;9;TSF:MSG:SEND,0-0-65-65,s=255,c=3,t=15,pt=6,l=2,sg=0,ft=0,st=OK:0100
06/11/2016 14:57:27	RX	0;255;3;0;9;TSF:MSG:READ,65-65-0,s=255,c=0,t=18,pt=0,l=10,sg=0:2.0.1-beta
06/11/2016 14:57:27	NODE	New node discovered, node id=65
06/11/2016 14:57:27	CHILD	New child discovered, node id=65, child id=internal
06/11/2016 14:57:27	DEBUG	Update child id=255, type=ARDUINO_RELAY
06/11/2016 14:57:27	RX	65;255;0;0;18;2.0.1-beta
06/11/2016 14:57:27	RX	0;255;3;0;9;TSF:MSG:READ,65-65-0,s=255,c=3,t=6,pt=1,l=1,sg=0:0
06/11/2016 14:57:27	TX	65;255;3;0;6;M
06/11/2016 14:57:27	RX	65;255;3;0;6;0
06/11/2016 14:57:29	RX	0;255;3;0;9;TSF:MSG:READ,65-65-0,s=255,c=3,t=11,pt=0,l=5,sg=0:Relay
06/11/2016 14:57:29	RX	65;255;3;0;11;Relay
06/11/2016 14:57:29	RX	0;255;3;0;9;TSF:MSG:READ,65-65-0,s=255,c=3,t=12,pt=0,l=3,sg=0:1.0
06/11/2016 14:57:29	RX	65;255;3;0;12;1.0
06/11/2016 14:57:29	RX	0;255;3;0;9;TSF:MSG:READ,65-65-0,s=1,c=0,t=3,pt=0,l=0,sg=0:
06/11/2016 14:57:29	CHILD	New child discovered, node id=65, child id=1
06/11/2016 14:57:29	DEBUG	Update child id=1, type=LIGHT
06/11/2016 14:57:29	RX	65;1;0;0;3;
06/11/2016 14:57:29	RX	0;255;3;0;9;TSF:MSG:READ,65-65-0,s=2,c=0,t=3,pt=0,l=0,sg=0:
06/11/2016 14:57:29	CHILD	New child discovered, node id=65, child id=2
06/11/2016 14:57:29	DEBUG	Update child id=2, type=LIGHT
06/11/2016 14:57:29	RX	65;2;0;0;3;
06/11/2016 14:57:30	RX	0;255;3;0;9;TSF:MSG:READ,65-65-0,s=3,c=0,t=3,pt=0,l=0,sg=0:
06/11/2016 14:57:30	CHILD	New child discovered, node id=65, child id=3
06/11/2016 14:57:30	DEBUG	Update child id=3, type=LIGHT
06/11/2016 14:57:30	RX	65;3;0;0;3;
06/11/2016 14:57:30	RX	0;255;3;0;9;TSF:MSG:READ,65-65-0,s=4,c=0,t=3,pt=0,l=0,sg=0:
06/11/2016 14:57:30	CHILD	New child discovered, node id=65, child id=4
06/11/2016 14:57:30	DEBUG	Update child id=4, type=LIGHT
06/11/2016 14:57:30	RX	65;4;0;0;3;
06/11/2016 14:57:30	RX	0;255;3;0;9;TSF:MSG:READ,65-65-0,s=255,c=3,t=26,pt=1,l=1,sg=0:2
06/11/2016 14:57:30	RX	0;255;3;0;9;TSF:MSG:SEND,0-0-65-65,s=255,c=3,t=27,pt=1,l=1,sg=0,ft=0,st=OK:1
06/11/2016 14:59:38	TX	65;1;1;0;2;
06/11/2016 14:59:43	TX	65;1;1;0;2;1
06/11/2016 14:59:48	TX	65;1;1;1;2;1

on node side :

0 MCO:BGN:INIT REPEATER,CP=RRNRA--,VER=2.0.1-beta
4 MCO:BGN:BFR
6 TSM:INIT
8 TSM:INIT:TSP OK
10 TSF:SID:OK,ID=65
12 TSM:FPAR
145 TSF:MSG:SEND,65-65-255-255,s=255,c=3,t=7,pt=0,l=0,sg=0,ft=0,st=OK:
493 TSF:MSG:READ,0-0-65,s=255,c=3,t=8,pt=1,l=1,sg=0:0
497 TSF:MSG:FPAR OK,ID=0,D=1
2152 TSM:FPAR:OK
2152 TSM:ID
2154 TSM:ID:OK
2156 TSM:UPL
2164 TSF:MSG:SEND,65-65-0-0,s=255,c=3,t=24,pt=1,l=1,sg=0,ft=0,st=OK:1
2183 TSF:MSG:READ,0-0-65,s=255,c=3,t=25,pt=1,l=1,sg=0:1
2189 TSF:MSG:PONG RECV,HP=1
2191 TSM:UPL:OK
2193 TSM:READY
2203 TSF:MSG:SEND,65-65-0-0,s=255,c=3,t=15,pt=6,l=2,sg=0,ft=0,st=OK:0100
2326 TSF:MSG:READ,0-0-65,s=255,c=3,t=15,pt=6,l=2,sg=0:0100
2385 TSF:MSG:SEND,65-65-0-0,s=255,c=0,t=18,pt=0,l=10,sg=0,ft=0,st=OK:2.0.1-beta
2402 TSF:MSG:SEND,65-65-0-0,s=255,c=3,t=6,pt=1,l=1,sg=0,ft=0,st=OK:0
4419 TSF:MSG:SEND,65-65-0-0,s=255,c=3,t=11,pt=0,l=5,sg=0,ft=0,st=OK:Relay
4433 TSF:MSG:SEND,65-65-0-0,s=255,c=3,t=12,pt=0,l=3,sg=0,ft=0,st=OK:1.0
4450 TSF:MSG:SEND,65-65-0-0,s=1,c=0,t=3,pt=0,l=0,sg=0,ft=0,st=OK:
4464 TSF:MSG:SEND,65-65-0-0,s=2,c=0,t=3,pt=0,l=0,sg=0,ft=0,st=OK:
4481 TSF:MSG:SEND,65-65-0-0,s=3,c=0,t=3,pt=0,l=0,sg=0,ft=0,st=OK:
4495 TSF:MSG:SEND,65-65-0-0,s=4,c=0,t=3,pt=0,l=0,sg=0,ft=0,st=OK:
4501 MCO:REG:REQ
4511 TSF:MSG:SEND,65-65-0-0,s=255,c=3,t=26,pt=1,l=1,sg=0,ft=0,st=OK:2
4569 TSF:MSG:READ,0-0-65,s=255,c=3,t=27,pt=1,l=1,sg=0:1
4575 MCO:PIM:NODE REG=1
4579 MCO:BGN:STP
4581 MCO:BGN:INIT OK,ID=65,PAR=0,DIS=1,REG=1

The other problem is still here, nothing happen when I try to change state of relay.
I tryed to send the the only Tx message sent during communication between GW and Node

06/11/2016 14:57:27	TX	65;255;3;0;6;M

and nothing

I also noticed every now and then that the Node is forwarding some broadcast message from GW :

477822 TSF:MSG:READ,0-0-255,s=255,c=3,t=20,pt=0,l=0,sg=0:
477831 TSF:MSG:BC
478488 TSF:MSG:SEND,65-65-0-0,s=255,c=3,t=21,pt=1,l=1,sg=0,ft=0,st=OK:0
478496 TSF:MSG:FWD BC MSG
478629 TSF:MSG:SEND,0-65-255-255,s=255,c=3,t=20,pt=0,l=0,sg=0,ft=0,st=OK:

It's got to be a problem bewteen PC/Rasp and GW ... maybe my FDTI ... but I have 2 different !

frencho

@tekka I have tried the FDTI with a dummy sketch. I confirm that the RX/TX is working as I change the value of a variable via serial port.

Multiple speed have been tested, from 9600 to 115200.

Looking at the failure tree, I see no other branch to cut down !
Serial com is working
the GW and node seems fine (regarding log)

So why the GW doesn't react when it gets serial messages ?

tekka

@frencho Hmm, something seems to disturb the serial traffic. What happens if you use the Arduino serial monitor (change line ending to NR & CR) and enter:

65;0;3;0;13;0

(this is a reboot command)

Also, what version of MYSController are you on?

frencho

@tekka tried what you asked, and some more stuff, still nothing happening

the reboot command send doesn't do anything, the MYSController version is 0.1.2.282

frencho

@tekka could it come from something i setup wrong in the Myconfig.h ?

tekka

@frencho Depends, what did you change in MyConfig.h? Also, try using the latest version of MYSController (1.0.0beta, >=3314)

frenchclem

@tekka unbelievable !!! I tried with NRF24 and arduino nano, it's working like a charm !!!
If I use the same sketch, on a pro mini using one of my ftdi as serial interface the Tx don't go threw anymore !!!

Ftdi use a 1047 chip
Arduino nano use a CH340 for which I had to install a Chinese driver for it !?!? !!!!

RelayActuator message not going threw

18

11.7k

11.2k

113.1k