読者です 読者をやめる 読者になる 読者になる

possible recursive locking detected

linux

久々に遭遇。再現できるかと思って試したけど再現しなかったので、ログだけ貼っ付けとく。

Jul 26 22:05:33 localhost kernel: [45852.371020] =============================================
Jul 26 22:05:33 localhost kernel: [45852.371026] [ INFO: possible recursive locking detected ]
Jul 26 22:05:33 localhost kernel: [45852.371030] 2.6.31-rc3-x86tip-tip #1
Jul 26 22:05:33 localhost kernel: [45852.371033] ---------------------------------------------
Jul 26 22:05:33 localhost kernel: [45852.371036] events/0/9 is trying to acquire lock:
Jul 26 22:05:33 localhost kernel: [45852.371040]  (&tty->output_lock){+.+...}, at: [<ffffffff812800d0>] process_echoes+0x4a/0x2c0
Jul 26 22:05:33 localhost kernel: [45852.371054] 
Jul 26 22:05:33 localhost kernel: [45852.371055] but task is already holding lock:
Jul 26 22:05:33 localhost kernel: [45852.371058]  (&tty->output_lock){+.+...}, at: [<ffffffff812800d0>] process_echoes+0x4a/0x2c0
Jul 26 22:05:33 localhost kernel: [45852.371067] 
Jul 26 22:05:33 localhost kernel: [45852.371067] other info that might help us debug this:
Jul 26 22:05:33 localhost kernel: [45852.371071] 4 locks held by events/0/9:
Jul 26 22:05:33 localhost kernel: [45852.371073]  #0:  (events){+.+.+.}, at: [<ffffffff81079866>] worker_thread+0x209/0x396
Jul 26 22:05:33 localhost kernel: [45852.371085]  #1:  (&(&tty->buf.work)->work){+.+...}, at: [<ffffffff81079866>] worker_thread+0x209/0x396
Jul 26 22:05:33 localhost kernel: [45852.371095]  #2:  (&tty->output_lock){+.+...}, at: [<ffffffff812800d0>] process_echoes+0x4a/0x2c0
Jul 26 22:05:33 localhost kernel: [45852.371104]  #3:  (&tty->echo_lock){+.+...}, at: [<ffffffff812800e5>] process_echoes+0x5f/0x2c0
Jul 26 22:05:33 localhost kernel: [45852.371114] 
Jul 26 22:05:33 localhost kernel: [45852.371115] stack backtrace:
Jul 26 22:05:33 localhost kernel: [45852.371119] Pid: 9, comm: events/0 Not tainted 2.6.31-rc3-x86tip-tip #1
Jul 26 22:05:33 localhost kernel: [45852.371122] Call Trace:
Jul 26 22:05:33 localhost kernel: [45852.371129]  [<ffffffff81095d89>] __lock_acquire+0xbca/0xc6a
Jul 26 22:05:33 localhost kernel: [45852.371135]  [<ffffffff812800d0>] ? process_echoes+0x4a/0x2c0
Jul 26 22:05:33 localhost kernel: [45852.371141]  [<ffffffff812800d0>] ? process_echoes+0x4a/0x2c0
Jul 26 22:05:33 localhost kernel: [45852.371146]  [<ffffffff81095f3c>] lock_acquire+0x113/0x153
Jul 26 22:05:33 localhost kernel: [45852.371151]  [<ffffffff812800d0>] ? process_echoes+0x4a/0x2c0
Jul 26 22:05:33 localhost kernel: [45852.371156]  [<ffffffff81095d4f>] ? __lock_acquire+0xb90/0xc6a
Jul 26 22:05:33 localhost kernel: [45852.371163]  [<ffffffff8139b9ad>] __mutex_lock_common+0x6e/0x4c7
Jul 26 22:05:33 localhost kernel: [45852.371168]  [<ffffffff812800d0>] ? process_echoes+0x4a/0x2c0
Jul 26 22:05:33 localhost kernel: [45852.371173]  [<ffffffff81093fff>] ? mark_lock+0x31/0x24c
Jul 26 22:05:33 localhost kernel: [45852.371179]  [<ffffffff812800d0>] ? process_echoes+0x4a/0x2c0
Jul 26 22:05:33 localhost kernel: [45852.371184]  [<ffffffff8109427a>] ? mark_held_locks+0x60/0x95
Jul 26 22:05:33 localhost kernel: [45852.371189]  [<ffffffff8139bf15>] mutex_lock_nested+0x48/0x65
Jul 26 22:05:33 localhost kernel: [45852.371194]  [<ffffffff812800d0>] process_echoes+0x4a/0x2c0
Jul 26 22:05:33 localhost kernel: [45852.371200]  [<ffffffff8128036b>] n_tty_write_wakeup+0x25/0x72
Jul 26 22:05:33 localhost kernel: [45852.371206]  [<ffffffff8107ad89>] ? schedule_delayed_work+0x31/0x47
Jul 26 22:05:33 localhost kernel: [45852.371211]  [<ffffffff8127e51f>] tty_wakeup+0x49/0x88
Jul 26 22:05:33 localhost kernel: [45852.371217]  [<ffffffff81286c63>] pty_write+0x72/0x93
Jul 26 22:05:33 localhost kernel: [45852.371223]  [<ffffffff8127bf55>] tty_put_char+0x41/0x57
Jul 26 22:05:33 localhost kernel: [45852.371228]  [<ffffffff81280058>] do_output_char+0x20d/0x23b
Jul 26 22:05:33 localhost kernel: [45852.371233]  [<ffffffff81280291>] process_echoes+0x20b/0x2c0
Jul 26 22:05:33 localhost kernel: [45852.371239]  [<ffffffff8128060f>] ? echo_char+0x8b/0xac
Jul 26 22:05:33 localhost kernel: [45852.371245]  [<ffffffff81281f5d>] n_tty_receive_buf+0x342/0xe67
Jul 26 22:05:33 localhost kernel: [45852.371251]  [<ffffffff812856cf>] ? flush_to_ldisc+0x5f/0x1fb
Jul 26 22:05:33 localhost kernel: [45852.371256]  [<ffffffff8109427a>] ? mark_held_locks+0x60/0x95
Jul 26 22:05:33 localhost kernel: [45852.371262]  [<ffffffff8139d4f7>] ? _spin_unlock_irqrestore+0x5e/0xb1
Jul 26 22:05:33 localhost kernel: [45852.371267]  [<ffffffff81094584>] ? trace_hardirqs_on_caller+0x123/0x15d
Jul 26 22:05:33 localhost kernel: [45852.371272]  [<ffffffff810945de>] ? trace_hardirqs_on+0x20/0x36
Jul 26 22:05:33 localhost kernel: [45852.371278]  [<ffffffff812857af>] flush_to_ldisc+0x13f/0x1fb
Jul 26 22:05:33 localhost kernel: [45852.371284]  [<ffffffff810798c0>] worker_thread+0x263/0x396
Jul 26 22:05:33 localhost kernel: [45852.371289]  [<ffffffff81079866>] ? worker_thread+0x209/0x396
Jul 26 22:05:33 localhost kernel: [45852.371294]  [<ffffffff8107965d>] ? worker_thread+0x0/0x396
Jul 26 22:05:33 localhost kernel: [45852.371299]  [<ffffffff81285670>] ? flush_to_ldisc+0x0/0x1fb
Jul 26 22:05:33 localhost kernel: [45852.371305]  [<ffffffff8139d525>] ? _spin_unlock_irqrestore+0x8c/0xb1
Jul 26 22:05:33 localhost kernel: [45852.371311]  [<ffffffff8107fd58>] ? autoremove_wake_function+0x0/0x63
Jul 26 22:05:33 localhost kernel: [45852.371317]  [<ffffffff8107965d>] ? worker_thread+0x0/0x396
Jul 26 22:05:33 localhost kernel: [45852.371322]  [<ffffffff8107f869>] kthread+0xa8/0xb0
Jul 26 22:05:33 localhost kernel: [45852.371329]  [<ffffffff810143da>] child_rip+0xa/0x20
Jul 26 22:05:33 localhost kernel: [45852.371336]  [<ffffffff81013d14>] ? restore_args+0x0/0x30
Jul 26 22:05:33 localhost kernel: [45852.371341]  [<ffffffff8107f7a0>] ? kthreadd+0x11b/0x13c
Jul 26 22:05:33 localhost kernel: [45852.371346]  [<ffffffff8107f7c1>] ? kthread+0x0/0xb0
Jul 26 22:05:33 localhost kernel: [45852.371351]  [<ffffffff810143d0>] ? child_rip+0x0/0x20
Jul 26 22:08:26 localhost kernel: [46025.306416] mtrr: no MTRR for d0000000,8000000 found
Jul 26 22:08:29 localhost kernel: [46028.381110] device eth0 left promiscuous mode
Jul 26 22:09:27 localhost kernel: [46086.124033] INFO: task events/0:9 blocked for more than 120 seconds.
Jul 26 22:09:27 localhost kernel: [46086.124091] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
Jul 26 22:09:27 localhost kernel: [46086.124145] events/0      D ffff8800b38738c8     0     9      2 0x00000000
Jul 26 22:09:27 localhost kernel: [46086.124238]  ffff8800b6fbb920 0000000000000082 0000000000000004 ffffffff81a117b0
Jul 26 22:09:27 localhost kernel: [46086.124386]  ffff8800b6fbb890 ffff8800b6fb43c0 00000000001d8580 0000000000010ac0
Jul 26 22:09:27 localhost kernel: [46086.124534]  ffff8800b6fb3c60 ffff88009cc9e4a0 ffff8800b6fb3f58 00000000411238be