RAK2245 - Downlink rejected

LPWAN Developer Gateways / Concentrators RAK2245 / RAK2243
1

Issue:
All downlink messages are rejected by the gatewa., Some are tagged as “too late” and some as “too early”.

Setup:
Gateway RAK2245:
image

Server:
TTN

Details:
The image below is the downlink pkg sent by Node-RED:

image

We can see all the trafic on the TTN console and on the GW log file.
image
image
image
image

Feb 21 10:03:37 rak-gateway systemd[1]: Started The Things Network Gateway.
Feb 21 10:04:05 rak-gateway ttn-gateway[1856]: *** Beacon Packet Forwarder for Lora Gateway ***
Feb 21 10:04:05 rak-gateway ttn-gateway[1856]: Version: 4.0.1
Feb 21 10:04:05 rak-gateway ttn-gateway[1856]: *** Lora concentrator HAL library version info ***
Feb 21 10:04:05 rak-gateway ttn-gateway[1856]: Version: 5.0.1;
Feb 21 10:04:05 rak-gateway ttn-gateway[1856]: ***
Feb 21 10:04:05 rak-gateway ttn-gateway[1856]: INFO: Little endian host
Feb 21 10:04:05 rak-gateway ttn-gateway[1856]: INFO: found global configuration file global_conf.json, parsing it
Feb 21 10:04:05 rak-gateway ttn-gateway[1856]: INFO: global_conf.json does contain a JSON object named SX1301_conf, parsing SX1301 parameters
Feb 21 10:04:05 rak-gateway ttn-gateway[1856]: INFO: lorawan_public 1, clksrc 1
Feb 21 10:04:05 rak-gateway ttn-gateway[1856]: INFO: no configuration for LBT
Feb 21 10:04:05 rak-gateway ttn-gateway[1856]: INFO: antenna_gain 0 dBi
Feb 21 10:04:05 rak-gateway ttn-gateway[1856]: INFO: Configuring TX LUT with 16 indexes
Feb 21 10:04:05 rak-gateway ttn-gateway[1856]: INFO: radio 0 enabled (type SX1257), center frequency 917200000, RSSI offset -166.000000, tx enabled 1, tx_notch_freq 0
Feb 21 10:04:05 rak-gateway ttn-gateway[1856]: INFO: radio 1 enabled (type SX1257), center frequency 917900000, RSSI offset -166.000000, tx enabled 0, tx_notch_freq 0
Feb 21 10:04:05 rak-gateway ttn-gateway[1856]: INFO: Lora multi-SF channel 0> radio 0, IF -400000 Hz, 125 kHz bw, SF 7 to 12
Feb 21 10:04:05 rak-gateway ttn-gateway[1856]: INFO: Lora multi-SF channel 1> radio 0, IF -200000 Hz, 125 kHz bw, SF 7 to 12
Feb 21 10:04:05 rak-gateway ttn-gateway[1856]: INFO: Lora multi-SF channel 2> radio 0, IF 0 Hz, 125 kHz bw, SF 7 to 12
Feb 21 10:04:05 rak-gateway ttn-gateway[1856]: INFO: Lora multi-SF channel 3> radio 0, IF 200000 Hz, 125 kHz bw, SF 7 to 12
Feb 21 10:04:05 rak-gateway ttn-gateway[1856]: INFO: Lora multi-SF channel 4> radio 1, IF -300000 Hz, 125 kHz bw, SF 7 to 12
Feb 21 10:04:05 rak-gateway ttn-gateway[1856]: INFO: Lora multi-SF channel 5> radio 1, IF -100000 Hz, 125 kHz bw, SF 7 to 12
Feb 21 10:04:05 rak-gateway ttn-gateway[1856]: INFO: Lora multi-SF channel 6> radio 1, IF 100000 Hz, 125 kHz bw, SF 7 to 12
Feb 21 10:04:05 rak-gateway ttn-gateway[1856]: INFO: Lora multi-SF channel 7> radio 1, IF 300000 Hz, 125 kHz bw, SF 7 to 12
Feb 21 10:04:05 rak-gateway ttn-gateway[1856]: INFO: Lora std channel> radio 0, IF 300000 Hz, 500000 Hz bw, SF 8
Feb 21 10:04:05 rak-gateway ttn-gateway[1856]: INFO: FSK channel 8 disabled
Feb 21 10:04:05 rak-gateway ttn-gateway[1856]: INFO: global_conf.json does contain a JSON object named gateway_conf, parsing gateway parameters
Feb 21 10:04:05 rak-gateway ttn-gateway[1856]: INFO: gateway MAC address is configured to B827EBFFFEFFEC56
Feb 21 10:04:05 rak-gateway ttn-gateway[1856]: INFO: server hostname or IP address is configured to “router.au.thethings.network”
Feb 21 10:04:05 rak-gateway ttn-gateway[1856]: INFO: upstream port is configured to “1700”
Feb 21 10:04:05 rak-gateway ttn-gateway[1856]: INFO: downstream port is configured to “1700”
Feb 21 10:04:05 rak-gateway ttn-gateway[1856]: INFO: downstream keep-alive interval is configured to 10 seconds
Feb 21 10:04:05 rak-gateway ttn-gateway[1856]: INFO: statistics display interval is configured to 30 seconds
Feb 21 10:04:05 rak-gateway ttn-gateway[1856]: INFO: upstream PUSH_DATA time-out is configured to 100 ms
Feb 21 10:04:05 rak-gateway ttn-gateway[1856]: INFO: packets received with a valid CRC will be forwarded
Feb 21 10:04:05 rak-gateway ttn-gateway[1856]: INFO: packets received with a CRC error will NOT be forwarded
Feb 21 10:04:05 rak-gateway ttn-gateway[1856]: INFO: packets received with no CRC will NOT be forwarded
Feb 21 10:04:05 rak-gateway ttn-gateway[1856]: INFO: GPS serial port path is configured to “/dev/ttyAMA0”
Feb 21 10:04:05 rak-gateway ttn-gateway[1856]: INFO: Reference latitude is configured to 10.000000 deg
Feb 21 10:04:05 rak-gateway ttn-gateway[1856]: INFO: Reference longitude is configured to 20.000000 deg
Feb 21 10:04:05 rak-gateway ttn-gateway[1856]: INFO: Reference altitude is configured to -1 meters
Feb 21 10:04:05 rak-gateway ttn-gateway[1856]: INFO: fake GPS is disabled
Feb 21 10:04:05 rak-gateway ttn-gateway[1856]: INFO: Auto-quit after 20 non-acknowledged PULL_DATA
Feb 21 10:04:05 rak-gateway ttn-gateway[1856]: INFO: found local configuration file local_conf.json, parsing it
Feb 21 10:04:05 rak-gateway ttn-gateway[1856]: INFO: redefined parameters will overwrite global parameter
Feb 21 10:04:05 rak-gateway ttn-gateway[1856]: INFO: local_conf.json does not contain a JSON object named SX1301_conf
Feb 21 10:04:05 rak-gateway ttn-gateway[1856]: INFO: local_conf.json does contain a JSON object named gateway_conf, parsing gateway parameters
Feb 21 10:04:05 rak-gateway ttn-gateway[1856]: INFO: gateway MAC address is configured to XX
Feb 21 10:04:05 rak-gateway ttn-gateway[1856]: INFO: packets received with a valid CRC will be forwarded
Feb 21 10:04:05 rak-gateway ttn-gateway[1856]: INFO: packets received with a CRC error will NOT be forwarded
Feb 21 10:04:05 rak-gateway ttn-gateway[1856]: INFO: packets received with no CRC will NOT be forwarded
Feb 21 10:04:05 rak-gateway ttn-gateway[1856]: INFO: [main] TTY port /dev/ttyAMA0 open for GPS synchronization
Feb 21 10:04:05 rak-gateway ttn-gateway[1856]: INFO: [main] concentrator started, packet can now be received
Feb 21 10:04:05 rak-gateway ttn-gateway[1856]: INFO: Disabling GPS mode for concentrator’s counter…
Feb 21 10:04:05 rak-gateway ttn-gateway[1856]: INFO: host/sx1301 time offset=(1613912619s:32788µs) - drift=1348149460µs
Feb 21 10:04:05 rak-gateway ttn-gateway[1856]: INFO: Enabling GPS mode for concentrator’s counter.
Feb 21 10:04:05 rak-gateway ttn-gateway[1856]: WARNING: [gps] GPS out of sync, keeping previous time reference
Feb 21 10:04:05 rak-gateway ttn-gateway[1856]: WARNING: [gps] GPS out of sync, keeping previous time reference
Feb 21 10:04:05 rak-gateway ttn-gateway[1856]: INFO: [modify_os_time] local_time=1613912621, gps_time=1613912620
Feb 21 10:04:05 rak-gateway ttn-gateway[1856]: INFO: [modify_os_time] The difference between the system time(1613912621) and the GPS time(1613912620) is less than 10 seconds. Use the system time.
Feb 21 10:04:05 rak-gateway ttn-gateway[1856]: INFO: [down] PULL_ACK received in 473 ms
Feb 21 10:04:05 rak-gateway ttn-gateway[1856]: INFO: [down] PULL_ACK received in 468 ms
Feb 21 10:04:05 rak-gateway ttn-gateway[1856]: INFO: [down] PULL_ACK received in 456 ms
Feb 21 10:04:05 rak-gateway ttn-gateway[1856]: INFO: Received pkt from mote: 26032F18 (fcnt=34)
Feb 21 10:04:05 rak-gateway ttn-gateway[1856]: JSON up: {“rxpk”:[{“tmst”:25818521,“time”:“2021-02-21T13:04:03.833868Z”,“tmms”:1297947862834,“chan”:8,“rfch”:0,“freq”:917.500000,“stat”:1,“modu”:“LORA”,“datr”:“SF8BW500”,“codr”:“4/5”,“lsnr”:11.0,“rssi”:-80,“size”:27,“data”:“QBgvAyYAIgABtt3eNvjIDPLv9JyF+HwCF1Fl”}]}
Feb 21 10:04:05 rak-gateway ttn-gateway[1856]: INFO: [down] PULL_RESP received - token[0:247] :slight_smile:
Feb 21 10:04:52 rak-gateway ttn-gateway[1856]: JSON down: {“txpk”:{“imme”:false,“tmst”:26818521,“freq”:923.9,“rfch”:0,“powe”:20,“modu”:“LORA”,“datr”:“SF7BW500”,“codr”:“4/5”,“ipol”:true,“size”:22,“ncrc”:true,“data”:“oBgvAyYAIAABxOUGVVjn6qJlxbY8sQ==”}}
Feb 21 10:04:52 rak-gateway ttn-gateway[1856]: INFO: == used txlut index:11
Feb 21 10:04:52 rak-gateway ttn-gateway[1856]: src/jitqueue.c:251:jit_enqueue(): ERROR: Packet REJECTED, timestamp seems wrong, too much in advance (current=26836065, packet=26818521, type=0)
Feb 21 10:04:52 rak-gateway ttn-gateway[1856]: ERROR: Packet REJECTED (jit error=2)
Feb 21 10:04:52 rak-gateway ttn-gateway[1856]: ##### 2021-02-21 13:04:11 GMT #####
Feb 21 10:04:52 rak-gateway ttn-gateway[1856]: ### [UPSTREAM] ###
Feb 21 10:04:52 rak-gateway ttn-gateway[1856]: # RF packets received by concentrator: 1
Feb 21 10:04:52 rak-gateway ttn-gateway[1856]: # CRC_OK: 100.00%, CRC_FAIL: 0.00%, NO_CRC: 0.00%
Feb 21 10:04:52 rak-gateway ttn-gateway[1856]: # RF packets forwarded: 1 (27 bytes)
Feb 21 10:04:52 rak-gateway ttn-gateway[1856]: # PUSH_DATA datagrams sent: 1 (267 bytes)
Feb 21 10:04:52 rak-gateway ttn-gateway[1856]: # PUSH_DATA acknowledged: 0.00%
Feb 21 10:04:52 rak-gateway ttn-gateway[1856]: ### [DOWNSTREAM] ###
Feb 21 10:04:52 rak-gateway ttn-gateway[1856]: # PULL_DATA sent: 3 (100.00% acknowledged)
Feb 21 10:04:52 rak-gateway ttn-gateway[1856]: # PULL_RESP(onse) datagrams received: 1 (196 bytes)
Feb 21 10:04:52 rak-gateway ttn-gateway[1856]: # RF packets sent to concentrator: 0 (22 bytes)
Feb 21 10:04:52 rak-gateway ttn-gateway[1856]: # TX errors: 0
Feb 21 10:04:52 rak-gateway ttn-gateway[1856]: # TX rejected (collision packet): 0.00% (req:1, rej:0)
Feb 21 10:04:52 rak-gateway ttn-gateway[1856]: # TX rejected (collision beacon): 0.00% (req:1, rej:0)
Feb 21 10:04:52 rak-gateway ttn-gateway[1856]: # TX rejected (too late): 0.00% (req:1, rej:0)
Feb 21 10:04:52 rak-gateway ttn-gateway[1856]: # TX rejected (too early): 100.00% (req:1, rej:1)
Feb 21 10:04:52 rak-gateway ttn-gateway[1856]: # BEACON queued: 0
Feb 21 10:04:52 rak-gateway ttn-gateway[1856]: # BEACON sent so far: 0
Feb 21 10:04:53 rak-gateway ttn-gateway[1856]: # BEACON rejected: 0
Feb 21 10:04:53 rak-gateway ttn-gateway[1856]: ### [JIT] ###
Feb 21 10:04:53 rak-gateway ttn-gateway[1856]: # SX1301 time (PPS): 31984653
Feb 21 10:04:53 rak-gateway ttn-gateway[1856]: src/jitqueue.c:448:jit_print_queue(): INFO: [jit] queue is empty
Feb 21 10:04:53 rak-gateway ttn-gateway[1856]: ### [GPS] ###
Feb 21 10:04:53 rak-gateway ttn-gateway[1856]: # Valid time reference (age: 0 sec)
Feb 21 10:04:53 rak-gateway ttn-gateway[1856]: # GPS coordinates: latitude -23.61261, longitude -46.66370, altitude 804 m
Feb 21 10:04:53 rak-gateway ttn-gateway[1856]: ##### END #####
Feb 21 10:04:53 rak-gateway ttn-gateway[1856]: JSON up: {“stat”:{“time”:“2021-02-21 13:04:11 GMT”,“lati”:-23.61261,“long”:-46.66370,“alti”:804,“rxnb”:1,“rxok”:1,“rxfw”:1,“ackr”:0.0,“dwnb”:1,“txnb”:0}}
Feb 21 10:04:53 rak-gateway ttn-gateway[1856]: INFO: [down] PULL_ACK received in 483 ms
Feb 21 10:04:53 rak-gateway ttn-gateway[1856]: INFO: [down] PULL_ACK received in 460 ms
Feb 21 10:04:53 rak-gateway ttn-gateway[1856]: INFO: [down] PULL_ACK received in 478 ms
Feb 21 10:04:53 rak-gateway ttn-gateway[1856]: INFO: Received pkt from mote: 26032F18 (fcnt=35)
Feb 21 10:04:53 rak-gateway ttn-gateway[1856]: JSON up: {“rxpk”:[{“tmst”:57928481,“time”:“2021-02-21T13:04:35.943825Z”,“tmms”:1297947894944,“chan”:8,“rfch”:0,“freq”:917.500000,“stat”:1,“modu”:“LORA”,“datr”:“SF8BW500”,“codr”:“4/5”,“lsnr”:10.5,“rssi”:-77,“size”:27,“data”:“QBgvAyYAIwAB9+CwAP4FUzyt7kLXioG+UIne”}]}
Feb 21 10:04:53 rak-gateway ttn-gateway[1856]: INFO: [down] PULL_RESP received - token[0:248] :slight_smile:
Feb 21 10:04:53 rak-gateway ttn-gateway[1856]: JSON down: {“txpk”:{“imme”:false,“tmst”:58928481,“freq”:923.9,“rfch”:0,“powe”:20,“modu”:“LORA”,“datr”:“SF7BW500”,“codr”:“4/5”,“ipol”:true,“size”:22,“ncrc”:true,“data”:“oBgvAyYAIQABzJGLOrjISq2Vv5WUTA==”}}
Feb 21 10:04:53 rak-gateway ttn-gateway[1856]: INFO: == used txlut index:11
Feb 21 10:04:53 rak-gateway ttn-gateway[1856]: src/jitqueue.c:251:jit_enqueue(): ERROR: Packet REJECTED, timestamp seems wrong, too much in advance (current=58982805, packet=58928481, type=0)
Feb 21 10:04:53 rak-gateway ttn-gateway[1856]: ERROR: Packet REJECTED (jit error=2)
Feb 21 10:04:53 rak-gateway ttn-gateway[1856]: INFO: Disabling GPS mode for concentrator’s counter…
Feb 21 10:04:53 rak-gateway ttn-gateway[1856]: ##### 2021-02-21 13:04:41 GMT #####
Feb 21 10:04:53 rak-gateway ttn-gateway[1856]: ### [UPSTREAM] ###
Feb 21 10:04:53 rak-gateway ttn-gateway[1856]: # RF packets received by concentrator: 1
Feb 21 10:04:53 rak-gateway ttn-gateway[1856]: # CRC_OK: 100.00%, CRC_FAIL: 0.00%, NO_CRC: 0.00%
Feb 21 10:04:53 rak-gateway ttn-gateway[1856]: # RF packets forwarded: 1 (27 bytes)
Feb 21 10:04:53 rak-gateway ttn-gateway[1856]: # PUSH_DATA datagrams sent: 2 (423 bytes)
Feb 21 10:04:53 rak-gateway ttn-gateway[1856]: # PUSH_DATA acknowledged: 0.00%
Feb 21 10:04:53 rak-gateway ttn-gateway[1856]: ### [DOWNSTREAM] ###
Feb 21 10:04:53 rak-gateway ttn-gateway[1856]: # PULL_DATA sent: 3 (100.00% acknowledged)
Feb 21 10:04:53 rak-gateway ttn-gateway[1856]: # PULL_RESP(onse) datagrams received: 1 (196 bytes)
Feb 21 10:04:53 rak-gateway ttn-gateway[1856]: # RF packets sent to concentrator: 0 (22 bytes)
Feb 21 10:04:53 rak-gateway ttn-gateway[1856]: # TX errors: 0
Feb 21 10:04:53 rak-gateway ttn-gateway[1856]: # TX rejected (collision packet): 0.00% (req:2, rej:0)
Feb 21 10:04:53 rak-gateway ttn-gateway[1856]: # TX rejected (collision beacon): 0.00% (req:2, rej:0)
Feb 21 10:04:53 rak-gateway ttn-gateway[1856]: # TX rejected (too late): 0.00% (req:2, rej:0)
Feb 21 10:04:53 rak-gateway ttn-gateway[1856]: # TX rejected (too early): 100.00% (req:2, rej:2)
Feb 21 10:04:53 rak-gateway ttn-gateway[1856]: # BEACON queued: 0
Feb 21 10:04:53 rak-gateway ttn-gateway[1856]: # BEACON sent so far: 0
Feb 21 10:04:53 rak-gateway ttn-gateway[1856]: INFO: host/sx1301 time offset=(1613912619s:32774µs) - drift=-14µs
Feb 21 10:04:53 rak-gateway ttn-gateway[1856]: INFO: Enabling GPS mode for concentrator’s counter.
Feb 21 10:04:53 rak-gateway ttn-gateway[1856]: # BEACON rejected: 0
Feb 21 10:04:53 rak-gateway ttn-gateway[1856]: ### [JIT] ###
Feb 21 10:04:53 rak-gateway ttn-gateway[1856]: # SX1301 time (PPS): 62657967
Feb 21 10:04:53 rak-gateway ttn-gateway[1856]: src/jitqueue.c:448:jit_print_queue(): INFO: [jit] queue is empty
Feb 21 10:04:53 rak-gateway ttn-gateway[1856]: ### [GPS] ###
Feb 21 10:04:53 rak-gateway ttn-gateway[1856]: # Valid time reference (age: 0 sec)
Feb 21 10:04:53 rak-gateway ttn-gateway[1856]: # GPS coordinates: latitude -23.61261, longitude -46.66369, altitude 805 m
Feb 21 10:04:53 rak-gateway ttn-gateway[1856]: ##### END #####

I tested it with two Heltec ESP32 Lora with 6m and 40m distance from de GW and the behavior was the same. All downlink pkg are rejected.

On the node I’m using the library below, setting the channels for Brazil (same as Australia).

image

image

Am I doing something wrong or it is a bug?

2

It would appear that either your Internet backhaul or the TTN infrastructure is not operating quickly enough to meet LoRaWAN timing requirements.

This message is a little bit confusing, because by “too much in advance” it really means “too late”. The microsecond counter against which packets are timed rolls over at 32 bits, so values in the recent past are treated as being absurdly early for when that count would again be reached in the future.

In this case, in response to an uplink packet ending at:

25818521 uS

The gateway is being asked to transmit exactly 1 second (1000000 uS) later at:

26818521 uS

But it’s not receiving or processing that request until

26836065 uS

Which is to say about 18 milliseconds too late - arguably “just missed” but really you want to be seeing things getting there hundreds of milliseconds in advance of need.

Allowing for routing delay through infrastructure of growing complexity is part of why TTN appears to be moving to a 5-second RX window in their newer V3 setup. Perhaps you’d do better registering your gateway with the new TTN version rather than the old one which it sounds like they are going to be phasing out anyway.

3

Thank you for the awnser, Chris

Infact, in this log sample all cases were “too early”, which is the most frequent rejection reason.

For this specifc issue, I’m not sure if V3 will help, since the GW is receiving the pkg on time.

4

It’s not receiving it on time, it is receiving it too late - it’s just the rolling nature of the counter causes that to misleadingly be reported as too early for the next time the requested value would be reached after the counter loops around. If Semtech’s reference code were a little bit smarter, it would consider anything a half rolling period below the current count to be late and anything more than that to be early.

TTN V3’s switch to a 5 second uplink-downlink delay and assumption of a queue in the gateway drastically increases the amount of time allowable for the downlink packet to get through the infrastructure and Internet to the gateway.

5

Wow, I’m not aware that.
Thank you Chris

I will move to V3 and post the result here

6

It worked as you told, Chris.

I moved the GW and one node to V3 and it is working. :smiley:

Thank you again!

7

This topic was automatically closed 2 days after the last reply. New replies are no longer allowed.