Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

dbuf_find() mutex contention #1291

Closed
cwedgwood opened this issue Feb 12, 2013 · 3 comments
Closed

dbuf_find() mutex contention #1291

cwedgwood opened this issue Feb 12, 2013 · 3 comments
Labels
Type: Performance Performance improvement or performance problem
Milestone

Comments

@cwedgwood
Copy link
Contributor

kvm & arc fighting it out for memory

[703932.789900] INFO: rcu_sched self-detected stall on CPU { 0}  (t=6000 jiffies)
[703932.797598] sending NMI to all CPUs:
[703932.797602] NMI backtrace for cpu 0
[703932.797603] CPU 0 
[703932.797606] Pid: 1507, comm: zvol/8 Tainted: G           O 3.7.5.cw2 #10 Supermicro X8DTL/X8DTL
[703932.797608] RIP: 0010:[<ffffffff8126b041>]  [<ffffffff8126b041>] __const_udelay+0x16/0x26
[703932.797616] RSP: 0018:ffff880333c03d68  EFLAGS: 00000002
[703932.797617] RAX: 00000000001a36f0 RBX: 00000000000003e9 RCX: 0000000000000020
[703932.797619] RDX: 0000000023c36734 RSI: 0000000000000002 RDI: 0000000000068dbc
[703932.797621] RBP: ffff880333c03d88 R08: ffffffff818213e0 R09: 00000000fffffffe
[703932.797622] R10: 0000000000000000 R11: 00000000000008c7 R12: 0000000000001000
[703932.797624] R13: 000000000000b022 R14: ffffffff818213e0 R15: 0000000000000002
[703932.797626] FS:  0000000000000000(0000) GS:ffff880333c00000(0000) knlGS:0000000000000000
[703932.797628] CS:  0010 DS: 0000 ES: 0000 CR0: 000000008005003b
[703932.797629] CR2: 000007fffffd5478 CR3: 000000000178d000 CR4: 00000000000027e0
[703932.797631] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
[703932.797633] DR3: 0000000000000000 DR6: 00000000ffff0ff0 DR7: 0000000000000400
[703932.797634] Process zvol/8 (pid: 1507, threadinfo ffff88032e554000, task ffff880331510000)
[703932.797636] Stack:
[703932.797637]  ffff880333c03d88 ffffffff8101e925 0000000000000002 0000000000000002
[703932.797640]  ffff880333c03da8 ffffffff8101f49b 0000000000000001 0000000000000086
[703932.797642]  ffff880333c03de8 ffffffff8101f523 000000000000002a 0000000000002710
[703932.797645] Call Trace:
[703932.797647]  <IRQ> 
[703932.797648]  [<ffffffff8101e925>] ? native_safe_apic_wait_icr_idle+0x39/0x45
[703932.797656]  [<ffffffff8101f49b>] __default_send_IPI_dest_field.constprop.0+0x1e/0x58
[703932.797658]  [<ffffffff8101f523>] default_send_IPI_mask_sequence_phys+0x4e/0x9f
[703932.797662]  [<ffffffff8102283a>] physflat_send_IPI_all+0x17/0x19
[703932.797664]  [<ffffffff8101f697>] arch_trigger_all_cpu_backtrace+0x50/0x79
[703932.797669]  [<ffffffff8109ba6b>] rcu_check_callbacks+0x156/0x42f
[703932.797673]  [<ffffffff8107c795>] ? tick_nohz_handler+0xde/0xde
[703932.797676]  [<ffffffff8104c0bd>] update_process_times+0x3e/0x73
[703932.797679]  [<ffffffff8107c81b>] tick_sched_timer+0x86/0xaf
[703932.797683]  [<ffffffff8105d59c>] __run_hrtimer+0x94/0x150
[703932.797689]  [<ffffffff8105dedb>] hrtimer_interrupt+0xc6/0x1af
[703932.797693]  [<ffffffff81513b6c>] smp_apic_timer_interrupt+0x77/0x8a
[703932.797696]  [<ffffffff81512db2>] apic_timer_interrupt+0x72/0x80
[703932.797697]  <EOI> 
[703932.797698]  [<ffffffff8150b820>] ? retint_restore_args+0x13/0x13
[703932.797706]  [<ffffffff8150991b>] ? mutex_lock+0x11/0x29
[703932.797735]  [<ffffffffa065cb23>] dbuf_find+0xcb/0x1b3 [zfs]
[703932.797738]  [<ffffffff8150b339>] ? _raw_spin_unlock_irqrestore+0x32/0x37
[703932.797754]  [<ffffffffa0661d80>] __dbuf_hold_impl+0x194/0x97a [zfs]
[703932.797757]  [<ffffffff8150b339>] ? _raw_spin_unlock_irqrestore+0x32/0x37
[703932.797773]  [<ffffffffa0662096>] __dbuf_hold_impl+0x4aa/0x97a [zfs]
[703932.797788]  [<ffffffffa06625e8>] dbuf_hold_impl+0x82/0xa4 [zfs]
[703932.797804]  [<ffffffffa0662cdf>] dbuf_prefetch+0x2a3/0x42a [zfs]
[703932.797808]  [<ffffffff81100110>] ? virt_to_head_page+0x9/0x2c
[703932.797828]  [<ffffffffa067bb94>] dmu_zfetch_dofetch.isra.3+0x132/0x16a [zfs]
[703932.797848]  [<ffffffffa067c6f5>] dmu_zfetch+0x67c/0xe8b [zfs]
[703932.797883]  [<ffffffffa0717fb9>] ? zio_data_buf_alloc+0x74/0x7b [zfs]
[703932.797900]  [<ffffffffa06606ee>] dbuf_read+0x6a5/0x943 [zfs]
[703932.797917]  [<ffffffffa066c89e>] dmu_buf_hold_array_by_dnode+0x2e4/0x4d2 [zfs]
[703932.797925]  [<ffffffffa059ac22>] ? kmem_free_debug+0x12e/0x178 [spl]
[703932.797942]  [<ffffffffa066ccaf>] dmu_buf_hold_array+0x5d/0x7e [zfs]
[703932.797960]  [<ffffffffa066e1cb>] dmu_read_req+0x56/0x195 [zfs]
[703932.797962]  [<ffffffff810ae8e9>] ? trace_hardirqs_off+0x9/0x20
[703932.797965]  [<ffffffff8150b32a>] ? _raw_spin_unlock_irqrestore+0x23/0x37
[703932.797998]  [<ffffffffa072686b>] zvol_read+0x5e/0x8c [zfs]
[703932.798005]  [<ffffffffa05a1cff>] taskq_thread+0x3db/0x5ba [spl]
[703932.798009]  [<ffffffff81064aa3>] ? finish_task_switch+0x82/0xad
[703932.798012]  [<ffffffff810685c9>] ? try_to_wake_up+0x1d4/0x1d4
[703932.798018]  [<ffffffffa05a1924>] ? task_done+0x207/0x207 [spl]
[703932.798020]  [<ffffffff8105a209>] kthread+0x8d/0x95
[703932.798023]  [<ffffffff8105a17c>] ? __kthread_parkme+0x65/0x65
[703932.798025]  [<ffffffff815122ac>] ret_from_fork+0x7c/0xb0
[703932.798028]  [<ffffffff8105a17c>] ? __kthread_parkme+0x65/0x65
[703932.798029] Code: ff c8 5d c3 66 66 66 66 90 55 48 89 e5 ff 15 3f 5d 56 00 5d c3 55 48 8d 04 bd 00 00 00 00 65 48 8b 14 25 d8 2a 01 00 48 6b d2 19 <48> 89 e5 f7 e2 48 8d 7a 01 e8 cb ff ff ff 5d c3 66 66 66 66 90 

[703932.798171] NMI backtrace for cpu 1
[703932.798174] CPU 1 
[703932.798177] Pid: 0, comm: swapper/1 Tainted: G           O 3.7.5.cw2 #10 Supermicro X8DTL/X8DTL
[703932.798179] RIP: 0010:[<ffffffff81292c8e>]  [<ffffffff81292c8e>] intel_idle+0xb8/0x120
[703932.798184] RSP: 0018:ffff880331e13e58  EFLAGS: 00000046
[703932.798186] RAX: 0000000000000010 RBX: 0000000000000004 RCX: 0000000000000001
[703932.798188] RDX: 0000000000000000 RSI: 0000000020eb6bcf RDI: 12e22be059e29000
[703932.798189] RBP: ffff880331e13eb8 R08: 0000000000000898 R09: 0000000000000001
[703932.798191] R10: ffff880624353d30 R11: ffff880624353d30 R12: 0000000000000002
[703932.798192] R13: ffff880333c39270 R14: 12e22be07acdfbcf R15: 0000000000000010
[703932.798194] FS:  0000000000000000(0000) GS:ffff880333c20000(0000) knlGS:0000000000000000
[703932.798196] CS:  0010 DS: 0000 ES: 0000 CR0: 000000008005003b
[703932.798198] CR2: 000000000275e5d8 CR3: 000000000178d000 CR4: 00000000000027e0
[703932.798199] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
[703932.798201] DR3: 0000000000000000 DR6: 00000000ffff0ff0 DR7: 0000000000000400
[703932.798203] Process swapper/1 (pid: 0, threadinfo ffff880331e10000, task ffff880331e096b0)
[703932.798204] Stack:
[703932.798205]  ffff880331e13e88 ffffffff8106a10e 0000000000000018 0000000100000001
[703932.798208]  0000000000000000 000000000095a924 ffff880331e13ee8 ffff880333c39270
[703932.798211]  ffffffff817d2d90 0000000000000002 0000000000000000 0000000000000000
[703932.798213] Call Trace:
[703932.798217]  [<ffffffff8106a10e>] ? sched_clock_cpu+0x46/0xcf
[703932.798222]  [<ffffffff813e8763>] cpuidle_enter+0x12/0x14
[703932.798225]  [<ffffffff813e8c00>] cpuidle_enter_state+0x14/0x3d
[703932.798228]  [<ffffffff813e8cbd>] cpuidle_idle_call+0x94/0xd4
[703932.798232]  [<ffffffff810098b2>] cpu_idle+0x64/0xb7
[703932.798235]  [<ffffffff814f9a91>] start_secondary+0x191/0x195
[703932.798237] Code: 48 8b 04 25 60 b8 00 00 48 89 d1 48 2d c8 3f 00 00 0f 01 c8 0f ae f0 e8 3a ff ff ff 85 c0 75 0b b9 01 00 00 00 4c 89 f8 0f 01 c9 <e8> 6d bc e1 ff e8 79 3b de ff 48 89 c7 4c 29 f7 e8 4e 17 db ff 

[703932.798270] NMI backtrace for cpu 2
[703932.798273] CPU 2 
[703932.798276] Pid: 0, comm: swapper/2 Tainted: G           O 3.7.5.cw2 #10 Supermicro X8DTL/X8DTL
[703932.798278] RIP: 0010:[<ffffffff81292c8e>]  [<ffffffff81292c8e>] intel_idle+0xb8/0x120
[703932.798282] RSP: 0018:ffff880331e17e58  EFLAGS: 00000046
[703932.798284] RAX: 0000000000000010 RBX: 0000000000000004 RCX: 0000000000000001
[703932.798286] RDX: 0000000000000000 RSI: 0000000020ebdf44 RDI: 12e22be059e29000
[703932.798288] RBP: ffff880331e17eb8 R08: 0000000000000320 R09: 0000000000000003
[703932.798289] R10: ffff88037c28fd30 R11: ffff88037c28fd30 R12: 0000000000000002
[703932.798291] R13: ffff880333c59270 R14: 12e22be07ace6f44 R15: 0000000000000010
[703932.798293] FS:  0000000000000000(0000) GS:ffff880333c40000(0000) knlGS:0000000000000000
[703932.798295] CS:  0010 DS: 0000 ES: 0000 CR0: 000000008005003b
[703932.798296] CR2: 00000000023d03c0 CR3: 000000000178d000 CR4: 00000000000027e0
[703932.798298] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
[703932.798300] DR3: 0000000000000000 DR6: 00000000ffff0ff0 DR7: 0000000000000400
[703932.798302] Process swapper/2 (pid: 0, threadinfo ffff880331e14000, task ffff880331e0ad60)
[703932.798303] Stack:
[703932.798304]  ffff880331e17e88 ffffffff8106a10e 0000000000000018 0000000200000002
[703932.798307]  0000000000000000 000000000095365e ffff880331e17ee8 ffff880333c59270
[703932.798313]  ffffffff817d2d90 0000000000000002 0000000000000000 0000000000000000
[703932.798316] Call Trace:
[703932.798319]  [<ffffffff8106a10e>] ? sched_clock_cpu+0x46/0xcf
[703932.798323]  [<ffffffff813e8763>] cpuidle_enter+0x12/0x14
[703932.798325]  [<ffffffff813e8c00>] cpuidle_enter_state+0x14/0x3d
[703932.798328]  [<ffffffff813e8cbd>] cpuidle_idle_call+0x94/0xd4
[703932.798331]  [<ffffffff810098b2>] cpu_idle+0x64/0xb7
[703932.798333]  [<ffffffff814f9a91>] start_secondary+0x191/0x195
[703932.798335] Code: 48 8b 04 25 60 b8 00 00 48 89 d1 48 2d c8 3f 00 00 0f 01 c8 0f ae f0 e8 3a ff ff ff 85 c0 75 0b b9 01 00 00 00 4c 89 f8 0f 01 c9 <e8> 6d bc e1 ff e8 79 3b de ff 48 89 c7 4c 29 f7 e8 4e 17 db ff 

[703932.798390] NMI backtrace for cpu 3
[703932.798393] CPU 3 
[703932.798396] Pid: 0, comm: swapper/3 Tainted: G           O 3.7.5.cw2 #10 Supermicro X8DTL/X8DTL
[703932.798397] RIP: 0010:[<ffffffff81292c8e>]  [<ffffffff81292c8e>] intel_idle+0xb8/0x120
[703932.798402] RSP: 0018:ffff880331e1be58  EFLAGS: 00000046
[703932.798404] RAX: 0000000000000020 RBX: 0000000000000008 RCX: 0000000000000001
[703932.798406] RDX: 0000000000000000 RSI: 0000000020e964ac RDI: 12e22be059e29000
[703932.798407] RBP: ffff880331e1beb8 R08: 0000000000000898 R09: 0000000000000009
[703932.798409] R10: ffff880333c6fda8 R11: ffff880333c6fda8 R12: 0000000000000003
[703932.798411] R13: ffff880333c79270 R14: 12e22be07acbf4ac R15: 0000000000000020
[703932.798413] FS:  0000000000000000(0000) GS:ffff880333c60000(0000) knlGS:0000000000000000
[703932.798415] CS:  0010 DS: 0000 ES: 0000 CR0: 000000008005003b
[703932.798416] CR2: 000000000275e5d8 CR3: 000000000178d000 CR4: 00000000000027e0
[703932.798418] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
[703932.798420] DR3: 0000000000000000 DR6: 00000000ffff0ff0 DR7: 0000000000000400
[703932.798422] Process swapper/3 (pid: 0, threadinfo ffff880331e18000, task ffff880331e0c410)
[703932.798423] Stack:
[703932.798424]  ffff880331e1be88 ffffffff8106a10e 0000000000000018 0000000300000003
[703932.798427]  0000000000000000 000000000097b0be ffff880331e1bee8 ffff880333c79270
[703932.798433]  ffffffff817d2d90 0000000000000003 0000000000000000 0000000000000000
[703932.798436] Call Trace:
[703932.798439]  [<ffffffff8106a10e>] ? sched_clock_cpu+0x46/0xcf
[703932.798443]  [<ffffffff813e8763>] cpuidle_enter+0x12/0x14
[703932.798445]  [<ffffffff813e8c00>] cpuidle_enter_state+0x14/0x3d
[703932.798448]  [<ffffffff813e8cbd>] cpuidle_idle_call+0x94/0xd4
[703932.798451]  [<ffffffff810098b2>] cpu_idle+0x64/0xb7
[703932.798453]  [<ffffffff814f9a91>] start_secondary+0x191/0x195
[703932.798455] Code: 48 8b 04 25 60 b8 00 00 48 89 d1 48 2d c8 3f 00 00 0f 01 c8 0f ae f0 e8 3a ff ff ff 85 c0 75 0b b9 01 00 00 00 4c 89 f8 0f 01 c9 <e8> 6d bc e1 ff e8 79 3b de ff 48 89 c7 4c 29 f7 e8 4e 17 db ff 

[703932.798508] NMI backtrace for cpu 4
[703932.798512] CPU 4 
[703932.798518] Pid: 0, comm: swapper/4 Tainted: G           O 3.7.5.cw2 #10 Supermicro X8DTL/X8DTL
[703932.798521] RIP: 0010:[<ffffffff81292c8e>]  [<ffffffff81292c8e>] intel_idle+0xb8/0x120
[703932.798531] RSP: 0018:ffff880331e1fe58  EFLAGS: 00000046
[703932.798533] RAX: 0000000000000020 RBX: 0000000000000008 RCX: 0000000000000001
[703932.798536] RDX: 0000000000000000 RSI: 0000000020ebaa7e RDI: 12e22be059e29000
[703932.798539] RBP: ffff880331e1feb8 R08: 0000000000000898 R09: 0000000000000005
[703932.798542] R10: ffff88063fc0d7c0 R11: ffff88063fc0d9c0 R12: 0000000000000003
[703932.798544] R13: ffff88063fc19270 R14: 12e22be07ace3a7e R15: 0000000000000020
[703932.798548] FS:  0000000000000000(0000) GS:ffff88063fc00000(0000) knlGS:0000000000000000
[703932.798550] CS:  0010 DS: 0000 ES: 0000 CR0: 000000008005003b
[703932.798553] CR2: fffff900c23a7000 CR3: 000000000178d000 CR4: 00000000000027e0
[703932.798556] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
[703932.798559] DR3: 0000000000000000 DR6: 00000000ffff0ff0 DR7: 0000000000000400
[703932.798562] Process swapper/4 (pid: 0, threadinfo ffff880331e1c000, task ffff880331e0dac0)
[703932.798564] Stack:
[703932.798566]  ffff880331e1fe88 00028177aacbde00 ffff88063fc0d9c0 0000000404334d9a
[703932.798571]  0000000000000122 000000000f7c2850 ffff880331e1fee8 ffff88063fc19270
[703932.798575]  ffffffff817d2d90 0000000000000003 0000000000000000 0000000000000000
[703932.798579] Call Trace:
[703932.798588]  [<ffffffff813e8763>] cpuidle_enter+0x12/0x14
[703932.798593]  [<ffffffff813e8c00>] cpuidle_enter_state+0x14/0x3d
[703932.798597]  [<ffffffff813e8cbd>] cpuidle_idle_call+0x94/0xd4
[703932.798604]  [<ffffffff810098b2>] cpu_idle+0x64/0xb7
[703932.798608]  [<ffffffff814f9a91>] start_secondary+0x191/0x195
[703932.798611] Code: 48 8b 04 25 60 b8 00 00 48 89 d1 48 2d c8 3f 00 00 0f 01 c8 0f ae f0 e8 3a ff ff ff 85 c0 75 0b b9 01 00 00 00 4c 89 f8 0f 01 c9 <e8> 6d bc e1 ff e8 79 3b de ff 48 89 c7 4c 29 f7 e8 4e 17 db ff 

[703932.798652] NMI backtrace for cpu 5
[703932.798656] CPU 5 
[703932.798660] Pid: 0, comm: swapper/5 Tainted: G           O 3.7.5.cw2 #10 Supermicro X8DTL/X8DTL
[703932.798663] RIP: 0010:[<ffffffff81292c8e>]  [<ffffffff81292c8e>] intel_idle+0xb8/0x120
[703932.798670] RSP: 0018:ffff880331e2be58  EFLAGS: 00000046
[703932.798672] RAX: 0000000000000020 RBX: 0000000000000008 RCX: 0000000000000001
[703932.798675] RDX: 0000000000000000 RSI: 0000000020eb105b RDI: 12e22be059e29000
[703932.798678] RBP: ffff880331e2beb8 R08: 0000000000000898 R09: 0000000000000005
[703932.798681] R10: ffff88063fc2d7c0 R11: ffff88063fc2d9c0 R12: 0000000000000003
[703932.798683] R13: ffff88063fc39270 R14: 12e22be07acda05b R15: 0000000000000020
[703932.798687] FS:  0000000000000000(0000) GS:ffff88063fc20000(0000) knlGS:0000000000000000
[703932.798690] CS:  0010 DS: 0000 ES: 0000 CR0: 000000008005003b
[703932.798692] CR2: fffff98003d42b88 CR3: 000000000178d000 CR4: 00000000000027e0
[703932.798695] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
[703932.798698] DR3: 0000000000000000 DR6: 00000000ffff0ff0 DR7: 0000000000000400
[703932.798701] Process swapper/5 (pid: 0, threadinfo ffff880331e28000, task ffff880331e20000)
[703932.798703] Stack:
[703932.798705]  ffff880331e2be88 00028177a9021a80 ffff88063fc2d9c0 0000000504334d9a
[703932.798709]  0000000000000122 000000000db2fdc4 ffff880331e2bee8 ffff88063fc39270
[703932.798714]  ffffffff817d2d90 0000000000000003 0000000000000000 0000000000000000
[703932.798718] Call Trace:
[703932.798724]  [<ffffffff813e8763>] cpuidle_enter+0x12/0x14
[703932.798729]  [<ffffffff813e8c00>] cpuidle_enter_state+0x14/0x3d
[703932.798733]  [<ffffffff813e8cbd>] cpuidle_idle_call+0x94/0xd4
[703932.798738]  [<ffffffff810098b2>] cpu_idle+0x64/0xb7
[703932.798742]  [<ffffffff814f9a91>] start_secondary+0x191/0x195
[703932.798744] Code: 48 8b 04 25 60 b8 00 00 48 89 d1 48 2d c8 3f 00 00 0f 01 c8 0f ae f0 e8 3a ff ff ff 85 c0 75 0b b9 01 00 00 00 4c 89 f8 0f 01 c9 <e8> 6d bc e1 ff e8 79 3b de ff 48 89 c7 4c 29 f7 e8 4e 17 db ff 

[703932.798785] NMI backtrace for cpu 6
[703932.798789] CPU 6 
[703932.798793] Pid: 0, comm: swapper/6 Tainted: G           O 3.7.5.cw2 #10 Supermicro X8DTL/X8DTL
[703932.798796] RIP: 0010:[<ffffffff81292c8e>]  [<ffffffff81292c8e>] intel_idle+0xb8/0x120
[703932.798803] RSP: 0018:ffff880331e2fe58  EFLAGS: 00000046
[703932.798805] RAX: 0000000000000010 RBX: 0000000000000004 RCX: 0000000000000001
[703932.798808] RDX: 0000000000000000 RSI: 0000000020eae347 RDI: 12e22be059e29000
[703932.798811] RBP: ffff880331e2feb8 R08: 0000000000000320 R09: 0000000000000002
[703932.798814] R10: ffff88063fc4d7c0 R11: ffff88063fc4d9c0 R12: 0000000000000002
[703932.798816] R13: ffff88063fc59270 R14: 12e22be07acd7347 R15: 0000000000000010
[703932.798820] FS:  0000000000000000(0000) GS:ffff88063fc40000(0000) knlGS:0000000000000000
[703932.798823] CS:  0010 DS: 0000 ES: 0000 CR0: 000000008005003b
[703932.798825] CR2: fffff98003d42b88 CR3: 000000000178d000 CR4: 00000000000027e0
[703932.798828] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
[703932.798831] DR3: 0000000000000000 DR6: 00000000ffff0ff0 DR7: 0000000000000400
[703932.798834] Process swapper/6 (pid: 0, threadinfo ffff880331e2c000, task ffff880331e216b0)
[703932.798836] Stack:
[703932.798837]  ffff880331e2fe88 0002813418561b00 ffff88063fc4d9c0 0000000604334d9a
[703932.798842]  0000000000000000 000000000097f7e4 ffff880331e2fee8 ffff88063fc59270
[703932.798847]  ffffffff817d2d90 0000000000000002 0000000000000000 0000000000000000
[703932.798851] Call Trace:
[703932.798857]  [<ffffffff813e8763>] cpuidle_enter+0x12/0x14
[703932.798862]  [<ffffffff813e8c00>] cpuidle_enter_state+0x14/0x3d
[703932.798866]  [<ffffffff813e8cbd>] cpuidle_idle_call+0x94/0xd4
[703932.798871]  [<ffffffff810098b2>] cpu_idle+0x64/0xb7
[703932.798875]  [<ffffffff814f9a91>] start_secondary+0x191/0x195
[703932.798878] Code: 48 8b 04 25 60 b8 00 00 48 89 d1 48 2d c8 3f 00 00 0f 01 c8 0f ae f0 e8 3a ff ff ff 85 c0 75 0b b9 01 00 00 00 4c 89 f8 0f 01 c9 <e8> 6d bc e1 ff e8 79 3b de ff 48 89 c7 4c 29 f7 e8 4e 17 db ff 

[703932.798918] NMI backtrace for cpu 7
[703932.798925] CPU 7 
[703932.798929] Pid: 0, comm: swapper/7 Tainted: G           O 3.7.5.cw2 #10 Supermicro X8DTL/X8DTL
[703932.798932] RIP: 0010:[<ffffffff81292c8e>]  [<ffffffff81292c8e>] intel_idle+0xb8/0x120
[703932.798938] RSP: 0018:ffff880331e33e58  EFLAGS: 00000046
[703932.798940] RAX: 0000000000000020 RBX: 0000000000000008 RCX: 0000000000000001
[703932.798943] RDX: 0000000000000000 RSI: 0000000020e9d6c1 RDI: 12e22be059e29000
[703932.798945] RBP: ffff880331e33eb8 R08: 0000000000000898 R09: 0000000000000009
[703932.798947] R10: 0000000000000fef R11: 0000000000000fef R12: 0000000000000003
[703932.798949] R13: ffff88063fc79270 R14: 12e22be07acc66c1 R15: 0000000000000020
[703932.798952] FS:  0000000000000000(0000) GS:ffff88063fc60000(0000) knlGS:0000000000000000
[703932.798955] CS:  0010 DS: 0000 ES: 0000 CR0: 000000008005003b
[703932.798957] CR2: ffffffffff600400 CR3: 000000000178d000 CR4: 00000000000027e0
[703932.798959] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
[703932.798962] DR3: 0000000000000000 DR6: 00000000ffff0ff0 DR7: 0000000000000400
[703932.798965] Process swapper/7 (pid: 0, threadinfo ffff880331e30000, task ffff880331e22d60)
[703932.798966] Stack:
[703932.798968]  ffff880331e33e88 ffffffff8106a10e 0000000000000018 0000000700000007
[703932.798972]  0000000000000000 000000000097412c ffff880331e33ee8 ffff88063fc79270
[703932.798976]  ffffffff817d2d90 0000000000000003 0000000000000000 0000000000000000
[703932.798979] Call Trace:
[703932.798985]  [<ffffffff8106a10e>] ? sched_clock_cpu+0x46/0xcf
[703932.798990]  [<ffffffff813e8763>] cpuidle_enter+0x12/0x14
[703932.798994]  [<ffffffff813e8c00>] cpuidle_enter_state+0x14/0x3d
[703932.798997]  [<ffffffff813e8cbd>] cpuidle_idle_call+0x94/0xd4
[703932.799002]  [<ffffffff810098b2>] cpu_idle+0x64/0xb7
[703932.799005]  [<ffffffff814f9a91>] start_secondary+0x191/0x195
[703932.799007] Code: 48 8b 04 25 60 b8 00 00 48 89 d1 48 2d c8 3f 00 00 0f 01 c8 0f ae f0 e8 3a ff ff ff 85 c0 75 0b b9 01 00 00 00 4c 89 f8 0f 01 c9 <e8> 6d bc e1 ff e8 79 3b de ff 48 89 c7 4c 29 f7 e8 4e 17 db ff 
@cwedgwood
Copy link
Contributor Author

@behlendorf I'm testing right now with:

diff --git a/include/sys/dbuf.h b/include/sys/dbuf.h
index ef93eb5..972c1dc 100644
--- a/include/sys/dbuf.h
+++ b/include/sys/dbuf.h
@@ -227,7 +227,7 @@ typedef struct dmu_buf_impl {
 } dmu_buf_impl_t;

 /* Note: the dbuf hash table is exposed only for the mdb module */
-#define        DBUF_MUTEXES 256
+#define        DBUF_MUTEXES 8192
 #define        DBUF_HASH_MUTEX(h, idx) (&(h)->hash_mutexes[(idx) & (DBUF_MUTEXES-1)])
 typedef struct dbuf_hash_table {
        uint64_t hash_table_mask;
diff --git a/module/zfs/arc.c b/module/zfs/arc.c
index 09924db..a2b2c38 100644
--- a/module/zfs/arc.c
+++ b/module/zfs/arc.c
@@ -600,7 +600,7 @@ struct ht_lock {
 #endif
 };

-#define        BUF_LOCKS 256
+#define        BUF_LOCKS 8192
 typedef struct buf_hash_table {
        uint64_t ht_mask;
        arc_buf_hdr_t **ht_table;

it's a bit early to say it's helping but so far it doesn't seem to have hurt (performance is the same not worse, I don't see rcu stalls (yet))

I'll probably leave this change in my tree for a while and revisit this in a week or two.

@cwedgwood
Copy link
Contributor Author

@behlendorf I just noticed this was still open.

As reported on IRC this did indeed help.

@behlendorf
Copy link
Contributor

@cwedgwood It helped by getting rid of the 'stall on CPU' messages or it measurably helped performance in some way?

@behlendorf behlendorf modified the milestones: 0.6.4, 0.6.3 Jun 4, 2014
behlendorf pushed a commit to behlendorf/zfs that referenced this issue Oct 23, 2014
Due to evidence of contention both the buf_hash_table and the
dbuf_hash_table sizes have been increased from 256 to 8192.

Signed-off-by: Brian Behlendorf <behlendorf1@llnl.gov>
Issue openzfs#1291
behlendorf pushed a commit to behlendorf/zfs that referenced this issue Oct 23, 2014
Due to evidence of contention both the buf_hash_table and the
dbuf_hash_table sizes have been increased from 256 to 8192.

Signed-off-by: Brian Behlendorf <behlendorf1@llnl.gov>
Issue openzfs#1291
snajpa pushed a commit to vpsfreecz/zfs that referenced this issue Nov 7, 2014
Due to evidence of contention both the buf_hash_table and the
dbuf_hash_table sizes have been increased from 256 to 8192.

Signed-off-by: Brian Behlendorf <behlendorf1@llnl.gov>
Issue openzfs#1291
Signed-off-by: Pavel Snajdr <snajpa@snajpa.net>
snajpa pushed a commit to relbit/zfs that referenced this issue Nov 8, 2014
Due to evidence of contention both the buf_hash_table and the
dbuf_hash_table sizes have been increased from 256 to 8192.

Signed-off-by: Brian Behlendorf <behlendorf1@llnl.gov>
Issue openzfs#1291
Signed-off-by: Pavel Snajdr <snajpa@snajpa.net>
ryao pushed a commit to ryao/zfs that referenced this issue Nov 29, 2014
Due to evidence of contention both the buf_hash_table and the
dbuf_hash_table sizes have been increased from 256 to 8192.

This increase in hash table size adds approximating 0.5M to
our fixed memory footprint.  This relatively small increase
is not expected to cause problems even on low memory machines.
This footprint will also become dynamic when the persistent
L2ARC support is finalized.  In the meanwhile, this small
change significantly reduces contention for certain workloads.

Signed-off-by: Chris Wedgwood <cw@f00f.org>
Signed-off-by: Brian Behlendorf <behlendorf1@llnl.gov>
Signed-off-by: Pavel Snajdr <snajpa@snajpa.net>
Closes openzfs#1291
@dweeezil dweeezil mentioned this issue Jul 20, 2015
19 tasks
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
Type: Performance Performance improvement or performance problem
Projects
None yet
Development

No branches or pull requests

2 participants