Missing downlink message

ChirpStack Application Server
1

Hi! So, I on my endpoint is running the abp-ttn.ino example, I just changed the ABP keys configuration. On the LoRa Server logs I am seeing some uplink messages until receiving a downlink message and then the uplink message does not appear anymore. Basically, the LoRa Server is receiving only one message with success. On endpoint console output I noticed all packets sent to the gateway.

This problem is occurring after an update that the LoRa Server did a 2 weeks ago. Before that, the same code was working properly.

51%20PM
Screen Shot 2018-03-31 at 8.28.51 PM.png1890×904 114 KB

2

Have you checked the logs?

3

Yes, there are the logs that come from lora_pkt_fwd:

##### 2018-04-01 19:31:43 GMT ##### 
### [UPSTREAM] ### 
# RF packets received by concentrator: 4 
# CRC_OK: 100.00%, CRC_FAIL: 0.00%, NO_CRC: 0.00% 
# RF packets forwarded: 4 (104 bytes) 
# PUSH_DATA datagrams sent: 4 (831 bytes) 
# PUSH_DATA acknowledged: 100.00% 
### [DOWNSTREAM] ### 
# PULL_DATA sent: 3 (100.00% acknowledged) 
# PULL_RESP(onse) datagrams received: 0 (0 bytes) 
# RF packets sent to concentrator: 0 (0 bytes) 
# TX errors: 0 
# BEACON queued: 0 
# BEACON sent so far: 0 
# BEACON rejected: 0 
### [JIT] ### 
# SX1301 time (PPS): 2425868 
src/jitqueue.c:448:jit_print_queue(): INFO: [jit] queue is empty 
### [GPS] ### 
# GPS sync is disabled 
##### END ##### 

JSON up: {"stat":{"time":"2018-04-01 19:31:43 GMT","rxnb":4,"rxok":4,"rxfw":4,"ackr":100.0,"dwnb":0,"txnb":0}} 
INFO: [up] PUSH_ACK received in 23 ms 
INFO: [down] PULL_ACK received in 20 ms 

INFO: Received pkt from mote: 07AA69A1 (fcnt=21) 

JSON up: {"rxpk":[{"tmst":34248780,"chan":5,"rfch":1,"freq":904.900000,"stat":1,"modu":"LORA","datr":"SF7BW125","codr":"4/5","lsnr":9.2,"rssi":-51,"size":26,"data":"QKFpqgeAFQABcZqZcv19VTP/qP57qWQ6kfs="}]}
INFO: [up] PUSH_ACK received in 23 ms 

INFO: Received pkt from mote: 07AA69A1 (fcnt=22) 

JSON up: {"rxpk":[{"tmst":41348716,"chan":6,"rfch":1,"freq":905.100000,"stat":1,"modu":"LORA","datr":"SF7BW125","codr":"4/5","lsnr":10.0,"rssi":-55,"size":26,"data":"QKFpqgeAFgAB7XRQ0Ads/zRTVyKI5J8kOLo="}]}
INFO: [up] PUSH_ACK received in 22 ms 
INFO: [down] PULL_ACK received in 21 ms 

INFO: Received pkt from mote: 07AA69A1 (fcnt=23) 

JSON up: {"rxpk":[{"tmst":48449852,"chan":7,"rfch":1,"freq":905.300000,"stat":1,"modu":"LORA","datr":"SF7BW125","codr":"4/5","lsnr":10.0,"rssi":-57,"size":26,"data":"QKFpqgeAFwABiLArqf5tdTTeEx8Brr+bu10="}]}
INFO: [up] PUSH_ACK received in 24 ms 
INFO: [down] PULL_ACK received in 22 ms 

INFO: Received pkt from mote: 07AA69A1 (fcnt=24) 

JSON up: {"rxpk":[{"tmst":55550083,"chan":0,"rfch":0,"freq":903.900000,"stat":1,"modu":"LORA","datr":"SF7BW125","codr":"4/5","lsnr":8.8,"rssi":-55,"size":26,"data":"QKFpqgeAGAAB5n4NQ6qhQVDtFSKfmfv0R0s="}]}
INFO: [up] PUSH_ACK received in 69 ms 

INFO: Disabling GPS mode for concentrator's counter... 

##### 2018-04-01 19:32:13 GMT ##### 
### [UPSTREAM] ### 
# RF packets received by concentrator: 4 
# CRC_OK: 100.00%, CRC_FAIL: 0.00%, NO_CRC: 0.00% 
# RF packets forwarded: 4 (104 bytes) 
# PUSH_DATA datagrams sent: 5 (947 bytes) 
# PUSH_DATA acknowledged: 100.00% 
### [DOWNSTREAM] ### 
# PULL_DATA sent: 3 (100.00% acknowledged) 
# PULL_RESP(onse) datagrams received: 0 (0 bytes) 
INFO: host/sx1301 time offset=(1522611070s:899173µs) - drift=346µs 
INFO: Enabling GPS mode for concentrator's counter. 

# RF packets sent to concentrator: 0 (0 bytes) 
# TX errors: 0 
# BEACON queued: 0 
# BEACON sent so far: 0 
# BEACON rejected: 0 
### [JIT] ### 
# SX1301 time (PPS): 62425802 
src/jitqueue.c:448:jit_print_queue(): INFO: [jit] queue is empty 
### [GPS] ### 
# GPS sync is disabled 
##### END ##### 

JSON up: {"stat":{"time":"2018-04-01 19:32:13 GMT","rxnb":4,"rxok":4,"rxfw":4,"ackr":100.0,"dwnb":0,"txnb":0}} 
INFO: [up] PUSH_ACK received in 23 ms 

INFO: Received pkt from mote: 07AA69A1 (fcnt=25) 

JSON up: {"rxpk":[{"tmst":62649051,"chan":1,"rfch":0,"freq":904.100000,"stat":1,"modu":"LORA","datr":"SF7BW125","codr":"4/5","lsnr":10.5,"rssi":-55,"size":26,"data":"QKFpqgeAGQAB0kUQZTAuN7Emjaia5rZjSww="}]}
INFO: [up] PUSH_ACK received in 21 ms 
INFO: [down] PULL_ACK received in 20 ms 

INFO: Received pkt from mote: 07AA69A1 (fcnt=26) 

JSON up: {"rxpk":[{"tmst":69749051,"chan":2,"rfch":0,"freq":904.300000,"stat":1,"modu":"LORA","datr":"SF7BW125","codr":"4/5","lsnr":10.0,"rssi":-49,"size":26,"data":"QKFpqgeAGgABEhneyi4uwXU54PCZWK2DEtM="}]}
INFO: [up] PUSH_ACK received in 22 ms 
INFO: [down] PULL_ACK received in 22 ms
4

I don’t know why but I executed it again to copy the logs to you and on this time there is not either the first downlink message.

This is the Arduino output message:

Starting
...
Packet queued
27112365: EV_TXCOMPLETE (includes waiting for RX windows)
Packet queued
27555403: EV_TXCOMPLETE (includes waiting for RX windows)
Packet queued
27998517: EV_TXCOMPLETE (includes waiting for RX windows)
Packet queued
28441619: EV_TXCOMPLETE (includes waiting for RX windows)
Packet queued
28884656: EV_TXCOMPLETE (includes waiting for RX windows)
Packet queued
29327695: EV_TXCOMPLETE (includes waiting for RX windows)
29327747: EV_LINK_DEAD
OP_TXRXPEND, not sending
29804269: EV_REJOIN_FAILED
5

This is my endpoint code:

#include <lmic.h>
#include <hal/hal.h>
#include <SPI.h>

// LoRaWAN NwkSKey, network session key
// This is the default Semtech key, which is used by the early prototype TTN
// network.
static const PROGMEM u1_t NWKSKEY[16] = {0xf1,0xd5,0x26,0xca,0xab,0x26,0x2b,0x66,0x19,0x0a,0x3f,0xc4,0xf9,0x64,0x85,0xf6};
static const u1_t PROGMEM APPSKEY[16] = {0xf1,0xd5,0x26,0xca,0xab,0x26,0x2b,0x66,0x19,0x0a,0x3f,0xc4,0xf9,0x64,0x85,0xf6};
static const u4_t DEVADDR = 0x07aa69a1 ; // <-- Change this address for every node!

// These callbacks are only used in over-the-air activation, so they are
// left empty here (we cannot leave them out completely unless
// DISABLE_JOIN is set in config.h, otherwise the linker will complain).
void os_getArtEui (u1_t* buf) { }
void os_getDevEui (u1_t* buf) { }
void os_getDevKey (u1_t* buf) { }

static uint8_t mydata[] = "Hello, world!";
static osjob_t sendjob;

// Schedule TX every this many seconds (might become longer due to duty
// cycle limitations).
const unsigned TX_INTERVAL = 5;

// Pin mapping
const lmic_pinmap lmic_pins = {
    .nss = 10,
    .rxtx = LMIC_UNUSED_PIN,
    .rst = LMIC_UNUSED_PIN,
    .dio = {2, 3, 4},
};

void onEvent (ev_t ev) {
    Serial.print(os_getTime());
    Serial.print(": ");
    switch(ev) {
        case EV_SCAN_TIMEOUT:
            Serial.println(F("EV_SCAN_TIMEOUT"));
            break;
        case EV_BEACON_FOUND:
            Serial.println(F("EV_BEACON_FOUND"));
            break;
        case EV_BEACON_MISSED:
            Serial.println(F("EV_BEACON_MISSED"));
            break;
        case EV_BEACON_TRACKED:
            Serial.println(F("EV_BEACON_TRACKED"));
            break;
        case EV_JOINING:
            Serial.println(F("EV_JOINING"));
            break;
        case EV_JOINED:
            Serial.println(F("EV_JOINED"));
            break;
        case EV_RFU1:
            Serial.println(F("EV_RFU1"));
            break;
        case EV_JOIN_FAILED:
            Serial.println(F("EV_JOIN_FAILED"));
            break;
        case EV_REJOIN_FAILED:
            Serial.println(F("EV_REJOIN_FAILED"));
            break;
        case EV_TXCOMPLETE:
            Serial.println(F("EV_TXCOMPLETE (includes waiting for RX windows)"));
            if (LMIC.txrxFlags & TXRX_ACK)
              Serial.println(F("Received ack"));
            if (LMIC.dataLen) {
              Serial.println(F("Received "));
              Serial.println(LMIC.dataLen);
              Serial.println(F(" bytes of payload"));
            }
            // Schedule next transmission
            os_setTimedCallback(&sendjob, os_getTime()+sec2osticks(TX_INTERVAL), do_send);
            break;
        case EV_LOST_TSYNC:
            Serial.println(F("EV_LOST_TSYNC"));
            break;
        case EV_RESET:
            Serial.println(F("EV_RESET"));
            break;
        case EV_RXCOMPLETE:
            // data received in ping slot
            Serial.println(F("EV_RXCOMPLETE"));
            break;
        case EV_LINK_DEAD:
            Serial.println(F("EV_LINK_DEAD"));
            break;
        case EV_LINK_ALIVE:
            Serial.println(F("EV_LINK_ALIVE"));
            break;
         default:
            Serial.println(F("Unknown event"));
            break;
    }
}

void do_send(osjob_t* j){
    // Check if there is not a current TX/RX job running
    if (LMIC.opmode & OP_TXRXPEND) {
        Serial.println(F("OP_TXRXPEND, not sending"));
    } else {
        // Prepare upstream data transmission at the next possible time.
        LMIC_setTxData2(1, mydata, sizeof(mydata)-1, 0);
        Serial.println(F("Packet queued"));
    }
    // Next TX is scheduled after TX_COMPLETE event.
}

void setup() {
    Serial.begin(115200);
    Serial.println(F("Starting"));
    #ifdef VCC_ENABLE
    // For Pinoccio Scout boards
    pinMode(VCC_ENABLE, OUTPUT);
    digitalWrite(VCC_ENABLE, HIGH);
    delay(1000);
    #endif
    // LMIC init
    os_init();
    // Reset the MAC state. Session and pending data transfers will be discarded.
    LMIC_reset();
    // Set static session parameters. Instead of dynamically establishing a session
    // by joining the network, precomputed session parameters are be provided.
    #ifdef PROGMEM
    // On AVR, these values are stored in flash and only copied to RAM
    // once. Copy them to a temporary buffer here, LMIC_setSession will
    // copy them into a buffer of its own again.
    uint8_t appskey[sizeof(APPSKEY)];
    uint8_t nwkskey[sizeof(NWKSKEY)];
    memcpy_P(appskey, APPSKEY, sizeof(APPSKEY));
    memcpy_P(nwkskey, NWKSKEY, sizeof(NWKSKEY));
    LMIC_setSession (0x1, DEVADDR, nwkskey, appskey);
    #else
    // If not running an AVR with PROGMEM, just use the arrays directly
    LMIC_setSession (0x1, DEVADDR, NWKSKEY, APPSKEY);
    #endif
    LMIC_selectSubBand(1);
    // Disable link check validation
    LMIC_setLinkCheckMode(0);
    // TTN uses SF9 for its RX2 window.
    LMIC.dn2Dr = DR_SF9;
    // Set data rate and transmit power for uplink (note: txpow seems to be ignored by the library)
    LMIC_setDrTxpow(DR_SF7,14);
    // Start job
    do_send(&sendjob);
}

void loop() {
    os_runloop_once();
}
6

Application config on LoRa Server:

04%20PM
Screen Shot 2018-04-01 at 4.43.04 PM.jpg2688×1780 484 KB

7

@brocaar while reading this issue I solved a part of my problem disabling the counter validation. Now, I am seeing only one message (uplink and downlink) and then I stop to see any other packets.

8

This sounds more like an issue related to out-of-sync frame-counters. Note that for security reasons, the frame-counter must always increment and for this reason LoRa Server rejects “replayed” frame-counters. A device resetting its counter values because a power-cycle will also be seen as a “replayed” frame-counter. See also: https://forum.loraserver.io/search?q=invalid%20fcnt.