Device sends ConfirmedUp but no UnconfirmedDown is initiated

mitarbeiter · January 6, 2021, 4:00pm

Hello,

a Dragino LSN50v2 device using ABP auth and QoS1 / CFM tried to send a frame but did not get a confirmation.
This was an exception, as the following frame was properly confirmed.
How is that possible? How can I prevent that?

Here are the device logs. It tried 8 times, as usual for this device:

LSN50 Device
Image Version: v1.7
LoRaWan Stack: DR-LWS-005
Frequency Band: EU868
DevEui= 12 34 56 78 90 12 34 56
JOINED

Please use AT+DEBUG to see debug info

***** UpLinkCounter= 0 *****
TX on freq 868.500 MHz at DR 0
txDone
RX on freq 868.500 MHz at DR 0
rxTimeOut
RX on freq 869.525 MHz at DR 3
rxTimeOut

***** UpLinkCounter= 0 *****
TX on freq 868.100 MHz at DR 0
txDone
RX on freq 868.100 MHz at DR 0
rxTimeOut
RX on freq 869.525 MHz at DR 3
rxTimeOut

***** UpLinkCounter= 0 *****
TX on freq 868.500 MHz at DR 0
txDone
RX on freq 868.500 MHz at DR 0
rxTimeOut
RX on freq 869.525 MHz at DR 3
rxTimeOut

***** UpLinkCounter= 0 *****
TX on freq 868.300 MHz at DR 0
txDone
RX on freq 868.300 MHz at DR 0
rxTimeOut
RX on freq 869.525 MHz at DR 3
rxTimeOut

***** UpLinkCounter= 0 *****
TX on freq 868.300 MHz at DR 0
txDone
RX on freq 868.300 MHz at DR 0
rxTimeOut
RX on freq 869.525 MHz at DR 3
rxTimeOut

***** UpLinkCounter= 0 *****
TX on freq 868.300 MHz at DR 0
txDone
RX on freq 868.300 MHz at DR 0
rxTimeOut
RX on freq 869.525 MHz at DR 3
rxTimeOut

***** UpLinkCounter= 0 *****
TX on freq 868.300 MHz at DR 0
txDone
RX on freq 868.300 MHz at DR 0
rxTimeOut
RX on freq 869.525 MHz at DR 3
rxTimeOut

***** UpLinkCounter= 0 *****
TX on freq 868.300 MHz at DR 0
txDone
RX on freq 868.300 MHz at DR 0
rxTimeOut
RX on freq 869.525 MHz at DR 3
rxTimeOut

The corresponding ChirpStack frame log:

[
    {
        "uplinkMetaData": {
            "rxInfo": [
                {
                    "gatewayID": "MjUxMhQARgA=",
                    "time": "2021-01-04T13:13:35.262344Z",
                    "timeSinceGPSEpoch": null,
                    "rssi": -48,
                    "loRaSNR": 10.75,
                    "channel": 1,
                    "rfChain": 1,
                    "board": 0,
                    "antenna": 0,
                    "location": {
                        "latitude": 0,
                        "longitude": 0,
                        "altitude": 0,
                        "source": "UNKNOWN",
                        "accuracy": 0
                    },
                    "fineTimestampType": "NONE",
                    "context": "/OHL5Q==",
                    "uplinkID": "Dtii2DTURtSe4dgy7gnRWA==",
                    "crcStatus": "CRC_OK"
                }
            ],
            "txInfo": {
                "frequency": 868300000,
                "modulation": "LORA",
                "loRaModulationInfo": {
                    "bandwidth": 125,
                    "spreadingFactor": 12,
                    "codeRate": "4/5",
                    "polarizationInversion": false
                }
            }
        },
        "phyPayload": {
            "mhdr": {
                "mType": "ConfirmedDataUp",
                "major": "LoRaWANR1"
            },
            "macPayload": {
                "fhdr": {
                    "devAddr": "01821d8d",
                    "fCtrl": {
                        "adr": true,
                        "adrAckReq": false,
                        "ack": false,
                        "fPending": false,
                        "classB": false
                    },
                    "fCnt": 0,
                    "fOpts": null
                },
                "fPort": 2,
                "frmPayload": [
                    {
                        "bytes": "Lm0aI9IDshmWOmQ="
                    }
                ]
            },
            "mic": "9b9b387a"
        }
    },
    {
        "uplinkMetaData": {
            "rxInfo": [
                {
                    "gatewayID": "MjUxMhQARgA=",
                    "time": "2021-01-04T13:13:29.255855Z",
                    "timeSinceGPSEpoch": null,
                    "rssi": -48,
                    "loRaSNR": 10.75,
                    "channel": 1,
                    "rfChain": 1,
                    "board": 0,
                    "antenna": 0,
                    "location": {
                        "latitude": 0,
                        "longitude": 0,
                        "altitude": 0,
                        "source": "UNKNOWN",
                        "accuracy": 0
                    },
                    "fineTimestampType": "NONE",
                    "context": "/IYnDQ==",
                    "uplinkID": "/A1Svm3ZTKGkr8odmh9rIw==",
                    "crcStatus": "CRC_OK"
                }
            ],
            "txInfo": {
                "frequency": 868300000,
                "modulation": "LORA",
                "loRaModulationInfo": {
                    "bandwidth": 125,
                    "spreadingFactor": 12,
                    "codeRate": "4/5",
                    "polarizationInversion": false
                }
            }
        },
        "phyPayload": {
            "mhdr": {
                "mType": "ConfirmedDataUp",
                "major": "LoRaWANR1"
            },
            "macPayload": {
                "fhdr": {
                    "devAddr": "01821d8d",
                    "fCtrl": {
                        "adr": true,
                        "adrAckReq": false,
                        "ack": false,
                        "fPending": false,
                        "classB": false
                    },
                    "fCnt": 0,
                    "fOpts": null
                },
                "fPort": 2,
                "frmPayload": [
                    {
                        "bytes": "Lm0aI9IDshmWOmQ="
                    }
                ]
            },
            "mic": "9b9b387a"
        }
    },
    {
        "uplinkMetaData": {
            "rxInfo": [
                {
                    "gatewayID": "MjUxMhQARgA=",
                    "time": "2021-01-04T13:13:24.250648Z",
                    "timeSinceGPSEpoch": null,
                    "rssi": -49,
                    "loRaSNR": 12.5,
                    "channel": 1,
                    "rfChain": 1,
                    "board": 0,
                    "antenna": 0,
                    "location": {
                        "latitude": 0,
                        "longitude": 0,
                        "altitude": 0,
                        "source": "UNKNOWN",
                        "accuracy": 0
                    },
                    "fineTimestampType": "NONE",
                    "context": "/DnGHQ==",
                    "uplinkID": "Utm+i028SHG5I68Qisn+IA==",
                    "crcStatus": "CRC_OK"
                }
            ],
            "txInfo": {
                "frequency": 868300000,
                "modulation": "LORA",
                "loRaModulationInfo": {
                    "bandwidth": 125,
                    "spreadingFactor": 12,
                    "codeRate": "4/5",
                    "polarizationInversion": false
                }
            }
        },
        "phyPayload": {
            "mhdr": {
                "mType": "ConfirmedDataUp",
                "major": "LoRaWANR1"
            },
            "macPayload": {
                "fhdr": {
                    "devAddr": "01821d8d",
                    "fCtrl": {
                        "adr": true,
                        "adrAckReq": false,
                        "ack": false,
                        "fPending": false,
                        "classB": false
                    },
                    "fCnt": 0,
                    "fOpts": null
                },
                "fPort": 2,
                "frmPayload": [
                    {
                        "bytes": "Lm0aI9IDshmWOmQ="
                    }
                ]
            },
            "mic": "9b9b387a"
        }
    },
    {
        "uplinkMetaData": {
            "rxInfo": [
                {
                    "gatewayID": "MjUxMhQARgA=",
                    "time": "2021-01-04T13:13:18.244903Z",
                    "timeSinceGPSEpoch": null,
                    "rssi": -49,
                    "loRaSNR": 9.75,
                    "channel": 1,
                    "rfChain": 1,
                    "board": 0,
                    "antenna": 0,
                    "location": {
                        "latitude": 0,
                        "longitude": 0,
                        "altitude": 0,
                        "source": "UNKNOWN",
                        "accuracy": 0
                    },
                    "fineTimestampType": "NONE",
                    "context": "+94iHQ==",
                    "uplinkID": "cH1BInwwQkqJNc26YPnj9w==",
                    "crcStatus": "CRC_OK"
                }
            ],
            "txInfo": {
                "frequency": 868300000,
                "modulation": "LORA",
                "loRaModulationInfo": {
                    "bandwidth": 125,
                    "spreadingFactor": 12,
                    "codeRate": "4/5",
                    "polarizationInversion": false
                }
            }
        },
        "phyPayload": {
            "mhdr": {
                "mType": "ConfirmedDataUp",
                "major": "LoRaWANR1"
            },
            "macPayload": {
                "fhdr": {
                    "devAddr": "01821d8d",
                    "fCtrl": {
                        "adr": true,
                        "adrAckReq": false,
                        "ack": false,
                        "fPending": false,
                        "classB": false
                    },
                    "fCnt": 0,
                    "fOpts": null
                },
                "fPort": 2,
                "frmPayload": [
                    {
                        "bytes": "Lm0aI9IDshmWOmQ="
                    }
                ]
            },
            "mic": "9b9b387a"
        }
    },
    {
        "uplinkMetaData": {
            "rxInfo": [
                {
                    "gatewayID": "MjUxMhQARgA=",
                    "time": "2021-01-04T13:13:13.239048Z",
                    "timeSinceGPSEpoch": null,
                    "rssi": -48,
                    "loRaSNR": 11.75,
                    "channel": 1,
                    "rfChain": 1,
                    "board": 0,
                    "antenna": 0,
                    "location": {
                        "latitude": 0,
                        "longitude": 0,
                        "altitude": 0,
                        "source": "UNKNOWN",
                        "accuracy": 0
                    },
                    "fineTimestampType": "NONE",
                    "context": "+5HBBQ==",
                    "uplinkID": "Zyg+GubURe2cKsiw3KzQyg==",
                    "crcStatus": "CRC_OK"
                }
            ],
            "txInfo": {
                "frequency": 868300000,
                "modulation": "LORA",
                "loRaModulationInfo": {
                    "bandwidth": 125,
                    "spreadingFactor": 12,
                    "codeRate": "4/5",
                    "polarizationInversion": false
                }
            }
        },
        "phyPayload": {
            "mhdr": {
                "mType": "ConfirmedDataUp",
                "major": "LoRaWANR1"
            },
            "macPayload": {
                "fhdr": {
                    "devAddr": "01821d8d",
                    "fCtrl": {
                        "adr": true,
                        "adrAckReq": false,
                        "ack": false,
                        "fPending": false,
                        "classB": false
                    },
                    "fCnt": 0,
                    "fOpts": null
                },
                "fPort": 2,
                "frmPayload": [
                    {
                        "bytes": "Lm0aI9IDshmWOmQ="
                    }
                ]
            },
            "mic": "9b9b387a"
        }
    },
    {
        "uplinkMetaData": {
            "rxInfo": [
                {
                    "gatewayID": "MjUxMhQARgA=",
                    "time": "2021-01-04T13:13:08.233605Z",
                    "timeSinceGPSEpoch": null,
                    "rssi": -48,
                    "loRaSNR": 9,
                    "channel": 2,
                    "rfChain": 1,
                    "board": 0,
                    "antenna": 0,
                    "location": {
                        "latitude": 0,
                        "longitude": 0,
                        "altitude": 0,
                        "source": "UNKNOWN",
                        "accuracy": 0
                    },
                    "fineTimestampType": "NONE",
                    "context": "+0VgFQ==",
                    "uplinkID": "FJxclmi9Rw+7bOQsUY+i8A==",
                    "crcStatus": "CRC_OK"
                }
            ],
            "txInfo": {
                "frequency": 868500000,
                "modulation": "LORA",
                "loRaModulationInfo": {
                    "bandwidth": 125,
                    "spreadingFactor": 12,
                    "codeRate": "4/5",
                    "polarizationInversion": false
                }
            }
        },
        "phyPayload": {
            "mhdr": {
                "mType": "ConfirmedDataUp",
                "major": "LoRaWANR1"
            },
            "macPayload": {
                "fhdr": {
                    "devAddr": "01821d8d",
                    "fCtrl": {
                        "adr": true,
                        "adrAckReq": false,
                        "ack": false,
                        "fPending": false,
                        "classB": false
                    },
                    "fCnt": 0,
                    "fOpts": null
                },
                "fPort": 2,
                "frmPayload": [
                    {
                        "bytes": "Lm0aI9IDshmWOmQ="
                    }
                ]
            },
            "mic": "9b9b387a"
        }
    },
    {
        "uplinkMetaData": {
            "rxInfo": [
                {
                    "gatewayID": "MTUyNSoAKwA=",
                    "time": "2021-01-04T13:13:18.183500Z",
                    "timeSinceGPSEpoch": null,
                    "rssi": -117,
                    "loRaSNR": -17.75,
                    "channel": 0,
                    "rfChain": 1,
                    "board": 0,
                    "antenna": 0,
                    "location": {
                        "latitude": 0,
                        "longitude": 0,
                        "altitude": 0,
                        "source": "UNKNOWN",
                        "accuracy": 0
                    },
                    "fineTimestampType": "NONE",
                    "context": "5C/A9A==",
                    "uplinkID": "4kKYWKWTSJ+0qzhGYWdkNQ==",
                    "crcStatus": "CRC_OK"
                },
                {
                    "gatewayID": "MjUxMhQARgA=",
                    "time": "2021-01-04T13:13:03.228844Z",
                    "timeSinceGPSEpoch": null,
                    "rssi": -49,
                    "loRaSNR": 10.75,
                    "channel": 0,
                    "rfChain": 1,
                    "board": 0,
                    "antenna": 0,
                    "location": {
                        "latitude": 0,
                        "longitude": 0,
                        "altitude": 0,
                        "source": "UNKNOWN",
                        "accuracy": 0
                    },
                    "fineTimestampType": "NONE",
                    "context": "+vj/ZQ==",
                    "uplinkID": "czCJdteKRti37FgiZOX9Lw==",
                    "crcStatus": "CRC_OK"
                }
            ],
            "txInfo": {
                "frequency": 868100000,
                "modulation": "LORA",
                "loRaModulationInfo": {
                    "bandwidth": 125,
                    "spreadingFactor": 12,
                    "codeRate": "4/5",
                    "polarizationInversion": false
                }
            }
        },
        "phyPayload": {
            "mhdr": {
                "mType": "ConfirmedDataUp",
                "major": "LoRaWANR1"
            },
            "macPayload": {
                "fhdr": {
                    "devAddr": "01821d8d",
                    "fCtrl": {
                        "adr": true,
                        "adrAckReq": false,
                        "ack": false,
                        "fPending": false,
                        "classB": false
                    },
                    "fCnt": 0,
                    "fOpts": null
                },
                "fPort": 2,
                "frmPayload": [
                    {
                        "bytes": "Lm0aI9IDshmWOmQ="
                    }
                ]
            },
            "mic": "9b9b387a"
        }
    },
    {
        "uplinkMetaData": {
            "rxInfo": [
                {
                    "gatewayID": "MjUxMhQARgA=",
                    "time": "2021-01-04T13:12:57.223488Z",
                    "timeSinceGPSEpoch": null,
                    "rssi": -49,
                    "loRaSNR": 8,
                    "channel": 2,
                    "rfChain": 1,
                    "board": 0,
                    "antenna": 0,
                    "location": {
                        "latitude": 0,
                        "longitude": 0,
                        "altitude": 0,
                        "source": "UNKNOWN",
                        "accuracy": 0
                    },
                    "fineTimestampType": "NONE",
                    "context": "+p1fPQ==",
                    "uplinkID": "BHCiKYz2RhOjW8ZEtCXWrQ==",
                    "crcStatus": "CRC_OK"
                }
            ],
            "txInfo": {
                "frequency": 868500000,
                "modulation": "LORA",
                "loRaModulationInfo": {
                    "bandwidth": 125,
                    "spreadingFactor": 12,
                    "codeRate": "4/5",
                    "polarizationInversion": false
                }
            }
        },
        "phyPayload": {
            "mhdr": {
                "mType": "ConfirmedDataUp",
                "major": "LoRaWANR1"
            },
            "macPayload": {
                "fhdr": {
                    "devAddr": "01821d8d",
                    "fCtrl": {
                        "adr": true,
                        "adrAckReq": false,
                        "ack": false,
                        "fPending": false,
                        "classB": false
                    },
                    "fCnt": 0,
                    "fOpts": null
                },
                "fPort": 2,
                "frmPayload": [
                    {
                        "bytes": "Lm0aI9IDshmWOmQ="
                    }
                ]
            },
            "mic": "9b9b387a"
        }
    }
]

As mentioned, the next frame was properly confirmed:

***** UpLinkCounter= 1 *****
TX on freq 868.300 MHz at DR 0
txDone
RX on freq 868.300 MHz at DR 0
rxDone(ACK)
Rssi= -54

ChirpStack Frames:

[
    {
        "downlinkMetaData": {
            "gatewayID": "3235313214004600",
            "txInfo": {
                "frequency": 868300000,
                "power": 14,
                "modulation": "LORA",
                "loRaModulationInfo": {
                    "bandwidth": 125,
                    "spreadingFactor": 12,
                    "codeRate": "4/5",
                    "polarizationInversion": true
                },
                "board": 0,
                "antenna": 0,
                "timing": "DELAY",
                "delayTimingInfo": {
                    "delay": "1s"
                },
                "context": "ALBbTQ=="
            }
        },
        "phyPayload": {
            "mhdr": {
                "mType": "UnconfirmedDataDown",
                "major": "LoRaWANR1"
            },
            "macPayload": {
                "fhdr": {
                    "devAddr": "01821d8d",
                    "fCtrl": {
                        "adr": true,
                        "adrAckReq": false,
                        "ack": true,
                        "fPending": false,
                        "classB": false
                    },
                    "fCnt": 691,
                    "fOpts": null
                },
                "fPort": null,
                "frmPayload": null
            },
            "mic": "4f446ed0"
        }
    },
    {
        "uplinkMetaData": {
            "rxInfo": [
                {
                    "gatewayID": "MjUxMhQARgA=",
                    "time": "2021-01-04T13:14:39.130628Z",
                    "timeSinceGPSEpoch": null,
                    "rssi": -43,
                    "loRaSNR": 9,
                    "channel": 1,
                    "rfChain": 1,
                    "board": 0,
                    "antenna": 0,
                    "location": {
                        "latitude": 0,
                        "longitude": 0,
                        "altitude": 0,
                        "source": "UNKNOWN",
                        "accuracy": 0
                    },
                    "fineTimestampType": "NONE",
                    "context": "ALBbTQ==",
                    "uplinkID": "hpHUDxV7Qfe3ialuhKSrxQ==",
                    "crcStatus": "CRC_OK"
                }
            ],
            "txInfo": {
                "frequency": 868300000,
                "modulation": "LORA",
                "loRaModulationInfo": {
                    "bandwidth": 125,
                    "spreadingFactor": 12,
                    "codeRate": "4/5",
                    "polarizationInversion": false
                }
            }
        },
        "phyPayload": {
            "mhdr": {
                "mType": "ConfirmedDataUp",
                "major": "LoRaWANR1"
            },
            "macPayload": {
                "fhdr": {
                    "devAddr": "01821d8d",
                    "fCtrl": {
                        "adr": true,
                        "adrAckReq": false,
                        "ack": false,
                        "fPending": false,
                        "classB": false
                    },
                    "fCnt": 1,
                    "fOpts": null
                },
                "fPort": 2,
                "frmPayload": [
                    {
                        "bytes": "hNrPhBWGjHasU84="
                    }
                ]
            },
            "mic": "c7f1e57c"
        }
    }
]

pulidoj · January 6, 2021, 7:03pm

Hello @mitarbeiter,

One question about this, does it happen only UpLinkCounter= 0 with you reset the device in or happens also later?

Regards.

mitarbeiter · January 7, 2021, 3:20pm

Thank you for the reply.

As I do not understand the cause of this misbehavior, I could not yet reproduce it. It happens sometimes, independent of the frame counter.

A good explanation would be the LoRa duty cycle. But since the next Frame was confirmed properly a few seconds after, I think we can safely assume that is not it.

Meh · February 6, 2021, 9:47pm

Hello.
It looks like we have the same issue with OTAA devices.

Versions:
Bridge: 3.10.0
Network: 3.12.0
Application: 3.14.0

End-device sends ConfirmedDataUp messages, but Chirpstack does not send UnconfirmedDataDown for all of them. It can lose from 1 up to 10 messages in a row.

Here is the last Downlink:
2021-02-06_23-43-14

Here is the last Uplink (confirmed):
2021-02-06_23-44-45

Here is the previous Uplink (unconfirmed):
2021-02-06_23-45-22

When we switch GW to another LoRaWAN Network Server, we can see all Uplinks has their Downlinks accordingly.
Please help to improve this.

Log files does not give any errors about this situations.

brocaar · February 12, 2021, 4:45pm

Please note that ChirpStack will log the transmission of the downlink when it has been acknowledged by the gateway for transmission. It is possible that ChirpStack did send it to the gateway, but that the gateway dropped it. You can confirm this by subscribing to the gateway MQTT data. If the gateway returned an error, then you can find this in the device data tab.

Meh · February 16, 2021, 7:07pm

After connection to MQTT with mosquitto_sub -t “gateway/00000cae7d234567/event/ack” -v I can see

gateway/00000cae7d234567/event/ack {"gatewayID":"AAAMrn0rBeA=","token":61758,"error":"","downlinkID":"8T4yG00uSf+5Xuee3N1mtw==","items":[{"status":"OK"},{"status":"IGNORED"}]}
gateway/00000cae7d234567/event/ack {"gatewayID":"AAAMrn0rBeA=","token":38870,"error":"","downlinkID":"l9ZS84BQQLq1RmPbRCjfUQ==","items":[{"status":"OK"},{"status":"IGNORED"}]}
gateway/00000cae7d234567/event/ack {"gatewayID":"AAAMrn0rBeA=","token":15268,"error":"","downlinkID":"O6QME8BoT2OPhZxow+86yw==","items":[{"status":"COLLISION_PACKET"},{"status":"OK"}]}
gateway/00000cae7d234567/event/ack {"gatewayID":"AAAMrn0rBeA=","token":19330,"error":"","downlinkID":"S4KO0VenRNqYk2+oZKhalg==","items":[{"status":"OK"},{"status":"IGNORED"}]}
gateway/00000cae7d234567/event/ack {"gatewayID":"AAAMrn0rBeA=","token":26920,"error":"","downlinkID":"aSgBKCNQSPW7Ah8qe/K+4Q==","items":[{"status":"OK"},{"status":"IGNORED"}]}
gateway/00000cae7d234567/event/ack {"gatewayID":"AAAMrn0rBeA=","token":38936,"error":"","downlinkID":"mBgmBts5Rhy8YctQTkTlvQ==","items":[{"status":"COLLISION_PACKET"},{"status":"OK"}]}
gateway/00000cae7d234567/event/ack {"gatewayID":"AAAMrn0rBeA=","token":24735,"error":"status:COLLISION_PACKET ","downlinkID":"YJ+K8AOJSx2h1Lrj5YQTZg==","items":[{"status":"COLLISION_PACKET"},{"status":"COLLISION_PACKET"}]}
gateway/00000cae7d234567/event/ack {"gatewayID":"AAAMrn0rBeA=","token":57505,"error":"status:COLLISION_PACKET ","downlinkID":"4KGT1dZXT9SnGwU+36rovw==","items":[{"status":"COLLISION_PACKET"},{"status":"COLLISION_PACKET"}]}
gateway/00000cae7d234567/event/ack {"gatewayID":"AAAMrn0rBeA=","token":8264,"error":"","downlinkID":"IEjwQWFFSMagqYXKb/fUdg==","items":[{"status":"OK"},{"status":"IGNORED"}]}
gateway/00000cae7d234567/event/ack {"gatewayID":"AAAMrn0rBeA=","token":38198,"error":"","downlinkID":"lTbTpcrLQsyjD1I5b4XEqw==","items":[{"status":"OK"},{"status":"IGNORED"}]}
gateway/00000cae7d234567/event/ack {"gatewayID":"AAAMrn0rBeA=","token":24745,"error":"","downlinkID":"YKmLeXD/RY6FF4D91yJQdA==","items":[{"status":"OK"},{"status":"IGNORED"}]}

Is it possible to lost Unconfirmed Downlinks because of these COLLISION_PACKET events?

brocaar · February 21, 2021, 5:31pm

That is very likely, as the gateway was not able to transmit the downlink.