From mboxrd@z Thu Jan 1 00:00:00 1970 Return-Path: Received: (majordomo@vger.kernel.org) by vger.kernel.org via listexpand id S1755445Ab1K3Cbi (ORCPT ); Tue, 29 Nov 2011 21:31:38 -0500 Received: from lennier.cc.vt.edu ([198.82.162.213]:48027 "EHLO lennier.cc.vt.edu" rhost-flags-OK-OK-OK-OK) by vger.kernel.org with ESMTP id S1752706Ab1K3Cbf (ORCPT ); Tue, 29 Nov 2011 21:31:35 -0500 X-Mailer: exmh version 2.7.2 01/07/2005 with nmh-1.3-dev To: "James E.J. Bottomley" , Len Brown , Pavel Machek , "Rafael J. Wysocki" Cc: linux-kernel@vger.kernel.org, linux-scsi@vger.kernel.org, linux-acpi@vger.kernel.org, linux-pm@vger.kernel.org Subject: 3.2.0-rc3-next-20111128 lockdep splat during boot.. From: Valdis.Kletnieks@vt.edu Mime-Version: 1.0 Content-Type: multipart/signed; boundary="==_Exmh_1322620187_2854P"; micalg=pgp-sha1; protocol="application/pgp-signature" Content-Transfer-Encoding: 7bit Date: Tue, 29 Nov 2011 21:29:47 -0500 Message-ID: <23526.1322620187@turing-police.cc.vt.edu> X-Mirapoint-Received-SPF: 198.82.161.152 auth3.smtp.vt.edu Valdis.Kletnieks@vt.edu 2 pass X-Junkmail-Status: score=10/50, host=steiner.cc.vt.edu X-Junkmail-Signature-Raw: score=unknown, refid=str=0001.0A02020A.4ED5951D.0083,ss=1,re=0.000,fgs=0, ip=0.0.0.0, so=2011-07-25 19:15:43, dmn=2011-05-27 18:58:46, mode=single engine X-Junkmail-IWF: false Sender: linux-kernel-owner@vger.kernel.org List-ID: X-Mailing-List: linux-kernel@vger.kernel.org --==_Exmh_1322620187_2854P Content-Type: text/plain; charset=us-ascii Seen this twice out of two boots while initrd was waiting for me to enter the passphrase for encrypted LVM. No idea *who* to toss this one at - got ACPI, PM, SCSI and vtconsole all listed in tracebacks, so I'm tossing this at everybody and hope it sticks. ;) [ 14.708463] [ 14.708747] ========================================================= [ 14.709229] [ INFO: possible irq lock inversion dependency detected ] [ 14.709229] 3.2.0-rc3-next-20111128 #41 [ 14.709229] --------------------------------------------------------- [ 14.709229] ksoftirqd/0/3 just changed the state of lock: [ 14.709229] (&(&dev->power.lock)->rlock){..-...}, at: [] pm_suspend_timer_fn+0x1d/0x72 [ 14.709229] but this lock took another, SOFTIRQ-unsafe lock in the past: [ 14.709229] (&(&k->k_lock)->rlock){+.+...} [ 14.709229] [ 14.709229] and interrupts could create inverse lock ordering between them. [ 14.709229] [ 14.709229] [ 14.709229] other info that might help us debug this: [ 14.709229] Possible interrupt unsafe locking scenario: [ 14.709229] [ 14.709229] CPU0 CPU1 [ 14.709229] ---- ---- [ 14.709229] lock(&(&k->k_lock)->rlock); [ 14.709229] local_irq_disable(); [ 14.709229] lock(&(&dev->power.lock)->rlock); [ 14.709229] lock(&(&k->k_lock)->rlock); [ 14.709229] [ 14.709229] lock(&(&dev->power.lock)->rlock); [ 14.709229] [ 14.709229] *** DEADLOCK *** [ 14.709229] [ 14.709229] 1 lock held by ksoftirqd/0/3: [ 14.709229] #0: (&dev->power.suspend_timer){+.-...}, at: [] call_timer_fn+0x0/0x1f7 [ 14.709229] [ 14.709229] the shortest dependencies between 2nd lock and 1st lock: [ 14.709229] -> (&(&k->k_lock)->rlock){+.+...} ops: 7510 { [ 14.709229] HARDIRQ-ON-W at: [ 14.709229] [] mark_irqflags+0xd2/0x13e [ 14.709229] [] __lock_acquire+0x22b/0x3e2 [ 14.709229] [] lock_acquire+0x103/0x153 [ 14.709229] [] _raw_spin_lock+0x36/0x45 [ 14.709229] [] klist_add_tail+0x20/0x3f [ 14.709229] [] device_add+0x23e/0x336 [ 14.709229] [] device_register+0x17/0x1c [ 14.709229] [] device_create_vargs+0xb2/0xea [ 14.709229] [] device_create+0x2c/0x2e [ 14.709229] [] vtconsole_class_init+0x97/0xf3 [ 14.709229] [] do_one_initcall+0x7a/0x130 [ 14.709229] [] kernel_init+0xcd/0x147 [ 14.709229] [] kernel_thread_helper+0x4/0x10 [ 14.709229] SOFTIRQ-ON-W at: [ 14.709229] [] mark_irqflags+0xf2/0x13e [ 14.709229] [] __lock_acquire+0x22b/0x3e2 [ 14.709229] [] lock_acquire+0x103/0x153 [ 14.709229] [] _raw_spin_lock+0x36/0x45 [ 14.709229] [] klist_add_tail+0x20/0x3f [ 14.709229] [] device_add+0x23e/0x336 [ 14.709229] [] device_register+0x17/0x1c [ 14.709229] [] device_create_vargs+0xb2/0xea [ 14.709229] [] device_create+0x2c/0x2e [ 14.709229] [] vtconsole_class_init+0x97/0xf3 [ 14.709229] [] do_one_initcall+0x7a/0x130 [ 14.709229] [] kernel_init+0xcd/0x147 [ 14.709229] [] kernel_thread_helper+0x4/0x10 [ 14.709229] INITIAL USE at: [ 14.709229] [] __lock_acquire+0x24a/0x3e2 [ 14.709229] [] lock_acquire+0x103/0x153 [ 14.709229] [] _raw_spin_lock+0x36/0x45 [ 14.709229] [] klist_add_tail+0x20/0x3f [ 14.709229] [] device_add+0x23e/0x336 [ 14.709229] [] device_register+0x17/0x1c [ 14.709229] [] device_create_vargs+0xb2/0xea [ 14.709229] [] device_create+0x2c/0x2e [ 14.709229] [] vtconsole_class_init+0x97/0xf3 [ 14.709229] [] do_one_initcall+0x7a/0x130 [ 14.709229] [] kernel_init+0xcd/0x147 [ 14.709229] [] kernel_thread_helper+0x4/0x10 [ 14.709229] } [ 14.709229] ... key at: [] __key.16100+0x0/0x680 [ 14.709229] ... acquired at: [ 14.709229] [] check_prevs_add+0x8b/0x104 [ 15.001689] [] validate_chain+0x361/0x39d [ 15.001689] [] __lock_acquire+0x369/0x3e2 [ 15.001689] [] lock_acquire+0x103/0x153 [ 15.001689] [] _raw_spin_lock+0x36/0x45 [ 15.001689] [] klist_next+0x21/0xd2 [ 15.001689] [] device_for_each_child+0x40/0x6a [ 15.001689] [] rpm_suspend+0x27d/0x4f8 [ 15.001689] [] __pm_runtime_suspend+0x6c/0x89 [ 15.001689] [] scsi_runtime_idle+0x2b/0x2f [ 15.001689] [] __rpm_callback+0x2f/0x56 [ 15.001689] [] rpm_idle+0x174/0x1db [ 15.001689] [] __pm_runtime_idle+0x6d/0x8a [ 15.001689] [] scsi_autopm_put_host+0x15/0x17 [ 15.001689] [] scsi_error_handler+0xb2/0x100 [ 15.001689] [] kthread+0x7f/0x87 [ 15.001689] [] kernel_thread_helper+0x4/0x10 [ 15.001689] [ 15.001689] -> (&(&dev->power.lock)->rlock){..-...} ops: 738 { [ 15.001689] IN-SOFTIRQ-W at: [ 15.001689] [] mark_irqflags+0x82/0x13e [ 15.001689] [] __lock_acquire+0x22b/0x3e2 [ 15.001689] [] lock_acquire+0x103/0x153 [ 15.001689] [] _raw_spin_lock_irqsave+0x44/0x57 [ 15.001689] [] pm_suspend_timer_fn+0x1d/0x72 [ 15.001689] [] call_timer_fn+0xb3/0x1f7 [ 15.001689] [] run_timer_softirq+0x1aa/0x1f2 [ 15.001689] [] __do_softirq+0x110/0x278 [ 15.001689] [] run_ksoftirqd+0xd0/0x20e [ 15.001689] [] kthread+0x7f/0x87 [ 15.001689] [] kernel_thread_helper+0x4/0x10 [ 15.001689] INITIAL USE at: [ 15.001689] [] __lock_acquire+0x24a/0x3e2 [ 15.001689] [] lock_acquire+0x103/0x153 [ 15.001689] [] _raw_spin_lock_irqsave+0x44/0x57 [ 15.001689] [] __pm_runtime_idle+0x5f/0x8a [ 15.001689] [] device_attach+0x88/0x9c [ 15.001689] [] bus_probe_device+0x24/0x62 [ 15.001689] [] device_add+0x1eb/0x336 [ 15.001689] [] device_register+0x17/0x1c [ 15.001689] [] acpi_device_register+0x150/0x221 [ 15.001689] [] acpi_add_single_object+0x1c2/0x226 [ 15.001689] [] acpi_bus_check_add+0x9e/0xe6 [ 15.001689] [] acpi_bus_scan+0x33/0x77 [ 15.001689] [] acpi_scan_init+0x4b/0xce [ 15.001689] [] acpi_init+0x9e/0xb4 [ 15.001689] [] do_one_initcall+0x7a/0x130 [ 15.001689] [] kernel_init+0xcd/0x147 [ 15.001689] [] kernel_thread_helper+0x4/0x10 [ 15.001689] } [ 15.001689] ... key at: [] __key.18419+0x0/0x8 [ 15.001689] ... acquired at: [ 15.001689] [] check_usage_forwards+0x95/0xa6 [ 15.001689] [] mark_lock_irq+0x94/0x120 [ 15.001689] [] mark_lock+0xaf/0x122 [ 15.001689] [] mark_irqflags+0x82/0x13e [ 15.001689] [] __lock_acquire+0x22b/0x3e2 [ 15.001689] [] lock_acquire+0x103/0x153 [ 15.001689] [] _raw_spin_lock_irqsave+0x44/0x57 [ 15.001689] [] pm_suspend_timer_fn+0x1d/0x72 [ 15.001689] [] call_timer_fn+0xb3/0x1f7 [ 15.001689] [] run_timer_softirq+0x1aa/0x1f2 [ 15.001689] [] __do_softirq+0x110/0x278 [ 15.001689] [] run_ksoftirqd+0xd0/0x20e [ 15.001689] [] kthread+0x7f/0x87 [ 15.001689] [] kernel_thread_helper+0x4/0x10 [ 15.001689] [ 15.001689] [ 15.001689] stack backtrace: [ 15.001689] Pid: 3, comm: ksoftirqd/0 Not tainted 3.2.0-rc3-next-20111128 #41 [ 15.001689] Call Trace: [ 15.001689] [] print_irq_inversion_bug.part.16+0x19f/0x1ae [ 15.001689] [] check_usage_forwards+0x95/0xa6 [ 15.001689] [] ? dump_trace+0x201/0x219 [ 15.001689] [] ? print_irq_inversion_bug.part.16+0x1ae/0x1ae [ 15.001689] [] mark_lock_irq+0x94/0x120 [ 15.001689] [] mark_lock+0xaf/0x122 [ 15.001689] [] mark_irqflags+0x82/0x13e [ 15.001689] [] __lock_acquire+0x22b/0x3e2 [ 15.001689] [] ? pm_suspend_timer_fn+0x1d/0x72 [ 15.001689] [] lock_acquire+0x103/0x153 [ 15.001689] [] ? pm_suspend_timer_fn+0x1d/0x72 [ 15.001689] [] ? rpm_suspend+0x4f8/0x4f8 [ 15.001689] [] ? rpm_suspend+0x4f8/0x4f8 [ 15.001689] [] _raw_spin_lock_irqsave+0x44/0x57 [ 15.001689] [] ? pm_suspend_timer_fn+0x1d/0x72 [ 18.416714] [] ? run_timer_softirq+0x1b2/0x1f2 [ 18.416714] [] pm_suspend_timer_fn+0x1d/0x72 [ 18.416714] [] ? rpm_suspend+0x4f8/0x4f8 [ 18.416714] [] ? rpm_suspend+0x4f8/0x4f8 [ 18.416714] [] call_timer_fn+0xb3/0x1f7 [ 18.416714] [] ? del_timer+0x75/0x75 [ 18.416714] [] ? rpm_suspend+0x4f8/0x4f8 [ 18.416714] [] ? rpm_suspend+0x4f8/0x4f8 [ 18.416714] [] run_timer_softirq+0x1aa/0x1f2 [ 18.416714] [] __do_softirq+0x110/0x278 [ 18.416714] [] run_ksoftirqd+0xd0/0x20e [ 18.416714] [] ? __do_softirq+0x278/0x278 [ 18.416714] [] kthread+0x7f/0x87 [ 18.416714] [] kernel_thread_helper+0x4/0x10 [ 18.416714] [] ? retint_restore_args+0xe/0xe [ 18.416714] [] ? __init_kthread_worker+0x55/0x55 [ 18.416714] [] ? gs_change+0xb/0xb --==_Exmh_1322620187_2854P Content-Type: application/pgp-signature -----BEGIN PGP SIGNATURE----- Version: GnuPG v1.4.11 (GNU/Linux) Comment: Exmh version 2.5 07/13/2001 iD8DBQFO1ZUbcC3lWbTT17ARAksLAJ4zY/vHTJpjmedNK2PwaKi/d9izKwCePq55 lTYFmQsMvfFkMSn7iEzMBSY= =WBfa -----END PGP SIGNATURE----- --==_Exmh_1322620187_2854P--