RFM69: ATC only works if MY_DEBUG_VERBOSE_RFM69 defined
-
I'm currently experimenting with RFM69 radios. I've already built a well working multi-transport GW (NRF24 + RFM69) based on the current 2.4.0 dev branch - sketch and setup is posted here.
Now I'm evaluating the range / coverage of different RFM69 transceivers and antennas in and around the house, taking measurements using the RFM69_RFM95_ATC_SignalReport sketch with these defines:
#define MY_DEBUG // #define MY_DEBUG_VERBOSE_RFM69 #define MY_SIGNAL_REPORT_ENABLED // RFM69 #define MY_RADIO_RFM69 #define MY_RFM69_NEW_DRIVER // Required by dualRF GW #define MY_RFM69_NETWORKID 69The multi-transport GW requires to use the new RFM69 driver, which has ATC enabled by default. As far as I understand, ATC is a technique to automatically adjust the TX power to match a specified TX signal strength (-80 dBm by default), which keeps the RF "polution" to a minimum and optimizes power consumption.
What I expect to see is a varying TX power depending on the signal quality / distance to the GW. A node right next to the GW should have a power level close to 0%. Across the house or outside, it should be much higher.
Here are some mean values collected over a period of half an hour each, using a non-amplified RFM69CW:
Location Upl. Quality TX RSSI RX RSSI Power (dBm) Power (%) Same Room as GW -85 -92 -28 13 100 Floor below, two rooms across -91 -94 -71 13 100 Garden (~30m) -92 -94 -79 13 100 TX RSSI is always below the target of -80, so ATC is boosting the TX power to the highest possible level. Correct? But even when the node is close to the GW, the TX RSSI exeeds the target value. Bad antenna?
Now look what happens when I uncomment
#define MY_DEBUG_VERBOSE_RFM69on the node:Location Upl. Quality TX RSSI RX RSSI Power (dBm) Power (%) Same Room as GW -52 -57 -29 -18 0 Floor below, two rooms across -78 -78 -63 -6 38 Garden (~30m) -72 -78 -85 11 93 These results look far more reasonable! But defining
MY_DEBUG_VERBOSE_RFM69shouldn't make a difference, right? As soon as I remove it, I'm back to the results in the first table.I've tried 2.3.2 and 2.4.0 on the node, they both behave the same. The RFM69 is connected to a 3V3 8 MHz Pro Mini. They are both powered with a regulated 3V3 source.
MY_RFM69_ATC_MODE_DISABLEDis not defined.For the antennas I'm using straight solid core wires of 82mm length on both transceivers, directly soldered to the ANT pin. I don't think that this is the issue - the range and reliability of the connection is great: out of a total of 48436 messages, I got only got 21 NACKs (< 0,05%).
Am I missing something here? Is there a bug?
-
Interesting finding!
I'm trying to replicate the behaviour, and have added some debug print statements in my code, which shows the tx level after each transmission. The number is changing often which doesn't correspond with your behaviour.
How did you measure this? -
Interesting finding!
I'm trying to replicate the behaviour, and have added some debug print statements in my code, which shows the tx level after each transmission. The number is changing often which doesn't correspond with your behaviour.
How did you measure this?@electrik I'm using the RFM69_RFM95_ATC_SignalReport sketch and store every message in a time-series database. The values listed in the table are the arithmetic means of the whole measurement period in a specific location.
I suspect that this is possibly a timing issue. And it also seems to be related to v2.4.0.
Adding a
wait(50)right before the return statement of theRFM69_executeATCfunction inRFM69_new.cppon line 636 seems to "fix" it. The TX power is now properly adjusting without definingMY_DEBUG_VERBOSE_RFM69and the reported TX RSSI value is no longer pinned down to a value below -90, regardless of how close the node is to the GW.If I undefine
MY_DEBUGaswell, I need a delay of at least 125 ms to achieve lower power levels.Here's the results of this adjustment:
TX RSSI is a little jumpy, but the connection is stable and the power level is regulated.
And just a few minutes ago, I changed my multi-transport GW running at 2.4.0 alpha to a RFM69-only GW with 2.3.2, while the RFM69 node is still on 2.4.0 alpha without my adjustments in the driver. With this change, the node is regulating the power levels aswell.
Results with the RFM69 GW at 2.3.2:
EDIT: For comparison, this is the signal report of a RFM69 node with unmodified driver at 2.4.0 alpha connected to a RFM69-only GW at 2.4.0 alpha:
The power level is near 100%, while the TX RSSI stays far below the target value.
-
Here's a roundup of all combinations I've tried today and their results:
GW Version Node Version MY_DEBUG_VERBOSE_RFM69defined?wait(50)on node?TX power regulating? 2.4.0-alpha 2.4.0-alpha NO NO NO 2.4.0-alpha 2.4.0-alpha YES NO YES 2.4.0-alpha 2.4.0-alpha NO YES YES 2.4.0-alpha 2.4.0-alpha YES YES YES 2.4.0-alpha 2.3.2 NO NO NO 2.4.0-alpha 2.3.2 YES NO YES 2.4.0-alpha 2.3.2 NO YES YES 2.4.0-alpha 2.3.2 YES YES YES 2.3.2 2.4.0-alpha NO NO YES 2.3.2 2.3.2 NO NO YES Only if the GW is on 2.4.0-alpha and the node (2.3.2 or 2.4.0-alpha) does neither define
MY_DEBUG_VERBOSE_RFM69nor addwait(50)inRFM69_executeATC, the node doesn't regulate the TX power. In all other cases, it does adjust the TX power. If the GW is on 2.3.2 it always regulates. -
@BearWithBeard
thank you for your investigations :+1:
yes, this is problably a timing issue. this will be fixed asap -
Hello,
I would like to step in here as you will look into this ATC mode anyway :-)
I've been observing the behaviour, and when it successfully sends a message, the power level is decreased. Excellent.
At some point the power becomes too low and messages are not ACK'ed anymore. I had expected the power level would be increased at that point, but it doesn't.
The result is that on another succesfull delivery the power level is decreased even more, and the node can't find the gateway anymore. Then the node increases its power level to the initial value (let's say 5) and then the process starts over again.
Would it be an idea to increase the power level when there is a NACK and then try to stay around this "ideal" level?I'm willing to test if it is needed ;-)
-
After I wrote the message above I realised this is another topic in fact, I hope you don't mind.
To explain a bit more what happens, here is some debug output. Each 10 seconds an increasing counter is sent to the gateway, and after each sent message the TX power is printed on the screen.46219 TSM:UPL:OK 46252 TSM:READY:ID=31,PAR=0,DIS=1 54607 TSF:MSG:SEND,31-31-0-0,s=22,c=1,t=23,pt=1,l=1,sg=0,ft=0,st=OK:4 Power is 3 64618 TSF:MSG:SEND,31-31-0-0,s=22,c=1,t=23,pt=1,l=1,sg=0,ft=0,st=OK:5 Power is 2 74629 TSF:MSG:SEND,31-31-0-0,s=22,c=1,t=23,pt=1,l=1,sg=0,ft=0,st=OK:6 Power is 1 85655 !TSF:MSG:SEND,31-31-0-0,s=22,c=1,t=23,pt=1,l=1,sg=0,ft=0,st=NACK:7 Power is 1 94650 TSF:MSG:SEND,31-31-0-0,s=22,c=1,t=23,pt=1,l=1,sg=0,ft=1,st=OK:8 Power is 0 105168 TSF:MSG:SEND,31-31-0-0,s=22,c=1,t=23,pt=1,l=1,sg=0,ft=0,st=OK:9 Power is -1 114671 TSF:MSG:SEND,31-31-0-0,s=22,c=1,t=23,pt=1,l=1,sg=0,ft=0,st=OK:10 Power is -2 124682 TSF:MSG:SEND,31-31-0-0,s=22,c=1,t=23,pt=1,l=1,sg=0,ft=0,st=OK:11 Power is -3 135708 !TSF:MSG:SEND,31-31-0-0,s=22,c=1,t=23,pt=1,l=1,sg=0,ft=0,st=NACK:12 Power is -3 144703 TSF:MSG:SEND,31-31-0-0,s=22,c=1,t=23,pt=1,l=1,sg=0,ft=1,st=OK:13 Power is -4 154714 TSF:MSG:SEND,31-31-0-0,s=22,c=1,t=23,pt=1,l=1,sg=0,ft=0,st=OK:14 Power is -5 164724 TSF:MSG:SEND,31-31-0-0,s=22,c=1,t=23,pt=1,l=1,sg=0,ft=0,st=OK:15 Power is -6 174735 TSF:MSG:SEND,31-31-0-0,s=22,c=1,t=23,pt=1,l=1,sg=0,ft=0,st=OK:16 Power is -7 184745 TSF:MSG:SEND,31-31-0-0,s=22,c=1,t=23,pt=1,l=1,sg=0,ft=0,st=OK:17 Power is -8 195772 !TSF:MSG:SEND,31-31-0-0,s=22,c=1,t=23,pt=1,l=1,sg=0,ft=0,st=NACK:18 Power is -8 204980 TSF:MSG:SEND,31-31-0-0,s=22,c=1,t=23,pt=1,l=1,sg=0,ft=1,st=OK:19 Power is -9 214990 TSF:MSG:SEND,31-31-0-0,s=22,c=1,t=23,pt=1,l=1,sg=0,ft=0,st=OK:20 Power is -10 225804 !TSF:MSG:SEND,31-31-0-0,s=22,c=1,t=23,pt=1,l=1,sg=0,ft=0,st=NACK:21 Power is -10 235438 TSF:MSG:SEND,31-31-0-0,s=22,c=1,t=23,pt=1,l=1,sg=0,ft=1,st=OK:22 Power is -11 245825 !TSF:MSG:SEND,31-31-0-0,s=22,c=1,t=23,pt=1,l=1,sg=0,ft=0,st=NACK:23 Power is -11 255836 !TSF:MSG:SEND,31-31-0-0,s=22,c=1,t=23,pt=1,l=1,sg=0,ft=1,st=NACK:24 Power is -11 265846 !TSF:MSG:SEND,31-31-0-0,s=22,c=1,t=23,pt=1,l=1,sg=0,ft=2,st=NACK:25 Power is -11 275857 !TSF:MSG:SEND,31-31-0-0,s=22,c=1,t=23,pt=1,l=1,sg=0,ft=3,st=NACK:26 Power is -11 285868 !TSF:MSG:SEND,31-31-0-0,s=22,c=1,t=23,pt=1,l=1,sg=0,ft=4,st=NACK:27 Power is -11Here are a couple of NACKs, so this is on the limit of TX power IMO. Still one succesfull one, which decreases the power even more.
294862 TSF:MSG:SEND,31-31-0-0,s=22,c=1,t=23,pt=1,l=1,sg=0,ft=5,st=OK:28 Power is -12 305889 !TSF:MSG:SEND,31-31-0-0,s=22,c=1,t=23,pt=1,l=1,sg=0,ft=0,st=NACK:29 Power is -12 315899 !TSF:MSG:SEND,31-31-0-0,s=22,c=1,t=23,pt=1,l=1,sg=0,ft=1,st=NACK:30 Power is -12 325910 !TSF:MSG:SEND,31-31-0-0,s=22,c=1,t=23,pt=1,l=1,sg=0,ft=2,st=NACK:31 Power is -12 335921 !TSF:MSG:SEND,31-31-0-0,s=22,c=1,t=23,pt=1,l=1,sg=0,ft=3,st=NACK:32 Power is -12 345931 !TSF:MSG:SEND,31-31-0-0,s=22,c=1,t=23,pt=1,l=1,sg=0,ft=4,st=NACK:33 Power is -12 355942 !TSF:MSG:SEND,31-31-0-0,s=22,c=1,t=23,pt=1,l=1,sg=0,ft=5,st=NACK:34 Power is -12Five failed messages and the node starts finding its parent. But also that fails.
356024 !TSM:READY:UPL FAIL,SNP 356073 TSM:FPAR 356089 ?TSF:MSG:SEND,31-31-255-255,s=255,c=3,t=7,pt=0,l=0,sg=0,ft=6,st=OK: 358203 !TSM:FPAR:NO REPLY 358219 TSM:FPAR 358252 ?TSF:MSG:SEND,31-31-255-255,s=255,c=3,t=7,pt=0,l=0,sg=0,ft=0,st=OK: 360366 !TSM:FPAR:NO REPLY 360382 TSM:FPAR 360415 ?TSF:MSG:SEND,31-31-255-255,s=255,c=3,t=7,pt=0,l=0,sg=0,ft=0,st=OK: 362512 !TSM:FPAR:NO REPLY 362528 TSM:FPAR 362561 ?TSF:MSG:SEND,31-31-255-255,s=255,c=3,t=7,pt=0,l=0,sg=0,ft=0,st=OK: 364675 !TSM:FPAR:FAIL 364691 TSM:FAIL:CNT=1 364724 TSM:FAIL:DIS 364740 TSF:TDI:TSL 364888 !TSF:SND:TNR Power is -12 374784 TSM:FAIL:RE-INIT 374800 TSM:INIT 374833 TSM:INIT:TSP OK 374865 TSM:INIT:STATID=31 374898 TSF:SID:OK,ID=31 374915 TSM:FPAR 374947 ?TSF:MSG:SEND,31-31-255-255,s=255,c=3,t=7,pt=0,l=0,sg=0,ft=0,st=OK: 375046 !TSF:SND:TNRNow the Transportlayer is re-initialised and the power level goes to 5, which makes the messages being ACKed again. This starts the process all over again.
Power is 5 375734 TSF:MSG:READ,0-0-31,s=255,c=3,t=8,pt=1,l=1,sg=0:0 375799 TSF:MSG:FPAR OK,ID=0,D=1 377044 TSM:FPAR:OK 377061 TSM:ID 377077 TSM:ID:OK 377110 TSM:UPL 377192 TSF:MSG:SEND,31-31-0-0,s=255,c=3,t=24,pt=1,l=1,sg=0,ft=0,st=OK:1 377913 TSF:MSG:READ,0-0-31,s=255,c=3,t=25,pt=1,l=1,sg=0:1 377978 TSF:MSG:PONG RECV,HP=1 378028 TSM:UPL:OK 378044 TSM:READY:ID=31,PAR=0,DIS=1 385105 TSF:MSG:SEND,31-31-0-0,s=22,c=1,t=23,pt=1,l=1,sg=0,ft=0,st=OK:37 Power is 3 395116 TSF:MSG:SEND,31-31-0-0,s=22,c=1,t=23,pt=1,l=1,sg=0,ft=0,st=OK:38 Power is 2 405127 TSF:MSG:SEND,31-31-0-0,s=22,c=1,t=23,pt=1,l=1,sg=0,ft=0,st=OK:39 Power is 1 415137 TSF:MSG:SEND,31-31-0-0,s=22,c=1,t=23,pt=1,l=1,sg=0,ft=0,st=OK:40 Power is 0 425148 TSF:MSG:SEND,31-31-0-0,s=22,c=1,t=23,pt=1,l=1,sg=0,ft=0,st=OK:41 Power is -1 435159 TSF:MSG:SEND,31-31-0-0,s=22,c=1,t=23,pt=1,l=1,sg=0,ft=0,st=OK:42 Power is -2 445169 TSF:MSG:SEND,31-31-0-0,s=22,c=1,t=23,pt=1,l=1,sg=0,ft=0,st=OK:43 Power is -3 455180 TSF:MSG:SEND,31-31-0-0,s=22,c=1,t=23,pt=1,l=1,sg=0,ft=0,st=OK:44 Power is -4 465207 TSF:MSG:SEND,31-31-0-0,s=22,c=1,t=23,pt=1,l=1,sg=0,ft=0,st=OK:45 Power is -5 475201 TSF:MSG:SEND,31-31-0-0,s=22,c=1,t=23,pt=1,l=1,sg=0,ft=0,st=OK:46 Power is -6 485720 TSF:MSG:SEND,31-31-0-0,s=22,c=1,t=23,pt=1,l=1,sg=0,ft=0,st=OK:47 Power is -7 495222 TSF:MSG:SEND,31-31-0-0,s=22,c=1,t=23,pt=1,l=1,sg=0,ft=0,st=OK:48 Power is -8 505446 TSF:MSG:SEND,31-31-0-0,s=22,c=1,t=23,pt=1,l=1,sg=0,ft=0,st=OK:49 Power is -9 516259 !TSF:MSG:SEND,31-31-0-0,s=22,c=1,t=23,pt=1,l=1,sg=0,ft=0,st=NACK:50 Power is -9 525254 TSF:MSG:SEND,31-31-0-0,s=22,c=1,t=23,pt=1,l=1,sg=0,ft=1,st=OK:51 Power is -10 536281 !TSF:MSG:SEND,31-31-0-0,s=22,c=1,t=23,pt=1,l=1,sg=0,ft=0,st=NACK:52 Power is -10 546291 !TSF:MSG:SEND,31-31-0-0,s=22,c=1,t=23,pt=1,l=1,sg=0,ft=1,st=NACK:53 Power is -10 556302 !TSF:MSG:SEND,31-31-0-0,s=22,c=1,t=23,pt=1,l=1,sg=0,ft=2,st=NACK:54 Power is -10 565510 TSF:MSG:SEND,31-31-0-0,s=22,c=1,t=23,pt=1,l=1,sg=0,ft=3,st=OK:55 Power is -11 576323 !TSF:MSG:SEND,31-31-0-0,s=22,c=1,t=23,pt=1,l=1,sg=0,ft=0,st=NACK:56 Power is -11 586334 !TSF:MSG:SEND,31-31-0-0,s=22,c=1,t=23,pt=1,l=1,sg=0,ft=1,st=NACK:57 Power is -11 596344 !TSF:MSG:SEND,31-31-0-0,s=22,c=1,t=23,pt=1,l=1,sg=0,ft=2,st=NACK:58 Power is -11 606355 !TSF:MSG:SEND,31-31-0-0,s=22,c=1,t=23,pt=1,l=1,sg=0,ft=3,st=NACK:59 Power is -11 615989 TSF:MSG:SEND,31-31-0-0,s=22,c=1,t=23,pt=1,l=1,sg=0,ft=4,st=OK:60 Power is -12 626376 !TSF:MSG:SEND,31-31-0-0,s=22,c=1,t=23,pt=1,l=1,sg=0,ft=0,st=NACK:61 Power is -12 636387 !TSF:MSG:SEND,31-31-0-0,s=22,c=1,t=23,pt=1,l=1,sg=0,ft=1,st=NACK:62 Power is -12 646397 !TSF:MSG:SEND,31-31-0-0,s=22,c=1,t=23,pt=1,l=1,sg=0,ft=2,st=NACK:63 Power is -12 656408 !TSF:MSG:SEND,31-31-0-0,s=22,c=1,t=23,pt=1,l=1,sg=0,ft=3,st=NACK:64 Power is -12 666419 !TSF:MSG:SEND,31-31-0-0,s=22,c=1,t=23,pt=1,l=1,sg=0,ft=4,st=NACK:65 Power is -12 676429 !TSF:MSG:SEND,31-31-0-0,s=22,c=1,t=23,pt=1,l=1,sg=0,ft=5,st=NACK:66 Power is -12 676511 !TSM:READY:UPL FAIL,SNP 676560 TSM:FPAR 676577 ?TSF:MSG:SEND,31-31-255-255,s=255,c=3,t=7,pt=0,l=0,sg=0,ft=6,st=OK: 678690 !TSM:FPAR:NO REPLY 678707 TSM:FPAR 678739 ?TSF:MSG:SEND,31-31-255-255,s=255,c=3,t=7,pt=0,l=0,sg=0,ft=0,st=OK: 680853 !TSM:FPAR:NO REPLY 680869 TSM:FPAR 680902 ?TSF:MSG:SEND,31-31-255-255,s=255,c=3,t=7,pt=0,l=0,sg=0,ft=0,st=OK: 682999 !TSM:FPAR:NO REPLY 683016 TSM:FPAR 683048 ?TSF:MSG:SEND,31-31-255-255,s=255,c=3,t=7,pt=0,l=0,sg=0,ft=0,st=OK: 685162 !TSM:FPAR:FAIL 685178 TSM:FAIL:CNT=1 685211 TSM:FAIL:DIS 685228 TSF:TDI:TSL 685375 !TSF:SND:TNR Power is -12 695271 TSM:FAIL:RE-INIT 695287 TSM:INIT 695320 TSM:INIT:TSP OK 695353 TSM:INIT:STATID=31 695386 TSF:SID:OK,ID=31 695402 TSM:FPAR 695435 ?TSF:MSG:SEND,31-31-255-255,s=255,c=3,t=7,pt=0,l=0,sg=0,ft=0,st=OK: 695533 !TSF:SND:TNR Power is 5 696369 TSF:MSG:READ,0-0-31,s=255,c=3,t=8,pt=1,l=1,sg=0:0 696434 TSF:MSG:FPAR OK,ID=0,D=1 697548 TSM:FPAR:OK 697565 TSM:ID 697581 TSM:ID:OK 697614 TSM:UPL 697696 TSF:MSG:SEND,31-31-0-0,s=255,c=3,t=24,pt=1,l=1,sg=0,ft=0,st=OK:1 698236 TSF:MSG:READ,0-0-31,s=255,c=3,t=25,pt=1,l=1,sg=0:1 698302 TSF:MSG:PONG RECV,HP=1 698335 TSM:UPL:OK 698351 TSM:READY:ID=31,PAR=0,DIS=1 705593 TSF:MSG:SEND,31-31-0-0,s=22,c=1,t=23,pt=1,l=1,sg=0,ft=0,st=OK:69 Power is 3 715603 TSF:MSG:SEND,31-31-0-0,s=22,c=1,t=23,pt=1,l=1,sg=0,ft=0,st=OK:70 Power is 2 725827 TSF:MSG:SEND,31-31-0-0,s=22,c=1,t=23,pt=1,l=1,sg=0,ft=0,st=OK:71 Power is 1 735641 TSF:MSG:SEND,31-31-0-0,s=22,c=1,t=23,pt=1,l=1,sg=0,ft=0,st=OK:72 Power is 0 745635 TSF:MSG:SEND,31-31-0-0,s=22,c=1,t=23,pt=1,l=1,sg=0,ft=0,st=OK:73 Power is -1 755646 TSF:MSG:SEND,31-31-0-0,s=22,c=1,t=23,pt=1,l=1,sg=0,ft=0,st=OK:74 Power is -2 765657 TSF:MSG:SEND,31-31-0-0,s=22,c=1,t=23,pt=1,l=1,sg=0,ft=0,st=OK:75 Power is -3 775667 TSF:MSG:SEND,31-31-0-0,s=22,c=1,t=23,pt=1,l=1,sg=0,ft=0,st=OK:76 Power is -4 785678 TSF:MSG:SEND,31-31-0-0,s=22,c=1,t=23,pt=1,l=1,sg=0,ft=0,st=OK:77
