Return-path: Received: from vserver.eikelenboom.it ([84.200.39.61]:40138 "EHLO smtp.eikelenboom.it" rhost-flags-OK-OK-OK-OK) by vger.kernel.org with ESMTP id S1752365AbaAZKrZ (ORCPT ); Sun, 26 Jan 2014 05:47:25 -0500 Date: Sun, 26 Jan 2014 11:47:21 +0100 From: Sander Eikelenboom Message-ID: <378824645.20140126114721@eikelenboom.it> (sfid-20140126_114732_248377_35723328) To: Greg Kroah-Hartman , Marcel Holtmann CC: linux-wireless@vger.kernel.org, linux-bluetooth@vger.kernel.org, Subject: 3.14-mw regression: circular locking dependency (&tty->legacy_mutex){+.+.+.}, at: [] tty_lock_nested+0x44/0xa0 MIME-Version: 1.0 Content-Type: text/plain; charset=us-ascii Sender: linux-wireless-owner@vger.kernel.org List-ID: 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: [] 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: [] 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] [] lock_acquire+0xcd/0x110 Jan 26 11:36:10 serveerstertje kernel: [ 73.006526] [] mutex_lock_nested+0x47/0x560 Jan 26 11:36:10 serveerstertje kernel: [ 73.012612] [] tty_port_open+0x67/0xe0 Jan 26 11:36:10 serveerstertje kernel: [ 73.018637] [] rfcomm_tty_open+0x26/0xe0 Jan 26 11:36:10 serveerstertje kernel: [ 73.024674] [] tty_open+0x16a/0x5c0 Jan 26 11:36:10 serveerstertje kernel: [ 73.030748] [] chrdev_open+0xa3/0x1c0 Jan 26 11:36:10 serveerstertje kernel: [ 73.036833] [] do_dentry_open.isra.16+0x246/0x2f0 Jan 26 11:36:10 serveerstertje kernel: [ 73.043001] [] finish_open+0x1d/0x30 Jan 26 11:36:10 serveerstertje kernel: [ 73.049106] [] do_last+0x7ce/0xdf0 Jan 26 11:36:10 serveerstertje kernel: [ 73.055191] [] path_openat+0xbd/0x6b0 Jan 26 11:36:10 serveerstertje kernel: [ 73.061211] [] do_filp_open+0x3e/0xa0 Jan 26 11:36:10 serveerstertje kernel: [ 73.067177] [] do_sys_open+0x13c/0x230 Jan 26 11:36:10 serveerstertje kernel: [ 73.073141] [] SyS_open+0x1d/0x20 Jan 26 11:36:10 serveerstertje kernel: [ 73.079047] [] 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] [] __lock_acquire+0x1d4b/0x2220 Jan 26 11:36:10 serveerstertje kernel: [ 73.102559] [] lock_acquire+0xcd/0x110 Jan 26 11:36:10 serveerstertje kernel: [ 73.108475] [] mutex_lock_nested+0x47/0x560 Jan 26 11:36:10 serveerstertje kernel: [ 73.114419] [] tty_lock_nested+0x44/0xa0 Jan 26 11:36:10 serveerstertje kernel: [ 73.120354] [] tty_lock+0xb/0x10 Jan 26 11:36:10 serveerstertje kernel: [ 73.126258] [] rfcomm_dev_activate+0xb7/0x250 Jan 26 11:36:10 serveerstertje kernel: [ 73.132222] [] tty_port_open+0x97/0xe0 Jan 26 11:36:10 serveerstertje kernel: [ 73.138195] [] rfcomm_tty_open+0x26/0xe0 Jan 26 11:36:10 serveerstertje kernel: [ 73.144207] [] tty_open+0x16a/0x5c0 Jan 26 11:36:10 serveerstertje kernel: [ 73.150164] [] chrdev_open+0xa3/0x1c0 Jan 26 11:36:10 serveerstertje kernel: [ 73.156127] [] do_dentry_open.isra.16+0x246/0x2f0 Jan 26 11:36:10 serveerstertje kernel: [ 73.162070] [] finish_open+0x1d/0x30 Jan 26 11:36:10 serveerstertje kernel: [ 73.167933] [] do_last+0x7ce/0xdf0 Jan 26 11:36:10 serveerstertje kernel: [ 73.173787] [] path_openat+0xbd/0x6b0 Jan 26 11:36:10 serveerstertje kernel: [ 73.179600] [] do_filp_open+0x3e/0xa0 Jan 26 11:36:10 serveerstertje kernel: [ 73.185302] [] do_sys_open+0x13c/0x230 Jan 26 11:36:10 serveerstertje kernel: [ 73.190880] [] SyS_open+0x1d/0x20 Jan 26 11:36:10 serveerstertje kernel: [ 73.196247] [] 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: [] 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] [] dump_stack+0x46/0x58 Jan 26 11:36:10 serveerstertje kernel: [ 73.322900] [] print_circular_bug+0x2f6/0x32a Jan 26 11:36:10 serveerstertje kernel: [ 73.327723] [] __lock_acquire+0x1d4b/0x2220 Jan 26 11:36:10 serveerstertje kernel: [ 73.332545] [] ? trace_hardirqs_on+0xd/0x10 Jan 26 11:36:10 serveerstertje kernel: [ 73.337414] [] ? finish_task_switch+0x41/0xf0 Jan 26 11:36:10 serveerstertje kernel: [ 73.342279] [] ? sleep_on_timeout+0x4/0x20 Jan 26 11:36:10 serveerstertje kernel: [ 73.347128] [] lock_acquire+0xcd/0x110 Jan 26 11:36:10 serveerstertje kernel: [ 73.351950] [] ? tty_lock_nested+0x44/0xa0 Jan 26 11:36:10 serveerstertje kernel: [ 73.356792] [] mutex_lock_nested+0x47/0x560 Jan 26 11:36:10 serveerstertje kernel: [ 73.361599] [] ? tty_lock_nested+0x44/0xa0 Jan 26 11:36:10 serveerstertje kernel: [ 73.366363] [] ? trace_hardirqs_on_caller+0xfb/0x240 Jan 26 11:36:10 serveerstertje kernel: [ 73.371200] [] ? trace_hardirqs_on+0xd/0x10 Jan 26 11:36:10 serveerstertje kernel: [ 73.376030] [] tty_lock_nested+0x44/0xa0 Jan 26 11:36:10 serveerstertje kernel: [ 73.380842] [] tty_lock+0xb/0x10 Jan 26 11:36:10 serveerstertje kernel: [ 73.385616] [] rfcomm_dev_activate+0xb7/0x250 Jan 26 11:36:10 serveerstertje kernel: [ 73.390398] [] ? mutex_lock_nested+0x337/0x560 Jan 26 11:36:10 serveerstertje kernel: [ 73.395154] [] ? __init_waitqueue_head+0x60/0x60 Jan 26 11:36:10 serveerstertje kernel: [ 73.399861] [] tty_port_open+0x97/0xe0 Jan 26 11:36:10 serveerstertje kernel: [ 73.404552] [] rfcomm_tty_open+0x26/0xe0 Jan 26 11:36:10 serveerstertje kernel: [ 73.409263] [] tty_open+0x16a/0x5c0 Jan 26 11:36:10 serveerstertje kernel: [ 73.413954] [] chrdev_open+0xa3/0x1c0 Jan 26 11:36:10 serveerstertje kernel: [ 73.418657] [] ? lockref_get+0x1d/0x30 Jan 26 11:36:10 serveerstertje kernel: [ 73.423379] [] ? cdev_put+0x30/0x30 Jan 26 11:36:10 serveerstertje kernel: [ 73.428056] [] do_dentry_open.isra.16+0x246/0x2f0 Jan 26 11:36:10 serveerstertje kernel: [ 73.432768] [] finish_open+0x1d/0x30 Jan 26 11:36:10 serveerstertje kernel: [ 73.437464] [] do_last+0x7ce/0xdf0 Jan 26 11:36:10 serveerstertje kernel: [ 73.442166] [] ? inode_permission+0x13/0x50 Jan 26 11:36:10 serveerstertje kernel: [ 73.446861] [] ? link_path_walk+0x21e/0x880 Jan 26 11:36:10 serveerstertje kernel: [ 73.451533] [] ? trace_hardirqs_on_caller+0xfb/0x240 Jan 26 11:36:10 serveerstertje kernel: [ 73.456280] [] path_openat+0xbd/0x6b0 Jan 26 11:36:10 serveerstertje kernel: [ 73.461029] [] ? __do_page_fault+0x103/0x4e0 Jan 26 11:36:10 serveerstertje kernel: [ 73.465782] [] ? lock_acquire+0xed/0x110 Jan 26 11:36:10 serveerstertje kernel: [ 73.470553] [] do_filp_open+0x3e/0xa0 Jan 26 11:36:10 serveerstertje kernel: [ 73.475321] [] ? __alloc_fd+0xd1/0x120 Jan 26 11:36:10 serveerstertje kernel: [ 73.480064] [] do_sys_open+0x13c/0x230 Jan 26 11:36:10 serveerstertje kernel: [ 73.484743] [] ? trace_hardirqs_on_caller+0xfb/0x240 Jan 26 11:36:10 serveerstertje kernel: [ 73.489470] [] SyS_open+0x1d/0x20 Jan 26 11:36:10 serveerstertje kernel: [ 73.494191] [] system_call_fastpath+0x16/0x1b