Help with debugging timer expired event lost on irq context

General
#1

I am debugging this piece of code where an irq callback event calls a state machine which starts two timers at different times, on successive interrupts. The second timer is shorter than the first one and will expire before the first one does. I never get that event.
I’ve set debug.level = 4 but I don’t see much:

[Nov 27 17:00:39.711] mgos_init.c:36          Init done, RAM: 309884 total, 276372 free, 276356 min free
[Nov 27 17:00:39.715] mgos_event.c:135        ev MOS0 triggered 0 handlers
[Nov 27 17:00:40.708] mg_net.c:67             0x3ffbb7dc user ev=6 ev_data=0x3ffb4260 flags=0x0 rmbl=0 smbl=0
[Nov 27 17:00:40.714] mg_net.c:89             0x3ffbb7dc after user flags=0x0 rmbl=0 smbl=0
[Nov 27 17:00:40.930] sx1276-board-radio.c:48 DIO0IRQ, state: 1     "<-- GPIO IRQ, got msg"
[Nov 27 17:00:40.933] main.c:133              RxDone
[Nov 27 17:00:40.936] main.c:73               RX: 35, -33, 7
[Nov 27 17:00:40.940] main.c:74               nmt: 0x3ffafe6c        "<-- start 1500ms timer"
[Nov 27 17:00:41.064] sx1276-board-radio.c:48 DIO0IRQ, state: 2     "<-- GPIO IRQ, response sent"
[Nov 27 17:00:41.067] main.c:125              TxDone
[Nov 27 17:00:41.070] main.c:80               sct: 0x3ffafe90        "<-- start 250ms timer"
[Nov 27 17:00:42.441] mg_net.c:67             0x3ffbb7dc user ev=6 ev_data=0x3ffb4260 flags=0x0 rmbl=0 smbl=0
[Nov 27 17:00:42.444] main.c:88               Sync lost             "<-- 1500ms timer expired, 250ms did not"
[Nov 27 17:00:42.450] mg_net.c:89             0x3ffbb7dc after user flags=0x0 rmbl=0 smbl=0

How can I dig deeper and trace what is going on ?
The irq event is setup with mgos_gpio_set_int_handler(); as I understand from the GPIO API doc, I’m not doing funky stuff (but…).
Hard is ESP32 and I’ve already tried setting single core, just in case.

#2

Well,

  1. Yes, gpio irqs using that function are just events, as per the docs
  2. The timer library does not have further debugging
  3. mOS timers are dynamic. When a timer is started, memory is alloc’ed and when it expires/is cleared, it is freed. The timer id returned seems to be the memory address.

In case someone is curious:
Since I don’t normally use dynamic memory allocation, new timers were getting an id coincident with formerly freed timers. The radio driver (ported from static memory architectures) was just in case clearing “his own” timer, which had expired and had been freed, and whose id clashed with the main program timer id (started after expiration but before clear), so clearing it and causing this behavior.