User message callback when multiple downlinks are queued.

[dbowerman]

Hi,

I'm using ttn-esp32 with Chirpstack V4. (I know it's for TTN, but it works perfectly with Chirpstack apart from one issue).

It seems that when there are multiple downlinks queued in chirpstack and delivered in quick succession, the user on_message_callback gets invoked incorrectly for the second one.

There are three examples below, Uplink with No Downlink, Uplink with 1 Downlink Message, and Uplink with 2 queued Downlink messages. In the Third scenario, the call back is not called until the subsequent uplink by which time the actual message data is invalid.

Is this a bug? or am i doing something wrong.

Cheers

// Uplink with no downlink - works fine

I (252862) ttn: event EV_TXSTART
16077284: TXMODE, freq=917800000, len=17, SF=7, BW=125, CR=4/5, IH=0
I (253892) ttn: event EV_RXSTART
start single rx: now-rxtime: 9
16142660: RXMODE_SINGLE, freq=926300000, SF=7, BW=500, CR=4/5, IH=0
rxtimeout: entry: 16143369 rxtime: 16142634 entry-rxtime: 735 now-entry: 10 rxtime-txend: 62126
I (254892) ttn: event EV_RXSTART
start single rx: now-rxtime: 9
16204906: RXMODE_SINGLE, freq=923300000, SF=12, BW=500, CR=4/5, IH=0
rxtimeout: entry: 16209506 rxtime: 16204884 entry-rxtime: 4622 now-entry: 11 rxtime-txend: 124376
I (254972) ttn: event EV_TXCOMPLETE
16209637: engineUpdate, opmode=0x900

// Uplink with 1 queued downlink - works fine

20357106: engineUpdate, opmode=0x908
I (321342) ttn: event EV_TXSTART
20357284: TXMODE, freq=918000000, len=17, SF=7, BW=125, CR=4/5, IH=0
I (322372) ttn: event EV_RXSTART
start single rx: now-rxtime: 8
20422658: RXMODE_SINGLE, freq=926900000, SF=7, BW=500, CR=4/5, IH=0
20423891: Received downlink, window=RX1, port=1, ack=0, txrxFlags=0x11
I (322402) ttn: event EV_TXCOMPLETE
20423928: engineUpdate, opmode=0x900
I (322412) IO: Set Relay 1 to 1 <<<----- THE USER CALLBACK FOR THE DOWNLINK

// Uplink with 2 queued downlinks - 1st downlink fine, 2nd downlink recieved by LMIC but not user callback

22431481: engineUpdate, opmode=0x908
I (354532) ttn: event EV_TXSTART
22431656: TXMODE, freq=916800000, len=17, SF=7, BW=125, CR=4/5, IH=0
I (355562) ttn: event EV_RXSTART
start single rx: now-rxtime: 9
22497030: RXMODE_SINGLE, freq=923300000, SF=7, BW=500, CR=4/5, IH=0
22498264: Received downlink, window=RX1, port=1, ack=0, txrxFlags=0x11
I (355592) ttn: event EV_TXCOMPLETE
22498300: engineUpdate, opmode=0x910
I (355602) IO: Set Relay 1 to 0 <<<----- THE USER CALLBACK FOR THE 1ST DOWNLINK
22528914: engineUpdate, opmode=0x110
I (356082) ttn: event EV_TXSTART
22529046: TXMODE, freq=917400000, len=12, SF=7, BW=125, CR=4/5, IH=0
I (357112) ttn: event EV_RXSTART
start single rx: now-rxtime: 8
22593779: RXMODE_SINGLE, freq=925100000, SF=7, BW=500, CR=4/5, IH=0
22595011: Received downlink, window=RX1, port=1, ack=0, txrxFlags=0x11
I (357142) ttn: event EV_TXCOMPLETE <<< ----- USER CALLBACK IS MISSING FOR THE 2ND DOWNLINK
22595048: engineUpdate, opmode=0x900

// The following Uplink

23435856: engineUpdate, opmode=0x908
I (370602) ttn: event EV_TXSTART
23436016: TXMODE, freq=917600000, len=17, SF=7, BW=125, CR=4/5, IH=0
E (370602) LORAWAN: Received unknown message type (0) <<<- THE MISSING USER CALLBACK and the original data is gone
I (371632) ttn: event EV_RXSTART
start single rx: now-rxtime: 9
23501391: RXMODE_SINGLE, freq=925700000, SF=7, BW=500, CR=4/5, IH=0
rxtimeout: entry: 23502100 rxtime: 23501365 entry-rxtime: 735 now-entry: 10 rxtime-txend: 62126
I (372632) ttn: event EV_RXSTART
start single rx: now-rxtime: 8
23563637: RXMODE_SINGLE, freq=923300000, SF=12, BW=500, CR=4/5, IH=0
rxtimeout: entry: 23568237 rxtime: 23563615 entry-rxtime: 4622 now-entry: 10 rxtime-txend: 124376
I (372712) ttn: event EV_TXCOMPLETE
23568362: engineUpdate, opmode=0x900