| lists.openwall.net | lists / announce owl-users owl-dev john-users john-dev passwdqc-users yescrypt popa3d-users / oss-security kernel-hardening musl sabotage tlsify passwords / crypt-dev xvendor / Bugtraq Full-Disclosure linux-kernel linux-netdev linux-ext4 linux-hardening linux-cve-announce PHC | |
|
Open Source and information security mailing list archives
| ||
|
Message-Id: <201012262316.26638.rjw@sisk.pl>
Date: Sun, 26 Dec 2010 23:16:26 +0100
From: "Rafael J. Wysocki" <rjw@...k.pl>
To: linux-ide@...r.kernel.org
Cc: Tejun Heo <htejun@...il.com>,
"linux-scsi" <linux-scsi@...r.kernel.org>,
"linux-kernel" <linux-kernel@...r.kernel.org>,
"Linux-pm mailing list" <linux-pm@...ts.linux-foundation.org>,
Alan Stern <stern@...land.harvard.edu>
Subject: [Probably regression] Possible circular locking dependency from ATA in current mainline
Hi,
I get the following during resume from hibernation:
[ 318.951686] ata9.00: ACPI cmd ef/03:0c:00:00:00:a0 (SET FEATURES) filtered out
[ 318.951688] ata9.00: ACPI cmd ef/03:46:00:00:00:a0 (SET FEATURES) filtered out
[ 318.963949] ata9.00: configured for UDMA/33
[ 319.103425] ata7: SATA link down (SStatus 0 SControl 300)
[ 319.103452] ata6: SATA link down (SStatus 0 SControl 300)
[ 319.103471] ata8: SATA link down (SStatus 0 SControl 300)
[ 319.103494] ata2: SATA link down (SStatus 0 SControl 300)
[ 319.103524] ata5: SATA link down (SStatus 0 SControl 300)
[ 319.110095] ata4: SATA link down (SStatus 0 SControl 300)
[ 319.256728] usb 3-2: reset full speed USB device using ohci_hcd and address 2
[ 319.270051] ata1: SATA link up 3.0 Gbps (SStatus 123 SControl 300)
[ 319.276717] ata3: SATA link up 3.0 Gbps (SStatus 123 SControl 300)
[ 319.281558] ata1.00: configured for UDMA/133
[ 319.281891]
[ 319.281892] =======================================================
[ 319.281893] [ INFO: possible circular locking dependency detected ]
[ 319.281894] 2.6.37-rc7+ #16
[ 319.281895] -------------------------------------------------------
[ 319.281896] kworker/1:0/13333 is trying to acquire lock:
[ 319.281897] (&bdev->bd_mutex){+.+.+.}, at: [<ffffffff811271a6>] revalidate_disk+0x56/0x90
[ 319.281902]
[ 319.281903] but task is already holding lock:
[ 319.281903] (&ap->scsi_scan_mutex){+.+...}, at: [<ffffffff81360420>] ata_scsi_dev_rescan+0x30/0x120
[ 319.281907]
[ 319.281907] which lock already depends on the new lock.
[ 319.281907]
[ 319.281908]
[ 319.281908] the existing dependency chain (in reverse order) is:
[ 319.281909]
[ 319.281910] -> #3 (&ap->scsi_scan_mutex){+.+...}:
[ 319.281911] [<ffffffff8107baa7>] lock_acquire+0x57/0x70
[ 319.281914] [<ffffffff81492fae>] mutex_lock_nested+0x5e/0x380
[ 319.281916] [<ffffffff81360420>] ata_scsi_dev_rescan+0x30/0x120
[ 319.281918] [<ffffffff81060722>] process_one_work+0x1a2/0x450
[ 319.281921] [<ffffffff81061ee2>] worker_thread+0x162/0x340
[ 319.281922] [<ffffffff810668e6>] kthread+0x96/0xa0
[ 319.281924] [<ffffffff81003594>] kernel_thread_helper+0x4/0x10
[ 319.281927]
[ 319.281927] -> #2 ((&ap->scsi_rescan_task)){+.+...}:
[ 319.281929] [<ffffffff8107baa7>] lock_acquire+0x57/0x70
[ 319.281930] [<ffffffff8106071c>] process_one_work+0x19c/0x450
[ 319.281932] [<ffffffff81061ee2>] worker_thread+0x162/0x340
[ 319.281934] [<ffffffff810668e6>] kthread+0x96/0xa0
[ 319.281935] [<ffffffff81003594>] kernel_thread_helper+0x4/0x10
[ 319.281937]
[ 319.281937] -> #1 (events){+.+.+.}:
[ 319.281939] [<ffffffff8107baa7>] lock_acquire+0x57/0x70
[ 319.281940] [<ffffffff81060463>] start_flush_work+0xc3/0x130
[ 319.281942] [<ffffffff810604f0>] flush_work+0x20/0x50
[ 319.281944] [<ffffffff81062a2b>] schedule_on_each_cpu+0xeb/0x130
[ 319.281946] [<ffffffff810c2070>] lru_add_drain_all+0x10/0x20
[ 319.281948] [<ffffffff81120578>] invalidate_bdev+0x28/0x40
[ 319.281950] [<ffffffff8112696a>] __invalidate_device+0x4a/0x60
[ 319.281952] [<ffffffff81126a78>] flush_disk+0x18/0xa0
[ 319.281953] [<ffffffff81126be8>] check_disk_size_change+0x78/0x80
[ 319.281955] [<ffffffff811271b1>] revalidate_disk+0x61/0x90
[ 319.281957] [<ffffffff813ba499>] do_md_run+0x59/0xa0
[ 319.281959] [<ffffffff813bbb78>] md_ioctl+0x928/0x1100
[ 319.281961] [<ffffffff811b87f8>] blkdev_ioctl+0x228/0x700
[ 319.281962] [<ffffffff8112681c>] block_ioctl+0x3c/0x40
[ 319.281964] [<ffffffff81107dc7>] do_vfs_ioctl+0x97/0x580
[ 319.281966] [<ffffffff81108329>] sys_ioctl+0x79/0x90
[ 319.281968] [<ffffffff8100273b>] system_call_fastpath+0x16/0x1b
[ 319.281970]
[ 319.281970] -> #0 (&bdev->bd_mutex){+.+.+.}:
[ 319.281972] [<ffffffff8107af58>] __lock_acquire+0x1698/0x1ca0
[ 319.281973] [<ffffffff8107baa7>] lock_acquire+0x57/0x70
[ 319.281975] [<ffffffff81492fae>] mutex_lock_nested+0x5e/0x380
[ 319.281976] [<ffffffff811271a6>] revalidate_disk+0x56/0x90
[ 319.281978] [<ffffffffa0055c92>] sd_rescan+0x22/0x40 [sd_mod]
[ 319.281981] [<ffffffff81346ed6>] scsi_rescan_device+0xa6/0xd0
[ 319.281984] [<ffffffff813604aa>] ata_scsi_dev_rescan+0xba/0x120
[ 319.281985] [<ffffffff81060722>] process_one_work+0x1a2/0x450
[ 319.281987] [<ffffffff81061ee2>] worker_thread+0x162/0x340
[ 319.281989] [<ffffffff810668e6>] kthread+0x96/0xa0
[ 319.281990] [<ffffffff81003594>] kernel_thread_helper+0x4/0x10
[ 319.281992]
[ 319.281993] other info that might help us debug this:
[ 319.281993]
[ 319.281994] 3 locks held by kworker/1:0/13333:
[ 319.281995] #0: (events){+.+.+.}, at: [<ffffffff810606c4>] process_one_work+0x144/0x450
[ 319.281998] #1: ((&ap->scsi_rescan_task)){+.+...}, at: [<ffffffff810606c4>] process_one_work+0x144/0x450
[ 319.282000] #2: (&ap->scsi_scan_mutex){+.+...}, at: [<ffffffff81360420>] ata_scsi_dev_rescan+0x30/0x120
[ 319.282003]
[ 319.282003] stack backtrace:
[ 319.282005] Pid: 13333, comm: kworker/1:0 Not tainted 2.6.37-rc7+ #16
[ 319.282006] Call Trace:
[ 319.282008] [<ffffffff81078707>] print_circular_bug+0xe7/0xf0
[ 319.282010] [<ffffffff8107af58>] __lock_acquire+0x1698/0x1ca0
[ 319.282013] [<ffffffff81044001>] ? get_parent_ip+0x11/0x50
[ 319.282015] [<ffffffff811271a6>] ? revalidate_disk+0x56/0x90
[ 319.282017] [<ffffffff8107baa7>] lock_acquire+0x57/0x70
[ 319.282019] [<ffffffff811271a6>] ? revalidate_disk+0x56/0x90
[ 319.282020] [<ffffffff810441a5>] ? add_preempt_count+0x95/0xd0
[ 319.282022] [<ffffffff81492fae>] mutex_lock_nested+0x5e/0x380
[ 319.282024] [<ffffffff811271a6>] ? revalidate_disk+0x56/0x90
[ 319.282026] [<ffffffff811c49e7>] ? kobject_put+0x27/0x60
[ 319.282028] [<ffffffff811b9784>] ? disk_get_part+0x14/0xa0
[ 319.282030] [<ffffffff81329b22>] ? put_device+0x12/0x20
[ 319.282032] [<ffffffff811271a6>] revalidate_disk+0x56/0x90
[ 319.282035] [<ffffffffa0055c92>] sd_rescan+0x22/0x40 [sd_mod]
[ 319.282037] [<ffffffff81346ed6>] scsi_rescan_device+0xa6/0xd0
[ 319.282038] [<ffffffff813604aa>] ata_scsi_dev_rescan+0xba/0x120
[ 319.282040] [<ffffffff81060722>] process_one_work+0x1a2/0x450
[ 319.282042] [<ffffffff810606c4>] ? process_one_work+0x144/0x450
[ 319.282044] [<ffffffff813603f0>] ? ata_scsi_dev_rescan+0x0/0x120
[ 319.282045] [<ffffffff81061ee2>] worker_thread+0x162/0x340
[ 319.282047] [<ffffffff81061d80>] ? worker_thread+0x0/0x340
[ 319.282049] [<ffffffff810668e6>] kthread+0x96/0xa0
[ 319.282051] [<ffffffff81003594>] kernel_thread_helper+0x4/0x10
[ 319.282052] [<ffffffff810375ab>] ? finish_task_switch+0x7b/0xe0
[ 319.282055] [<ffffffff81495d00>] ? restore_args+0x0/0x30
[ 319.282056] [<ffffffff81066850>] ? kthread+0x0/0xa0
[ 319.282058] [<ffffffff81003590>] ? kernel_thread_helper+0x0/0x10
[ 319.288123] ata3.00: configured for UDMA/133
[ 319.346789] firewire_core: rediscovered device fw0
[ 319.683384] usb 3-3: reset low speed USB device using ohci_hcd and address 3
[ 319.992978] PM: restore of devices complete after 1208.480 msecs
The kernel is more-or-less current Linus' tree.
Full dmesg is attached, please let me know if you need any more information.
Thanks,
Rafael
View attachment "desktop.log" of type "text/x-log" (117919 bytes)
Powered by blists - more mailing lists