Hi Marcel / Gianluca, Bisection points to this commit: 4a2fb3ecc7467c775b154813861f25a0ddc11aa0 is the first bad commit commit 4a2fb3ecc7467c775b154813861f25a0ddc11aa0 Author: Gianluca Anzolin <gianluca@xxxxxxxxxxxxxx> 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 <gianluca@xxxxxxxxxxxxxx> Reported-by: Andrey Vihrov <andrey.vihrov@xxxxxxxxx> Reported-by: Beson Chow <blc+bluez@xxxxxxxxxxxxxxx> Signed-off-by: Marcel Holtmann <marcel@xxxxxxxxxxxx> 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:linux@xxxxxxxxxxxxxx -- To unsubscribe from this list: send the line "unsubscribe linux-bluetooth" in the body of a message to majordomo@xxxxxxxxxxxxxxx More majordomo info at http://vger.kernel.org/majordomo-info.html