Hello,
I am trying to integrate a Tabs.io Object locator that supposidely works with LoRaWAN v1.1
However, I am having trouble with the OTAA join of this node. It seems to be stuck in a constant join-request join-accept loop. It’s as if the node is not accepting the downlink message containing the join accept message. I am confident that the application key and the network keys that the manufacturer has given me are correct, since the Loraserver AS has computed and validated them properly. What could the source of the problem? What should I be checking right now?
Here is the loraserver log contents:
Aug 08 16:19:38 brocaar loraserver[18040]: time="2018-08-08T16:19:38Z" level=info msg="backend/gateway: rx packet received"
Aug 08 16:19:38 brocaar loraserver[18040]: time="2018-08-08T16:19:38Z" level=info msg="packet(s) collected" dev_eui=58a0cb000020219f gw_count=1 gw_macs=647fdafffe005172 mtype=JoinRequest
Aug 08 16:19:38 brocaar loraserver[18040]: time="2018-08-08T16:19:38Z" level=debug msg="sql query executed" args="[[88 160 203 0 0 32 33 159]]" duration=1.078699ms query="select * from device where dev_eui = $1"
Aug 08 16:19:38 brocaar loraserver[18040]: time="2018-08-08T16:19:38Z" level=debug msg="sql query executed" args="[7e59e9ee-0ef3-4d65-be96-1beb19ab590e]" duration=1.223146ms query="\n select\n created_at,\n updated_at,\n\n device_profile_id,\n supports_class_b,\n class_b_timeout,\n
Aug 08 16:19:38 brocaar loraserver[18040]: time="2018-08-08T16:19:38Z" level=debug msg="sql query executed" args="[4a42154b-8139-4134-a51f-7d660cbf1056]" duration=1.751239ms query="select * from service_profile where service_profile_id = $1"
Aug 08 16:19:38 brocaar loraserver[18040]: time="2018-08-08T16:19:38Z" level=debug msg="sql query executed" args="[58a0cb000020219f 58a0cb0000210000 49131 JoinRequestType]" duration="760.44µs" query="\n\t\tselect\n\t\t\tcount(*)\n\t\tfrom\n\t\t\tdevice_activation\n\t\twhere\n\t\t\tdev_eui = $1\n\t\t\tand join_eui = $2\n\t\t\tand dev_nonce = $3\
Aug 08 16:19:38 brocaar loraserver[18040]: time="2018-08-08T16:19:38Z" level=debug msg="sql query executed" args="[[88 160 203 0 0 32 33 159]]" duration="499.151µs" query="delete from device_queue where dev_eui = $1"
Aug 08 16:19:38 brocaar loraserver[18040]: time="2018-08-08T16:19:38Z" level=info msg="device-queue flushed" dev_eui=58a0cb000020219f
Aug 08 16:19:38 brocaar loraserver[18040]: time="2018-08-08T16:19:38Z" level=info msg="device-session saved" dev_addr=002a715b dev_eui=58a0cb000020219f
Aug 08 16:19:38 brocaar loraserver[18040]: time="2018-08-08T16:19:38Z" level=debug msg="sql query executed" args="[2018-08-08 16:19:38.36084225 +0000 UTC m=+422.156184668 [88 160 203 0 0 32 33 159] [88 160 203 0 0 33 0 0] [0 42 113 91] [119 63 88 0 57 124 12 173 60 91 91 120 20 21 198 124] [150 24 170 144 101 107 66 169 254 91 77 205 77 153 25
Aug 08 16:19:38 brocaar loraserver[18040]: time="2018-08-08T16:19:38Z" level=info msg="device-activation created" dev_eui=58a0cb000020219f id=63
Aug 08 16:19:38 brocaar loraserver[18040]: time="2018-08-08T16:19:38Z" level=info msg="backend/gateway: publishing tx packet" qos=0 topic=gateway/647fdafffe005172/tx
Aug 08 16:19:38 brocaar loraserver[18040]: time="2018-08-08T16:19:38Z" level=debug msg="running class-c scheduler batch"
Aug 08 16:19:38 brocaar loraserver[18040]: time="2018-08-08T16:19:38Z" level=debug msg="sql query executed" args="[100 338272h19m58.858005474s]" duration=1.221063ms query="\n select\n d.*\n from\n device d\n inner join device_profile dp\n on dp.device_profile_id = d.device_profile_id\n
Aug 08 16:19:39 brocaar loraserver[18040]: time="2018-08-08T16:19:39Z" level=debug msg="running class-c scheduler batch"
Aug 08 16:19:39 brocaar loraserver[18040]: time="2018-08-08T16:19:39Z" level=debug msg="sql query executed" args="[100 338272h19m59.861313895s]" duration=1.300829ms query="\n select\n d.*\n from\n device d\n inner join device_profile dp\n on dp.device_profile_id = d.device_profile_id\n
Aug 08 16:19:40 brocaar loraserver[18040]: time="2018-08-08T16:19:40Z" level=debug msg="running class-c scheduler batch"
Aug 08 16:19:40 brocaar loraserver[18040]: time="2018-08-08T16:19:40Z" level=debug msg="sql query executed" args="[100 338272h20m0.864493169s]" duration=1.246902ms query="\n select\n d.*\n from\n device d\n inner join device_profile dp\n on dp.device_profile_id = d.device_profile_id\n
Aug 08 16:19:41 brocaar loraserver[18040]: time="2018-08-08T16:19:41Z" level=debug msg="running class-c scheduler batch"
Aug 08 16:19:41 brocaar loraserver[18040]: time="2018-08-08T16:19:41Z" level=debug msg="sql query executed" args="[100 338272h20m1.867835039s]" duration=1.200748ms query="\n select\n d.*\n from\n device d\n inner join device_profile dp\n on dp.device_profile_id = d.device_profile_id\n
Aug 08 16:19:42 brocaar loraserver[18040]: time="2018-08-08T16:19:42Z" level=debug msg="running class-c scheduler batch"
Aug 08 16:19:42 brocaar loraserver[18040]: time="2018-08-08T16:19:42Z" level=debug msg="sql query executed" args="[100 338272h20m2.871140202s]" duration=1.31786ms query="\n select\n d.*\n from\n device d\n inner join device_profile dp\n on dp.device_profile_id = d.device_profile_id\n
Aug 08 16:19:43 brocaar loraserver[18040]: time="2018-08-08T16:19:43Z" level=debug msg="running class-c scheduler batch"
Aug 08 16:19:43 brocaar loraserver[18040]: time="2018-08-08T16:19:43Z" level=debug msg="sql query executed" args="[100 338272h20m3.874695679s]" duration=1.374857ms query="\n select\n d.*\n from\n device d\n inner join device_profile dp\n on dp.device_profile_id = d.device_profile_id\n
Aug 08 16:19:44 brocaar loraserver[18040]: time="2018-08-08T16:19:44Z" level=debug msg="running class-c scheduler batch"
Aug 08 16:19:44 brocaar loraserver[18040]: time="2018-08-08T16:19:44Z" level=debug msg="sql query executed" args="[100 338272h20m4.878647443s]" duration=1.926801ms query="\n select\n d.*\n from\n device d\n inner join device_profile dp\n on dp.device_profile_id = d.device_profile_id\n
Aug 08 16:19:45 brocaar loraserver[18040]: time="2018-08-08T16:19:45Z" level=debug msg="running class-c scheduler batch"
Aug 08 16:19:45 brocaar loraserver[18040]: time="2018-08-08T16:19:45Z" level=debug msg="sql query executed" args="[100 338272h20m5.883250509s]" duration=1.243913ms query="\n select\n d.*\n from\n device d\n inner join device_profile dp\n on dp.device_profile_id = d.device_profile_id\n
Aug 08 16:19:46 brocaar loraserver[18040]: time="2018-08-08T16:19:46Z" level=debug msg="running class-c scheduler batch"
Aug 08 16:19:46 brocaar loraserver[18040]: time="2018-08-08T16:19:46Z" level=debug msg="sql query executed" args="[100 338272h20m6.886694711s]" duration=1.157913ms query="\n select\n d.*\n from\n device d\n inner join device_profile dp\n on dp.device_profile_id = d.device_profile_id\n
I sniffed the packets coming in and out of the lora server, and I see that the gateway is receiving the packets fine when the downlink packet is sent from the gateway because it is sending an ack.
Sent by the gateway bridge:
{
“txpk”:
{
“imme”:false,
“tmst”:2139894516,
“freq”:925.1,
“rfch”:0,
“powe”:20,
“modu”:“LORA”,
“datr”:“SF10BW500”,
“codr”:“4/5”,
“ipol”:true,
“size”:33,
“data”:“IAIWZEDXFM1JBlqVjhein020k+nA05Y5jsLurMU78OpL”,
“brd”:0,
“ant”:0
}
}
Received from
{"txpk_ack":{"error":"NONE"}}
Is there a way to see the logical contents of the join accept through some sort of log? NetID, downlink parameters, etc…
Thanks,
Alex