"INFO: possible irq lock inversion dependency detected" in 2.6.29-git2
From: Grissiom
Date: Fri Mar 27 2009 - 22:32:48 EST
Hi all,
The attachment is the full dmesg. Key section follow:
[ 133.276235]
[ 133.276243] =========================================================
[ 133.276253] [ INFO: possible irq lock inversion dependency detected ]
[ 133.276262] 2.6.29-g14-rfkill-nophy-ledon-03652-g5d80f8e #87
[ 133.276268] ---------------------------------------------------------
[ 133.276274] swapper/0 just changed the state of lock:
[ 133.276281] (fasync_lock){..+.}, at: [<c01b7107>] kill_fasync+0x27/0x50
[ 133.276303] but this lock took another, hard-irq-unsafe lock in the past:
[ 133.276310] (&f->f_lock){--..}
[ 133.276316]
[ 133.276317] and interrupts could create inverse lock ordering between them.
[ 133.276321]
[ 133.276326]
[ 133.276327] other info that might help us debug this:
[ 133.276334] 4 locks held by swapper/0:
[ 133.276338] #0: (&serio->lock){++..}, at: [<c039c281>]
serio_interrupt+0x21/0x80
[ 133.276358] #1: (&dev->event_lock){++..}, at: [<c03a0ac0>]
input_event+0x40/0x70
[ 133.276373] #2: (rcu_read_lock){..--}, at: [<c039f220>]
input_pass_event+0x0/0xf0
[ 133.276390] #3: (rcu_read_lock){..--}, at: [<c03a3be0>]
evdev_event+0x0/0x110
[ 133.276407]
[ 133.276408] the first lock's dependencies:
[ 133.276413] -> (fasync_lock){..+.} ops: 0 {
[ 133.276425] initial-use at:
[ 133.276432] [<c0153761>]
__lock_acquire+0x151/0x1920
[ 133.276448] [<c0154f8e>]
lock_acquire+0x5e/0x80
[ 133.276459] [<c0506293>]
_write_lock_irq+0x43/0x50
[ 133.276472] [<c01b6b84>]
fasync_helper+0x24/0x140
[ 133.276483] [<c02d5775>]
tty_fasync+0x65/0x120
[ 133.276494] [<c02d7e66>]
tty_release_dev+0x66/0x4f0
[ 133.276505] [<c02d8302>]
tty_release+0x12/0x20
[ 133.276514] [<c01abe32>]
__fput+0xc2/0x1b0
[ 133.276526] [<c01abf3f>]
fput+0x1f/0x30
[ 133.276536] [<c01a8e17>]
filp_close+0x47/0x70
[ 133.276548] [<c01a8eb0>]
sys_close+0x70/0xd0
[ 133.276558] [<c010351a>]
syscall_call+0x7/0xb
[ 133.276570] [<ffffffff>] 0xffffffff
[ 133.276582] in-hardirq-R at:
[ 133.276587] [<c0153d0c>]
__lock_acquire+0x6fc/0x1920
[ 133.276598] [<c0154f8e>]
lock_acquire+0x5e/0x80
[ 133.276608] [<c050643d>]
_read_lock+0x3d/0x50
[ 133.276618] [<c01b7107>]
kill_fasync+0x27/0x50
[ 133.276629] [<c03a38ef>]
evdev_pass_event+0x6f/0x80
[ 133.276638] [<c03a3c52>]
evdev_event+0x72/0x110
[ 133.276648] [<c039f284>]
input_pass_event+0x64/0xf0
[ 133.276659] [<c039f70d>]
input_handle_event+0x7d/0x420
[ 133.276670] [<c03a0ae0>]
input_event+0x60/0x70
[ 133.276679] [<c03a87a6>]
synaptics_process_byte+0x476/0x860
[ 133.276692] [<c03a6a7f>]
psmouse_handle_byte+0xf/0x110
[ 133.276703] [<c03a7874>]
psmouse_interrupt+0xc4/0x2b0
[ 133.276714] [<c039c29b>]
serio_interrupt+0x3b/0x80
[ 133.276724] [<c039d2e3>]
i8042_interrupt+0xb3/0x250
[ 133.276735] [<c016f6d9>]
handle_IRQ_event+0x39/0xa0
[ 133.276746] [<c0170ded>]
handle_edge_irq+0xad/0x140
[ 133.276756] [<c0104f9b>]
do_IRQ+0x4b/0x90
[ 133.276767] [<c0103aac>]
common_interrupt+0x2c/0x34
[ 133.276777] [<c010966b>]
c1e_idle+0x9b/0x100
[ 133.276788] [<c0102370>]
cpu_idle+0x70/0xb0
[ 133.276798] [<c04f2547>]
rest_init+0x67/0x70
[ 133.276809] [<ffffffff>] 0xffffffff
[ 133.276817] }
[ 133.276821] ... key at: [<c068f6c4>] fasync_lock+0x10/0x1c
[ 133.276834] -> (&f->f_lock){--..} ops: 0 {
[ 133.276845] initial-use at:
[ 133.276851] [<c0153761>]
__lock_acquire+0x151/0x1920
[ 133.276862] [<c0154f8e>]
lock_acquire+0x5e/0x80
[ 133.276872] [<c050609d>]
_spin_lock+0x3d/0x50
[ 133.276883] [<c01b6bc8>]
fasync_helper+0x68/0x140
[ 133.276893] [<c02d5775>]
tty_fasync+0x65/0x120
[ 133.276902] [<c02d7e66>]
tty_release_dev+0x66/0x4f0
[ 133.276912] [<c02d8302>]
tty_release+0x12/0x20
[ 133.276921] [<c01abe32>]
__fput+0xc2/0x1b0
[ 133.276931] [<c01abf3f>]
fput+0x1f/0x30
[ 133.276941] [<c01a8e17>]
filp_close+0x47/0x70
[ 133.276951] [<c01a8eb0>]
sys_close+0x70/0xd0
[ 133.276961] [<c010351a>]
syscall_call+0x7/0xb
[ 133.276970] [<ffffffff>] 0xffffffff
[ 133.276979] softirq-on-W at:
[ 133.276984] [<c0153bed>]
__lock_acquire+0x5dd/0x1920
[ 133.276995] [<c0154f8e>]
lock_acquire+0x5e/0x80
[ 133.277006] [<c050609d>]
_spin_lock+0x3d/0x50
[ 133.277016] [<c01b7649>]
do_fcntl+0x329/0x3f0
[ 133.277027] [<c01b7752>]
sys_fcntl64+0x42/0x90
[ 133.277037] [<c010351a>]
syscall_call+0x7/0xb
[ 133.277046] [<ffffffff>] 0xffffffff
[ 133.277054] hardirq-on-W at:
[ 133.277059] [<c0153bc7>]
__lock_acquire+0x5b7/0x1920
[ 133.277069] [<c0154f8e>]
lock_acquire+0x5e/0x80
[ 133.277079] [<c050609d>]
_spin_lock+0x3d/0x50
[ 133.277089] [<c01b7649>]
do_fcntl+0x329/0x3f0
[ 133.277099] [<c01b7752>]
sys_fcntl64+0x42/0x90
[ 133.277109] [<c010351a>]
syscall_call+0x7/0xb
[ 133.277118] [<ffffffff>] 0xffffffff
[ 133.277127] }
[ 133.277130] ... key at: [<c0b2c388>] __key.20023+0x0/0x8
[ 133.277140] ... acquired at:
[ 133.277144] [<c01545ab>] __lock_acquire+0xf9b/0x1920
[ 133.277154] [<c0154f8e>] lock_acquire+0x5e/0x80
[ 133.277162] [<c050609d>] _spin_lock+0x3d/0x50
[ 133.277171] [<c01b6bc8>] fasync_helper+0x68/0x140
[ 133.277180] [<c02d5775>] tty_fasync+0x65/0x120
[ 133.277188] [<c02d7e66>] tty_release_dev+0x66/0x4f0
[ 133.277196] [<c02d8302>] tty_release+0x12/0x20
[ 133.277203] [<c01abe32>] __fput+0xc2/0x1b0
[ 133.277212] [<c01abf3f>] fput+0x1f/0x30
[ 133.277220] [<c01a8e17>] filp_close+0x47/0x70
[ 133.277228] [<c01a8eb0>] sys_close+0x70/0xd0
[ 133.277237] [<c010351a>] syscall_call+0x7/0xb
[ 133.277245] [<ffffffff>] 0xffffffff
[ 133.277252]
[ 133.277255]
[ 133.277256] the second lock's dependencies:
[ 133.277261] -> (&f->f_lock){--..} ops: 0 {
[ 133.277272] initial-use at:
[ 133.277277] [<c0153761>]
__lock_acquire+0x151/0x1920
[ 133.277287] [<c0154f8e>]
lock_acquire+0x5e/0x80
[ 133.277297] [<c050609d>]
_spin_lock+0x3d/0x50
[ 133.277307] [<c01b6bc8>]
fasync_helper+0x68/0x140
[ 133.277317] [<c02d5775>]
tty_fasync+0x65/0x120
[ 133.277326] [<c02d7e66>]
tty_release_dev+0x66/0x4f0
[ 133.277336] [<c02d8302>]
tty_release+0x12/0x20
[ 133.277345] [<c01abe32>]
__fput+0xc2/0x1b0
[ 133.277355] [<c01abf3f>]
fput+0x1f/0x30
[ 133.277365] [<c01a8e17>]
filp_close+0x47/0x70
[ 133.277375] [<c01a8eb0>]
sys_close+0x70/0xd0
[ 133.277384] [<c010351a>]
syscall_call+0x7/0xb
[ 133.277394] [<ffffffff>] 0xffffffff
[ 133.277402] softirq-on-W at:
[ 133.277408] [<c0153bed>]
__lock_acquire+0x5dd/0x1920
[ 133.277418] [<c0154f8e>]
lock_acquire+0x5e/0x80
[ 133.277429] [<c050609d>]
_spin_lock+0x3d/0x50
[ 133.277439] [<c01b7649>]
do_fcntl+0x329/0x3f0
[ 133.277449] [<c01b7752>]
sys_fcntl64+0x42/0x90
[ 133.277459] [<c010351a>]
syscall_call+0x7/0xb
[ 133.277468] [<ffffffff>] 0xffffffff
[ 133.277476] hardirq-on-W at:
[ 133.277482] [<c0153bc7>]
__lock_acquire+0x5b7/0x1920
[ 133.277492] [<c0154f8e>]
lock_acquire+0x5e/0x80
[ 133.277504] [<c050609d>]
_spin_lock+0x3d/0x50
[ 133.277514] [<c01b7649>]
do_fcntl+0x329/0x3f0
[ 133.277524] [<c01b7752>]
sys_fcntl64+0x42/0x90
[ 133.277534] [<c010351a>]
syscall_call+0x7/0xb
[ 133.277544] [<ffffffff>] 0xffffffff
[ 133.277552] }
[ 133.277556] ... key at: [<c0b2c388>] __key.20023+0x0/0x8
[ 133.277564]
[ 133.277565] stack backtrace:
[ 133.277573] Pid: 0, comm: swapper Not tainted
2.6.29-g14-rfkill-nophy-ledon-03652-g5d80f8e #87
[ 133.277580] Call Trace:
[ 133.277588] [<c0502887>] ? printk+0x18/0x1a
[ 133.277598] [<c0151b6d>] print_irq_inversion_bug+0x11d/0x190
[ 133.277607] [<c0151c47>] check_usage_forwards+0x67/0xb0
[ 133.277616] [<c0150f9a>] ? save_trace+0x3a/0xa0
[ 133.277624] [<c015223d>] mark_lock+0x4fd/0xc30
[ 133.277633] [<c0153d0c>] __lock_acquire+0x6fc/0x1920
[ 133.277643] [<c0154f8e>] lock_acquire+0x5e/0x80
[ 133.277651] [<c01b7107>] ? kill_fasync+0x27/0x50
[ 133.277660] [<c050643d>] _read_lock+0x3d/0x50
[ 133.277669] [<c01b7107>] ? kill_fasync+0x27/0x50
[ 133.277677] [<c01b7107>] kill_fasync+0x27/0x50
[ 133.277685] [<c03a38ef>] evdev_pass_event+0x6f/0x80
[ 133.277693] [<c03a3c52>] evdev_event+0x72/0x110
[ 133.277700] [<c03a3be0>] ? evdev_event+0x0/0x110
[ 133.277710] [<c039f284>] input_pass_event+0x64/0xf0
[ 133.277719] [<c039f220>] ? input_pass_event+0x0/0xf0
[ 133.277729] [<c039f70d>] input_handle_event+0x7d/0x420
[ 133.277736] [<c03a0ae0>] input_event+0x60/0x70
[ 133.277745] [<c03a87a6>] synaptics_process_byte+0x476/0x860
[ 133.277755] [<c03a6a7f>] psmouse_handle_byte+0xf/0x110
[ 133.277764] [<c03a7874>] psmouse_interrupt+0xc4/0x2b0
[ 133.277773] [<c050619d>] ? _spin_lock_irqsave+0x4d/0x60
[ 133.277782] [<c039c29b>] serio_interrupt+0x3b/0x80
[ 133.277791] [<c039d2e3>] i8042_interrupt+0xb3/0x250
[ 133.277799] [<c016f6d9>] handle_IRQ_event+0x39/0xa0
[ 133.277808] [<c0170ded>] handle_edge_irq+0xad/0x140
[ 133.277816] [<c0104f9b>] do_IRQ+0x4b/0x90
[ 133.277824] [<c0103aac>] common_interrupt+0x2c/0x34
[ 133.277833] [<c01094b7>] ? default_idle+0x57/0x60
[ 133.277842] [<c010966b>] c1e_idle+0x9b/0x100
[ 133.277850] [<c0102370>] cpu_idle+0x70/0xb0
[ 133.277857] [<c04f2547>] rest_init+0x67/0x70
Attachment:
dmesg
Description: Binary data