I study Linux lock mechanism recently, and want to see the lock holding and waiting time.
我最近研究了Linux锁机制，希望看到锁保持和等待时间。
So I turn on CONFIG_LOCK_STAT flag in the .config file via make menuconfig and after recompiling the kernel run the command:
因此，我通过make menuconfig打开.config文件中的CONFIG_LOCK_STAT标志，在重新编译内核之后，运行以下命令:
# 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.
只是不知道为什么，因为我已经打开了内核hack->锁会话中的所有标志。
P.S. The environment I use: kernel 3.12.6 (by uname -a).
我使用的环境:内核3.12.6(由uname -a)。
UPDATE: dmesg with __debug_locks_off() and dump_stack() on
更新:带有__debug_locks_off()和dump_stack()的dmesg
[ 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
2 个解决方案
#1
2
Enable lock statistics
First of all be sure to enable lock statistics collecting. From Documentation/locking/lockstat.txt:
首先，确保启用锁统计信息收集。从文档/锁定/ lockstat.txt:
- CONFIGURATION
- 配置
Lock statistics are enabled via
CONFIG_LOCK_STAT.通过CONFIG_LOCK_STAT启用锁统计数据。
- USAGE
- 使用
Enable collection of statistics:
启用统计信息的收集:
# echo 1 >/proc/sys/kernel/lock_statDisable collection of statistics:
禁用收集的数据:
# echo 0 >/proc/sys/kernel/lock_statLook 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():
内核/锁定/ lockdep_proc。c:seq_header():
if (unlikely(!debug_locks))
seq_printf(m, "*WARNING* lock debugging disabled!! - possibly due to a lockdep warning\n");
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:
通过debug_locks_off()函数将这个debug_locks变量设置为0(禁用)，这反过来可以从很多地方调用。让我们来看看这个变量的定义:
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.
因此，通过lockdep机制检查您的内核日志(通过dmesg命令)来查找实际发现的bug。您可能会找到一个，这将解释为什么锁调试被禁用。
UPDATE
Regarding this message:
关于这个信息:
[ 0.084000] SMP alternatives: lockdep: fixing up alternatives
SMP替代方案:lockdep:修复替代方案
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():
拱/ x86 /内核/选择。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 alternatives\n");
#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
lockdep, x86/替代:删除古老的lockdep修复消息
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.
所以我认为这是导致禁止收集锁统计信息的其他原因。很难说到底是怎么回事。我唯一能想到的就是修改内核，这样您就可以看到是什么原因导致了锁定调试、重新构建内核，并查看内核日志，以找出在哪里调用了lock debug禁用。
So, if you are up to this, modify __debug_locks_off() function as follows:
因此，如果您要进行此操作，请修改__debug_locks_off()函数，如下所示:
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.
此外,添加# include < linux / printk。在文件顶部的h>行，以防万一。
Then rebuild your kernel, run it and provide the whole dmesg output. It should be enough to tell where it's been disabled.
然后重新构建内核，运行它并提供整个dmesg输出。它应该足以告诉它在哪里被禁用。
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:
正如我从您提供的回溯中看到的，所有dump_stack()调用(您添加到__debug_locks_off()函数中)——它们从locking_selftest()函数中调用，这反过来只是一些单元测试例程。让我们看一下它:locking_selftest()。这里需要注意的是:
} 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).
因此，您可以看到，在locking_selftest()末尾启用了debug_locks变量(“on”)。考虑到您提供的所有消息实际上是由locking_selftest()触发的，我可以说这些消息不会导致您的问题(禁用了debug_locks变量)。
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).
所以您仍然需要弄清楚这个debug_locks变量在哪里以及为什么(在您的例子中)被禁用。让我们从以下内容开始:请与我们共享完整的dmesg输出(您可以使用一些pastebin服务并将链接添加到您的问题或作为新的注释)。您可能忽略了dmesg输出中的某些__debug_locks_off()调用，而这些调用实际上是相关的(不是从那个自测试例程中调用的)。
#2
0
You can set CONFIG_PROVE_RCU_REPEATEDLY=y which means "don't disable PROVE_RCU on first splat"
你可以设置config_prove_rcu_repeat =y意思是“不要在第一个splat上禁用PROVE_RCU”
#1
2
Enable lock statistics
First of all be sure to enable lock statistics collecting. From Documentation/locking/lockstat.txt:
首先，确保启用锁统计信息收集。从文档/锁定/ lockstat.txt:
- CONFIGURATION
- 配置
Lock statistics are enabled via
CONFIG_LOCK_STAT.通过CONFIG_LOCK_STAT启用锁统计数据。
- USAGE
- 使用
Enable collection of statistics:
启用统计信息的收集:
# echo 1 >/proc/sys/kernel/lock_statDisable collection of statistics:
禁用收集的数据:
# echo 0 >/proc/sys/kernel/lock_statLook 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():
内核/锁定/ lockdep_proc。c:seq_header():
if (unlikely(!debug_locks))
seq_printf(m, "*WARNING* lock debugging disabled!! - possibly due to a lockdep warning\n");
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:
通过debug_locks_off()函数将这个debug_locks变量设置为0(禁用)，这反过来可以从很多地方调用。让我们来看看这个变量的定义:
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.
因此，通过lockdep机制检查您的内核日志(通过dmesg命令)来查找实际发现的bug。您可能会找到一个，这将解释为什么锁调试被禁用。
UPDATE
Regarding this message:
关于这个信息:
[ 0.084000] SMP alternatives: lockdep: fixing up alternatives
SMP替代方案:lockdep:修复替代方案
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():
拱/ x86 /内核/选择。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 alternatives\n");
#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
lockdep, x86/替代:删除古老的lockdep修复消息
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.
所以我认为这是导致禁止收集锁统计信息的其他原因。很难说到底是怎么回事。我唯一能想到的就是修改内核，这样您就可以看到是什么原因导致了锁定调试、重新构建内核，并查看内核日志，以找出在哪里调用了lock debug禁用。
So, if you are up to this, modify __debug_locks_off() function as follows:
因此，如果您要进行此操作，请修改__debug_locks_off()函数，如下所示:
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.
此外,添加# include < linux / printk。在文件顶部的h>行，以防万一。
Then rebuild your kernel, run it and provide the whole dmesg output. It should be enough to tell where it's been disabled.
然后重新构建内核，运行它并提供整个dmesg输出。它应该足以告诉它在哪里被禁用。
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:
正如我从您提供的回溯中看到的，所有dump_stack()调用(您添加到__debug_locks_off()函数中)——它们从locking_selftest()函数中调用，这反过来只是一些单元测试例程。让我们看一下它:locking_selftest()。这里需要注意的是:
} 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).
因此，您可以看到，在locking_selftest()末尾启用了debug_locks变量(“on”)。考虑到您提供的所有消息实际上是由locking_selftest()触发的，我可以说这些消息不会导致您的问题(禁用了debug_locks变量)。
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).
所以您仍然需要弄清楚这个debug_locks变量在哪里以及为什么(在您的例子中)被禁用。让我们从以下内容开始:请与我们共享完整的dmesg输出(您可以使用一些pastebin服务并将链接添加到您的问题或作为新的注释)。您可能忽略了dmesg输出中的某些__debug_locks_off()调用，而这些调用实际上是相关的(不是从那个自测试例程中调用的)。
#2
0
You can set CONFIG_PROVE_RCU_REPEATEDLY=y which means "don't disable PROVE_RCU on first splat"
你可以设置config_prove_rcu_repeat =y意思是“不要在第一个splat上禁用PROVE_RCU”