2014-01-26 10:47:21

by Sander Eikelenboom

[permalink] [raw]
Subject: 3.14-mw regression: circular locking dependency (&tty->legacy_mutex){+.+.+.}, at: [<ffffffff81ad6344>] tty_lock_nested+0x44/0xa0

Hi,

I have got a regression with a 3.14-mw kernel (last commit is 4ba9920e5e9c0e16b5ed24292d45322907bb9035)
when a script is started that reads from serial over bluetooth, that wasn't in the 3.13 release kernel:


Jan 26 11:36:10 serveerstertje kernel: [ 72.892926]
Jan 26 11:36:10 serveerstertje kernel: [ 72.900249] ======================================================
Jan 26 11:36:10 serveerstertje kernel: [ 72.907697] [ INFO: possible circular locking dependency detected ]
Jan 26 11:36:10 serveerstertje kernel: [ 72.915214] 3.13.0-20140125-mw-pcireset+ #1 Not tainted
Jan 26 11:36:10 serveerstertje kernel: [ 72.922307] -------------------------------------------------------
Jan 26 11:36:10 serveerstertje kernel: [ 72.928315] zabbix_slimmeme/5909 is trying to acquire lock:
Jan 26 11:36:10 serveerstertje kernel: [ 72.934323] (&tty->legacy_mutex){+.+.+.}, at: [<ffffffff81ad6344>] tty_lock_nested+0x44/0xa0
Jan 26 11:36:10 serveerstertje kernel: [ 72.940434]
Jan 26 11:36:10 serveerstertje kernel: [ 72.940434] but task is already holding lock:
Jan 26 11:36:10 serveerstertje kernel: [ 72.952263] (&port->mutex){+.+.+.}, at: [<ffffffff81518aa7>] tty_port_open+0x67/0xe0
Jan 26 11:36:10 serveerstertje kernel: [ 72.958292]
Jan 26 11:36:10 serveerstertje kernel: [ 72.958292] which lock already depends on the new lock.
Jan 26 11:36:10 serveerstertje kernel: [ 72.958292]
Jan 26 11:36:10 serveerstertje kernel: [ 72.976267]
Jan 26 11:36:10 serveerstertje kernel: [ 72.976267] the existing dependency chain (in reverse order) is:
Jan 26 11:36:10 serveerstertje kernel: [ 72.988276]
Jan 26 11:36:10 serveerstertje kernel: [ 72.988276] -> #1 (&port->mutex){+.+.+.}:
Jan 26 11:36:10 serveerstertje kernel: [ 73.000386] [<ffffffff81102dfd>] lock_acquire+0xcd/0x110
Jan 26 11:36:10 serveerstertje kernel: [ 73.006526] [<ffffffff81ad3f97>] mutex_lock_nested+0x47/0x560
Jan 26 11:36:10 serveerstertje kernel: [ 73.012612] [<ffffffff81518aa7>] tty_port_open+0x67/0xe0
Jan 26 11:36:10 serveerstertje kernel: [ 73.018637] [<ffffffff81aa4356>] rfcomm_tty_open+0x26/0xe0
Jan 26 11:36:10 serveerstertje kernel: [ 73.024674] [<ffffffff8150fcea>] tty_open+0x16a/0x5c0
Jan 26 11:36:10 serveerstertje kernel: [ 73.030748] [<ffffffff811b4013>] chrdev_open+0xa3/0x1c0
Jan 26 11:36:10 serveerstertje kernel: [ 73.036833] [<ffffffff811ad686>] do_dentry_open.isra.16+0x246/0x2f0
Jan 26 11:36:10 serveerstertje kernel: [ 73.043001] [<ffffffff811ad81d>] finish_open+0x1d/0x30
Jan 26 11:36:10 serveerstertje kernel: [ 73.049106] [<ffffffff811befae>] do_last+0x7ce/0xdf0
Jan 26 11:36:10 serveerstertje kernel: [ 73.055191] [<ffffffff811bf68d>] path_openat+0xbd/0x6b0
Jan 26 11:36:10 serveerstertje kernel: [ 73.061211] [<ffffffff811c004e>] do_filp_open+0x3e/0xa0
Jan 26 11:36:10 serveerstertje kernel: [ 73.067177] [<ffffffff811aeaec>] do_sys_open+0x13c/0x230
Jan 26 11:36:10 serveerstertje kernel: [ 73.073141] [<ffffffff811aebfd>] SyS_open+0x1d/0x20
Jan 26 11:36:10 serveerstertje kernel: [ 73.079047] [<ffffffff81ad6f39>] system_call_fastpath+0x16/0x1b
Jan 26 11:36:10 serveerstertje kernel: [ 73.084962]
Jan 26 11:36:10 serveerstertje kernel: [ 73.084962] -> #0 (&tty->legacy_mutex){+.+.+.}:
Jan 26 11:36:10 serveerstertje kernel: [ 73.096600] [<ffffffff8110230b>] __lock_acquire+0x1d4b/0x2220
Jan 26 11:36:10 serveerstertje kernel: [ 73.102559] [<ffffffff81102dfd>] lock_acquire+0xcd/0x110
Jan 26 11:36:10 serveerstertje kernel: [ 73.108475] [<ffffffff81ad3f97>] mutex_lock_nested+0x47/0x560
Jan 26 11:36:10 serveerstertje kernel: [ 73.114419] [<ffffffff81ad6344>] tty_lock_nested+0x44/0xa0
Jan 26 11:36:10 serveerstertje kernel: [ 73.120354] [<ffffffff81ad63ab>] tty_lock+0xb/0x10
Jan 26 11:36:10 serveerstertje kernel: [ 73.126258] [<ffffffff81aa4677>] rfcomm_dev_activate+0xb7/0x250
Jan 26 11:36:10 serveerstertje kernel: [ 73.132222] [<ffffffff81518ad7>] tty_port_open+0x97/0xe0
Jan 26 11:36:10 serveerstertje kernel: [ 73.138195] [<ffffffff81aa4356>] rfcomm_tty_open+0x26/0xe0
Jan 26 11:36:10 serveerstertje kernel: [ 73.144207] [<ffffffff8150fcea>] tty_open+0x16a/0x5c0
Jan 26 11:36:10 serveerstertje kernel: [ 73.150164] [<ffffffff811b4013>] chrdev_open+0xa3/0x1c0
Jan 26 11:36:10 serveerstertje kernel: [ 73.156127] [<ffffffff811ad686>] do_dentry_open.isra.16+0x246/0x2f0
Jan 26 11:36:10 serveerstertje kernel: [ 73.162070] [<ffffffff811ad81d>] finish_open+0x1d/0x30
Jan 26 11:36:10 serveerstertje kernel: [ 73.167933] [<ffffffff811befae>] do_last+0x7ce/0xdf0
Jan 26 11:36:10 serveerstertje kernel: [ 73.173787] [<ffffffff811bf68d>] path_openat+0xbd/0x6b0
Jan 26 11:36:10 serveerstertje kernel: [ 73.179600] [<ffffffff811c004e>] do_filp_open+0x3e/0xa0
Jan 26 11:36:10 serveerstertje kernel: [ 73.185302] [<ffffffff811aeaec>] do_sys_open+0x13c/0x230
Jan 26 11:36:10 serveerstertje kernel: [ 73.190880] [<ffffffff811aebfd>] SyS_open+0x1d/0x20
Jan 26 11:36:10 serveerstertje kernel: [ 73.196247] [<ffffffff81ad6f39>] system_call_fastpath+0x16/0x1b
Jan 26 11:36:10 serveerstertje kernel: [ 73.201486]
Jan 26 11:36:10 serveerstertje kernel: [ 73.201486] other info that might help us debug this:
Jan 26 11:36:10 serveerstertje kernel: [ 73.201486]
Jan 26 11:36:10 serveerstertje kernel: [ 73.216718] Possible unsafe locking scenario:
Jan 26 11:36:10 serveerstertje kernel: [ 73.216718]
Jan 26 11:36:10 serveerstertje kernel: [ 73.226933] CPU0 CPU1
Jan 26 11:36:10 serveerstertje kernel: [ 73.231978] ---- ----
Jan 26 11:36:10 serveerstertje kernel: [ 73.237001] lock(&port->mutex);
Jan 26 11:36:10 serveerstertje kernel: [ 73.241994] lock(&tty->legacy_mutex);
Jan 26 11:36:10 serveerstertje kernel: [ 73.247043] lock(&port->mutex);
Jan 26 11:36:10 serveerstertje kernel: [ 73.251999] lock(&tty->legacy_mutex);
Jan 26 11:36:10 serveerstertje kernel: [ 73.256902]
Jan 26 11:36:10 serveerstertje kernel: [ 73.256902] *** DEADLOCK ***
Jan 26 11:36:10 serveerstertje kernel: [ 73.256902]
Jan 26 11:36:10 serveerstertje kernel: [ 73.270890] 1 lock held by zabbix_slimmeme/5909:
Jan 26 11:36:10 serveerstertje kernel: [ 73.275398] #0: (&port->mutex){+.+.+.}, at: [<ffffffff81518aa7>] tty_port_open+0x67/0xe0
Jan 26 11:36:10 serveerstertje kernel: [ 73.280124]
Jan 26 11:36:10 serveerstertje kernel: [ 73.280124] stack backtrace:
Jan 26 11:36:10 serveerstertje kernel: [ 73.289130] CPU: 5 PID: 5909 Comm: zabbix_slimmeme Not tainted 3.13.0-20140125-mw-pcireset+ #1
Jan 26 11:36:10 serveerstertje kernel: [ 73.293860] Hardware name: MSI MS-7640/890FXA-GD70 (MS-7640) , BIOS V1.8B1 09/13/2010
Jan 26 11:36:10 serveerstertje kernel: [ 73.298625] ffffffff826e2b70 ffff88005858f818 ffffffff81acbcfa ffff880057c72300
Jan 26 11:36:10 serveerstertje kernel: [ 73.303571] ffffffff826e2b70 ffff88005858f868 ffffffff81ac7011 ffff880057c72300
Jan 26 11:36:10 serveerstertje kernel: [ 73.308511] ffff880057c72300 ffff88005858f868 ffff880057c72ac0 0000000000000000
Jan 26 11:36:10 serveerstertje kernel: [ 73.313325] Call Trace:
Jan 26 11:36:10 serveerstertje kernel: [ 73.318092] [<ffffffff81acbcfa>] dump_stack+0x46/0x58
Jan 26 11:36:10 serveerstertje kernel: [ 73.322900] [<ffffffff81ac7011>] print_circular_bug+0x2f6/0x32a
Jan 26 11:36:10 serveerstertje kernel: [ 73.327723] [<ffffffff8110230b>] __lock_acquire+0x1d4b/0x2220
Jan 26 11:36:10 serveerstertje kernel: [ 73.332545] [<ffffffff810fedbd>] ? trace_hardirqs_on+0xd/0x10
Jan 26 11:36:10 serveerstertje kernel: [ 73.337414] [<ffffffff810e6141>] ? finish_task_switch+0x41/0xf0
Jan 26 11:36:10 serveerstertje kernel: [ 73.342279] [<ffffffff81ad0244>] ? sleep_on_timeout+0x4/0x20
Jan 26 11:36:10 serveerstertje kernel: [ 73.347128] [<ffffffff81102dfd>] lock_acquire+0xcd/0x110
Jan 26 11:36:10 serveerstertje kernel: [ 73.351950] [<ffffffff81ad6344>] ? tty_lock_nested+0x44/0xa0
Jan 26 11:36:10 serveerstertje kernel: [ 73.356792] [<ffffffff81ad3f97>] mutex_lock_nested+0x47/0x560
Jan 26 11:36:10 serveerstertje kernel: [ 73.361599] [<ffffffff81ad6344>] ? tty_lock_nested+0x44/0xa0
Jan 26 11:36:10 serveerstertje kernel: [ 73.366363] [<ffffffff810fec6b>] ? trace_hardirqs_on_caller+0xfb/0x240
Jan 26 11:36:10 serveerstertje kernel: [ 73.371200] [<ffffffff810fedbd>] ? trace_hardirqs_on+0xd/0x10
Jan 26 11:36:10 serveerstertje kernel: [ 73.376030] [<ffffffff81ad6344>] tty_lock_nested+0x44/0xa0
Jan 26 11:36:10 serveerstertje kernel: [ 73.380842] [<ffffffff81ad63ab>] tty_lock+0xb/0x10
Jan 26 11:36:10 serveerstertje kernel: [ 73.385616] [<ffffffff81aa4677>] rfcomm_dev_activate+0xb7/0x250
Jan 26 11:36:10 serveerstertje kernel: [ 73.390398] [<ffffffff81ad4287>] ? mutex_lock_nested+0x337/0x560
Jan 26 11:36:10 serveerstertje kernel: [ 73.395154] [<ffffffff810f90f0>] ? __init_waitqueue_head+0x60/0x60
Jan 26 11:36:10 serveerstertje kernel: [ 73.399861] [<ffffffff81518ad7>] tty_port_open+0x97/0xe0
Jan 26 11:36:10 serveerstertje kernel: [ 73.404552] [<ffffffff81aa4356>] rfcomm_tty_open+0x26/0xe0
Jan 26 11:36:10 serveerstertje kernel: [ 73.409263] [<ffffffff8150fcea>] tty_open+0x16a/0x5c0
Jan 26 11:36:10 serveerstertje kernel: [ 73.413954] [<ffffffff811b4013>] chrdev_open+0xa3/0x1c0
Jan 26 11:36:10 serveerstertje kernel: [ 73.418657] [<ffffffff81457bfd>] ? lockref_get+0x1d/0x30
Jan 26 11:36:10 serveerstertje kernel: [ 73.423379] [<ffffffff811b3f70>] ? cdev_put+0x30/0x30
Jan 26 11:36:10 serveerstertje kernel: [ 73.428056] [<ffffffff811ad686>] do_dentry_open.isra.16+0x246/0x2f0
Jan 26 11:36:10 serveerstertje kernel: [ 73.432768] [<ffffffff811ad81d>] finish_open+0x1d/0x30
Jan 26 11:36:10 serveerstertje kernel: [ 73.437464] [<ffffffff811befae>] do_last+0x7ce/0xdf0
Jan 26 11:36:10 serveerstertje kernel: [ 73.442166] [<ffffffff811baff3>] ? inode_permission+0x13/0x50
Jan 26 11:36:10 serveerstertje kernel: [ 73.446861] [<ffffffff811bb5ce>] ? link_path_walk+0x21e/0x880
Jan 26 11:36:10 serveerstertje kernel: [ 73.451533] [<ffffffff810fec6b>] ? trace_hardirqs_on_caller+0xfb/0x240
Jan 26 11:36:10 serveerstertje kernel: [ 73.456280] [<ffffffff811bf68d>] path_openat+0xbd/0x6b0
Jan 26 11:36:10 serveerstertje kernel: [ 73.461029] [<ffffffff8104cb03>] ? __do_page_fault+0x103/0x4e0
Jan 26 11:36:10 serveerstertje kernel: [ 73.465782] [<ffffffff81102e1d>] ? lock_acquire+0xed/0x110
Jan 26 11:36:10 serveerstertje kernel: [ 73.470553] [<ffffffff811c004e>] do_filp_open+0x3e/0xa0
Jan 26 11:36:10 serveerstertje kernel: [ 73.475321] [<ffffffff811cda31>] ? __alloc_fd+0xd1/0x120
Jan 26 11:36:10 serveerstertje kernel: [ 73.480064] [<ffffffff811aeaec>] do_sys_open+0x13c/0x230
Jan 26 11:36:10 serveerstertje kernel: [ 73.484743] [<ffffffff810fec6b>] ? trace_hardirqs_on_caller+0xfb/0x240
Jan 26 11:36:10 serveerstertje kernel: [ 73.489470] [<ffffffff811aebfd>] SyS_open+0x1d/0x20
Jan 26 11:36:10 serveerstertje kernel: [ 73.494191] [<ffffffff81ad6f39>] system_call_fastpath+0x16/0x1b


2014-02-07 06:55:30

by Gianluca Anzolin

[permalink] [raw]
Subject: Re: BISECTED Re: 3.14-mw regression: circular locking dependency (&tty->legacy_mutex){+.+.+.}, at: [<ffffffff81ad6344>] tty_lock_nested+0x44/0xa0

Hi Sander,

On Fri, Feb 07, 2014 at 01:37:50AM +0100, Sander Eikelenboom wrote:
> Hi Marcel / Gianluca,
>
> Bisection points to this commit:
>
> 4a2fb3ecc7467c775b154813861f25a0ddc11aa0 is the first bad commit
> commit 4a2fb3ecc7467c775b154813861f25a0ddc11aa0
> Author: Gianluca Anzolin <[email protected]>
> Date: Mon Jan 6 21:23:52 2014 +0100

Thank you for you report. I'm aware of this bug, no need to investigate
further.

This and other bugs are being tackled by Peter Hurley, who knows the tty
code way better than me.

You just have to wait for his patches, I think they will come shortly.

Thank you,

Gianluca

2014-02-07 00:37:50

by Sander Eikelenboom

[permalink] [raw]
Subject: BISECTED Re: 3.14-mw regression: circular locking dependency (&tty->legacy_mutex){+.+.+.}, at: [<ffffffff81ad6344>] tty_lock_nested+0x44/0xa0

Hi Marcel / Gianluca,

Bisection points to this commit:

4a2fb3ecc7467c775b154813861f25a0ddc11aa0 is the first bad commit
commit 4a2fb3ecc7467c775b154813861f25a0ddc11aa0
Author: Gianluca Anzolin <[email protected]>
Date: Mon Jan 6 21:23:52 2014 +0100

Bluetooth: Always wait for a connection on RFCOMM open()

This patch fixes two regressions introduced with the recent rfcomm tty
rework.

The current code uses the carrier_raised() method to wait for the
bluetooth connection when a process opens the tty.

However processes may open the port with the O_NONBLOCK flag or set the
CLOCAL termios flag: in these cases the open() syscall returns
immediately without waiting for the bluetooth connection to
complete.

This behaviour confuses userspace which expects an established bluetooth
connection.

The patch restores the old behaviour by waiting for the connection in
rfcomm_dev_activate() and removes carrier_raised() from the tty_port ops.

As a side effect the new code also fixes the case in which the rfcomm
tty device is created with the flag RFCOMM_REUSE_DLC: the old code
didn't call device_move() and ModemManager skipped the detection
probe. Now device_move() is always called inside rfcomm_dev_activate().

Signed-off-by: Gianluca Anzolin <[email protected]>
Reported-by: Andrey Vihrov <[email protected]>
Reported-by: Beson Chow <[email protected]>
Signed-off-by: Marcel Holtmann <[email protected]>

BTW perhaps time to update your tree ?
Bisection took me back to 3.12 like areas .. the risk of bisection failing of other unrelated bugs seems to increase that way



Sunday, January 26, 2014, 11:47:21 AM, you wrote:

> Hi,

> I have got a regression with a 3.14-mw kernel (last commit is 4ba9920e5e9c0e16b5ed24292d45322907bb9035)
> when a script is started that reads from serial over bluetooth, that wasn't in the 3.13 release kernel:


> Jan 26 11:36:10 serveerstertje kernel: [ 72.892926]
> Jan 26 11:36:10 serveerstertje kernel: [ 72.900249] ======================================================
> Jan 26 11:36:10 serveerstertje kernel: [ 72.907697] [ INFO: possible circular locking dependency detected ]
> Jan 26 11:36:10 serveerstertje kernel: [ 72.915214] 3.13.0-20140125-mw-pcireset+ #1 Not tainted
> Jan 26 11:36:10 serveerstertje kernel: [ 72.922307] -------------------------------------------------------
> Jan 26 11:36:10 serveerstertje kernel: [ 72.928315] zabbix_slimmeme/5909 is trying to acquire lock:
> Jan 26 11:36:10 serveerstertje kernel: [ 72.934323] (&tty->legacy_mutex){+.+.+.}, at: [<ffffffff81ad6344>] tty_lock_nested+0x44/0xa0
> Jan 26 11:36:10 serveerstertje kernel: [ 72.940434]
> Jan 26 11:36:10 serveerstertje kernel: [ 72.940434] but task is already holding lock:
> Jan 26 11:36:10 serveerstertje kernel: [ 72.952263] (&port->mutex){+.+.+.}, at: [<ffffffff81518aa7>] tty_port_open+0x67/0xe0
> Jan 26 11:36:10 serveerstertje kernel: [ 72.958292]
> Jan 26 11:36:10 serveerstertje kernel: [ 72.958292] which lock already depends on the new lock.
> Jan 26 11:36:10 serveerstertje kernel: [ 72.958292]
> Jan 26 11:36:10 serveerstertje kernel: [ 72.976267]
> Jan 26 11:36:10 serveerstertje kernel: [ 72.976267] the existing dependency chain (in reverse order) is:
> Jan 26 11:36:10 serveerstertje kernel: [ 72.988276]
> Jan 26 11:36:10 serveerstertje kernel: [ 72.988276] -> #1 (&port->mutex){+.+.+.}:
> Jan 26 11:36:10 serveerstertje kernel: [ 73.000386] [<ffffffff81102dfd>] lock_acquire+0xcd/0x110
> Jan 26 11:36:10 serveerstertje kernel: [ 73.006526] [<ffffffff81ad3f97>] mutex_lock_nested+0x47/0x560
> Jan 26 11:36:10 serveerstertje kernel: [ 73.012612] [<ffffffff81518aa7>] tty_port_open+0x67/0xe0
> Jan 26 11:36:10 serveerstertje kernel: [ 73.018637] [<ffffffff81aa4356>] rfcomm_tty_open+0x26/0xe0
> Jan 26 11:36:10 serveerstertje kernel: [ 73.024674] [<ffffffff8150fcea>] tty_open+0x16a/0x5c0
> Jan 26 11:36:10 serveerstertje kernel: [ 73.030748] [<ffffffff811b4013>] chrdev_open+0xa3/0x1c0
> Jan 26 11:36:10 serveerstertje kernel: [ 73.036833] [<ffffffff811ad686>] do_dentry_open.isra.16+0x246/0x2f0
> Jan 26 11:36:10 serveerstertje kernel: [ 73.043001] [<ffffffff811ad81d>] finish_open+0x1d/0x30
> Jan 26 11:36:10 serveerstertje kernel: [ 73.049106] [<ffffffff811befae>] do_last+0x7ce/0xdf0
> Jan 26 11:36:10 serveerstertje kernel: [ 73.055191] [<ffffffff811bf68d>] path_openat+0xbd/0x6b0
> Jan 26 11:36:10 serveerstertje kernel: [ 73.061211] [<ffffffff811c004e>] do_filp_open+0x3e/0xa0
> Jan 26 11:36:10 serveerstertje kernel: [ 73.067177] [<ffffffff811aeaec>] do_sys_open+0x13c/0x230
> Jan 26 11:36:10 serveerstertje kernel: [ 73.073141] [<ffffffff811aebfd>] SyS_open+0x1d/0x20
> Jan 26 11:36:10 serveerstertje kernel: [ 73.079047] [<ffffffff81ad6f39>] system_call_fastpath+0x16/0x1b
> Jan 26 11:36:10 serveerstertje kernel: [ 73.084962]
> Jan 26 11:36:10 serveerstertje kernel: [ 73.084962] -> #0 (&tty->legacy_mutex){+.+.+.}:
> Jan 26 11:36:10 serveerstertje kernel: [ 73.096600] [<ffffffff8110230b>] __lock_acquire+0x1d4b/0x2220
> Jan 26 11:36:10 serveerstertje kernel: [ 73.102559] [<ffffffff81102dfd>] lock_acquire+0xcd/0x110
> Jan 26 11:36:10 serveerstertje kernel: [ 73.108475] [<ffffffff81ad3f97>] mutex_lock_nested+0x47/0x560
> Jan 26 11:36:10 serveerstertje kernel: [ 73.114419] [<ffffffff81ad6344>] tty_lock_nested+0x44/0xa0
> Jan 26 11:36:10 serveerstertje kernel: [ 73.120354] [<ffffffff81ad63ab>] tty_lock+0xb/0x10
> Jan 26 11:36:10 serveerstertje kernel: [ 73.126258] [<ffffffff81aa4677>] rfcomm_dev_activate+0xb7/0x250
> Jan 26 11:36:10 serveerstertje kernel: [ 73.132222] [<ffffffff81518ad7>] tty_port_open+0x97/0xe0
> Jan 26 11:36:10 serveerstertje kernel: [ 73.138195] [<ffffffff81aa4356>] rfcomm_tty_open+0x26/0xe0
> Jan 26 11:36:10 serveerstertje kernel: [ 73.144207] [<ffffffff8150fcea>] tty_open+0x16a/0x5c0
> Jan 26 11:36:10 serveerstertje kernel: [ 73.150164] [<ffffffff811b4013>] chrdev_open+0xa3/0x1c0
> Jan 26 11:36:10 serveerstertje kernel: [ 73.156127] [<ffffffff811ad686>] do_dentry_open.isra.16+0x246/0x2f0
> Jan 26 11:36:10 serveerstertje kernel: [ 73.162070] [<ffffffff811ad81d>] finish_open+0x1d/0x30
> Jan 26 11:36:10 serveerstertje kernel: [ 73.167933] [<ffffffff811befae>] do_last+0x7ce/0xdf0
> Jan 26 11:36:10 serveerstertje kernel: [ 73.173787] [<ffffffff811bf68d>] path_openat+0xbd/0x6b0
> Jan 26 11:36:10 serveerstertje kernel: [ 73.179600] [<ffffffff811c004e>] do_filp_open+0x3e/0xa0
> Jan 26 11:36:10 serveerstertje kernel: [ 73.185302] [<ffffffff811aeaec>] do_sys_open+0x13c/0x230
> Jan 26 11:36:10 serveerstertje kernel: [ 73.190880] [<ffffffff811aebfd>] SyS_open+0x1d/0x20
> Jan 26 11:36:10 serveerstertje kernel: [ 73.196247] [<ffffffff81ad6f39>] system_call_fastpath+0x16/0x1b
> Jan 26 11:36:10 serveerstertje kernel: [ 73.201486]
> Jan 26 11:36:10 serveerstertje kernel: [ 73.201486] other info that might help us debug this:
> Jan 26 11:36:10 serveerstertje kernel: [ 73.201486]
> Jan 26 11:36:10 serveerstertje kernel: [ 73.216718] Possible unsafe locking scenario:
> Jan 26 11:36:10 serveerstertje kernel: [ 73.216718]
> Jan 26 11:36:10 serveerstertje kernel: [ 73.226933] CPU0 CPU1
> Jan 26 11:36:10 serveerstertje kernel: [ 73.231978] ---- ----
> Jan 26 11:36:10 serveerstertje kernel: [ 73.237001] lock(&port->mutex);
> Jan 26 11:36:10 serveerstertje kernel: [ 73.241994] lock(&tty->legacy_mutex);
> Jan 26 11:36:10 serveerstertje kernel: [ 73.247043] lock(&port->mutex);
> Jan 26 11:36:10 serveerstertje kernel: [ 73.251999] lock(&tty->legacy_mutex);
> Jan 26 11:36:10 serveerstertje kernel: [ 73.256902]
> Jan 26 11:36:10 serveerstertje kernel: [ 73.256902] *** DEADLOCK ***
> Jan 26 11:36:10 serveerstertje kernel: [ 73.256902]
> Jan 26 11:36:10 serveerstertje kernel: [ 73.270890] 1 lock held by zabbix_slimmeme/5909:
> Jan 26 11:36:10 serveerstertje kernel: [ 73.275398] #0: (&port->mutex){+.+.+.}, at: [<ffffffff81518aa7>] tty_port_open+0x67/0xe0
> Jan 26 11:36:10 serveerstertje kernel: [ 73.280124]
> Jan 26 11:36:10 serveerstertje kernel: [ 73.280124] stack backtrace:
> Jan 26 11:36:10 serveerstertje kernel: [ 73.289130] CPU: 5 PID: 5909 Comm: zabbix_slimmeme Not tainted 3.13.0-20140125-mw-pcireset+ #1
> Jan 26 11:36:10 serveerstertje kernel: [ 73.293860] Hardware name: MSI MS-7640/890FXA-GD70 (MS-7640) , BIOS V1.8B1 09/13/2010
> Jan 26 11:36:10 serveerstertje kernel: [ 73.298625] ffffffff826e2b70 ffff88005858f818 ffffffff81acbcfa ffff880057c72300
> Jan 26 11:36:10 serveerstertje kernel: [ 73.303571] ffffffff826e2b70 ffff88005858f868 ffffffff81ac7011 ffff880057c72300
> Jan 26 11:36:10 serveerstertje kernel: [ 73.308511] ffff880057c72300 ffff88005858f868 ffff880057c72ac0 0000000000000000
> Jan 26 11:36:10 serveerstertje kernel: [ 73.313325] Call Trace:
> Jan 26 11:36:10 serveerstertje kernel: [ 73.318092] [<ffffffff81acbcfa>] dump_stack+0x46/0x58
> Jan 26 11:36:10 serveerstertje kernel: [ 73.322900] [<ffffffff81ac7011>] print_circular_bug+0x2f6/0x32a
> Jan 26 11:36:10 serveerstertje kernel: [ 73.327723] [<ffffffff8110230b>] __lock_acquire+0x1d4b/0x2220
> Jan 26 11:36:10 serveerstertje kernel: [ 73.332545] [<ffffffff810fedbd>] ? trace_hardirqs_on+0xd/0x10
> Jan 26 11:36:10 serveerstertje kernel: [ 73.337414] [<ffffffff810e6141>] ? finish_task_switch+0x41/0xf0
> Jan 26 11:36:10 serveerstertje kernel: [ 73.342279] [<ffffffff81ad0244>] ? sleep_on_timeout+0x4/0x20
> Jan 26 11:36:10 serveerstertje kernel: [ 73.347128] [<ffffffff81102dfd>] lock_acquire+0xcd/0x110
> Jan 26 11:36:10 serveerstertje kernel: [ 73.351950] [<ffffffff81ad6344>] ? tty_lock_nested+0x44/0xa0
> Jan 26 11:36:10 serveerstertje kernel: [ 73.356792] [<ffffffff81ad3f97>] mutex_lock_nested+0x47/0x560
> Jan 26 11:36:10 serveerstertje kernel: [ 73.361599] [<ffffffff81ad6344>] ? tty_lock_nested+0x44/0xa0
> Jan 26 11:36:10 serveerstertje kernel: [ 73.366363] [<ffffffff810fec6b>] ? trace_hardirqs_on_caller+0xfb/0x240
> Jan 26 11:36:10 serveerstertje kernel: [ 73.371200] [<ffffffff810fedbd>] ? trace_hardirqs_on+0xd/0x10
> Jan 26 11:36:10 serveerstertje kernel: [ 73.376030] [<ffffffff81ad6344>] tty_lock_nested+0x44/0xa0
> Jan 26 11:36:10 serveerstertje kernel: [ 73.380842] [<ffffffff81ad63ab>] tty_lock+0xb/0x10
> Jan 26 11:36:10 serveerstertje kernel: [ 73.385616] [<ffffffff81aa4677>] rfcomm_dev_activate+0xb7/0x250
> Jan 26 11:36:10 serveerstertje kernel: [ 73.390398] [<ffffffff81ad4287>] ? mutex_lock_nested+0x337/0x560
> Jan 26 11:36:10 serveerstertje kernel: [ 73.395154] [<ffffffff810f90f0>] ? __init_waitqueue_head+0x60/0x60
> Jan 26 11:36:10 serveerstertje kernel: [ 73.399861] [<ffffffff81518ad7>] tty_port_open+0x97/0xe0
> Jan 26 11:36:10 serveerstertje kernel: [ 73.404552] [<ffffffff81aa4356>] rfcomm_tty_open+0x26/0xe0
> Jan 26 11:36:10 serveerstertje kernel: [ 73.409263] [<ffffffff8150fcea>] tty_open+0x16a/0x5c0
> Jan 26 11:36:10 serveerstertje kernel: [ 73.413954] [<ffffffff811b4013>] chrdev_open+0xa3/0x1c0
> Jan 26 11:36:10 serveerstertje kernel: [ 73.418657] [<ffffffff81457bfd>] ? lockref_get+0x1d/0x30
> Jan 26 11:36:10 serveerstertje kernel: [ 73.423379] [<ffffffff811b3f70>] ? cdev_put+0x30/0x30
> Jan 26 11:36:10 serveerstertje kernel: [ 73.428056] [<ffffffff811ad686>] do_dentry_open.isra.16+0x246/0x2f0
> Jan 26 11:36:10 serveerstertje kernel: [ 73.432768] [<ffffffff811ad81d>] finish_open+0x1d/0x30
> Jan 26 11:36:10 serveerstertje kernel: [ 73.437464] [<ffffffff811befae>] do_last+0x7ce/0xdf0
> Jan 26 11:36:10 serveerstertje kernel: [ 73.442166] [<ffffffff811baff3>] ? inode_permission+0x13/0x50
> Jan 26 11:36:10 serveerstertje kernel: [ 73.446861] [<ffffffff811bb5ce>] ? link_path_walk+0x21e/0x880
> Jan 26 11:36:10 serveerstertje kernel: [ 73.451533] [<ffffffff810fec6b>] ? trace_hardirqs_on_caller+0xfb/0x240
> Jan 26 11:36:10 serveerstertje kernel: [ 73.456280] [<ffffffff811bf68d>] path_openat+0xbd/0x6b0
> Jan 26 11:36:10 serveerstertje kernel: [ 73.461029] [<ffffffff8104cb03>] ? __do_page_fault+0x103/0x4e0
> Jan 26 11:36:10 serveerstertje kernel: [ 73.465782] [<ffffffff81102e1d>] ? lock_acquire+0xed/0x110
> Jan 26 11:36:10 serveerstertje kernel: [ 73.470553] [<ffffffff811c004e>] do_filp_open+0x3e/0xa0
> Jan 26 11:36:10 serveerstertje kernel: [ 73.475321] [<ffffffff811cda31>] ? __alloc_fd+0xd1/0x120
> Jan 26 11:36:10 serveerstertje kernel: [ 73.480064] [<ffffffff811aeaec>] do_sys_open+0x13c/0x230
> Jan 26 11:36:10 serveerstertje kernel: [ 73.484743] [<ffffffff810fec6b>] ? trace_hardirqs_on_caller+0xfb/0x240
> Jan 26 11:36:10 serveerstertje kernel: [ 73.489470] [<ffffffff811aebfd>] SyS_open+0x1d/0x20
> Jan 26 11:36:10 serveerstertje kernel: [ 73.494191] [<ffffffff81ad6f39>] system_call_fastpath+0x16/0x1b



--
Best regards,
Sander mailto:[email protected]