2008-07-31 09:42:07

by Zdenek Kabelac

[permalink] [raw]
Subject: INFO: possible recursive locking detected ps2_command

Hi

During mouse unplugging from psaux connector from the laptops' docking
station I've got attached INFO trace.
(laptops still has synaptics device)

Also for unknown reason to me psaux mouse & synaptic device do not
work somehow together - is it hw limitation
of /dev/input/mice interface?
(USB mouse and synaptics do work quite well together)

[ INFO: possible recursive locking detected ]
2.6.27-rc1 #48
---------------------------------------------
kseriod/166 is trying to acquire lock:
(&ps2dev->cmd_mutex){--..}, at: [<ffffffff8126e9ae>] ps2_command+0x5e/0x460

but task is already holding lock:
(&ps2dev->cmd_mutex){--..}, at: [<ffffffff8126e9ae>] ps2_command+0x5e/0x460

other info that might help us debug this:
4 locks held by kseriod/166:
#0: (serio_mutex){--..}, at: [<ffffffff8126cc1e>] serio_thread+0x3e/0x410
#1: (&serio->drv_mutex){--..}, at: [<ffffffff8126bf8b>]
serio_connect_driver+0x2b/0x50
#2: (psmouse_mutex){--..}, at: [<ffffffffa009aa00>]
psmouse_connect+0x30/0x2c0 [psmouse]
#3: (&ps2dev->cmd_mutex){--..}, at: [<ffffffff8126e9ae>]
ps2_command+0x5e/0x460

stack backtrace:
Pid: 166, comm: kseriod Not tainted 2.6.27-rc1 #48

Call Trace:
[<ffffffff81068bda>] __lock_acquire+0xcea/0x13b0
[<ffffffff81066401>] ? trace_hardirqs_off_caller+0x21/0xc0
[<ffffffff810664ad>] ? trace_hardirqs_off+0xd/0x10
[<ffffffff8126e9ae>] ? ps2_command+0x5e/0x460
[<ffffffff81069336>] lock_acquire+0x96/0xe0
[<ffffffff8126e9ae>] ? ps2_command+0x5e/0x460
[<ffffffff81313861>] mutex_lock_nested+0xc1/0x340
[<ffffffff8126e9ae>] ? ps2_command+0x5e/0x460
[<ffffffff810135a0>] ? native_sched_clock+0x90/0xb0
[<ffffffff8126e9ae>] ps2_command+0x5e/0x460
[<ffffffff81066401>] ? trace_hardirqs_off_caller+0x21/0xc0
[<ffffffff81065834>] ? get_lock_stats+0x34/0x70
[<ffffffffa009977d>] psmouse_sliced_command+0x2d/0x90 [psmouse]
[<ffffffff8126e838>] ? ps2_sendbyte+0x48/0x130
[<ffffffffa009b8f7>] synaptics_pt_write+0x27/0x60 [psmouse]
[<ffffffff81315acd>] ? _spin_unlock_irq+0x3d/0x80
[<ffffffff8126e84d>] ps2_sendbyte+0x5d/0x130
[<ffffffff81319840>] ? sub_preempt_count+0x80/0x120
[<ffffffff8126ea4d>] ps2_command+0xfd/0x460
[<ffffffff81319840>] ? sub_preempt_count+0x80/0x120
[<ffffffff81315acd>] ? _spin_unlock_irq+0x3d/0x80
[<ffffffffa0099917>] psmouse_probe+0x27/0xa0 [psmouse]
[<ffffffff8126c1e1>] ? serio_open+0x11/0x50
[<ffffffffa009ab48>] psmouse_connect+0x178/0x2c0 [psmouse]
[<ffffffff8126bf96>] serio_connect_driver+0x36/0x50
[<ffffffff8126bfcb>] serio_driver_probe+0x1b/0x20
[<ffffffff81221112>] driver_probe_device+0xa2/0x1e0
[<ffffffff812212e0>] ? __device_attach+0x0/0x10
[<ffffffff812212e9>] __device_attach+0x9/0x10
[<ffffffff8122050b>] bus_for_each_drv+0x6b/0xa0
[<ffffffff812213b8>] device_attach+0x88/0x90
[<ffffffff812202d5>] bus_attach_device+0x55/0x80
[<ffffffff8121ee99>] device_add+0x4f9/0x610
[<ffffffff81319840>] ? sub_preempt_count+0x80/0x120
[<ffffffff8126ce1c>] serio_thread+0x23c/0x410
[<ffffffff810571a0>] ? autoremove_wake_function+0x0/0x40
[<ffffffff8126cbe0>] ? serio_thread+0x0/0x410
[<ffffffff81056de9>] kthread+0x49/0x90
[<ffffffff8100d669>] child_rip+0xa/0x11
[<ffffffff8103b757>] ? finish_task_switch+0x57/0x110
[<ffffffff81315acd>] ? _spin_unlock_irq+0x3d/0x80
[<ffffffff8100cc73>] ? restore_args+0x0/0x30
[<ffffffff810664ad>] ? trace_hardirqs_off+0xd/0x10
[<ffffffff81056da0>] ? kthread+0x0/0x90
[<ffffffff8100d65f>] ? child_rip+0x0/0x11


2008-07-31 21:59:26

by Andrew Morton

[permalink] [raw]
Subject: Re: INFO: possible recursive locking detected ps2_command


(cc linux-input)

On Thu, 31 Jul 2008 11:41:25 +0200
"Zdenek Kabelac" <[email protected]> wrote:

> Hi
>
> During mouse unplugging from psaux connector from the laptops' docking
> station I've got attached INFO trace.
> (laptops still has synaptics device)
>
> Also for unknown reason to me psaux mouse & synaptic device do not
> work somehow together - is it hw limitation
> of /dev/input/mice interface?
> (USB mouse and synaptics do work quite well together)
>
> [ INFO: possible recursive locking detected ]
> 2.6.27-rc1 #48

(it's 2.6.27-rc1)

> ---------------------------------------------
> kseriod/166 is trying to acquire lock:
> (&ps2dev->cmd_mutex){--..}, at: [<ffffffff8126e9ae>] ps2_command+0x5e/0x460
>
> but task is already holding lock:
> (&ps2dev->cmd_mutex){--..}, at: [<ffffffff8126e9ae>] ps2_command+0x5e/0x460
>
> other info that might help us debug this:
> 4 locks held by kseriod/166:
> #0: (serio_mutex){--..}, at: [<ffffffff8126cc1e>] serio_thread+0x3e/0x410
> #1: (&serio->drv_mutex){--..}, at: [<ffffffff8126bf8b>]
> serio_connect_driver+0x2b/0x50
> #2: (psmouse_mutex){--..}, at: [<ffffffffa009aa00>]
> psmouse_connect+0x30/0x2c0 [psmouse]
> #3: (&ps2dev->cmd_mutex){--..}, at: [<ffffffff8126e9ae>]
> ps2_command+0x5e/0x460
>
> stack backtrace:
> Pid: 166, comm: kseriod Not tainted 2.6.27-rc1 #48
>
> Call Trace:
> [<ffffffff81068bda>] __lock_acquire+0xcea/0x13b0
> [<ffffffff81066401>] ? trace_hardirqs_off_caller+0x21/0xc0
> [<ffffffff810664ad>] ? trace_hardirqs_off+0xd/0x10
> [<ffffffff8126e9ae>] ? ps2_command+0x5e/0x460
> [<ffffffff81069336>] lock_acquire+0x96/0xe0
> [<ffffffff8126e9ae>] ? ps2_command+0x5e/0x460
> [<ffffffff81313861>] mutex_lock_nested+0xc1/0x340
> [<ffffffff8126e9ae>] ? ps2_command+0x5e/0x460
> [<ffffffff810135a0>] ? native_sched_clock+0x90/0xb0
> [<ffffffff8126e9ae>] ps2_command+0x5e/0x460
> [<ffffffff81066401>] ? trace_hardirqs_off_caller+0x21/0xc0
> [<ffffffff81065834>] ? get_lock_stats+0x34/0x70
> [<ffffffffa009977d>] psmouse_sliced_command+0x2d/0x90 [psmouse]
> [<ffffffff8126e838>] ? ps2_sendbyte+0x48/0x130
> [<ffffffffa009b8f7>] synaptics_pt_write+0x27/0x60 [psmouse]
> [<ffffffff81315acd>] ? _spin_unlock_irq+0x3d/0x80
> [<ffffffff8126e84d>] ps2_sendbyte+0x5d/0x130
> [<ffffffff81319840>] ? sub_preempt_count+0x80/0x120
> [<ffffffff8126ea4d>] ps2_command+0xfd/0x460
> [<ffffffff81319840>] ? sub_preempt_count+0x80/0x120
> [<ffffffff81315acd>] ? _spin_unlock_irq+0x3d/0x80
> [<ffffffffa0099917>] psmouse_probe+0x27/0xa0 [psmouse]
> [<ffffffff8126c1e1>] ? serio_open+0x11/0x50
> [<ffffffffa009ab48>] psmouse_connect+0x178/0x2c0 [psmouse]
> [<ffffffff8126bf96>] serio_connect_driver+0x36/0x50
> [<ffffffff8126bfcb>] serio_driver_probe+0x1b/0x20
> [<ffffffff81221112>] driver_probe_device+0xa2/0x1e0
> [<ffffffff812212e0>] ? __device_attach+0x0/0x10
> [<ffffffff812212e9>] __device_attach+0x9/0x10
> [<ffffffff8122050b>] bus_for_each_drv+0x6b/0xa0
> [<ffffffff812213b8>] device_attach+0x88/0x90
> [<ffffffff812202d5>] bus_attach_device+0x55/0x80
> [<ffffffff8121ee99>] device_add+0x4f9/0x610
> [<ffffffff81319840>] ? sub_preempt_count+0x80/0x120
> [<ffffffff8126ce1c>] serio_thread+0x23c/0x410
> [<ffffffff810571a0>] ? autoremove_wake_function+0x0/0x40
> [<ffffffff8126cbe0>] ? serio_thread+0x0/0x410
> [<ffffffff81056de9>] kthread+0x49/0x90
> [<ffffffff8100d669>] child_rip+0xa/0x11
> [<ffffffff8103b757>] ? finish_task_switch+0x57/0x110
> [<ffffffff81315acd>] ? _spin_unlock_irq+0x3d/0x80
> [<ffffffff8100cc73>] ? restore_args+0x0/0x30
> [<ffffffff810664ad>] ? trace_hardirqs_off+0xd/0x10
> [<ffffffff81056da0>] ? kthread+0x0/0x90
> [<ffffffff8100d65f>] ? child_rip+0x0/0x11

2008-08-01 03:04:58

by Dmitry Torokhov

[permalink] [raw]
Subject: Re: INFO: possible recursive locking detected ps2_command

On Thu, Jul 31, 2008 at 02:57:39PM -0700, Andrew Morton wrote:
>
> (cc linux-input)
>
> On Thu, 31 Jul 2008 11:41:25 +0200
> "Zdenek Kabelac" <[email protected]> wrote:
>
> > Hi
> >
> > During mouse unplugging from psaux connector from the laptops' docking
> > station I've got attached INFO trace.
> > (laptops still has synaptics device)
> >

Dell?

> > Also for unknown reason to me psaux mouse & synaptic device do not
> > work somehow together - is it hw limitation
> > of /dev/input/mice interface?
> > (USB mouse and synaptics do work quite well together)
> >
> > [ INFO: possible recursive locking detected ]
> > 2.6.27-rc1 #48
>
> (it's 2.6.27-rc1)
>

Peter, here is the trace we talked about long time ago. For some reason
lockdep annotation only works once. If reconnect is forced or psmouse
module is reloaded lockdep starts complaining about passthrough port.

> > ---------------------------------------------
> > kseriod/166 is trying to acquire lock:
> > (&ps2dev->cmd_mutex){--..}, at: [<ffffffff8126e9ae>] ps2_command+0x5e/0x460
> >
> > but task is already holding lock:
> > (&ps2dev->cmd_mutex){--..}, at: [<ffffffff8126e9ae>] ps2_command+0x5e/0x460
> >
> > other info that might help us debug this:
> > 4 locks held by kseriod/166:
> > #0: (serio_mutex){--..}, at: [<ffffffff8126cc1e>] serio_thread+0x3e/0x410
> > #1: (&serio->drv_mutex){--..}, at: [<ffffffff8126bf8b>]
> > serio_connect_driver+0x2b/0x50
> > #2: (psmouse_mutex){--..}, at: [<ffffffffa009aa00>]
> > psmouse_connect+0x30/0x2c0 [psmouse]
> > #3: (&ps2dev->cmd_mutex){--..}, at: [<ffffffff8126e9ae>]
> > ps2_command+0x5e/0x460
> >
> > stack backtrace:
> > Pid: 166, comm: kseriod Not tainted 2.6.27-rc1 #48
> >
> > Call Trace:
> > [<ffffffff81068bda>] __lock_acquire+0xcea/0x13b0
> > [<ffffffff81066401>] ? trace_hardirqs_off_caller+0x21/0xc0
> > [<ffffffff810664ad>] ? trace_hardirqs_off+0xd/0x10
> > [<ffffffff8126e9ae>] ? ps2_command+0x5e/0x460
> > [<ffffffff81069336>] lock_acquire+0x96/0xe0
> > [<ffffffff8126e9ae>] ? ps2_command+0x5e/0x460
> > [<ffffffff81313861>] mutex_lock_nested+0xc1/0x340
> > [<ffffffff8126e9ae>] ? ps2_command+0x5e/0x460
> > [<ffffffff810135a0>] ? native_sched_clock+0x90/0xb0
> > [<ffffffff8126e9ae>] ps2_command+0x5e/0x460
> > [<ffffffff81066401>] ? trace_hardirqs_off_caller+0x21/0xc0
> > [<ffffffff81065834>] ? get_lock_stats+0x34/0x70
> > [<ffffffffa009977d>] psmouse_sliced_command+0x2d/0x90 [psmouse]
> > [<ffffffff8126e838>] ? ps2_sendbyte+0x48/0x130
> > [<ffffffffa009b8f7>] synaptics_pt_write+0x27/0x60 [psmouse]
> > [<ffffffff81315acd>] ? _spin_unlock_irq+0x3d/0x80
> > [<ffffffff8126e84d>] ps2_sendbyte+0x5d/0x130
> > [<ffffffff81319840>] ? sub_preempt_count+0x80/0x120
> > [<ffffffff8126ea4d>] ps2_command+0xfd/0x460
> > [<ffffffff81319840>] ? sub_preempt_count+0x80/0x120
> > [<ffffffff81315acd>] ? _spin_unlock_irq+0x3d/0x80
> > [<ffffffffa0099917>] psmouse_probe+0x27/0xa0 [psmouse]
> > [<ffffffff8126c1e1>] ? serio_open+0x11/0x50
> > [<ffffffffa009ab48>] psmouse_connect+0x178/0x2c0 [psmouse]
> > [<ffffffff8126bf96>] serio_connect_driver+0x36/0x50
> > [<ffffffff8126bfcb>] serio_driver_probe+0x1b/0x20
> > [<ffffffff81221112>] driver_probe_device+0xa2/0x1e0
> > [<ffffffff812212e0>] ? __device_attach+0x0/0x10
> > [<ffffffff812212e9>] __device_attach+0x9/0x10
> > [<ffffffff8122050b>] bus_for_each_drv+0x6b/0xa0
> > [<ffffffff812213b8>] device_attach+0x88/0x90
> > [<ffffffff812202d5>] bus_attach_device+0x55/0x80
> > [<ffffffff8121ee99>] device_add+0x4f9/0x610
> > [<ffffffff81319840>] ? sub_preempt_count+0x80/0x120
> > [<ffffffff8126ce1c>] serio_thread+0x23c/0x410
> > [<ffffffff810571a0>] ? autoremove_wake_function+0x0/0x40
> > [<ffffffff8126cbe0>] ? serio_thread+0x0/0x410
> > [<ffffffff81056de9>] kthread+0x49/0x90
> > [<ffffffff8100d669>] child_rip+0xa/0x11
> > [<ffffffff8103b757>] ? finish_task_switch+0x57/0x110
> > [<ffffffff81315acd>] ? _spin_unlock_irq+0x3d/0x80
> > [<ffffffff8100cc73>] ? restore_args+0x0/0x30
> > [<ffffffff810664ad>] ? trace_hardirqs_off+0xd/0x10
> > [<ffffffff81056da0>] ? kthread+0x0/0x90
> > [<ffffffff8100d65f>] ? child_rip+0x0/0x11
>
> --
> To unsubscribe from this list: send the line "unsubscribe linux-input" in
> the body of a message to [email protected]
> More majordomo info at http://vger.kernel.org/majordomo-info.html

--
Dmitry

2008-08-08 10:50:20

by Peter Zijlstra

[permalink] [raw]
Subject: Re: INFO: possible recursive locking detected ps2_command

On Thu, 2008-07-31 at 23:04 -0400, Dmitry Torokhov wrote:
> On Thu, Jul 31, 2008 at 02:57:39PM -0700, Andrew Morton wrote:
> >
> > (cc linux-input)
> >
> > On Thu, 31 Jul 2008 11:41:25 +0200
> > "Zdenek Kabelac" <[email protected]> wrote:
> >
> > > Hi
> > >
> > > During mouse unplugging from psaux connector from the laptops' docking
> > > station I've got attached INFO trace.
> > > (laptops still has synaptics device)
> > >
>
> Dell?
>
> > > Also for unknown reason to me psaux mouse & synaptic device do not
> > > work somehow together - is it hw limitation
> > > of /dev/input/mice interface?
> > > (USB mouse and synaptics do work quite well together)
> > >
> > > [ INFO: possible recursive locking detected ]
> > > 2.6.27-rc1 #48
> >
> > (it's 2.6.27-rc1)
> >
>
> Peter, here is the trace we talked about long time ago. For some reason
> lockdep annotation only works once. If reconnect is forced or psmouse
> module is reloaded lockdep starts complaining about passthrough port.

Bit puzzling - and I don't have any ps2 hardware around to test with
(nor do I normally use modules - but that is fixable of course).

Does Rabin's patch help?

http://lkml.org/lkml/2008/8/7/329

> > > ---------------------------------------------
> > > kseriod/166 is trying to acquire lock:
> > > (&ps2dev->cmd_mutex){--..}, at: [<ffffffff8126e9ae>] ps2_command+0x5e/0x460
> > >
> > > but task is already holding lock:
> > > (&ps2dev->cmd_mutex){--..}, at: [<ffffffff8126e9ae>] ps2_command+0x5e/0x460
> > >
> > > other info that might help us debug this:
> > > 4 locks held by kseriod/166:
> > > #0: (serio_mutex){--..}, at: [<ffffffff8126cc1e>] serio_thread+0x3e/0x410
> > > #1: (&serio->drv_mutex){--..}, at: [<ffffffff8126bf8b>]
> > > serio_connect_driver+0x2b/0x50
> > > #2: (psmouse_mutex){--..}, at: [<ffffffffa009aa00>]
> > > psmouse_connect+0x30/0x2c0 [psmouse]
> > > #3: (&ps2dev->cmd_mutex){--..}, at: [<ffffffff8126e9ae>]
> > > ps2_command+0x5e/0x460
> > >
> > > stack backtrace:
> > > Pid: 166, comm: kseriod Not tainted 2.6.27-rc1 #48
> > >
> > > Call Trace:
> > > [<ffffffff81068bda>] __lock_acquire+0xcea/0x13b0
> > > [<ffffffff81066401>] ? trace_hardirqs_off_caller+0x21/0xc0
> > > [<ffffffff810664ad>] ? trace_hardirqs_off+0xd/0x10
> > > [<ffffffff8126e9ae>] ? ps2_command+0x5e/0x460
> > > [<ffffffff81069336>] lock_acquire+0x96/0xe0
> > > [<ffffffff8126e9ae>] ? ps2_command+0x5e/0x460
> > > [<ffffffff81313861>] mutex_lock_nested+0xc1/0x340
> > > [<ffffffff8126e9ae>] ? ps2_command+0x5e/0x460
> > > [<ffffffff810135a0>] ? native_sched_clock+0x90/0xb0
> > > [<ffffffff8126e9ae>] ps2_command+0x5e/0x460
> > > [<ffffffff81066401>] ? trace_hardirqs_off_caller+0x21/0xc0
> > > [<ffffffff81065834>] ? get_lock_stats+0x34/0x70
> > > [<ffffffffa009977d>] psmouse_sliced_command+0x2d/0x90 [psmouse]
> > > [<ffffffff8126e838>] ? ps2_sendbyte+0x48/0x130
> > > [<ffffffffa009b8f7>] synaptics_pt_write+0x27/0x60 [psmouse]
> > > [<ffffffff81315acd>] ? _spin_unlock_irq+0x3d/0x80
> > > [<ffffffff8126e84d>] ps2_sendbyte+0x5d/0x130
> > > [<ffffffff81319840>] ? sub_preempt_count+0x80/0x120
> > > [<ffffffff8126ea4d>] ps2_command+0xfd/0x460
> > > [<ffffffff81319840>] ? sub_preempt_count+0x80/0x120
> > > [<ffffffff81315acd>] ? _spin_unlock_irq+0x3d/0x80
> > > [<ffffffffa0099917>] psmouse_probe+0x27/0xa0 [psmouse]
> > > [<ffffffff8126c1e1>] ? serio_open+0x11/0x50
> > > [<ffffffffa009ab48>] psmouse_connect+0x178/0x2c0 [psmouse]
> > > [<ffffffff8126bf96>] serio_connect_driver+0x36/0x50
> > > [<ffffffff8126bfcb>] serio_driver_probe+0x1b/0x20
> > > [<ffffffff81221112>] driver_probe_device+0xa2/0x1e0
> > > [<ffffffff812212e0>] ? __device_attach+0x0/0x10
> > > [<ffffffff812212e9>] __device_attach+0x9/0x10
> > > [<ffffffff8122050b>] bus_for_each_drv+0x6b/0xa0
> > > [<ffffffff812213b8>] device_attach+0x88/0x90
> > > [<ffffffff812202d5>] bus_attach_device+0x55/0x80
> > > [<ffffffff8121ee99>] device_add+0x4f9/0x610
> > > [<ffffffff81319840>] ? sub_preempt_count+0x80/0x120
> > > [<ffffffff8126ce1c>] serio_thread+0x23c/0x410
> > > [<ffffffff810571a0>] ? autoremove_wake_function+0x0/0x40
> > > [<ffffffff8126cbe0>] ? serio_thread+0x0/0x410
> > > [<ffffffff81056de9>] kthread+0x49/0x90
> > > [<ffffffff8100d669>] child_rip+0xa/0x11
> > > [<ffffffff8103b757>] ? finish_task_switch+0x57/0x110
> > > [<ffffffff81315acd>] ? _spin_unlock_irq+0x3d/0x80
> > > [<ffffffff8100cc73>] ? restore_args+0x0/0x30
> > > [<ffffffff810664ad>] ? trace_hardirqs_off+0xd/0x10
> > > [<ffffffff81056da0>] ? kthread+0x0/0x90
> > > [<ffffffff8100d65f>] ? child_rip+0x0/0x11

2008-08-08 12:44:53

by Dmitry Torokhov

[permalink] [raw]
Subject: Re: INFO: possible recursive locking detected ps2_command

On Fri, Aug 08, 2008 at 12:49:49PM +0200, Peter Zijlstra wrote:
> On Thu, 2008-07-31 at 23:04 -0400, Dmitry Torokhov wrote:
> > On Thu, Jul 31, 2008 at 02:57:39PM -0700, Andrew Morton wrote:
> > >
> > > (cc linux-input)
> > >
> > > On Thu, 31 Jul 2008 11:41:25 +0200
> > > "Zdenek Kabelac" <[email protected]> wrote:
> > >
> > > > Hi
> > > >
> > > > During mouse unplugging from psaux connector from the laptops' docking
> > > > station I've got attached INFO trace.
> > > > (laptops still has synaptics device)
> > > >
> >
> > Dell?
> >
> > > > Also for unknown reason to me psaux mouse & synaptic device do not
> > > > work somehow together - is it hw limitation
> > > > of /dev/input/mice interface?
> > > > (USB mouse and synaptics do work quite well together)
> > > >
> > > > [ INFO: possible recursive locking detected ]
> > > > 2.6.27-rc1 #48
> > >
> > > (it's 2.6.27-rc1)
> > >
> >
> > Peter, here is the trace we talked about long time ago. For some reason
> > lockdep annotation only works once. If reconnect is forced or psmouse
> > module is reloaded lockdep starts complaining about passthrough port.
>
> Bit puzzling - and I don't have any ps2 hardware around to test with
> (nor do I normally use modules - but that is fixable of course).
>
> Does Rabin's patch help?
>
> http://lkml.org/lkml/2008/8/7/329
>

I doubt it resolves problem fully because it only takes care of module
unload. I can easily trip lockdep by reconnecting the device. Just to
give some more details about the problem:

- synaptics touchpads have a pass-through port that allows to connect
either external mouse or maybe a trackpoint device. Both devices
are represented by 'serio' structures and are handled by the same
driver (psmouse).

- as far as I know we have proper locking there and lockdep
annotatinos were added to lockdep to reflect the nesting of the
serio ports.

- if child port (pass-through port) is destroyed and recreated (due
to module unload, or because user requested reconnect through sysfs
or system-initiated reconnect) lockdep starts complaining although
the new child port should still have the same "depth" as the old
one.

Thanks!

--
Dmitry

2009-09-03 22:48:46

by Zdenek Kabelac

[permalink] [raw]
Subject: Re: INFO: possible recursive locking detected ps2_command

2008/8/8 Dmitry Torokhov <[email protected]>:
> On Fri, Aug 08, 2008 at 12:49:49PM +0200, Peter Zijlstra wrote:
>> On Thu, 2008-07-31 at 23:04 -0400, Dmitry Torokhov wrote:
>> > On Thu, Jul 31, 2008 at 02:57:39PM -0700, Andrew Morton wrote:
>> > >
>> > > (cc linux-input)
>> > >
>> > > On Thu, 31 Jul 2008 11:41:25 +0200
>> > > "Zdenek Kabelac" <[email protected]> wrote:
>> > >
>> > > > Hi
>> > > >
>> > > > During mouse unplugging from psaux connector from the laptops' docking
>> > > > station I've got attached INFO trace.
>> > > > (laptops still has synaptics device)
>> > > >
>> >
>> > Dell?
>> >
>> > > > Also for unknown reason to me ?psaux mouse & synaptic device do not
>> > > > work somehow together - is it hw limitation
>> > > > of /dev/input/mice ?interface?
>> > > > (USB mouse and synaptics do work quite well together)
>> > > >
>> > > > [ INFO: possible recursive locking detected ]
>> > > > 2.6.27-rc1 #48
>> > >
>> > > (it's 2.6.27-rc1)
>> > >
>> >
>> > Peter, here is the trace we talked about long time ago. For some reason
>> > lockdep annotation only works once. If reconnect is forced or psmouse
>> > module is reloaded lockdep starts complaining about passthrough port.
>>
>> Bit puzzling - and I don't have any ps2 hardware around to test with
>> (nor do I normally use modules - but that is fixable of course).
>>
>> Does Rabin's patch help?
>>
>> ? http://lkml.org/lkml/2008/8/7/329
>>
>
> I doubt it resolves problem fully because it only takes care of module
> unload. I can easily trip lockdep by reconnecting the device. Just to
> give some more details about the problem:
>
> ?- synaptics touchpads have a pass-through port that allows to connect
> ? either external mouse or maybe a trackpoint device. Both devices
> ? are represented by 'serio' structures and are handled by the same
> ? driver (psmouse).
>
> ?- as far as I know we have proper locking there and lockdep
> ? annotatinos were added to lockdep to reflect the nesting of the
> ? serio ports.
>
> ?- if child port (pass-through port) is destroyed and recreated (due
> ? to module unload, or because user requested reconnect through sysfs
> ? or system-initiated reconnect) lockdep starts complaining although
> ? the new child port should still have the same "depth" as the old
> ? one.
>

Well just noticed this issue again in my log - during resume operation
- thus no external mouse connection in the game this time:

platform dock.2: completing resume
platform dock.1: completing resume
platform dock.0: completing resume
PM: Finishing wakeup.
Restarting tasks ... done.
PM: Removing info for No Bus:vcs63
PM: Removing info for No Bus:vcsa63
psmouse.c: Failed to enable mouse on isa0060/serio1
PM: Removing info for No Bus:mouse1
PM: Removing info for No Bus:event8
PM: Removing info for No Bus:input8

=============================================
[ INFO: possible recursive locking detected ]
2.6.31-rc8-00043-gf2332bf #30
---------------------------------------------
kseriod/207 is trying to acquire lock:
(&ps2dev->cmd_mutex){+.+...}, at: [<ffffffff8132675b>] ps2_command+0x5b/0x470

but task is already holding lock:
(&ps2dev->cmd_mutex){+.+...}, at: [<ffffffff8132675b>] ps2_command+0x5b/0x470

other info that might help us debug this:
4 locks held by kseriod/207:
#0: (serio_mutex){+.+.+.}, at: [<ffffffff8132453e>] serio_thread+0x3e/0x400
#1: (&serio->drv_mutex){+.+.+.}, at: [<ffffffff81323b00>]
serio_connect_driver+0x30/0x60
#2: (psmouse_mutex){+.+.+.}, at: [<ffffffffa00c5f85>]
psmouse_connect+0x35/0x370 [psmouse]
#3: (&ps2dev->cmd_mutex){+.+...}, at: [<ffffffff8132675b>]
ps2_command+0x5b/0x470

stack backtrace:
Pid: 207, comm: kseriod Not tainted 2.6.31-rc8-00043-gf2332bf #30
Call Trace:
[<ffffffff8107f0ba>] __lock_acquire+0xe6a/0x1090
[<ffffffff8107f37a>] lock_acquire+0x9a/0x180
[<ffffffff8132675b>] ? ps2_command+0x5b/0x470
[<ffffffff813da81f>] __mutex_lock_common+0x5f/0x4a0
[<ffffffff8132675b>] ? ps2_command+0x5b/0x470
[<ffffffff8100f4b8>] ? dump_trace+0x118/0x2f0
[<ffffffff8132675b>] ? ps2_command+0x5b/0x470
[<ffffffff813dad41>] mutex_lock_nested+0x41/0x50
[<ffffffff8132675b>] ps2_command+0x5b/0x470
[<ffffffffa00c47b3>] psmouse_sliced_command+0x33/0x90 [psmouse]
[<ffffffffa00c6a9c>] synaptics_pt_write+0x2c/0x60 [psmouse]
[<ffffffff81326636>] ps2_sendbyte+0x66/0x130
[<ffffffff8107d7ed>] ? trace_hardirqs_on_caller+0x15d/0x1a0
[<ffffffff8107d83d>] ? trace_hardirqs_on+0xd/0x10
[<ffffffff813267f9>] ps2_command+0xf9/0x470
[<ffffffff8107d83d>] ? trace_hardirqs_on+0xd/0x10
[<ffffffff813dcbbb>] ? _spin_unlock_irq+0x3b/0x60
[<ffffffffa00c494c>] psmouse_probe+0x2c/0xa0 [psmouse]
[<ffffffff81323d86>] ? serio_open+0x16/0x50
[<ffffffffa00c6108>] psmouse_connect+0x1b8/0x370 [psmouse]
[<ffffffff81323b0b>] serio_connect_driver+0x3b/0x60
[<ffffffff81323b50>] serio_driver_probe+0x20/0x30
[<ffffffff812d2379>] driver_probe_device+0x89/0x180
[<ffffffff812d2520>] ? __device_attach+0x0/0x60
[<ffffffff812d2573>] __device_attach+0x53/0x60
[<ffffffff812d13dc>] bus_for_each_drv+0x6c/0xa0
[<ffffffff812d2639>] device_attach+0x89/0x90
[<ffffffff81323cbd>] serio_find_driver+0x1d/0x50
[<ffffffff813240c7>] serio_reconnect_port+0x57/0x90
[<ffffffff81324758>] serio_thread+0x258/0x400
[<ffffffff81069540>] ? autoremove_wake_function+0x0/0x40
[<ffffffff81324500>] ? serio_thread+0x0/0x400
[<ffffffff810690e6>] kthread+0xa6/0xb0
[<ffffffff8100d2da>] child_rip+0xa/0x20
[<ffffffff8100cc40>] ? restore_args+0x0/0x30
[<ffffffff81069040>] ? kthread+0x0/0xb0
[<ffffffff8100d2d0>] ? child_rip+0x0/0x20

2009-09-04 03:23:51

by Dmitry Torokhov

[permalink] [raw]
Subject: Re: INFO: possible recursive locking detected ps2_command

On Fri, Sep 04, 2009 at 12:48:45AM +0200, Zdenek Kabelac wrote:
> 2008/8/8 Dmitry Torokhov <[email protected]>:
> > On Fri, Aug 08, 2008 at 12:49:49PM +0200, Peter Zijlstra wrote:
> >> On Thu, 2008-07-31 at 23:04 -0400, Dmitry Torokhov wrote:
> >> > On Thu, Jul 31, 2008 at 02:57:39PM -0700, Andrew Morton wrote:
> >> > >
> >> > > (cc linux-input)
> >> > >
> >> > > On Thu, 31 Jul 2008 11:41:25 +0200
> >> > > "Zdenek Kabelac" <[email protected]> wrote:
> >> > >
> >> > > > Hi
> >> > > >
> >> > > > During mouse unplugging from psaux connector from the laptops' docking
> >> > > > station I've got attached INFO trace.
> >> > > > (laptops still has synaptics device)
> >> > > >
> >> >
> >> > Dell?
> >> >
> >> > > > Also for unknown reason to me ?psaux mouse & synaptic device do not
> >> > > > work somehow together - is it hw limitation
> >> > > > of /dev/input/mice ?interface?
> >> > > > (USB mouse and synaptics do work quite well together)
> >> > > >
> >> > > > [ INFO: possible recursive locking detected ]
> >> > > > 2.6.27-rc1 #48
> >> > >
> >> > > (it's 2.6.27-rc1)
> >> > >
> >> >
> >> > Peter, here is the trace we talked about long time ago. For some reason
> >> > lockdep annotation only works once. If reconnect is forced or psmouse
> >> > module is reloaded lockdep starts complaining about passthrough port.
> >>
> >> Bit puzzling - and I don't have any ps2 hardware around to test with
> >> (nor do I normally use modules - but that is fixable of course).
> >>
> >> Does Rabin's patch help?
> >>
> >> ? http://lkml.org/lkml/2008/8/7/329
> >>
> >
> > I doubt it resolves problem fully because it only takes care of module
> > unload. I can easily trip lockdep by reconnecting the device. Just to
> > give some more details about the problem:
> >
> > ?- synaptics touchpads have a pass-through port that allows to connect
> > ? either external mouse or maybe a trackpoint device. Both devices
> > ? are represented by 'serio' structures and are handled by the same
> > ? driver (psmouse).
> >
> > ?- as far as I know we have proper locking there and lockdep
> > ? annotatinos were added to lockdep to reflect the nesting of the
> > ? serio ports.
> >
> > ?- if child port (pass-through port) is destroyed and recreated (due
> > ? to module unload, or because user requested reconnect through sysfs
> > ? or system-initiated reconnect) lockdep starts complaining although
> > ? the new child port should still have the same "depth" as the old
> > ? one.
> >
>
> Well just noticed this issue again in my log - during resume operation
> - thus no external mouse connection in the game this time:
>

External mouse does not have to be connected, the fact that you have
a pass-through serio port is enough to trigger this warning.

--
Dmitry