(Relay) node asks for parent. Gateway forwards (!)
-
Hi!
I have a problem with one of my nodes, a sensor that is counting pulses on my power meter and also acts as relay. The relay functionality works fine from what I can see, but I'm not receiving any data from the power meter.
I don't have the output from the actual node available (it's in the garage..), but I see strange things happening on the gateway. Here's a typical message that reoccurs every 10s:
16-08-07 19:58:04 mysensors.mysensors: n:0 c:255 t:3 s:9 p:TSF:MSG:READ,4-4-255,s=255,c=3,t=7,pt=0,l=0,sg=0: 16-08-07 19:58:04 mysensors.mysensors: n:0 c:255 t:3 s:9 p:TSF:MSG:BC 16-08-07 19:58:04 mysensors.mysensors: n:0 c:255 t:3 s:9 p:TSF:MSG:FPAR REQ,ID=4 16-08-07 19:58:04 mysensors.mysensors: n:0 c:255 t:3 s:9 p:TSF:CHKUPL:OK,FCTRL 16-08-07 19:58:04 mysensors.mysensors: n:0 c:255 t:3 s:9 p:TSF:MSG:GWL OK 16-08-07 19:58:05 mysensors.mysensors: n:0 c:255 t:3 s:9 p:TSF:MSG:SEND,0-0-4-4,s=255,c=3,t=8,pt=1,l=1,sg=0,ft=0,st=OK:0Now, I don't have the whole protocol understanding, and I just switched to 2.0.1-beta1 (directly off git) on the gateway to see if that was the problem, but if I read the above right the node (node id 4) is sending a request to get a parent, but the gateway forwards it instead of replying with a message that it is the parent.
Am I right? What could be the reason of this? Bad routing table in gateway?
Receiving messages from other nodes works w/o problems - even from nodes that pass through this troublesome node.
Gateway is running what's on development branch right now (d054c1c0c87d444c2e34e0e49f5e357e401ee209). The node is running a slightly earlier version.
Thanks!
\EFFor reference, here's my gateway code:
// Enable debug prints to serial monitor #define MY_DEBUG // Enable and select radio type attached #define MY_RADIO_NRF24 // 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_HIGH #define MY_RF24_CHANNEL 42 // Enable serial gateway #define MY_GATEWAY_SERIAL // Flash leds on rx/tx/err // #define MY_LEDS_BLINKING_FEATURE // Set blinking period #define MY_DEFAULT_LED_BLINK_PERIOD 300 // 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 // 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 <SPI.h> #include <MySensors.h> void setup() { // Setup locally attached sensors } void presentation() { // Present locally attached sensors } void loop() { // Send locally attached sensor data here }
-
So, replying to my own post, after looking a bit closer, it does send a reply telling the node that its parent is 0. So I guess the problem is on the other side some way. Hmm.. Need to investigate further.
-
@Erik-Forsberg The GW replies to a I_FIND_PARENT request from node 4 - nothing unusual here. I assume there is a radio/power issue with node 4 - can you get the debug log from that node?
Here is an explanation of the different GW messages
- Node 4 sends I_FIND_PARENT request to broadcast address (=255)
TSF:MSG:READ,4-4-255,s=255,c=3,t=7,pt=0,l=0,sg=0:- GW receives broadcast message
TSF:MSG:BC- BC message is identified as I_FIND_PARENT request from node 4
TSF:MSG:FPAR REQ,ID=4- GW has also repeater functionality, meaning it checks the uplink (in that case to itself). Uplink is ok. FCTRL refers to "flood control", a mechanism that prevents flooding the GW with check uplink requests.
TSF:CHKUPL:OK,FCTRL TSF:MSG:GWL OK- Send I_FIND_PARENT_RESPONSE to node 4
TSF:MSG:SEND,0-0-4-4,s=255,c=3,t=8,pt=1,l=1,sg=0,ft=0,st=OK:0Everything as expected from a GW/repeater perspective
-
@tekka Thankyou! I will need to dig further another day. I will start by upgrading that troublesome node to the latest library version and see if the problem persists.
After enabling signing debug, it's now complaining a lot about the node not signing messages that should really be signed. So there could be some bug hidden in the combination of a node that makes both get and set requests, is a relay, and use soft signing.
I'll report back as soon as I find the time to make these experiments.
-
@Erik-Forsberg ok, certainly a good idea to update all nodes and GW to the most recent version - there are incompatibilities with singing and other features if used in a mixed setup.
-
Hmm.. basically, this node works if signing is disabled. If it's enabled, all the nonce requests fail to transmit (with st=NACK). Disabling signing, it has greater success in transferring its data.
So I guess it's yet another problem with the radio. I suspected this.
This is an NRF24L01+PA+LNA module. I have:
- Tried multiple radio modules to rule out a faulty one.
- Put the radio module on a dedicated 3.3V power regulator.
- Tried both high and low PA level.
- Same thing on gateway - NRF24L01+PA+LNA, on dedicated 3.3V power regulator.
It seems to succeed in most cases, at least when it's sending just a set request. Presentations and others do not work. It's like it's having trouble transmitting longer messages. Odd.
The code in this sketch is using an interrupt handler to count pulsess on my energy meter. Could this be related?
Some debug output from the node, with signing disabled:
MCO:BGN:INIT REPEATER,CP=RNNRA--,VER=2.0.1-beta TSM:INIT TSM:INIT:TSP OK TSF:ASID:OK,ID=4 TSM:FPAR TSF:MSG:SEND,4-4-255-255,s=255,c=3,t=7,pt=0,l=0,sg=0,ft=0,st=bc: TSF:MSG:READ,0-0-4,s=255,c=3,t=8,pt=1,l=1,sg=0:0 TSF:MSG:FPAR RES,ID=0,D=0 TSF:MSG:FPAR OK,ID=0,D=1 TSM:FPAR:OK TSM:ID TSM:ID:OK,ID=4 TSM:UPL TSF:PING:SEND,TO=0 TSF:MSG:SEND,4-4-0-0,s=255,c=3,t=24,pt=1,l=1,sg=0,ft=0,st=OK:1 TSF:MSG:READ,0-0-4,s=255,c=3,t=25,pt=1,l=1,sg=0:1 TSF:MSG:PONG RECV,HP=1 TSF:CHKUPL:OK TSM:UPL:OK TSM:READY TSF:MSG:SEND,4-4-0-0,s=255,c=3,t=15,pt=6,l=2,sg=0,ft=0,st=OK:0100 !TSF:MSG:SEND,4-4-0-0,s=255,c=0,t=18,pt=0,l=10,sg=0,ft=0,st=NACK:2.0.1-beta TSF:MSG:SEND,4-4-0-0,s=255,c=3,t=6,pt=1,l=1,sg=0,ft=1,st=OK:0 TSF:MSG:READ,0-0-4,s=255,c=3,t=15,pt=6,l=2,sg=0:0100 TSF:MSG:READ,0-0-4,s=255,c=3,t=6,pt=0,l=1,sg=0:M !TSF:MSG:SEND,4-4-0-0,s=255,c=3,t=11,pt=0,l=12,sg=0,ft=0,st=NACK:Energy Meter TSF:MSG:SEND,4-4-0-0,s=255,c=3,t=12,pt=0,l=3,sg=0,ft=1,st=OK:1.1 TSF:MSG:SEND,4-4-0-0,s=4,c=0,t=13,pt=0,l=0,sg=0,ft=0,st=OK: MCO:REG:REQ TSF:MSG:SEND,4-4-0-0,s=255,c=3,t=26,pt=1,l=1,sg=0,ft=0,st=OK:2 TSF:MSG:READ,0-0-4,s=255,c=3,t=27,pt=1,l=1,sg=0:1 MCO:PIM:NODE REG=1 setup(). Radio Channel is 42 TSF:MSG:SEND,4-4-0-0,s=4,c=2,t=24,pt=0,l=0,sg=0,ft=0,st=OK: MCO:BGN:INIT OK,ID=4,PAR=0,DIS=1,REG=1 TSF:MSG:READ,0-0-4,s=4,c=1,t=24,pt=0,l=7,sg=0:7418044 Received last pulse count from gw:7418044 TSF:MSG:SEND,4-4-0-0,s=4,c=1,t=17,pt=5,l=4,sg=0,ft=0,st=OK:3169 Watt:3169 !TSF:MSG:SEND,4-4-0-0,s=4,c=1,t=24,pt=5,l=4,sg=0,ft=0,st=NACK:7418088 !TSF:MSG:SEND,4-4-0-0,s=4,c=1,t=18,pt=7,l=5,sg=0,ft=1,st=NACK:741.8089 TSF:MSG:SEND,4-4-0-0,s=4,c=1,t=17,pt=5,l=4,sg=0,ft=2,st=OK:3156 Watt:3156 TSF:MSG:SEND,4-4-0-0,s=4,c=1,t=24,pt=5,l=4,sg=0,ft=0,st=OK:7418132 TSF:MSG:SEND,4-4-0-0,s=4,c=1,t=18,pt=7,l=5,sg=0,ft=0,st=OK:741.8133 TSF:MSG:SEND,4-4-0-0,s=4,c=1,t=17,pt=5,l=4,sg=0,ft=0,st=OK:3169 Watt:3169 TSF:MSG:SEND,4-4-0-0,s=4,c=1,t=24,pt=5,l=4,sg=0,ft=0,st=OK:7418177 TSF:MSG:SEND,4-4-0-0,s=4,c=1,t=18,pt=7,l=5,sg=0,ft=0,st=OK:741.8177 TSF:MSG:SEND,4-4-0-0,s=4,c=1,t=17,pt=5,l=4,sg=0,ft=0,st=OK:7311 Watt:7241 TSF:MSG:SEND,4-4-0-0,s=4,c=1,t=24,pt=5,l=4,sg=0,ft=0,st=OK:7418249 TSF:MSG:SEND,4-4-0-0,s=4,c=1,t=18,pt=7,l=5,sg=0,ft=0,st=OK:741.8249```
