Unable to Join OTAA on US915

Hi guys,

My board is a custom board using the RAK4200 module.
Currently talking directly with the RAK4200 to do an OTAA join.
But I’m unable to.

Device will show the following failure to join:
OTAA Join Start…
[LoRa]:Join retry Cnt:1
[LoRa]:Join retry Cnt:2
[LoRa]:Join retry Cnt:3
[LoRa]:Join retry Cnt:4
[LoRa]:Join retry Cnt:5
[LoRa]:Join retry Cnt:6
ERROR: RUI_AT_LORA_INFO_STATUS_JOIN_FAIL 99

However on the TTN console, we can see all the activation packets coming in without fail. This is also reflected on the RAK7258 US915 gateway log. It does seem the node is not receiving the down-link properly during the join process.

Both the frequency channels used on both RAK4200 and gateway are same:
==============LoRaWAN Channel List===============
0,off,902300000,0,3; 1,off,902500000,0,3; 2,off,902700000,0,3; 3,off,902900000,0,3; 4,off,903100000,0,3; 5,off,903300000,0,3; 6,off,903500000,0,3; 7,off,903700000,0,3;
* 8,on,903900000,0,3; * 9,on,904100000,0,3; *10,on,904300000,0,3; *11,on,904500000,0,3; *12,on,904700000,0,3; *13,on,904900000,0,3; *14,on,905100000,0,3; *15,on,905300000,0,3;
16,off,905500000,0,3; 17,off,905700000,0,3; 18,off,905900000,0,3; 19,off,906100000,0,3; 20,off,906300000,0,3; 21,off,906500000,0,3; 22,off,906700000,0,3; 23,off,906900000,0,3;
24,off,907100000,0,3; 25,off,907300000,0,3; 26,off,907500000,0,3; 27,off,907700000,0,3; 28,off,907900000,0,3; 29,off,908100000,0,3; 30,off,908300000,0,3; 31,off,908500000,0,3;
32,off,908700000,0,3; 33,off,908900000,0,3; 34,off,909100000,0,3; 35,off,909300000,0,3; 36,off,909500000,0,3; 37,off,909700000,0,3; 38,off,909900000,0,3; 39,off,910100000,0,3;
40,off,910300000,0,3; 41,off,910500000,0,3; 42,off,910700000,0,3; 43,off,910900000,0,3; 44,off,911100000,0,3; 45,off,911300000,0,3; 46,off,911500000,0,3; 47,off,911700000,0,3;
48,off,911900000,0,3; 49,off,912100000,0,3; 50,off,912300000,0,3; 51,off,912500000,0,3; 52,off,912700000,0,3; 53,off,912900000,0,3; 54,off,913100000,0,3; 55,off,913300000,0,3;
56,off,913500000,0,3; 57,off,913700000,0,3; 58,off,913900000,0,3; 59,off,914100000,0,3; 60,off,914300000,0,3; 61,off,914500000,0,3; 62,off,914700000,0,3; 63,off,914900000,0,3;
64,off,903000000,4,4; 65,off,904600000,4,4; 66,off,906200000,4,4; 67,off,907800000,4,4; 68,off,909400000,4,4; 69,off,911000000,4,4; 70,off,912600000,4,4; 71,off,914200000,4,4
===================List End======================

Firmware Version: RUI v3.2.0.12

Any ideas what could be wrong?

Thanks.

On the TTN console, we can see all the activation packets coming in without fail.
Can you see if they are in the gateway or the node console?And can you give me the configuration here?

Hi Nicholas,

Thanks for the prompt reply.

Yes, I can see them on both gateway and TTN console.

Here are the settings you have requested. The are exact match with the RAK4200 setting.

Is APP_KEY right??You need to identify it!

Yes, they are correct. I copied directly from TTN console.

But, you could see that the gateway did sent the join request acknowledgement to the node. But, it looks like the node is not receiving any of that.

Yes,He did receive it, but it failed because the frequency point was inconsistent.
because the app_key of TTN will change, so it’s best to make sure.

Hi Nicholas,

As I mentioned, app_key is the same.

Can you try connect ABP mode or connect NS?

Hi Nicholas,

ABP is okay, can join and can send data. Data is reflected on TTN console.

One observation. I tried to send confirmed messages to test the downlink using ABP mode. I notice it will need exactly 8 tries (all 8 tries appears on TTN console) for each message for it to receive the downlink. It is always 8. Does that ring a bell to you? Maybe it is sweeping across all 8 channels?

Yes!You can reestablished node is added via otaa mode!!!

Hi Nicholas,

I think you misunderstood my statement. OTAA is still NOT working.

The downlink part I mentioned working will always work BUT only at the 8th try of message transmission. I have try using my other RN2903A based boards, they joined by OTAA without any issues.

@kenyu do you have any idea what is wrong?

You can try the built-in lora server and make sure the gateway is ok!!!

My gateway is okay. RN2903A boards is able to send data all the way to TTN.

How far is the node from the gateway? Is the antenna still connected?

About 2 meters. I have been testing with few hundreds of RN2903A using the same gateway at the same location.

Antenna is connected to the RAK4200.

Edit: Even tried 5 m and in another room also same result.

Have you read this? This is probably where we could find the answer.

OK, I’ll find willing again!

Hi Nicholas,

I added here the gateway traffic on the TTN console for your reference:

Do you think these downlink “join accept” packages is at the correct frequency and anticipated frequency by the RAK4200?

Also, the status of the RAK4200:

==============LoRaWAN Status List================
Work Mode: LoRaWAN
Region: US915
Send_interval: 600s 
Auto send status: false.
Join_mode: OTAA
DevEui: 60C5A8FFFE7540B9
AppEui: 70B3D57EF000512A
AppKey: 7710BD5C0C2FD357E5472191358036CD
Class: A
Joined Network:false
IsConfirm: false
AdrEnable: true
EnableRepeaterSupport: false
RX2_CHANNEL_FREQUENCY: 923300000, RX2_CHANNEL_DR:8
RX_WINDOW_DURATION: 3000ms
RECEIVE_DELAY_1: 1000ms
RECEIVE_DELAY_2: 2000ms
JOIN_ACCEPT_DELAY_1: 5000ms
JOIN_ACCEPT_DELAY_2: 6000ms
Current Datarate: 0
Primeval Datarate: 0
ChannelsTxPower: 0
UpLinkCounter: 0
DownLinkCounter: 0
===================List End======================

I have checked on whether the gateway is transmitting the join-accept package and from the log below, you can see it does transmit them as there’s no TOO_LATE or TX rejected (too late) debug messages in the log. So, we can rule out latency issue. I do think the issue is on the node itself not tuning in at the correct frequency band after transmitting the join-request package. How can we check at what frequency band is the RAK4200 listening to when anticipating the join-accept package from the gateway?

Sun May 10 09:59:49 2020 user.debug lora_pkt_fwd[3144]: 	ED CB 2F BB EF D5 66 08 
Sun May 10 09:59:49 2020 user.debug lora_pkt_fwd[3144]: 	1D 
Sun May 10 09:59:49 2020 user.info lora_pkt_fwd[3144]: INFO: Packet ENQUENUE SUCCESS on sx1301 0
Sun May 10 09:59:50 2020 user.info lora_pkt_fwd[3144]: INFO: [down] PULL_ACK received in 273 ms
Sun May 10 09:59:50 2020 user.info lora_pkt_fwd[3144]: src/lora_pkt_fwd.c:4128:thread_jit(): lgw_send done: count_us=478693060
Sun May 10 09:59:55 2020 user.info lora_pkt_fwd[3144]: INFO: [down] PULL_ACK received in 249 ms
Sun May 10 09:59:56 2020 user.info lora_pkt_fwd[3144]: INFO: Received pkt CRC BAD
Sun May 10 09:59:56 2020 user.debug lora_pkt_fwd[3144]: INFO: [filter] white list join filter is not enable
Sun May 10 09:59:56 2020 user.debug lora_pkt_fwd[3144]: Uplink Frame : 
Sun May 10 09:59:56 2020 user.debug lora_pkt_fwd[3144]: 	00 2A 51 00 F0 7E D5 B3 
Sun May 10 09:59:56 2020 user.debug lora_pkt_fwd[3144]: 	70 B9 40 75 FE FF A8 C5 
Sun May 10 09:59:56 2020 user.debug lora_pkt_fwd[3144]: 	60 22 EA 2D DE 93 DF 
Sun May 10 09:59:56 2020 user.debug lora_pkt_fwd[3144]: rrd_statistic_up 359 uplinkTqByAirtime : dr = 0, timeonair = 370, tm = 1589104796
Sun May 10 09:59:56 2020 user.debug lora_pkt_fwd[3144]: rrd_statistic_up 361 uplinkTqByPkt : dr = 0,  tm = 1589104796
Sun May 10 09:59:56 2020 user.debug lora_pkt_fwd[3144]: rrd_statistic_up 363 ChanBusyByAirtime chan 7, timeonair = 370, tm = 1589104796
Sun May 10 09:59:56 2020 user.info lora_pkt_fwd[3144]: 
JSON up: {"rxpk":[{"tmst":484599028,"chan":7,"rfch":1,"freq":905.300000,"stat":1,"modu":"LORA","datr":"SF10BW125","codr":"4/5","lsnr":9.3,"rssi":-24,"size":23,"data":"ACpRAPB+1bNwuUB1/v+oxWAi6i3ek98="}]}
Sun May 10 09:59:56 2020 user.info lora_pkt_fwd[3144]: WARNING: [up] ignored out-of sync ACK packet
Sun May 10 09:59:57 2020 user.info lora_pkt_fwd[3144]: INFO - packet logger: logread timeout, auto stop
Sun May 10 10:00:00 2020 user.info lora_pkt_fwd[3144]: INFO: [down] PULL_ACK received in 214 ms
Sun May 10 10:00:00 2020 user.info lora_pkt_fwd[3144]: INFO: [down] PULL_RESP received  - token[0:30] :)
Sun May 10 10:00:00 2020 user.info lora_pkt_fwd[3144]: 
JSON down: {"txpk":{"imme":false,"tmst":489599028,"freq":927.5,"rfch":0,"powe":20,"modu":"LORA","datr":"SF10BW500","codr":"4/5","ipol":true,"size":17,"ncrc":true,"data":"IHukY/euf9Gyr1d4duUeoDI="}}
Sun May 10 10:00:00 2020 user.debug lora_pkt_fwd[3144]: DownLink Frame :
Sun May 10 10:00:00 2020 user.debug lora_pkt_fwd[3144]: 	20 7B A4 63 F7 AE 7F D1 
Sun May 10 10:00:00 2020 user.debug lora_pkt_fwd[3144]: 	B2 AF 57 78 76 E5 1E A0 
Sun May 10 10:00:00 2020 user.debug lora_pkt_fwd[3144]: 	32 
Sun May 10 10:00:00 2020 user.info lora_pkt_fwd[3144]: INFO: Packet ENQUENUE SUCCESS on sx1301 0
Sun May 10 10:00:01 2020 user.info lora_pkt_fwd[3144]: src/lora_pkt_fwd.c:4128:thread_jit(): lgw_send done: count_us=489599028
Sun May 10 10:00:05 2020 user.info lora_pkt_fwd[3144]: 
INFO: Disabling GPS mode for concentrator's counter...
Sun May 10 10:00:05 2020 user.info lora_pkt_fwd[3144]: INFO: host/sx1301 time offset=(1589104311s:952240µs) - drift=441µs
Sun May 10 10:00:05 2020 user.info lora_pkt_fwd[3144]: INFO: Enabling GPS mode for concentrator's counter.

Sun May 10 10:00:05 2020 user.notice lora_pkt_fwd[3144]: 
##### 2020-05-10 10:00:05 UTC #####
Sun May 10 10:00:05 2020 user.notice lora_pkt_fwd[3144]: ### [UPSTREAM] ###
Sun May 10 10:00:05 2020 user.notice lora_pkt_fwd[3144]: # RF packets received by concentrator: 3
Sun May 10 10:00:05 2020 user.notice lora_pkt_fwd[3144]: # CRC_OK: 66.67, CRC_FAIL: 33.33, NO_CRC: 0.00
Sun May 10 10:00:05 2020 user.notice lora_pkt_fwd[3144]: # RF packets forwarded: 2 (46 bytes)
Sun May 10 10:00:05 2020 user.notice lora_pkt_fwd[3144]: # PUSH_DATA datagrams sent: 3 (546 bytes)
Sun May 10 10:00:05 2020 user.notice lora_pkt_fwd[3144]: # PUSH_DATA acknowledged: 0.00
Sun May 10 10:00:05 2020 user.notice lora_pkt_fwd[3144]: ### [DOWNSTREAM] ###
Sun May 10 10:00:05 2020 user.notice lora_pkt_fwd[3144]: # PULL_DATA sent: 6 (83.33 acknowledged)
Sun May 10 10:00:05 2020 user.notice lora_pkt_fwd[3144]: # PULL_RESP(onse) datagrams received: 3 (570 bytes)
Sun May 10 10:00:05 2020 user.notice lora_pkt_fwd[3144]: # RF packets sent to concentrator: 3 (51 bytes)
Sun May 10 10:00:05 2020 user.notice lora_pkt_fwd[3144]: # TX errors: 0
Sun May 10 10:00:05 2020 user.notice lora_pkt_fwd[3144]: # TX rejected (collision packet): 0.00 (req:10, rej:0)
Sun May 10 10:00:05 2020 user.notice lora_pkt_fwd[3144]: # TX rejected (collision beacon): 0.00 (req:10, rej:0)
Sun May 10 10:00:05 2020 user.notice lora_pkt_fwd[3144]: # TX rejected (too late): 0.00 (req:10, rej:0)
Sun May 10 10:00:05 2020 user.notice lora_pkt_fwd[3144]: # TX rejected (too early): 0.00 (req:10, rej:0)
Sun May 10 10:00:05 2020 user.notice lora_pkt_fwd[3144]: # BEACON queued: 0
Sun May 10 10:00:05 2020 user.notice lora_pkt_fwd[3144]: # BEACON sent so far: 0
Sun May 10 10:00:05 2020 user.notice lora_pkt_fwd[3144]: # BEACON rejected: 0
Sun May 10 10:00:05 2020 user.notice lora_pkt_fwd[3144]: ### [JIT] ###
Sun May 10 10:00:05 2020 user.notice lora_pkt_fwd[3144]: # SX1301 time (PPS): 493253204, offset us 0
Sun May 10 10:00:05 2020 user.info lora_pkt_fwd[3144]: src/jitqueue.c:456:jit_print_queue(): INFO: [jit] queue is empty
Sun May 10 10:00:05 2020 user.notice lora_pkt_fwd[3144]: ### [GPS] ###
Sun May 10 10:00:05 2020 user.notice lora_pkt_fwd[3144]: # Invalid time reference (age: 1589104805 sec)
Sun May 10 10:00:05 2020 user.notice lora_pkt_fwd[3144]: # no valid GPS coordinates available yet
Sun May 10 10:00:05 2020 user.notice lora_pkt_fwd[3144]: ##### END #####
Sun May 10 10:00:05 2020 user.info lora_pkt_fwd[3144]: 
JSON up: {"stat":{"time":"2020-05-10 10:00:05 UTC","rxnb":3,"rxok":2,"rxfw":2,"ackr":0.0,"dwnb":3,"txnb":3,"cpur":0.0,"memr":0.0}}
Sun May 10 10:00:05 2020 user.info lora_pkt_fwd[3144]: WARNING: [up] ignored out-of sync ACK packet
Sun May 10 10:00:05 2020 user.info lora_pkt_fwd[3144]: INFO: [down] PULL_ACK received in 200 ms
Sun May 10 10:00:07 2020 user.debug lora_pkt_fwd[3144]: INFO: [filter] white list join filter is not enable
Sun May 10 10:00:07 2020 user.debug lora_pkt_fwd[3144]: Uplink Frame : 
Sun May 10 10:00:07 2020 user.debug lora_pkt_fwd[3144]: 	00 2A 51 00 F0 7E D5 B3 
Sun May 10 10:00:07 2020 user.debug lora_pkt_fwd[3144]: 	70 B9 40 75 FE FF A8 C5 
Sun May 10 10:00:07 2020 user.debug lora_pkt_fwd[3144]: 	60 EA DA 33 98 F9 35 
Sun May 10 10:00:07 2020 user.debug lora_pkt_fwd[3144]: rrd_statistic_up 359 uplinkTqByAirtime : dr = 0, timeonair = 370, tm = 1589104807
Sun May 10 10:00:07 2020 user.debug lora_pkt_fwd[3144]: rrd_statistic_up 361 uplinkTqByPkt : dr = 0,  tm = 1589104807
Sun May 10 10:00:07 2020 user.debug lora_pkt_fwd[3144]: rrd_statistic_up 363 ChanBusyByAirtime chan 0, timeonair = 370, tm = 1589104807
Sun May 10 10:00:07 2020 user.info lora_pkt_fwd[3144]: 
JSON up: {"rxpk":[{"tmst":495420908,"chan":0,"rfch":0,"freq":903.900000,"stat":1,"modu":"LORA","datr":"SF10BW125","codr":"4/5","lsnr":9.0,"rssi":-29,"size":23,"data":"ACpRAPB+1bNwuUB1/v+oxWDq2jOY+TU="}]}
Sun May 10 10:00:07 2020 user.info lora_pkt_fwd[3144]: WARNING: [up] ignored out-of sync ACK packet
Sun May 10 10:00:10 2020 user.info lora_pkt_fwd[3144]: INFO: [down] PULL_ACK received in 230 ms
Sun May 10 10:00:11 2020 user.info lora_pkt_fwd[3144]: INFO: [down] PULL_RESP received  - token[0:31] :)
Sun May 10 10:00:11 2020 user.info lora_pkt_fwd[3144]: 
JSON down: {"txpk":{"imme":false,"tmst":500420908,"freq":923.3,"rfch":0,"powe":20,"modu":"LORA","datr":"SF10BW500","codr":"4/5","ipol":true,"size":17,"ncrc":true,"data":"IJLrRauL5Ygon76HA7YwVc4="}}
Sun May 10 10:00:11 2020 user.debug lora_pkt_fwd[3144]: DownLink Frame :
Sun May 10 10:00:11 2020 user.debug lora_pkt_fwd[3144]: 	20 92 EB 45 AB 8B E5 88 
Sun May 10 10:00:11 2020 user.debug lora_pkt_fwd[3144]: 	28 9F BE 87 03 B6 30 55 
Sun May 10 10:00:11 2020 user.debug lora_pkt_fwd[3144]: 	CE 
Sun May 10 10:00:11 2020 user.info lora_pkt_fwd[3144]: INFO: Packet ENQUENUE SUCCESS on sx1301 0
Sun May 10 10:00:12 2020 user.info lora_pkt_fwd[3144]: src/lora_pkt_fwd.c:4128:thread_jit(): lgw_send done: count_us=500420908
Sun May 10 10:00:15 2020 user.info lora_pkt_fwd[3144]: INFO: [down] PULL_ACK received in 213 ms
Sun May 10 10:00:18 2020 user.debug lora_pkt_fwd[3144]: INFO: [filter] white list join filter is not enable
Sun May 10 10:00:18 2020 user.debug lora_pkt_fwd[3144]: Uplink Frame : 
Sun May 10 10:00:18 2020 user.debug lora_pkt_fwd[3144]: 	00 2A 51 00 F0 7E D5 B3 
Sun May 10 10:00:18 2020 user.debug lora_pkt_fwd[3144]: 	70 B9 40 75 FE FF A8 C5 
Sun May 10 10:00:18 2020 user.debug lora_pkt_fwd[3144]: 	60 3D 7A 2E 22 34 95 
Sun May 10 10:00:18 2020 user.debug lora_pkt_fwd[3144]: rrd_statistic_up 359 uplinkTqByAirtime : dr = 0, timeonair = 370, tm = 1589104818
Sun May 10 10:00:18 2020 user.debug lora_pkt_fwd[3144]: rrd_statistic_up 361 uplinkTqByPkt : dr = 0,  tm = 1589104818
Sun May 10 10:00:18 2020 user.debug lora_pkt_fwd[3144]: rrd_statistic_up 363 ChanBusyByAirtime chan 4, timeonair = 370, tm = 1589104818
Sun May 10 10:00:18 2020 user.info lora_pkt_fwd[3144]: 
JSON up: {"rxpk":[{"tmst":506269932,"chan":4,"rfch":1,"freq":904.700000,"stat":1,"modu":"LORA","datr":"SF10BW125","codr":"4/5","lsnr":10.0,"rssi":-30,"size":23,"data":"ACpRAPB+1bNwuUB1/v+oxWA9ei4iNJU="}]}
Sun May 10 10:00:18 2020 user.info lora_pkt_fwd[3144]: WARNING: [up] ignored out-of sync ACK packet
Sun May 10 10:00:20 2020 user.info lora_pkt_fwd[3144]: INFO: [down] PULL_ACK received in 247 ms
Sun May 10 10:00:22 2020 user.info lora_pkt_fwd[3144]: INFO: [down] PULL_RESP received  - token[0:32] :)
Sun May 10 10:00:22 2020 user.info lora_pkt_fwd[3144]: 
JSON down: {"txpk":{"imme":false,"tmst":511269932,"freq":925.7,"rfch":0,"powe":20,"modu":"LORA","datr":"SF10BW500","codr":"4/5","ipol":true,"size":17,"ncrc":true,"data":"IPbeQu5iyNKd+rCopmkO9J8="}}
Sun May 10 10:00:22 2020 user.debug lora_pkt_fwd[3144]: DownLink Frame :
Sun May 10 10:00:22 2020 user.debug lora_pkt_fwd[3144]: 	20 F6 DE 42 EE 62 C8 D2 
Sun May 10 10:00:22 2020 user.debug lora_pkt_fwd[3144]: 	9D FA B0 A8 A6 69 0E F4 
Sun May 10 10:00:22 2020 user.debug lora_pkt_fwd[3144]: 	9F 
Sun May 10 10:00:22 2020 user.info lora_pkt_fwd[3144]: INFO: Packet ENQUENUE SUCCESS on sx1301 0
Sun May 10 10:00:23 2020 user.info lora_pkt_fwd[3144]: src/lora_pkt_fwd.c:4128:thread_jit(): lgw_send done: count_us=511269932
Sun May 10 10:00:25 2020 user.info lora_pkt_fwd[3144]: INFO: [down] PULL_ACK received in 227 ms
Sun May 10 10:00:29 2020 user.debug lora_pkt_fwd[3144]: INFO: [filter] white list join filter is not enable
Sun May 10 10:00:29 2020 user.debug lora_pkt_fwd[3144]: Uplink Frame : 
Sun May 10 10:00:29 2020 user.debug lora_pkt_fwd[3144]: 	00 2A 51 00 F0 7E D5 B3 
Sun May 10 10:00:29 2020 user.debug lora_pkt_fwd[3144]: 	70 B9 40 75 FE FF A8 C5 
Sun May 10 10:00:29 2020 user.debug lora_pkt_fwd[3144]: 	60 6C 8A BC E3 19 FB 
Sun May 10 10:00:29 2020 user.debug lora_pkt_fwd[3144]: rrd_statistic_up 359 uplinkTqByAirtime : dr = 0, timeonair = 370, tm = 1589104829
Sun May 10 10:00:29 2020 user.debug lora_pkt_fwd[3144]: rrd_statistic_up 361 uplinkTqByPkt : dr = 0,  tm = 1589104829
Sun May 10 10:00:29 2020 user.debug lora_pkt_fwd[3144]: rrd_statistic_up 363 ChanBusyByAirtime chan 5, timeonair = 370, tm = 1589104829
Sun May 10 10:00:29 2020 user.info lora_pkt_fwd[3144]: 
JSON up: {"rxpk":[{"tmst":517179100,"chan":5,"rfch":1,"freq":904.900000,"stat":1,"modu":"LORA","datr":"SF10BW125","codr":"4/5","lsnr":11.0,"rssi":-28,"size":23,"data":"ACpRAPB+1bNwuUB1/v+oxWBsirzjGfs="}]}
Sun May 10 10:00:29 2020 user.info lora_pkt_fwd[3144]: WARNING: [up] ignored out-of sync ACK packet
Sun May 10 10:00:30 2020 user.info lora_pkt_fwd[3144]: INFO: [down] PULL_ACK received in 243 ms
Sun May 10 10:00:33 2020 user.info lora_pkt_fwd[3144]: INFO: [down] PULL_RESP received  - token[0:33] :)
Sun May 10 10:00:33 2020 user.info lora_pkt_fwd[3144]: 
JSON down: {"txpk":{"imme":false,"tmst":522179100,"freq":926.3,"rfch":0,"powe":20,"modu":"LORA","datr":"SF10BW500","codr":"4/5","ipol":true,"size":17,"ncrc":true,"data":"IKgHuxRea2lMbmOhFfvrwSw="}}
Sun May 10 10:00:33 2020 user.debug lora_pkt_fwd[3144]: DownLink Frame :
Sun May 10 10:00:33 2020 user.debug lora_pkt_fwd[3144]: 	20 A8 07 BB 14 5E 6B 69 
Sun May 10 10:00:33 2020 user.debug lora_pkt_fwd[3144]: 	4C 6E 63 A1 15 FB EB C1 
Sun May 10 10:00:33 2020 user.debug lora_pkt_fwd[3144]: 	2C 
Sun May 10 10:00:33 2020 user.info lora_pkt_fwd[3144]: INFO: Packet ENQUENUE SUCCESS on sx1301 0
Sun May 10 10:00:34 2020 user.info lora_pkt_fwd[3144]: src/lora_pkt_fwd.c:4128:thread_jit(): lgw_send done: count_us=522179100
Sun May 10 10:00:35 2020 user.notice lora_pkt_fwd[3144]: 
##### 2020-05-10 10:00:35 UTC #####
Sun May 10 10:00:35 2020 user.notice lora_pkt_fwd[3144]: ### [UPSTREAM] ###
Sun May 10 10:00:35 2020 user.notice lora_pkt_fwd[3144]: # RF packets received by concentrator: 3
Sun May 10 10:00:35 2020 user.notice lora_pkt_fwd[3144]: # CRC_OK: 100.00, CRC_FAIL: 0.00, NO_CRC: 0.00
Sun May 10 10:00:35 2020 user.notice lora_pkt_fwd[3144]: # RF packets forwarded: 3 (69 bytes)
Sun May 10 10:00:35 2020 user.notice lora_pkt_fwd[3144]: # PUSH_DATA datagrams sent: 4 (753 bytes)
Sun May 10 10:00:35 2020 user.notice lora_pkt_fwd[3144]: # PUSH_DATA acknowledged: 0.00
Sun May 10 10:00:35 2020 user.notice lora_pkt_fwd[3144]: ### [DOWNSTREAM] ###
Sun May 10 10:00:35 2020 user.notice lora_pkt_fwd[3144]: # PULL_DATA sent: 5 (120.00 acknowledged)
Sun May 10 10:00:35 2020 user.notice lora_pkt_fwd[3144]: # PULL_RESP(onse) datagrams received: 3 (570 bytes)
Sun May 10 10:00:35 2020 user.notice lora_pkt_fwd[3144]: # RF packets sent to concentrator: 3 (51 bytes)
Sun May 10 10:00:35 2020 user.notice lora_pkt_fwd[3144]: # TX rejected (collision packet): 0.00 (req:13, rej:0)
Sun May 10 10:00:35 2020 user.notice lora_pkt_fwd[3144]: # TX rejected (collision beacon): 0.00 (req:13, rej:0)
Sun May 10 10:00:35 2020 user.notice lora_pkt_fwd[3144]: # TX rejected (too late): 0.00 (req:13, rej:0)
Sun May 10 10:00:35 2020 user.notice lora_pkt_fwd[3144]: # TX rejected (too early): 0.00 (req:13, rej:0)
Sun May 10 10:00:35 2020 user.notice lora_pkt_fwd[3144]: # BEACON queued: 0
Sun May 10 10:00:35 2020 user.notice lora_pkt_fwd[3144]: # BEACON sent so far: 0
Sun May 10 10:00:35 2020 user.notice lora_pkt_fwd[3144]: # BEACON rejected: 0
Sun May 10 10:00:35 2020 user.notice lora_pkt_fwd[3144]: ### [JIT] ###
Sun May 10 10:00:35 2020 user.notice lora_pkt_fwd[3144]: # SX1301 time (PPS): 493253204, offset us 0
Sun May 10 10:00:35 2020 user.info lora_pkt_fwd[3144]: src/jitqueue.c:456:jit_print_queue(): INFO: [jit] queue is empty
Sun May 10 10:00:35 2020 user.notice lora_pkt_fwd[3144]: ### [GPS] ###
Sun May 10 10:00:35 2020 user.notice lora_pkt_fwd[3144]: # Invalid time reference (age: 1589104835 sec)
Sun May 10 10:00:35 2020 user.notice lora_pkt_fwd[3144]: # no valid GPS coordinates available yet
Sun May 10 10:00:35 2020 user.notice lora_pkt_fwd[3144]: ##### END #####
Sun May 10 10:00:35 2020 user.info lora_pkt_fwd[3144]: 
JSON up: {"stat":{"time":"2020-05-10 10:00:35 UTC","rxnb":3,"rxok":3,"rxfw":3,"ackr":0.0,"dwnb":3,"txnb":3,"cpur":0.0,"memr":0.0}}
Sun May 10 10:00:35 2020 user.info lora_pkt_fwd[3144]: WARNING: [up] ignored out-of sync ACK packet
Sun May 10 10:00:36 2020 user.info lora_pkt_fwd[3144]: INFO: [down] PULL_ACK received in 239 ms
Sun May 10 10:00:40 2020 user.info lora_pkt_fwd[3144]: INFO: Received pkt CRC BAD
Sun May 10 10:00:40 2020 user.debug lora_pkt_fwd[3144]: INFO: [filter] white list join filter is not enable
Sun May 10 10:00:40 2020 user.debug lora_pkt_fwd[3144]: Uplink Frame : 
Sun May 10 10:00:40 2020 user.debug lora_pkt_fwd[3144]: 	00 2A 51 00 F0 7E D5 B3 
Sun May 10 10:00:40 2020 user.debug lora_pkt_fwd[3144]: 	70 B9 40 75 FE FF A8 C5 
Sun May 10 10:00:40 2020 user.debug lora_pkt_fwd[3144]: 	60 98 90 89 F1 69 DE 
Sun May 10 10:00:40 2020 user.debug lora_pkt_fwd[3144]: rrd_statistic_up 359 uplinkTqByAirtime : dr = 0, timeonair = 370, tm = 1589104840
Sun May 10 10:00:40 2020 user.debug lora_pkt_fwd[3144]: rrd_statistic_up 361 uplinkTqByPkt : dr = 0,  tm = 1589104840
Sun May 10 10:00:40 2020 user.debug lora_pkt_fwd[3144]: rrd_statistic_up 363 ChanBusyByAirtime chan 2, timeonair = 370, tm = 1589104840
Sun May 10 10:00:40 2020 user.info lora_pkt_fwd[3144]: 
JSON up: {"rxpk":[{"tmst":528089940,"chan":2,"rfch":0,"freq":904.300000,"stat":1,"modu":"LORA","datr":"SF10BW125","codr":"4/5","lsnr":7.3,"rssi":-27,"size":23,"data":"ACpRAPB+1bNwuUB1/v+oxWCYkInxad4="}]}
Sun May 10 10:00:40 2020 user.info lora_pkt_fwd[3144]: WARNING: [up] ignored out-of sync ACK packet
Sun May 10 10:00:41 2020 user.info lora_pkt_fwd[3144]: INFO: [down] PULL_ACK received in 240 ms
Sun May 10 10:00:44 2020 user.info lora_pkt_fwd[3144]: INFO: [down] PULL_RESP received  - token[0:34] :)
Sun May 10 10:00:44 2020 user.info lora_pkt_fwd[3144]: 
JSON down: {"txpk":{"imme":false,"tmst":533089940,"freq":924.5,"rfch":0,"powe":20,"modu":"LORA","datr":"SF10BW500","codr":"4/5","ipol":true,"size":17,"ncrc":true,"data":"IKHlBqmpXZKjEoE7gHB4YdQ="}}
Sun May 10 10:00:44 2020 user.debug lora_pkt_fwd[3144]: DownLink Frame :
Sun May 10 10:00:44 2020 user.debug lora_pkt_fwd[3144]: 	20 A1 E5 06 A9 A9 5D 92 
Sun May 10 10:00:44 2020 user.debug lora_pkt_fwd[3144]: 	A3 12 81 3B 80 70 78 61 
Sun May 10 10:00:44 2020 user.debug lora_pkt_fwd[3144]: 	D4 
Sun May 10 10:00:44 2020 user.info lora_pkt_fwd[3144]: INFO: Packet ENQUENUE SUCCESS on sx1301 0
Sun May 10 10:00:45 2020 user.info lora_pkt_fwd[3144]: src/lora_pkt_fwd.c:4128:thread_jit(): lgw_send done: count_us=533089940
Sun May 10 10:00:46 2020 user.info lora_pkt_fwd[3144]: INFO: [down] PULL_ACK received in 247 ms
Sun May 10 10:00:51 2020 user.info lora_pkt_fwd[3144]: INFO: [down] PULL_ACK received in 239 ms