Index of /bits/2.6.33-rc6/jfs/dbench
Name Last modified Size Description
![[DIR]](/spicons/back.gif)
Parent Directory 09-Feb-2010 23:10 -
![[TXT]](/spicons/text.gif)
jfs_read_cache_page.diff.txt 09-Feb-2010 23:10 1k
![[ ]](/spicons/compressed.gif)
dmesg-70.txt.gz 09-Feb-2010 23:10 7k
dmesg-50.txt.gz 09-Feb-2010 23:10 4k
dbench-70.log.gz 09-Feb-2010 23:10 1k
dbench-50.log.gz 09-Feb-2010 23:10 3k
# ls -lgos /mnt/test.img
4198404 -rw-r--r-- 1 4294967296 2010-02-03 11:09 /mnt/test.img
# losetup -f /mnt/test.img
# mkfs.jfs /dev/loop0
# mount -t jfs /dev/loop0 /mnt/test
# grep jfs /proc/mounts
/dev/loop0 /mnt/test jfs rw,relatime 0 0
# dbench -t 600 -D /mnt/test/ -x 50
PROC: 50 / Tue Feb 9 02:03:51 PST 2010
# dbench -t 600 -D /mnt/test/ -x 70
PROC: 70 / Tue Feb 9 02:18:04 PST 2010
Feb 9 02:18:34 stanley kernel: [22696.323599] [ INFO: possible irq lock inversion dependency detected ]
# dmesg
[...]
[22696.323599] [ INFO: possible irq lock inversion dependency detected ]
[22696.400694] 2.6.33-rc6 #1
[22696.431940] ---------------------------------------------------------
[22696.509032] dbench/8886 just changed the state of lock:
[22696.571536] (&jfs_ip->commit_mutex){+.+.+.}, at: [<00000000100b4d58>] jfs_mkdir+0x98/0x380 [jfs]
[22696.677793] but this lock was taken by another, RECLAIM_FS-safe lock in the past:
[22696.767379] (&jfs_ip->rdwrlock#3){+.+.-.}
[22696.814258]
[22696.814267] and interrupts could create inverse lock ordering between them.
[22696.814283]
[22696.935099]
[22696.935108] other info that might help us debug this:
[22697.013234] 3 locks held by dbench/8886:
[22697.060108] #0: (&sb->s_type->i_mutex_key#12/1){+.+.+.}, at: [<00000000004cea38>] lookup_create+0x18/0xc0
[22697.176783] #1: (&jfs_ip->commit_mutex){+.+.+.}, at: [<00000000100b4d58>] jfs_mkdir+0x98/0x380 [jfs]
[22697.288250] #2: (&jfs_ip->commit_mutex/1){+.+...}, at: [<00000000100b4d68>] jfs_mkdir+0xa8/0x380 [jfs]
[22697.401799]
[22697.401809] the shortest dependencies between 2nd lock and 1st lock:
[22697.495561] -> (&jfs_ip->rdwrlock#3){+.+.-.} ops: 3929349614993408 {
[22697.572642] HARDIRQ-ON-W at:
[22697.611189] [<000000000047dff4>] lock_acquire+0x54/0x80
[22697.716402] [<000000000046edb4>] down_write_nested+0x34/0x80
[22697.826827] [<00000000100b32e0>] jfs_get_block+0x20/0x300 [jfs]
[22697.940377] [<00000000004ee684>] nobh_write_begin+0x164/0x460
[22698.051841] [<00000000100b2f2c>] jfs_write_begin+0x2c/0x40 [jfs]
[22698.166434] [<0000000000494d50>] generic_file_buffered_write+0x170/0x220
[22698.289358] [<0000000000496e58>] __generic_file_aio_write+0x258/0x3a0
[22698.409157] [<0000000000496fd8>] generic_file_aio_write+0x38/0xc0
[22698.524791] [<00000000004c5694>] do_sync_write+0x74/0xc0
[22698.631047] [<00000000004c6128>] vfs_write+0x68/0x140
[22698.734180] [<00000000004c6264>] SyS_pwrite64+0x64/0x80
[22698.839396] [<00000000004400f4>] sys32_pwrite64+0x14/0x40
[22698.946695] [<0000000000406114>] linux_sparc_syscall32+0x34/0x40
[22699.061291] SOFTIRQ-ON-W at:
[22699.099832] [<000000000047dff4>] lock_acquire+0x54/0x80
[22699.205047] [<000000000046edb4>] down_write_nested+0x34/0x80
[22699.315470] [<00000000100b32e0>] jfs_get_block+0x20/0x300 [jfs]
[22699.429021] [<00000000004ee684>] nobh_write_begin+0x164/0x460
[22699.540486] [<00000000100b2f2c>] jfs_write_begin+0x2c/0x40 [jfs]
[22699.655079] [<0000000000494d50>] generic_file_buffered_write+0x170/0x220
[22699.778003] [<0000000000496e58>] __generic_file_aio_write+0x258/0x3a0
[22699.897803] [<0000000000496fd8>] generic_file_aio_write+0x38/0xc0
[22700.013436] [<00000000004c5694>] do_sync_write+0x74/0xc0
[22700.119693] [<00000000004c6128>] vfs_write+0x68/0x140
[22700.222825] [<00000000004c6264>] SyS_pwrite64+0x64/0x80
[22700.328041] [<00000000004400f4>] sys32_pwrite64+0x14/0x40
[22700.435340] [<0000000000406114>] linux_sparc_syscall32+0x34/0x40
[22700.549934] IN-RECLAIM_FS-W at:
[22700.591602] [<000000000047dff4>] lock_acquire+0x54/0x80
[22700.699941] [<000000000046edb4>] down_write_nested+0x34/0x80
[22700.813491] [<00000000100b32e0>] jfs_get_block+0x20/0x300 [jfs]
[22700.930168] [<00000000004ee0a8>] __block_write_full_page+0x248/0x4a0
[22701.052050] [<00000000004ee39c>] block_write_full_page_endio+0x9c/0xe0
[22701.176016] [<00000000004ee3f4>] block_write_full_page+0x14/0x40
[22701.293733] [<00000000100b2ff0>] jfs_writepage+0x10/0x40 [jfs]
[22701.409367] [<00000000004a1df8>] shrink_page_list+0x518/0x880
[22701.523958] [<00000000004a27e8>] shrink_zone+0x688/0xb20
[22701.633341] [<00000000004a3838>] try_to_free_pages+0x2b8/0x360
[22701.748973] [<000000000049bf54>] __alloc_pages_nodemask+0x354/0x660
[22701.869815] [<0000000000496014>] grab_cache_page_write_begin+0x54/0xc0
[22701.993781] [<00000000004ee55c>] nobh_write_begin+0x3c/0x460
[22702.107330] [<00000000100b2f2c>] jfs_write_begin+0x2c/0x40 [jfs]
[22702.225049] [<0000000000494d50>] generic_file_buffered_write+0x170/0x220
[22702.351099] [<0000000000496e58>] __generic_file_aio_write+0x258/0x3a0
[22702.474023] [<0000000000496fd8>] generic_file_aio_write+0x38/0xc0
[22702.592781] [<00000000004c5694>] do_sync_write+0x74/0xc0
[22702.702164] [<00000000004c6128>] vfs_write+0x68/0x140
[22702.808421] [<00000000004c6264>] SyS_pwrite64+0x64/0x80
[22702.916762] [<00000000004400f4>] sys32_pwrite64+0x14/0x40
[22703.027187] [<0000000000406114>] linux_sparc_syscall32+0x34/0x40
[22703.144906] INITIAL USE at:
[22703.182406] [<000000000047dff4>] lock_acquire+0x54/0x80
[22703.286579] [<000000000046edb4>] down_write_nested+0x34/0x80
[22703.395962] [<00000000100b32e0>] jfs_get_block+0x20/0x300 [jfs]
[22703.508470] [<00000000004ee684>] nobh_write_begin+0x164/0x460
[22703.618894] [<00000000100b2f2c>] jfs_write_begin+0x2c/0x40 [jfs]
[22703.732444] [<0000000000494d50>] generic_file_buffered_write+0x170/0x220
[22703.854327] [<0000000000496e58>] __generic_file_aio_write+0x258/0x3a0
[22703.973084] [<0000000000496fd8>] generic_file_aio_write+0x38/0xc0
[22704.087676] [<00000000004c5694>] do_sync_write+0x74/0xc0
[22704.192892] [<00000000004c6128>] vfs_write+0x68/0x140
[22704.294983] [<00000000004c6264>] SyS_pwrite64+0x64/0x80
[22704.399156] [<00000000004400f4>] sys32_pwrite64+0x14/0x40
[22704.505414] [<0000000000406114>] linux_sparc_syscall32+0x34/0x40
[22704.618966] }
[22704.639800] ... key at: [<00000000100dd194>] __key.23313+0x0/0xffffffffffffd194 [jfs]
[22704.740848] ... acquired at:
[22704.777309] [<000000000047dff4>] lock_acquire+0x54/0x80
[22704.842937] [<00000000006f7420>] mutex_lock_nested+0x40/0x360
[22704.914817] [<00000000100ce374>] extAlloc+0x34/0x540 [jfs]
[22704.983572] [<00000000100b34e8>] jfs_get_block+0x228/0x300 [jfs]
[22705.058579] [<00000000004ee684>] nobh_write_begin+0x164/0x460
[22705.130457] [<00000000100b2f2c>] jfs_write_begin+0x2c/0x40 [jfs]
[22705.205463] [<0000000000494d50>] generic_file_buffered_write+0x170/0x220
[22705.288801] [<0000000000496e58>] __generic_file_aio_write+0x258/0x3a0
[22705.369015] [<0000000000496fd8>] generic_file_aio_write+0x38/0xc0
[22705.445061] [<00000000004c5694>] do_sync_write+0x74/0xc0
[22705.511733] [<00000000004c6128>] vfs_write+0x68/0x140
[22705.575280] [<00000000004c6264>] SyS_pwrite64+0x64/0x80
[22705.640908] [<00000000004400f4>] sys32_pwrite64+0x14/0x40
[22705.708623] [<0000000000406114>] linux_sparc_syscall32+0x34/0x40
[22705.783628]
[22705.801339] -> (&jfs_ip->commit_mutex){+.+.+.} ops: 2011277350141952 {
[22705.879469] HARDIRQ-ON-W at:
[22705.916970] [<000000000047dff4>] lock_acquire+0x54/0x80
[22706.020102] [<00000000006f7420>] mutex_lock_nested+0x40/0x360
[22706.129485] [<00000000100b3070>] jfs_commit_inode+0x50/0x140 [jfs]
[22706.244077] [<00000000100b3724>] jfs_write_inode+0x44/0x80 [jfs]
[22706.356586] [<00000000004e444c>] writeback_single_inode+0x10c/0x3a0
[22706.472217] [<00000000004e52ac>] writeback_inodes_wb+0x32c/0x500
[22706.584724] [<00000000004e55bc>] wb_writeback+0x13c/0x200
[22706.689940] [<00000000004e5974>] wb_do_writeback+0x214/0x240
[22706.798281] [<00000000004e5a00>] bdi_writeback_task+0x60/0xa0
[22706.907663] [<00000000004a90a4>] bdi_start_fn+0x64/0xe0
[22707.010796] [<000000000046a7a0>] kthread+0x60/0x80
[22707.108720] [<000000000042b570>] kernel_thread+0x30/0x60
[22707.212894] [<000000000046a89c>] kthreadd+0xdc/0x160
[22707.312902] SOFTIRQ-ON-W at:
[22707.350403] [<000000000047dff4>] lock_acquire+0x54/0x80
[22707.453534] [<00000000006f7420>] mutex_lock_nested+0x40/0x360
[22707.562917] [<00000000100b3070>] jfs_commit_inode+0x50/0x140 [jfs]
[22707.677510] [<00000000100b3724>] jfs_write_inode+0x44/0x80 [jfs]
[22707.790018] [<00000000004e444c>] writeback_single_inode+0x10c/0x3a0
[22707.905650] [<00000000004e52ac>] writeback_inodes_wb+0x32c/0x500
[22708.018157] [<00000000004e55bc>] wb_writeback+0x13c/0x200
[22708.123372] [<00000000004e5974>] wb_do_writeback+0x214/0x240
[22708.231714] [<00000000004e5a00>] bdi_writeback_task+0x60/0xa0
[22708.341097] [<00000000004a90a4>] bdi_start_fn+0x64/0xe0
[22708.444229] [<000000000046a7a0>] kthread+0x60/0x80
[22708.542153] [<000000000042b570>] kernel_thread+0x30/0x60
[22708.646325] [<000000000046a89c>] kthreadd+0xdc/0x160
[22708.746336] RECLAIM_FS-ON-W at:
[22708.786961] [<000000000047b100>] lockdep_trace_alloc+0xe0/0x100
[22708.901552] [<00000000004c253c>] kmem_cache_alloc+0x1c/0x120
[22709.013017] [<00000000100cb384>] dtInsert+0x9a4/0x19e0 [jfs]
[22709.124486] [<00000000100b4f4c>] jfs_mkdir+0x28c/0x380 [jfs]
[22709.235951] [<00000000004cf19c>] vfs_mkdir+0x5c/0xa0
[22709.339083] [<00000000004d162c>] SyS_mkdirat+0xcc/0x100
[22709.445339] [<00000000004cf88c>] SyS_mkdir+0xc/0x20
[22709.547431] [<0000000000406114>] linux_sparc_syscall32+0x34/0x40
[22709.663066] INITIAL USE at:
[22709.699524] [<000000000047dff4>] lock_acquire+0x54/0x80
[22709.801614] [<00000000006f7420>] mutex_lock_nested+0x40/0x360
[22709.909955] [<00000000100b3070>] jfs_commit_inode+0x50/0x140 [jfs]
[22710.023506] [<00000000100b3724>] jfs_write_inode+0x44/0x80 [jfs]
[22710.134971] [<00000000004e444c>] writeback_single_inode+0x10c/0x3a0
[22710.249562] [<00000000004e52ac>] writeback_inodes_wb+0x32c/0x500
[22710.361028] [<00000000004e55bc>] wb_writeback+0x13c/0x200
[22710.465202] [<00000000004e5974>] wb_do_writeback+0x214/0x240
[22710.572500] [<00000000004e5a00>] bdi_writeback_task+0x60/0xa0
[22710.680842] [<00000000004a90a4>] bdi_start_fn+0x64/0xe0
[22710.782932] [<000000000046a7a0>] kthread+0x60/0x80
[22710.879813] [<000000000042b570>] kernel_thread+0x30/0x60
[22710.982946] [<000000000046a89c>] kthreadd+0xdc/0x160
[22711.081912] }
[22711.101705] ... key at: [<00000000100dd18c>] __key.23314+0x0/0xffffffffffffd19c [jfs]
[22711.201713] ... acquired at:
[22711.237133] [<000000000047aa88>] mark_lock+0x2a8/0x780
[22711.301718] [<000000000047afd4>] mark_held_locks+0x74/0xc0
[22711.370474] [<000000000047b100>] lockdep_trace_alloc+0xe0/0x100
[22711.444436] [<00000000004c253c>] kmem_cache_alloc+0x1c/0x120
[22711.515275] [<00000000100cb384>] dtInsert+0x9a4/0x19e0 [jfs]
[22711.586114] [<00000000100b4f4c>] jfs_mkdir+0x28c/0x380 [jfs]
[22711.656953] [<00000000004cf19c>] vfs_mkdir+0x5c/0xa0
[22711.719455] [<00000000004d162c>] SyS_mkdirat+0xcc/0x100
[22711.785086] [<00000000004cf88c>] SyS_mkdir+0xc/0x20
[22711.846548] [<0000000000406114>] linux_sparc_syscall32+0x34/0x40
[22711.921554]
[22711.939263]
[22711.939272] stack backtrace:
[22711.991351] Call Trace:
[22712.020532] [000000000047b758] print_irq_inversion_bug+0xf8/0x120
[22712.094494] [000000000047b948] check_usage_backwards+0xa8/0x120
[22712.166372] [000000000047aa88] mark_lock+0x2a8/0x780
[22712.226793] [000000000047afd4] mark_held_locks+0x74/0xc0
[22712.291382] [000000000047b100] lockdep_trace_alloc+0xe0/0x100
[22712.361179] [00000000004c253c] kmem_cache_alloc+0x1c/0x120
[22712.427885] [00000000100cb384] dtInsert+0x9a4/0x19e0 [jfs]
[22712.494543] [00000000100b4f4c] jfs_mkdir+0x28c/0x380 [jfs]
[22712.561197] [00000000004cf19c] vfs_mkdir+0x5c/0xa0
[22712.619529] [00000000004d162c] SyS_mkdirat+0xcc/0x100
[22712.680996] [00000000004cf88c] SyS_mkdir+0xc/0x20
[22712.738300] [0000000000406114] linux_sparc_syscall32+0x34/0x40