Dragino Node working with bugs

handyman · August 10, 2018, 8:24am

Hi,

I have a setup for a lora network with the fallowing componets:

lora server
lora app server
lora gw made of:
- raspberry
- IC880A backplane v1.5
- iC880A-SPI - LoRaWAN Concentrator 868 MHz
lora nodes:
- Multitech MBOX
- Arduino + Dragino Shield V1.4

First I checked the connectivity from node to app with the MBOX and the hole system works with out an error. I send the data from the Mbox and I decrypt it into the Lora App Server. So the system is working correctly.

I tried to make a node using the Arduino + Dragino Shield V1.4 with ABP autentification. The node sends data and the AppServer displays it until first restart. After I reboot the node something is happening because even though the node sends the data to the GW I can see the data on the GW but the App Server doesn’t received it

on the GW:

JSON up: {“stat”:{“time”:“2018-08-10 08:15:03 GMT”,“rxnb”:1,“rxok”:0,“rxfw”:0,“ackr”:100.0,“dwnb”:0,“txnb”:0}}
Aug 10 11:15:43 jessie lora-packet-fw[2479]: INFO: [up] PUSH_ACK received in 2 ms
Aug 10 11:15:43 jessie lora-packet-fw[2479]: INFO: [down] PULL_ACK received in 0 ms
Aug 10 11:15:43 jessie lora-packet-fw[2479]: INFO: [down] PULL_ACK received in 0 ms
Aug 10 11:15:43 jessie lora-packet-fw[2479]: INFO: Received pkt from mote: 01A4EBA9 (fcnt=7)
Aug 10 11:15:43 jessie lora-packet-fw[2479]: JSON up: {“rxpk”:[{“tmst”:4289313052,“chan”:7,“rfch”:0,“freq”:867.900000,“stat”:1,“modu”:“LORA”,“datr”:“SF7BW125”,“codr”:“4/5”,“lsnr”:10.0,“rssi”:-21,“size”:26,“data”:“QKnrpAGABwAB0SPkwYc6UHOK0XjO4kX2uq8=”}]}
Aug 10 11:15:43 jessie lora-packet-fw[2479]: INFO: [up] PUSH_ACK received in 0 ms
Aug 10 11:15:43 jessie lora-packet-fw[2479]: INFO: [down] PULL_ACK received in 0 ms
Aug 10 11:15:43 jessie lora-packet-fw[2479]: ##### 2018-08-10 08:15:33 GMT #####
Aug 10 11:15:43 jessie lora-packet-fw[2479]: ### [UPSTREAM] ###
Aug 10 11:15:43 jessie lora-packet-fw[2479]: # RF packets received by concentrator: 1
Aug 10 11:15:43 jessie lora-packet-fw[2479]: # CRC_OK: 100.00%, CRC_FAIL: 0.00%, NO_CRC: 0.00%
Aug 10 11:15:43 jessie lora-packet-fw[2479]: # RF packets forwarded: 1 (26 bytes)
Aug 10 11:15:43 jessie lora-packet-fw[2479]: # PUSH_DATA datagrams sent: 2 (324 bytes)
Aug 10 11:15:43 jessie lora-packet-fw[2479]: # PUSH_DATA acknowledged: 100.00%
Aug 10 11:15:43 jessie lora-packet-fw[2479]: ### [DOWNSTREAM] ###
Aug 10 11:15:43 jessie lora-packet-fw[2479]: # PULL_DATA sent: 3 (100.00% acknowledged)
Aug 10 11:15:43 jessie lora-packet-fw[2479]: # PULL_RESP(onse) datagrams received: 0 (0 bytes)
Aug 10 11:15:43 jessie lora-packet-fw[2479]: # RF packets sent to concentrator: 0 (0 bytes)
Aug 10 11:15:43 jessie lora-packet-fw[2479]: # TX errors: 0
Aug 10 11:15:43 jessie lora-packet-fw[2479]: # TX rejected (collision packet): 0.00% (req:433, rej:0)
Aug 10 11:15:43 jessie lora-packet-fw[2479]: # TX rejected (collision beacon): 0.00% (req:433, rej:0)
Aug 10 11:15:43 jessie lora-packet-fw[2479]: # TX rejected (too late): 0.00% (req:433, rej:0)
Aug 10 11:15:43 jessie lora-packet-fw[2479]: # TX rejected (too early): 0.00% (req:433, rej:0)
Aug 10 11:15:43 jessie lora-packet-fw[2479]: # BEACON queued: 0
Aug 10 11:15:43 jessie lora-packet-fw[2479]: # BEACON sent so far: 0
Aug 10 11:15:43 jessie lora-packet-fw[2479]: # BEACON rejected: 0
Aug 10 11:15:43 jessie lora-packet-fw[2479]: ### [JIT] ###
Aug 10 11:15:43 jessie lora-packet-fw[2479]: # SX1301 time (PPS): 4264717592
Aug 10 11:15:43 jessie lora-packet-fw[2479]: src/jitqueue.c:448:jit_print_queue(): INFO: [jit] queue is empty
Aug 10 11:15:43 jessie lora-packet-fw[2479]: ### [GPS] ###
Aug 10 11:15:43 jessie lora-packet-fw[2479]: # GPS sync is disabled
Aug 10 11:15:43 jessie lora-packet-fw[2479]: ##### END #####

For Arduino lora library I used the Arduino-LMIC library

If i delete the node from the AppServer and recreate it afterwords it works, but like before, until first reboot of the node. after the reboot the same thing happens.

I don’t have this issue with the Multitech MBOX

Has somebody hit the same problem?

Clement · August 10, 2018, 9:41am

You probably have a Frame count “issue”

When you activate your device using ABP, the FCnt is 0 on server-side and node-side.
Then you wait N uplinks, the FCnt will be N on server-side and node-side.

If you reactivate the node (by resetting it or reuploading it or unplug-plug power supply) the Fcnt on node-side will be reset to 0. So it will send N uplink which won’t be considered as correct by the server because FCnt of server and node dismatch. After N uplinks sent for nothing, the following uplinks will be OK for the server.

handyman · August 10, 2018, 9:53am

Thanks for your prompt response.
Ok, I can understand your point of view, but why doesn’t this happens with the MBOX node ?

Clement · August 10, 2018, 9:56am

Can you paste error logs of loraserver and lora-app-server to confirm my hypothesis ?

handyman · August 13, 2018, 7:21am

Hello,
i have no logs in either of them. should I lock in another place ?
do i have to specificaly enable logs for them? how and where do I configure loging ?

best regards

Clement · August 13, 2018, 8:56am

journalctl -f -u lora-app-server -n 50 
journalctl -f -u loraserver -n 50
journalctl -f -u lora-gateway-bridge -n 50

handyman · August 13, 2018, 9:23am

[root@LoraServer ~]# journalctl -f -u loraserver -n 50

Aug 13 13:08:40 LoraServer.lora loraserver[981]: time="2018-08-13T13:08:40+03:00" level=info msg="backend/gateway: gateway stats packet received" mac=b827ebfffefa606c
Aug 13 13:08:40 LoraServer.lora loraserver[981]: time="2018-08-13T13:08:40+03:00" level=info msg="gateway updated" mac=b827ebfffefa606c
Aug 13 13:09:10 LoraServer.lora loraserver[981]: time="2018-08-13T13:09:10+03:00" level=info msg="backend/gateway: gateway stats packet received" mac=b827ebfffefa606c
Aug 13 13:09:10 LoraServer.lora loraserver[981]: time="2018-08-13T13:09:10+03:00" level=info msg="gateway updated" mac=b827ebfffefa606c
Aug 13 13:09:14 LoraServer.lora loraserver[981]: time="2018-08-13T13:09:14+03:00" level=info msg="backend/gateway: rx packet received"
Aug 13 13:09:14 LoraServer.lora loraserver[981]: time="2018-08-13T13:09:14+03:00" level=warning msg="get device-sessions for dev_addr error: object does not exist" dev_addr=01a4eba9 dev_eui=1234567890123456
Aug 13 13:09:14 LoraServer.lora loraserver[981]: time="2018-08-13T13:09:14+03:00" level=error msg="processing rx packet error: get device-session error: device-session does not exist or invalid fcnt or mic" data_base64="QKnrpAGAAwABvSWTRLcMLhSYOUkIIzWCE5E="
Aug 13 13:09:40 LoraServer.lora loraserver[981]: time="2018-08-13T13:09:40+03:00" level=info msg="backend/gateway: gateway stats packet received" mac=b827ebfffefa606c
Aug 13 13:09:40 LoraServer.lora loraserver[981]: time="2018-08-13T13:09:40+03:00" level=info msg="gateway updated" mac=b827ebfffefa606c
Aug 13 13:10:00 LoraServer.lora loraserver[981]: time="2018-08-13T13:10:00+03:00" level=info msg="backend/gateway: rx packet received"
Aug 13 13:10:00 LoraServer.lora loraserver[981]: time="2018-08-13T13:10:00+03:00" level=info msg="packet(s) collected" dev_eui=000db53906663659 gw_count=1 gw_macs=b827ebfffefa606c mtype=JoinRequest
Aug 13 13:10:00 LoraServer.lora loraserver[981]: time="2018-08-13T13:10:00+03:00" level=error msg="processing rx packet error: get device error: object does not exist" data_base64="AAMCAQAAAAAAWTZmBjm1DQDGyKj35P8="
Aug 13 13:10:01 LoraServer.lora loraserver[981]: time="2018-08-13T13:10:01+03:00" level=info msg="backend/gateway: rx packet received"
Aug 13 13:10:01 LoraServer.lora loraserver[981]: time="2018-08-13T13:10:01+03:00" level=info msg="packet(s) collected" dev_eui=000db53112753552 gw_count=1 gw_macs=b827ebfffefa606c mtype=JoinRequest
Aug 13 13:10:01 LoraServer.lora loraserver[981]: time="2018-08-13T13:10:01+03:00" level=error msg="processing rx packet error: get device error: object does not exist" data_base64="AAMCAQAAAAAAUjV1EjG1DQDpBc7BGcM="
Aug 13 13:10:10 LoraServer.lora loraserver[981]: time="2018-08-13T13:10:10+03:00" level=info msg="backend/gateway: gateway stats packet received" mac=b827ebfffefa606c
Aug 13 13:10:10 LoraServer.lora loraserver[981]: time="2018-08-13T13:10:10+03:00" level=info msg="gateway updated" mac=b827ebfffefa606c
Aug 13 13:10:16 LoraServer.lora loraserver[981]: time="2018-08-13T13:10:16+03:00" level=info msg="backend/gateway: rx packet received"
Aug 13 13:10:16 LoraServer.lora loraserver[981]: time="2018-08-13T13:10:16+03:00" level=warning msg="get device-sessions for dev_addr error: object does not exist" dev_addr=01a4eba9 dev_eui=1234567890123456
Aug 13 13:10:16 LoraServer.lora loraserver[981]: time="2018-08-13T13:10:16+03:00" level=error msg="processing rx packet error: get device-session error: device-session does not exist or invalid fcnt or mic" data_base64="QKnrpAGABAABYO6nCiTS5o6DcOwcOuuBrZQ="
Aug 13 13:10:34 LoraServer.lora loraserver[981]: time="2018-08-13T13:10:34+03:00" level=info msg="finished unary call with code OK" grpc.code=OK grpc.method=GetDevice grpc.service=ns.NetworkServer grpc.start_time="2018-08-13T13:10:34+03:00" grpc.time_ms=0.771 peer.address="[::1]:56708" span.kind=server system=grpc
Aug 13 13:10:34 LoraServer.lora loraserver[981]: time="2018-08-13T13:10:34+03:00" level=info msg="finished unary call with code OK" grpc.code=OK grpc.method=GetDevice grpc.service=ns.NetworkServer grpc.start_time="2018-08-13T13:10:34+03:00" grpc.time_ms=0.534 peer.address="[::1]:56708" span.kind=server system=grpc
Aug 13 13:10:34 LoraServer.lora loraserver[981]: time="2018-08-13T13:10:34+03:00" level=info msg="finished unary call with code OK" grpc.code=OK grpc.method=GetDeviceProfile grpc.service=ns.NetworkServer grpc.start_time="2018-08-13T13:10:34+03:00" grpc.time_ms=1.387 peer.address="[::1]:56708" span.kind=server system=grpc
Aug 13 13:10:37 LoraServer.lora loraserver[981]: time="2018-08-13T13:10:37+03:00" level=info msg="finished unary call with code OK" grpc.code=OK grpc.method=GetDevice grpc.service=ns.NetworkServer grpc.start_time="2018-08-13T13:10:37+03:00" grpc.time_ms=0.587 peer.address="[::1]:56708" span.kind=server system=grpc
Aug 13 13:10:37 LoraServer.lora loraserver[981]: time="2018-08-13T13:10:37+03:00" level=info msg="finished unary call with code OK" grpc.code=OK grpc.method=GetDeviceProfile grpc.service=ns.NetworkServer grpc.start_time="2018-08-13T13:10:37+03:00" grpc.time_ms=0.709 peer.address="[::1]:56708" span.kind=server system=grpc
Aug 13 13:10:40 LoraServer.lora loraserver[981]: time="2018-08-13T13:10:40+03:00" level=info msg="backend/gateway: gateway stats packet received" mac=b827ebfffefa606c
Aug 13 13:10:40 LoraServer.lora loraserver[981]: time="2018-08-13T13:10:40+03:00" level=info msg="gateway updated" mac=b827ebfffefa606c
Aug 13 13:11:10 LoraServer.lora loraserver[981]: time="2018-08-13T13:11:10+03:00" level=info msg="backend/gateway: gateway stats packet received" mac=b827ebfffefa606c
Aug 13 13:11:10 LoraServer.lora loraserver[981]: time="2018-08-13T13:11:10+03:00" level=info msg="gateway updated" mac=b827ebfffefa606c
Aug 13 13:11:18 LoraServer.lora loraserver[981]: time="2018-08-13T13:11:18+03:00" level=info msg="backend/gateway: rx packet received"
Aug 13 13:11:18 LoraServer.lora loraserver[981]: time="2018-08-13T13:11:18+03:00" level=warning msg="get device-sessions for dev_addr error: object does not exist" dev_addr=01a4eba9 dev_eui=1234567890123456
Aug 13 13:11:18 LoraServer.lora loraserver[981]: time="2018-08-13T13:11:18+03:00" level=error msg="processing rx packet error: get device-session error: device-session does not exist or invalid fcnt or mic" data_base64="QKnrpAGABQAB6LnZLIpls6KAsFLEFpnnGJs="
Aug 13 13:11:40 LoraServer.lora loraserver[981]: time="2018-08-13T13:11:40+03:00" level=info msg="backend/gateway: gateway stats packet received" mac=b827ebfffefa606c
Aug 13 13:11:40 LoraServer.lora loraserver[981]: time="2018-08-13T13:11:40+03:00" level=info msg="gateway updated" mac=b827ebfffefa606c

[root@LoraServer ~]# journalctl -f -u lora-app-server -n 50

Aug 13 13:10:34 LoraServer.lora lora-app-server[11063]: time="2018-08-13T13:10:34+03:00" level=info msg="finished unary call with code OK" grpc.code=OK grpc.method=Get grpc.service=api.Organization grpc.start_time="2018-08-13T13:10:34+03:00" grpc.time_ms=22.71 peer.address="[::1]:55488" span.kind=server system=grpc
Aug 13 13:10:34 LoraServer.lora lora-app-server[11063]: time="2018-08-13T13:10:34+03:00" level=info msg="finished client unary call" grpc.code=OK grpc.method=GetDevice grpc.service=ns.NetworkServer grpc.time_ms=1.833 span.kind=client system=grpc
Aug 13 13:10:34 LoraServer.lora lora-app-server[11063]: time="2018-08-13T13:10:34+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-08-13T13:10:34+03:00" grpc.time_ms=34.849 peer.address="[::1]:55490" span.kind=server system=grpc
Aug 13 13:10:34 LoraServer.lora lora-app-server[11063]: time="2018-08-13T13:10:34+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-08-13T13:10:34+03:00" grpc.time_ms=42.711 peer.address="[::1]:55496" span.kind=server system=grpc
Aug 13 13:10:34 LoraServer.lora lora-app-server[11063]: time="2018-08-13T13:10:34+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-08-13T13:10:34+03:00" grpc.time_ms=47.155 peer.address="[::1]:55482" span.kind=server system=grpc
Aug 13 13:10:34 LoraServer.lora lora-app-server[11063]: time="2018-08-13T13:10:34+03:00" level=info msg="finished client unary call" grpc.code=OK grpc.method=GetDeviceProfile grpc.service=ns.NetworkServer grpc.time_ms=2.322 span.kind=client system=grpc
Aug 13 13:10:34 LoraServer.lora lora-app-server[11063]: time="2018-08-13T13:10:34+03:00" level=info msg="finished unary call with code OK" grpc.code=OK grpc.method=Get grpc.service=api.DeviceProfileService grpc.start_time="2018-08-13T13:10:34+03:00" grpc.time_ms=10.321 peer.address="[::1]:55496" span.kind=server system=grpc
Aug 13 13:10:36 LoraServer.lora lora-app-server[11063]: time="2018-08-13T13:10:36+03:00" level=info msg="finished unary call with code OK" grpc.code=OK grpc.method=Branding grpc.service=api.Internal grpc.start_time="2018-08-13T13:10:36+03:00" grpc.time_ms=0.028 peer.address="[::1]:55498" span.kind=server system=grpc
Aug 13 13:10:36 LoraServer.lora lora-app-server[11063]: time="2018-08-13T13:10:36+03:00" level=info msg="finished unary call with code OK" grpc.code=OK grpc.method=Profile grpc.service=api.Internal grpc.start_time="2018-08-13T13:10:36+03:00" grpc.time_ms=5.753 peer.address="[::1]:55498" span.kind=server system=grpc
Aug 13 13:10:37 LoraServer.lora lora-app-server[11063]: time="2018-08-13T13:10:37+03:00" level=info msg="finished unary call with code OK" grpc.code=OK grpc.method=Get grpc.service=api.Organization grpc.start_time="2018-08-13T13:10:37+03:00" grpc.time_ms=4.68 peer.address="[::1]:55488" span.kind=server system=grpc
Aug 13 13:10:37 LoraServer.lora lora-app-server[11063]: time="2018-08-13T13:10:37+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-08-13T13:10:37+03:00" grpc.time_ms=8.184 peer.address="[::1]:55482" span.kind=server system=grpc
Aug 13 13:10:37 LoraServer.lora lora-app-server[11063]: time="2018-08-13T13:10:37+03:00" level=info msg="finished client streaming call" grpc.code=OK grpc.method=StreamFrameLogsForDevice grpc.service=ns.NetworkServer grpc.time_ms=0.026 span.kind=client system=grpc
Aug 13 13:10:37 LoraServer.lora lora-app-server[11063]: time="2018-08-13T13:10:37+03:00" level=info msg="finished unary call with code OK" grpc.code=OK grpc.method=List grpc.service=api.Organization grpc.start_time="2018-08-13T13:10:37+03:00" grpc.time_ms=12.584 peer.address="[::1]:55488" span.kind=server system=grpc
Aug 13 13:10:37 LoraServer.lora lora-app-server[11063]: time="2018-08-13T13:10:37+03:00" level=info msg="finished client unary call" grpc.code=OK grpc.method=GetDevice grpc.service=ns.NetworkServer grpc.time_ms=2.001 span.kind=client system=grpc
Aug 13 13:10:37 LoraServer.lora lora-app-server[11063]: time="2018-08-13T13:10:37+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-08-13T13:10:37+03:00" grpc.time_ms=26.93 peer.address="[::1]:55490" span.kind=server system=grpc
Aug 13 13:10:37 LoraServer.lora lora-app-server[11063]: time="2018-08-13T13:10:37+03:00" level=info msg="finished unary call with code OK" grpc.code=OK grpc.method=Get grpc.service=api.Organization grpc.start_time="2018-08-13T13:10:37+03:00" grpc.time_ms=27.346 peer.address="[::1]:55488" span.kind=server system=grpc
Aug 13 13:10:37 LoraServer.lora lora-app-server[11063]: time="2018-08-13T13:10:37+03:00" level=info msg="finished unary call with code OK" grpc.code=OK grpc.method=Get grpc.service=api.Organization grpc.start_time="2018-08-13T13:10:37+03:00" grpc.time_ms=4.389 peer.address="[::1]:55488" span.kind=server system=grpc
Aug 13 13:10:37 LoraServer.lora lora-app-server[11063]: time="2018-08-13T13:10:37+03:00" level=info msg="finished unary call with code OK" grpc.code=OK grpc.method=Get grpc.service=api.Organization grpc.start_time="2018-08-13T13:10:37+03:00" grpc.time_ms=4.379 peer.address="[::1]:55488" span.kind=server system=grpc
Aug 13 13:10:37 LoraServer.lora lora-app-server[11063]: time="2018-08-13T13:10:37+03:00" level=info msg="finished client unary call" grpc.code=OK grpc.method=GetDeviceProfile grpc.service=ns.NetworkServer grpc.time_ms=1.236 span.kind=client system=grpc
Aug 13 13:10:37 LoraServer.lora lora-app-server[11063]: time="2018-08-13T13:10:37+03:00" level=info msg="finished unary call with code OK" grpc.code=OK grpc.method=Get grpc.service=api.DeviceProfileService grpc.start_time="2018-08-13T13:10:37+03:00" grpc.time_ms=6.122 peer.address="[::1]:55496" span.kind=server system=grpc

root@jessie:~# journalctl -f -u lora-gateway-bridge -n 50

Aug 13 12:16:12 jessie lora-gateway-bridge[2491]: time="2018-08-13T12:16:12+03:00" level=info msg="gateway: rxpk packet received" addr="127.0.0.1:51176" data="QKnrpAGABAABYO6nCiTS5o6DcOwcOuuBrZQ=" mac=b827ebfffefa606c
Aug 13 12:16:12 jessie lora-gateway-bridge[2491]: time="2018-08-13T12:16:12+03:00" level=info msg="gateway: sending udp packet to gateway" addr="127.0.0.1:51176" protocol_version=2 type=PushACK
Aug 13 12:16:12 jessie lora-gateway-bridge[2491]: time="2018-08-13T12:16:12+03:00" level=info msg="backend: publishing packet" qos=0 topic=gateway/b827ebfffefa606c/rx
Aug 13 12:16:20 jessie lora-gateway-bridge[2491]: time="2018-08-13T12:16:20+03:00" level=info msg="gateway: received udp packet from gateway" addr="127.0.0.1:50165" protocol_version=2 type=PullData
Aug 13 12:16:20 jessie lora-gateway-bridge[2491]: time="2018-08-13T12:16:20+03:00" level=info msg="gateway: sending udp packet to gateway" addr="127.0.0.1:50165" protocol_version=2 type=PullACK
Aug 13 12:16:30 jessie lora-gateway-bridge[2491]: time="2018-08-13T12:16:30+03:00" level=info msg="gateway: received udp packet from gateway" addr="127.0.0.1:50165" protocol_version=2 type=PullData
Aug 13 12:16:30 jessie lora-gateway-bridge[2491]: time="2018-08-13T12:16:30+03:00" level=info msg="gateway: sending udp packet to gateway" addr="127.0.0.1:50165" protocol_version=2 type=PullACK
Aug 13 12:16:37 jessie lora-gateway-bridge[2491]: time="2018-08-13T12:16:37+03:00" level=info msg="gateway: received udp packet from gateway" addr="127.0.0.1:51176" protocol_version=2 type=PushData
Aug 13 12:16:37 jessie lora-gateway-bridge[2491]: time="2018-08-13T12:16:37+03:00" level=info msg="gateway: stat packet received" addr="127.0.0.1:51176" mac=b827ebfffefa606c
Aug 13 12:16:37 jessie lora-gateway-bridge[2491]: time="2018-08-13T12:16:37+03:00" level=info msg="backend: publishing packet" qos=0 topic=gateway/b827ebfffefa606c/stats
Aug 13 12:16:37 jessie lora-gateway-bridge[2491]: time="2018-08-13T12:16:37+03:00" level=info msg="gateway: sending udp packet to gateway" addr="127.0.0.1:51176" protocol_version=2 type=PushACK
Aug 13 12:16:40 jessie lora-gateway-bridge[2491]: time="2018-08-13T12:16:40+03:00" level=info msg="gateway: received udp packet from gateway" addr="127.0.0.1:50165" protocol_version=2 type=PullData
Aug 13 12:16:40 jessie lora-gateway-bridge[2491]: time="2018-08-13T12:16:40+03:00" level=info msg="gateway: sending udp packet to gateway" addr="127.0.0.1:50165" protocol_version=2 type=PullACK
Aug 13 12:16:50 jessie lora-gateway-bridge[2491]: time="2018-08-13T12:16:50+03:00" level=info msg="gateway: received udp packet from gateway" addr="127.0.0.1:50165" protocol_version=2 type=PullData
Aug 13 12:16:50 jessie lora-gateway-bridge[2491]: time="2018-08-13T12:16:50+03:00" level=info msg="gateway: sending udp packet to gateway" addr="127.0.0.1:50165" protocol_version=2 type=PullACK
Aug 13 12:17:00 jessie lora-gateway-bridge[2491]: time="2018-08-13T12:17:00+03:00" level=info msg="gateway: received udp packet from gateway" addr="127.0.0.1:50165" protocol_version=2 type=PullData
Aug 13 12:17:00 jessie lora-gateway-bridge[2491]: time="2018-08-13T12:17:00+03:00" level=info msg="gateway: sending udp packet to gateway" addr="127.0.0.1:50165" protocol_version=2 type=PullACK
Aug 13 12:17:07 jessie lora-gateway-bridge[2491]: time="2018-08-13T12:17:07+03:00" level=info msg="gateway: received udp packet from gateway" addr="127.0.0.1:51176" protocol_version=2 type=PushData
Aug 13 12:17:07 jessie lora-gateway-bridge[2491]: time="2018-08-13T12:17:07+03:00" level=info msg="gateway: stat packet received" addr="127.0.0.1:51176" mac=b827ebfffefa606c
Aug 13 12:17:07 jessie lora-gateway-bridge[2491]: time="2018-08-13T12:17:07+03:00" level=info msg="gateway: sending udp packet to gateway" addr="127.0.0.1:51176" protocol_version=2 type=PushACK
Aug 13 12:17:07 jessie lora-gateway-bridge[2491]: time="2018-08-13T12:17:07+03:00" level=info msg="backend: publishing packet" qos=0 topic=gateway/b827ebfffefa606c/stats
Aug 13 12:17:10 jessie lora-gateway-bridge[2491]: time="2018-08-13T12:17:10+03:00" level=info msg="gateway: received udp packet from gateway" addr="127.0.0.1:50165" protocol_version=2 type=PullData
Aug 13 12:17:10 jessie lora-gateway-bridge[2491]: time="2018-08-13T12:17:10+03:00" level=info msg="gateway: sending udp packet to gateway" addr="127.0.0.1:50165" protocol_version=2 type=PullACK
Aug 13 12:17:14 jessie lora-gateway-bridge[2491]: time="2018-08-13T12:17:14+03:00" level=info msg="gateway: received udp packet from gateway" addr="127.0.0.1:51176" protocol_version=2 type=PushData
Aug 13 12:17:14 jessie lora-gateway-bridge[2491]: time="2018-08-13T12:17:14+03:00" level=info msg="gateway: rxpk packet received" addr="127.0.0.1:51176" data="QKnrpAGABQAB6LnZLIpls6KAsFLEFpnnGJs=" mac=b827ebfffefa606c
Aug 13 12:17:14 jessie lora-gateway-bridge[2491]: time="2018-08-13T12:17:14+03:00" level=info msg="gateway: sending udp packet to gateway" addr="127.0.0.1:51176" protocol_version=2 type=PushACK
Aug 13 12:17:14 jessie lora-gateway-bridge[2491]: time="2018-08-13T12:17:14+03:00" level=info msg="backend: publishing packet" qos=0 topic=gateway/b827ebfffefa606c/rx
Aug 13 12:17:20 jessie lora-gateway-bridge[2491]: time="2018-08-13T12:17:20+03:00" level=info msg="gateway: received udp packet from gateway" addr="127.0.0.1:50165" protocol_version=2 type=PullData
Aug 13 12:17:21 jessie lora-gateway-bridge[2491]: time="2018-08-13T12:17:20+03:00" level=info msg="gateway: sending udp packet to gateway" addr="127.0.0.1:50165" protocol_version=2 type=PullACK
Aug 13 12:17:31 jessie lora-gateway-bridge[2491]: time="2018-08-13T12:17:31+03:00" level=info msg="gateway: received udp packet from gateway" addr="127.0.0.1:50165" protocol_version=2 type=PullData
Aug 13 12:17:31 jessie lora-gateway-bridge[2491]: time="2018-08-13T12:17:31+03:00" level=info msg="gateway: sending udp packet to gateway" addr="127.0.0.1:50165" protocol_version=2 type=PullACK
Aug 13 12:17:37 jessie lora-gateway-bridge[2491]: time="2018-08-13T12:17:37+03:00" level=info msg="gateway: received udp packet from gateway" addr="127.0.0.1:51176" protocol_version=2 type=PushData
Aug 13 12:17:37 jessie lora-gateway-bridge[2491]: time="2018-08-13T12:17:37+03:00" level=info msg="gateway: stat packet received" addr="127.0.0.1:51176" mac=b827ebfffefa606c
Aug 13 12:17:37 jessie lora-gateway-bridge[2491]: time="2018-08-13T12:17:37+03:00" level=info msg="gateway: sending udp packet to gateway" addr="127.0.0.1:51176" protocol_version=2 type=PushACK
Aug 13 12:17:37 jessie lora-gateway-bridge[2491]: time="2018-08-13T12:17:37+03:00" level=info msg="backend: publishing packet" qos=0 topic=gateway/b827ebfffefa606c/stats
Aug 13 12:17:41 jessie lora-gateway-bridge[2491]: time="2018-08-13T12:17:41+03:00" level=info msg="gateway: received udp packet from gateway" addr="127.0.0.1:50165" protocol_version=2 type=PullData
Aug 13 12:17:41 jessie lora-gateway-bridge[2491]: time="2018-08-13T12:17:41+03:00" level=info msg="gateway: sending udp packet to gateway" addr="127.0.0.1:50165" protocol_version=2 type=PullACK
Aug 13 12:17:51 jessie lora-gateway-bridge[2491]: time="2018-08-13T12:17:51+03:00" level=info msg="gateway: received udp packet from gateway" addr="127.0.0.1:50165" protocol_version=2 type=PullData
Aug 13 12:17:51 jessie lora-gateway-bridge[2491]: time="2018-08-13T12:17:51+03:00" level=info msg="gateway: sending udp packet to gateway" addr="127.0.0.1:50165" protocol_version=2 type=PullACK
Aug 13 12:18:01 jessie lora-gateway-bridge[2491]: time="2018-08-13T12:18:01+03:00" level=info msg="gateway: received udp packet from gateway" addr="127.0.0.1:50165" protocol_version=2 type=PullData
Aug 13 12:18:01 jessie lora-gateway-bridge[2491]: time="2018-08-13T12:18:01+03:00" level=info msg="gateway: sending udp packet to gateway" addr="127.0.0.1:50165" protocol_version=2 type=PullACK
Aug 13 12:18:07 jessie lora-gateway-bridge[2491]: time="2018-08-13T12:18:07+03:00" level=info msg="gateway: received udp packet from gateway" addr="127.0.0.1:51176" protocol_version=2 type=PushData
Aug 13 12:18:07 jessie lora-gateway-bridge[2491]: time="2018-08-13T12:18:07+03:00" level=info msg="gateway: stat packet received" addr="127.0.0.1:51176" mac=b827ebfffefa606c
Aug 13 12:18:07 jessie lora-gateway-bridge[2491]: time="2018-08-13T12:18:07+03:00" level=info msg="gateway: sending udp packet to gateway" addr="127.0.0.1:51176" protocol_version=2 type=PushACK
Aug 13 12:18:07 jessie lora-gateway-bridge[2491]: time="2018-08-13T12:18:07+03:00" level=info msg="backend: publishing packet" qos=0 topic=gateway/b827ebfffefa606c/stats
Aug 13 12:18:11 jessie lora-gateway-bridge[2491]: time="2018-08-13T12:18:11+03:00" level=info msg="gateway: received udp packet from gateway" addr="127.0.0.1:50165" protocol_version=2 type=PullData
Aug 13 12:18:11 jessie lora-gateway-bridge[2491]: time="2018-08-13T12:18:11+03:00" level=info msg="gateway: sending udp packet to gateway" addr="127.0.0.1:50165" protocol_version=2 type=PullACK
Aug 13 12:18:16 jessie lora-gateway-bridge[2491]: time="2018-08-13T12:18:16+03:00" level=info msg="gateway: received udp packet from gateway" addr="127.0.0.1:51176" protocol_version=2 type=PushData
Aug 13 12:18:16 jessie lora-gateway-bridge[2491]: time="2018-08-13T12:18:16+03:00" level=info msg="gateway: rxpk packet received" addr="127.0.0.1:51176" data="QKnrpAGABgABQc4gp+r0pw8mmGS27gb52ZQ=" mac=b827ebfffefa606c
Aug 13 12:18:16 jessie lora-gateway-bridge[2491]: time="2018-08-13T12:18:16+03:00" level=info msg="backend: publishing packet" qos=0 topic=gateway/b827ebfffefa606c/rx
Aug 13 12:18:16 jessie lora-gateway-bridge[2491]: time="2018-08-13T12:18:16+03:00" level=info msg="gateway: sending udp packet to gateway" addr="127.0.0.1:51176" protocol_version=2 type=PushACK
Aug 13 12:18:17 jessie lora-gateway-bridge[2491]: time="2018-08-13T12:18:17+03:00" level=info msg="gateway: received udp packet from gateway" addr="127.0.0.1:51176" protocol_version=2 type=PushData
Aug 13 12:18:17 jessie lora-gateway-bridge[2491]: time="2018-08-13T12:18:17+03:00" level=info msg="gateway: rxpk packet received" addr="127.0.0.1:51176" data="AAMCAQAAAAAAWTZmBjm1DQDHKms7IOw=" mac=b827ebfffefa606c
Aug 13 12:18:17 jessie lora-gateway-bridge[2491]: time="2018-08-13T12:18:17+03:00" level=info msg="backend: publishing packet" qos=0 topic=gateway/b827ebfffefa606c/rx
Aug 13 12:18:17 jessie lora-gateway-bridge[2491]: time="2018-08-13T12:18:17+03:00" level=info msg="gateway: sending udp packet to gateway" addr="127.0.0.1:51176" protocol_version=2 type=PushACK
Aug 13 12:18:18 jessie lora-gateway-bridge[2491]: time="2018-08-13T12:18:18+03:00" level=info msg="gateway: received udp packet from gateway" addr="127.0.0.1:51176" protocol_version=2 type=PushData
Aug 13 12:18:18 jessie lora-gateway-bridge[2491]: time="2018-08-13T12:18:18+03:00" level=info msg="gateway: rxpk packet received" addr="127.0.0.1:51176" data="AAMCAQAAAAAAUjV1EjG1DQBgLkA0o94=" mac=b827ebfffefa606c
Aug 13 12:18:18 jessie lora-gateway-bridge[2491]: time="2018-08-13T12:18:18+03:00" level=info msg="gateway: sending udp packet to gateway" addr="127.0.0.1:51176" protocol_version=2 type=PushACK
Aug 13 12:18:18 jessie lora-gateway-bridge[2491]: time="2018-08-13T12:18:18+03:00" level=info msg="backend: publishing packet" qos=0 topic=gateway/b827ebfffefa606c/rx
Aug 13 12:18:21 jessie lora-gateway-bridge[2491]: time="2018-08-13T12:18:21+03:00" level=info msg="gateway: received udp packet from gateway" addr="127.0.0.1:50165" protocol_version=2 type=PullData
Aug 13 12:18:21 jessie lora-gateway-bridge[2491]: time="2018-08-13T12:18:21+03:00" level=info msg="gateway: sending udp packet to gateway" addr="127.0.0.1:50165" protocol_version=2 type=PullACK
Aug 13 12:18:31 jessie lora-gateway-bridge[2491]: time="2018-08-13T12:18:31+03:00" level=info msg="gateway: received udp packet from gateway" addr="127.0.0.1:50165" protocol_version=2 type=PullData
Aug 13 12:18:31 jessie lora-gateway-bridge[2491]: time="2018-08-13T12:18:31+03:00" level=info msg="gateway: sending udp packet to gateway" addr="127.0.0.1:50165" protocol_version=2 type=PullACK
Aug 13 12:18:37 jessie lora-gateway-bridge[2491]: time="2018-08-13T12:18:37+03:00" level=info msg="gateway: received udp packet from gateway" addr="127.0.0.1:51176" protocol_version=2 type=PushData
Aug 13 12:18:37 jessie lora-gateway-bridge[2491]: time="2018-08-13T12:18:37+03:00" level=info msg="gateway: stat packet received" addr="127.0.0.1:51176" mac=b827ebfffefa606c
Aug 13 12:18:37 jessie lora-gateway-bridge[2491]: time="2018-08-13T12:18:37+03:00" level=info msg="backend: publishing packet" qos=0 topic=gateway/b827ebfffefa606c/stats
Aug 13 12:18:37 jessie lora-gateway-bridge[2491]: time="2018-08-13T12:18:37+03:00" level=info msg="gateway: sending udp packet to gateway" addr="127.0.0.1:51176" protocol_version=2 type=PushACK
Aug 13 12:18:41 jessie lora-gateway-bridge[2491]: time="2018-08-13T12:18:41+03:00" level=info msg="gateway: received udp packet from gateway" addr="127.0.0.1:50165" protocol_version=2 type=PullData
Aug 13 12:18:41 jessie lora-gateway-bridge[2491]: time="2018-08-13T12:18:41+03:00" level=info msg="gateway: sending udp packet to gateway" addr="127.0.0.1:50165" protocol_version=2 type=PullACK
Aug 13 12:18:51 jessie lora-gateway-bridge[2491]: time="2018-08-13T12:18:51+03:00" level=info msg="gateway: received udp packet from gateway" addr="127.0.0.1:50165" protocol_version=2 type=PullData
Aug 13 12:18:51 jessie lora-gateway-bridge[2491]: time="2018-08-13T12:18:51+03:00" level=info msg="gateway: sending udp packet to gateway" addr="127.0.0.1:50165" protocol_version=2 type=PullACK
Aug 13 12:19:01 jessie lora-gateway-bridge[2491]: time="2018-08-13T12:19:01+03:00" level=info msg="gateway: received udp packet from gateway" addr="127.0.0.1:50165" protocol_version=2 type=PullData
Aug 13 12:19:01 jessie lora-gateway-bridge[2491]: time="2018-08-13T12:19:01+03:00" level=info msg="gateway: sending udp packet to gateway" addr="127.0.0.1:50165" protocol_version=2 type=PullACK
Aug 13 12:19:07 jessie lora-gateway-bridge[2491]: time="2018-08-13T12:19:07+03:00" level=info msg="gateway: received udp packet from gateway" addr="127.0.0.1:51176" protocol_version=2 type=PushData
Aug 13 12:19:07 jessie lora-gateway-bridge[2491]: time="2018-08-13T12:19:07+03:00" level=info msg="gateway: stat packet received" addr="127.0.0.1:51176" mac=b827ebfffefa606c
Aug 13 12:19:07 jessie lora-gateway-bridge[2491]: time="2018-08-13T12:19:07+03:00" level=info msg="backend: publishing packet" qos=0 topic=gateway/b827ebfffefa606c/stats
Aug 13 12:19:07 jessie lora-gateway-bridge[2491]: time="2018-08-13T12:19:07+03:00" level=info msg="gateway: sending udp packet to gateway" addr="127.0.0.1:51176" protocol_version=2 type=PushACK
Aug 13 12:19:11 jessie lora-gateway-bridge[2491]: time="2018-08-13T12:19:11+03:00" level=info msg="gateway: received udp packet from gateway" addr="127.0.0.1:50165" protocol_version=2 type=PullData
Aug 13 12:19:11 jessie lora-gateway-bridge[2491]: time="2018-08-13T12:19:11+03:00" level=info msg="gateway: sending udp packet to gateway" addr="127.0.0.1:50165" protocol_version=2 type=PullACK
Aug 13 12:19:19 jessie lora-gateway-bridge[2491]: time="2018-08-13T12:19:19+03:00" level=info msg="gateway: received udp packet from gateway" addr="127.0.0.1:51176" protocol_version=2 type=PushData
Aug 13 12:19:19 jessie lora-gateway-bridge[2491]: time="2018-08-13T12:19:19+03:00" level=info msg="gateway: rxpk packet received" addr="127.0.0.1:51176" data="QKnrpAGABwAB0SPkwYc6UHOK0XjO4kX2uq8=" mac=b827ebfffefa606c
Aug 13 12:19:19 jessie lora-gateway-bridge[2491]: time="2018-08-13T12:19:19+03:00" level=info msg="backend: publishing packet" qos=0 topic=gateway/b827ebfffefa606c/rx
Aug 13 12:19:19 jessie lora-gateway-bridge[2491]: time="2018-08-13T12:19:19+03:00" level=info msg="gateway: sending udp packet to gateway" addr="127.0.0.1:51176" protocol_version=2 type=PushACK
Aug 13 12:19:21 jessie lora-gateway-bridge[2491]: time="2018-08-13T12:19:21+03:00" level=info msg="gateway: received udp packet from gateway" addr="127.0.0.1:50165" protocol_version=2 type=PullData
Aug 13 12:19:21 jessie lora-gateway-bridge[2491]: time="2018-08-13T12:19:21+03:00" level=info msg="gateway: sending udp packet to gateway" addr="127.0.0.1:50165" protocol_version=2 type=PullACK
Aug 13 12:19:32 jessie lora-gateway-bridge[2491]: time="2018-08-13T12:19:32+03:00" level=info msg="gateway: received udp packet from gateway" addr="127.0.0.1:50165" protocol_version=2 type=PullData
Aug 13 12:19:32 jessie lora-gateway-bridge[2491]: time="2018-08-13T12:19:32+03:00" level=info msg="gateway: sending udp packet to gateway" addr="127.0.0.1:50165" protocol_version=2 type=PullACK
Aug 13 12:19:37 jessie lora-gateway-bridge[2491]: time="2018-08-13T12:19:37+03:00" level=info msg="gateway: received udp packet from gateway" addr="127.0.0.1:51176" protocol_version=2 type=PushData
Aug 13 12:19:37 jessie lora-gateway-bridge[2491]: time="2018-08-13T12:19:37+03:00" level=info msg="gateway: sending udp packet to gateway" addr="127.0.0.1:51176" protocol_version=2 type=PushACK
Aug 13 12:19:37 jessie lora-gateway-bridge[2491]: time="2018-08-13T12:19:37+03:00" level=info msg="gateway: stat packet received" addr="127.0.0.1:51176" mac=b827ebfffefa606c
Aug 13 12:19:37 jessie lora-gateway-bridge[2491]: time="2018-08-13T12:19:37+03:00" level=info msg="backend: publishing packet" qos=0 topic=gateway/b827ebfffefa606c/stats
Aug 13 12:19:42 jessie lora-gateway-bridge[2491]: time="2018-08-13T12:19:42+03:00" level=info msg="gateway: received udp packet from gateway" addr="127.0.0.1:50165" protocol_version=2 type=PullData
Aug 13 12:19:42 jessie lora-gateway-bridge[2491]: time="2018-08-13T12:19:42+03:00" level=info msg="gateway: sending udp packet to gateway" addr="127.0.0.1:50165" protocol_version=2 type=PullACK

Clement · August 13, 2018, 10:01am

Is your MBox in OTAA or ABP ?

if it is in OTAA then, the FCnt on server side is reset for every new activation, so no problem.

if it is in ABP, maybe the MBox keeps the FCnt in flash memory and reload it after each power up.

However, the issue on your arduino is the FCnt according to the logs.

handyman · August 13, 2018, 10:22am

i had the MBOX configured both ways and I don’t remember to had any issues.

but, if a device reboots shouldn’t the server reset the FCnt on ABP join request. to me it seams common sense.
why should it be kept de FCnt for ABP and reset for OTAA?

Clement · August 13, 2018, 11:28am

It’s a question of security. To avoid replay attack if I remember.

On OTAA keys are renegociated every time the node reactivates. So there is no problem to reset the FCnt on server side.

geofbaum · August 13, 2018, 1:31pm

When you set up your MBox you likely unknowingly have it save and restore a session after a reset which would keep the Frame Count intact. You can do this with the Dragino shield but you’re going to have to save the Frame Count counter to the EEPROM on the Arduino and have it pull that number upon a reset. The only down side is that you are going to have to do it every data packet send cycle and the EEPROM on the Arduino has something like a guarantee of 100,000 write cycle before things could start going south. If that’s ok for you than all you’ll need to do is add some lines to your code to read and save the Frame Counter.

https://www.arduino.cc/en/Tutorial/EEPROMWrite
https://www.arduino.cc/en/Tutorial/EEPROMRead

handyman · August 13, 2018, 1:43pm

thank you guys

I’ve learned something new with your help.
Best regards