-
Notifications
You must be signed in to change notification settings - Fork 130
Testing with lockdep
ABC edited this page Jun 10, 2014
·
3 revisions
Linux supports builtin lock validator lockdep. To enable it recompile the kernel with appropriate CONFIG_DEBUG_*
.config
options. Note that some options considerably slow down the kernel, so this is not suitable for production boxes. On my test set up I enabled only these:
debian6:/usr/src/linux-source-2.6.32# grep CONFIG_DEBUG .config
# CONFIG_DEBUG_PERF_USE_VMALLOC is not set
# CONFIG_DEBUG_DRIVER is not set
# CONFIG_DEBUG_DEVRES is not set
CONFIG_DEBUG_FS=y
CONFIG_DEBUG_KERNEL=y
# CONFIG_DEBUG_SHIRQ is not set
CONFIG_DEBUG_OBJECTS=y
# CONFIG_DEBUG_OBJECTS_SELFTEST is not set
# CONFIG_DEBUG_OBJECTS_FREE is not set
CONFIG_DEBUG_OBJECTS_TIMERS=y
CONFIG_DEBUG_OBJECTS_ENABLE_DEFAULT=1
CONFIG_DEBUG_RT_MUTEXES=y
CONFIG_DEBUG_PI_LIST=y
CONFIG_DEBUG_SPINLOCK=y
CONFIG_DEBUG_MUTEXES=y
CONFIG_DEBUG_LOCK_ALLOC=y
CONFIG_DEBUG_LOCKDEP=y
CONFIG_DEBUG_SPINLOCK_SLEEP=y
# CONFIG_DEBUG_LOCKING_API_SELFTESTS is not set
CONFIG_DEBUG_KOBJECT=y
CONFIG_DEBUG_BUGVERBOSE=y
CONFIG_DEBUG_INFO=y
# CONFIG_DEBUG_VM is not set
# CONFIG_DEBUG_VIRTUAL is not set
# CONFIG_DEBUG_WRITECOUNT is not set
CONFIG_DEBUG_MEMORY_INIT=y
CONFIG_DEBUG_LIST=y
# CONFIG_DEBUG_SG is not set
CONFIG_DEBUG_NOTIFIERS=y
# CONFIG_DEBUG_CREDENTIALS is not set
# CONFIG_DEBUG_BLOCK_EXT_DEVT is not set
# CONFIG_DEBUG_FORCE_WEAK_PER_CPU is not set
# CONFIG_DEBUG_PAGEALLOC is not set
CONFIG_DEBUG_STACKOVERFLOW=y
# CONFIG_DEBUG_STACK_USAGE is not set
# CONFIG_DEBUG_PER_CPU_MAPS is not set
CONFIG_DEBUG_RODATA=y
# CONFIG_DEBUG_RODATA_TEST is not set
# CONFIG_DEBUG_NX_TEST is not set
# CONFIG_DEBUG_BOOT_PARAMS is not set
If you encounter locking problem message will be written into dmesg
(and also in kern syslog or console if you configured these). Example message:
[ 1445.726890] =================================
[ 1445.728040] [ INFO: inconsistent lock state ]
[ 1445.728040] 2.6.32 #1
[ 1445.728040] ---------------------------------
[ 1445.728040] inconsistent {SOFTIRQ-ON-R} -> {IN-SOFTIRQ-W} usage.
[ 1445.728040] events/0/9 [HC0[0]:SC1[1]:HE1:SE0] takes:
[ 1445.728040] (clock-AF_INET){++-?..}, at: [<ffffffffa0353da7>] sk_error_report+0x42/0x8a [ipt_NETFLOW]
[ 1445.728040] {SOFTIRQ-ON-R} state was registered at:
[ 1445.728040] [<ffffffff8107d0b0>] __lock_acquire+0x33e/0xd29
[ 1445.728040] [<ffffffff8107db68>] lock_acquire+0xcd/0xf1
[ 1445.728040] [<ffffffff8132af4e>] _read_lock+0x2f/0x3e
[ 1445.728040] [<ffffffff8126a524>] sock_def_write_space+0x19/0x9e
[ 1445.728040] [<ffffffff8126b8ea>] sock_setsockopt+0x20e/0x5ac
[ 1445.728040] [<ffffffff812672b6>] sys_setsockopt+0x6f/0x9f
[ 1445.728040] [<ffffffff81010b02>] system_call_fastpath+0x16/0x1b
[ 1445.728040] irq event stamp: 244536
[ 1445.728040] hardirqs last enabled at (244536): [<ffffffff81059118>] _local_bh_enable_ip+0xca/0xd5
[ 1445.728040] hardirqs last disabled at (244535): [<ffffffff810590ad>] _local_bh_enable_ip+0x5f/0xd5
[ 1445.728040] softirqs last enabled at (244474): [<ffffffff8127739a>] rcu_read_unlock_bh+0x21/0x23
[ 1445.728040] softirqs last disabled at (244475): [<ffffffff81011d6c>] call_softirq+0x1c/0x30
[ 1445.728040]
[ 1445.728040] other info that might help us debug this:
[ 1445.728040] 8 locks held by events/0/9:
[ 1445.728040] #0: (events){+.+.+.}, at: [<ffffffff810681e3>] worker_thread+0x1f7/0x342
[ 1445.728040] #1: ((netflow_work).work){+.+.+.}, at: [<ffffffff810681e3>] worker_thread+0x1f7/0x342
[ 1445.728040] #2: (sock_lock){+.+...}, at: [<ffffffffa0353e4d>] netflow_sendmsg+0x5e/0x1ee [ipt_NETFLOW]
[ 1445.728040] #3: (sk_lock-AF_INET){+.+.+.}, at: [<ffffffff812bd5bf>] udp_sendmsg+0x506/0x723
[ 1445.728040] #4: (rcu_read_lock){.+.+..}, at: [<ffffffff812746a4>] rcu_read_lock+0x0/0x30
[ 1445.728040] #5: (rcu_read_lock){.+.+..}, at: [<ffffffff812746a4>] rcu_read_lock+0x0/0x30
[ 1445.728040] #6: (rcu_read_lock){.+.+..}, at: [<ffffffff8129c6d7>] ip_local_deliver_finish+0x44/0x235
[ 1445.728040] #7: (rcu_read_lock){.+.+..}, at: [<ffffffff812c014f>] rcu_read_lock+0x0/0x30
[ 1445.728040]
[ 1445.728040] stack backtrace:
[ 1445.728040] Pid: 9, comm: events/0 Not tainted 2.6.32 #1
[ 1445.728040] Call Trace:
[ 1445.728040] <IRQ> [<ffffffff8107bc7a>] valid_state+0x17f/0x192
[ 1445.728040] [<ffffffff8107e50e>] ? check_usage_forwards+0x0/0x8a
[ 1445.728040] [<ffffffff8107bde6>] mark_lock+0x159/0x23d
[ 1445.728040] [<ffffffff8107d03c>] __lock_acquire+0x2ca/0xd29
[ 1445.728040] [<ffffffff8105309b>] ? release_console_sem+0x1b6/0x1e7
[ 1445.728040] [<ffffffffa0353da7>] ? sk_error_report+0x42/0x8a [ipt_NETFLOW]
[ 1445.728040] [<ffffffff8107db68>] lock_acquire+0xcd/0xf1
[ 1445.728040] [<ffffffffa0353da7>] ? sk_error_report+0x42/0x8a [ipt_NETFLOW]
[ 1445.728040] [<ffffffff8132ad4d>] _write_lock+0x2c/0x3b
[ 1445.728040] [<ffffffffa0353da7>] ? sk_error_report+0x42/0x8a [ipt_NETFLOW]
...
Just mail its full content to me for investigations. Preferable with module binary itself (ipt_NETFLOW.ko
), this is required to resolve strings like netflow_sendmsg+0x5e
into exact code line.