Zephyr interrupt-thread synchronization - improving real time performance

[eyalasko]

Hello,

In an nRF52840, NCS2.7.0 application (based on BT NUS shell) I need to address the following case:

1. UART Interrupt handler monitors incoming bytes
2. A working thread (UART message parser & handler) is blocked on a sync object until a full message is received
3. Once the interrupt handler recognizes the end-of-UART-messgae condition, it asserts the sync object
4. The thread gets unblocked and handles the received message.

The problem I'm facing is a very looong (>20ms !) latency from the time the interrupt asserted the sync object until the thread is unblocked.

I tried:

• Using events for synchronization (k_event_post/k_event_wait)
• Using Semaphore (k_sem_give/k_sem_take)
• Changing the thread priority between priority 7 & priority 1

Nothing seems to improve the poor real-time response to a reasonable latency.

I have past experience with freertos and I've never experienced such long latencies. I assume I'm missing something here.

• Is there a recommended 'light' sync object that can mitigate that?
• Will using a workqueue yield a better realtime behavior?
• Any Kconfig parameter I should be aware of?

Thanks for any advice

[Jakob Ruhe]

Hi,

20 ms is a very long time indeed! Regardless if you use k_event, k_sem or workques, you should have a latency magnitudes below that!

As long as you do it right of course. 

And since you have a latency of 20 ms, something is definitely not right.

However. Without any source code it is hard to say what is wrong.

eyalasko said:

The problem I'm facing is a very looong (>20ms !) latency from the time the interrupt asserted the sync object until the thread is unblocked.

Are you sure you are measuring the time from when the "interrupt asserted the sync object until the thread is unblocked"? How do you measure this latency?

[eyalasko]

Hey @Jakob,

I measure the latency by toggling  a bit when giving the semaphore and when taking (consuming) it

[Jakob Ruhe]

Sounds like a good approach! I assume you use a logic analyzer to capture the output of the pin and to measure the time.

Probably not exactly related to your problem but one detail that do differ between FreeRTOS and Zephyr are that in Zephyr a low priority value means high priority. You can read about that here: Threads — Zephyr Project Documentation.

If you add the following to your `prj.conf`:

CONFIG_THREAD_NAME=y
CONFIG_THREAD_MONITOR=y

You can log all your threads like this:

void log_thread_info(const struct k_thread *thread, void *user_data)
{
    k_tid_t tid = (k_tid_t)thread;
    LOG_INF("Thread: %s (%p), priority: %d", k_thread_name_get(tid), tid, k_thread_priority_get(tid));
}

k_thread_foreach(log_thread_info, NULL);

But again, your problem is probably not related to the priorities of the thread, unless you do a lot of work in them. If you can share a minimal application so that others can reproduce your problem it would increase the likelihood of getting help a lot!

[Edvin]

Hello,

You are sure that it isn't the UART RX time that is taking up the time? In what interrupts do you toggle the GPIO? If you could share some snippets, or perhaps the entire application, then I can have a look.

Best regards,

Edvin