Bug 10924 - if cdrom is in cd-drive on wakeup -> "possible circular locking dependency detected"
Summary: if cdrom is in cd-drive on wakeup -> "possible circular locking dependency de...
Status: REJECTED INSUFFICIENT_DATA
Alias: None
Product: Power Management
Classification: Unclassified
Component: Hibernation/Suspend (show other bugs)
Hardware: All Linux
: P1 normal
Assignee: Rafael J. Wysocki
URL:
Keywords:
Depends on:
Blocks: 7216
  Show dependency tree
 
Reported: 2008-06-15 23:12 UTC by Oleksij Rempel (fishor)
Modified: 2009-10-15 07:51 UTC (History)
2 users (show)

See Also:
Kernel Version: 2.6.26-rc6-00028-gc6d8f40
Subsystem:
Regression: No
Bisected commit-id:


Attachments
2.6.26-rc6-testing-00028-gc6d8f40 (48.53 KB, text/plain)
2008-06-15 23:14 UTC, Oleksij Rempel (fishor)
Details
dmesg no cdrom (42.77 KB, text/plain)
2008-06-16 02:54 UTC, Oleksij Rempel (fishor)
Details
dmesg SLAB - BUG (45.31 KB, text/plain)
2008-06-17 03:42 UTC, Oleksij Rempel (fishor)
Details

Description Oleksij Rempel (fishor) 2008-06-15 23:12:36 UTC
Latest working kernel version: none due other suspend related bugs 

Distribution: ubuntu 8.04

Problem Description:
if you leave cdrom inside cd drive before suspend, on wakeup you'll get this message:

[ 3318.563397] ADDRCONF(NETDEV_CHANGE): eth0: link becomes ready
[ 3323.020004] VFS: busy inodes on changed media.
[ 3323.145401] VFS: busy inodes on changed media.
[ 3323.443158] VFS: busy inodes on changed media.
[ 3323.567484] VFS: busy inodes on changed media.
[ 3323.703937] VFS: busy inodes on changed media.
[ 3323.830314] VFS: busy inodes on changed media.
[ 3333.712739] VFS: busy inodes on changed media.
[ 3335.568628] 
[ 3335.568628] =======================================================
[ 3335.568628] [ INFO: possible circular locking dependency detected ]
[ 3335.568628] 2.6.26-rc6-testing-00028-gc6d8f40 #68
[ 3335.568628] -------------------------------------------------------
[ 3335.568628] mount/5781 is trying to acquire lock:
[ 3335.568628]  (&bdev->bd_mutex){--..}, at: [<c0197765>] __blkdev_put+0x24/0x10f
[ 3335.568628] 
[ 3335.568628] but task is already holding lock:
[ 3335.568628]  (&type->s_umount_key#20){----}, at: [<c0177722>] sget+0x68/0x339
[ 3335.568628] 
[ 3335.568628] which lock already depends on the new lock.
[ 3335.568628] 
[ 3335.568628] 
[ 3335.568628] the existing dependency chain (in reverse order) is:
[ 3335.568628] 
[ 3335.568628] -> #1 (&type->s_umount_key#20){----}:
[ 3335.568628]        [<c013e0af>] __lock_acquire+0x9e4/0xb91
[ 3335.568628]        [<c013e2c8>] lock_acquire+0x6c/0x89
[ 3335.568628]        [<c035775e>] down_read+0x2b/0x65
[ 3335.568628]        [<c01781d5>] get_super+0x42/0x87
[ 3335.568628]        [<c0197354>] __invalidate_device+0xf/0x38
[ 3335.568628]        [<c01973a1>] check_disk_change+0x24/0x6a
[ 3335.568628]        [<c02b0af0>] cdrom_open+0x850/0x89d
[ 3335.568628]        [<c02943ec>] sr_block_open+0x75/0x8a
[ 3335.568628]        [<c0197b23>] do_open+0x1c0/0x273
[ 3335.568628]        [<c0197d98>] blkdev_open+0x28/0x51
[ 3335.568628]        [<c0174bf9>] __dentry_open+0x147/0x236
[ 3335.568628]        [<c0174d07>] nameidata_to_filp+0x1f/0x33
[ 3335.568628]        [<c017fd66>] do_filp_open+0x347/0x695
[ 3335.568628]        [<c01749d1>] do_sys_open+0x40/0xb6
[ 3335.568628]        [<c0174a89>] sys_open+0x1e/0x26
[ 3335.568628]        [<c0102d4d>] sysenter_past_esp+0x6a/0xb1
[ 3335.568628]        [<ffffffff>] 0xffffffff
[ 3335.568628] 
[ 3335.568628] -> #0 (&bdev->bd_mutex){--..}:
[ 3335.568628]        [<c013dfd6>] __lock_acquire+0x90b/0xb91
[ 3335.568628]        [<c013e2c8>] lock_acquire+0x6c/0x89
[ 3335.568628]        [<c0357211>] mutex_lock_nested+0xc5/0x23c
[ 3335.568628]        [<c0197765>] __blkdev_put+0x24/0x10f
[ 3335.568628]        [<c019785a>] blkdev_put+0xa/0xc
[ 3335.568628]        [<c019786e>] close_bdev_excl+0x12/0x15
[ 3335.568628]        [<c01782a5>] get_sb_bdev+0x8b/0x10b
[ 3335.568628]        [<f93c04a4>] isofs_get_sb+0x13/0x15 [isofs]
[ 3335.568642]        [<c0177ecf>] vfs_kern_mount+0x81/0xf7
[ 3335.568642]        [<c0177f89>] do_kern_mount+0x32/0xba
[ 3335.568642]        [<c018b1c8>] do_new_mount+0x46/0x74
[ 3335.568642]        [<c018b38d>] do_mount+0x197/0x1b5
[ 3335.568642]        [<c018b40f>] sys_mount+0x64/0x9b
[ 3335.568642]        [<c0102d4d>] sysenter_past_esp+0x6a/0xb1
[ 3335.568642]        [<ffffffff>] 0xffffffff
[ 3335.568642] 
[ 3335.568642] other info that might help us debug this:
[ 3335.568642] 
[ 3335.568642] 1 lock held by mount/5781:
[ 3335.568642]  #0:  (&type->s_umount_key#20){----}, at: [<c0177722>] sget+0x68/0x339
[ 3335.568642] 
[ 3335.568642] stack backtrace:
[ 3335.568642] Pid: 5781, comm: mount Not tainted 2.6.26-rc6-testing-00028-gc6d8f40 #68
[ 3335.568642]  [<c013c1ab>] print_circular_bug_tail+0x5b/0x66
[ 3335.568642]  [<c013cb57>] ? print_circular_bug_header+0xa5/0xb0
[ 3335.568642]  [<c013dfd6>] __lock_acquire+0x90b/0xb91
[ 3335.568642]  [<c013e2c8>] lock_acquire+0x6c/0x89
[ 3335.568642]  [<c0197765>] ? __blkdev_put+0x24/0x10f
[ 3335.568642]  [<c0357211>] mutex_lock_nested+0xc5/0x23c
[ 3335.568642]  [<c0197765>] ? __blkdev_put+0x24/0x10f
[ 3335.568642]  [<c0197765>] ? __blkdev_put+0x24/0x10f
[ 3335.568642]  [<c0197765>] __blkdev_put+0x24/0x10f
[ 3335.568642]  [<c019785a>] blkdev_put+0xa/0xc
[ 3335.568642]  [<c019786e>] close_bdev_excl+0x12/0x15
[ 3335.568642]  [<c01782a5>] get_sb_bdev+0x8b/0x10b
[ 3335.568642]  [<c018a194>] ? alloc_vfsmnt+0xe3/0x10b
[ 3335.568642]  [<f93c04a4>] isofs_get_sb+0x13/0x15 [isofs]
[ 3335.568642]  [<f93c0fbe>] ? isofs_fill_super+0x0/0x8ea [isofs]
[ 3335.568642]  [<c0177ecf>] vfs_kern_mount+0x81/0xf7
[ 3335.568642]  [<c0177f89>] do_kern_mount+0x32/0xba
[ 3335.568642]  [<c018b1c8>] do_new_mount+0x46/0x74
[ 3335.568642]  [<c018b38d>] do_mount+0x197/0x1b5
[ 3335.568642]  [<c017dd35>] ? getname+0x1a/0xb4
[ 3335.568642]  [<c015cd1a>] ? __get_free_pages+0x1b/0x21
[ 3335.568642]  [<c0189436>] ? copy_mount_options+0x27/0x10e
[ 3335.568642]  [<c018b40f>] sys_mount+0x64/0x9b
[ 3335.568642]  [<c0102d4d>] sysenter_past_esp+0x6a/0xb1
[ 3335.568642]  =======================


Steps to reproduce:
1. insert cdrom in cddrive
2. wait until automount
3. suspend (s3) && resume
Comment 1 Oleksij Rempel (fishor) 2008-06-15 23:14:13 UTC
Created attachment 16499 [details]
2.6.26-rc6-testing-00028-gc6d8f40
Comment 2 ykzhao 2008-06-16 00:07:10 UTC
Hi, Alexey
   Will you please confirm whether the problem still exists if there is no cdrom in cddrive? 
   Thanks.
Comment 3 Oleksij Rempel (fishor) 2008-06-16 02:54:34 UTC
Created attachment 16505 [details]
dmesg no cdrom

Here is clean resume without cdrom
Comment 4 Len Brown 2008-06-16 19:14:25 UTC
did a previous version of linux suspend correctly without this issue?
if yes, what is the latest version that worked?
Comment 5 Oleksij Rempel (fishor) 2008-06-17 02:02:59 UTC
I can't test regression due other supend bugs in older kernels. All i can say, it is present in 2.6.25 too, but i have more random crushes on resume. And at the moment is use SLUB kernel becouse it work better (not perfekt) with suspend/resume for me than SLAB.
Comment 6 Oleksij Rempel (fishor) 2008-06-17 03:41:29 UTC
Seems like this is SLUB realted issue. I tested SLAB kernel and didn't get this message. Instead i get this one:

[  246.260071] BUG: sleeping function called from invalid context at mm/slab.c:3052
[  246.260074] in_atomic():1, irqs_disabled():0
[  246.260078] 5 locks held by pm-suspend/4983:
[  246.260080]  #0:  (&buffer->mutex){--..}, at: [<c01ac056>] sysfs_write_file+0x25/0xe3
[  246.260096]  #1:  (pm_mutex){--..}, at: [<c014635a>] enter_state+0x166/0x17d
[  246.260102]  #2:  (cpu_add_remove_lock){--..}, at: [<c0141e83>] cpu_maps_update_begin+0xf/0x11
[  246.260109]  #3:  (&cpu_hotplug.lock){--..}, at: [<c0141ec7>] cpu_hotplug_begin+0x1a/0x42
[  246.260115]  #4:  (smp_alt){--..}, at: [<c0106f8c>] alternatives_smp_switch+0x14c/0x165
[  246.260124] Pid: 4983, comm: pm-suspend Not tainted 2.6.26-rc6-testing-00149-gc8988f9 #2
[  246.260129]  [<c0119c8d>] __might_sleep+0xe7/0xee
[  246.260136]  [<c0172011>] kmem_cache_alloc+0x27/0xd2
[  246.260142]  [<c0169e7c>] ? __get_vm_area_node+0x86/0x186
[  246.260149]  [<c0169e7c>] __get_vm_area_node+0x86/0x186
[  246.260155]  [<c0169ffc>] get_vm_area_caller+0x3e/0x43
[  246.260160]  [<c0358531>] ? text_poke+0x9e/0x11e
[  246.260167]  [<c016a437>] vmap+0x21/0x44
[  246.260171]  [<c0358531>] text_poke+0x9e/0x11e
[  246.260176]  [<c0101433>] ? sys_execve+0x37/0x4d
[  246.260182]  [<c0106d63>] alternatives_smp_unlock+0x41/0x50
[  246.260188]  [<c0106f58>] alternatives_smp_switch+0x118/0x165
[  246.260193]  [<c035b3c1>] ? _etext+0x0/0xf
[  246.260198]  [<c012173d>] ? printk+0x15/0x17
[  246.260204]  [<c010e232>] __cpu_die+0x42/0x69
[  246.260210]  [<c0347ad3>] _cpu_down+0x148/0x1f8
[  246.260217]  [<c0141fbd>] disable_nonboot_cpus+0x4a/0xc5
[  246.260223]  [<c014612b>] suspend_devices_and_enter+0x91/0x132
[  246.260228]  [<c0146315>] enter_state+0x121/0x17d
[  246.260233]  [<c0146407>] state_store+0x96/0xac
[  246.260237]  [<c0146371>] ? state_store+0x0/0xac
[  246.260243]  [<c01e76a5>] kobj_attr_store+0x1a/0x22
[  246.260249]  [<c01ac0e9>] sysfs_write_file+0xb8/0xe3
[  246.260255]  [<c01ac031>] ? sysfs_write_file+0x0/0xe3
[  246.260260]  [<c0175196>] vfs_write+0x8c/0x108
[  246.260265]  [<c01756f0>] sys_write+0x3b/0x60
[  246.260271]  [<c0102d4d>] sysenter_past_esp+0x6a/0xb1
[  246.260277]  =======================
Comment 7 Oleksij Rempel (fishor) 2008-06-17 03:42:29 UTC
Created attachment 16525 [details]
dmesg SLAB - BUG
Comment 8 Zhang Rui 2009-07-13 07:24:44 UTC
please attach the acpidump output.
Comment 9 Zhang Rui 2009-10-15 07:51:39 UTC
close this bug as there is no response from the bug reporter.
please reopen it if
1. the problem still exists in the latest kernel
2. you can provide the info requested in comment #8.

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