core: add core_mutex_debug to aid debugging deadlocks

Adding `USEMODULE += core_mutex_debug` to your `Makefile` results in
on log messages such as

    [mutex] waiting for thread 1 (pc = 0x800024d)

being added whenever `mutex_lock()` blocks. This makes tracing down
deadlocks easier.

core/Kconfig

@@ -39,6 +39,9 @@ config MODULE_CORE_MSG_BUS
     help
         Messaging Bus API for inter process message broadcast.
 
+config MODULE_CORE_MUTEX_DEBUG
+    bool "Aid debugging deadlocks by printing on whom mutex_lock() is waiting"
+
 config MODULE_CORE_MUTEX_PRIORITY_INHERITANCE
     bool "Use priority inheritance to mitigate priority inversion for mutexes"
 

core/include/mutex.h

@@ -112,6 +112,8 @@
 #include <stdint.h>
 #include <stdbool.h>
 
+#include "architecture.h"
+#include "cpu.h"
 #include "kernel_defines.h"
 #include "list.h"
 #include "thread.h"
@@ -130,7 +132,8 @@ typedef struct {
      * @internal
      */
     list_node_t queue;
-#if defined(DOXYGEN) || defined(MODULE_CORE_MUTEX_PRIORITY_INHERITANCE)
+#if defined(DOXYGEN) || defined(MODULE_CORE_MUTEX_PRIORITY_INHERITANCE) \
+    || defined(MODULE_CORE_MUTEX_DEBUG)
     /**
      * @brief   The current owner of the mutex or `NULL`
      * @note    Only available if module core_mutex_priority_inheritance
@@ -141,6 +144,18 @@ typedef struct {
      * this will have the value of `NULL`.
      */
     kernel_pid_t owner;
+#endif
+#if defined(DOXYGEN) || defined(MODULE_CORE_MUTEX_DEBUG)
+    /**
+     * @brief   Program counter of the call to @ref mutex_lock that most
+     *          recently acquired this mutex
+     *
+     * This is used when the module `core_mutex_debug` is used to debug
+     * deadlocks and is non-existing otherwise
+     */
+    uinttxtptr_t owner_calling_pc;
+#endif
+#if defined(DOXYGEN) || defined(MODULE_CORE_MUTEX_PRIORITY_INHERITANCE)
     /**
      * @brief   Original priority of the owner
      * @note    Only available if module core_mutex_priority_inheritance

core/mutex.c

@@ -50,6 +50,11 @@
 static inline __attribute__((always_inline)) void _block(mutex_t *mutex,
                                                          unsigned irq_state)
 {
+#if IS_USED(MODULE_CORE_MUTEX_DEBUG)
+    printf("[mutex] waiting for thread %" PRIkernel_pid " (pc = 0x%" PRIxTXTPTR
+           ")\n",
+           mutex->owner, mutex->owner_calling_pc);
+#endif
     thread_t *me = thread_get_active();
 
     /* Fail visibly even if a blocking action is called from somewhere where
@@ -91,9 +96,15 @@ bool mutex_lock_internal(mutex_t *mutex, bool block)
     if (mutex->queue.next == NULL) {
         /* mutex is unlocked. */
         mutex->queue.next = MUTEX_LOCKED;
-#ifdef MODULE_CORE_MUTEX_PRIORITY_INHERITANCE
+#if IS_USED(MODULE_CORE_MUTEX_PRIORITY_INHERITANCE) \
+        || IS_USED(MODULE_CORE_MUTEX_DEBUG)
         thread_t *me = thread_get_active();
         mutex->owner = me->pid;
+#endif
+#if IS_USED(MODULE_CORE_MUTEX_DEBUG)
+    mutex->owner_calling_pc = cpu_get_caller_pc();
+#endif
+#if IS_USED(MODULE_CORE_MUTEX_PRIORITY_INHERITANCE)
         mutex->owner_original_priority = me->priority;
 #endif
         DEBUG("PID[%" PRIkernel_pid "] mutex_lock(): early out.\n",
@@ -129,9 +140,15 @@ int mutex_lock_cancelable(mutex_cancel_t *mc)
     if (mutex->queue.next == NULL) {
         /* mutex is unlocked. */
         mutex->queue.next = MUTEX_LOCKED;
-#ifdef MODULE_CORE_MUTEX_PRIORITY_INHERITANCE
+#if IS_USED(MODULE_CORE_MUTEX_PRIORITY_INHERITANCE) \
+        || IS_USED(MODULE_CORE_MUTEX_DEBUG)
         thread_t *me = thread_get_active();
         mutex->owner = me->pid;
+#endif
+#if IS_USED(MODULE_CORE_MUTEX_DEBUG)
+    mutex->owner_calling_pc = cpu_get_caller_pc();
+#endif
+#if IS_USED(MODULE_CORE_MUTEX_PRIORITY_INHERITANCE)
         mutex->owner_original_priority = me->priority;
 #endif
         DEBUG("PID[%" PRIkernel_pid "] mutex_lock_cancelable() early out.\n",
@@ -183,7 +200,7 @@ void mutex_unlock(mutex_t *mutex)
 
     uint16_t process_priority = process->priority;
 
-#ifdef MODULE_CORE_MUTEX_PRIORITY_INHERITANCE
+#if IS_USED(MODULE_CORE_MUTEX_PRIORITY_INHERITANCE)
     thread_t *owner = thread_get(mutex->owner);
     if ((owner) && (owner->priority != mutex->owner_original_priority)) {
         DEBUG("PID[%" PRIkernel_pid "] prio %u --> %u\n",
@@ -192,6 +209,9 @@ void mutex_unlock(mutex_t *mutex)
         sched_change_priority(owner, mutex->owner_original_priority);
     }
 #endif
+#if IS_USED(MODULE_CORE_MUTEX_DEBUG)
+    mutex->owner_calling_pc = 0;
+#endif
 
     irq_restore(irqstate);
     sched_switch(process_priority);