Calling k_sem_give causes MPU Fault on nRF52833

[bamkrs]

Describe the bug
I have tied a simple interrupt to a pin on my nRF52833. This interrupt finally calls a small function that only gives an semaphore.
Another thread waits for this semaphore. This works just fine:

K_SEM_DEFINE(interrupt_sem, 0, 1);

void wait_for_sem() {
  k_sem_take(&interrupt_sem, K_FOREVER);
}

void trigger_sem() {
  k_sem_give(&interrupt_sem);
}

However, after a period of time, calling k_sem_give(&interrupt_sem); causes an MPU Fault.
The exact location of the fault is in include/sys/dlist.h when calling sys_dlist_remove(sys_dnode_t). Rewinding the stack further, this is caused by thread->base.qnode_dlist only being NULL. This can be worked around by just setting next/prev to "it self":

K_SEM_DEFINE(interrupt_sem, 0, 1);

void wait_for_sem() {
  k_sem_take(&interrupt_sem, K_FOREVER);
}

void trigger_sem() {
  if (interrupt_sem.wait_q.waitq.next->next != NULL) {
    k_sem_give(&interrupt_sem);
  } else {
    interrupt_sem.wait_q.waitq.next->next = interrupt_sem.wait_q.waitq.next;
    interrupt_sem.wait_q.waitq.next->prev = interrupt_sem.wait_q.waitq.prev;
    k_sem_give(&interrupt_sem);
  }
}

However, I don't understand why interrupt_sem.wait_q.waitq.next->next is NULL in the first place. This only happens after some amount of calling k_sem_give(). The first couple of times (multiple hundred) everything works as expected.

To Reproduce
Having an ISR call k_sem_give() a couple of times.
The thread waiting for the semaphore is an workqueue.

Expected behavior
Having k_sem_give() just increase the semaphore count without any MPU Faults.

Impact
Showstopper, its a critical routine to synchronize an external PHY.

Logs and console output

[00:00:07.941,162] <err> os: ***** MPU FAULT *****
[00:00:07.962,432] <err> os:   Data Access Violation
[00:00:07.983,917] <err> os:   MMFAR Address: 0x0
[00:00:08.005,096] <err> os: r0/a1:  0x20002828  r1/a2:  0x20002828  r2/a3:  0x00000000
[00:00:08.030,151] <err> os: r3/a4:  0x00000000 r12/ip:  0x80000000 r14/lr:  0x00024f31
[00:00:08.055,206] <err> os:  xpsr:  0x81000016
[00:00:08.076,263] <err> os: Faulting instruction address (r15/pc): 0x00023008
[00:00:08.100,341] <err> os: >>> ZEPHYR FATAL ERROR 0: CPU exception on CPU 0
[00:00:08.124,298] <err> os: Fault during interrupt handling

[00:00:08.146,636] <err> os: Current thread: 0x20002828 (idle 00)
[00:00:08.189,300] <err> os: Halting system

Callstack:

mem_manage_fault fault.c:214
fault_handle fault.c:699
z_arm_fault fault.c:962
z_arm_usage_fault fault_s.S:102
<signal handler called> 0x00000000fffffff1
sys_dlist_remove dlist.h:497
z_priq_dumb_remove sched.c:929
unpend_thread_no_timeout sched.c:652
z_unpend_thread_no_timeout sched.c:660
z_unpend1_no_timeout ksched.h:304
z_unpend_first_thread sched.c:713
z_impl_k_sem_give sem.c:113
k_sem_give kernel.h:770
trigger_sem interrupt.c:22
if_int_handler pplc_nrf52_if.c:148
gpio_fire_callbacks gpio_utils.h:70
fire_callbacks gpio_nrfx.c:394
gpiote_event_handler gpio_nrfx.c:442
_isr_wrapper isr_wrapper.S:186
<signal handler called> 0x00000000fffffff1
get_num_regions arm_mpu.c:45
mpu_configure_dynamic_mpu_regions arm_mpu_v7_internal.h:344
arm_core_mpu_configure_dynamic_mpu_regions arm_mpu.c:287
z_arm_configure_dynamic_mpu_regions arm_core_mpu.c:305
z_arm_pendsv swap_helper.S:287

Environment:

• OS: Debian 11
• Zephyr SDK 2.4 (nRF Connect SDK v1.4.0)
• https://github.com/nrfconnect/sdk-zephyr e34b2f4 (HEAD, tag: v2.4.0-ncs2-rc1, tag: v2.4.0-ncs2, manifest-rev)

[ioannisg]

The fault suggest your are accessing address 0x0, during an ISR - could that be null-pointer dereferencing?

[ioannisg]

BTW, if this concerns the nRF SDK - please open the ticket at the nRF Connect project. :)

[bamkrs]

Hey @ioannisg
Yes accessing NULL/0x0 in the ISR is the problem I'm chasing. The question is why its NULL. The semaphore is only touched in these two functions and if I interpret the code correctly, the NULL-ptr is in the threads wait-queue. I do not have any control over the wait-queue and its some zephyr internal wizardry. Its all standard zephyr, the only nordic SDK part is the ISR itself. So I thought it would rather fit this repo.

[ioannisg]

@pabigot may I assign you here, so you could provide some help, or suggest alternative assignees?

[pabigot]

I'm not sure what I can do other than try to reproduce this in current upstream. I don't see any relevant differences between NCS and Zephyr 2.4.0, but there may be some between Zephyr 2.4.0 and current.

@bamkrs How frequently does that interrupt trigger? What's the minimum delay between triggering signals?

[bamkrs]

@pabigot roughly 40 times until the MPU fault. ~10ms delay.

[pabigot]

@bamkrs Thanks. What's the priority of the thread that blocks on semaphore, in particular cooperative or preemptive? Are there any indications that it may not have completed its work before the next trigger arrives? Or that perhaps it's the active thread when the interrupt is being handled? Is that something you could test?

I'm unaware of any problems with the Zephyr semaphore code except #28105 (comment) which is only supposed to be a problem on SMP (though if you're using ZLIs anywhere all bets are off). I don't see any clear candidates for what could be going wrong, so this is going to be very difficult to diagnose without a reproducing case.

[bamkrs]

@pabigot the waiting thread is mostly the thread that is interrupted by the IRQ. A legacy library forces us to send some data over SPI to the PHY and runs into the semaphore. When the PHY has an answer, it pulls an interrupt pin which finally calls the semaphores "give". One thing to mention is that the ISR is incredibly long (does another SPI-Call) by design (poor design choices of the legacy library).

[ioannisg]

@bamkrs is it possible that the Interrupt stack overflows?
Also, would be nice to show us the prj.conf (ideally, autoconf.h as well) to see if there's something in the configuration that might be responsible for what you observe.

[bamkrs]

@ioannisg oh, this is an interesting idea. I have to check this. I try to get back to this issue later that day.

[pabigot]

I'm not sure how a stack overflow could explain this, but I'm very skeptical that it's due to a bug in the semaphore implementation. I believe it could be, but it's more likely something else. Can you also run with CONFIG_ASSERT=y and see if that changes anything, or identifies a problem?

If you provide config data the .config file in the build/zephyr directory is the most complete/self-contained.

[ioannisg]

If the interrupt stack overflows (for which we have no guard on ARMv7-m) it might corrupt thread data and nullify the semaphore content. Unlikely but worth looking at it.