gotthardp / lorawan-server

Compact server for private LoRaWAN networks
https://gotthardp.github.io/lorawan-server
MIT License
941 stars 326 forks source link

ACK is not received by Node #784

Open pshingala145 opened 3 years ago

pshingala145 commented 3 years ago

We are using Sentrius RG1xx LoRaWAN gateway with RN2903A(US) LoRaWAN modules mounted on IMP006 Board and Gotthardp LoRaWAN Network server.

Moreover, we send Confirm up-link messages to LoRaWAN network server(NS), in that up-link is being received by NS and NS also send the ACK to a gateway for the same Up-link messages, though node doesn't receive ACK from Gateway.

we examined Packet forwarder(Semtech UDP forwarder) Logs and observed the ACK is received by Gateway from NS, but all the time, the frequency is different from each Downlink message (ACK). We have set Down-link(ACK) frequency on the network server which is 924.5 MHz, but we don't see such value on the gateway's received packets and the Packet forwarder itself changes the frequency, so we are not sure on what frequency and data rate our node should listen on receiving windows.

Why Packet forwarder changes the frequency of Downlink messages and could you suggest how can we set the static frequency on Packet forwarder for the same.

Could you please help us with how node and gateway synchronized for Down-link(ACK) messages?

kindly find attached gateway Logs and receiving windows Configuration.

Any leads would be appreciated!

123_1

INFO: [down] PULL_RESP received - token[230:33] :) RG1xx29F063 lora user.notice Jul 9 09:00:09 # BEACON sent so far: 0 RG1xx29F063 lora user.notice Jul 9 09:00:09 # BEACON queued: 0 RG1xx29F063 lora user.notice Jul 9 09:00:09 # TX rejected (too early): 0.00% (req:2, rej:0) RG1xx29F063 lora user.notice Jul 9 09:00:09 # TX rejected (too late): 0.00% (req:2, rej:0) RG1xx29F063 lora user.notice Jul 9 09:00:09 # TX rejected (collision beacon): 0.00% (req:2, rej:0) RG1xx29F063 lora user.notice Jul 9 09:00:09 # TX rejected (collision packet): 0.00% (req:2, rej:0) RG1xx29F063 lora user.notice Jul 9 09:00:09 # TX errors: 0 RG1xx29F063 lora user.notice Jul 9 09:00:09 # RF packets sent to concentrator: 1 (13 bytes) RG1xx29F063 lora user.notice Jul 9 09:00:09 # PULL_RESP(onse) datagrams received: 1 (172 bytes) RG1xx29F063 lora user.notice Jul 9 09:00:09 # PULL_DATA sent: 3 (100.00% acknowledged) RG1xx29F063 lora user.notice Jul 9 09:00:09 ### [DOWNSTREAM] ### RG1xx29F063 lora user.notice Jul 9 09:00:09 # PUSH_DATA acknowledged: 100.00% RG1xx29F063 lora user.notice Jul 9 09:00:09 # PUSH_DATA datagrams sent: 2 (343 bytes) RG1xx29F063 lora user.notice Jul 9 09:00:09 # RF packets forwarded: 1 (41 bytes) RG1xx29F063 lora user.notice Jul 9 09:00:09 # CRC_OK: 50.00%, CRC_FAIL: 50.00%, NO_CRC: 0.00% RG1xx29F063 lora user.notice Jul 9 09:00:09 # RF packets received by concentrator: 2 RG1xx29F063 lora user.notice Jul 9 09:00:09 ### [UPSTREAM] ### RG1xx29F063 lora user.notice Jul 9 09:00:09 ##### 2021-07-09 08:58:39 GMT ##### RG1xx29F063 lora user.notice Jul 9 09:00:09 INFO: Enabling GPS mode for concentrator's counter. RG1xx29F063 lora user.notice Jul 9 09:00:09 INFO: host/sx1301 time offset=(1625820936s:351348µs) - drift=19959µs RG1xx29F063 lora user.notice Jul 9 09:00:09 INFO: Disabling GPS mode for concentrator's counter... RG1xx29F063 lora user.notice Jul 9 09:00:09 INFO: [down] PULL_ACK received in 26 ms RG1xx29F063 lora user.notice Jul 9 09:00:09 INFO: Requested 5 power level RG1xx29F063 lora user.notice Jul 9 09:00:09 INFO: tx_start_delay=1497 (1497.000000) - (1497, bw_delay=0.000000, notch_delay=0.000000) RG1xx29F063 lora user.notice Jul 9 08:58:21 INFO: Duty = 0, Dwell = 0, Hops = 0, Flags = 0x0, next tx ms = 0 RG1xx29F063 lora user.notice Jul 9 08:58:21 INFO: Channel found, transmission allowed RG1xx29F063 lora user.notice Jul 9 08:58:21 INFO: Requested time on air: 20 RG1xx29F063 lora user.notice Jul 9 08:58:21 INFO: Requested channel within regulatory rule 902 - 928 MHz RG1xx29F063 lora user.notice Jul 9 08:58:21 INFO: [down] PULL_ACK received in 28 ms RG1xx29F063 lora user.notice Jul 9 08:58:21 JSON down: {"txpk":{"powe":7,"imme":false,"tmst":165190452,"codr":"4/5","datr":"SF8BW500","freq":925.1,"modu":"LORA","rfch":0,"ipol":true,"size":13,"data":"YJvZIwAhAwAG9uREEQ=="}}** RG1xx29F063 lora user.notice Jul 9 08:58:21 INFO: [down] PULL_RESP received - token[230:33] :) RG1xx29F063 lora user.notice Jul 9 08:58:21 INFO: [up] PUSH_ACK received in 26 ms RG1xx29F063 lora user.notice Jul 9 08:58:21 JSON up: {"rxpk":[{"tmst":163190452,"chan":7,"rfch":0,"freq":904.500000,"stat":1,"modu":"LORA","datr":"SF8BW125","codr":"4/5","lsnr":11.5,"rssi":-75,"size":41,"data":"gJvZIwCAAwADMjqWX6yoV4XJz96iRZOVlo9HJMtXQVxdGeCTRzXoT8c="}]}** RG1xx29F063 lora user.notice Jul 9 08:58:21 INFO: Received pkt from mote: 0023D99B (fcnt=3) RG1xx29F063 lora user.notice Jul 9 08:58:21 INFO: [down] PULL_ACK received in 25 ms RG1xx29F063 lora user.notice Jul 9 08:58:21 INFO: [up] PUSH_ACK received in 27 ms RG1xx29F063 lora user.notice Jul 9 08:58:21 JSON up: {"stat":{"time":"2021-07-09 08:58:09 GMT","rxnb":2,"rxok":0,"rxfw":0,"ackr":100.0,"dwnb":0,"txnb":0}}

RG1xx29F063 lora user.notice Jul 9 09:07:09 # GPS sync is disabled RG1xx29F063 lora user.notice Jul 9 09:07:09 ### [GPS] ### RG1xx29F063 lora user.notice Jul 9 09:07:09 src/jitqueue.c:448:jit_print_queue(): INFO: [jit] queue is empty RG1xx29F063 lora user.notice Jul 9 09:07:09 # SX1301 time (PPS): 602697652 RG1xx29F063 lora user.notice Jul 9 09:07:09 ### [JIT] ### RG1xx29F063 lora user.notice Jul 9 09:07:09 # BEACON rejected: 0 RG1xx29F063 lora user.notice Jul 9 09:07:09 # BEACON sent so far: 0 RG1xx29F063 lora user.notice Jul 9 09:07:09 # BEACON queued: 0 RG1xx29F063 lora user.notice Jul 9 09:07:09 # TX rejected (too early): 0.00% (req:4, rej:0) RG1xx29F063 lora user.notice Jul 9 09:07:09 # TX rejected (too late): 0.00% (req:4, rej:0) RG1xx29F063 lora user.notice Jul 9 09:07:09 # TX rejected (collision beacon): 0.00% (req:4, rej:0) RG1xx29F063 lora user.notice Jul 9 09:07:09 # TX rejected (collision packet): 0.00% (req:4, rej:0) RG1xx29F063 lora user.notice Jul 9 09:07:09 # TX errors: 0 RG1xx29F063 lora user.notice Jul 9 09:07:09 # RF packets sent to concentrator: 1 (13 bytes) RG1xx29F063 lora user.notice Jul 9 09:07:09 # PULL_RESP(onse) datagrams received: 1 (172 bytes) RG1xx29F063 lora user.notice Jul 9 09:07:09 # PULL_DATA sent: 3 (100.00% acknowledged) RG1xx29F063 lora user.notice Jul 9 09:07:09 ### [DOWNSTREAM] ### RG1xx29F063 lora user.notice Jul 9 09:07:09 # PUSH_DATA acknowledged: 100.00% RG1xx29F063 lora user.notice Jul 9 09:07:09 # PUSH_DATA datagrams sent: 2 (342 bytes) RG1xx29F063 lora user.notice Jul 9 09:07:09 # RF packets forwarded: 1 (41 bytes) RG1xx29F063 lora user.notice Jul 9 09:07:09 # CRC_OK: 100.00%, CRC_FAIL: 0.00%, NO_CRC: 0.00% RG1xx29F063 lora user.notice Jul 9 09:07:09 # RF packets received by concentrator: 1 RG1xx29F063 lora user.notice Jul 9 09:07:09 ### [UPSTREAM] ### RG1xx29F063 lora user.notice Jul 9 09:07:09 ##### 2021-07-09 09:05:39 GMT ##### RG1xx29F063 lora user.notice Jul 9 09:07:09 INFO: Enabling GPS mode for concentrator's counter. RG1xx29F063 lora user.notice Jul 9 09:07:09 INFO: host/sx1301 time offset=(1625820936s:242137µs) - drift=22946µs RG1xx29F063 lora user.notice Jul 9 09:07:09 INFO: Disabling GPS mode for concentrator's counter... RG1xx29F063 lora user.notice Jul 9 09:07:09 INFO: [down] PULL_ACK received in 31 ms RG1xx29F063 lora user.notice Jul 9 09:07:09 INFO: [down] PULL_ACK received in 30 ms RG1xx29F063 lora user.notice Jul 9 09:07:09 INFO: Requested 5 power level RG1xx29F063 lora user.notice Jul 9 09:07:09 INFO: tx_start_delay=1497 (1497.000000) - (1497, bw_delay=0.000000, notch_delay=0.000000) RG1xx29F063 lora user.notice Jul 9 09:05:12 INFO: Duty = 0, Dwell = 0, Hops = 0, Flags = 0x0, next tx ms = 0 RG1xx29F063 lora user.notice Jul 9 09:05:12 INFO: Channel found, transmission allowed RG1xx29F063 lora user.notice Jul 9 09:05:12 INFO: Requested time on air: 20 RG1xx29F063 lora user.notice Jul 9 09:05:12 INFO: Requested channel within regulatory rule 902 - 928 MHz RG1xx29F063 lora user.notice Jul 9 09:05:12 JSON down: {"txpk":{"powe":7,"imme":false,"tmst":576346684,"codr":"4/5","datr":"SF8BW500","freq":924.5,"modu":"LORA","rfch":0,"ipol":true,"size":13,"data":"YJvZIwAhBQAGLlCQ/Q=="}} RG1xx29F063 lora user.notice Jul 9 09:05:12 INFO: [down] PULL_RESP received - token[184:113] :) RG1xx29F063 lora user.notice Jul 9 09:05:12 INFO: [up] PUSH_ACK received in 29 ms RG1xx29F063 lora user.notice Jul 9 09:05:12 JSON up: {"rxpk":[{"tmst":574346684,"chan":4,"rfch":0,"freq":904.300000,"stat":1,"modu":"LORA","datr":"SF8BW125","codr":"4/5","lsnr":8.8,"rssi":-77,"size":41,"data":"gJvZIwCADgADoJOLXtjMw6W2jGXHKRtV0e3R6/WRaV1MA5uvc2vCcZs="}]}

Lora Receiving Windows Configuration on Device and Network Server. initCommands <- [ format("%s mod %s", RADIO_SET, RADIO_MODE), format("%s freq %i", RADIO_SET, RADIO_FREQ), format("%s sf %s", RADIO_SET, RADIO_SPREADING_FACTOR), format("%s bw %i", RADIO_SET, RADIO_BANDWIDTH), format("%s cr %s", RADIO_SET, RADIO_CODING_RATE), format("%s crc %s", RADIO_SET, RADIO_CRC), format("%s sync %i", RADIO_SET, RADIO_SYNC_WORD), format("%s wdt %i", RADIO_SET, RADIO_WATCHDOG_TIMEOUT), "mac set pwridx 5","radio set prlen 8","radio set iqi on", "sys get hweui","mac set devaddr 0023D99B", "mac set nwkskey 0123456789ABCDEF0123456789ABCDEF" , "mac set appskey 0123456789ABCDEF0123456789FEDCBA","mac set dr 4","mac set adr on","mac set retx 5", "mac set rxdelay1 1000","mac set rx2 8 924500000","mac set ar on","mac save", "mac join abp"];

Screenshot_2021-07-10_11-45-10 Screenshot_2021-07-10_11-45-22

altishchenko commented 3 years ago

Hello, By the looks of it (I am not experienced in US radio plan), your setup is correct. Moreover, by the very first screenshot you attached, your end device is incrementing its uplink fcnt counter, which means that it does receive acknowledgements really. End devices usually attempt to do multiple re-transmissions of the same frame, if the acknowledgement was not received.

As for the different downlink frequencies you see, the server usually tries to send an ACK in RX1 timeslot at a channel shift that is mandated by your regional plan (for Europe it is the channel on which the uplink was received), if that fails, as detected by the re-up frames showing up in the Frames table, it will try the fixed frequency for the RX2 receive window. You can change this behaviour in the device's Profile setting on the Network server, in the General tab - the TX Window parameter, which is set by default to Auto, can be changed to RX1 or RX2 respectively.

pshingala145 commented 3 years ago

hello altishchenko,

Thanks for your suggestion.

The issue with Downlink(ACK) frequency getting changed all time has been resolved by setting TX WINDOW parameter as RX2 on the LoRaWAN Network server, but node still doesn't get ACK and through the error called mac_error as before.

we are using the RN2903A(US) LoRa module and Sentrius RG1xx LoRaWAN gateway.

Receiving window parameters(RX1/RX2 delays, DR, and frequency) are same at both the places node and NS.

I m attaching the screenshot of Node logs. WhatsApp Image 2021-07-12 at 10 47 11 AM

altishchenko commented 3 years ago

Hi, mac_err is quite cryptic, to be honest. Is there any sort of debug level with packet dump on the thing? Does this happen when you are sending a downlink, not the usual server ACK, or on its own? If the latter is the case, your device may reject some server MAC commands, like device info request or attempt to set the ADR parameters. Is your node OTAA or ABP?

pshingala145 commented 3 years ago

hello,

Node uses ABP to join the network.

We have tried sending Downlink Messages from Server, but Node Didn't receive it. We could see the Downlink payload at the gateway. I don't know whether the gateway emits data or not.

Is there any sort of debug level with packet dump on the thing? uplink

The following screenshot is the downlink Msg payload. Downlink

altishchenko commented 3 years ago

Sorry for delay. Screenshots look good to me. The packet on the last screenshot is an acknowledgement from the server, that contains a few LoRaWAN options (which are not displayed unfortunately). It is a control, not data, message, because the Port field is empty and FOpts are present. You can have a look in the server's debug.log file, to see what is going on the server side when you are receiving data or sending downlink messages.

Can you show me how are you sending downlinks? Full JSON as you send it to the server will be great.

By the way, what is the setting for the FCnt Check field in your device's profile? Looks like it is set to 'Reset on zero', which is ok if the ABP device reboots from time to time and doesn't keep the FCnt counters in the flash/eeprom.

pshingala145 commented 3 years ago

hey @ altishchenko

Thanks for the feedback For your reference, I'm attaching one more screenshot from the gateway logs. On the LNS side, I have disabled the Frame counter. Not only that but, in my Lora firmware I'm not setting the Frame counter

I have attached the server logs and Gateway ping here All suggestions and comments welcome Thanks!

server_log_fcnt

WhatsApp Image 2021-07-20 at 2 15 29 PM

altishchenko commented 3 years ago

Hello, you should not disable frame counter in your firmware! Server will reject all of the frames and will never send downlink on such a frame. What I was saying is - counters must be running and must match. From your logs before I didn't see any problems with the counters, but still you said you were not getting any downlinks though you should, because everything looked fine. Enable counters back! Just make sure, if you use 'Reset on zero', counters on your device must be 16-bit, not 32.

Make sure your LoRaWAN version on the device is 1.0.3 or 1.0.4.

One more hint, you must send your downlink only when your device has started and is already running. Any message with FCnt=1 will perform a virtual "join" for the ABP and drop all messages in the downlink queue.

Please, send me the JSON you push to the server to send downlink, as I asked you before! Don't play with counters it is meaningless.

pshingala145 commented 3 years ago

hi,

Following is the Downlink Payload that we push to the server.

{ "data": "4c45445f4f4e", "devaddr": "69E611CE" }

pshingala145 commented 3 years ago

Hi..

I have recently enabled the Frame counter check at LNS to "Reset on Zero" Now, from my firmware, I'm also setting the uint16_t up_counter & down_counter which is incremented at every frame send

By means of the downlink, here I'm talking about the acknowledgment from the LNS to the gateway and from Gateway to Node!

Right now , I'm dealing with RN2903 module at US Frequencies, which has the LoRaWAN version 1.0.3 My issue is, every confirmed message I'm getting "mac_err" However, the message appears at the LNS but somehow node is unable to get the ack from the gateway!

Before that, in my firmware, I have set the downlink Frequency to 924.5 Mhz And, at the LNS I'd set the TX Window as "RX2" in device profile to get the downlink at the desired Frequencies

Here, I have attached the 2 screenshot One is from LNS, where you can see the increment of the Frame counters In 2nd Screenshot, you can see that the gateway is getting the downlink ack ping at the 924.5 Mhz

Now, the issue is somehow the node is unable to get the ack and that's how it's responding as "mac_err"!

WhatsApp Image 2021-07-20 at 5 56 32 PM

WhatsApp Image 2021-07-20 at 5 56 33 PM

altishchenko commented 3 years ago

Oh, I see. I was diverted by your first screenshot, not noticing that these were different devices sending uplinks listed - the FCnt for the uplinks, so happened, steadily increases on that slide.

To be honest, I am out of ideas on why your device is not getting the acknowledgement, as everything looks fine from the server and gateway perspective. US band is a bit tricky to handle and, given such an issue, I, myself, would probably try some simpler to control band like EU866 - less channels, simpler rules for uplinks and downlinks, less possible issues in known opensource stacks, like LoRaMac-node (I am not saying there are any at the current state).

One last question, as I stumbled upon this once or twice, is your device expecting downlinks in the proper reversed polarity? Some devices are violating LoRaWAN standard and expect downlinks in the same polarity as uplinks.

Sorry, but it looks like the server is not the one to blame here. Do you have any other known to be working devices to check? Sometimes it helps to narrow down if the device's stack is the problem and not, for example, the gateway or server configuration.

pshingala145 commented 3 years ago

Hello @altishchenko,

The same code and the same node are working with one of our Chinese gateway having the same network configuration. So it should work with the Laird gateway as I presume. However, we also have tried with the sub-band 1 (902.3 - 903.7 Mhz) but, every time the gateway is unable to send the downlink ack!

kangyang73 commented 3 years ago

Hello @pshingala145, Did you solve the problem? I also have the same problem with you.