Rough numbers from a Join here:
Serial log says:
2022-02-17 15:37:53 → LoRaWAN_Start
2022-02-17 15:37:53 → 6s810:TX on freq 868300000 Hz at DR 0
2022-02-17 15:37:54 → OnMacProcessNotify
2022-02-17 15:37:54 → 8s345:MAC txDone
2022-02-17 15:37:59 → 13s379:RX_1 on freq 868300000 Hz at DR 0
2022-02-17 15:38:01 → OnMacProcessNotify
2022-02-17 15:38:01 → 15s187:MAC rxDone
2022-02-17 15:38:01 → OnTxData - after transmission
2022-02-17 15:38:01 → OnJoinRequest
2022-02-17 15:38:01 →
2022-02-17 15:38:01 → ##### = JOINED = OTAA
2022-02-17 15:38:01 → First uplink in 5s
2022-02-17 15:38:01 →
2022-02-17 15:38:01 → OnRxData
2022-02-17 15:38:01 → Received: D/L FRAME:0000 | SLOT:1 | PORT:0 | DR:0 | RSSI:-99 | SNR:10
2022-02-17 15:38:01 → DOWNLINK:
This one is upside down so scroll in the box to see the details.
{
"name": "as.up.join.forward",
"time": "2022-02-17T15:37:56.519017586Z", <-- This is when it left the application server
"identifiers": [
{
"device_ids": {
"device_id": "x",
"application_ids": {
"application_id": "x"
}
}
},
{
"device_ids": {
"device_id": "x",
"application_ids": {
"application_id": "x"
},
"dev_eui": "x",
"join_eui": "x",
"dev_addr": "260BD10B"
}
}
],
"data": {
"@type": "type.googleapis.com/ttn.lorawan.v3.ApplicationUp",
"end_device_ids": {
"device_id": "x",
"application_ids": {
"application_id": "x"
},
"dev_eui": "x",
"join_eui": "x",
"dev_addr": "260BD10B"
},
"correlation_ids": [
],
"received_at": "2022-02-17T15:37:56.517453194Z",
"join_accept": {
"session_key_id": "AX8IVS8iToAMfhNIXdFHfw==",
"received_at": "2022-02-17T15:37:54.705234370Z"
}
},
"correlation_ids": [
],
"origin": "ip-10-100-15-123.eu-west-1.compute.internal",
"context": {
"tenant-id": "CgN0dG4="
},
"visibility": {
},
"unique_id": "01FW45ADH7534T2RC3E1XW09YN"
},
{
"name": "js.join.accept",
"time": "2022-02-17T15:37:54.724582570Z", <-- This is when it hit the application server
"identifiers": [
{
"device_ids": {
"device_id": "x",
"application_ids": {
"application_id": "x"
}
}
},
{
"device_ids": {
"device_id": "x",
"application_ids": {
"application_id": "x"
},
"dev_eui": "x",
"join_eui": "x",
"dev_addr": "260BD10B"
}
}
],
"correlation_ids": [
],
"origin": "ip-10-100-12-108.eu-west-1.compute.internal",
"context": {
"tenant-id": "CgN0dG4="
},
"visibility": {
},
"unique_id": "01FW45ABS41CY4HEHXNNSS6D9T"
},
- Device sends Join Request at 2022-02-17 15:37:53
- Device console gets notification at 2022-02-17T15:37:54.724582570Z
- App server sends out the Join Accept at 2022-02-17T15:37:56.519017586Z
- Device gets the Join Accept at 2022-02-17 15:37:59
The serial log output has no decimal places and won’t be accurately aligned with the TTS time, but both on are on NTP so close enough. And there is the transmission time plus the whole serial port delays.
- So, about 1 second to go from device to gateway to gateway server to network server to application server.
- Join Accept leaves 1.79 seconds later - presumably takes about a second to thread through the gateway server and on to the gateway.
- This is ~ 3.8 seconds.
- Device reports arrival of transmission in first slot 6 seconds after it sent the join - allowing for rounding errors we can call that 5, as expected
- There was 1.2 seconds spare.
These numbers are lacking in any rigor or precision, but it gives you some idea of timings.
Next time I do a join (in the morning), I’ll remember to leave the gateway console open and log in to the gateway log so we can see some much more accurate timings.