* INFO: possible circular locking in the resume
@ 2008-02-26 23:29 Zdenek Kabelac
2008-02-27 0:17 ` Andrew Morton
0 siblings, 1 reply; 5+ messages in thread
From: Zdenek Kabelac @ 2008-02-26 23:29 UTC (permalink / raw)
To: Kernel development list
Hi
I'm getting this INFO: from suspend/resume process.
(Kernel uses patches from this bugzilla to survive suspend
http://bugzilla.kernel.org/show_bug.cgi?id=10030)
(Config is available in the bugzilla)
[ 42.097522] MMC: killing requests for dead queue
[ 42.098738] PM: Finishing wakeup.
[ 42.098740] Restarting tasks ... <6>usb 3-2: USB disconnect, address 2
[ 42.129810] done.
[ 42.258523]
[ 42.258524] =======================================================
[ 42.258626] [ INFO: possible circular locking dependency detected ]
[ 42.258681] 2.6.25-rc3 #81
[ 42.258736] -------------------------------------------------------
[ 42.258787] sh/1973 is trying to acquire lock:
[ 42.258839] (&cpu_hotplug.lock){--..}, at: [<ffffffff8106d7a5>]
get_online_cpus+0x35/0x50
[ 42.259068]
[ 42.259068] but task is already holding lock:
[ 42.259166] (&sp->mutex){--..}, at: [<ffffffff8105adb0>]
synchronize_srcu+0x20/0x90
[ 42.259376]
[ 42.259377] which lock already depends on the new lock.
[ 42.259377]
[ 42.259501]
[ 42.259501] the existing dependency chain (in reverse order) is:
[ 42.259501]
[ 42.259501] -> #3 (&sp->mutex){--..}:
[ 42.259501] [<ffffffff81066d30>] __lock_acquire+0xfb0/0x1040
[ 42.259501] [<ffffffff81066e68>] lock_acquire+0xa8/0xf0
[ 42.259501] [<ffffffff812ef5ac>] mutex_lock_nested+0xcc/0x370
[ 42.259501] [<ffffffff8105adb0>] synchronize_srcu+0x20/0x90
[ 42.259501] [<ffffffff8105b2b4>]
srcu_notifier_chain_unregister+0x74/0xe0
[ 42.259501] [<ffffffff8125a337>] cpufreq_unregister_notifier+0x17/0x40
[ 42.259501] [<ffffffff8829e296>]
cpufreq_governor_userspace+0x1b6/0x1f4 [cpufreq_userspace]
[ 42.259501] [<ffffffff81259923>] __cpufreq_governor+0xd3/0x150
[ 42.259501] [<ffffffff8125a0b5>] __cpufreq_set_policy+0x115/0x170
[ 42.259501] [<ffffffff8125a819>] store_scaling_governor+0xc9/0x260
[ 42.259501] [<ffffffff8125b527>] store+0x87/0xa0
[ 42.259501] [<ffffffff811101fa>] sysfs_write_file+0xca/0x140
[ 42.259501] [<ffffffff810bb82b>] vfs_write+0xcb/0x170
[ 42.259501] [<ffffffff810bb9c0>] sys_write+0x50/0x90
[ 42.259501] [<ffffffff8100c70a>] system_call_after_swapgs+0x8a/0x8f
[ 42.259501] [<ffffffffffffffff>] 0xffffffffffffffff
[ 42.259501]
[ 42.259501] -> #2 (userspace_mutex){--..}:
[ 42.259501] [<ffffffff81066d30>] __lock_acquire+0xfb0/0x1040
[ 42.259501] [<ffffffff81066e68>] lock_acquire+0xa8/0xf0
[ 42.259501] [<ffffffff812ef5ac>] mutex_lock_nested+0xcc/0x370
[ 42.259501] [<ffffffff8829e13c>]
cpufreq_governor_userspace+0x5c/0x1f4 [cpufreq_userspace]
[ 42.259501] [<ffffffff81259923>] __cpufreq_governor+0xd3/0x150
[ 42.259501] [<ffffffff8125a0cb>] __cpufreq_set_policy+0x12b/0x170
[ 42.259501] [<ffffffff8125a819>] store_scaling_governor+0xc9/0x260
[ 42.259501] [<ffffffff8125b527>] store+0x87/0xa0
[ 42.259501] [<ffffffff811101fa>] sysfs_write_file+0xca/0x140
[ 42.259501] [<ffffffff810bb82b>] vfs_write+0xcb/0x170
[ 42.259501] [<ffffffff810bb9c0>] sys_write+0x50/0x90
[ 42.259501] [<ffffffff8100c70a>] system_call_after_swapgs+0x8a/0x8f
[ 42.259501] [<ffffffffffffffff>] 0xffffffffffffffff
[ 42.259501]
[ 42.259501] -> #1 (&per_cpu(cpu_policy_rwsem, cpu)){----}:
[ 42.259501] [<ffffffff81066d30>] __lock_acquire+0xfb0/0x1040
[ 42.259501] [<ffffffff81066e68>] lock_acquire+0xa8/0xf0
[ 42.259501] [<ffffffff812effc8>] down_write+0x38/0x70
[ 42.259501] [<ffffffff8125ae7c>] lock_policy_rwsem_write+0x4c/0x90
[ 42.259501] [<ffffffff812edbed>] cpufreq_cpu_callback+0x6d/0x90
[ 42.259501] [<ffffffff812f578f>] notifier_call_chain+0x3f/0x80
[ 42.259501] [<ffffffff8105b059>] __raw_notifier_call_chain+0x9/0x10
[ 42.259501] [<ffffffff8106d368>] _cpu_down+0xa8/0x290
[ 42.259501] [<ffffffff8106d621>] disable_nonboot_cpus+0x71/0x110
[ 42.259501] [<ffffffff810730d5>] suspend_devices_and_enter+0xe5/0x1a0
[ 42.259501] [<ffffffff81073306>] enter_state+0x146/0x1d0
[ 42.259501] [<ffffffff8107344a>] state_store+0xba/0x100
[ 42.259501] [<ffffffff811757f7>] kobj_attr_store+0x17/0x20
[ 42.259501] [<ffffffff811101fa>] sysfs_write_file+0xca/0x140
[ 42.259501] [<ffffffff810bb82b>] vfs_write+0xcb/0x170
[ 42.259501] [<ffffffff810bb9c0>] sys_write+0x50/0x90
[ 42.259501] [<ffffffff8100c70a>] system_call_after_swapgs+0x8a/0x8f
[ 42.259501] [<ffffffffffffffff>] 0xffffffffffffffff
[ 42.259501]
[ 42.259501] -> #0 (&cpu_hotplug.lock){--..}:
[ 42.259501] [<ffffffff81066c3d>] __lock_acquire+0xebd/0x1040
[ 42.259501] [<ffffffff81066e68>] lock_acquire+0xa8/0xf0
[ 42.259501] [<ffffffff812ef5ac>] mutex_lock_nested+0xcc/0x370
[ 42.259501] [<ffffffff8106d7a5>] get_online_cpus+0x35/0x50
[ 42.259501] [<ffffffff8103837e>] sched_getaffinity+0x1e/0xa0
[ 42.259501] [<ffffffff8108b386>] __synchronize_sched+0x16/0x90
[ 42.259501] [<ffffffff8105add5>] synchronize_srcu+0x45/0x90
[ 42.259501] [<ffffffff8105b2b4>]
srcu_notifier_chain_unregister+0x74/0xe0
[ 42.259501] [<ffffffff8125a337>] cpufreq_unregister_notifier+0x17/0x40
[ 42.259501] [<ffffffff8829e296>]
cpufreq_governor_userspace+0x1b6/0x1f4 [cpufreq_userspace]
[ 42.259501] [<ffffffff81259923>] __cpufreq_governor+0xd3/0x150
[ 42.259501] [<ffffffff8125a0b5>] __cpufreq_set_policy+0x115/0x170
[ 42.259501] [<ffffffff8125a819>] store_scaling_governor+0xc9/0x260
[ 42.259501] [<ffffffff8125b527>] store+0x87/0xa0
[ 42.259501] [<ffffffff811101fa>] sysfs_write_file+0xca/0x140
[ 42.259501] [<ffffffff810bb82b>] vfs_write+0xcb/0x170
[ 42.259501] [<ffffffff810bb9c0>] sys_write+0x50/0x90
[ 42.259501] [<ffffffff8100c70a>] system_call_after_swapgs+0x8a/0x8f
[ 42.259501] [<ffffffffffffffff>] 0xffffffffffffffff
[ 42.259501]
[ 42.259501] other info that might help us debug this:
[ 42.259501]
[ 42.259501] 4 locks held by sh/1973:
[ 42.259501] #0: (&buffer->mutex){--..}, at: [<ffffffff81110173>]
sysfs_write_file+0x43/0x140
[ 42.259501] #1: (&per_cpu(cpu_policy_rwsem, cpu)){----}, at:
[<ffffffff8125ae7c>] lock_policy_rwsem_write+0x4c/0x90
[ 42.259501] #2: (userspace_mutex){--..}, at: [<ffffffff8829e22e>]
cpufreq_governor_userspace+0x14e/0x1f4 [cpufreq_userspace]
[ 42.259501] #3: (&sp->mutex){--..}, at: [<ffffffff8105adb0>]
synchronize_srcu+0x20/0x90
[ 42.259501]
[ 42.259501] stack backtrace:
[ 42.259501] Pid: 1973, comm: sh Not tainted 2.6.25-rc3 #81
[ 42.259501]
[ 42.259501] Call Trace:
[ 42.259501] [<ffffffff81065ac4>] print_circular_bug_tail+0x84/0x90
[ 42.259501] [<ffffffff81065872>] ? print_circular_bug_entry+0x52/0x60
[ 42.259501] [<ffffffff81066c3d>] __lock_acquire+0xebd/0x1040
[ 42.259501] [<ffffffff8106353b>] ? find_usage_backwards+0xcb/0x110
[ 42.259502] [<ffffffff8106353b>] ? find_usage_backwards+0xcb/0x110
[ 42.259502] [<ffffffff8106d7a5>] ? get_online_cpus+0x35/0x50
[ 42.259502] [<ffffffff81066e68>] lock_acquire+0xa8/0xf0
[ 42.259502] [<ffffffff8106d7a5>] ? get_online_cpus+0x35/0x50
[ 42.259502] [<ffffffff812ef5ac>] mutex_lock_nested+0xcc/0x370
[ 42.259502] [<ffffffff8106d7a5>] ? get_online_cpus+0x35/0x50
[ 42.259502] [<ffffffff81065649>] ? trace_hardirqs_on+0x139/0x1a0
[ 42.259502] [<ffffffff8106d7a5>] get_online_cpus+0x35/0x50
[ 42.259502] [<ffffffff8103837e>] sched_getaffinity+0x1e/0xa0
[ 42.259502] [<ffffffff8108b386>] __synchronize_sched+0x16/0x90
[ 42.259502] [<ffffffff8105add5>] synchronize_srcu+0x45/0x90
[ 42.259502] [<ffffffff8105b2b4>] srcu_notifier_chain_unregister+0x74/0xe0
[ 42.259502] [<ffffffff8125a337>] cpufreq_unregister_notifier+0x17/0x40
[ 42.259502] [<ffffffff8829e296>]
:cpufreq_userspace:cpufreq_governor_userspace+0x1b6/0x1f4
[ 42.259502] [<ffffffff81259923>] __cpufreq_governor+0xd3/0x150
[ 42.259502] [<ffffffff8125a0b5>] __cpufreq_set_policy+0x115/0x170
[ 42.259502] [<ffffffff8125a819>] store_scaling_governor+0xc9/0x260
[ 42.259502] [<ffffffff8125b650>] ? handle_update+0x0/0x10
[ 42.259502] [<ffffffff812efff0>] ? down_write+0x60/0x70
[ 42.259502] [<ffffffff8125b527>] store+0x87/0xa0
[ 42.259502] [<ffffffff811101fa>] sysfs_write_file+0xca/0x140
[ 42.259502] [<ffffffff810bb82b>] vfs_write+0xcb/0x170
[ 42.259502] [<ffffffff810bb9c0>] sys_write+0x50/0x90
[ 42.259502] [<ffffffff8100c70a>] system_call_after_swapgs+0x8a/0x8f
[ 42.259502]
[ 41.439840] mmc0: new SD card at address 5a61
[ 41.440027] mmcblk0: mmc0:5a61 S016B 14560KiB
[ 41.440123] mmcblk0: p1
[ 41.916006] usb 3-2: new full speed USB device using uhci_hcd and address 3
[ 42.900716] usb 3-2: configuration #1 chosen from 1 choice
[ 42.080814] usb 3-2: New USB device found, idVendor=0483, idProduct=2016
[ 42.080939] usb 3-2: New USB device strings: Mfr=1, Product=2, SerialNumber=0
[ 42.081094] usb 3-2: Product: Biometric Coprocessor
[ 42.081212] usb 3-2: Manufacturer: STMicroelectronics
[ 47.925651] PM: Syncing filesystems ... done.
[ 47.925845] PM: Preparing system for mem sleep
[ 47.925925] Freezing user space processes ... (elapsed 0.00 seconds) done.
[ 47.926302] Freezing remaining freezable tasks ... (elapsed 0.00
seconds) done.
[ 47.926596] PM: Entering mem sleep
[ 47.929993] ACPI: Preparing to enter system sleep state S3
[ 49.169572] sd 0:0:0:0: [sda] Synchronizing SCSI cache
[ 49.169771] sd 0:0:0:0: [sda] Stopping disk
[ 51.204365] mmc0: card 5a61 removed
[ 51.204365] ACPI handle has no context!
[ 51.204365] ACPI: PCI interrupt for device 0000:15:00.2 disabled
[ 51.204365] ACPI handle has no context!
^ permalink raw reply [flat|nested] 5+ messages in thread
* Re: INFO: possible circular locking in the resume
2008-02-26 23:29 INFO: possible circular locking in the resume Zdenek Kabelac
@ 2008-02-27 0:17 ` Andrew Morton
2008-02-28 5:14 ` Gautham R Shenoy
0 siblings, 1 reply; 5+ messages in thread
From: Andrew Morton @ 2008-02-27 0:17 UTC (permalink / raw)
To: Zdenek Kabelac; +Cc: Kernel development list, linux-usb, Gautham R Shenoy
On Wed, 27 Feb 2008 00:29:21 +0100 "Zdenek Kabelac" <zdenek.kabelac@gmail.com> wrote:
> Hi
>
> I'm getting this INFO: from suspend/resume process.
> (Kernel uses patches from this bugzilla to survive suspend
> http://bugzilla.kernel.org/show_bug.cgi?id=10030)
> (Config is available in the bugzilla)
>
>
> [ 42.097522] MMC: killing requests for dead queue
> [ 42.098738] PM: Finishing wakeup.
> [ 42.098740] Restarting tasks ... <6>usb 3-2: USB disconnect, address 2
> [ 42.129810] done.
> [ 42.258523]
> [ 42.258524] =======================================================
> [ 42.258626] [ INFO: possible circular locking dependency detected ]
> [ 42.258681] 2.6.25-rc3 #81
> [ 42.258736] -------------------------------------------------------
> [ 42.258787] sh/1973 is trying to acquire lock:
> [ 42.258839] (&cpu_hotplug.lock){--..}, at: [<ffffffff8106d7a5>]
> get_online_cpus+0x35/0x50
heh.
> [ 42.259068]
> [ 42.259068] but task is already holding lock:
> [ 42.259166] (&sp->mutex){--..}, at: [<ffffffff8105adb0>]
> synchronize_srcu+0x20/0x90
> [ 42.259376]
> [ 42.259377] which lock already depends on the new lock.
> [ 42.259377]
> [ 42.259501]
> [ 42.259501] the existing dependency chain (in reverse order) is:
> [ 42.259501]
> [ 42.259501] -> #3 (&sp->mutex){--..}:
> [ 42.259501] [<ffffffff81066d30>] __lock_acquire+0xfb0/0x1040
> [ 42.259501] [<ffffffff81066e68>] lock_acquire+0xa8/0xf0
> [ 42.259501] [<ffffffff812ef5ac>] mutex_lock_nested+0xcc/0x370
> [ 42.259501] [<ffffffff8105adb0>] synchronize_srcu+0x20/0x90
> [ 42.259501] [<ffffffff8105b2b4>]
> srcu_notifier_chain_unregister+0x74/0xe0
> [ 42.259501] [<ffffffff8125a337>] cpufreq_unregister_notifier+0x17/0x40
> [ 42.259501] [<ffffffff8829e296>]
> cpufreq_governor_userspace+0x1b6/0x1f4 [cpufreq_userspace]
> [ 42.259501] [<ffffffff81259923>] __cpufreq_governor+0xd3/0x150
> [ 42.259501] [<ffffffff8125a0b5>] __cpufreq_set_policy+0x115/0x170
> [ 42.259501] [<ffffffff8125a819>] store_scaling_governor+0xc9/0x260
> [ 42.259501] [<ffffffff8125b527>] store+0x87/0xa0
> [ 42.259501] [<ffffffff811101fa>] sysfs_write_file+0xca/0x140
> [ 42.259501] [<ffffffff810bb82b>] vfs_write+0xcb/0x170
> [ 42.259501] [<ffffffff810bb9c0>] sys_write+0x50/0x90
> [ 42.259501] [<ffffffff8100c70a>] system_call_after_swapgs+0x8a/0x8f
> [ 42.259501] [<ffffffffffffffff>] 0xffffffffffffffff
> [ 42.259501]
> [ 42.259501] -> #2 (userspace_mutex){--..}:
> [ 42.259501] [<ffffffff81066d30>] __lock_acquire+0xfb0/0x1040
> [ 42.259501] [<ffffffff81066e68>] lock_acquire+0xa8/0xf0
> [ 42.259501] [<ffffffff812ef5ac>] mutex_lock_nested+0xcc/0x370
> [ 42.259501] [<ffffffff8829e13c>]
> cpufreq_governor_userspace+0x5c/0x1f4 [cpufreq_userspace]
> [ 42.259501] [<ffffffff81259923>] __cpufreq_governor+0xd3/0x150
> [ 42.259501] [<ffffffff8125a0cb>] __cpufreq_set_policy+0x12b/0x170
> [ 42.259501] [<ffffffff8125a819>] store_scaling_governor+0xc9/0x260
> [ 42.259501] [<ffffffff8125b527>] store+0x87/0xa0
> [ 42.259501] [<ffffffff811101fa>] sysfs_write_file+0xca/0x140
> [ 42.259501] [<ffffffff810bb82b>] vfs_write+0xcb/0x170
> [ 42.259501] [<ffffffff810bb9c0>] sys_write+0x50/0x90
> [ 42.259501] [<ffffffff8100c70a>] system_call_after_swapgs+0x8a/0x8f
> [ 42.259501] [<ffffffffffffffff>] 0xffffffffffffffff
> [ 42.259501]
> [ 42.259501] -> #1 (&per_cpu(cpu_policy_rwsem, cpu)){----}:
> [ 42.259501] [<ffffffff81066d30>] __lock_acquire+0xfb0/0x1040
> [ 42.259501] [<ffffffff81066e68>] lock_acquire+0xa8/0xf0
> [ 42.259501] [<ffffffff812effc8>] down_write+0x38/0x70
> [ 42.259501] [<ffffffff8125ae7c>] lock_policy_rwsem_write+0x4c/0x90
> [ 42.259501] [<ffffffff812edbed>] cpufreq_cpu_callback+0x6d/0x90
> [ 42.259501] [<ffffffff812f578f>] notifier_call_chain+0x3f/0x80
> [ 42.259501] [<ffffffff8105b059>] __raw_notifier_call_chain+0x9/0x10
> [ 42.259501] [<ffffffff8106d368>] _cpu_down+0xa8/0x290
> [ 42.259501] [<ffffffff8106d621>] disable_nonboot_cpus+0x71/0x110
> [ 42.259501] [<ffffffff810730d5>] suspend_devices_and_enter+0xe5/0x1a0
> [ 42.259501] [<ffffffff81073306>] enter_state+0x146/0x1d0
> [ 42.259501] [<ffffffff8107344a>] state_store+0xba/0x100
> [ 42.259501] [<ffffffff811757f7>] kobj_attr_store+0x17/0x20
> [ 42.259501] [<ffffffff811101fa>] sysfs_write_file+0xca/0x140
> [ 42.259501] [<ffffffff810bb82b>] vfs_write+0xcb/0x170
> [ 42.259501] [<ffffffff810bb9c0>] sys_write+0x50/0x90
> [ 42.259501] [<ffffffff8100c70a>] system_call_after_swapgs+0x8a/0x8f
> [ 42.259501] [<ffffffffffffffff>] 0xffffffffffffffff
> [ 42.259501]
> [ 42.259501] -> #0 (&cpu_hotplug.lock){--..}:
> [ 42.259501] [<ffffffff81066c3d>] __lock_acquire+0xebd/0x1040
> [ 42.259501] [<ffffffff81066e68>] lock_acquire+0xa8/0xf0
> [ 42.259501] [<ffffffff812ef5ac>] mutex_lock_nested+0xcc/0x370
> [ 42.259501] [<ffffffff8106d7a5>] get_online_cpus+0x35/0x50
> [ 42.259501] [<ffffffff8103837e>] sched_getaffinity+0x1e/0xa0
> [ 42.259501] [<ffffffff8108b386>] __synchronize_sched+0x16/0x90
> [ 42.259501] [<ffffffff8105add5>] synchronize_srcu+0x45/0x90
> [ 42.259501] [<ffffffff8105b2b4>]
> srcu_notifier_chain_unregister+0x74/0xe0
> [ 42.259501] [<ffffffff8125a337>] cpufreq_unregister_notifier+0x17/0x40
> [ 42.259501] [<ffffffff8829e296>]
> cpufreq_governor_userspace+0x1b6/0x1f4 [cpufreq_userspace]
> [ 42.259501] [<ffffffff81259923>] __cpufreq_governor+0xd3/0x150
> [ 42.259501] [<ffffffff8125a0b5>] __cpufreq_set_policy+0x115/0x170
> [ 42.259501] [<ffffffff8125a819>] store_scaling_governor+0xc9/0x260
> [ 42.259501] [<ffffffff8125b527>] store+0x87/0xa0
> [ 42.259501] [<ffffffff811101fa>] sysfs_write_file+0xca/0x140
> [ 42.259501] [<ffffffff810bb82b>] vfs_write+0xcb/0x170
> [ 42.259501] [<ffffffff810bb9c0>] sys_write+0x50/0x90
> [ 42.259501] [<ffffffff8100c70a>] system_call_after_swapgs+0x8a/0x8f
> [ 42.259501] [<ffffffffffffffff>] 0xffffffffffffffff
> [ 42.259501]
> [ 42.259501] other info that might help us debug this:
> [ 42.259501]
> [ 42.259501] 4 locks held by sh/1973:
> [ 42.259501] #0: (&buffer->mutex){--..}, at: [<ffffffff81110173>]
> sysfs_write_file+0x43/0x140
> [ 42.259501] #1: (&per_cpu(cpu_policy_rwsem, cpu)){----}, at:
> [<ffffffff8125ae7c>] lock_policy_rwsem_write+0x4c/0x90
> [ 42.259501] #2: (userspace_mutex){--..}, at: [<ffffffff8829e22e>]
> cpufreq_governor_userspace+0x14e/0x1f4 [cpufreq_userspace]
> [ 42.259501] #3: (&sp->mutex){--..}, at: [<ffffffff8105adb0>]
> synchronize_srcu+0x20/0x90
> [ 42.259501]
> [ 42.259501] stack backtrace:
> [ 42.259501] Pid: 1973, comm: sh Not tainted 2.6.25-rc3 #81
> [ 42.259501]
> [ 42.259501] Call Trace:
> [ 42.259501] [<ffffffff81065ac4>] print_circular_bug_tail+0x84/0x90
> [ 42.259501] [<ffffffff81065872>] ? print_circular_bug_entry+0x52/0x60
> [ 42.259501] [<ffffffff81066c3d>] __lock_acquire+0xebd/0x1040
> [ 42.259501] [<ffffffff8106353b>] ? find_usage_backwards+0xcb/0x110
> [ 42.259502] [<ffffffff8106353b>] ? find_usage_backwards+0xcb/0x110
> [ 42.259502] [<ffffffff8106d7a5>] ? get_online_cpus+0x35/0x50
> [ 42.259502] [<ffffffff81066e68>] lock_acquire+0xa8/0xf0
> [ 42.259502] [<ffffffff8106d7a5>] ? get_online_cpus+0x35/0x50
> [ 42.259502] [<ffffffff812ef5ac>] mutex_lock_nested+0xcc/0x370
> [ 42.259502] [<ffffffff8106d7a5>] ? get_online_cpus+0x35/0x50
> [ 42.259502] [<ffffffff81065649>] ? trace_hardirqs_on+0x139/0x1a0
> [ 42.259502] [<ffffffff8106d7a5>] get_online_cpus+0x35/0x50
> [ 42.259502] [<ffffffff8103837e>] sched_getaffinity+0x1e/0xa0
> [ 42.259502] [<ffffffff8108b386>] __synchronize_sched+0x16/0x90
> [ 42.259502] [<ffffffff8105add5>] synchronize_srcu+0x45/0x90
> [ 42.259502] [<ffffffff8105b2b4>] srcu_notifier_chain_unregister+0x74/0xe0
> [ 42.259502] [<ffffffff8125a337>] cpufreq_unregister_notifier+0x17/0x40
> [ 42.259502] [<ffffffff8829e296>]
> :cpufreq_userspace:cpufreq_governor_userspace+0x1b6/0x1f4
> [ 42.259502] [<ffffffff81259923>] __cpufreq_governor+0xd3/0x150
> [ 42.259502] [<ffffffff8125a0b5>] __cpufreq_set_policy+0x115/0x170
> [ 42.259502] [<ffffffff8125a819>] store_scaling_governor+0xc9/0x260
> [ 42.259502] [<ffffffff8125b650>] ? handle_update+0x0/0x10
> [ 42.259502] [<ffffffff812efff0>] ? down_write+0x60/0x70
> [ 42.259502] [<ffffffff8125b527>] store+0x87/0xa0
> [ 42.259502] [<ffffffff811101fa>] sysfs_write_file+0xca/0x140
> [ 42.259502] [<ffffffff810bb82b>] vfs_write+0xcb/0x170
> [ 42.259502] [<ffffffff810bb9c0>] sys_write+0x50/0x90
> [ 42.259502] [<ffffffff8100c70a>] system_call_after_swapgs+0x8a/0x8f
> [ 42.259502]
> [ 41.439840] mmc0: new SD card at address 5a61
> [ 41.440027] mmcblk0: mmc0:5a61 S016B 14560KiB
> [ 41.440123] mmcblk0: p1
> [ 41.916006] usb 3-2: new full speed USB device using uhci_hcd and address 3
> [ 42.900716] usb 3-2: configuration #1 chosen from 1 choice
> [ 42.080814] usb 3-2: New USB device found, idVendor=0483, idProduct=2016
> [ 42.080939] usb 3-2: New USB device strings: Mfr=1, Product=2, SerialNumber=0
> [ 42.081094] usb 3-2: Product: Biometric Coprocessor
> [ 42.081212] usb 3-2: Manufacturer: STMicroelectronics
> [ 47.925651] PM: Syncing filesystems ... done.
> [ 47.925845] PM: Preparing system for mem sleep
> [ 47.925925] Freezing user space processes ... (elapsed 0.00 seconds) done.
> [ 47.926302] Freezing remaining freezable tasks ... (elapsed 0.00
> seconds) done.
> [ 47.926596] PM: Entering mem sleep
> [ 47.929993] ACPI: Preparing to enter system sleep state S3
> [ 49.169572] sd 0:0:0:0: [sda] Synchronizing SCSI cache
> [ 49.169771] sd 0:0:0:0: [sda] Stopping disk
> [ 51.204365] mmc0: card 5a61 removed
> [ 51.204365] ACPI handle has no context!
> [ 51.204365] ACPI: PCI interrupt for device 0000:15:00.2 disabled
> [ 51.204365] ACPI handle has no context!
Something for Gautham and the USB people to scratch their heads over.
^ permalink raw reply [flat|nested] 5+ messages in thread
* Re: INFO: possible circular locking in the resume
2008-02-27 0:17 ` Andrew Morton
@ 2008-02-28 5:14 ` Gautham R Shenoy
0 siblings, 0 replies; 5+ messages in thread
From: Gautham R Shenoy @ 2008-02-28 5:14 UTC (permalink / raw)
To: Andrew Morton; +Cc: Zdenek Kabelac, Kernel development list, linux-usb
On Tue, Feb 26, 2008 at 04:17:59PM -0800, Andrew Morton wrote:
> On Wed, 27 Feb 2008 00:29:21 +0100 "Zdenek Kabelac" <zdenek.kabelac@gmail.com> wrote:
>
> > Hi
> >
> > I'm getting this INFO: from suspend/resume process.
> > (Kernel uses patches from this bugzilla to survive suspend
> > http://bugzilla.kernel.org/show_bug.cgi?id=10030)
> > (Config is available in the bugzilla)
> >
> >
> > [ 42.097522] MMC: killing requests for dead queue
> > [ 42.098738] PM: Finishing wakeup.
> > [ 42.098740] Restarting tasks ... <6>usb 3-2: USB disconnect, address 2
> > [ 42.129810] done.
> > [ 42.258523]
> > [ 42.258524] =======================================================
> > [ 42.258626] [ INFO: possible circular locking dependency detected ]
> > [ 42.258681] 2.6.25-rc3 #81
> > [ 42.258736] -------------------------------------------------------
> > [ 42.258787] sh/1973 is trying to acquire lock:
> > [ 42.258839] (&cpu_hotplug.lock){--..}, at: [<ffffffff8106d7a5>]
> > get_online_cpus+0x35/0x50
>
> heh.
This have been pretty silent on this front for quite sometime now :)
This has nothing to do with bluetooth/srcu/cpufreq per se.
If I am not mistaken, this can be reproduced by running cpu-hotplug
in a tight loop, while trying to change the cpufreq governor to userspace.
The problem here being that on the read-path, we use cpu_hotplug.lock
to just increment the refcount. We don't hold the lock once we are done
with that. But on the write path, we hold the lock to block any readers.
And thus, in lockdep's dependency chain, we have this dependency between
sp->mutex --> per_cpu(cpu_policy_rwsem, cpu) --> cpu_hotplug.lock in the
reverse order in the write path.
and
cpu_hotplug.lock --> sp->mutex on the read-path, i.e synchronize_srcu().
This can be solved by using a spin_lock to increment the refcount and
check for the writer, and a waitqueue for refcount
queueing the readers when a write is in progress, thus getting rid of
the mutex totally.
I have the patch, but it needs to be tested. Will post it later today.
Thanks for pointing this out :)
>
> > [ 42.259068]
> > [ 42.259068] but task is already holding lock:
> > [ 42.259166] (&sp->mutex){--..}, at: [<ffffffff8105adb0>]
> > synchronize_srcu+0x20/0x90
> > [ 42.259376]
> > [ 42.259377] which lock already depends on the new lock.
> > [ 42.259377]
> > [ 42.259501]
> > [ 42.259501] the existing dependency chain (in reverse order) is:
> > [ 42.259501]
> > [ 42.259501] -> #3 (&sp->mutex){--..}:
> > [ 42.259501] [<ffffffff81066d30>] __lock_acquire+0xfb0/0x1040
> > [ 42.259501] [<ffffffff81066e68>] lock_acquire+0xa8/0xf0
> > [ 42.259501] [<ffffffff812ef5ac>] mutex_lock_nested+0xcc/0x370
> > [ 42.259501] [<ffffffff8105adb0>] synchronize_srcu+0x20/0x90
> > [ 42.259501] [<ffffffff8105b2b4>]
> > srcu_notifier_chain_unregister+0x74/0xe0
> > [ 42.259501] [<ffffffff8125a337>] cpufreq_unregister_notifier+0x17/0x40
> > [ 42.259501] [<ffffffff8829e296>]
> > cpufreq_governor_userspace+0x1b6/0x1f4 [cpufreq_userspace]
> > [ 42.259501] [<ffffffff81259923>] __cpufreq_governor+0xd3/0x150
> > [ 42.259501] [<ffffffff8125a0b5>] __cpufreq_set_policy+0x115/0x170
> > [ 42.259501] [<ffffffff8125a819>] store_scaling_governor+0xc9/0x260
> > [ 42.259501] [<ffffffff8125b527>] store+0x87/0xa0
> > [ 42.259501] [<ffffffff811101fa>] sysfs_write_file+0xca/0x140
> > [ 42.259501] [<ffffffff810bb82b>] vfs_write+0xcb/0x170
> > [ 42.259501] [<ffffffff810bb9c0>] sys_write+0x50/0x90
> > [ 42.259501] [<ffffffff8100c70a>] system_call_after_swapgs+0x8a/0x8f
> > [ 42.259501] [<ffffffffffffffff>] 0xffffffffffffffff
> > [ 42.259501]
> > [ 42.259501] -> #2 (userspace_mutex){--..}:
> > [ 42.259501] [<ffffffff81066d30>] __lock_acquire+0xfb0/0x1040
> > [ 42.259501] [<ffffffff81066e68>] lock_acquire+0xa8/0xf0
> > [ 42.259501] [<ffffffff812ef5ac>] mutex_lock_nested+0xcc/0x370
> > [ 42.259501] [<ffffffff8829e13c>]
> > cpufreq_governor_userspace+0x5c/0x1f4 [cpufreq_userspace]
> > [ 42.259501] [<ffffffff81259923>] __cpufreq_governor+0xd3/0x150
> > [ 42.259501] [<ffffffff8125a0cb>] __cpufreq_set_policy+0x12b/0x170
> > [ 42.259501] [<ffffffff8125a819>] store_scaling_governor+0xc9/0x260
> > [ 42.259501] [<ffffffff8125b527>] store+0x87/0xa0
> > [ 42.259501] [<ffffffff811101fa>] sysfs_write_file+0xca/0x140
> > [ 42.259501] [<ffffffff810bb82b>] vfs_write+0xcb/0x170
> > [ 42.259501] [<ffffffff810bb9c0>] sys_write+0x50/0x90
> > [ 42.259501] [<ffffffff8100c70a>] system_call_after_swapgs+0x8a/0x8f
> > [ 42.259501] [<ffffffffffffffff>] 0xffffffffffffffff
> > [ 42.259501]
> > [ 42.259501] -> #1 (&per_cpu(cpu_policy_rwsem, cpu)){----}:
> > [ 42.259501] [<ffffffff81066d30>] __lock_acquire+0xfb0/0x1040
> > [ 42.259501] [<ffffffff81066e68>] lock_acquire+0xa8/0xf0
> > [ 42.259501] [<ffffffff812effc8>] down_write+0x38/0x70
> > [ 42.259501] [<ffffffff8125ae7c>] lock_policy_rwsem_write+0x4c/0x90
> > [ 42.259501] [<ffffffff812edbed>] cpufreq_cpu_callback+0x6d/0x90
> > [ 42.259501] [<ffffffff812f578f>] notifier_call_chain+0x3f/0x80
> > [ 42.259501] [<ffffffff8105b059>] __raw_notifier_call_chain+0x9/0x10
> > [ 42.259501] [<ffffffff8106d368>] _cpu_down+0xa8/0x290
> > [ 42.259501] [<ffffffff8106d621>] disable_nonboot_cpus+0x71/0x110
> > [ 42.259501] [<ffffffff810730d5>] suspend_devices_and_enter+0xe5/0x1a0
> > [ 42.259501] [<ffffffff81073306>] enter_state+0x146/0x1d0
> > [ 42.259501] [<ffffffff8107344a>] state_store+0xba/0x100
> > [ 42.259501] [<ffffffff811757f7>] kobj_attr_store+0x17/0x20
> > [ 42.259501] [<ffffffff811101fa>] sysfs_write_file+0xca/0x140
> > [ 42.259501] [<ffffffff810bb82b>] vfs_write+0xcb/0x170
> > [ 42.259501] [<ffffffff810bb9c0>] sys_write+0x50/0x90
> > [ 42.259501] [<ffffffff8100c70a>] system_call_after_swapgs+0x8a/0x8f
> > [ 42.259501] [<ffffffffffffffff>] 0xffffffffffffffff
> > [ 42.259501]
> > [ 42.259501] -> #0 (&cpu_hotplug.lock){--..}:
> > [ 42.259501] [<ffffffff81066c3d>] __lock_acquire+0xebd/0x1040
> > [ 42.259501] [<ffffffff81066e68>] lock_acquire+0xa8/0xf0
> > [ 42.259501] [<ffffffff812ef5ac>] mutex_lock_nested+0xcc/0x370
> > [ 42.259501] [<ffffffff8106d7a5>] get_online_cpus+0x35/0x50
> > [ 42.259501] [<ffffffff8103837e>] sched_getaffinity+0x1e/0xa0
> > [ 42.259501] [<ffffffff8108b386>] __synchronize_sched+0x16/0x90
> > [ 42.259501] [<ffffffff8105add5>] synchronize_srcu+0x45/0x90
> > [ 42.259501] [<ffffffff8105b2b4>]
> > srcu_notifier_chain_unregister+0x74/0xe0
> > [ 42.259501] [<ffffffff8125a337>] cpufreq_unregister_notifier+0x17/0x40
> > [ 42.259501] [<ffffffff8829e296>]
> > cpufreq_governor_userspace+0x1b6/0x1f4 [cpufreq_userspace]
> > [ 42.259501] [<ffffffff81259923>] __cpufreq_governor+0xd3/0x150
> > [ 42.259501] [<ffffffff8125a0b5>] __cpufreq_set_policy+0x115/0x170
> > [ 42.259501] [<ffffffff8125a819>] store_scaling_governor+0xc9/0x260
> > [ 42.259501] [<ffffffff8125b527>] store+0x87/0xa0
> > [ 42.259501] [<ffffffff811101fa>] sysfs_write_file+0xca/0x140
> > [ 42.259501] [<ffffffff810bb82b>] vfs_write+0xcb/0x170
> > [ 42.259501] [<ffffffff810bb9c0>] sys_write+0x50/0x90
> > [ 42.259501] [<ffffffff8100c70a>] system_call_after_swapgs+0x8a/0x8f
> > [ 42.259501] [<ffffffffffffffff>] 0xffffffffffffffff
> > [ 42.259501]
> > [ 42.259501] other info that might help us debug this:
> > [ 42.259501]
> > [ 42.259501] 4 locks held by sh/1973:
> > [ 42.259501] #0: (&buffer->mutex){--..}, at: [<ffffffff81110173>]
> > sysfs_write_file+0x43/0x140
> > [ 42.259501] #1: (&per_cpu(cpu_policy_rwsem, cpu)){----}, at:
> > [<ffffffff8125ae7c>] lock_policy_rwsem_write+0x4c/0x90
> > [ 42.259501] #2: (userspace_mutex){--..}, at: [<ffffffff8829e22e>]
> > cpufreq_governor_userspace+0x14e/0x1f4 [cpufreq_userspace]
> > [ 42.259501] #3: (&sp->mutex){--..}, at: [<ffffffff8105adb0>]
> > synchronize_srcu+0x20/0x90
> > [ 42.259501]
> > [ 42.259501] stack backtrace:
> > [ 42.259501] Pid: 1973, comm: sh Not tainted 2.6.25-rc3 #81
> > [ 42.259501]
> > [ 42.259501] Call Trace:
> > [ 42.259501] [<ffffffff81065ac4>] print_circular_bug_tail+0x84/0x90
> > [ 42.259501] [<ffffffff81065872>] ? print_circular_bug_entry+0x52/0x60
> > [ 42.259501] [<ffffffff81066c3d>] __lock_acquire+0xebd/0x1040
> > [ 42.259501] [<ffffffff8106353b>] ? find_usage_backwards+0xcb/0x110
> > [ 42.259502] [<ffffffff8106353b>] ? find_usage_backwards+0xcb/0x110
> > [ 42.259502] [<ffffffff8106d7a5>] ? get_online_cpus+0x35/0x50
> > [ 42.259502] [<ffffffff81066e68>] lock_acquire+0xa8/0xf0
> > [ 42.259502] [<ffffffff8106d7a5>] ? get_online_cpus+0x35/0x50
> > [ 42.259502] [<ffffffff812ef5ac>] mutex_lock_nested+0xcc/0x370
> > [ 42.259502] [<ffffffff8106d7a5>] ? get_online_cpus+0x35/0x50
> > [ 42.259502] [<ffffffff81065649>] ? trace_hardirqs_on+0x139/0x1a0
> > [ 42.259502] [<ffffffff8106d7a5>] get_online_cpus+0x35/0x50
> > [ 42.259502] [<ffffffff8103837e>] sched_getaffinity+0x1e/0xa0
> > [ 42.259502] [<ffffffff8108b386>] __synchronize_sched+0x16/0x90
> > [ 42.259502] [<ffffffff8105add5>] synchronize_srcu+0x45/0x90
> > [ 42.259502] [<ffffffff8105b2b4>] srcu_notifier_chain_unregister+0x74/0xe0
> > [ 42.259502] [<ffffffff8125a337>] cpufreq_unregister_notifier+0x17/0x40
> > [ 42.259502] [<ffffffff8829e296>]
> > :cpufreq_userspace:cpufreq_governor_userspace+0x1b6/0x1f4
> > [ 42.259502] [<ffffffff81259923>] __cpufreq_governor+0xd3/0x150
> > [ 42.259502] [<ffffffff8125a0b5>] __cpufreq_set_policy+0x115/0x170
> > [ 42.259502] [<ffffffff8125a819>] store_scaling_governor+0xc9/0x260
> > [ 42.259502] [<ffffffff8125b650>] ? handle_update+0x0/0x10
> > [ 42.259502] [<ffffffff812efff0>] ? down_write+0x60/0x70
> > [ 42.259502] [<ffffffff8125b527>] store+0x87/0xa0
> > [ 42.259502] [<ffffffff811101fa>] sysfs_write_file+0xca/0x140
> > [ 42.259502] [<ffffffff810bb82b>] vfs_write+0xcb/0x170
> > [ 42.259502] [<ffffffff810bb9c0>] sys_write+0x50/0x90
> > [ 42.259502] [<ffffffff8100c70a>] system_call_after_swapgs+0x8a/0x8f
> > [ 42.259502]
> > [ 41.439840] mmc0: new SD card at address 5a61
> > [ 41.440027] mmcblk0: mmc0:5a61 S016B 14560KiB
> > [ 41.440123] mmcblk0: p1
> > [ 41.916006] usb 3-2: new full speed USB device using uhci_hcd and address 3
> > [ 42.900716] usb 3-2: configuration #1 chosen from 1 choice
> > [ 42.080814] usb 3-2: New USB device found, idVendor=0483, idProduct=2016
> > [ 42.080939] usb 3-2: New USB device strings: Mfr=1, Product=2, SerialNumber=0
> > [ 42.081094] usb 3-2: Product: Biometric Coprocessor
> > [ 42.081212] usb 3-2: Manufacturer: STMicroelectronics
> > [ 47.925651] PM: Syncing filesystems ... done.
> > [ 47.925845] PM: Preparing system for mem sleep
> > [ 47.925925] Freezing user space processes ... (elapsed 0.00 seconds) done.
> > [ 47.926302] Freezing remaining freezable tasks ... (elapsed 0.00
> > seconds) done.
> > [ 47.926596] PM: Entering mem sleep
> > [ 47.929993] ACPI: Preparing to enter system sleep state S3
> > [ 49.169572] sd 0:0:0:0: [sda] Synchronizing SCSI cache
> > [ 49.169771] sd 0:0:0:0: [sda] Stopping disk
> > [ 51.204365] mmc0: card 5a61 removed
> > [ 51.204365] ACPI handle has no context!
> > [ 51.204365] ACPI: PCI interrupt for device 0000:15:00.2 disabled
> > [ 51.204365] ACPI handle has no context!
>
> Something for Gautham and the USB people to scratch their heads over.
--
Thanks and Regards
gautham
^ permalink raw reply [flat|nested] 5+ messages in thread
* Re: INFO: possible circular locking in the resume
2008-04-03 23:22 ` INFO: possible circular locking in the resume Rafael J. Wysocki
@ 2008-04-04 5:20 ` Gautham R Shenoy
0 siblings, 0 replies; 5+ messages in thread
From: Gautham R Shenoy @ 2008-04-04 5:20 UTC (permalink / raw)
To: Rafael J. Wysocki; +Cc: Linux Kernel Mailing List, Zdenek Kabelac
On Fri, Apr 04, 2008 at 01:22:43AM +0200, Rafael J. Wysocki wrote:
> The following report is on the current list of known regressions
> from 2.6.24. Please verify if the issue is still present in the
> mainline.
>
>
> Bug-Entry : http://bugzilla.kernel.org/show_bug.cgi?id=10133
> Subject : INFO: possible circular locking in the resume
> Submitter : Zdenek Kabelac <zdenek.kabelac@gmail.com>
> Date : 2008-02-27 (37 days old)
> References : http://lkml.org/lkml/2008/2/26/479
> Handled-By : Gautham R Shenoy <ego@in.ibm.com>
>
Yes it still is present in the mainline.
Sorry, didn't have time to fix it, since I have been busy with other stuff.
Will have a look at it over the weekend.
--
Thanks and Regards
gautham
^ permalink raw reply [flat|nested] 5+ messages in thread
* INFO: possible circular locking in the resume
2008-04-03 22:49 2.6.25-rc8-git2: Reported regressions from 2.6.24 Rafael J. Wysocki
@ 2008-04-03 23:22 ` Rafael J. Wysocki
2008-04-04 5:20 ` Gautham R Shenoy
0 siblings, 1 reply; 5+ messages in thread
From: Rafael J. Wysocki @ 2008-04-03 23:22 UTC (permalink / raw)
To: Linux Kernel Mailing List; +Cc: Gautham R Shenoy, Zdenek Kabelac
The following report is on the current list of known regressions
from 2.6.24. Please verify if the issue is still present in the
mainline.
Bug-Entry : http://bugzilla.kernel.org/show_bug.cgi?id=10133
Subject : INFO: possible circular locking in the resume
Submitter : Zdenek Kabelac <zdenek.kabelac@gmail.com>
Date : 2008-02-27 (37 days old)
References : http://lkml.org/lkml/2008/2/26/479
Handled-By : Gautham R Shenoy <ego@in.ibm.com>
^ permalink raw reply [flat|nested] 5+ messages in thread
end of thread, other threads:[~2008-04-04 5:20 UTC | newest]
Thread overview: 5+ messages (download: mbox.gz / follow: Atom feed)
-- links below jump to the message on this page --
2008-02-26 23:29 INFO: possible circular locking in the resume Zdenek Kabelac
2008-02-27 0:17 ` Andrew Morton
2008-02-28 5:14 ` Gautham R Shenoy
2008-04-03 22:49 2.6.25-rc8-git2: Reported regressions from 2.6.24 Rafael J. Wysocki
2008-04-03 23:22 ` INFO: possible circular locking in the resume Rafael J. Wysocki
2008-04-04 5:20 ` Gautham R Shenoy
This is a public inbox, see mirroring instructions
for how to clone and mirror all data and code used for this inbox;
as well as URLs for NNTP newsgroup(s).