3. RFM69 weirdness: kind of solved but not really

RFM69 weirdness: kind of solved but not really

  • user2684
    Contest Winner

    Or most likely my own weirdness...long story short, I was testing the excellent fork from @scalz having a RFM69 attached directly to a raspberry. Everything has worked fine for a few days but then I've noticed the range was not as good as with a serial gateway (but this is a different story) and reverted everything back to 2.1.1. Then all the weirdness started and started two days of intense troubleshooting.

    What happened was quit random and with so many changes in the middle I had a lot of challenges in tracking down the root cause which I know is not helping anybody. It started with gw and sensor unable to communicate even if very close, something in the middle between https://forum.mysensors.org/topic/5610/radio-fail-after-3-weeks-solved and https://forum.mysensors.org/topic/5154/serialgateway-is-rebooting-on-relay, with the gateway rebooting after failing to send a message:

    0;255;3;0;9;MCO:BGN:INIT GW,CP=RRNGA--,VER=2.1.1
0;255;3;0;9;TSM:INIT
0;255;3;0;9;TSF:WUR:MS=0
0;255;3;0;9;TSM:INIT:TSP OK
0;255;3;0;9;TSM:INIT:GW MODE
0;255;3;0;9;TSM:READY:ID=0,PAR=0,DIS=0
0;255;3;0;9;MCO:REG:NOT NEEDED
0;255;3;0;14;Gateway startup complete.
0;255;0;0;18;2.1.1
0;255;3;0;9;MCO:BGN:STP
0;255;3;0;9;MCO:BGN:INIT OK,TSP=1
0;255;3;0;9;TSF:MSG:READ,3-3-255,s=255,c=3,t=7,pt=0,l=0,sg=0:
0;255;3;0;9;TSF:MSG:BC
0;255;3;0;9;TSF:MSG:FPAR REQ,ID=3
0;255;3;0;9;TSF:CKU:OK,FCTRL
0;255;3;0;9;TSF:MSG:GWL OK
0;255;3;0;9;TSF:MSG:SEND,0-0-3-3,s=255,c=3,t=8,pt=1,l=1,sg=0,ft=0,st=OK:0
0;255;3;0;9;TSF:MSG:READ,3-3-0,s=255,c=3,t=24,pt=1,l=1,sg=0:1
0;255;3;0;9;TSF:MSG:PINGED,ID=3,HP=1
0;255;3;0;9;TSF:MSG:SEND,0-0-3-3,s=255,c=3,t=25,pt=1,l=1,sg=0,ft=0,st=OK:1
0;255;3;0;9;TSF:MSG:READ,3-3-0,s=255,c=3,t=15,pt=6,l=2,sg=0:0100
0;255;3;0;9;!TSF:MSG:SEND,0-0-3-3,s=255,c=3,t=15,pt=6,l=2,sg=0,ft=0,st=NACK:0100
0;255;3;0;9;MCO:BGN:INIT GW,CP=RRNGA--,VER=2.1.1
0;255;3;0;9;TSM:INIT
0;255;3;0;9;TSF:WUR:MS=0
0;255;3;0;9;TSM:INIT:TSP OK
0;255;3;0;9;TSM:INIT:GW MODE
0;255;3;0;9;TSM:READY:ID=0,PAR=0,DIS=0
0;255;3;0;9;MCO:REG:NOT NEEDED
0;255;3;0;14;Gateway startup complete.
0;255;0;0;18;2.1.1
0;255;3;0;9;MCO:BGN:STP
0;255;3;0;9;MCO:BGN:INIT OK,TSP=1
0;255;3;0;9;TSF:MSG:READ,3-3-0,s=255,c=3,t=6,pt=1,l=1,sg=0:0
3;255;3;0;6;0
0;255;3;0;9;TSF:MSG:READ,3-3-0,s=255,c=3,t=11,pt=0,l=12,sg=0:BoilerSensor
3;255;3;0;11;BoilerSensor
0;255;3;0;9;TSF:MSG:READ,3-3-0,s=255,c=3,t=11,pt=0,l=12,sg=0:BoilerSensor
3;255;3;0;11;BoilerSensor
0;255;3;0;9;TSF:MSG:READ,3-3-0,s=255,c=3,t=12,pt=0,l=3,sg=0:1.0
3;255;3;0;12;1.0
0;255;3;0;9;TSF:MSG:READ,3-3-0,s=255,c=3,t=12,pt=0,l=3,sg=0:1.0
3;255;3;0;12;1.0
0;255;3;0;9;TSF:MSG:READ,3-3-0,s=200,c=0,t=23,pt=0,l=0,sg=0:
3;200;0;0;23;
0;255;3;0;9;TSF:MSG:READ,3-3-0,s=200,c=0,t=23,pt=0,l=0,sg=0:
3;200;0;0;23;
0;255;3;0;9;TSF:MSG:READ,3-3-0,s=201,c=0,t=30,pt=0,l=0,sg=0:
3;201;0;0;30;
0;255;3;0;9;TSF:MSG:READ,3-3-0,s=201,c=0,t=30,pt=0,l=0,sg=0:
3;201;0;0;30;
0;255;3;0;9;TSF:MSG:READ,3-3-0,s=255,c=3,t=0,pt=1,l=1,sg=0:100
3;255;3;0;0;100
0;255;3;0;9;TSF:MSG:READ,3-3-0,s=255,c=3,t=0,pt=1,l=1,sg=0:100
3;255;3;0;0;100
0;255;3;0;9;TSF:MSG:READ,3-3-0,s=1,c=0,t=3,pt=0,l=0,sg=0:
3;1;0;0;3;
0;255;3;0;9;TSF:MSG:READ,3-3-0,s=1,c=0,t=3,pt=0,l=0,sg=0:
3;1;0;0;3;
0;255;3;0;9;TSF:MSG:READ,3-3-0,s=2,c=0,t=3,pt=0,l=0,sg=0:
3;2;0;0;3;
0;255;3;0;9;TSF:MSG:READ,3-3-0,s=2,c=0,t=3,pt=0,l=0,sg=0:
3;2;0;0;3;
0;255;3;0;9;TSF:MSG:READ,3-3-0,s=255,c=3,t=26,pt=1,l=1,sg=0:2
0;255;3;0;9;!TSF:MSG:SEND,0-0-3-3,s=255,c=3,t=27,pt=1,l=1,sg=0,ft=0,st=NACK:1
0;255;3;0;9;MCO:BGN:INIT GW,CP=RRNGA--,VER=2.1.1
0;255;3;0;9;TSM:INIT
0;255;3;0;9;TSF:WUR:MS=0
0;255;3;0;9;TSM:INIT:TSP OK
0;255;3;0;9;TSM:INIT:GW MODE
0;255;3;0;9;TSM:READY:ID=0,PAR=0,DIS=0

    I then moved to 2.2.0-beta from the dev branch and got similar results but without reboot (I guess because of a code change):

    0;255;3;0;9;10407 TSF:MSG:READ,3-3-0,s=255,c=3,t=24,pt=1,l=1,sg=0:1
0;255;3;0;9;10477 TSF:MSG:PINGED,ID=3,HP=1
0;255;3;0;9;10657 !TSF:MSG:SEND,0-0-3-3,s=255,c=3,t=25,pt=1,l=1,sg=0,ft=0,st=NACK:1
0;255;3;0;9;0 MCO:BGN:INIT GW,CP=RRNGA--X,VER=2.2.0-beta
0;255;3;0;9;57 TSM:INIT
0;255;3;0;9;81 TSF:WUR:MS=0
0;255;3;0;9;112 TSM:INIT:TSP OK
0;255;3;0;9;145 TSM:INIT:GW MODE
0;255;3;0;9;180 TSM:READY:ID=0,PAR=0,DIS=0
0;255;3;0;9;225 MCO:REG:NOT NEEDED
0;255;3;0;14;Gateway startup complete.
0;255;0;0;18;2.2.0-beta
0;255;3;0;9;264 MCO:BGN:STP
0;255;3;0;9;354 MCO:BGN:INIT OK,TSP=1
0;255;3;0;9;399 TSF:MSG:READ,3-3-0,s=255,c=3,t=24,pt=1,l=1,sg=0:1
0;255;3;0;9;466 TSF:MSG:PINGED,ID=3,HP=1
0;255;3;0;9;645 !TSF:MSG:SEND,0-0-3-3,s=255,c=3,t=25,pt=1,l=1,sg=0,ft=0,st=NACK:1
0;255;3;0;9;4931 TSF:MSG:READ,3-3-255,s=255,c=3,t=7,pt=0,l=0,sg=0:
0;255;3;0;9;5001 TSF:MSG:BC
0;255;3;0;9;5029 TSF:MSG:FPAR REQ,ID=3
0;255;3;0;9;5070 TSF:CKU:OK,FCTRL
0;255;3;0;9;5105 TSF:MSG:GWL OK
0;255;3;0;9;5267 TSF:MSG:SEND,0-0-3-3,s=255,c=3,t=8,pt=1,l=1,sg=0,ft=0,st=OK:0
0;255;3;0;9;7202 TSF:MSG:READ,3-3-0,s=255,c=3,t=24,pt=1,l=1,sg=0:1
0;255;3;0;9;7272 TSF:MSG:PINGED,ID=3,HP=1
0;255;3;0;9;7450 !TSF:MSG:SEND,0-0-3-3,s=255,c=3,t=25,pt=1,l=1,sg=0,ft=0,st=NACK:1
0;255;3;0;9;9433 TSF:MSG:READ,3-3-0,s=255,c=3,t=24,pt=1,l=1,sg=0:1
0;255;3;0;9;9502 TSF:MSG:PINGED,ID=3,HP=1
0;255;3;0;9;9680 !TSF:MSG:SEND,0-0-3-3,s=255,c=3,t=25,pt=1,l=1,sg=0,ft=0,st=NACK:1
0;255;3;0;9;11665 TSF:MSG:READ,3-3-0,s=255,c=3,t=24,pt=1,l=1,sg=0:1
0;255;3;0;9;11737 TSF:MSG:PINGED,ID=3,HP=1
0;255;3;0;9;11915 !TSF:MSG:SEND,0-0-3-3,s=255,c=3,t=25,pt=1,l=1,sg=0,ft=0,st=NACK:1
0;255;3;0;9;13899 TSF:MSG:READ,3-3-0,s=255,c=3,t=24,pt=1,l=1,sg=0:1
0;255;3;0;9;13969 TSF:MSG:PINGED,ID=3,HP=1
0;255;3;0;9;14125 TSF:MSG:SEND,0-0-3-3,s=255,c=3,t=25,pt=1,l=1,sg=0,ft=0,st=OK:1
0;255;3;0;9;14292 TSF:MSG:READ,3-3-0,s=255,c=3,t=15,pt=6,l=2,sg=0:0100
0;255;3;0;9;14501 !TSF:MSG:SEND,0-0-3-3,s=255,c=3,t=15,pt=6,l=2,sg=0,ft=0,st=NACK:0100
0;255;3;0;9;16525 TSF:MSG:READ,3-3-0,s=255,c=0,t=17,pt=0,l=10,sg=0:2.2.0-beta
3;255;0;0;17;2.2.0-beta
0;255;3;0;9;16623 TSF:MSG:READ,3-3-0,s=255,c=0,t=17,pt=0,l=10,sg=0:2.2.0-beta
3;255;0;0;17;2.2.0-beta
0;255;3;0;9;16762 TSF:MSG:READ,3-3-0,s=255,c=3,t=6,pt=1,l=1,sg=0:0
3;255;3;0;6;0
0;255;3;0;9;16863 TSF:MSG:READ,3-3-0,s=255,c=3,t=6,pt=1,l=1,sg=0:0
3;255;3;0;6;0
0;255;3;0;9;18987 TSF:MSG:READ,3-3-0,s=255,c=3,t=11,pt=0,l=12,sg=0:BoilerSensor
3;255;3;0;11;BoilerSensor
0;255;3;0;9;19083 TSF:MSG:READ,3-3-0,s=255,c=3,t=11,pt=0,l=12,sg=0:BoilerSensor
3;255;3;0;11;BoilerSensor
0;255;3;0;9;19226 TSF:MSG:READ,3-3-0,s=255,c=3,t=12,pt=0,l=3,sg=0:1.0
3;255;3;0;12;1.0
0;255;3;0;9;19322 TSF:MSG:READ,3-3-0,s=255,c=3,t=12,pt=0,l=3,sg=0:1.0
3;255;3;0;12;1.0
0;255;3;0;9;19456 TSF:MSG:READ,3-3-0,s=200,c=0,t=23,pt=0,l=0,sg=0:
3;200;0;0;23;
0;255;3;0;9;19550 TSF:MSG:READ,3-3-0,s=200,c=0,t=23,pt=0,l=0,sg=0:
3;200;0;0;23;
0;255;3;0;9;19679 TSF:MSG:READ,3-3-0,s=201,c=0,t=30,pt=0,l=0,sg=0:
3;201;0;0;30;
0;255;3;0;9;19775 TSF:MSG:READ,3-3-0,s=201,c=0,t=30,pt=0,l=0,sg=0:
3;201;0;0;30;
0;255;3;0;9;20011 TSF:MSG:READ,3-3-0,s=255,c=3,t=0,pt=1,l=1,sg=0:100
3;255;3;0;0;100
0;255;3;0;9;20115 TSF:MSG:READ,3-3-0,s=255,c=3,t=0,pt=1,l=1,sg=0:100
3;255;3;0;0;100
0;255;3;0;9;20248 TSF:MSG:READ,3-3-0,s=1,c=0,t=3,pt=0,l=0,sg=0:
3;1;0;0;3;
0;255;3;0;9;20342 TSF:MSG:READ,3-3-0,s=1,c=0,t=3,pt=0,l=0,sg=0:
3;1;0;0;3;
0;255;3;0;9;20469 TSF:MSG:READ,3-3-0,s=2,c=0,t=3,pt=0,l=0,sg=0:
3;2;0;0;3;
0;255;3;0;9;20570 TSF:MSG:READ,3-3-0,s=2,c=0,t=3,pt=0,l=0,sg=0:
3;2;0;0;3;
0;255;3;0;9;20721 TSF:MSG:READ,3-3-0,s=255,c=3,t=26,pt=1,l=1,sg=0:2
0;255;3;0;9;20926 !TSF:MSG:SEND,0-0-3-3,s=255,c=3,t=27,pt=1,l=1,sg=0,ft=0,st=NACK:1
0;255;3;0;9;21012 TSF:MSG:READ,3-3-255,s=255,c=3,t=7,pt=0,l=0,sg=0:
0;255;3;0;9;21082 TSF:MSG:BC
0;255;3;0;9;21110 TSF:MSG:FPAR REQ,ID=3
0;255;3;0;9;21153 TSF:PNG:SEND,TO=0
0;255;3;0;9;21190 TSF:CKU:OK
0;255;3;0;9;21219 TSF:MSG:GWL OK
0;255;3;0;9;22163 !TSF:MSG:SEND,0-0-3-3,s=255,c=3,t=8,pt=1,l=1,sg=0,ft=0,st=NACK:0
0;255;3;0;9;23267 TSF:MSG:READ,3-3-255,s=255,c=3,t=7,pt=0,l=0,sg=0:
0;255;3;0;9;23336 TSF:MSG:BC
0;255;3;0;9;23367 TSF:MSG:FPAR REQ,ID=3
0;255;3;0;9;23408 TSF:CKU:OK,FCTRL
0;255;3;0;9;23445 TSF:MSG:GWL OK
0;255;3;0;9;24496 TSF:MSG:SEND,0-0-3-3,s=255,c=3,t=8,pt=1,l=1,sg=0,ft=0,st=OK:0
0;255;3;0;9;25567 TSF:MSG:READ,3-3-0,s=255,c=3,t=24,pt=1,l=1,sg=0:1
0;255;3;0;9;25636 TSF:MSG:PINGED,ID=3,HP=1
0;255;3;0;9;25817 !TSF:MSG:SEND,0-0-3-3,s=255,c=3,t=25,pt=1,l=1,sg=0,ft=0,st=NACK:1
0;255;3;0;9;27807 TSF:MSG:READ,3-3-0,s=255,c=3,t=24,pt=1,l=1,sg=0:1
0;255;3;0;9;27879 TSF:MSG:PINGED,ID=3,HP=1
0;255;3;0;9;28057 !TSF:MSG:SEND,0-0-3-3,s=255,c=3,t=25,pt=1,l=1,sg=0,ft=0,st=NACK:1
0;255;3;0;9;30965 TSF:MSG:READ,3-3-0,s=255,c=3,t=24,pt=1,l=1,sg=0:1
0;255;3;0;9;31035 TSF:MSG:PINGED,ID=3,HP=1
0;255;3;0;9;31215 !TSF:MSG:SEND,0-0-3-3,s=255,c=3,t=25,pt=1,l=1,sg=0,ft=0,st=NACK:1
0;255;3;0;9;33200 TSF:MSG:READ,3-3-0,s=255,c=3,t=24,pt=1,l=1,sg=0:1
0;255;3;0;9;33269 TSF:MSG:PINGED,ID=3,HP=1
0;255;3;0;9;33425 TSF:MSG:SEND,0-0-3-3,s=255,c=3,t=25,pt=1,l=1,sg=0,ft=0,st=OK:1
0;255;3;0;9;33660 TSF:MSG:READ,3-3-0,s=200,c=1,t=48,pt=0,l=8,sg=0:SLEEPING
3;200;1;0;48;SLEEPING
0;255;3;0;9;33767 TSF:MSG:READ,3-3-0,s=200,c=1,t=48,pt=0,l=8,sg=0:SLEEPING
3;200;1;0;48;SLEEPING
0;255;3;0;9;33972 TSF:MSG:READ,3-3-0,s=255,c=3,t=22,pt=5,l=4,sg=0:376
3;255;3;0;22;376
0;255;3;0;9;34072 TSF:MSG:READ,3-3-0,s=255,c=3,t=22,pt=5,l=4,sg=0:376
3;255;3;0;22;376

    What frustrated me was that the same configuration with the 2.1.1 lib a few days before was working great with a range of 30+ meters indoor, without any capacitor or dedicated power supply and this was the reason why I didn't give up.

    After having tried everything (capacitor, new arduinos, new radios, new cables, no encryption, new bootloaders, etc.) I've realized I was using a 1Mhz bootloader for the sensor (I really need the 1.8v lower bound when running on batteries). When I put a standard bootloader, everything was still working great. I've then tried the 1Mhz bootloader on both gw and sensor, so without mixing them, and still the range was poor and a lot of send failure happened. Is this somehow expected, e.g. running at low speed could cause problems with the radio?

    Thanks

    0
  • user2684
    Contest Winner

    Ok, I have a more clear understanding now. It has definitely something to do with the CPU clock. I've tried multiple times, when both the sensor and the gw are running at 8Mhz everything works fine. When one or the other or both are running at 1Mhz I see the same issues of the first post. This is true for both 2.1.1 and for the development version.

    I then asked myself why this hasn't come out during my first test so I reverted back to @scalz https://github.com/scalz/Mysensors/tree/rfm69_update2 and magically (I'm sure there is no magic behind) started working again IF both the serial gw and the sensor are running at the same speed (e.g. 8Mhz and 8Mhz or 1Mhz and 1Mhz). So I can finally have my low power sensor working. I then tried to put the radio back on the pi and at least the behavior is coherent: it works but the range is kind of a half compared to the serial gw (might have something to do with the clock as well).
    So I think I can conclude the new driver is working better 🙂

    0
  • scalz
    Hardware Contributor

    @user2684
    Yes, if i remember I also encountered same kind of behaviour (packet collisions, not sync ..)
    Unfortunately, you'll have to wait a bit for the new rfm69 driver before it's in master branch, because it changes the packet format. The PR is now handled by Super @tekka , big thx again 🙂
    and my fork is deprecated for the moment.

    Actually i'm finishing some hardware before going back to software 😥
    so i can take a look and test some part of your nice lib 👍 with my low power nodes

    0
Log in to reply
 

Suggested Topics

56
Online

11.4k
Users

11.1k
Topics

112.7k
Posts



Copyright 2019 Sensnology   |   Forum Guidelines   |   Privacy Policy   |   Terms of Service