I study Linux lock mechanism recently, and want to see the lock holding and waiting time.

So I turn on CONFIG_LOCK_STAT flag in the .config file via make menuconfig and after recompiling the kernel run the command:

# less /proc/lock_stat

I got the following message:

*WARNING* lock debugging disabled!! - possibly due to a lockdep warning.

Just don’t know why, since I’ve turn on all the flags in the kernel hack->lock session.

P.S. The environment I use: kernel 3.12.6 (by uname -a).

UPDATE: dmesg with __debug_locks_off() and dump_stack() on

[    0.000000]  [<ffffffff817516a2>] _raw_write_lock+0x72/0x80
[    0.000000]  [<ffffffff81392718>] ? irqsafe4_soft_wlock_213+0x98/0xf0
[    0.000000]  [<ffffffff81392718>] irqsafe4_soft_wlock_213+0x98/0xf0
[    0.000000]  [<ffffffff817481f5>] dotest+0x43/0x5a7
[    0.000000]  [<ffffffff81399cd6>] locking_selftest+0x1286/0x2100
[    0.000000]  [<ffffffff81f1aca9>] start_kernel+0x2d2/0x427
[    0.000000]  [<ffffffff81f1a120>] ? early_idt_handlers+0x120/0x120
[    0.000000]  [<ffffffff81f1a4c7>] x86_64_start_reservations+0x2a/0x2c
[    0.000000]  [<ffffffff81f1a5d6>] x86_64_start_kernel+0x10d/0x11c
[    0.000000]   ok  |  ok  |
[    0.000000]     hard-safe-A + unsafe-B #2/231:### __debug_locks_off called!
[    0.000000] CPU: 0 PID: 0 Comm: swapper/0 Not tainted 3.12.6 #13
[    0.000000] Hardware name: Sony Corporation VGN-Z25TN_B/VAIO, BIOS R2140M3 08/26/2008
[    0.000000]  0000000000000002 ffffffff81c01c38 ffffffff81747f7c ffffffff81c15c98
[    0.000000]  ffffffff81c01c48 ffffffff81383d27 ffffffff81c01d60 ffffffff810d9d1e
[    0.000000]  ffffffff81c01ff8 ffffffff81c00000 ffffffff81c01fe8 ffffffff824d2d58
[    0.000000] Call Trace:
[    0.000000]  [<ffffffff81747f7c>] dump_stack+0x54/0x74
[    0.000000]  [<ffffffff81383d27>] debug_locks_off+0x17/0x50
[    0.000000]  [<ffffffff810d9d1e>] check_usage+0x10e/0x550
[    0.000000]  [<ffffffff810170f4>] ? dump_trace+0x194/0x2f0
[    0.000000]  [<ffffffff810d6a54>] ? __bfs+0x24/0x240
[    0.000000]  [<ffffffff810da1af>] check_irq_usage+0x4f/0xc0
[    0.000000]  [<ffffffff810dd1ae>] __lock_acquire+0x1bce/0x2190
[    0.000000]  [<ffffffff817511e7>] ? _raw_spin_unlock_irqrestore+0x67/0x70
[    0.000000]  [<ffffffff810c13b6>] ? vprintk_emit+0x1d6/0x630
[    0.000000]  [<ffffffff810de882>] lock_acquire+0xb2/0x160
[    0.000000]  [<ffffffff8138b936>] ? irqsafe4_hard_spin_231+0xc6/0x110
[    0.000000]  [<ffffffff8138b870>] ? irqsafe4_hard_rlock_231+0x110/0x110
[    0.000000]  [<ffffffff81750e96>] _raw_spin_lock+0x46/0x80
[    0.000000]  [<ffffffff8138b936>] ? irqsafe4_hard_spin_231+0xc6/0x110
[    0.000000]  [<ffffffff8138b936>] irqsafe4_hard_spin_231+0xc6/0x110
[    0.000000]  [<ffffffff817481f5>] dotest+0x43/0x5a7
[    0.000000]  [<ffffffff81399d22>] locking_selftest+0x12d2/0x2100
[    0.000000]  [<ffffffff81f1aca9>] start_kernel+0x2d2/0x427
[    0.000000]  [<ffffffff81f1a120>] ? early_idt_handlers+0x120/0x120
[    0.000000]  [<ffffffff81f1a4c7>] x86_64_start_reservations+0x2a/0x2c
[    0.000000]  [<ffffffff81f1a5d6>] x86_64_start_kernel+0x10d/0x11c
[    0.000000] ### __debug_locks_off called!
[    0.000000] CPU: 0 PID: 0 Comm: swapper/0 Not tainted 3.12.6 #13
[    0.000000] Hardware name: Sony Corporation VGN-Z25TN_B/VAIO, BIOS R2140M3 08/26/2008
[    0.000000]  ffffffff81c15580 ffffffff81c01e78 ffffffff81747f7c ffffffff81cab258
[    0.000000]  ffffffff81c01e88 ffffffff81383d27 ffffffff81c01ed8 ffffffff810df539
[    0.000000]  0000000000000082 ffffffff8138b936 0000000000000092 ffffffff81cab258
[    0.000000] Call Trace:
[    0.000000]  [<ffffffff81747f7c>] dump_stack+0x54/0x74
[    0.000000]  [<ffffffff81383d27>] debug_locks_off+0x17/0x50
[    0.000000]  [<ffffffff810df539>] lock_acquired+0x2f9/0x4d0
[    0.000000]  [<ffffffff8138b936>] ? irqsafe4_hard_spin_231+0xc6/0x110
[    0.000000]  [<ffffffff8138b870>] ? irqsafe4_hard_rlock_231+0x110/0x110
[    0.000000]  [<ffffffff81750ec2>] _raw_spin_lock+0x72/0x80
[    0.000000]  [<ffffffff8138b936>] ? irqsafe4_hard_spin_231+0xc6/0x110
[    0.000000]  [<ffffffff8138b936>] irqsafe4_hard_spin_231+0xc6/0x110
[    0.000000]  [<ffffffff817481f5>] dotest+0x43/0x5a7
[    0.000000]  [<ffffffff81399d22>] locking_selftest+0x12d2/0x2100
[    0.000000]  [<ffffffff81f1aca9>] start_kernel+0x2d2/0x427
[    0.000000]  [<ffffffff81f1a120>] ? early_idt_handlers+0x120/0x120
[    0.000000]  [<ffffffff81f1a4c7>] x86_64_start_reservations+0x2a/0x2c
[    0.000000]  [<ffffffff81f1a5d6>] x86_64_start_kernel+0x10d/0x11c
[    0.000000]   ok  |### __debug_locks_off called!
[    0.000000] CPU: 0 PID: 0 Comm: swapper/0 Not tainted 3.12.6 #13
[    0.000000] Hardware name: Sony Corporation VGN-Z25TN_B/VAIO, BIOS R2140M3 08/26/2008
[    0.000000]  0000000000000002 ffffffff81c01c38 ffffffff81747f7c ffffffff81c15c98
[    0.000000]  ffffffff81c01c48 ffffffff81383d27 ffffffff81c01d60 ffffffff810d9d1e
[    0.000000]  ffffffff81c01ff8 ffffffff81c00000 ffffffff81c01fe8 ffffffff824d3138
[    0.000000] Call Trace:
[    0.000000]  [<ffffffff81747f7c>] dump_stack+0x54/0x74
[    0.000000]  [<ffffffff81383d27>] debug_locks_off+0x17/0x50
[    0.000000]  [<ffffffff810d9d1e>] check_usage+0x10e/0x550
[    0.000000]  [<ffffffff810170f4>] ? dump_trace+0x194/0x2f0
[    0.000000]  [<ffffffff810d6a54>] ? __bfs+0x24/0x240
[    0.000000]  [<ffffffff810da1af>] check_irq_usage+0x4f/0xc0
[    0.000000]  [<ffffffff810dd1ae>] __lock_acquire+0x1bce/0x2190
[    0.000000]  [<ffffffff810d80e8>] ? lockdep_init_map+0x68/0x6d0
[    0.000000]  [<ffffffff810de882>] lock_acquire+0xb2/0x160
[    0.000000]  [<ffffffff81392636>] ? irqsafe4_hard_wlock_231+0xc6/0x110
[    0.000000]  [<ffffffff81392570>] ? irqsafe4_soft_wlock_231+0xf0/0xf0
[    0.000000]  [<ffffffff81751676>] _raw_write_lock+0x46/0x80
[    0.000000]  [<ffffffff81392636>] ? irqsafe4_hard_wlock_231+0xc6/0x110
[    0.000000]  [<ffffffff81392636>] irqsafe4_hard_wlock_231+0xc6/0x110
[    0.000000]  [<ffffffff817481f5>] dotest+0x43/0x5a7
[    0.000000]  [<ffffffff81399d35>] locking_selftest+0x12e5/0x2100
[    0.000000]  [<ffffffff81f1aca9>] start_kernel+0x2d2/0x427
[    0.000000]  [<ffffffff81f1a120>] ? early_idt_handlers+0x120/0x120
[    0.000000]  [<ffffffff81f1a4c7>] x86_64_start_reservations+0x2a/0x2c
[    0.000000]  [<ffffffff81f1a5d6>] x86_64_start_kernel+0x10d/0x11c
[    0.000000] ### __debug_locks_off called!
[    0.000000] CPU: 0 PID: 0 Comm: swapper/0 Not tainted 3.12.6 #13
[    0.000000] Hardware name: Sony Corporation VGN-Z25TN_B/VAIO, BIOS R2140M3 08/26/2008
[    0.000000]  ffffffff81c15580 ffffffff81c01e78 ffffffff81747f7c ffffffff81cab058
[    0.000000]  ffffffff81c01e88 ffffffff81383d27 ffffffff81c01ed8 ffffffff810df539
[    0.000000]  0000000000000082 ffffffff81392636 0000000000000092 ffffffff81cab058
[    0.000000] Call Trace:
[    0.000000]  [<ffffffff81747f7c>] dump_stack+0x54/0x74
[    0.000000]  [<ffffffff81383d27>] debug_locks_off+0x17/0x50
[    0.000000]  [<ffffffff810df539>] lock_acquired+0x2f9/0x4d0
[    0.000000]  [<ffffffff81392636>] ? irqsafe4_hard_wlock_231+0xc6/0x110
[    0.000000]  [<ffffffff81392570>] ? irqsafe4_soft_wlock_231+0xf0/0xf0
[    0.000000]  [<ffffffff817516a2>] _raw_write_lock+0x72/0x80
[    0.000000]  [<ffffffff81392636>] ? irqsafe4_hard_wlock_231+0xc6/0x110
[    0.000000]  [<ffffffff81392636>] irqsafe4_hard_wlock_231+0xc6/0x110
[    0.000000]  [<ffffffff817481f5>] dotest+0x43/0x5a7
[    0.000000]  [<ffffffff81399d35>] locking_selftest+0x12e5/0x2100
[    0.000000]  [<ffffffff81f1aca9>] start_kernel+0x2d2/0x427
[    0.000000]  [<ffffffff81f1a120>] ? early_idt_handlers+0x120/0x120
[    0.000000]  [<ffffffff81f1a4c7>] x86_64_start_reservations+0x2a/0x2c
[    0.000000]  [<ffffffff81f1a5d6>] x86_64_start_kernel+0x10d/0x11c
[    0.000000]   ok  |  ok  |
[    0.000000]     soft-safe-A + unsafe-B #2/231:### __debug_locks_off called!
[    0.000000] CPU: 0 PID: 0 Comm: swapper/0 Not tainted 3.12.6 #13
[    0.000000] Hardware name: Sony Corporation VGN-Z25TN_B/VAIO, BIOS R2140M3 08/26/2008
[    0.000000]  0000000000000006 ffffffff81c01c38 ffffffff81747f7c ffffffff81c15c98
[    0.000000]  ffffffff81c01c48 ffffffff81383d27 ffffffff81c01d60 ffffffff810d9d1e
[    0.000000]  ffffffff81c01cd8 0000000081c00000 ffffffff81c01fe8 0000000000000001
[    0.000000] Call Trace:
[    0.000000]  [<ffffffff81747f7c>] dump_stack+0x54/0x74
[    0.000000]  [<ffffffff81383d27>] debug_locks_off+0x17/0x50
[    0.000000]  [<ffffffff810d9d1e>] check_usage+0x10e/0x550
[    0.000000]  [<ffffffff810d9ac2>] ? check_usage_backwards+0x72/0x1c0
[    0.000000]  [<ffffffff810d6a54>] ? __bfs+0x24/0x240
[    0.000000]  [<ffffffff810da1af>] check_irq_usage+0x4f/0xc0
[    0.000000]  [<ffffffff810dd1cd>] __lock_acquire+0x1bed/0x2190
[    0.000000]  [<ffffffff817511e7>] ? _raw_spin_unlock_irqrestore+0x67/0x70
[    0.000000]  [<ffffffff810c13b6>] ? vprintk_emit+0x1d6/0x630
[    0.000000]  [<ffffffff810de882>] lock_acquire+0xb2/0x160
[    0.000000]  [<ffffffff8138d6f8>] ? irqsafe4_soft_spin_231+0xa8/0xf0
[    0.000000]  [<ffffffff8138d650>] ? irqsafe4_soft_rlock_231+0xf0/0xf0
[    0.000000]  [<ffffffff81750e96>] _raw_spin_lock+0x46/0x80
[    0.000000]  [<ffffffff8138d6f8>] ? irqsafe4_soft_spin_231+0xa8/0xf0
[    0.000000]  [<ffffffff8138d6f8>] irqsafe4_soft_spin_231+0xa8/0xf0
[    0.000000]  [<ffffffff817481f5>] dotest+0x43/0x5a7
[    0.000000]  [<ffffffff81399d81>] locking_selftest+0x1331/0x2100
[    0.000000]  [<ffffffff81f1aca9>] start_kernel+0x2d2/0x427
[    0.000000]  [<ffffffff81f1a120>] ? early_idt_handlers+0x120/0x120
[    0.000000]  [<ffffffff81f1a4c7>] x86_64_start_reservations+0x2a/0x2c
[    0.000000]  [<ffffffff81f1a5d6>] x86_64_start_kernel+0x10d/0x11c
[    0.000000] ### __debug_locks_off called!
[    0.000000] CPU: 0 PID: 0 Comm: swapper/0 Not tainted 3.12.6 #13
[    0.000000] Hardware name: Sony Corporation VGN-Z25TN_B/VAIO, BIOS R2140M3 08/26/2008
[    0.000000]  ffffffff81c15580 ffffffff81c01e78 ffffffff81747f7c ffffffff81cab258
[    0.000000]  ffffffff81c01e88 ffffffff81383d27 ffffffff81c01ed8 ffffffff810df539
[    0.000000]  0000000000000282 ffffffff8138d6f8 0000000000000292 ffffffff81cab258
[    0.000000] Call Trace:
[    0.000000]  [<ffffffff81747f7c>] dump_stack+0x54/0x74
[    0.000000]  [<ffffffff81383d27>] debug_locks_off+0x17/0x50
[    0.000000]  [<ffffffff810df539>] lock_acquired+0x2f9/0x4d0
[    0.000000]  [<ffffffff8138d6f8>] ? irqsafe4_soft_spin_231+0xa8/0xf0
[    0.000000]  [<ffffffff8138d650>] ? irqsafe4_soft_rlock_231+0xf0/0xf0
[    0.000000]  [<ffffffff81750ec2>] _raw_spin_lock+0x72/0x80
[    0.000000]  [<ffffffff8138d6f8>] ? irqsafe4_soft_spin_231+0xa8/0xf0
[    0.000000]  [<ffffffff8138d6f8>] irqsafe4_soft_spin_231+0xa8/0xf0
[    0.000000]  [<ffffffff817481f5>] dotest+0x43/0x5a7
[    0.000000]  [<ffffffff81399d81>] locking_selftest+0x1331/0x2100
[    0.000000]  [<ffffffff81f1aca9>] start_kernel+0x2d2/0x427
[    0.000000]  [<ffffffff81f1a120>] ? early_idt_handlers+0x120/0x120
[    0.000000]  [<ffffffff81f1a4c7>] x86_64_start_reservations+0x2a/0x2c
[    0.000000]  [<ffffffff81f1a5d6>] x86_64_start_kernel+0x10d/0x11c
[    0.000000]   ok  |### __debug_locks_off called!
[    0.000000] CPU: 0 PID: 0 Comm: swapper/0 Not tainted 3.12.6 #13
[    0.000000] Hardware name: Sony Corporation VGN-Z25TN_B/VAIO, BIOS R2140M3 08/26/2008
[    0.000000]  0000000000000006 ffffffff81c01c38 ffffffff81747f7c ffffffff81c15c98
[    0.000000]  ffffffff81c01c48 ffffffff81383d27 ffffffff81c01d60 ffffffff810d9d1e
[    0.000000]  ffffffff81c01cd8 0000000081c00000 ffffffff81c01fe8 0000000000000001
[    0.000000] Call Trace:
[    0.000000]  [<ffffffff81747f7c>] dump_stack+0x54/0x74
[    0.000000]  [<ffffffff81383d27>] debug_locks_off+0x17/0x50
[    0.000000]  [<ffffffff810d9d1e>] check_usage+0x10e/0x550
[    0.000000]  [<ffffffff810d9ac2>] ? check_usage_backwards+0x72/0x1c0
[    0.000000]  [<ffffffff810d6a54>] ? __bfs+0x24/0x240
[    0.000000]  [<ffffffff810da1af>] check_irq_usage+0x4f/0xc0
[    0.000000]  [<ffffffff810dd1cd>] __lock_acquire+0x1bed/0x2190
[    0.000000]  [<ffffffff810d80e8>] ? lockdep_init_map+0x68/0x6d0
[    0.000000]  [<ffffffff810de882>] lock_acquire+0xb2/0x160
[    0.000000]  [<ffffffff81392528>] ? irqsafe4_soft_wlock_231+0xa8/0xf0
[    0.000000]  [<ffffffff81392480>] ? irqsafe4_hard_wlock_312+0x110/0x110
[    0.000000]  [<ffffffff81751676>] _raw_write_lock+0x46/0x80
[    0.000000]  [<ffffffff81392528>] ? irqsafe4_soft_wlock_231+0xa8/0xf0
[    0.000000]  [<ffffffff81392528>] irqsafe4_soft_wlock_231+0xa8/0xf0
[    0.000000]  [<ffffffff817481f5>] dotest+0x43/0x5a7
[    0.000000]  [<ffffffff81399d94>] locking_selftest+0x1344/0x2100
[    0.000000]  [<ffffffff81f1aca9>] start_kernel+0x2d2/0x427
[    0.000000]  [<ffffffff81f1a120>] ? early_idt_handlers+0x120/0x120
[    0.000000]  [<ffffffff81f1a4c7>] x86_64_start_reservations+0x2a/0x2c
[    0.000000]  [<ffffffff81f1a5d6>] x86_64_start_kernel+0x10d/0x11c
[    0.000000] ### __debug_locks_off called!
[    0.000000] CPU: 0 PID: 0 Comm: swapper/0 Not tainted 3.12.6 #13
[    0.000000] Hardware name: Sony Corporation VGN-Z25TN_B/VAIO, BIOS R2140M3 08/26/2008
[    0.000000]  ffffffff81c15580 ffffffff81c01e78 ffffffff81747f7c ffffffff81cab058
[    0.000000]  ffffffff81c01e88 ffffffff81383d27 ffffffff81c01ed8 ffffffff810df539
[    0.000000]  0000000000000282 ffffffff81392528 0000000000000292 ffffffff81cab058
[    0.000000] Call Trace:
[    0.000000]  [<ffffffff81747f7c>] dump_stack+0x54/0x74
[    0.000000]  [<ffffffff81383d27>] debug_locks_off+0x17/0x50
[    0.000000]  [<ffffffff810df539>] lock_acquired+0x2f9/0x4d0
[    0.000000]  [<ffffffff81392528>] ? irqsafe4_soft_wlock_231+0xa8/0xf0
[    0.000000]  [<ffffffff81392480>] ? irqsafe4_hard_wlock_312+0x110/0x110
[    0.000000]  [<ffffffff817516a2>] _raw_write_lock+0x72/0x80
[    0.000000]  [<ffffffff81392528>] ? irqsafe4_soft_wlock_231+0xa8/0xf0
[    0.000000]  [<ffffffff81392528>] irqsafe4_soft_wlock_231+0xa8/0xf0
[    0.000000]  [<ffffffff817481f5>] dotest+0x43/0x5a7
[    0.000000]  [<ffffffff81399d94>] locking_selftest+0x1344/0x2100
[    0.000000]  [<ffffffff81f1aca9>] start_kernel+0x2d2/0x427
[    0.000000]  [<ffffffff81f1a120>] ? early_idt_handlers+0x120/0x120
[    0.000000]  [<ffffffff81f1a4c7>] x86_64_start_reservations+0x2a/0x2c
[    0.000000]  [<ffffffff81f1a5d6>] x86_64_start_kernel+0x10d/0x11c
[    0.000000]   ok  |  ok  |
[    0.000000]     hard-safe-A + unsafe-B #2/312:### __debug_locks_off called!
[    0.000000] CPU: 0 PID: 0 Comm: swapper/0 Not tainted 3.12.6 #13
[    0.000000] Hardware name: Sony Corporation VGN-Z25TN_B/VAIO, BIOS R2140M3 08/26/2008
[    0.000000]  0000000000000000 ffffffff81c01cb0 ffffffff81747f7c ffffffff81c15c98
[    0.000000]  ffffffff81c01cc0 ffffffff81383d27 ffffffff81c01d50 ffffffff810d9adf
[    0.000000]  0000000000000000 ffffffff8288dec0 ffffffff824d43a8 0000000081c01d60
[    0.000000] Call Trace:
[    0.000000]  [<ffffffff81747f7c>] dump_stack+0x54/0x74
[    0.000000]  [<ffffffff81383d27>] debug_locks_off+0x17/0x50
[    0.000000]  [<ffffffff810d9adf>] check_usage_backwards+0x8f/0x1c0
[    0.000000]  [<ffffffff810da9c2>] mark_lock+0x412/0x820
[    0.000000]  [<ffffffff810d9a50>] ? check_usage_forwards+0x1c0/0x1c0
[    0.000000]  [<ffffffff810dbf68>] __lock_acquire+0x988/0x2190
[    0.000000]  [<ffffffff817511e7>] ? _raw_spin_unlock_irqrestore+0x67/0x70
[    0.000000]  [<ffffffff810c13b6>] ? vprintk_emit+0x1d6/0x630
[    0.000000]  [<ffffffff810de882>] lock_acquire+0xb2/0x160
[    0.000000]  [<ffffffff8138b72e>] ? irqsafe4_hard_spin_312+0xde/0x110
[    0.000000]  [<ffffffff8138b650>] ? irqsafe4_hard_rlock_312+0x110/0x110
[    0.000000]  [<ffffffff81750e96>] _raw_spin_lock+0x46/0x80
[    0.000000]  [<ffffffff8138b72e>] ? irqsafe4_hard_spin_312+0xde/0x110
[    0.000000]  [<ffffffff8138b72e>] irqsafe4_hard_spin_312+0xde/0x110
[    0.000000]  [<ffffffff817481f5>] dotest+0x43/0x5a7
[    0.000000]  [<ffffffff81399de0>] locking_selftest+0x1390/0x2100
[    0.000000]  [<ffffffff81f1aca9>] start_kernel+0x2d2/0x427
[    0.000000]  [<ffffffff81f1a120>] ? early_idt_handlers+0x120/0x120
[    0.000000]  [<ffffffff81f1a4c7>] x86_64_start_reservations+0x2a/0x2c
[    0.000000]  [<ffffffff81f1a5d6>] x86_64_start_kernel+0x10d/0x11c
[    0.000000] ### __debug_locks_off called!
[    0.000000] CPU: 0 PID: 0 Comm: swapper/0 Not tainted 3.12.6 #13
[    0.000000] Hardware name: Sony Corporation VGN-Z25TN_B/VAIO, BIOS R2140M3 08/26/2008
[    0.000000]  ffffffff81c15580 ffffffff81c01e78 ffffffff81747f7c ffffffff81cab258
[    0.000000]  ffffffff81c01e88 ffffffff81383d27 ffffffff81c01ed8 ffffffff810df595
[    0.000000]  0000000000000282 ffffffff8138b72e 0000000000000292 ffffffff81cab258
[    0.000000] Call Trace:
[    0.000000]  [<ffffffff81747f7c>] dump_stack+0x54/0x74
[    0.000000]  [<ffffffff81383d27>] debug_locks_off+0x17/0x50
[    0.000000]  [<ffffffff810df595>] lock_acquired+0x355/0x4d0
[    0.000000]  [<ffffffff8138b72e>] ? irqsafe4_hard_spin_312+0xde/0x110
[    0.000000]  [<ffffffff8138b650>] ? irqsafe4_hard_rlock_312+0x110/0x110
[    0.000000]  [<ffffffff81750ec2>] _raw_spin_lock+0x72/0x80
[    0.000000]  [<ffffffff8138b72e>] ? irqsafe4_hard_spin_312+0xde/0x110
[    0.000000]  [<ffffffff8138b72e>] irqsafe4_hard_spin_312+0xde/0x110
[    0.000000]  [<ffffffff817481f5>] dotest+0x43/0x5a7
[    0.000000]  [<ffffffff81399de0>] locking_selftest+0x1390/0x2100
[    0.000000]  [<ffffffff81f1aca9>] start_kernel+0x2d2/0x427
[    0.000000]  [<ffffffff81f1a120>] ? early_idt_handlers+0x120/0x120
[    0.000000]  [<ffffffff81f1a4c7>] 
[    0.000000]  [<ffffffff81f1a5d6>] x86_64_start_kernel+0x10d/0x11c
[    0.000000]   ok  |
[    0.000000] -------------------------------------------------------
[    0.000000] Good, all 253 testcases passed! |
[    0.000000] ---------------------------------
[    0.000000] hpet clockevent registered

Answer

Enable lock statistics

First of all be sure to enable lock statistics collecting. From Documentation/locking/lockstat.txt:

CONFIGURATION

Lock statistics are enabled via CONFIG_LOCK_STAT.

USAGE

Enable collection of statistics:
# echo 1 >/proc/sys/kernel/lock_stat
Disable collection of statistics:
# echo 0 >/proc/sys/kernel/lock_stat
Look at the current lock statistics:

( line numbers not part of actual output, done for clarity in the explanation below )
# less /proc/lock_stat

So, be sure to enable collection of lock statistics first.

Check lockdep warnings in kernel log

Now, let’s take a look at the code where your warning message is printing:

kernel/locking/lockdep_proc.c : seq_header():

if (unlikely(!debug_locks))
    seq_printf(m, "*WARNING* lock debugging disabled!! - possibly due to a lockdep warningn");

This debug_locks variable is being set to 0 (disabled) by debug_locks_off() function, which is in turn can be called from a lot of places. Let’s take a look at the place where this variable is defined:

lib/debug_locks.c:

/*
 * We want to turn all lock-debugging facilities on/off at once,
 * via a global flag. The reason is that once a single bug has been
 * detected and reported, there might be cascade of followup bugs
 * that would just muddy the log. So we report the first one and
 * shut up after that.
 */
int debug_locks = 1;
EXPORT_SYMBOL_GPL(debug_locks);

Comment for that variable explain why you see that warning.

So check your kernel log (via dmesg command) for actual found bugs by lockdep mechanism. You will probably find one, which will explain why lock debugging is disabled.

UPDATE

Regarding this message:

[ 0.084000] SMP alternatives: lockdep: fixing up alternatives

It seems like it has nothing to do with your actual issue. This message is printing by next code:

arch/x86/kernel/alternative.c : alternatives_enable_smp():

#ifdef CONFIG_LOCKDEP
   /*
    * Older binutils section handling bug prevented
    * alternatives-replacement from working reliably.
    *
    * If this still occurs then you should see a hang
    * or crash shortly after this line:
    */
   pr_info("lockdep: fixing up alternativesn");
#endif

This code is old and obsolete, and it’s dropped in newer kernel versions by this commit:

lockdep, x86/alternatives: Drop ancient lockdep fixup message

So I think it’s something else that leads to disabling of collecting lock statistics. It’s hard to tell what exactly though. The only thing I can think of is to modify kernel so that you can see what caused disabling of lock debug, rebuild kernel and look into the kernel log to figure out, where lock debug disabling was called from.

So, if you are up to this, modify __debug_locks_off() function as follows:

static inline int __debug_locks_off(void)
{
    /* ---- Add this code ---- */
    pr_err("### __debug_locks_off() called!n");
    dump_stack();
    /* ----------------------- */

    return xchg(&debug_locks, 0);
}

Also, add #include <linux/printk.h> line at the top of that file, just in case.

Then rebuild your kernel, run it and provide the whole dmesg output. It should be enough to tell where it’s been disabled.

UPDATE 2

As I can see from backtraces you provided, all the dump_stack() calls (that you added to __debug_locks_off() function) — they called from locking_selftest() function, which is in turn just some unit testing routine. Let’s take a look at it: locking_selftest(). What is important to notice here is this code:

} else {
    printk("-------------------------------------------------------n");
    printk("Good, all %3d testcases passed! |n",
        testcase_successes);
    printk("---------------------------------n");
    debug_locks = 1;
}

So you can see that in your case you have debug_locks variable enabled (“on”) in the end of the locking_selftest(). Taking into the account that all the messages you provided were actually triggered from locking_selftest() I can say that those messages couldn’t lead to your issue (which is disabled debug_locks variable).

So you still need to figure out, where and why (in your case) this debug_locks variable is disabled. Let’s start with this: please share complete dmesg output with us (you can use some pastebin service and just add the link to your question or as new comment). You may overlooked some __debug_locks_off() call in your dmesg output which was actually relevant (not called from that self-testing routine).

lookup the lock statistic in linux kernel

Advertisement

Answer

Enable lock statistics

Check lockdep warnings in kernel log

UPDATE

UPDATE 2