Yet another fight against my RFM69

[user2684]

There must be something I constantly do wrong since looks like I'm one of the few dealing always with similar issues
I have a sleeping sensor waking up every minute and wait some commands from the controller. It used to work ok but at a certain point it stopped executing my orders. I could see it reporting awake and sleeping but no more activating the attached relay as instructed. I initially thought was due to the distance so I took it close the gw and the issue was still there. I had a look at the logs and there were a lot of re-transmission and during those my remote command was lost (which makes sense). For completeness, I'm testing the new RFM69 driver with the latest patch @tekka put together but I don't think this is related. Here are the logs:

0 MCO:BGN:INIT NODE,CP=RPNNA---,VER=2.2.0-beta
49 MCO:BGN:BFR
REG I=1 P=6 P=3 T=2
REG I=2 P=7 P=3 T=2
NodeManager v1.5-dev5
INT1 M=255
INT2 M=255
458 TSM:INIT
475 TSF:WUR:MS=0
491 RFM69:INIT
507 RFM69:INIT:PIN,CS=10,IQP=2,IQN=0
557 RFM69:PTX:LEVEL=20 dBm
589 TSM:INIT:TSP OK
622 TSM:INIT:STATID=6
638 TSF:SID:OK,ID=6
655 TSM:FPAR
671 RFM69:SWR:SEND,TO=255,RETRY=0
720 TSF:MSG:SEND,6-6-255-255,s=255,c=3,t=7,pt=0,l=0,sg=0,ft=0,st=OK:
1474 RFM69:SAC:SEND ACK,TO=0,RSSI=-35
1523 TSF:MSG:READ,0-0-6,s=255,c=3,t=8,pt=1,l=1,sg=0:0
1589 TSF:MSG:FPAR OK,ID=0,D=1
2818 TSM:FPAR:OK
2834 TSM:ID
2850 TSM:ID:OK
2867 TSM:UPL
2883 RFM69:SWR:SEND,TO=0,RETRY=0
4145 !RFM69:SWR:NACK
4161 RFM69:SWR:SEND,TO=0,RETRY=1
4423 !RFM69:SWR:NACK
4440 RFM69:SWR:SEND,TO=0,RETRY=2
4702 !RFM69:SWR:NACK
4718 RFM69:SWR:SEND,TO=0,RETRY=3
4980 !RFM69:SWR:NACK
4997 RFM69:SWR:SEND,TO=0,RETRY=4
5259 !RFM69:SWR:NACK
5275 RFM69:SWR:SEND,TO=0,RETRY=5
5537 !RFM69:SWR:NACK
5554 !TSF:MSG:SEND,6-6-0-0,s=255,c=3,t=24,pt=1,l=1,sg=0,ft=0,st=NACK:1
5636 RFM69:SAC:SEND ACK,TO=0,RSSI=-34
5685 TSF:MSG:READ,0-0-6,s=255,c=3,t=25,pt=1,l=1,sg=0:1
5750 TSF:MSG:PONG RECV,HP=1
5783 TSM:UPL:OK
5799 TSM:READY:ID=6,PAR=0,DIS=1
5832 RFM69:SWR:SEND,TO=0,RETRY=0
5931 RFM69:SWR:ACK,FROM=0,SEQ=5,RSSI=-37
5980 TSF:MSG:SEND,6-6-0-0,s=255,c=3,t=15,pt=6,l=2,sg=0,ft=0,st=OK:0100
6946 RFM69:SAC:SEND ACK,TO=0,RSSI=-37
6995 TSF:MSG:READ,0-0-6,s=255,c=3,t=15,pt=6,l=2,sg=0:0100
7061 RFM69:SWR:SEND,TO=0,RETRY=0
7192 RFM69:SWR:ACK,FROM=0,SEQ=7,RSSI=-37
7241 TSF:MSG:SEND,6-6-0-0,s=255,c=0,t=17,pt=0,l=10,sg=0,ft=0,st=OK:2.2.0-beta
7340 RFM69:SWR:SEND,TO=0,RETRY=0
7421 RFM69:SWR:ACK,FROM=0,SEQ=8,RSSI=-36
7471 TSF:MSG:SEND,6-6-0-0,s=255,c=3,t=6,pt=1,l=1,sg=0,ft=0,st=OK:0
8470 RFM69:SAC:SEND ACK,TO=0,RSSI=-38
8519 TSF:MSG:READ,0-0-6,s=255,c=3,t=6,pt=0,l=1,sg=0:M
RADIO OK
8585 RFM69:SWR:SEND,TO=0,RETRY=0
8847 !RFM69:SWR:NACK
8863 RFM69:SWR:SEND,TO=0,RETRY=1
8962 RFM69:SWR:ACK,FROM=0,SEQ=10,RSSI=-36
9011 TSF:MSG:SEND,6-6-0-0,s=255,c=3,t=11,pt=0,l=20,sg=0,ft=0,st=OK:IrrigationController
9125 RFM69:SWR:SEND,TO=0,RETRY=0
9256 RFM69:SWR:ACK,FROM=0,SEQ=11,RSSI=-35
9306 TSF:MSG:SEND,6-6-0-0,s=255,c=3,t=12,pt=0,l=3,sg=0,ft=0,st=OK:1.2
PRES I=200, T=23
9404 RFM69:SWR:SEND,TO=0,RETRY=0
9666 !RFM69:SWR:NACK
9682 RFM69:SWR:SEND,TO=0,RETRY=1
9945 !RFM69:SWR:NACK
9961 RFM69:SWR:SEND,TO=0,RETRY=2
10223 !RFM69:SWR:NACK
10240 RFM69:SWR:SEND,TO=0,RETRY=3
10502 !RFM69:SWR:NACK
10518 RFM69:SWR:SEND,TO=0,RETRY=4
10715 RFM69:SWR:ACK,FROM=0,SEQ=12,RSSI=-36
10764 TSF:MSG:SEND,6-6-0-0,s=200,c=0,t=23,pt=0,l=0,sg=0,ft=0,st=OK:
PRES I=201, T=30
10846 RFM69:SWR:SEND,TO=0,RETRY=0
11108 !RFM69:SWR:NACK
11124 RFM69:SWR:SEND,TO=0,RETRY=1
11304 RFM69:SWR:ACK,FROM=0,SEQ=13,RSSI=-35
11354 TSF:MSG:SEND,6-6-0-0,s=201,c=0,t=30,pt=0,l=0,sg=0,ft=0,st=OK:
BATT V=3.67 P=33
SEND D=0 I=201 C=0 T=38 S= I=0 F=3.67
11468 !MCO:SND:NODE NOT REG
11534 RFM69:SWR:SEND,TO=0,RETRY=0
11796 !RFM69:SWR:NACK
11812 RFM69:SWR:SEND,TO=0,RETRY=1
12075 !RFM69:SWR:NACK
12091 RFM69:SWR:SEND,TO=0,RETRY=2
12337 RFM69:SWR:ACK,FROM=0,SEQ=14,RSSI=-36
12386 TSF:MSG:SEND,6-6-0-0,s=255,c=3,t=0,pt=1,l=1,sg=0,ft=0,st=OK:33
PRES I=1 T=3
12468 RFM69:SWR:SEND,TO=0,RETRY=0
12746 !RFM69:SWR:NACK
12763 RFM69:SWR:SEND,TO=0,RETRY=1
13025 !RFM69:SWR:NACK
13041 RFM69:SWR:SEND,TO=0,RETRY=2
13156 RFM69:SWR:ACK,FROM=0,SEQ=15,RSSI=-35
13205 TSF:MSG:SEND,6-6-0-0,s=1,c=0,t=3,pt=0,l=0,sg=0,ft=0,st=OK:
PRES I=2 T=3
13287 RFM69:SWR:SEND,TO=0,RETRY=0
13385 RFM69:SWR:ACK,FROM=0,SEQ=16,RSSI=-36
13434 TSF:MSG:SEND,6-6-0-0,s=2,c=0,t=3,pt=0,l=0,sg=0,ft=0,st=OK:
READY

13516 MCO:REG:REQ
13533 RFM69:SWR:SEND,TO=0,RETRY=0
13631 RFM69:SWR:ACK,FROM=0,SEQ=17,RSSI=-35
13680 TSF:MSG:SEND,6-6-0-0,s=255,c=3,t=26,pt=1,l=1,sg=0,ft=0,st=OK:2
14663 RFM69:SAC:SEND ACK,TO=0,RSSI=-37
14712 TSF:MSG:READ,0-0-6,s=255,c=3,t=27,pt=1,l=1,sg=0:1
14778 MCO:PIM:NODE REG=1
14811 MCO:BGN:STP
MY I=6 M=1
14827 MCO:BGN:INIT OK,TSP=1

SLEEP 60s

14876 MCO:SLP:MS=60000,SMS=1,I1=255,M1=255,I2=255,M2=255
14942 RFM69:SWR:SEND,TO=0,RETRY=0
15204 !RFM69:SWR:NACK
15220 RFM69:SWR:SEND,TO=0,RETRY=1
15335 RFM69:SWR:ACK,FROM=0,SEQ=19,RSSI=-37
15384 TSF:MSG:SEND,6-6-0-0,s=255,c=3,t=32,pt=5,l=4,sg=0,ft=0,st=OK:1000
16482 TSF:TDI:TSL
16498 RFM69:RSL
16515 MCO:SLP:WUP=-1
16547 TSF:TRI:TSB
16564 RFM69:RSB
16580 RFM69:SWR:SEND,TO=0,RETRY=0
16842 !RFM69:SWR:NACK
16859 RFM69:SWR:SEND,TO=0,RETRY=1
17006 RFM69:SWR:ACK,FROM=0,SEQ=20,RSSI=-37
17055 TSF:MSG:SEND,6-6-0-0,s=255,c=3,t=33,pt=5,l=4,sg=0,ft=0,st=OK:60000
AWAKE

SLEEP 60s

17137 MCO:SLP:MS=60000,SMS=1,I1=255,M1=255,I2=255,M2=255
17219 RFM69:SWR:SEND,TO=0,RETRY=0
17481 !RFM69:SWR:NACK
17498 RFM69:SWR:SEND,TO=0,RETRY=1
17760 !RFM69:SWR:NACK
17776 RFM69:SWR:SEND,TO=0,RETRY=2
18038 !RFM69:SWR:NACK
18055 RFM69:SWR:SEND,TO=0,RETRY=3
18317 !RFM69:SWR:NACK
18333 RFM69:SWR:SEND,TO=0,RETRY=4
18595 !RFM69:SWR:NACK
18612 RFM69:SWR:SEND,TO=0,RETRY=5
18874 !RFM69:SWR:NACK
18890 !TSF:MSG:SEND,6-6-0-0,s=255,c=3,t=32,pt=5,l=4,sg=0,ft=0,st=NACK:1000
19300 RFM69:SAC:SEND ACK,TO=0,RSSI=-36
19349 TSF:MSG:READ,0-0-6,s=2,c=2,t=2,pt=0,l=1,sg=0:1
RECV S=0 I=2 C=2 T=2 P=1
DOUT I=2 P=7 V=1 P=50
SEND D=0 I=2 C=0 T=2 S= I=1 F=0.00
21495 RFM69:SWR:SEND,TO=0,RETRY=0
21594 RFM69:SWR:ACK,FROM=0,SEQ=23,RSSI=-39
21643 TSF:MSG:SEND,6-6-0-0,s=2,c=1,t=2,pt=2,l=2,sg=0,ft=1,st=OK:1
21708 TSF:TDI:TSL
21741 RFM69:RSL
21757 MCO:SLP:WUP=-1
21790 TSF:TRI:TSB
21807 RFM69:RSB
21823 RFM69:SWR:SEND,TO=0,RETRY=0
21970 RFM69:SWR:ACK,FROM=0,SEQ=24,RSSI=-37
22020 TSF:MSG:SEND,6-6-0-0,s=255,c=3,t=33,pt=5,l=4,sg=0,ft=0,st=OK:60000
AWAKE

SLEEP 60s

22118 MCO:SLP:MS=60000,SMS=1,I1=255,M1=255,I2=255,M2=255
22200 RFM69:SWR:SEND,TO=0,RETRY=0
22446 !RFM69:SWR:NACK
22462 RFM69:SWR:SEND,TO=0,RETRY=1
22724 !RFM69:SWR:NACK
22740 RFM69:SWR:SEND,TO=0,RETRY=2
23003 !RFM69:SWR:NACK
23019 RFM69:SWR:SEND,TO=0,RETRY=3
23281 !RFM69:SWR:NACK
23298 RFM69:SWR:SEND,TO=0,RETRY=4
23560 !RFM69:SWR:NACK
23576 RFM69:SWR:SEND,TO=0,RETRY=5
23838 !RFM69:SWR:NACK
23855 !TSF:MSG:SEND,6-6-0-0,s=255,c=3,t=32,pt=5,l=4,sg=0,ft=0,st=NACK:1000
24297 RFM69:SAC:SEND ACK,TO=0,RSSI=-36
24346 TSF:MSG:READ,0-0-6,s=1,c=2,t=2,pt=0,l=1,sg=0:1
RECV S=0 I=1 C=2 T=2 P=1
DOUT I=1 P=6 V=1 P=50
SEND D=0 I=1 C=0 T=2 S= I=1 F=0.00
26492 RFM69:SWR:SEND,TO=0,RETRY=0
26591 RFM69:SWR:ACK,FROM=0,SEQ=27,RSSI=-39
26640 TSF:MSG:SEND,6-6-0-0,s=1,c=1,t=2,pt=2,l=2,sg=0,ft=1,st=OK:1
26722 TSF:TDI:TSL
26738 RFM69:RSL
26755 MCO:SLP:WUP=-1
26787 TSF:TRI:TSB
26804 RFM69:RSB
26836 RFM69:SWR:SEND,TO=0,RETRY=0
27000 RFM69:SWR:ACK,FROM=0,SEQ=28,RSSI=-41
27049 TSF:MSG:SEND,6-6-0-0,s=255,c=3,t=33,pt=5,l=4,sg=0,ft=0,st=OK:60000
AWAKE

SLEEP 60s

27131 MCO:SLP:MS=60000,SMS=1,I1=255,M1=255,I2=255,M2=255
27213 RFM69:SWR:SEND,TO=0,RETRY=0
27475 !RFM69:SWR:NACK
27492 RFM69:SWR:SEND,TO=0,RETRY=1
27754 !RFM69:SWR:NACK
27770 RFM69:SWR:SEND,TO=0,RETRY=2
28033 !RFM69:SWR:NACK
28049 RFM69:SWR:SEND,TO=0,RETRY=3
28278 RFM69:SWR:ACK,FROM=0,SEQ=29,RSSI=-41
28327 TSF:MSG:SEND,6-6-0-0,s=255,c=3,t=32,pt=5,l=4,sg=0,ft=0,st=OK:1000
29409 TSF:TDI:TSL
29425 RFM69:RSL
29442 MCO:SLP:WUP=-1
29474 TSF:TRI:TSB
29491 RFM69:RSB
29507 RFM69:SWR:SEND,TO=0,RETRY=0
29753 RFM69:SWR:ACK,FROM=0,SEQ=30,RSSI=-39
29802 TSF:MSG:SEND,6-6-0-0,s=255,c=3,t=33,pt=5,l=4,sg=0,ft=0,st=OK:60000
AWAKE

SLEEP 60s

29900 MCO:SLP:MS=60000,SMS=1,I1=255,M1=255,I2=255,M2=255
29966 RFM69:SWR:SEND,TO=0,RETRY=0
30179 RFM69:SWR:ACK,FROM=0,SEQ=31,RSSI=-39
30228 TSF:MSG:SEND,6-6-0-0,s=255,c=3,t=32,pt=5,l=4,sg=0,ft=0,st=OK:1000
31326 TSF:TDI:TSL
31342 RFM69:RSL

First of all why getting a NACK with an excellent RSSI of 30 is strange. But now it comes the weird part. I restarted the gw, and the sensor was back again working fine....for a few minutes, then the same bad behavior was there again. I restarted the sensor a few times and always the same problem but finally after another reboot it was still ok (and consistently ok). Which tells me...well nothing to me Bad wiring? Or since I have a 50v/10uF capacitor between the radio vcc and gnd, it is not charging fast enough and "cuts" out the power?

[scalz]

Hi.

• what's your GW setup? (mcu, and gateway mode)
• what's your node hardware, especially mcu, do you change clocks during sketch, and which one do you use, which RFM69 variant too (high power or not) ?
• how are relays connected to your node (could be some noise too..)

[user2684]

@scalz sorry I always forget to add all the relevant information The hw is a serial gw (pro mini 3.3v attached to a Rpi usb port), the node is another 3.3v pro mini powered by AA batteries. Both running at 1Mhz (which with the new driver is working fine provided all the nodes are running at the same speed) and I'm using tekka's https://github.com/tekka007/MySensors/tree/RFM69_Update which is initializing both the gw and the node at max power and since then I had no more range issues. Btw the logs above have been take with ATC disabled but I had similar logs with it enabled. The relay is connected to an arduino's pin and powered independently.

I must say I have another three nodes running without a problem with a similar configuration since a few weeks now. Since the last reboot also this one is running perfectly once again. I remember I had a similar issue with another node, same configuration, after a few times I plugged in and out again and again it stared running fine and it is doing so since then. Like if it starts in a good shape, it will continue to do so, if it doesn't, oh then begins the troubles

[user2684]

Just a quick update after 24 hours. I don't see anymore re-transmissions (no more duplicated messages on the gateway) and the relay is always triggering. Once again, if it starts in a good shape, everything goes well. But sooner or later I need to identify the real issue Cannot be software since the sketch is the same, cannot be hardware I think since the hw is the same, cannot be the distance since yesterday the behavior was the same, when both far away or very close to the gw. Maybe when I move it around I somehow touch something not very well connected but this does not explain how it could happen with another node and only with a RFM69. Who knows

[scalz]

@user2684
no clue on my side.. we could also imagine for instance:

• different "environment" parameters influencing RF
• a little bit different antenna (i'm exagerating a bit i think), or difference in assembly
• collision..
• different mcu or radio quality
• how much remaining memory do you have after compilation
• i know 10uF should be enough, but i generally use this for nrf, and add a bit more in case for rfm69 as it uses more power (but that depends on the power supply i use too).

I almost already know your reply to this Some points are maybe irrelevant for your case, these are just there for ref. I'm like you, i don't trust in mystical issues

[user2684]

@scalz thanks, well, nothing is irrelevant, when not working there must be at least one of your points above which I'm not considering enough
Now it is still working well, checking in every minute without a single duplicated message in the controller even if far away from the gw and the remote relay triggering when requested. I should probably do a better job in replicating the issue to at least limit the possible causes...I'll report back in the future with better data I hope Thanks!