manuelbl / ttn-esp32

The Things Network device library for ESP32 (ESP-IDF) and SX127x based devices
MIT License
303 stars 64 forks source link

Getting `??ack error ack=1 txCnt=0` messages #11

Closed jcwren closed 4 years ago

jcwren commented 5 years ago

I have several different LoRaWAN stacks running on various devices, such as the ST Micro LRWAN stack, whatever's in the Microchip RN2903, and the LMIC stack. The LMIC stack is running on a Heltec V1 board configured for the US915 band plan. It's talking to the The Things Network server, but the server is sending a downlink message on every uplink, unlike the other stacks. Now I suspect this is a LMIC thing, but I'm starting here, wondering if this has been seen before. It occurs almost every time, although there's the occasional packet that doesn't.

Any ideas what I'm looking at here? As I say the data is showing up decoded in the TTN console, so the DevEUI, App EUI and App Key are all correct.

Bad:

Sending message...
75061095: engineUpdate, opmode=0x808
I (1201387) ttn: event EV_TXSTART
75061120: engineUpdate, opmode=0x888
75061234: TXMODE, freq=904300000, len=19, SF=7, BW=125, CR=4/5, IH=0
75126858: setupRx1 txrxFlags 0x21 --> 01
start single rx: now-rxtime: 6
75126992: RXMODE_SINGLE, freq=924500000, SF=7, BW=500, CR=4/5, IH=0
I (1202447) spi_master: Allocate RX buffer for DMA
75127898: process options (olen=0xa)
75127907: LinkAdrReq: p1:40 chmap:0002 chpage:70 uprt:01 ans:87
75128076: LinkAdrReq: p1:35 chmap:ff00 chpage:00 uprt:01 ans:87
75128429: ??ack error ack=1 txCnt=0
75128629: decodeFrame txrxFlags 0x1 --> 21
75128868: Received downlink, window=RX1, port=-1, ack=1, txrxFlags=0x21
I (1202477) ttn: event EV_TXCOMPLETE
75129530: engineUpdate, opmode=0x800
Message sent.

Good:

Sending message...
77004220: engineUpdate, opmode=0x808
I (1232477) ttn: event EV_TXSTART
77004246: engineUpdate, opmode=0x888
77004359: TXMODE, freq=905100000, len=19, SF=7, BW=125, CR=4/5, IH=0
77069983: setupRx1 txrxFlags 0x21 --> 01
start single rx: now-rxtime: 6
77070117: RXMODE_SINGLE, freq=926900000, SF=7, BW=500, CR=4/5, IH=0
rxtimeout: entry: 77070199 rxtime: 77070107 entry-rxtime: 92 now-entry: 7 rxtime-txend: 62524
77133227: setupRx2 txrxFlags 0x1 --> 02
start single rx: now-rxtime: 6
77133361: RXMODE_SINGLE, freq=923300000, SF=12, BW=500, CR=4/5, IH=0
rxtimeout: entry: 77135924 rxtime: 77133351 entry-rxtime: 2573 now-entry: 6 rxtime-txend: 125768
77135949: processRx2DnData txrxFlags 0x2 --> 00
77183025: processDnData txrxFlags 00 --> 20
I (1235337) ttn: event EV_TXCOMPLETE
77183039: engineUpdate, opmode=0x800
Message sent.
manuelbl commented 5 years ago

You're not the only one to notice. See for example https://www.thethingsnetwork.org/forum/t/the-workbench-part-3/21125/323 (about an hour ago).

My devices get these downlink messages (on port 0, empty payload) as well.

Most likely the real issue is the one described in this thread: https://www.thethingsnetwork.org/forum/t/recent-change-in-adr-handling-in-tnn-and-lmic-generate-downlink-loop/24164

The good news is that the problem seems to have been addressed by the LMIC code this library is based on (MCCI Catena LMIC). I've integrated the latest LMIC code and pushed it to a separate branch: https://github.com/manuelbl/ttn-esp32/tree/lmic-master

I will integrate it into the master branch once an official release is available on https://github.com/mcci-catena/arduino-lmic.

jcwren commented 5 years ago

This seems to be a step backwards, as I can no longer join the network at all. Unless I missed a step...

Using your directory structure, per the Wiki:

cd components/ttn-esp32
git checkout lmic-master
cd ../..
make clean
make
make flash

Doesn't look like the hello-world example changed, so no API differences.

jcwren commented 5 years ago

Ignore that. It took an excessive number of retries, but finally did join. It does seem to join faster on the master branch than on the lmic-master branch, for some reason.