OTAA Join Accept not received by Arduino/STM32 LMiC node through iC880A RPi 3 gateway

End Devices (Nodes)
1

I am currently playing around with LoRaWAN and TTN and try to getting SX1272 Modem (DRF1272F) to work.
I implemented the LMiC Stack on both systems, the STM32L0 and Arduino Mega (with arduino-lmic by matthijskooijman). When otaa join starts the device gets registered in the ttn console but i never receive the join accept back on my node. So with both MCU’s the join hangs up after EV_JOINING event.
I fiddled around with the timer settings and the LMIC_setClockError() function without any change.

Could it be possible that this is a problem on the gateway’s side? Or are there any other possibilites that cause those problem? (In the forum i also found problems/solutions regarding the datarate in the RX1 and RX2 windows that weren’t LoRa compliant but according to the changelog they resolved that a while ago so it couldn’t be the source of my problem).

2

Following earlier debugging in OTAA ok, 12h later I get denied, reboot gateway –> OK again …!?, this might be related to your gateway receiving the Join Accept too late, due to network lag.

So:

  1. What gateway?

  2. How is it connected?

  3. Any firewall?

  4. What does a ping to some other server like google.com give you?

  5. Can you peek into its logs to check the timestamps (as explained in the other post, like for a successful join)?

3

@arjanvanb

  1. Gateway is the iC880A and RPi 3 from IMST configured with the tools from here: https://github.com/ttn-zh/ic880a-gateway
  2. Board over SPI, RPi over LAN.
  3. Yes, but tried it also with disabling the firewall -> same result.
  4. Ping to google.com gives 30ms response time (shouldn’t be a problem i guess)
  5. Did that already:

GW to 52.169.76.203.1700:
{"rxpk":[{"tmst":18525355,"time":"2017-02-16T09:42:41.944159Z","chan":0,"rfch":1,"freq":868.100000,"stat":1,"modu":"LORA","datr":"SF7BW125","codr":"4/5","lsnr":10.0,"rssi":-42,"size":23,"data":"ADYeAPB+1bNwrxwD8I/Vs3AXtMrWje8="}]}

52.169.76.203.1700 to GW:
{"txpk":{"imme":false,"tmst":23525355,"freq":868.1,"rfch":0,"powe":14,"modu":"LORA","datr":"SF7BW125","codr":"4/5","ipol":true,"size":33,"data":"IOXEHIHkTunTWzibUFpChC4wtTYMIxD+JkIi1ufv94hh"}}

./poly_forwarder:
##### 2017-02-16 09:42:46 GMT #####
### [UPSTREAM] ###
# RF packets received by concentrator: 1
# CRC_OK: 100.00%, CRC_FAIL: 0.00%, NO_CRC: 0.00%
# RF packets forwarded: 1 (23 bytes)
# PUSH_DATA datagrams sent: 1 (242 bytes)
# PUSH_DATA acknowledged: 100.00%
### [DOWNSTREAM] ###
# PULL_DATA sent: 3 (100.00% acknowledged)
# PULL_RESP(onse) datagrams received: 0 (0 bytes)
# RF packets sent to concentrator: 0 (0 bytes)
# TX errors: 0
### [GPS] ###
# Invalid gps time reference (age: 1487238166 sec)
# Manual GPS coordinates: latitude 48.78466, longitude 9.17769, altitude 247 m
##### END #####

What does that TX Error mean (sometimes i get tx error 1)?

##### 2017-02-16 09:58:05 GMT #####
### [UPSTREAM] ###
# RF packets received by concentrator: 3
# CRC_OK: 33.33%, CRC_FAIL: 66.67%, NO_CRC: 0.00%
# RF packets forwarded: 1 (23 bytes)
# PUSH_DATA datagrams sent: 1 (241 bytes)
# PUSH_DATA acknowledged: 100.00%
### [DOWNSTREAM] ###
# PULL_DATA sent: 3 (100.00% acknowledged)
# PULL_RESP(onse) datagrams received: 1 (196 bytes)
# RF packets sent to concentrator: 1 (33 bytes)
# TX errors: 1
### [GPS] ###
# Invalid gps time reference (age: 1487239085 sec)
# Manual GPS coordinates: latitude 48.78466, longitude 9.17769, altitude 247 m
##### END #####
INFO: [up] PUSH_ACK for server router.eu.thethings.network received in 47 ms
INFO: [down] for server router.eu.thethings.network PULL_ACK received in 47 ms
INFO: [down] for server router.eu.thethings.network PULL_ACK received in 46 ms
INFO: [down] for server router.eu.thethings.network PULL_ACK received in 46 ms

##### 2017-02-16 09:58:35 GMT #####
### [UPSTREAM] ###
# RF packets received by concentrator: 0
# CRC_OK: 0.00%, CRC_FAIL: 0.00%, NO_CRC: 0.00%
# RF packets forwarded: 0 (0 bytes)
# PUSH_DATA datagrams sent: 1 (242 bytes)
# PUSH_DATA acknowledged: 100.00%
### [DOWNSTREAM] ###
# PULL_DATA sent: 3 (100.00% acknowledged)
# PULL_RESP(onse) datagrams received: 0 (0 bytes)
# RF packets sent to concentrator: 0 (0 bytes)
# TX errors: 0
### [GPS] ###
# Invalid gps time reference (age: 1487239115 sec)
# Manual GPS coordinates: latitude 48.78466, longitude 9.17769, altitude 247 m
##### END #####
INFO: [up] PUSH_ACK for server router.eu.thethings.network received in 47 ms
INFO: [down] for server router.eu.thethings.network PULL_ACK received in 47 ms
INFO: [down] for server router.eu.thethings.network PULL_ACK received in 47 ms
INFO: [up] PUSH_ACK for server router.eu.thethings.network received in 47 ms
INFO: [down] for server router.eu.thethings.network serv_addr[ic]PULL_RESP received :)
INFO: [down] a packet will be sent on timestamp value 82190035
WARNING: [down] lgw_send failed
INFO: [down] for server router.eu.thethings.network PULL_ACK received in 47 ms

##### 2017-02-16 09:59:05 GMT #####
### [UPSTREAM] ###
# RF packets received by concentrator: 1
# CRC_OK: 100.00%, CRC_FAIL: 0.00%, NO_CRC: 0.00%
# RF packets forwarded: 1 (23 bytes)
# PUSH_DATA datagrams sent: 2 (483 bytes)
# PUSH_DATA acknowledged: 100.00%
### [DOWNSTREAM] ###
# PULL_DATA sent: 3 (100.00% acknowledged)
# PULL_RESP(onse) datagrams received: 1 (196 bytes)
# RF packets sent to concentrator: 1 (33 bytes)
# TX errors: 1
### [GPS] ###
# Invalid gps time reference (age: 1487239145 sec)
# Manual GPS coordinates: latitude 48.78466, longitude 9.17769, altitude 247 m
##### END #####
INFO: [up] PUSH_ACK for server router.eu.thethings.network received in 47 ms
INFO: [down] for server router.eu.thethings.network PULL_ACK received in 47 ms
INFO: [down] for server router.eu.thethings.network PULL_ACK received in 47 ms
^]^C
##### 2017-02-16 09:59:24 GMT #####
### [UPSTREAM] ###
# RF packets received by concentrator: 0
# CRC_OK: 0.00%, CRC_FAIL: 0.00%, NO_CRC: 0.00%
# RF packets forwarded: 0 (0 bytes)
# PUSH_DATA datagrams sent: 1 (242 bytes)
# PUSH_DATA acknowledged: 100.00%
### [DOWNSTREAM] ###
# PULL_DATA sent: 2 (100.00% acknowledged)
# PULL_RESP(onse) datagrams received: 0 (0 bytes)
# RF packets sent to concentrator: 0 (0 bytes)
# TX errors: 0
### [GPS] ###
# Invalid gps time reference (age: 1487239164 sec)
# Manual GPS coordinates: latitude 48.78466, longitude 9.17769, altitude 247 m
##### END #####
4

Hi, My experience is that the timing of the receive window is something to pay attention to. In both my Arduino and Raspberry nodes with lmic 1.5 I had to expand the receive window to make OTAA successful.

1 Like
5

Thanks for that hint, but i’ve tried all of that first.
I played with the timing stuff for over a week and on arduino i tried everything from 0-100% with the clockError function. No change.
ABP works perfectly fine btw.

6

I have the same problem…

It seems that the gateway doesn’t send a confirmation message to the node because the trasmitted message counter on the gateway page on TTN increments the value when receives an activation frame

Could it be a problem with the external port, on which the server tries to communicate with the rpi?

7

Any chance you can print the timestamps at which your gateway sent this, and at which it received the response? (That was key in the linked topic in my earlier answer: it was received too late; did you look at those links?) The following (or alternatives) might help to add a timestamp when monitoring a file called logfile:

tail -f logfile 2>&1 | while read l; do d=`date +%H:%M:%S.%N`; echo $d $l; done

As for the response from the TTN backend:

{"txpk": ... "data":"IOXEHIHkTunTWzibUFpChC4wtTYMIxD+JkIi1ufv94hh"}}

That’s the Join Accept. So surely no firewall issues.

# RF packets sent to concentrator: 0 (0 bytes)

I think this should be 1 if the gateway forwarded the Join Accept (or any downlink) to the LoRa concentrator, to actually have it transmitted.

# RF packets sent to concentrator: 1 (33 bytes)  
# TX errors: 1

I don’t know what the error means.

A gateway cannot know if a node received anything it sent, so I assume the actual transmission failed for some reason. I don’t know if your gateway would even try to forward the packet to the LoRa concentrator if it arrived too late to be received by the node, and/or if the concentrator does any validation of the timestamps.

…but downlinks on ABP might be failing too?

8

You’re probably right (it’s surely the case for @rkeck). But it could also be that your gateway never receives the Join Accept that TTN has sent. (Firewall, network.) So you really need to look into the gateway’s log file first.

Note that the gateway sends UDP packets to the TTN backend to try to keep firewalls open; see UDP ports and firewalling.

9

A possible cause is the concentrator rejecting the packet because the timestamp for transmission is in the past.

10

I think i have a simlar issue: a badgerboard sketch wants to do OTAA.

on the gateway it reads:

Feb 18 07:31:27 ttn-gateway ttn-gateway[1018]: ### [UPSTREAM] ###
Feb 18 07:31:27 ttn-gateway ttn-gateway[1018]: # RF packets received by concentrator: 1
Feb 18 07:31:27 ttn-gateway ttn-gateway[1018]: # CRC_OK: 0.00%, CRC_FAIL: 100.00%, NO_CRC: 0.00%
Feb 18 07:31:27 ttn-gateway ttn-gateway[1018]: # RF packets forwarded: 0 (0 bytes)
Feb 18 07:31:27 ttn-gateway ttn-gateway[1018]: # PUSH_DATA datagrams sent: 1 (220 bytes)
Feb 18 07:31:27 ttn-gateway ttn-gateway[1018]: # PUSH_DATA acknowledged: 0.00%
Feb 18 07:31:27 ttn-gateway ttn-gateway[1018]: ### [DOWNSTREAM] ###
Feb 18 07:31:27 ttn-gateway ttn-gateway[1018]: # PULL_DATA sent: 3 (0.00% acknowledged)
Feb 18 07:31:27 ttn-gateway ttn-gateway[1018]: # PULL_RESP(onse) datagrams received: 0 (0 bytes)
Feb 18 07:31:27 ttn-gateway ttn-gateway[1018]: # RF packets sent to concentrator: 0 (0 bytes)
Feb 18 07:31:27 ttn-gateway ttn-gateway[1018]: # TX errors: 0
Feb 18 07:31:27 ttn-gateway ttn-gateway[1018]: ### [GPS] ###

The only noteworthy is the CRC_FAIL message, which seems to cause that nothing is forwarded. Do yu have any idea?

11

No.

Looking at the limited information from your log, I assume in your case TTN Console does not show any activation at all. The following tells you that the gateway didn’t like the packet sent by your node. It might not even be a packet form your node; it could be anything:

# RF packets received by concentrator: 1
# CRC_OK: 0.00%, CRC_FAIL: 100.00%, NO_CRC: 0.00%
# RF packets forwarded: 0 (0 bytes)
12

Sorry i thought you mean the timestamps included in the rx/tx json objects.

So new try with a OTAA Join request that shows activated (last seen x seconds ago) in the TTN Console but doesn’t receive the Join Accept.
tcpdump with timestamps:
A 11:39:03.544003 IP raspberrypi.fritz.box.56890 > 52.169.76.203.1700: UDP, length 242 {"rxpk":[{"tmst":28674635,"time":"2017-02-20T10:39:03.543870Z","chan":0,"rfch":1,"freq":868.100000,"stat":1,"modu":"LORA","datr":"SF7BW125","codr":"4/5","lsnr":11.2,"rssi":-39,"size":23,"data":"ADYeAPB+1bNwrxwD8I/Vs3CJ7XC00dY="}]}

B 11:39:07.276382 IP raspberrypi.fritz.box.56890 > 52.169.76.203.1700: UDP, length 242 {"stat":{"time":"2017-02-20 10:39:07 GMT","lati":48.78466,"long":9.17769,"alti":247,"rxnb":1,"rxok":1,"rxfw":1,"ackr":100.0,"dwnb":0,"txnb":0,"..."}}

C 11:39:08.215948 IP 52.169.76.203.1700 > raspberrypi.fritz.box.53146: UDP, length 196 {"txpk":{"imme":false,"tmst":33674635,"freq":868.1,"rfch":0,"powe":14,"modu":"LORA","datr":"SF7BW125","codr":"4/5","ipol":true,"size":33,"data":"ILb0/M6xc5u8k3Q7SDBK6XHcPU2x+JtdJu2FIknzk7Gc"}}

And this from the poly_packet_fwd

##### 2017-02-20 10:39:07 GMT #####
### [UPSTREAM] ###
# RF packets received by concentrator: 1
# CRC_OK: 100.00%, CRC_FAIL: 0.00%, NO_CRC: 0.00%
# RF packets forwarded: 1 (23 bytes)
# PUSH_DATA datagrams sent: 1 (242 bytes)
# PUSH_DATA acknowledged: 100.00%
### [DOWNSTREAM] ###
# PULL_DATA sent: 3 (100.00% acknowledged)
# PULL_RESP(onse) datagrams received: 0 (0 bytes)
# RF packets sent to concentrator: 0 (0 bytes)
# TX errors: 0
### [GPS] ###
# Invalid gps time reference (age: 1487587147 sec)
# Manual GPS coordinates: latitude 48.78466, longitude 9.17769, altitude 247 m
##### END #####
INFO: [up] PUSH_ACK for server router.eu.thethings.network received in 47 ms
INFO: [down] for server router.eu.thethings.network PULL_ACK received in 46 ms
INFO: [down] for server router.eu.thethings.network serv_addr[ic]PULL_RESP received :)
INFO: [down] a packet will be sent on timestamp value 33674635
WARNING: [down] lgw_send failed
INFO: [down] for server router.eu.thethings.network PULL_ACK received in 46 ms

So again he says 0 Packets sent to concentrator (and the warning lgw_send failed?).

13

I gues you know, but just to be sure:

That’s a Join Request.

And that’s the Join Accept, received after 4.67 seconds, so just in time to be transmitted by the gateway 33,674,635 - 28,674,635 ms = 5 seconds after the gateway received the Join Request. So, assuming the tcpdump was created on the gateway, all looks fine up to:

INFO: [down] a packet will be sent on timestamp value 33674635
WARNING: [down] lgw_send failed

I didn’t notice that error in your previous log, but it was there too. As the gateway cannot know if the node received its transmission, it has encountered some other error when trying to send it :frowning:

14

I solved connecting the gateway with the router at home where I can receive external connection. Before I tried at university where I think the firewall locks the external connection

15

I reinstalled the GW and everything works fine now. Don’t know where the error could come from.
But thank you for your effort anyway!

16

So i have another problem: I have 2 different boards with stm32 and sx1272 modem. One works flawless, the other one sends the OTAA Join (which is received by ttn and showd in console) request but doesn’t receive the accept at all or sometimes after 10 join tries…
The Gateway shows the following:

##### 2017-03-02 11:44:21 GMT #####
### [UPSTREAM] ###
# RF packets received by concentrator: 0
# CRC_OK: 0.00%, CRC_FAIL: 0.00%, NO_CRC: 0.00%
# RF packets forwarded: 0 (0 bytes)
# PUSH_DATA datagrams sent: 1 (215 bytes)
# PUSH_DATA acknowledged: 100.00%
### [DOWNSTREAM] ###
# PULL_DATA sent: 3 (100.00% acknowledged)
# PULL_RESP(onse) datagrams received: 0 (0 bytes)
# RF packets sent to concentrator: 0 (0 bytes)
# TX errors: 0
### [GPS] ###
# Invalid gps time reference (age: 1488455061 sec)
# Manual GPS coordinates: latitude 0.00000, longitude 0.00000, altitude 0 m
##### END #####
INFO: [up] PUSH_ACK for server router.eu.thethings.network received in 46 ms
INFO: [down] for server router.eu.thethings.network PULL_ACK received in 46 ms
INFO: [up] PUSH_ACK for server router.eu.thethings.network received in 47 ms
INFO: [down] for server router.eu.thethings.network PULL_ACK received in 46 ms
INFO: [down] for server router.eu.thethings.network serv_addr[ic]PULL_RESP received :)
INFO: [down] a packet will be sent on timestamp value 347564667
INFO: [down] for server router.eu.thethings.network PULL_ACK received in 46 ms

##### 2017-03-02 11:44:51 GMT #####
### [UPSTREAM] ###
# RF packets received by concentrator: 2
# CRC_OK: 50.00%, CRC_FAIL: 50.00%, NO_CRC: 0.00%
# RF packets forwarded: 1 (23 bytes)
# PUSH_DATA datagrams sent: 2 (457 bytes)
# PUSH_DATA acknowledged: 100.00%
### [DOWNSTREAM] ###
# PULL_DATA sent: 3 (100.00% acknowledged)
# PULL_RESP(onse) datagrams received: 1 (197 bytes)
# RF packets sent to concentrator: 1 (33 bytes)
# TX errors: 0
### [GPS] ###
# Invalid gps time reference (age: 1488455091 sec)
# Manual GPS coordinates: latitude 0.00000, longitude 0.00000, altitude 0 m
##### END #####
INFO: [up] PUSH_ACK for server router.eu.thethings.network received in 47 ms
INFO: [down] for server router.eu.thethings.network PULL_ACK received in 46 ms
INFO: [down] for server router.eu.thethings.network PULL_ACK received in 46 ms

Why is there 0.00% on every CRC field but the Join is received and shown in the console and custom backend?
I think it has to be a problem on the node side in this case because my other node works like a charm. But i have no Idea what the Error could be because the boards have the same MCU and modem chip they are just different modules in size and features.

17

There isn’t. The 11:44:21 summary shows that nothing was received in the past 30 seconds, so nothing to validate with a CRC either. However, the 11:44:51 summary shows:

# CRC_OK: 50.00%, CRC_FAIL: 50.00%, NO_CRC: 0.00%

The 11:45:51 summary also shows it forwarded the (presumably) Join Request to the backend:

# RF packets forwarded: 1 (23 bytes)

The other packet (the other 50%), for which the CRC failed, was discarded. But that might not even be one of your node’s packets.

And it also transmitted the (presumably) Join Accept t received from the backend:

# RF packets sent to concentrator: 1 (33 bytes)

That’s all we know.

1 Like
18

hi pe1mew, could tell me how you did this. I’m also having trouble with otaa.

19

Hi, I had the same problem. I resolved it by using this fix>