Bug 560087 - [ INFO: possible circular locking dependency detected ] - iscsid/622 is trying to acquire lock:
Summary: [ INFO: possible circular locking dependency detected ] - iscsid/622 is tryin...
Keywords:
Status: CLOSED UPSTREAM
Alias: None
Product: Fedora
Classification: Fedora
Component: kernel
Version: 14
Hardware: All
OS: Linux
low
medium
Target Milestone: ---
Assignee: Mike Christie
QA Contact: Fedora Extras Quality Assurance
URL:
Whiteboard:
Depends On:
Blocks:
TreeView+ depends on / blocked
 
Reported: 2010-01-29 19:50 UTC by James Laska
Modified: 2013-09-02 06:43 UTC (History)
10 users (show)

Fixed In Version:
Doc Type: Bug Fix
Doc Text:
Clone Of:
Environment:
Last Closed: 2011-08-30 18:00:14 UTC
Type: ---
Embargoed:


Attachments (Terms of Use)


Links
System ID Private Priority Status Summary Last Updated
Linux Kernel 15278 0 None None None Never

Description James Laska 2010-01-29 19:50:06 UTC
Description of problem:


Version-Release number of selected component (if applicable):
 * anaconda-13.23
 * 2.6.33-0.23.rc5.git1.fc13.x86_64

How reproducible:


Steps to Reproduce:
1. Attempt to add a iSCSI target during installation
2. Enter IP and IQN, click Add
  
Actual results:

On the console, I see the following messages:

Running anaconda 13.23, the Fedora system installer - please wait.             
19:44:55 Starting VNC...
19:44:57 The VNC server is now running.
19:44:57 

WARNING!!! VNC server running with NO PASSWORD!
You can use the vncpassword=<password> boot option
if you would like to secure the server.


19:44:57 Please manually connect your vnc client to test1201.test.redhat.com:1 (10.10.10.201) to begin the install.
Press <enter> for a shell
19:44:57 Starting graphical installation.

=======================================================
[ INFO: possible circular locking dependency detected ]
2.6.33-0.23.rc5.git1.fc13.x86_64 #1
-------------------------------------------------------
iscsid/622 is trying to acquire lock:
 (&shost->scan_mutex){+.+.+.}, at: [<ffffffff81305660>] scsi_scan_target+0x5b/0xa0

but task is already holding lock:
 (&ihost->mutex){+.+...}, at: [<ffffffffa001feb4>] iscsi_user_scan_session+0x89/0x138 [scsi_transport_iscsi]

which lock already depends on the new lock.


the existing dependency chain (in reverse order) is:

-> #2 (&ihost->mutex){+.+...}:
       [<ffffffff8107e416>] __lock_acquire+0xb71/0xd19
       [<ffffffff8107e69a>] lock_acquire+0xdc/0x102
       [<ffffffff81475b3f>] __mutex_lock_common+0x4b/0x392
       [<ffffffff81475f4a>] mutex_lock_nested+0x3e/0x43
       [<ffffffffa001feb4>] iscsi_user_scan_session+0x89/0x138 [scsi_transport_iscsi]
       [<ffffffff812e90ac>] device_for_each_child+0x3a/0x71
       [<ffffffffa001fe0b>] iscsi_user_scan+0x2d/0x2f [scsi_transport_iscsi]
       [<ffffffff813060ba>] store_scan+0xad/0xec
       [<ffffffff812e8722>] dev_attr_store+0x20/0x22
       [<ffffffff81174d73>] sysfs_write_file+0x108/0x144
       [<ffffffff8111e311>] vfs_write+0xae/0x10b
       [<ffffffff8111e42e>] sys_write+0x4a/0x6e
       [<ffffffff81009c32>] system_call_fastpath+0x16/0x1b

-> #1 (s_active){++++.+}:
       [<ffffffff8107e416>] __lock_acquire+0xb71/0xd19
       [<ffffffff8107e69a>] lock_acquire+0xdc/0x102
       [<ffffffff81175a13>] sysfs_deactivate+0x9a/0x103
       [<ffffffff81176006>] sysfs_addrm_finish+0x36/0x55
       [<ffffffff81174374>] sysfs_hash_and_remove+0x53/0x6a
       [<ffffffff8117658f>] sysfs_remove_link+0x21/0x23
       [<ffffffff812ec4c5>] driver_sysfs_remove+0x2a/0x3e
       [<ffffffff812ec96e>] driver_probe_device+0x12c/0x21a
       [<ffffffff812ecb17>] __device_attach+0x3a/0x3f
       [<ffffffff812eba0f>] bus_for_each_drv+0x59/0x90
       [<ffffffff812ecbb7>] device_attach+0x6c/0x90
       [<ffffffff812eb823>] bus_probe_device+0x27/0x3e
       [<ffffffff812e9e8d>] device_add+0x3c2/0x580
       [<ffffffff81306acd>] scsi_sysfs_add_sdev+0xbf/0x22e
       [<ffffffff813047cd>] scsi_probe_and_add_lun+0xb35/0xc38
       [<ffffffff81305762>] __scsi_add_device+0xbd/0xe9
       [<ffffffff8131d8b9>] ata_scsi_scan_host+0x79/0x173
       [<ffffffff8131bad8>] async_port_probe+0xb0/0xbc
       [<ffffffff81072663>] async_thread+0x103/0x1e4
       [<ffffffff8106b30c>] kthread+0x9a/0xa2
       [<ffffffff8100aaa4>] kernel_thread_helper+0x4/0x10

-> #0 (&shost->scan_mutex){+.+.+.}:
       [<ffffffff8107e2c0>] __lock_acquire+0xa1b/0xd19
       [<ffffffff8107e69a>] lock_acquire+0xdc/0x102
       [<ffffffff81475b3f>] __mutex_lock_common+0x4b/0x392
       [<ffffffff81475f4a>] mutex_lock_nested+0x3e/0x43
       [<ffffffff81305660>] scsi_scan_target+0x5b/0xa0
       [<ffffffffa001ff15>] iscsi_user_scan_session+0xea/0x138 [scsi_transport_iscsi]
       [<ffffffff812e90ac>] device_for_each_child+0x3a/0x71
       [<ffffffffa001fe0b>] iscsi_user_scan+0x2d/0x2f [scsi_transport_iscsi]
       [<ffffffff813060ba>] store_scan+0xad/0xec
       [<ffffffff812e8722>] dev_attr_store+0x20/0x22
       [<ffffffff81174d73>] sysfs_write_file+0x108/0x144
       [<ffffffff8111e311>] vfs_write+0xae/0x10b
       [<ffffffff8111e42e>] sys_write+0x4a/0x6e
       [<ffffffff81009c32>] system_call_fastpath+0x16/0x1b

other info that might help us debug this:

4 locks held by iscsid/622:
 #0:  (&buffer->mutex){+.+.+.}, at: [<ffffffff81174ca7>] sysfs_write_file+0x3c/0x144
 #1:  (s_active){++++.+}, at: [<ffffffff811761c1>] sysfs_get_active_two+0x24/0x48
 #2:  (s_active){++++.+}, at: [<ffffffff811761ce>] sysfs_get_active_two+0x31/0x48
 #3:  (&ihost->mutex){+.+...}, at: [<ffffffffa001feb4>] iscsi_user_scan_session+0x89/0x138 [scsi_transport_iscsi]

stack backtrace:
Pid: 622, comm: iscsid Not tainted 2.6.33-0.23.rc5.git1.fc13.x86_64 #1
Call Trace:
 [<ffffffff8107d483>] print_circular_bug+0xa8/0xb6
 [<ffffffff8107e2c0>] __lock_acquire+0xa1b/0xd19
 [<ffffffff8107e69a>] lock_acquire+0xdc/0x102
 [<ffffffff81305660>] ? scsi_scan_target+0x5b/0xa0
 [<ffffffff81305660>] ? scsi_scan_target+0x5b/0xa0
 [<ffffffff81475b3f>] __mutex_lock_common+0x4b/0x392
 [<ffffffff81305660>] ? scsi_scan_target+0x5b/0xa0
 [<ffffffffa001f6ed>] ? spin_unlock_irqrestore+0xe/0x10 [scsi_transport_iscsi]
 [<ffffffff81070fb6>] ? sched_clock_cpu+0xc3/0xce
 [<ffffffff8107b8e6>] ? trace_hardirqs_off+0xd/0xf
 [<ffffffff8107cb4b>] ? mark_lock+0x2d/0x22e
 [<ffffffff81475f4a>] mutex_lock_nested+0x3e/0x43
 [<ffffffff81305660>] scsi_scan_target+0x5b/0xa0
 [<ffffffffa001ff15>] iscsi_user_scan_session+0xea/0x138 [scsi_transport_iscsi]
 [<ffffffffa001fe2b>] ? iscsi_user_scan_session+0x0/0x138 [scsi_transport_iscsi]
 [<ffffffff812e90ac>] device_for_each_child+0x3a/0x71
 [<ffffffffa001fe0b>] iscsi_user_scan+0x2d/0x2f [scsi_transport_iscsi]
 [<ffffffff813060ba>] store_scan+0xad/0xec
 [<ffffffff81175963>] ? sysfs_get_active+0x64/0x7a
 [<ffffffff811761ce>] ? sysfs_get_active_two+0x31/0x48
 [<ffffffff812e8722>] dev_attr_store+0x20/0x22
 [<ffffffff81174d73>] sysfs_write_file+0x108/0x144
 [<ffffffff8111e311>] vfs_write+0xae/0x10b
 [<ffffffff8107d01e>] ? trace_hardirqs_on_caller+0x111/0x135
 [<ffffffff8111e42e>] sys_write+0x4a/0x6e
 [<ffffffff81009c32>] system_call_fastpath+0x16/0x1b
scsi 3:0:0:0: Direct-Access     IBM      DS300    S320    7.01 PQ: 0 ANSI: 4
sd 3:0:0:0: Attached scsi generic sg5 type 0
sd 3:0:0:0: [sde] 20971520 512-byte logical blocks: (10.7 GB/10.0 GiB)
sd 3:0:0:0: [sde] Write Protect is off
sd 3:0:0:0: [sde] Mode Sense: 8f 00 00 08
sd 3:0:0:0: [sde] Write cache: disabled, read cache: enabled, doesn't support DPO or FUA
 sde: sde1
sd 3:0:0:0: [sde] Attached SCSI disk


Expected results:

No lock messages on the console.

Additional info:
 * The target device appears correctly in anaconda, despite the console messages
 * Added to F13Blocker per Final release criteria (https://fedoraproject.org/wiki/Fedora_13_Final_Release_Criteria)

Comment 1 James Laska 2010-02-24 14:26:42 UTC
Updated test results against F-13-Alpha-RC2-x86_64

[ INFO: possible circular locking dependency detected ]
2.6.33-0.51.rc8.git6.fc13.x86_64 #1
-------------------------------------------------------
iscsid/472 is trying to acquire lock:
 (&shost->scan_mutex){+.+.+.}, at: [<ffffffff813062cd>] scsi_scan_target+0x5b/0xa0

but task is already holding lock:
 (&ihost->mutex){+.+...}, at: [<ffffffffa001fe93>] iscsi_user_scan_session+0x89/0x138 [scsi_transport_iscsi]

which lock already depends on the new lock.


the existing dependency chain (in reverse order) is:

-> #2 (&ihost->mutex){+.+...}:
       [<ffffffff8107e805>] __lock_acquire+0xb87/0xd36
       [<ffffffff8107ea90>] lock_acquire+0xdc/0x102
       [<ffffffff81476f95>] __mutex_lock_common+0x4b/0x392
       [<ffffffff814773a0>] mutex_lock_nested+0x3e/0x43
       [<ffffffffa001fe93>] iscsi_user_scan_session+0x89/0x138 [scsi_transport_iscsi]
       [<ffffffff812e9b05>] device_for_each_child+0x3a/0x71
       [<ffffffffa001fdea>] iscsi_user_scan+0x2d/0x2f [scsi_transport_iscsi]
       [<ffffffff81306c86>] store_scan+0xad/0xec
       [<ffffffff812e9172>] dev_attr_store+0x20/0x22
       [<ffffffff81175c5b>] sysfs_write_file+0x108/0x144
       [<ffffffff8111ed81>] vfs_write+0xae/0x10b
       [<ffffffff8111ee9e>] sys_write+0x4a/0x6e
       [<ffffffff81009c72>] system_call_fastpath+0x16/0x1b

-> #1 (s_active){++++.+}:
       [<ffffffff8107e805>] __lock_acquire+0xb87/0xd36
       [<ffffffff8107ea90>] lock_acquire+0xdc/0x102
       [<ffffffff811768ff>] sysfs_deactivate+0x9a/0x103
       [<ffffffff81176ef2>] sysfs_addrm_finish+0x36/0x55
       [<ffffffff81175244>] sysfs_hash_and_remove+0x53/0x6a
       [<ffffffff8117747b>] sysfs_remove_link+0x21/0x23
       [<ffffffff812ecf45>] driver_sysfs_remove+0x2a/0x3e
       [<ffffffff812ed3ee>] driver_probe_device+0x12c/0x21a
       [<ffffffff812ed597>] __device_attach+0x3a/0x3f
       [<ffffffff812ec4a3>] bus_for_each_drv+0x59/0x90
       [<ffffffff812ed637>] device_attach+0x6c/0x90
       [<ffffffff812ec2b7>] bus_probe_device+0x27/0x3e
       [<ffffffff812ea904>] device_add+0x3c2/0x59e
       [<ffffffff81307699>] scsi_sysfs_add_sdev+0xbf/0x22e
       [<ffffffff8130553b>] scsi_probe_and_add_lun+0xb35/0xc38
       [<ffffffff813056fb>] __scsi_add_device+0xbd/0xe9
       [<ffffffff8131e2ea>] ata_scsi_scan_host+0x79/0x173
       [<ffffffff8131c332>] async_port_probe+0xb0/0xb9
       [<ffffffff81072564>] async_thread+0x10a/0x1f9
       [<ffffffff8106b58c>] kthread+0x9a/0xa2
       [<ffffffff8100aae4>] kernel_thread_helper+0x4/0x10

-> #0 (&shost->scan_mutex){+.+.+.}:
       [<ffffffff8107e6af>] __lock_acquire+0xa31/0xd36
       [<ffffffff8107ea90>] lock_acquire+0xdc/0x102
       [<ffffffff81476f95>] __mutex_lock_common+0x4b/0x392
       [<ffffffff814773a0>] mutex_lock_nested+0x3e/0x43
       [<ffffffff813062cd>] scsi_scan_target+0x5b/0xa0
       [<ffffffffa001fef4>] iscsi_user_scan_session+0xea/0x138 [scsi_transport_iscsi]
       [<ffffffff812e9b05>] device_for_each_child+0x3a/0x71
       [<ffffffffa001fdea>] iscsi_user_scan+0x2d/0x2f [scsi_transport_iscsi]
       [<ffffffff81306c86>] store_scan+0xad/0xec
       [<ffffffff812e9172>] dev_attr_store+0x20/0x22
       [<ffffffff81175c5b>] sysfs_write_file+0x108/0x144
       [<ffffffff8111ed81>] vfs_write+0xae/0x10b
       [<ffffffff8111ee9e>] sys_write+0x4a/0x6e
       [<ffffffff81009c72>] system_call_fastpath+0x16/0x1b

other info that might help us debug this:

4 locks held by iscsid/472:
 #0:  (&buffer->mutex){+.+.+.}, at: [<ffffffff81175b8f>] sysfs_write_file+0x3c/0x144
 #1:  (s_active){++++.+}, at: [<ffffffff811770ad>] sysfs_get_active_two+0x24/0x48
 #2:  (s_active){++++.+}, at: [<ffffffff811770ba>] sysfs_get_active_two+0x31/0x48
 #3:  (&ihost->mutex){+.+...}, at: [<ffffffffa001fe93>] iscsi_user_scan_session+0x89/0x138 [scsi_transport_iscsi]

stack backtrace:
Pid: 472, comm: iscsid Not tainted 2.6.33-0.51.rc8.git6.fc13.x86_64 #1
Call Trace:
 [<ffffffff8107d855>] print_circular_bug+0xaf/0xbd
 [<ffffffff8107e6af>] __lock_acquire+0xa31/0xd36
 [<ffffffff8107ea90>] lock_acquire+0xdc/0x102
 [<ffffffff813062cd>] ? scsi_scan_target+0x5b/0xa0
 [<ffffffff8102a08a>] ? pvclock_clocksource_read+0x47/0x83
 [<ffffffff813062cd>] ? scsi_scan_target+0x5b/0xa0
 [<ffffffff81476f95>] __mutex_lock_common+0x4b/0x392
 [<ffffffff813062cd>] ? scsi_scan_target+0x5b/0xa0
 [<ffffffff81010329>] ? sched_clock+0x9/0xd
 [<ffffffff810710c5>] ? sched_clock_local+0x1c/0x82
 [<ffffffffa001febb>] ? iscsi_user_scan_session+0xb1/0x138 [scsi_transport_iscsi]
 [<ffffffff810711ee>] ? sched_clock_cpu+0xc3/0xce
 [<ffffffff8107ccd2>] ? mark_lock+0x2d/0x235
 [<ffffffff814773a0>] mutex_lock_nested+0x3e/0x43
 [<ffffffff813062cd>] scsi_scan_target+0x5b/0xa0
 [<ffffffffa001fef4>] iscsi_user_scan_session+0xea/0x138 [scsi_transport_iscsi]
 [<ffffffffa001fe0a>] ? iscsi_user_scan_session+0x0/0x138 [scsi_transport_iscsi]
 [<ffffffff812e9b05>] device_for_each_child+0x3a/0x71
 [<ffffffffa001fdea>] iscsi_user_scan+0x2d/0x2f [scsi_transport_iscsi]
 [<ffffffff81306c86>] store_scan+0xad/0xec
 [<ffffffff8117684f>] ? sysfs_get_active+0x64/0x7a
 [<ffffffff811770ba>] ? sysfs_get_active_two+0x31/0x48
 [<ffffffff812e9172>] dev_attr_store+0x20/0x22
 [<ffffffff81175c5b>] sysfs_write_file+0x108/0x144
 [<ffffffff8111ed81>] vfs_write+0xae/0x10b
 [<ffffffff8107d1ac>] ? trace_hardirqs_on_caller+0x111/0x135
 [<ffffffff8111ee9e>] sys_write+0x4a/0x6e
 [<ffffffff81009c72>] system_call_fastpath+0x16/0x1b
scsi 2:0:0:0: Direct-Access     IBM      DS300    S320    7.01 PQ: 0 ANSI: 4
sd 2:0:0:0: Attached scsi generic sg1 type 0
sd 2:0:0:0: [sda] 20971520 512-byte logical blocks: (10.7 GB/10.0 GiB)
sd 2:0:0:0: [sda] Write Protect is off
sd 2:0:0:0: [sda] Mode Sense: 8f 00 00 08
sd 2:0:0:0: [sda] Write cache: disabled, read cache: enabled, doesn't support DPO or FUA
 sda: sda1
sd 2:0:0:0: [sda] Attached SCSI disk

Comment 2 Mike Christie 2010-02-24 18:42:41 UTC
I am working on this upstream. I am still not 100% sure what is wrong.

Comment 3 James Laska 2010-04-16 19:32:08 UTC
I'd like to retest this again post-Beta F-13 to see if this problem remains, and how it impacts the installed system.

Comment 4 Mike Christie 2010-04-16 23:01:44 UTC
(In reply to comment #3)
> I'd like to retest this again post-Beta F-13 to see if this problem remains,
> and how it impacts the installed system.    

This should be fixed in linus's tree now. It not not a real locking problem.

For F-13 are we going to rebase the kernel to 2.6.34 when it is out? If so we will get the fixed for free.

If not I can back port the changes.

Comment 5 Adam Williamson 2010-04-23 18:02:16 UTC
Discussed at today's blocker bug review meeting. This is just a warning and ought not to cause any actual problems; jlaska confirms in testing that it doesn't seem to. It should not be visible with the final release kernel (with debugging disabled). So we're dropping it from the blocker list.



-- 
Fedora Bugzappers volunteer triage team
https://fedoraproject.org/wiki/BugZappers

Comment 6 Bug Zapper 2010-07-30 10:50:03 UTC
This bug appears to have been reported against 'rawhide' during the Fedora 14 development cycle.
Changing version to '14'.

More information and reason for this action is here:
http://fedoraproject.org/wiki/BugZappers/HouseKeeping

Comment 7 Josh Boyer 2011-08-30 18:00:14 UTC
This should be fixed upstream per comment #4


Note You need to log in before you can comment on or make changes to this bug.