Linux kernel deadlock detection tool – Lockdep

Foreword

Deadlock refers to the phenomenon of two or more processes waiting for each other due to competition for resources. For example, process A needs resource Will cause deadlock.

In kernel development, concurrency design must always be considered. Even if correct programming ideas are adopted, it is impossible to avoid deadlock. In the Linux kernel, there are two common deadlocks:

  • Recursive deadlock: If a lock is used in an interrupt delay operation, it forms a recursive deadlock with an external lock.

  • AB-BA deadlock: Multiple locks can cause deadlocks due to improper handling. Inconsistent lock processing sequences on multiple kernel paths can also cause deadlocks.

The Linux kernel introduced the deadlock debugging module lockdep in 2006. lockdep will track the status of each lock and the dependencies between each lock. After a series of verifications Rules to ensure that dependencies between locks are correct.

Configuring the kernel

To use the lockdep function in the Linux kernel, you need to turn on the CONFIG_DEBUG_LOCKDEP option:

CONFIG_LOCK_STAT=y
CONFIG_PROVE_LOCKING=y
CONFIG_DEBUG_LOCKDEP=y

Then recompile the kernel, replace the kernel and restart the system.

In the proc directory, there will be three file nodes: lockdep, lockdep_chains and lockdep_stats, which shows that the lockdep module has taken effect:

#cat /proc/lockdep
lockdep lockdep_chains lockdep_stats

Simple AB-BA deadlock case

Here is an example of a simple AB-BA deadlock:

#include <linux/module.h>
#include <linux/init.h>
#include <linux/kernel.h>

static DEFINE_SPINLOCK(hack_spinA);
static DEFINE_SPINLOCK(hack_spinB);

void hack_spinAB(void)
{
    printk("hack_lockdep:A->B\
");
    spin_lock( &hack_spinA);
    spin_lock( &hack_spinB);
}

void hack_spinBA(void)
{
    printk("hack_lockdep:B->A\
");
    spin_lock( &hack_spinB);
}

static int __init lockdep_test_init(void)
{
    printk("figo: my lockdep module init\
");
    
    hack_spinAB();
    hack_spinBA();
 
    return 0;
}

static void __exit lockdep_test_exit(void)
{
  printk("goodbye\
");
}

module_init(lockdep_test_init);
module_exit(lockdep_test_exit);
MODULE_LICENSE("GPL");

The above code initializes two spin locks. The hack_spinAB() function applies for the hack_spinA lock and the hack_spinB lock respectively. The hack_spinBA() function applies for the hack_spinB code>Lock. Because the lock hack_spinB has been successfully acquired and has not been released, it will wait forever, and it is also locked in the critical section of hack_spinA.

Phenomenon:

# insmod lockdep_test.ko
[437.981262] figo:my lockdep module init
[437.985145] hack_lockdep:A->B
[437.989054] hack_lockdep:B->A
[437.992304]
[ 437.993819] =================================================
[ 437.999229] [ INFO: possible recursive locking detected ]
[ 438.004641] 4.9.88 #2 Tainted: G O
[ 438.009180] ------------------------------------------------
[ 438.014589] insmod/367 is trying to acquire lock:
[ 438.019303] (hack_spinB){ + . + ...}, at: [<7f00a030>] lockdep_test_init + 0x30/0x3c [lockdep_test]

[438.028006] but task is already holding lock:
[ 438.032547] (hack_spinB){ + . + ...}, at: [<7f008038>] hack_spinAB + 0x38/0x3c [lockdep_test]

[ 438.040715] other info that might help us debug this:
[ 438.045950] Possible unsafe locking scenario:
[438.045950]
[438.051883] CPU0
[438.054337] ----
[438.056790] lock(hack_spinB);
[438.059975] lock(hack_spinB);
[438.063160]
[438.063160] *** DEADLOCK ***
[438.063160]
[ 438.069094] May be due to missing lock nesting notation
[438.069094]
[438.075896] 2 locks held by insmod/367:
[ 438.079740] #0: (hack_spinA){ + . + ...}, at: [<7f008030>] hack_spinAB + 0x30/0x3c [lockdep_test]
[438.088358] #1: (hack_spinB){ + . + ...}, at: [<7f008038>] hack_spinAB + 0x38/0x3c [lockdep_test]
[438.096977]
[438.096977] stack backtrace:
[438.101352] CPU: 0 PID: 367 Comm: insmod Tainted: G O 4.9.88 #2
[438.108410] Hardware name: Freescale i.MX6 UltraLite (Device Tree)
[ 438.114628] [<801136cc>] (unwind_backtrace) from [<8010e78c>] (show_stack + 0x20/0x24)
[ 438.122396] [<8010e78c>] (show_stack) from [<804ccc34>] (dump_stack + 0xa0/0xcc)
[ 438.129646] [<804ccc34>] (dump_stack) from [<8018f020>] (__lock_acquire + 0x8bc/0x1d4c)
[438.137502] [<8018f020>] (__lock_acquire) from [<80190b78>] (lock_acquire + 0xf4/0x2f8)
[ 438.145358] [<80190b78>] (lock_acquire) from [<80c94a0c>] (_raw_spin_lock + 0x4c/0x84)
[ 438.153129] [<80c94a0c>] (_raw_spin_lock) from [<7f00a030>] (lockdep_test_init + 0x30/0x3c [lockdep_test])
[438.162638] [<7f00a030>] (lockdep_test_init [lockdep_test]) from [<80102004>] (do_one_initcall + 0x54/0x184)
[ 438.172315] [<80102004>] (do_one_initcall) from [<80229624>] (do_init_module + 0x74/0x1f8)
[ 438.180431] [<80229624>] (do_init_module) from [<801dac54>] (load_module + 0x201c/0x279c)
[ 438.188461] [<801dac54>] (load_module) from [<801db648>] (SyS_finit_module + 0xc4/0xfc)
[ 438.196317] [<801db648>] (SyS_finit_module) from [<80109680>] (ret_fast_syscall + 0x0/0x1c)

The prompt message displays: Trying to acquire the hack_spinB lock, but the lock has been locked in the function hack_spinAB:

lockdep has clearly displayed the path where the deadlock occurred and the stack information of the function call when it occurred. Based on this information, the problem can be quickly located and solved.

Deadlock in actual projects

The following example is a bit more complicated. This is a deadlock extracted from an actual project and is more representative.

#include <linux/init.h>
#include <linux/module.h>
#include <linux/kernel.h>
#include <linux/kthread.h>
#include <linux/freezer.h>
#include <linux/delay.h>


static DEFINE_MUTEX(mutex_a);
static struct delayed_work delay_task;
static void lockdep_timefunc(unsigned long);
static DEFINE_TIMER(lockdep_timer, lockdep_timefunc, 0, 0);

static void lockdep_timefunc(unsigned long dummy)
{
    schedule_delayed_work( & delay_task, 10);
    mod_timer( & lockdep_timer, jiffies + msecs_to_jiffies(100));
}

static void lockdep_test_work(struct work_struct *work)
{
    mutex_lock( & mutex_a);
    mdelay(300);//Process some things, here use mdelay instead
    mutex_unlock( & mutex_a);
}

static int lockdep_thread(void *nothing)
{
    set_freezable();//Clear the PF_NOFREEZE bit in the flags of the current thread flag, indicating that the current thread can enter the suspended or dormant state.
    set_user_nice(current, 0);
    while(!kthread_should_stop()){
        mdelay(500);//Process some things, here use mdelay instead

        //Encounter some special circumstances, need to cancel delay_task
        mutex_lock( & mutex_a);
        cancel_delayed_work_sync( &delay_task);
        mutex_unlock( & mutex_a);
    }

    return 0;
}


static int __init lockdep_test_init(void)
{
    printk("figo:my lockdep module init\
");
    
   struct task_struct *lock_thread;

   /*Create a thread to handle something*/
   lock_thread = kthread_run(lockdep_thread, NULL, "lockdep_test");

   /*Create a delayed work queue*/
   INIT_DELAYED_WORK( & delay_task, lockdep_test_work);

   /* Create a timer to simulate some asynchronous events, such as interrupts, etc. */
   lockdep_timer. expires = jiffies + msecs_to_jiffies(500);
   add_timer( & amp;lockdep_timer);
 
    return 0;
}


static void __exit lockdep_test_exit(void)
{
  printk("goodbye\
");
}

MODULE_LICENSE("GPL");
module_init(lockdep_test_init);
module_exit(lockdep_test_exit);

First create a lockdep_thread kernel thread to process certain things periodically,

Then create a work queue called lockdep_test_worker to handle some delayed operations like interrupting the second half,

Finally use a timer to simulate certain asynchronous events (such as interrupts).

In the lockdep_thread kernel thread, the work queue often needs to be canceled under certain special circumstances. The code first applies for a mutex_a mutex lock, and then calls the cancel_delayed_work_sync() function to cancel the work queue. In addition, the timer schedules the work queue regularly and applies for the mutex_a mutex lock in the callback function lockdep_test_worker() function.

The above is the calling scenario of this example. The following is the deadlock information captured during runtime:

# insmod lockdep_test.ko
[370.477536] figo:my lockdep module init
[ 371.124433]
[371.125970] ================================================= =======
[ 371.132162] [ INFO: possible circular locking dependency detected ]
[371.138445] 4.9.88 #2 Tainted: G O
[371.142987] -------------------------------------------------- --------
[371.149265] kworker/0:2/104 is trying to acquire lock:
[ 371.154414] (mutex_a){ + . + ...}, at: [<7f004078>] lockdep_test_work + 0x24/0x58 [lockdep_test]

[371.162852] but task is already holding lock:
[ 371.167392] (( & amp;( & amp;delay_task)->work)){ + . + ...}, at: [<80157104>] process_one_work + 0x1ec/0x8bc

[ 371.175912] which lock already depends on the new lock.
[ 371.175912]
[ 371.182799]
[ 371.182799] the existing dependency chain (in reverse order) is:
[ 371.190291]
-> #1 (( & amp;( & amp;delay_task)->work)){ + . + ...}:
[371.195432] flush_work + 0x4c/0x278
[ 371.199371] __cancel_work_timer+0xa8/0x1d0
[ 371.204088] cancel_delayed_work_sync + 0x1c/0x20
[ 371.209157] lockdep_thread + 0x84/0xa4 [lockdep_test]
[371.214658] kthread + 0x120/0x124
[371.218423] ret_from_fork + 0x14/0x38
[ 371.222529]
-> #0 (mutex_a){ + . + ...}:
[371.226374] lock_acquire + 0xf4/0x2f8
[ 371.230487] mutex_lock_nested + 0x70/0x4bc
[ 371.235036] lockdep_test_work + 0x24/0x58 [lockdep_test]
[ 371.240797] process_one_work + 0x2b0/0x8bc
[371.245342] worker_thread + 0x68/0x5c4
[371.249538] kthread + 0x120/0x124
[371.253301] ret_from_fork + 0x14/0x38
[ 371.257407]
[ 371.257407] other info that might help us debug this:
[ 371.257407]
[ 371.265424] Possible unsafe locking scenario:
[371.265424]
[ 371.271353] CPU0 CPU1
[ 371.275891] ---- ----
[ 371.280428] lock(( &( &delay_task)->work));
[371.284656] lock(mutex_a);
[ 371.290098] lock(( & amp;( & amp;delay_task)->work));
[371.296843] lock(mutex_a);
[371.299768]
[371.299768] *** DEADLOCK ***
[371.299768]
[371.305704] 2 locks held by kworker/0:2/104:
[ 371.309981] #0: ("events"){. + . + . + }, at: [<80157104>] process_one_work + 0x1ec/0x8bc
[ 371.317729] #1: (( & amp;( & amp;delay_task)->work)){ + . + ...}, at: [<80157104>] process_one_work + 0x1ec/0x8bc
[371.326690]
[371.326690] stack backtrace:
[371.331066] CPU: 0 PID: 104 Comm: kworker/0:2 Tainted: G O 4.9.88 #2
[ 371.338558] Hardware name: Freescale i.MX6 UltraLite (Device Tree)
[371.344760] Workqueue: events lockdep_test_work [lockdep_test]
[ 371.350643] [<801136cc>] (unwind_backtrace) from [<8010e78c>] (show_stack + 0x20/0x24)
[ 371.358409] [<8010e78c>] (show_stack) from [<804ccc34>] (dump_stack + 0xa0/0xcc)
[ 371.365659] [<804ccc34>] (dump_stack) from [<8018c6e4>] (print_circular_bug + 0x208/0x320)
[ 371.373774] [<8018c6e4>] (print_circular_bug) from [<801900a0>] (__lock_acquire + 0x193c/0x1d4c)
[ 371.382408] [<801900a0>] (__lock_acquire) from [<80190b78>] (lock_acquire + 0xf4/0x2f8)
[ 371.390259] [<80190b78>] (lock_acquire) from [<80c8fda0>] (mutex_lock_nested + 0x70/0x4bc)
[ 371.398373] [<80c8fda0>] (mutex_lock_nested) from [<7f004078>] (lockdep_test_work + 0x24/0x58 [lockdep_test])
[ 371.408140] [<7f004078>] (lockdep_test_work [lockdep_test]) from [<801571c8>] (process_one_work + 0x2b0/0x8bc)
[ 371.417988] [<801571c8>] (process_one_work) from [<8015783c>] (worker_thread + 0x68/0x5c4)
[ 371.426099] [<8015783c>] (worker_thread) from [<8015e6c8>] (kthread + 0x120/0x124)
[ 371.433516] [<8015e6c8>] (kthread) from [<8010971c>] (ret_from_fork + 0x14/0x38)

The ockdep information first prompts that a recursive deadlock “possible circular locking dependency detected” may occur, and then prompts “kworker/0:2/104” The thread tried to acquire the mutex_a mutex lock, but the lock was already held by other processes. The process with the lock is in &delay_task->work.

The following function call stack shows the call path of the above attempt to acquire the mutex_a lock. The two paths are as follows:

(1) The kernel thread lockdep_thread first successfully acquired the mutex_a mutex lock, and then called the cancel_delayed_work_sync() function to cancel kworker. Note that the cancel_delayed_work_sync() function will call the flush operation and wait for all kworker callback functions to be executed before calling mutex_unlock( & amp;mutex_a) to release the lock.

(2) The kworker callback function lockdep_test_worker() will first try to obtain the mutex_a mutex lock. Note that the kernel thread lockdep_thread has just acquired the mutex_a mutex lock and has been waiting for the current kworker callback function to finish executing, so a deadlock occurred.

The following is the CPU call relationship of the deadlock scenario: