OTAA ok, 12h later I get denied, reboot gateway --> OK again ...!?

…but you already tried that? Of course, you could make the windows even larger; @matthijs already explained earlier, as quoted above.

Hi @arjanvanb,

since the problem was the missing downlink packet reception, I got back to ABP sketch and I didn’t make that fix, also because it was not working anyway during OTAA. Any advise to give about that?

I’d assume you could increase it by 10%, 20%, whatever you want. For 20%, I’d try:

LMIC_setClockError(MAX_CLOCK_ERROR * 20 / 100);

…but taking a step back:

If the downlink packets are received (or: pulled?) too late for the downlink window (which seems to be the problem), then why would restarting the gateway solve this for some time? Maybe it somehow decreases the 3G network lag, due to some more network activity when the gateway is started?

…not hundred percent sure that the problem is due to late pull from server, but considering the results of the test I have made, I don’t see any other explanation by now.

[/quote][quote=“arjanvanb, post:36, topic:2025”]
LMIC_setClockError(MAX_CLOCK_ERROR * 20 / 100);
[/quote]

Anyway, this fix in the code doesn’t solve the problem. With regard to LMIC library I have seen that receiving downlink packets in RX1 window has been not tested yet. Only RX2 should work. Have you ever tried to get packets back using LMIC library?

True for TTN, for reasons described in Why is RX_SLOT 1 not used?

Not for data, but LMiC OTAA works fine for me.

How far did you stretch the receive window? Maybe even 100% of the maximum error is allowed:

LMIC_setClockError(MAX_CLOCK_ERROR);

Hi @arjanvanb,

Have you tried to just remove power from your arduino (or even push the reset button) and then try to activate it once again? In my case, as soon as I restart my Arduino, I can’t activate the device any longer (I didn’t make any change at all!).
I post the console view: in the event of a restart, you can see a new JOIN_REQUEST, the device can’t get JOIN_ACCEPT so it will keep sending request at scheduled TX interval.

Please, let me know if you run that test.

I have no specific problems with resetting and all. I don’t always get a successful OTAA right away, but I’m using Jaap’s single channel gateway, and that uses some smart timing to scan for all spreading factors, that might miss out on packets. I never need to reset anything to eventually get activated.

But that’s not new information, right? That’s why you came to this topic in the first place, or has something changed now?

A bit of logging from my single channel gateway, for a successful OTAA:

A 18:23:18.659167	pull	01946a025ccf7ff42f1970ec
B 18:23:22.555010	rxpk	01bf72005ccf7ff42f1970ec	message	{"rxpk":[{"rssi":-46,"stat":1,"modu":"LORA","rfch":0,"tmst":349218460,"datr":"SF7BW125","lsnr":9,"time":"2017-01-26T18:23:22.510034Z","codr":"4/5","data":"ANwAANB+1bNwHm/t9XzurwDIhgMK8sk=","freq":868.100,"chan":0,"size":23}]}	length	237
C 18:23:23.658268	pull	01af68025ccf7ff42f1970ec
D 18:23:27.372908	txpk	{"txpk":{"imme":false,"tmst":354218460,"freq":868.1,"rfch":0,"powe":14,"modu":"LORA","datr":"SF7BW125","codr":"4/5","ipol":true,"size":33,"data":"IIE/R/UI/6JnC24j4B+EueJdnEEV8C7qCz3T4gs+ypLa"}}
E 18:23:27.389906	txpk_ack	{"txpk_ack":{"error":"NONE"}}
F 18:23:27.508022	transmitPkt	9886	6300	-1	868100000	112	112	2	64	14	33

Above, line B is the Join Request (with the gateway’s timestamp being 349218460). TTN Console shows that at 19:23:22; it seems to know my local time zone.

Line D is the Join Accept which seems to arrive at the gateway after 4.818 seconds. The timestamp in the Accept, indicating when to forward it to the node, is set to be 354218460, hence 5,000,000 microseconds or 5 seconds after the timestamp from the Join Request. (All relative to the gateway’s timestamp, like Kersing explained above.) So, TTN wants the gateway to send it in RX1, following JOIN_ACCEPT_DELAY1. Indeed, in line F it’s transmitted.

Before truly transmitting it in line F, in line E an acknowledgement is already sent back to TTN. Jaap’s single channel gateway will report TOO_LATE if the downlink came too late (following Semtech’s Gateway to Server Interface Definition):

local msg='{"txpk_ack":{"error":"NONE"}}'
if trig <= 0 then
  msg='{"txpk_ack":{"error":"TOO_LATE"}}'
end

So, the size of the acknowledgement might give you an indication if the gateway thinks all is fine? When sent without whitespace, the NONE is 29 bytes, the TOO_LATE is 33 bytes.

As LMiC starts OTAA whenever the first packet is to be sent, a successful Join is followed by the first data:

G 18:23:27.684300	rxpk	01ee4d005ccf7ff42f1970ec	message	{"rxpk":[{"rssi":-48,"stat":1,"modu":"LORA","rfch":0,"tmst":354347381,"datr":"SF7BW125","lsnr":9,"time":"2017-01-26T18:23:27.639420Z","codr":"4/5","data":"QCkuASaAAAAByFaF53Iu+vzmwQ==","freq":868.100,"chan":0,"size":19}]}	length	233

(As an aside: this way, the first data received after a Join, will always be a bit late, unless one explicitly first forces a Join when starting the device.)

After the OTAA, the gateway goes into pulling commands from TTN, and sending statistics:

H 18:23:28.657846	pull	017601025ccf7ff42f1970ec
I 18:23:33.657938	pull	015754025ccf7ff42f1970ec
J 18:23:38.631359	stat	01e961005ccf7ff42f1970ec	message	{"stat":{"rxfw":2,"alti":3,"lati":52.123456,"rxok":2,"long":4.987654,"time":"2017-01-26 18:23:38 GMT","txnb":1,"dwnb":2,"rxnb":2,"ackr":100.0}}	length	155
K 18:23:38.659612	pull	01b3d0025ccf7ff42f1970ec

Every now and then my node will ask for a link check in an uplink. (Even though TTN does not support ADR yet, my test node has link check enabled.)

L 19:02:53.661983	pull	015e66025ccf7ff42f1970ec
M 19:02:54.474860	rxpk	01450f005ccf7ff42f1970ec	message	{"rxpk":[{"rssi":-54,"stat":1,"modu":"LORA","rfch":0,"tmst":573653463,"datr":"SF10BW125","lsnr":12,"time":"2017-01-26T19:02:54.429481Z","codr":"4/5","data":"QCkuASbAMwABMngK0sWEN3AgBQ==","freq":868.100,"chan":0,"size":19}]}	length	235
N 19:02:56.191305	txpk	{"txpk":{"imme":false,"tmst":575653463,"freq":869.525,"rfch":0,"powe":27,"modu":"LORA","datr":"SF9BW125","codr":"4/5","ipol":true,"size":12,"data":"YCkuASYgAwDQNni9"}}
O 19:02:56.206041	txpk_ack	{"txpk_ack":{"error":"NONE"}}
P 19:02:56.426678	transmitPkt	10332	7063	0	869525000	144	112	2	64	27	12
Q 19:02:58.661714	pull	013877025ccf7ff42f1970ec

In line M the timestamp in the uplink is 573653463. In the downlink in line N, which is received after 1.716 seconds, it’s 575653463, hence 2 seconds difference. Again, the downlink is received just in time to forward it to the node. For this, TTN Console seems to have the seconds wrong in 20:02:50, and they are not in line with the uplink that preceded the downlink:

If your gateway does not print timestamps, then 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

I’m not entirely sure that will work - at some point the RX windows will end up overlapping (which each other and possibly even the TX time), and I’m not sure what will happen then (I remember leaving that for later, but I never got around to handling that gracefully).

Hi @arjanvanb,

very kind of you posting such log, I really appreciate it! Following your lead I did a bit of logging as well, seems like timing is working fine also on my side.

  /    * OTAA activation tentative. Device not activated! JOIN_ACCEPT message forwarded to endnode
5 seconds after JOIN_REQUEST */

11:04:50.435723 IP 31.157.192.137.49457 > 52.169.76.203.1700: UDP, length 243
        0x0000:  4500 010f c9ec 4000 4011 0e57 1f9d c089  E.....@.@..W....
        0x0010:  34a9 4ccb c131 06a4 00fb c605 01d9 6700  4.L..1........g.
        0x0020:  0000 024b 0803 0571 7b22 7278 706b 223a  ...K...q{"rxpk":
        0x0030:  5b7b 2274 6d73 7422 3a39 3938 3937 3935  [{"tmst":9989795
        0x0040:  3438 2c22 7469 6d65 223a 2232 3031 372d  48,"time":"2017-
        0x0050:  3031 2d32 3754 3130 3a30 343a 3530 2e34  01-27T10:04:50.4
        0x0060:  3335 3131 315a 222c 2263 6861 6e22 3a30  35111Z","chan":0
        0x0070:  2c22 7266 6368 223a 312c 2266 7265 7122  ,"rfch":1,"freq"
        0x0080:  3a38 3638 2e31 3030 3030 302c 2273 7461  :868.100000,"sta
        0x0090:  7422 3a31 2c22 6d6f 6475 223a 224c 4f52  t":1,"modu":"LOR
        0x00a0:  4122 2c22 6461 7472 223a 2253 4638 4257  A","datr":"SF8BW
        0x00b0:  3132 3522 2c22 636f 6472 223a 2234 2f35  125","codr":"4/5
        0x00c0:  222c 226c 736e 7222 3a31 312e 382c 2272  ","lsnr":11.8,"r
        0x00d0:  7373 6922 3a2d 3335 2c22 7369 7a65 223a  ssi":-35,"size":
        0x00e0:  3233 2c22 6461 7461 223a 2241 4730 7a41  23,"data":"AG0zA
        0x00f0:  5042 2b31 624e 774c 6439 376a 746d 5761  PB+1bNwLd97jtmWa
        0x0100:  5144 675a 3552 3932 4e77 3d22 7d5d 7d    QDgZ5R92Nw="}]}
11:04:51.254810 IP 52.169.76.203.1700 > 31.157.192.137.49457: UDP, length 4
        0x0000:  4500 0020 b229 4000 2c11 3b09 34a9 4ccb  E....)@.,.;.4.L.
        0x0010:  1f9d c089 06a4 c131 000c 6d8b 01d9 6701  .......1..m...g.
11:04:55.914887 IP 52.169.76.203.1700 > 31.157.192.137.44731: UDP, length 198
        0x0000:  4500 00e2 b68a 4000 2c11 35e6 34a9 4ccb  E.....@.,.5.4.L.
        0x0010:  1f9d c089 06a4 aebb 00ce a1a4 0100 0003  ................
        0x0020:  7b22 7478 706b 223a 7b22 696d 6d65 223a  {"txpk":{"imme":
        0x0030:  6661 6c73 652c 2274 6d73 7422 3a31 3030  false,"tmst":100
        0x0040:  3339 3739 3534 382c 2266 7265 7122 3a38  3979548,"freq":8
        0x0050:  3638 2e31 2c22 7266 6368 223a 302c 2270  68.1,"rfch":0,"p
        0x0060:  6f77 6522 3a31 342c 226d 6f64 7522 3a22  owe":14,"modu":"
        0x0070:  4c4f 5241 222c 2264 6174 7222 3a22 5346  LORA","datr":"SF
        0x0080:  3842 5731 3235 222c 2263 6f64 7222 3a22  8BW125","codr":"
        0x0090:  342f 3522 2c22 6970 6f6c 223a 7472 7565  4/5","ipol":true
        0x00a0:  2c22 7369 7a65 223a 3333 2c22 6461 7461  ,"size":33,"data
        0x00b0:  223a 2249 4779 6469 494b 5073 6b77 3064  ":"IGydiIKPskw0d
        0x00c0:  5230 7654 4234 686e 3463 4f48 6462 6b64  R0vTB4hn4cOHdbkd
        0x00d0:  5967 622f 4458 6874 2f6c 4872 4f79 4222  Ygb/DXht/lHrOyB"
        0x00e0:  7d7d                                     }}
11:04:58.718783 IP 31.157.192.137.44731 > 52.169.76.203.1700: UDP, length 12
        0x0000:  4500 0028 c9ed 4000 4011 0f3d 1f9d c089  E..(..@.@..=....
        0x0010:  34a9 4ccb aebb 06a4 0014 20d7 0133 b702  4.L..........3..
        0x0020:  0000 024b 0803 0571                      ...K...q
11:04:58.944786 IP 52.169.76.203.1700 > 31.157.192.137.44731: UDP, length 4
        0x0000:  4500 0020 b76f 4000 2c11 35c3 34a9 4ccb  E....o@.,.5.4.L.
        0x0010:  1f9d c089 06a4 aebb 000c 30a4 0133 b704  ..........0..3..
11:05:08.738834 IP 31.157.192.137.44731 > 52.169.76.203.1700: UDP, length 12
        0x0000:  4500 0028 c9ee 4000 4011 0f3c 1f9d c089  E..(..@.@..<....
        0x0010:  34a9 4ccb aebb 06a4 0014 8771 0199 5002  4.L........q..P.
        0x0020:  0000 024b 0803 0571                      ...K...q
11:05:08.984790 IP 52.169.76.203.1700 > 31.157.192.137.44731: UDP, length 4
        0x0000:  4500 0020 b999 4000 2c11 3399 34a9 4ccb  E.....@.,.3.4.L.
        0x0010:  1f9d c089 06a4 aebb 000c 973e 0199 5004  ...........>..P.
11:05:13.950806 IP 31.157.192.137.49457 > 52.169.76.203.1700: UDP, length 111
        0x0000:  4500 008b c9ef 4000 4011 0ed8 1f9d c089  E.....@.@.......
        0x0010:  34a9 4ccb c131 06a4 0077 f9dd 01a3 e300  4.L..1...w......
        0x0020:  0000 024b 0803 0571 7b22 7374 6174 223a  ...K...q{"stat":
        0x0030:  7b22 7469 6d65 223a 2232 3031 372d 3031  {"time":"2017-01
        0x0040:  2d32 3720 3130 3a30 353a 3133 2047 4d54  -27.10:05:13.GMT
        0x0050:  222c 2272 786e 6222 3a31 2c22 7278 6f6b  ","rxnb":1,"rxok
        0x0060:  223a 312c 2272 7866 7722 3a31 2c22 6163  ":1,"rxfw":1,"ac
        0x0070:  6b72 223a 302e 302c 2264 776e 6222 3a31  kr":0.0,"dwnb":1
        0x0080:  2c22 7478 6e62 223a 317d 7d              ,"txnb":1}}`

As you can see, the JOIN_ACCEPT message is forwarded to the endnode 5 secs after the JOIN_REQUEST, same timing as yours. Then I decided to restart both gateway and arduino since, by now, this is the only way I can get my device activated (in fact it worked and device was being immediately activated). With device activated, I sent few downlink packets to monitor timing and see if it is in accordance with the results you posted.

/* OTAA device activated! Uplink packet sent back to endnode 1 sec after "Hello World!" downlink */


10:52:06.493745 IP 31.157.192.137.49457 > 52.169.76.203.1700: UDP, length 246
        0x0000:  4500 0112 c97a 4000 4011 0ec6 1f9d c089  E....z@.@.......
        0x0010:  34a9 4ccb c131 06a4 00fe 365e 015c 2a00  4.L..1....6^.\*.
        0x0020:  0000 024b 0803 0571 7b22 7278 706b 223a  ...K...q{"rxpk":
        0x0030:  5b7b 2274 6d73 7422 3a32 3335 3032 3630  [{"tmst":2350260
        0x0040:  3532 2c22 7469 6d65 223a 2232 3031 372d  52,"time":"2017-
        0x0050:  3031 2d32 3754 3039 3a35 323a 3036 2e34  01-27T09:52:06.4
        0x0060:  3933 3135 335a 222c 2263 6861 6e22 3a35  93153Z","chan":5
        0x0070:  2c22 7266 6368 223a 302c 2266 7265 7122  ,"rfch":0,"freq"
        0x0080:  3a38 3637 2e35 3030 3030 302c 2273 7461  :867.500000,"sta
        0x0090:  7422 3a31 2c22 6d6f 6475 223a 224c 4f52  t":1,"modu":"LOR
        0x00a0:  4122 2c22 6461 7472 223a 2253 4637 4257  A","datr":"SF7BW
        0x00b0:  3132 3522 2c22 636f 6472 223a 2234 2f35  125","codr":"4/5
        0x00c0:  222c 226c 736e 7222 3a37 2e38 2c22 7273  ","lsnr":7.8,"rs
        0x00d0:  7369 223a 2d33 312c 2273 697a 6522 3a32  si":-31,"size":2
        0x00e0:  362c 2264 6174 6122 3a22 5143 5174 4153  6,"data":"QCQtAS
        0x00f0:  6141 4267 4142 5647 566e 6e6c 307a 6556  aABgABVGVnnl0zeV
        0x0100:  5a72 7144 554e 4c78 4261 6b4b 413d 227d  ZrqDUNLxBakKA="}
        0x0110:  5d7d                                     ]}
10:52:07.219847 IP 52.169.76.203.1700 > 31.157.192.137.49457: UDP, length 4
        0x0000:  4500 0020 30ce 4000 2c11 bc64 34a9 4ccb  E...0.@.,..d4.L.
        0x0010:  1f9d c089 06a4 c131 000c ab08 015c 2a01  .......1.....\*.
10:52:07.880705 IP 52.169.76.203.1700 > 31.157.192.137.44731: UDP, length 173
        0x0000:  4500 00c9 30d8 4000 2c11 bbb1 34a9 4ccb  E...0.@.,...4.L.
        0x0010:  1f9d c089 06a4 aebb 00b5 4d85 0100 0003  ..........M.....
        0x0020:  7b22 7478 706b 223a 7b22 696d 6d65 223a  {"txpk":{"imme":
        0x0030:  6661 6c73 652c 2274 6d73 7422 3a32 3336  false,"tmst":236
        0x0040:  3032 3630 3532 2c22 6672 6571 223a 3836  026052,"freq":86
        0x0050:  372e 352c 2272 6663 6822 3a30 2c22 706f  7.5,"rfch":0,"po
        0x0060:  7765 223a 3134 2c22 6d6f 6475 223a 224c  we":14,"modu":"L
        0x0070:  4f52 4122 2c22 6461 7472 223a 2253 4637  ORA","datr":"SF7
        0x0080:  4257 3132 3522 2c22 636f 6472 223a 2234  BW125","codr":"4
        0x0090:  2f35 222c 2269 706f 6c22 3a74 7275 652c  /5","ipol":true,
        0x00a0:  2273 697a 6522 3a31 342c 2264 6174 6122  "size":14,"data"
        0x00b0:  3a22 5943 5174 4153 5941 4151 4142 3742  :"YCQtASYAAQAB7B
        0x00c0:  6f46 6230 773d 227d 7d                   oFb0w="}}
10:52:13.933259 IP 31.157.192.137.49457 > 52.169.76.203.1700: UDP, length 111
        0x0000:  4500 008b c97b 4000 4011 0f4c 1f9d c089  E....{@.@..L....
        0x0010:  34a9 4ccb c131 06a4 0077 3087 01ec b000  4.L..1...w0.....
        0x0020:  0000 024b 0803 0571 7b22 7374 6174 223a  ...K...q{"stat":
        0x0030:  7b22 7469 6d65 223a 2232 3031 372d 3031  {"time":"2017-01
        0x0040:  2d32 3720 3039 3a35 323a 3133 2047 4d54  -27.09:52:13.GMT
        0x0050:  222c 2272 786e 6222 3a31 2c22 7278 6f6b  ","rxnb":1,"rxok
        0x0060:  223a 312c 2272 7866 7722 3a31 2c22 6163  ":1,"rxfw":1,"ac
        0x0070:  6b72 223a 302e 302c 2264 776e 6222 3a31  kr":0.0,"dwnb":1
        0x0080:  2c22 7478 6e62 223a 317d 7d              ,"txnb":1}}
10:52:14.419806 IP 52.169.76.203.1700 > 31.157.192.137.49457: UDP, length 4
        0x0000:  4500 0020 3470 4000 2c11 b8c2 34a9 4ccb  E...4p@.,...4.L.
        0x0010:  1f9d c089 06a4 c131 000c 2478 01ec b001  .......1..$x....
10:52:15.298769 IP 31.157.192.137.44731 > 52.169.76.203.1700: UDP, length 12
        0x0000:  4500 0028 c97c 4000 4011 0fae 1f9d c089  E..(.|@.@.......
        0x0010:  34a9 4ccb aebb 06a4 0014 dcce 013b fb02  4.L..........;..
        0x0020:  0000 024b 0803 0571                      ...K...q
10:52:15.540786 IP 52.169.76.203.1700 > 31.157.192.137.44731: UDP, length 4
        0x0000:  4500 0020 3493 4000 2c11 b89f 34a9 4ccb  E...4.@.,...4.L.
        0x0010:  1f9d c089 06a4 aebb 000c ec9b 013b fb04  .............;..
10:52:25.348910 IP 31.157.192.137.44731 > 52.169.76.203.1700: UDP, length 12
        0x0000:  4500 0028 c97d 4000 4011 0fad 1f9d c089  E..(.}@.@.......
        0x0010:  34a9 4ccb aebb 06a4 0014 28d8 0132 af02  4.L.......(..2..
        0x0020:  0000 024b 0803 0571                      ...K...q
10:52:25.579806 IP 52.169.76.203.1700 > 31.157.192.137.44731: UDP, length 4
        0x0000:  4500 0020 37a7 4000 2c11 b58b 34a9 4ccb  E...7.@.,...4.L.
        0x0010:  1f9d c089 06a4 aebb 000c 38a5 0132 af04  ..........8..2..

In this latter case, the downlink packet sent from TTN console follows the “Hello World!” uplink, and it was forwarded 1 sec after. However, I couldn’t open Arduino Serial Monitor since it would restart the sketch and (for sure considering any previous attempt), it would have failed trying to activate my device once again.
Finally, I uploaded the “ttn-abp.ino” sketch to check timing as well. What I have seen is that also in this case the downlink packet from the server is forwarded 1 sec after the “Hello World!” uplink, so I guess it should be just fine…however I don’t see any packet received on Serial Monitor (LMIC.dataLen = 0 means that no packet is being received).

/* ABP activated device. Downlink packet sent to endnode 1 sec after "Hello World!" uplink.
However, LMIC.dataLen=0 on Arduino side meaning no downlink packet has been received. */

10:19:53.487901 IP 2.43.193.163.33372 > 52.169.76.203.1700: UDP, length 247
        0x0000:  4500 0113 067b 4000 4011 ee1c 022b c1a3  E....{@.@....+..
        0x0010:  34a9 4ccb 825c 06a4 00ff 832b 0135 c100  4.L..\.....+.5..
        0x0020:  0000 024b 0803 0571 7b22 7278 706b 223a  ...K...q{"rxpk":
        0x0030:  5b7b 2274 6d73 7422 3a31 3433 3539 3937  [{"tmst":1435997
        0x0040:  3637 352c 2274 696d 6522 3a22 3230 3137  675,"time":"2017
        0x0050:  2d30 312d 3237 5430 393a 3139 3a35 332e  -01-27T09:19:53.
        0x0060:  3438 3733 3032 5a22 2c22 6368 616e 223a  487302Z","chan":
        0x0070:  322c 2272 6663 6822 3a31 2c22 6672 6571  2,"rfch":1,"freq
        0x0080:  223a 3836 382e 3530 3030 3030 2c22 7374  ":868.500000,"st
        0x0090:  6174 223a 312c 226d 6f64 7522 3a22 4c4f  at":1,"modu":"LO
        0x00a0:  5241 222c 2264 6174 7222 3a22 5346 3742  RA","datr":"SF7B
        0x00b0:  5731 3235 222c 2263 6f64 7222 3a22 342f  W125","codr":"4/
        0x00c0:  3522 2c22 6c73 6e72 223a 372e 322c 2272  5","lsnr":7.2,"r
        0x00d0:  7373 6922 3a2d 3333 2c22 7369 7a65 223a  ssi":-33,"size":
        0x00e0:  3236 2c22 6461 7461 223a 2251 4830 6141  26,"data":"QH0aA
        0x00f0:  5361 4142 5141 424e 7863 3963 5a54 4d79  SaABQABNxc9cZTMy
        0x0100:  6a36 4342 4676 5571 6679 5938 5a6b 3d22  j6CBFvUqfyY8Zk="
        0x0110:  7d5d 7d                                  }]}
10:19:54.295617 IP 52.169.76.203.1700 > 2.43.193.163.33372: UDP, length 4
        0x0000:  4500 0020 2dc5 4000 2c11 dbc5 34a9 4ccb  E...-.@.,...4.L.
        0x0010:  022b c1a3 06a4 825c 000c 6f5c 0135 c101  .+.....\..o\.5..
10:19:54.936678 IP 52.169.76.203.1700 > 2.43.193.163.44112: UDP, length 174
        0x0000:  4500 00ca 2e13 4000 2c11 dacd 34a9 4ccb  E.....@.,...4.L.
        0x0010:  022b c1a3 06a4 ac50 00b6 ac81 0100 0003  .+.....P........
        0x0020:  7b22 7478 706b 223a 7b22 696d 6d65 223a  {"txpk":{"imme":
        0x0030:  6661 6c73 652c 2274 6d73 7422 3a31 3433  false,"tmst":143
        0x0040:  3639 3937 3637 352c 2266 7265 7122 3a38  6997675,"freq":8
        0x0050:  3638 2e35 2c22 7266 6368 223a 302c 2270  68.5,"rfch":0,"p
        0x0060:  6f77 6522 3a31 342c 226d 6f64 7522 3a22  owe":14,"modu":"
        0x0070:  4c4f 5241 222c 2264 6174 7222 3a22 5346  LORA","datr":"SF
        0x0080:  3742 5731 3235 222c 2263 6f64 7222 3a22  7BW125","codr":"
        0x0090:  342f 3522 2c22 6970 6f6c 223a 7472 7565  4/5","ipol":true
        0x00a0:  2c22 7369 7a65 223a 3134 2c22 6461 7461  ,"size":14,"data
        0x00b0:  223a 2259 4830 6141 5359 4141 5141 426b  ":"YH0aASYAAQABk
        0x00c0:  5a74 4a6d 7634 3d22 7d7d                 ZtJmv4="}}
10:19:57.538524 IP 2.43.193.163.44112 > 52.169.76.203.1700: UDP, length 12
        0x0000:  4500 0028 067c 4000 4011 ef06 022b c1a3  E..(.|@.@....+..
        0x0010:  34a9 4ccb ac50 06a4 0014 1206 01c7 e402  4.L..P..........
        0x0020:  0000 024b 0803 0571                      ...K...q
10:19:57.785606 IP 52.169.76.203.1700 > 2.43.193.163.44112: UDP, length 4
        0x0000:  4500 0020 3072 4000 2c11 d918 34a9 4ccb  E...0r@.,...4.L.
        0x0010:  022b c1a3 06a4 ac50 000c 21d3 01c7 e404  .+.....P..!.....
10:19:59.952094 IP 2.43.193.163.33372 > 52.169.76.203.1700: UDP, length 111
        0x0000:  4500 008b 067d 4000 4011 eea2 022b c1a3  E....}@.@....+..
        0x0010:  34a9 4ccb 825c 06a4 0077 ae79 0124 8300  4.L..\...w.y.$..
        0x0020:  0000 024b 0803 0571 7b22 7374 6174 223a  ...K...q{"stat":
        0x0030:  7b22 7469 6d65 223a 2232 3031 372d 3031  {"time":"2017-01
        0x0040:  2d32 3720 3039 3a31 393a 3539 2047 4d54  -27.09:19:59.GMT
        0x0050:  222c 2272 786e 6222 3a32 2c22 7278 6f6b  ","rxnb":2,"rxok
        0x0060:  223a 312c 2272 7866 7722 3a31 2c22 6163  ":1,"rxfw":1,"ac
        0x0070:  6b72 223a 302e 302c 2264 776e 6222 3a31  kr":0.0,"dwnb":1
        0x0080:  2c22 7478 6e62 223a 317d 7d              ,"txnb":1}}
10:20:00.505729 IP 52.169.76.203.1700 > 2.43.193.163.33372: UDP, length 4
        0x0000:  4500 0020 32d4 4000 2c11 d6b6 34a9 4ccb  E...2.@.,...4.L.
        0x0010:  022b c1a3 06a4 825c 000c ad6d 0124 8301  .+.....\...m.$..

Few considerations:

  • I have noticed that I don’t see ACK traffic after a packet is being sent, so I guess that if a packet get lost no way to recognize that event.

  • Downlink packets are sent 1 sec after uplink, so Arduino should get them in the RX1 first slot. Is that supposed to work with LMIC library? @matthijs

  • Downlink packets are sent over the same channel used for uplink. I have seen from your log that it has been forwarded on the 869.525 MHZ with SF9BW125 instead. Is that normal? As far as I recall the uplink transmission should be accomplished with a SF9…but maybe I am wrong.

Once again, many thanks for your support. Looking forward for your feedback!

That could well be the case. I do not know the typical response times for IP traffic for your GSM provider.

For join the windows are at 5 and 6 seconds ± 20 microseconds after the node transmitted the packet, windows length depends on the implementation but is probably about about 0.3 seconds at SF12.

No, it is false for ONE of the radios. The other radio takes care of all transmissions.

You should be using the configuartion from TTN Github That one is set correctly.

That seems to be the case.

Looking at multiple traces you provided I am sure your gateway receives data late. Looking at the latest trace:
11:04:50.435723 is join request.
11:04:55.914887 is join accept response
Time difference is 5.479164 seconds. That should have been at most 4.9 seconds to allow the gateway software some processing time. (The relative timestamp tmst in the join request is 998979548 microseconds, in the accept it’s 1003979548. So TTN wants the gateway to send the join accept 5000000 microseconds after receiving the join request.)

10:52:06.493745 uplink packet from node
10:52:07.880705 downlink response.
Time difference is 1.38696 which again is well beyond the limits. (Timestamps being 235026052 and 236026052, hence 1000000 microseconds difference.)

The thing to look at now is why the data is getting to your gateway late. That is something network related between your gateway and TTN router because TTN sends data in a timely manner for other gateways.

1 Like

Just noticed that the 3rd logs were sent from a different gateway IP address? Is that to be expected, or is it a different gateway?

@arjanvanb,

same gateway, I am using DHCP and the ABP log was made at a different time.

Hi @kersing, @arjanvanb,

I post the answer that I’ve got finally from Kerlink Support. They have also failed into the attempt of connecting to TTN over GSM.

Hello Mr Forte,

I installed the “the thing network” packet forwarder. When using GSM, I received multiple join procedures from the mote and no data packets. The join procedure isn’t successful.
Do you receive multiple join procedure?

When using Ethernet, it works perfectly and I can reboot my mote as many time as I want without any problem (no need to reboot the station).

It seems like there is a problem with your packet forwarder.
In my opinion, a too high ping with the server might be the problem. Also, there may be a bad synchronization between the server and the station. When receiving a packet from the server the packet forwarder display something like that:

INFO: [down] a packet will be sent on timestamp value 123126684

Displaying the current timestamp may be a good start to see if there is a problem.

As you are not using official Kerlink packet forwarder I cannot help you more. To begin with, we usually recommend our client to use our packet forwarder with the Semtech server but their server is not working with OTAA right now.

Your json files are OK. There are two front-ends able to handle radio frequencies. The “tx_enable: true” field defines which front-end will send packets. The defined frequencies (868.1 MHz / 868.3 MHz / 868.5 MHz) that are configured into radio 1 are only used to receive packets.

There is a point I cannot check myself. The json files describes the radio calibration parameters: Did you check them with the following instruction?

wiki:calibration [Wirnet™ Station]

Also, make sure your station is at least 5 meters away from your motes. I doubt it will solve your problems but it is recommended.

I dug deeper into the problem and there are few considerations I would like to share with you:

  • As far as I understood, after the uplink transmission the end-node will open an RX1 slot at the same frequency used for the uplink, and a second receive window (RX2) at a fixed frequency that should be set according the one used by TTN server. On my own Kerlink Gateway there are two radio front-ends able to handle the set of Lora frequency, one only used to receive packets from end-node, and the second one to transmit packets from the server to Lora side. In my case, I am using the 3 standard channels from Lora specification (868.1/868.3/868.5) to send uplink packets: these same frequency cannot send data packets back according to the way are configured into Kerlink Gateway, so I guess that I will never receive downlink within RX1 slot. Therefore, I should focus on the only RX2 slot. TTN uses f=869.525 MHz (SF9BW125), but this frequency is not set into none of the two radio front-ends (see TTN Github). In addition, the “ttn-abp.ino” arduino sketch provided along with LMIC library clearly states:
 // TTN defines an additional channel at 869.525Mhz using SF9 for class B
    // devices' ping slots. LMIC does not have an easy way to define set this
    // frequency and support for class B is spotty and untested, so this
    // frequency is not configured here. 

As result, above all said, I will never get downlink packets in RX2 window as well. Taking a step back, I would like to post once again a log that I simply got running a very basic ABP arduino sketch.

/* ABP activated device. Downlink packet sent to endnode 1 sec after "Hello World!" uplink.
However, LMIC.dataLen=0 on Arduino side meaning no downlink packet has been received. */

10:19:53.487901 IP 2.43.193.163.33372 > 52.169.76.203.1700: UDP, length 247
        0x0000:  4500 0113 067b 4000 4011 ee1c 022b c1a3  E....{@.@....+..
        0x0010:  34a9 4ccb 825c 06a4 00ff 832b 0135 c100  4.L..\.....+.5..
        0x0020:  0000 024b 0803 0571 7b22 7278 706b 223a  ...K...q{"rxpk":
        0x0030:  5b7b 2274 6d73 7422 3a31 3433 3539 3937  [{"tmst":1435997
        0x0040:  3637 352c 2274 696d 6522 3a22 3230 3137  675,"time":"2017
        0x0050:  2d30 312d 3237 5430 393a 3139 3a35 332e  -01-27T09:19:53.
        0x0060:  3438 3733 3032 5a22 2c22 6368 616e 223a  487302Z","chan":
        0x0070:  322c 2272 6663 6822 3a31 2c22 6672 6571  2,"rfch":1,"freq
        0x0080:  223a 3836 382e 3530 3030 3030 2c22 7374  ":868.500000,"st
        0x0090:  6174 223a 312c 226d 6f64 7522 3a22 4c4f  at":1,"modu":"LO
        0x00a0:  5241 222c 2264 6174 7222 3a22 5346 3742  RA","datr":"SF7B
        0x00b0:  5731 3235 222c 2263 6f64 7222 3a22 342f  W125","codr":"4/
        0x00c0:  3522 2c22 6c73 6e72 223a 372e 322c 2272  5","lsnr":7.2,"r
        0x00d0:  7373 6922 3a2d 3333 2c22 7369 7a65 223a  ssi":-33,"size":
        0x00e0:  3236 2c22 6461 7461 223a 2251 4830 6141  26,"data":"QH0aA
        0x00f0:  5361 4142 5141 424e 7863 3963 5a54 4d79  SaABQABNxc9cZTMy
        0x0100:  6a36 4342 4676 5571 6679 5938 5a6b 3d22  j6CBFvUqfyY8Zk="
        0x0110:  7d5d 7d                                  }]}
10:19:54.295617 IP 52.169.76.203.1700 > 2.43.193.163.33372: UDP, length 4
        0x0000:  4500 0020 2dc5 4000 2c11 dbc5 34a9 4ccb  E...-.@.,...4.L.
        0x0010:  022b c1a3 06a4 825c 000c 6f5c 0135 c101  .+.....\..o\.5..
10:19:54.936678 IP 52.169.76.203.1700 > 2.43.193.163.44112: UDP, length 174
        0x0000:  4500 00ca 2e13 4000 2c11 dacd 34a9 4ccb  E.....@.,...4.L.
        0x0010:  022b c1a3 06a4 ac50 00b6 ac81 0100 0003  .+.....P........
        0x0020:  7b22 7478 706b 223a 7b22 696d 6d65 223a  {"txpk":{"imme":
        0x0030:  6661 6c73 652c 2274 6d73 7422 3a31 3433  false,"tmst":143
        0x0040:  3639 3937 3637 352c 2266 7265 7122 3a38  6997675,"freq":8
        0x0050:  3638 2e35 2c22 7266 6368 223a 302c 2270  68.5,"rfch":0,"p
        0x0060:  6f77 6522 3a31 342c 226d 6f64 7522 3a22  owe":14,"modu":"
        0x0070:  4c4f 5241 222c 2264 6174 7222 3a22 5346  LORA","datr":"SF
        0x0080:  3742 5731 3235 222c 2263 6f64 7222 3a22  7BW125","codr":"
        0x0090:  342f 3522 2c22 6970 6f6c 223a 7472 7565  4/5","ipol":true
        0x00a0:  2c22 7369 7a65 223a 3134 2c22 6461 7461  ,"size":14,"data
        0x00b0:  223a 2259 4830 6141 5359 4141 5141 426b  ":"YH0aASYAAQABk
        0x00c0:  5a74 4a6d 7634 3d22 7d7d                 ZtJmv4="}}

As you can see the downlink packet was sent back on Lora side on the 868.5 MHz frequency, which belong to “radio 1” Kerlink front-end, for which the “tx_enable” is set to FALSE. Now the questions I keep asking to myself are:

  1. Has the gateway sent this packet anyway?
  2. Has the gateway discarded this packet since it cannot use that frequency for transmission?
  3. Is the node supposed to say (in its uplink packet) which frequency the server must use for eventually sent downlink packets?
  4. Is the node really listening on 869.525 MHz with the current LMIC library implementation? (@matthijs)

Sorry if I was too long, despite that I think that sharing such experiences is of great value for anyone who, just like me, is eager to gain truly knowledge and understanding on Lora.
Of course, as always, I look forward to get your considerations.

Thanks again, wish you good day!

2 Likes

Nice research salvatore_forte ! We are struggling with the same questions. How do we know for sure if the node receives back from the TTN server in its either first or second receive window the payload the network server sends back downstream.

you mention : [quote=“salvatore_forte, post:48, topic:2025”]
However, LMIC.dataLen=0 on Arduino side meaning no downlink packet has been received.
[/quote]

Where do you see in your tcpdump -XX on the packet_forwarder that de dataLen is 0 ?
When I paste my txpk hereafter, one can see that size of the sent packet by the packet_forwarder is 29. Does this mean the LMIC.dataLen= 29 ?

12:23:20.022556 IP 52.169.76.203.1700 > 10.10.10.2.34773: UDP, length 195
0x0000: 84eb 18e5 5232 e48d 8cd3 5fe4 0800 4500 …R2…_…E.
0x0010: 00df e345 4000 3111 d048 34a9 4ccb 0a0a …E@.1…H4.L…
0x0020: 0a02 06a4 87d5 00cb 4b1f 0100 0003 7b22 …K…{"
0x0030: 7478 706b 223a 7b22 696d 6d65 223a 6661 txpk":{“imme”:fa
0x0040: 6c73 652c 2274 6d73 7422 3a32 3337 3237 lse,“tmst”:23727
0x0050: 3838 3034 2c22 6672 6571 223a 3836 392e 8804,“freq”:869.
0x0060: 3532 352c 2272 6663 6822 3a30 2c22 706f 525,“rfch”:0,“po
0x0070: 7765 223a 3237 2c22 6d6f 6475 223a 224c we”:27,“modu”:“L
0x0080: 4f52 4122 2c22 6461 7472 223a 2253 4639 ORA”,“datr”:“SF9
0x0090: 4257 3132 3522 2c22 636f 6472 223a 2234 BW125”,“codr”:“4
0x00a0: 2f35 222c 2269 706f 6c22 3a74 7275 652c /5”,“ipol”:true,
0x00b0: 2273 697a 6522 3a32 392c 2264 6174 6122 “size”:29,“data”
0x00c0: 3a22 5946 6358 4153 5941 5a67 7342 6858 :“YFcXASYAZgsBhX
0x00d0: 716e 7657 486b 4376 446d 5139 5447 5a66 qnvWHkCvDmQ9TGZf
0x00e0: 2b37 665a 7373 4f55 673d 227d 7d +7fZssOUg=”}}

With mqtt I can show in Node-red the device/down/scheduled and device/down/sent topics. There is also a device/down/ack topic that should conclude the transmission which acknowlegdes the reveiving of the sent packet from the gw. In my case, I see none of these. I am not sure if this has got to do with it. Any clue on this part ?

Please do continue your research on the downlink capability of TTN, hopelfully we can contribute too. On another post we talked about it too : Dragino GPS Tracker.

Have a nice day !

1 Like

Hi @wdebbaut,

many thanks for the support, the replies that I have got from all of you have been very helpful so far! To answer your question:

Where do you see in your tcpdump -XX on the packet_forwarder that de dataLen is 0 ?

“dataLen” is a parameter declared within the LMIC struct, I just printed it out inside the arduino sketch, and this has allowed me to do a bit of debugging also on end-node side. As I said before, basically it gives you the number of bytes of the received payload. In my case always =0, indicating that I am not getting any packet at all.

Now I am wondering if the “txpk” I see in the log you posted is the actual JOIN_ACCEPT message to deliver to node, or just an acknowledgement, also considering what @arjanvanb said few posts ago:

the size of the acknowledgement might give you an indication if the gateway thinks all is fine? The NONE is 29 bytes, the TOO_LATE is 33 bytes.

In my case, the size of the sent packets is always 33 bytes, further confirming that the message is arriving too late. In order to make a fair comparison with the missing reception of downlink packets I am facing, would you be so kind to post the complete log you get running tcpdump command? Precisely, you might start from the uplink message (JOIN_REQUEST) sent from gateway to TTN, and then the downlink that follows.

I repost my log (OTAA not working) for your comprehension:

/* OTAA activation tentative. Device not activated! JOIN_ACCEPT message forwarded to endnode
5 seconds after JOIN_REQUEST */

11:04:50.435723 IP 31.157.192.137.49457 > 52.169.76.203.1700: UDP, length 243
        0x0000:  4500 010f c9ec 4000 4011 0e57 1f9d c089  E.....@.@..W....
        0x0010:  34a9 4ccb c131 06a4 00fb c605 01d9 6700  4.L..1........g.
        0x0020:  0000 024b 0803 0571 7b22 7278 706b 223a  ...K...q{"rxpk":
        0x0030:  5b7b 2274 6d73 7422 3a39 3938 3937 3935  [{"tmst":9989795
        0x0040:  3438 2c22 7469 6d65 223a 2232 3031 372d  48,"time":"2017-
        0x0050:  3031 2d32 3754 3130 3a30 343a 3530 2e34  01-27T10:04:50.4
        0x0060:  3335 3131 315a 222c 2263 6861 6e22 3a30  35111Z","chan":0
        0x0070:  2c22 7266 6368 223a 312c 2266 7265 7122  ,"rfch":1,"freq"
        0x0080:  3a38 3638 2e31 3030 3030 302c 2273 7461  :868.100000,"sta
        0x0090:  7422 3a31 2c22 6d6f 6475 223a 224c 4f52  t":1,"modu":"LOR
        0x00a0:  4122 2c22 6461 7472 223a 2253 4638 4257  A","datr":"SF8BW
        0x00b0:  3132 3522 2c22 636f 6472 223a 2234 2f35  125","codr":"4/5
        0x00c0:  222c 226c 736e 7222 3a31 312e 382c 2272  ","lsnr":11.8,"r
        0x00d0:  7373 6922 3a2d 3335 2c22 7369 7a65 223a  ssi":-35,"size":
        0x00e0:  3233 2c22 6461 7461 223a 2241 4730 7a41  23,"data":"AG0zA
        0x00f0:  5042 2b31 624e 774c 6439 376a 746d 5761  PB+1bNwLd97jtmWa
        0x0100:  5144 675a 3552 3932 4e77 3d22 7d5d 7d    QDgZ5R92Nw="}]}
11:04:51.254810 IP 52.169.76.203.1700 > 31.157.192.137.49457: UDP, length 4
        0x0000:  4500 0020 b229 4000 2c11 3b09 34a9 4ccb  E....)@.,.;.4.L.
        0x0010:  1f9d c089 06a4 c131 000c 6d8b 01d9 6701  .......1..m...g.
11:04:55.914887 IP 52.169.76.203.1700 > 31.157.192.137.44731: UDP, length 198
        0x0000:  4500 00e2 b68a 4000 2c11 35e6 34a9 4ccb  E.....@.,.5.4.L.
        0x0010:  1f9d c089 06a4 aebb 00ce a1a4 0100 0003  ................
        0x0020:  7b22 7478 706b 223a 7b22 696d 6d65 223a  {"txpk":{"imme":
        0x0030:  6661 6c73 652c 2274 6d73 7422 3a31 3030  false,"tmst":100
        0x0040:  3339 3739 3534 382c 2266 7265 7122 3a38  3979548,"freq":8
        0x0050:  3638 2e31 2c22 7266 6368 223a 302c 2270  68.1,"rfch":0,"p
        0x0060:  6f77 6522 3a31 342c 226d 6f64 7522 3a22  owe":14,"modu":"
        0x0070:  4c4f 5241 222c 2264 6174 7222 3a22 5346  LORA","datr":"SF
        0x0080:  3842 5731 3235 222c 2263 6f64 7222 3a22  8BW125","codr":"
        0x0090:  342f 3522 2c22 6970 6f6c 223a 7472 7565  4/5","ipol":true
        0x00a0:  2c22 7369 7a65 223a 3333 2c22 6461 7461  ,"size":33,"data
        0x00b0:  223a 2249 4779 6469 494b 5073 6b77 3064  ":"IGydiIKPskw0d
        0x00c0:  5230 7654 4234 686e 3463 4f48 6462 6b64  R0vTB4hn4cOHdbkd
        0x00d0:  5967 622f 4458 6874 2f6c 4872 4f79 4222  Ygb/DXht/lHrOyB"
        0x00e0:  7d7d                                     }}

With regard to my log, I can definitely say:

  • “tmst_rxpk”=998979548 us / “tmst_txpk”=1003979548 us (difference = 5 sec, so TTN tell the gateway to send the downlink packet 5 sec after the received uplink)

  • “time_rxpk”=11:04:50.435723 / “time_txpk”=11:04:55.914887 (difference = 5.479164 sec, so the downlink message arrives later than the time scheduled by TTN for sending message back to end-node).

…but you’re not using Class B devices, right? (TTN does not support that anyhow.)

For a node it will be set AFTER a successful OTAA Join, as the Join Accept then includes those values and the node will configure those. However, for the Join Accept itself, TTN will use the standard, being 869.525 MHz / DR0 (SF12, 125 kHz). So, even if regular downlinks do not work, the Join Accept should. (And it does, for some time after you restart the gateway. So if the node uses the right channels, then the gateway must do so too?)

I find the findings about radio configuration in the Kerlink interesting, but not my cup of tea so I have no answers to that. But remember that after a restart your gateway is surely sending the OTAA Join Accept and the node surely receives it. And for subsequent downlinks we’ve seen that for you (@salvatore_forte), the packets arrive at your gateway too late to be received by a node (if even sent by the gateway when being too late anyhow). So I doubt there is also a problem in the channel configurations… (I’d guess you’re misinterpreting the gateway’s configuration.)

If anyone else is facing the same problem, but with downlinks arriving at the gateway in time: any chance that after the first OTAA Join Accepts/downlinks the gateway’s radios are configured differently, or are left in some weird state…? And: how many nodes can join after a restart of the gateway?

When referring to YFcXASYAZgsBhXqnvWHkCvDmQ9TGZf+7fZssOUg=, that is an unconfirmed data down. It’s not a Join Accept, like mine was.

Your above Base64-encoded txpk packet of IGydiIKPskw0dR0vTB4hn4cOHdbkdYgb/DXht/lHrOyB indeed is 33 bytes, but it is a Join Accept. Your log above does not show if the gateway sent anything back to the server to acknowledge whether or not it forwarded it.

In my explanation of “Line E” above, I was referring to the size of txpk_ack acknowledgement packets, which in my logs are not Base64 encoded but plain readable JSON. These packets are sent from gateway to server, so can simply use JSON as they have no size limit; the Base64 txpk is sent from server to node (via the gateway) and is binary-encoded according to the LoRaWAN specifications, to save bandwidth.

You are right so far.

No, both are set to receive data from nodes if you are using the TTN configuration. One will also be used to transmit.

Your gateway will be able to send at any frequency requested by TTN. You do not configure the transmit frequencies in the json files.

Wrong assumption.

Again, the transmit frequencies are not specified in the global_conf.json file.

As I stated before, the cause of you issues is timing. You are only confusing yourself by looking elsewhere. Again, the information you posted clearly shows the data to transmit is received at the gateway after it should have been transmitted. As such the node will never receive it. To solve you issue you need to find why the network connection is ‘slow’ or why its speed varies over time.
One thing you could try is to start a ‘ping www.google.com’ on the gateway and look at the times response time for the ping packets.

1 Like