Hi everyone. We’re trying to implement a LoRa network in my college, for which we’re using a Multitech Conduit gateway with the Multi Protocol Packet Forwarder (https://github.com/kersing/packet_forwarder) using the US915 frequency plan, set up to forward packets to a LoRa Server instance we installed in our network, with LoPy and Microchip RN2903 nodes. We were doing some tests with the nodes, trying to make an OTAA Join, but we encountered a problem. We can see the Join Requests at the LoRa Server web log, and also that a Join Accept is generated, but the nodes aren’t receiving the Accept for some reason. Also, when using ABP, and sending a confirmed uplink (tested with the Microchip node), the packet is received but the acknowledgement isn’t generated. We tried running tcpdump at the gateway and we can see that the downlink Join Accept packets are arriving, but they never arrive to the nodes, so we’re suspecting that it can be a problem regarding the frequency channels, but we can’t find where the failure is.
These are the LoRa Server logs:
Gateway Bridge:
feb 08 11:02:59 loraserverlcd-VirtualBox lora-gateway-bridge[986]: time=“2018-02-08T11:02:59-03:00” level=info msg=“backend: publishing packet” topic=“gateway/00800000a0001261/ack”
feb 08 11:03:02 loraserverlcd-VirtualBox lora-gateway-bridge[986]: time=“2018-02-08T11:03:02-03:00” level=info msg=“gateway: received udp packet from gateway” addr=192.168.1.9:42724 protocol_version=2 type=PullData
feb 08 11:03:02 loraserverlcd-VirtualBox lora-gateway-bridge[986]: time=“2018-02-08T11:03:02-03:00” level=info msg=“gateway: sending udp packet to gateway” addr=192.168.1.9:42724 protocol_version=2 type=PullACK
feb 08 11:03:07 loraserverlcd-VirtualBox lora-gateway-bridge[986]: time=“2018-02-08T11:03:07-03:00” level=info msg=“gateway: received udp packet from gateway” addr=192.168.1.9:51252 protocol_version=2 type=PushData
feb 08 11:03:07 loraserverlcd-VirtualBox lora-gateway-bridge[986]: time=“2018-02-08T11:03:07-03:00” level=info msg=“gateway: stat packet received” addr=192.168.1.9:51252 mac=00800000a0001261
feb 08 11:03:07 loraserverlcd-VirtualBox lora-gateway-bridge[986]: time=“2018-02-08T11:03:07-03:00” level=info msg=“backend: publishing packet” topic=“gateway/00800000a0001261/stats”
feb 08 11:03:07 loraserverlcd-VirtualBox lora-gateway-bridge[986]: time=“2018-02-08T11:03:07-03:00” level=info msg=“gateway: sending udp packet to gateway” addr=192.168.1.9:51252 protocol_version=2 type=PushACK
feb 08 11:03:13 loraserverlcd-VirtualBox lora-gateway-bridge[986]: time=“2018-02-08T11:03:13-03:00” level=info msg=“gateway: received udp packet from gateway” addr=192.168.1.9:42724 protocol_version=2 type=PullData
feb 08 11:03:13 loraserverlcd-VirtualBox lora-gateway-bridge[986]: time=“2018-02-08T11:03:13-03:00” level=info msg=“gateway: sending udp packet to gateway” addr=192.168.1.9:42724 protocol_version=2 type=PullACK
feb 08 11:03:13 loraserverlcd-VirtualBox lora-gateway-bridge[986]: time=“2018-02-08T11:03:13-03:00” level=info msg=“gateway: received udp packet from gateway” addr=192.168.1.9:51252 protocol_version=2 type=PushData
feb 08 11:03:13 loraserverlcd-VirtualBox lora-gateway-bridge[986]: time=“2018-02-08T11:03:13-03:00” level=info msg=“gateway: rxpk packet received” addr=192.168.1.9:51252 data=“AAEBAQEBAQEB+q8PlEnVs3D2RHYLJUo=” mac=00800000a0001261
feb 08 11:03:13 loraserverlcd-VirtualBox lora-gateway-bridge[986]: time=“2018-02-08T11:03:13-03:00” level=info msg=“backend: publishing packet” topic=“gateway/00800000a0001261/rx”
feb 08 11:03:13 loraserverlcd-VirtualBox lora-gateway-bridge[986]: time=“2018-02-08T11:03:13-03:00” level=info msg=“gateway: sending udp packet to gateway” addr=192.168.1.9:51252 protocol_version=2 type=PushACK
feb 08 11:03:14 loraserverlcd-VirtualBox lora-gateway-bridge[986]: time=“2018-02-08T11:03:14-03:00” level=info msg=“backend: packet received” topic=“gateway/00800000a0001261/tx”
feb 08 11:03:14 loraserverlcd-VirtualBox lora-gateway-bridge[986]: time=“2018-02-08T11:03:14-03:00” level=info msg=“gateway: sending udp packet to gateway” addr=192.168.1.9:42724 protocol_version=2 type=PullResp
feb 08 11:03:14 loraserverlcd-VirtualBox lora-gateway-bridge[986]: time=“2018-02-08T11:03:14-03:00” level=info msg=“gateway: received udp packet from gateway” addr=192.168.1.9:42724 protocol_version=2 type=TXACK
feb 08 11:03:14 loraserverlcd-VirtualBox lora-gateway-bridge[986]: time=“2018-02-08T11:03:14-03:00” level=info msg=“backend: publishing packet” topic=“gateway/00800000a0001261/ack”
feb 08 11:03:23 loraserverlcd-VirtualBox lora-gateway-bridge[986]: time=“2018-02-08T11:03:23-03:00” level=info msg=“gateway: received udp packet from gateway” addr=192.168.1.9:42724 protocol_version=2 type=PullData
feb 08 11:03:23 loraserverlcd-VirtualBox lora-gateway-bridge[986]: time=“2018-02-08T11:03:23-03:00” level=info msg=“gateway: sending udp packet to gateway” addr=192.168.1.9:42724 protocol_version=2 type=PullACK
feb 08 11:03:28 loraserverlcd-VirtualBox lora-gateway-bridge[986]: time=“2018-02-08T11:03:28-03:00” level=info msg=“gateway: received udp packet from gateway” addr=192.168.1.9:51252 protocol_version=2 type=PushData
feb 08 11:03:28 loraserverlcd-VirtualBox lora-gateway-bridge[986]: time=“2018-02-08T11:03:28-03:00” level=info msg=“gateway: rxpk packet received” addr=192.168.1.9:51252 data=“AAEBAQEBAQEB+q8PlEnVs3DJp8omqLo=” mac=00800000a0001261
feb 08 11:03:28 loraserverlcd-VirtualBox lora-gateway-bridge[986]: time=“2018-02-08T11:03:28-03:00” level=info msg=“backend: publishing packet” topic=“gateway/00800000a0001261/rx”
feb 08 11:03:28 loraserverlcd-VirtualBox lora-gateway-bridge[986]: time=“2018-02-08T11:03:28-03:00” level=info msg=“gateway: sending udp packet to gateway” addr=192.168.1.9:51252 protocol_version=2 type=PushACK
feb 08 11:03:29 loraserverlcd-VirtualBox lora-gateway-bridge[986]: time=“2018-02-08T11:03:29-03:00” level=info msg=“backend: packet received” topic=“gateway/00800000a0001261/tx”
feb 08 11:03:29 loraserverlcd-VirtualBox lora-gateway-bridge[986]: time=“2018-02-08T11:03:29-03:00” level=info msg=“gateway: sending udp packet to gateway” addr=192.168.1.9:42724 protocol_version=2 type=PullResp
feb 08 11:03:29 loraserverlcd-VirtualBox lora-gateway-bridge[986]: time=“2018-02-08T11:03:29-03:00” level=info msg=“gateway: received udp packet from gateway” addr=192.168.1.9:42724 protocol_version=2 type=TXACK
feb 08 11:03:29 loraserverlcd-VirtualBox lora-gateway-bridge[986]: time=“2018-02-08T11:03:29-03:00” level=info msg=“backend: publishing packet” topic=“gateway/00800000a0001261/ack”
feb 08 11:03:33 loraserverlcd-VirtualBox lora-gateway-bridge[986]: time=“2018-02-08T11:03:33-03:00” level=info msg=“gateway: received udp packet from gateway” addr=192.168.1.9:42724 protocol_version=2 type=PullData
feb 08 11:03:33 loraserverlcd-VirtualBox lora-gateway-bridge[986]: time=“2018-02-08T11:03:33-03:00” level=info msg=“gateway: sending udp packet to gateway” addr=192.168.1.9:42724 protocol_version=2 type=PullACK
feb 08 11:03:37 loraserverlcd-VirtualBox lora-gateway-bridge[986]: time=“2018-02-08T11:03:37-03:00” level=info msg=“gateway: received udp packet from gateway” addr=192.168.1.9:51252 protocol_version=2 type=PushData
feb 08 11:03:37 loraserverlcd-VirtualBox lora-gateway-bridge[986]: time=“2018-02-08T11:03:37-03:00” level=info msg=“gateway: stat packet received” addr=192.168.1.9:51252 mac=00800000a0001261
feb 08 11:03:37 loraserverlcd-VirtualBox lora-gateway-bridge[986]: time=“2018-02-08T11:03:37-03:00” level=info msg=“backend: publishing packet” topic=“gateway/00800000a0001261/stats”
feb 08 11:03:37 loraserverlcd-VirtualBox lora-gateway-bridge[986]: time=“2018-02-08T11:03:37-03:00” level=info msg=“gateway: sending udp packet to gateway” addr=192.168.1.9:51252 protocol_version=2 type=PushACK
feb 08 11:03:43 loraserverlcd-VirtualBox lora-gateway-bridge[986]: time=“2018-02-08T11:03:43-03:00” level=info msg=“gateway: received udp packet from gateway” addr=192.168.1.9:42724 protocol_version=2 type=PullData
feb 08 11:03:43 loraserverlcd-VirtualBox lora-gateway-bridge[986]: time=“2018-02-08T11:03:43-03:00” level=info msg=“gateway: sending udp packet to gateway” addr=192.168.1.9:42724 protocol_version=2 type=PullACK
feb 08 11:03:43 loraserverlcd-VirtualBox lora-gateway-bridge[986]: time=“2018-02-08T11:03:43-03:00” level=info msg=“gateway: received udp packet from gateway” addr=192.168.1.9:51252 protocol_version=2 type=PushData
feb 08 11:03:43 loraserverlcd-VirtualBox lora-gateway-bridge[986]: time=“2018-02-08T11:03:43-03:00” level=info msg=“gateway: rxpk packet received” addr=192.168.1.9:51252 data=“AAEBAQEBAQEB+q8PlEnVs3DHoYE60aY=” mac=00800000a0001261
feb 08 11:03:43 loraserverlcd-VirtualBox lora-gateway-bridge[986]: time=“2018-02-08T11:03:43-03:00” level=info msg=“backend: publishing packet” topic=“gateway/00800000a0001261/rx”
feb 08 11:03:43 loraserverlcd-VirtualBox lora-gateway-bridge[986]: time=“2018-02-08T11:03:43-03:00” level=info msg=“gateway: sending udp packet to gateway” addr=192.168.1.9:51252 protocol_version=2 type=PushACK
feb 08 11:03:44 loraserverlcd-VirtualBox lora-gateway-bridge[986]: time=“2018-02-08T11:03:44-03:00” level=info msg=“backend: packet received” topic=“gateway/00800000a0001261/tx”
feb 08 11:03:44 loraserverlcd-VirtualBox lora-gateway-bridge[986]: time=“2018-02-08T11:03:44-03:00” level=info msg=“gateway: sending udp packet to gateway” addr=192.168.1.9:42724 protocol_version=2 type=PullResp
feb 08 11:03:44 loraserverlcd-VirtualBox lora-gateway-bridge[986]: time=“2018-02-08T11:03:44-03:00” level=info msg=“gateway: received udp packet from gateway” addr=192.168.1.9:42724 protocol_version=2 type=TXACK
feb 08 11:03:44 loraserverlcd-VirtualBox lora-gateway-bridge[986]: time=“2018-02-08T11:03:44-03:00” level=info msg=“backend: publishing packet” topic=“gateway/00800000a0001261/ack”
feb 08 11:03:53 loraserverlcd-VirtualBox lora-gateway-bridge[986]: time=“2018-02-08T11:03:53-03:00” level=info msg=“gateway: received udp packet from gateway” addr=192.168.1.9:42724 protocol_version=2 type=PullData
feb 08 11:03:53 loraserverlcd-VirtualBox lora-gateway-bridge[986]: time=“2018-02-08T11:03:53-03:00” level=info msg=“gateway: sending udp packet to gateway” addr=192.168.1.9:42724 protocol_version=2 type=PullACK
feb 08 11:03:58 loraserverlcd-VirtualBox lora-gateway-bridge[986]: time=“2018-02-08T11:03:58-03:00” level=info msg=“gateway: received udp packet from gateway” addr=192.168.1.9:51252 protocol_version=2 type=PushData
feb 08 11:03:58 loraserverlcd-VirtualBox lora-gateway-bridge[986]: time=“2018-02-08T11:03:58-03:00” level=info msg=“gateway: rxpk packet received” addr=192.168.1.9:51252 data=“AAEBAQEBAQEB+q8PlEnVs3Ce4taN2J8=” mac=00800000a0001261
feb 08 11:03:58 loraserverlcd-VirtualBox lora-gateway-bridge[986]: time=“2018-02-08T11:03:58-03:00” level=info msg=“backend: publishing packet” topic=“gateway/00800000a0001261/rx”
feb 08 11:03:58 loraserverlcd-VirtualBox lora-gateway-bridge[986]: time=“2018-02-08T11:03:58-03:00” level=info msg=“gateway: sending udp packet to gateway” addr=192.168.1.9:51252 protocol_version=2 type=PushACK
feb 08 11:03:59 loraserverlcd-VirtualBox lora-gateway-bridge[986]: time=“2018-02-08T11:03:59-03:00” level=info msg=“backend: packet received” topic=“gateway/00800000a0001261/tx”
feb 08 11:03:59 loraserverlcd-VirtualBox lora-gateway-bridge[986]: time=“2018-02-08T11:03:59-03:00” level=info msg=“gateway: sending udp packet to gateway” addr=192.168.1.9:42724 protocol_version=2 type=PullResp
feb 08 11:03:59 loraserverlcd-VirtualBox lora-gateway-bridge[986]: time=“2018-02-08T11:03:59-03:00” level=info msg=“gateway: received udp packet from gateway” addr=192.168.1.9:42724 protocol_version=2 type=TXACK
feb 08 11:03:59 loraserverlcd-VirtualBox lora-gateway-bridge[986]: time=“2018-02-08T11:03:59-03:00” level=info msg=“backend: publishing packet” topic=“gateway/00800000a0001261/ack”
LoRa Server:
– Logs begin at jue 2018-02-08 09:13:27 -03. –
feb 08 11:55:38 loraserverlcd-VirtualBox loraserver[987]: time=“2018-02-08T11:55:38-03:00” level=info msg=“backend/gateway: gateway stats packet received” mac=00800000a0001261
feb 08 11:55:38 loraserverlcd-VirtualBox loraserver[987]: time=“2018-02-08T11:55:38-03:00” level=info msg=“gateway updated” mac=00800000a0001261
feb 08 11:56:08 loraserverlcd-VirtualBox loraserver[987]: time=“2018-02-08T11:56:08-03:00” level=info msg=“backend/gateway: gateway stats packet received” mac=00800000a0001261
feb 08 11:56:08 loraserverlcd-VirtualBox loraserver[987]: time=“2018-02-08T11:56:08-03:00” level=info msg=“gateway updated” mac=00800000a0001261
feb 08 11:56:38 loraserverlcd-VirtualBox loraserver[987]: time=“2018-02-08T11:56:38-03:00” level=info msg=“backend/gateway: gateway stats packet received” mac=00800000a0001261
feb 08 11:56:38 loraserverlcd-VirtualBox loraserver[987]: time=“2018-02-08T11:56:38-03:00” level=info msg=“gateway updated” mac=00800000a0001261
feb 08 11:57:08 loraserverlcd-VirtualBox loraserver[987]: time=“2018-02-08T11:57:08-03:00” level=info msg=“backend/gateway: gateway stats packet received” mac=00800000a0001261
feb 08 11:57:08 loraserverlcd-VirtualBox loraserver[987]: time=“2018-02-08T11:57:08-03:00” level=info msg=“gateway updated” mac=00800000a0001261
feb 08 11:57:38 loraserverlcd-VirtualBox loraserver[987]: time=“2018-02-08T11:57:38-03:00” level=info msg=“backend/gateway: gateway stats packet received” mac=00800000a0001261
feb 08 11:57:38 loraserverlcd-VirtualBox loraserver[987]: time=“2018-02-08T11:57:38-03:00” level=info msg=“gateway updated” mac=00800000a0001261
feb 08 11:58:08 loraserverlcd-VirtualBox loraserver[987]: time=“2018-02-08T11:58:08-03:00” level=info msg=“backend/gateway: gateway stats packet received” mac=00800000a0001261
feb 08 11:58:08 loraserverlcd-VirtualBox loraserver[987]: time=“2018-02-08T11:58:08-03:00” level=info msg=“gateway updated” mac=00800000a0001261
feb 08 11:58:38 loraserverlcd-VirtualBox loraserver[987]: time=“2018-02-08T11:58:38-03:00” level=info msg=“backend/gateway: gateway stats packet received” mac=00800000a0001261
feb 08 11:58:38 loraserverlcd-VirtualBox loraserver[987]: time=“2018-02-08T11:58:38-03:00” level=info msg=“gateway updated” mac=00800000a0001261
LoRa App Server:
– Logs begin at jue 2018-02-08 09:13:27 -03. –
feb 08 11:51:39 loraserverlcd-VirtualBox lora-app-server[1099]: time=“2018-02-08T11:51:39-03:00” level=info msg=“finished client unary call” grpc.code=OK grpc.method=GetFrameLogsForDevEUI grpc.service=ns.NetworkServer grpc.time_ms=2.799 span.kind=client system=grpc
feb 08 11:51:39 loraserverlcd-VirtualBox lora-app-server[1099]: time=“2018-02-08T11:51:39-03:00” level=info msg=“finished unary call with code OK” grpc.code=OK grpc.method=GetFrameLogs grpc.service=api.Device grpc.start_time=“2018-02-08T11:51:39-03:00” grpc.time_ms=6.124 peer.address=“127.0.0.1:32818” span.kind=server system=grpc
feb 08 11:51:39 loraserverlcd-VirtualBox lora-app-server[1099]: time=“2018-02-08T11:51:39-03:00” level=info msg=“finished client unary call” grpc.code=OK grpc.method=GetFrameLogsForDevEUI grpc.service=ns.NetworkServer grpc.time_ms=2.858 span.kind=client system=grpc
feb 08 11:51:39 loraserverlcd-VirtualBox lora-app-server[1099]: time=“2018-02-08T11:51:39-03:00” level=info msg=“finished unary call with code OK” grpc.code=OK grpc.method=GetFrameLogs grpc.service=api.Device grpc.start_time=“2018-02-08T11:51:39-03:00” grpc.time_ms=6.235 peer.address=“127.0.0.1:32818” span.kind=server system=grpc
feb 08 11:51:39 loraserverlcd-VirtualBox lora-app-server[1099]: time=“2018-02-08T11:51:39-03:00” level=info msg=“finished client unary call” grpc.code=OK grpc.method=GetFrameLogsForDevEUI grpc.service=ns.NetworkServer grpc.time_ms=2.783 span.kind=client system=grpc
feb 08 11:51:39 loraserverlcd-VirtualBox lora-app-server[1099]: time=“2018-02-08T11:51:39-03:00” level=info msg=“finished unary call with code OK” grpc.code=OK grpc.method=GetFrameLogs grpc.service=api.Device grpc.start_time=“2018-02-08T11:51:39-03:00” grpc.time_ms=6.193 peer.address=“127.0.0.1:32818” span.kind=server system=grpc
feb 08 11:51:39 loraserverlcd-VirtualBox lora-app-server[1099]: time=“2018-02-08T11:51:39-03:00” level=info msg=“finished client unary call” grpc.code=OK grpc.method=GetFrameLogsForDevEUI grpc.service=ns.NetworkServer grpc.time_ms=2.888 span.kind=client system=grpc
feb 08 11:51:39 loraserverlcd-VirtualBox lora-app-server[1099]: time=“2018-02-08T11:51:39-03:00” level=info msg=“finished unary call with code OK” grpc.code=OK grpc.method=GetFrameLogs grpc.service=api.Device grpc.start_time=“2018-02-08T11:51:39-03:00” grpc.time_ms=6.282 peer.address=“127.0.0.1:32818” span.kind=server system=grpc
feb 08 11:51:39 loraserverlcd-VirtualBox lora-app-server[1099]: time=“2018-02-08T11:51:39-03:00” level=info msg=“finished client unary call” grpc.code=OK grpc.method=GetFrameLogsForDevEUI grpc.service=ns.NetworkServer grpc.time_ms=2.874 span.kind=client system=grpc
feb 08 11:51:39 loraserverlcd-VirtualBox lora-app-server[1099]: time=“2018-02-08T11:51:39-03:00” level=info msg=“finished unary call with code OK” grpc.code=OK grpc.method=GetFrameLogs grpc.service=api.Device grpc.start_time=“2018-02-08T11:51:39-03:00” grpc.time_ms=6.17 peer.address=“127.0.0.1:32818” span.kind=server system=grpc
feb 08 12:02:04 loraserverlcd-VirtualBox lora-app-server[1099]: time=“2018-02-08T12:02:04-03:00” level=info msg=“finished unary call with code OK” grpc.code=OK grpc.method=Get grpc.service=api.Application grpc.start_time=“2018-02-08T12:02:04-03:00” grpc.time_ms=8.404 peer.address=“127.0.0.1:32834” span.kind=server system=grpc
feb 08 12:02:04 loraserverlcd-VirtualBox lora-app-server[1099]: time=“2018-02-08T12:02:04-03:00” level=info msg=“finished unary call with code OK” grpc.code=OK grpc.method=Get grpc.service=api.Device grpc.start_time=“2018-02-08T12:02:04-03:00” grpc.time_ms=10.098 peer.address=“127.0.0.1:32818” span.kind=server system=grpc
feb 08 12:02:04 loraserverlcd-VirtualBox lora-app-server[1099]: time=“2018-02-08T12:02:04-03:00” level=info msg=“finished unary call with code OK” grpc.code=OK grpc.method=List grpc.service=api.DeviceProfileService grpc.start_time=“2018-02-08T12:02:04-03:00” grpc.time_ms=6.054 peer.address=“127.0.0.1:32832” span.kind=server system=grpc
feb 08 12:02:06 loraserverlcd-VirtualBox lora-app-server[1099]: time=“2018-02-08T12:02:06-03:00” level=info msg=“finished client unary call” grpc.code=OK grpc.method=GetFrameLogsForDevEUI grpc.service=ns.NetworkServer grpc.time_ms=4.652 span.kind=client system=grpc
feb 08 12:02:06 loraserverlcd-VirtualBox lora-app-server[1099]: time=“2018-02-08T12:02:06-03:00” level=info msg=“finished unary call with code OK” grpc.code=OK grpc.method=GetFrameLogs grpc.service=api.Device grpc.start_time=“2018-02-08T12:02:06-03:00” grpc.time_ms=10.631 peer.address=“127.0.0.1:32818” span.kind=server system=grpc
Thanks for reading!