Timing issue on Teensy++ 2.0 is preventing EV_TXCOMPLETE from being issued

[dolfandringa]

Describe your question or issue A timing issue is causing EV_TXCOMPLETE only to get issued if I add a few debug print statements. I am using the LMIC library with abp. I can consistently reproduce this issue with the teensy++ 2.0. I am using these compile flags:

-DLMIC_USE_INTERRUPTS -DCFG_sx1276_radio -DCFG_us915 -DARDUINO_LMIC_PROJECT_CONFIG_H_SUPPRESS -DDISABLE_INVERT_IQ_ON_RX -DDISABLE_PING -DDISABLE_BEACONS -DLMIC_PRINTF_TO=Serial1 -DLMIC_DEBUG_LEVEL=0

I have modified lmic.h slightly so LMIC_DEBUG_PRINTF is also available with LMIC_DEBUG_LEVEL=0 (using #ifdef LMIC_DEBUG_LEVEL instead of #if LMIC_DEBUG_LEVEL > 0). This allows me to add a few debug print statements manually.

With the standard abp sample, but using only a single channel through

for (int c = 0; c < 72; c++){
      LMIC_disableChannel(c);
    }
    LMIC_enableChannel(14);

the EV_TXSTART event gets issued consistently, but the EV_TXCOMPLETE event never happens. The gateway does receive the packet, so it is sent correctly. And checking the DIO0 and DIO1 pins with my oscilloscope, they do go high. The IRQ's are also detected correctly (saw with a few debug statements), but somehow there is a timing issue once the IRQ happens, that prevents EV_TXCOMPLETE from being triggered.

If I add 2 LMIC_DEBUG_PRINTF statements, EV_TXCOMPLETE gets issued just fine. So I am guessing there is a timing issue which causes the timing of os_setTimedCallback to be wrong?

Without additional debug statements, execution halts after updataDone like this:

7595: EV_TXSTART
Packet queued
11500: updataDone

But when adding debug print statements in setupRx1 and setupRx2DnData, EV_TXCOMPLETE gets issued normally like this:

7651: EV_TXSTART
Packet queued
11619: updataDone
setupRx1: setting LMIC.osjob.func to Rx1 cb func
setupRx2DnData: setting LMIC.osjob.func to processRx2DnData
137864: EV_TXCOMPLETE (includes waiting for RX windows)

I am guessing there is an issue with calculating the sec2osticks time? I do see the OSTICKS_PER_SEC, but don't know how an "ostick" is defined. The teensy++ 2.0 uses a 16MHz AT90USB1286, which I run at 3.3V.

Environment

• Version of LMIC being used: 3.1.0
• Version of Arduino IDE being used: platformio 4.2.1 with teensyduino 1.8.5
• Network provider local Chirpstack with Congduc Pham's Low Cost LoRa Gateway
• Region (EU868, US915, etc.) US915
• Board (MCCI Catena, Adafruit Feather M0, Heltec Wi-Fi LoRa 32 v2, etc.) Teensy++ 2.0 with AT90USB1286 16Mhz MCU at 3.3V
• Radio (HopeRF, SX1276, etc.) RFM96W

[altishchenko]

@dolfandringa Dolf, are you using a closed loop in your code? Like this or a similar approach:

while (1) {
    os_runloop_once();
   /* do something */
}

If yes, can you try for me please disabling your DEBUG logs back to original and inserting a small delay() call in the loop? Like this:

while (1) {
    os_runloop_once();
    /* do something */
   delay(5);
}

Let me know of the results please.

[dolfandringa]

I am using the standard arduino loop() function and have indeed os_runloop_once in there. I will add a delay in there to see if it help and let you know.

[dolfandringa]

@altishchenko That indeed worked! I guess the os_runloop_once is called again before the timed handler was set properly or something? Weird, but it works! Thanks.