Mono delay never returns (sometimes)

[Erhannis]

RP2040, rtic-monotonics: 2.0.3, rustc 1.86.0-nightly (124cc9219 2025-02-09)

It's hard to say what the problem is, exactly, but there's one delay in my code that sometimes doesn't return. Specifically:

rp2040_timer_monotonic!(Mono);
...
...
info!("TXBG before wait");
Mono::delay(10_u64.micros()).await;
info!("TXBG after wait");

I see the first info, but not the second, and the task never loops again. Thing is, it used to do this, and then for no obvious reason stopped doing it, and now it's doing it again. There's some slim evidence it's related to the idle loop; seems like the delay runs sometimes (successfully) once before the idle task gets going, but once the idle task starts, the next run of that delay fails to complete. Btw, I've tried the idle loop with and without cortex_m::asm::wfi(), I've seen that in some examples and am not sure of when and whether to use it, but it doesn't seem to make a difference for this code. All the tasks (except idle) are priority 1. I've (previously) used Mono::delay in other places in the code with no issue I noticed, so I'm not sure what's special about this one. Are there special conditions I need to observe in order to use Mono::delay? Do I need to register an interrupt? Make sure to have such-and-such a call somewhere else?

[korken89]

Hi, thank for the report!

Do you have an example to look at? Usually if this happen some high priority task is blocking, it's not something like that?

[Finomnis]

wfi is just a low power optimization, it should not effect anything.

Given this issue is silent since over a month, did you manage to find the problem @Erhannis?

[Erhannis]

I haven't yet, sorry; I've just been working on other things. I expect to get back to it eventually, but I don't know when.

[Erhannis]

Ok, it became relevant again, and I spent like 8 hours haltingly trimming out stuff until I had a vaguely minimal example.
https://github.com/Erhannis/delay_freeze_demo
So, I run a loop on core1 while all the RTIC stuff runs on core0 and I use a thingbuf channel to send data from core1 back to an RTIC task on core0. This USUALLY works, but it seems like if a delay finishes and another is started, all while one message is in transit, the new delay never finishes. (Or, it MIGHT never finish - there's a bunch of times I see this happen in the logs without triggering the problem, but the problem always seems to occur under those conditions.) All the times I've read the log, it runs for maybe 30 seconds and then the final pattern I see looks like

[TRACE] Pushing to channel @11616381
[TRACE] ...delay done @11616425
[TRACE] delay...
[INFO ] msg_receiver rx msg @11616473 [0]

and then becomes just

[TRACE] Pushing to channel @11616381
[INFO ] msg_receiver rx msg @11616473 [0]
[TRACE] Pushing to channel @11616381
[INFO ] msg_receiver rx msg @11616473 [0]
[TRACE] Pushing to channel @11616381
[INFO ] msg_receiver rx msg @11616473 [0]
...

and the final delay never returns.

I don't really know how interrupts work, but my suspicion is that, like, receiving the message under those circumstances consumes the delay's interrupt somehow, so the delay is never notified. I don't understand enough about interrupts to know how it should be handled, nor which part of the system is wrong.

[Finomnis]

Sadly I'm very busy right now, I hope someone else can take a look at this.

[Erhannis]

Ok, so I watched some videos on interrupts, and whether or not they helped, I think I found a workaround. I changed my message receiver from a loop to an ISR bound to a new IRQ, and explicitly trigger that IRQ from the second core after sending a message. Maybe I'm just not hitting the race condition anymore, but the system can process like 50K msgs a second, and doesn't seem to have encountered an error in 10,000,000 messages, so...much better than it was, at least, haha, and possibly correct.

[Erhannis]

Ah, rats. Back in my actual program, I've discovered that the ISR sending messages to other tasks waiting for messages doesn't notify them - the tasks stay asleep. If I also run a separate normal task that periodically sends messages on the same channel, those get through, and task reads the pending msgs from the ISR while it's awake.

If you pend an IRQ from core1, does the ISR run on core1 or core0? I'm suspicious I simply moved the disconnect into another function.

[Erhannis]

Answer: my ISR was running on core1, the same core I pended the IRQ on.
I think I found a better solution - I bound my message receiver task to SIO_IRQ_PROC0, the core0 fifo IRQ, and then when I send a message on core1 I also send a 0 to the fifo, which triggers the ISR on core0. So far it seems reliable and prompt.

[Finomnis]

So is there still a bug in the rtic monotonics or not?

[Erhannis]

I still don't know if it was RTIC's fault for not handling an interrupt correctly, or if it was my fault for doing something weird with cores and interrupts (because I'm still a little fuzzy on how the interrupts work). It is strange for the outcome to be "a delay in an unrelated task never returns", but if my interrupt stuff was sufficiently wrong I wouldn't be too surprised for it to have other effects. Is there a doc somewhere describing how RTIC uses interrupts under the hood, or would I need to read the code?