XFS read hangs in 3.1-rc10
Hello!
We're seeing a big problem with read latency in 3.1-rc10 and 3.1-rc7 when compared with 2.6.36, to the point that the hung task detector is spitting out traces when set to 30 seconds. At first, we noticed this on SATA disks on a PERC5 controller and figured it was just really bad RAID latency, but it also seems to be happening on an SSD box.
This is kind of a pain to debug since running "ps" also seems to cause reclaim from fork() which hits a lock held by the rest of the blocked stuff, so I wrote some hacky tools that do it without allocating (much) memory or forking: http://0x.ca/sim/ref/tools/
watch_utilization: full-screen iostat/vmstat type output
pstack: full-screen "ps -eo pid,cmd,stat | grep D" with stack trace
kswapd has a stack trace like this (and is almost always in D state), from cat /proc/pidof kswapd0/stack:
[<ffffffff8126f205>] xfs_reclaim_inode+0x85/0x2b0 [<ffffffff8126f5b0>] xfs_reclaim_inodes_ag+0x180/0x2f0 [<ffffffff8126f74e>] xfs_reclaim_inodes_nr+0x2e/0x40 [<ffffffff8126ccf0>] xfs_fs_free_cached_objects+0x10/0x20 [<ffffffff81119a70>] prune_super+0x110/0x1b0 [<ffffffff810e4fa5>] shrink_slab+0x1e5/0x2a0 [<ffffffff810e5821>] kswapd+0x7c1/0xba0 [<ffffffff8107ada6>] kthread+0x96/0xb0 [<ffffffff816c0474>] kernel_thread_helper+0x4/0x10
[<ffffffffffffffff>] 0xffffffffffffffff
All of the other processes that get stuck have this stack:
[<ffffffff81080587>] down+0x47/0x50 [<ffffffff8125e816>] xfs_buf_lock+0x66/0xd0 [<ffffffff812603ad>] _xfs_buf_find+0x16d/0x270 [<ffffffff81260517>] xfs_buf_get+0x67/0x1a0 [<ffffffff8126067a>] xfs_buf_read+0x2a/0x120 [<ffffffff812b876f>] xfs_trans_read_buf+0x28f/0x3f0 [<ffffffff8129e161>] xfs_read_agi+0x71/0x100 [<ffffffff8129e219>] xfs_ialloc_read_agi+0x29/0xa0 [<ffffffff8129e59b>] xfs_ialloc_ag_select+0x1db/0x2a0 [<ffffffff8129fc95>] xfs_dialloc+0x415/0x8c0 [<ffffffff812a336c>] xfs_ialloc+0x5c/0x710 [<ffffffff812712d5>] xfs_dir_ialloc+0x75/0x290 [<ffffffff8127390a>] xfs_create+0x46a/0x600 [<ffffffff81269a7a>] xfs_vn_mknod+0x7a/0x130 [<ffffffff81269b4b>] xfs_vn_create+0xb/0x10 [<ffffffff81124c99>] vfs_create+0x99/0xd0 [<ffffffff8112635b>] do_last+0x69b/0x810 [<ffffffff8112659f>] path_openat+0xcf/0x3f0 [<ffffffff811269d3>] do_filp_open+0x43/0xa0 [<ffffffff81115202>] do_sys_open+0x152/0x1f0 [<ffffffff811152cb>] sys_open+0x1b/0x20 [<ffffffff816be392>] system_call_fastpath+0x16/0x1b
[<ffffffffffffffff>] 0xffffffffffffffff
By the way, xfs_reclaim_inode+0x85 (133) disassembles as:
0xffffffff8128d4dd <+77>: nopl (%rax) 0xffffffff8128d4e0 <+80>: mov $0x4,%esi 0xffffffff8128d4e5 <+85>: mov %r12,%rdi 0xffffffff8128d4e8 <+88>: callq 0xffffffff812831c0 <xfs_ilock> 0xffffffff8128d4ed <+93>: mov %r15,%rdi 0xffffffff8128d4f0 <+96>: callq 0xffffffff8104c810 <try_wait_for_completion> 0xffffffff8128d4f5 <+101>: test %al,%al 0xffffffff8128d4f7 <+103>: jne 0xffffffff8128d515 <xfs_reclaim_inode+133> 0xffffffff8128d4f9 <+105>: test %r14d,%r14d 0xffffffff8128d4fc <+108>: nopl 0x0(%rax) 0xffffffff8128d500 <+112>: je 0xffffffff8128d6d8 <xfs_reclaim_inode+584> 0xffffffff8128d506 <+118>: mov %r15,%rdi 0xffffffff8128d509 <+121>: nopl 0x0(%rax) 0xffffffff8128d510 <+128>: callq 0xffffffff816f1bb0 <wait_for_completion> 0xffffffff8128d515 <+133>: mov -0x40(%rbp),%rdi 0xffffffff8128d519 <+137>: callq 0xffffffff81146e10 <is_bad_inode> 0xffffffff8128d51e <+142>: test %eax,%eax
...So the next function is wait_for_completion(), which is marked __sched and thus doesn't show up in the trace.
When the clog happens, "iostat -x -k 1" shows no reads from the XFS devices, though writes keep happening. "vmstat 1" matches. I tried switching schedulers from CFQ to deadline -- no difference. Queue depth is empty on the devices and nothing is actually clogged up at the device -- it's not actually plugged at the controller or disk. I did a sysreq-w while this was happening. About 10 seconds later, everything unclogs and continues. Sysreq-W output below. I poked around at the various XFS tracepoints in /sys/kernel/debug/tracing/events/xfs, but I'm not sure which tracepoints to use and many of them scroll too fast to see anything. Any suggestions?
Simon-
SysRq : Show Blocked State
task PC stack pid father
kswapd0 D ffff88022fc52940 0 543 2 0x00000000
ffff8802261f1940 0000000000000046 ffff8802261f0010 ffff880226b5ac80 0000000000012940 ffff8802261f1fd8 ffff8802261f1fd8 0000000000012940 0000000000000001 ffff880226b5ac80 ffff8801e0831640 ffff880226b5b000
Call Trace: [<ffffffff816b482a>] ? schedule+0x3a/0x60 [<ffffffff8111167e>] ? __slab_free+0x1fe/0x320 [<ffffffff816b482a>] schedule+0x3a/0x60 [<ffffffff816b4ced>] schedule_timeout+0x21d/0x280 [<ffffffff816b3bae>] wait_for_common+0xee/0x180 [<ffffffff81050490>] ? try_to_wake_up+0x270/0x270 [<ffffffff810aa980>] ? call_rcu_sched+0x10/0x20 [<ffffffff816b3ce8>] wait_for_completion+0x18/0x20 [<ffffffff8126f205>] xfs_reclaim_inode+0x85/0x2b0 [<ffffffff8137663b>] ? radix_tree_gang_lookup_tag+0xab/0x120 [<ffffffff8126f5b0>] xfs_reclaim_inodes_ag+0x180/0x2f0 [<ffffffff8126f74e>] xfs_reclaim_inodes_nr+0x2e/0x40 [<ffffffff8126ccf0>] xfs_fs_free_cached_objects+0x10/0x20 [<ffffffff81119a70>] prune_super+0x110/0x1b0 [<ffffffff810e4fa5>] shrink_slab+0x1e5/0x2a0 [<ffffffff810e5821>] kswapd+0x7c1/0xba0 [<ffffffff8105049d>] ? default_wake_function+0xd/0x10 [<ffffffff8107b2c0>] ? wake_up_bit+0x40/0x40 [<ffffffff810e5060>] ? shrink_slab+0x2a0/0x2a0 [<ffffffff8107ada6>] kthread+0x96/0xb0 [<ffffffff816c0474>] kernel_thread_helper+0x4/0x10 [<ffffffff8107ad10>] ? kthread_worker_fn+0x190/0x190 [<ffffffff816c0470>] ? gs_change+0x13/0x13
pop3 D ffff88022fcd2940 0 4189 4182 0x00000000
ffff880226a8fa18 0000000000000082 ffff880226a8e010 ffff8802253a0000 0000000000012940 ffff880226a8ffd8 ffff880226a8ffd8 0000000000012940 0000000000000003 ffff8802253a0000 ffff880226949640 ffff8802253a0380
Call Trace: [<ffffffff81371163>] ? cpumask_next_and+0x23/0x40 [<ffffffff810498ca>] ? select_task_rq_fair+0x5aa/0xb30 [<ffffffff816b482a>] schedule+0x3a/0x60 [<ffffffff816b4ced>] schedule_timeout+0x21d/0x280 [<ffffffff8112da50>] ? dput+0x40/0x320 [<ffffffff816b5cc0>] __down+0x70/0xb0 [<ffffffff812603ad>] ? _xfs_buf_find+0x16d/0x270 [<ffffffff81080587>] down+0x47/0x50 [<ffffffff8125e816>] xfs_buf_lock+0x66/0xd0 [<ffffffff812603ad>] _xfs_buf_find+0x16d/0x270 [<ffffffff81274c37>] ? kmem_zone_alloc+0x77/0xe0 [<ffffffff81260517>] xfs_buf_get+0x67/0x1a0 [<ffffffff8126067a>] xfs_buf_read+0x2a/0x120 [<ffffffff812b876f>] xfs_trans_read_buf+0x28f/0x3f0 [<ffffffff8129e161>] xfs_read_agi+0x71/0x100 [<ffffffff812a3f58>] xfs_iunlink+0x48/0x150 [<ffffffff8105f1a2>] ? current_fs_time+0x22/0x30 [<ffffffff812b8ccd>] ? xfs_trans_ichgtime+0x1d/0xb0 [<ffffffff81271246>] xfs_droplink+0x56/0x70 [<ffffffff812731fd>] xfs_remove+0x2bd/0x3a0 [<ffffffff81269c73>] xfs_vn_unlink+0x43/0x90 [<ffffffff811250d1>] vfs_unlink+0x91/0x110 [<ffffffff81125313>] do_unlinkat+0x1c3/0x1e0 [<ffffffff8111b831>] ? sys_newstat+0x31/0x50 [<ffffffff81125341>] sys_unlink+0x11/0x20 [<ffffffff816be392>] system_call_fastpath+0x16/0x1b
pop3 D ffff88022fc12940 0 4190 4182 0x00000000
ffff880225475648 0000000000000082 ffff880225474010 ffff8802253a5900 0000000000012940 ffff880225475fd8 ffff880225475fd8 0000000000012940 0000000000000000 ffff8802253a5900 ffffffff819b3020 ffff8802253a5c80
Call Trace: [<ffffffff810d56e1>] ? mempool_alloc_slab+0x11/0x20 [<ffffffff810d57f0>] ? mempool_alloc+0x60/0x140 [<ffffffff812a1181>] ? xfs_iext_bno_to_ext+0x91/0x180 [<ffffffff816b482a>] schedule+0x3a/0x60 [<ffffffff816b4ced>] schedule_timeout+0x21d/0x280 [<ffffffff810d57f0>] ? mempool_alloc+0x60/0x140 [<ffffffff816b5cc0>] __down+0x70/0xb0 [<ffffffff812603ad>] ? _xfs_buf_find+0x16d/0x270 [<ffffffff81080587>] down+0x47/0x50 [<ffffffff8125e816>] xfs_buf_lock+0x66/0xd0 [<ffffffff812603ad>] _xfs_buf_find+0x16d/0x270 [<ffffffff81274c37>] ? kmem_zone_alloc+0x77/0xe0 [<ffffffff81260517>] xfs_buf_get+0x67/0x1a0 [<ffffffff8126067a>] xfs_buf_read+0x2a/0x120 [<ffffffff812b876f>] xfs_trans_read_buf+0x28f/0x3f0 [<ffffffff8129e161>] xfs_read_agi+0x71/0x100 [<ffffffff8129e219>] xfs_ialloc_read_agi+0x29/0xa0 [<ffffffff8129e59b>] xfs_ialloc_ag_select+0x1db/0x2a0 [<ffffffff8129fc95>] xfs_dialloc+0x415/0x8c0 [<ffffffff815e14f3>] ? dev_queue_xmit+0x153/0x5b0 [<ffffffff810d6e2a>] ? zone_watermark_ok+0x1a/0x20 [<ffffffff813758a6>] ? __prop_inc_single+0x46/0x60 [<ffffffff8112da50>] ? dput+0x40/0x320 [<ffffffff812a336c>] xfs_ialloc+0x5c/0x710 [<ffffffff812b381f>] ? xlog_grant_log_space+0x24f/0x530 [<ffffffff81274cd5>] ? kmem_zone_zalloc+0x35/0x50 [<ffffffff812712d5>] xfs_dir_ialloc+0x75/0x290 [<ffffffff812afa39>] ? xfs_trans_reserve+0x99/0x210 [<ffffffff8127390a>] xfs_create+0x46a/0x600 [<ffffffff811228ba>] ? inode_permission+0x7a/0xd0 [<ffffffff81121bd7>] ? do_lookup+0xf7/0x3a0 [<ffffffff81269a7a>] xfs_vn_mknod+0x7a/0x130 [<ffffffff81269b4b>] xfs_vn_create+0xb/0x10 [<ffffffff81124c99>] vfs_create+0x99/0xd0 [<ffffffff8112635b>] do_last+0x69b/0x810 [<ffffffff8112659f>] path_openat+0xcf/0x3f0 [<ffffffff8112401d>] ? user_path_at+0x8d/0xb0 [<ffffffff811269d3>] do_filp_open+0x43/0xa0 [<ffffffff81131d2a>] ? alloc_fd+0x4a/0x140 [<ffffffff81115202>] do_sys_open+0x152/0x1f0 [<ffffffff811152cb>] sys_open+0x1b/0x20 [<ffffffff816be392>] system_call_fastpath+0x16/0x1b
pop3 D ffff88022fc12940 0 4191 4182 0x00000000
ffff880225e29648 0000000000000086 ffff880225e28010 ffff880226b09640 0000000000012940 ffff880225e29fd8 ffff880225e29fd8 0000000000012940 0000000000000000 ffff880226b09640 ffffffff819b3020 ffff880226b099c0
Call Trace: [<ffffffff810d57f0>] ? mempool_alloc+0x60/0x140 [<ffffffff81111fde>] ? kmem_cache_alloc+0xee/0x100 [<ffffffff816b482a>] schedule+0x3a/0x60 [<ffffffff816b4ced>] schedule_timeout+0x21d/0x280 [<ffffffff810d56e1>] ? mempool_alloc_slab+0x11/0x20 [<ffffffff816b5cc0>] __down+0x70/0xb0 [<ffffffff812603ad>] ? _xfs_buf_find+0x16d/0x270 [<ffffffff81080587>] down+0x47/0x50 [<ffffffff8125e816>] xfs_buf_lock+0x66/0xd0 [<ffffffff812603ad>] _xfs_buf_find+0x16d/0x270 [<ffffffff81274c37>] ? kmem_zone_alloc+0x77/0xe0 [<ffffffff81260517>] xfs_buf_get+0x67/0x1a0 [<ffffffff8126067a>] xfs_buf_read+0x2a/0x120 [<ffffffff812b876f>] xfs_trans_read_buf+0x28f/0x3f0 [<ffffffff8129e161>] xfs_read_agi+0x71/0x100 [<ffffffff8129e219>] xfs_ialloc_read_agi+0x29/0xa0 [<ffffffff8129e59b>] xfs_ialloc_ag_select+0x1db/0x2a0 [<ffffffff8129fc95>] xfs_dialloc+0x415/0x8c0 [<ffffffff81265482>] ? xfs_iunlock+0xc2/0x130 [<ffffffff8125c201>] ? __xfs_get_blocks+0x411/0x4a0 [<ffffffff813758a6>] ? __prop_inc_single+0x46/0x60 [<ffffffff8112da50>] ? dput+0x40/0x320 [<ffffffff812a336c>] xfs_ialloc+0x5c/0x710 [<ffffffff812b381f>] ? xlog_grant_log_space+0x24f/0x530 [<ffffffff81274cd5>] ? kmem_zone_zalloc+0x35/0x50 [<ffffffff812712d5>] xfs_dir_ialloc+0x75/0x290 [<ffffffff812afa39>] ? xfs_trans_reserve+0x99/0x210 [<ffffffff8127390a>] xfs_create+0x46a/0x600 [<ffffffff811228ba>] ? inode_permission+0x7a/0xd0 [<ffffffff81121bd7>] ? do_lookup+0xf7/0x3a0 [<ffffffff81269a7a>] xfs_vn_mknod+0x7a/0x130 [<ffffffff81269b4b>] xfs_vn_create+0xb/0x10 [<ffffffff81124c99>] vfs_create+0x99/0xd0 [<ffffffff8112635b>] do_last+0x69b/0x810 [<ffffffff8112659f>] path_openat+0xcf/0x3f0 [<ffffffff8112401d>] ? user_path_at+0x8d/0xb0 [<ffffffff811269d3>] do_filp_open+0x43/0xa0 [<ffffffff81131d2a>] ? alloc_fd+0x4a/0x140 [<ffffffff81115202>] do_sys_open+0x152/0x1f0 [<ffffffff811152cb>] sys_open+0x1b/0x20 [<ffffffff816be392>] system_call_fastpath+0x16/0x1b
pop3 D ffff88022fc12940 0 4192 4182 0x00000000
ffff880224071648 0000000000000086 ffff880224070010 ffff880226b0c2c0 0000000000012940 ffff880224071fd8 ffff880224071fd8 0000000000012940 0000000000000000 ffff880226b0c2c0 ffffffff819b3020 ffff880226b0c640
Call Trace: [<ffffffff812a1181>] ? xfs_iext_bno_to_ext+0x91/0x180 [<ffffffff816b482a>] schedule+0x3a/0x60 [<ffffffff816b4ced>] schedule_timeout+0x21d/0x280 [<ffffffff810d57f0>] ? mempool_alloc+0x60/0x140 [<ffffffff816b5cc0>] __down+0x70/0xb0 [<ffffffff812603ad>] ? _xfs_buf_find+0x16d/0x270 [<ffffffff81080587>] down+0x47/0x50 [<ffffffff8125e816>] xfs_buf_lock+0x66/0xd0 [<ffffffff812603ad>] _xfs_buf_find+0x16d/0x270 [<ffffffff81274c37>] ? kmem_zone_alloc+0x77/0xe0 [<ffffffff81260517>] xfs_buf_get+0x67/0x1a0 [<ffffffff8126067a>] xfs_buf_read+0x2a/0x120 [<ffffffff812b876f>] xfs_trans_read_buf+0x28f/0x3f0 [<ffffffff8129e161>] xfs_read_agi+0x71/0x100 [<ffffffff8129e219>] xfs_ialloc_read_agi+0x29/0xa0 [<ffffffff8129e59b>] xfs_ialloc_ag_select+0x1db/0x2a0 [<ffffffff8129fc95>] xfs_dialloc+0x415/0x8c0 [<ffffffff816b4f6b>] ? __wait_on_bit+0x7b/0x90 [<ffffffff813758a6>] ? __prop_inc_single+0x46/0x60 [<ffffffff8112da50>] ? dput+0x40/0x320 [<ffffffff812a336c>] xfs_ialloc+0x5c/0x710 [<ffffffff812b381f>] ? xlog_grant_log_space+0x24f/0x530 [<ffffffff81274cd5>] ? kmem_zone_zalloc+0x35/0x50 [<ffffffff812712d5>] xfs_dir_ialloc+0x75/0x290 [<ffffffff812afa39>] ? xfs_trans_reserve+0x99/0x210 [<ffffffff8127390a>] xfs_create+0x46a/0x600 [<ffffffff811228ba>] ? inode_permission+0x7a/0xd0 [<ffffffff81121bd7>] ? do_lookup+0xf7/0x3a0 [<ffffffff81269a7a>] xfs_vn_mknod+0x7a/0x130 [<ffffffff81269b4b>] xfs_vn_create+0xb/0x10 [<ffffffff81124c99>] vfs_create+0x99/0xd0 [<ffffffff8112635b>] do_last+0x69b/0x810 [<ffffffff8112659f>] path_openat+0xcf/0x3f0 [<ffffffff8112401d>] ? user_path_at+0x8d/0xb0 [<ffffffff811269d3>] do_filp_open+0x43/0xa0 [<ffffffff81131d2a>] ? alloc_fd+0x4a/0x140 [<ffffffff81115202>] do_sys_open+0x152/0x1f0 [<ffffffff811152cb>] sys_open+0x1b/0x20 [<ffffffff816be392>] system_call_fastpath+0x16/0x1b
pop3 D ffff88022fc12940 0 4193 4182 0x00000000
ffff8802255db648 0000000000000082 ffff8802255da010 ffff8802261c42c0 0000000000012940 ffff8802255dbfd8 ffff8802255dbfd8 0000000000012940 0000000000000000 ffff8802261c42c0 ffffffff819b3020 ffff8802261c4640
Call Trace: [<ffffffff810d56e1>] ? mempool_alloc_slab+0x11/0x20 [<ffffffff810d57f0>] ? mempool_alloc+0x60/0x140 [<ffffffff816b482a>] schedule+0x3a/0x60 [<ffffffff816b4ced>] schedule_timeout+0x21d/0x280 [<ffffffff816b5cc0>] __down+0x70/0xb0 [<ffffffff812603ad>] ? _xfs_buf_find+0x16d/0x270 [<ffffffff81080587>] down+0x47/0x50 [<ffffffff8125e816>] xfs_buf_lock+0x66/0xd0 [<ffffffff812603ad>] _xfs_buf_find+0x16d/0x270 [<ffffffff81274c37>] ? kmem_zone_alloc+0x77/0xe0 [<ffffffff81260517>] xfs_buf_get+0x67/0x1a0 [<ffffffff8126067a>] xfs_buf_read+0x2a/0x120 [<ffffffff812b876f>] xfs_trans_read_buf+0x28f/0x3f0 [<ffffffff8129e161>] xfs_read_agi+0x71/0x100 [<ffffffff8129e219>] xfs_ialloc_read_agi+0x29/0xa0 [<ffffffff8129e59b>] xfs_ialloc_ag_select+0x1db/0x2a0 [<ffffffff8129fc95>] xfs_dialloc+0x415/0x8c0 [<ffffffff81265482>] ? xfs_iunlock+0xc2/0x130 [<ffffffff8125c201>] ? __xfs_get_blocks+0x411/0x4a0 [<ffffffff813758a6>] ? __prop_inc_single+0x46/0x60 [<ffffffff8112da50>] ? dput+0x40/0x320 [<ffffffff812a336c>] xfs_ialloc+0x5c/0x710 [<ffffffff812b381f>] ? xlog_grant_log_space+0x24f/0x530 [<ffffffff81274cd5>] ? kmem_zone_zalloc+0x35/0x50 [<ffffffff812712d5>] xfs_dir_ialloc+0x75/0x290 [<ffffffff812afa39>] ? xfs_trans_reserve+0x99/0x210 [<ffffffff8127390a>] xfs_create+0x46a/0x600 [<ffffffff811228ba>] ? inode_permission+0x7a/0xd0 [<ffffffff81121bd7>] ? do_lookup+0xf7/0x3a0 [<ffffffff81269a7a>] xfs_vn_mknod+0x7a/0x130 [<ffffffff81269b4b>] xfs_vn_create+0xb/0x10 [<ffffffff81124c99>] vfs_create+0x99/0xd0 [<ffffffff8112635b>] do_last+0x69b/0x810 [<ffffffff8112659f>] path_openat+0xcf/0x3f0 [<ffffffff8112401d>] ? user_path_at+0x8d/0xb0 [<ffffffff811269d3>] do_filp_open+0x43/0xa0 [<ffffffff81131d2a>] ? alloc_fd+0x4a/0x140 [<ffffffff81115202>] do_sys_open+0x152/0x1f0 [<ffffffff811152cb>] sys_open+0x1b/0x20 [<ffffffff816be392>] system_call_fastpath+0x16/0x1b
pop3 D ffff88022fcd2940 0 4194 4182 0x00000000
ffff880224121648 0000000000000086 ffff880224120010 ffff880226249640 0000000000012940 ffff880224121fd8 ffff880224121fd8 0000000000012940 0000000000000003 ffff880226249640 ffff880226949640 ffff8802262499c0
Call Trace: [<ffffffff810d57f0>] ? mempool_alloc+0x60/0x140 [<ffffffff81111fde>] ? kmem_cache_alloc+0xee/0x100 [<ffffffff816b482a>] schedule+0x3a/0x60 [<ffffffff816b4ced>] schedule_timeout+0x21d/0x280 [<ffffffff810d56e1>] ? mempool_alloc_slab+0x11/0x20 [<ffffffff816b5cc0>] __down+0x70/0xb0 [<ffffffff812603ad>] ? _xfs_buf_find+0x16d/0x270 [<ffffffff81080587>] down+0x47/0x50 [<ffffffff8125e816>] xfs_buf_lock+0x66/0xd0 [<ffffffff812603ad>] _xfs_buf_find+0x16d/0x270 [<ffffffff81274c37>] ? kmem_zone_alloc+0x77/0xe0 [<ffffffff81260517>] xfs_buf_get+0x67/0x1a0 [<ffffffff8126067a>] xfs_buf_read+0x2a/0x120 [<ffffffff812b876f>] xfs_trans_read_buf+0x28f/0x3f0 [<ffffffff8129e161>] xfs_read_agi+0x71/0x100 [<ffffffff8129e219>] xfs_ialloc_read_agi+0x29/0xa0 [<ffffffff8129e59b>] xfs_ialloc_ag_select+0x1db/0x2a0 [<ffffffff8129fc95>] xfs_dialloc+0x415/0x8c0 [<ffffffff81375790>] ? prop_norm_single+0x80/0xd0 [<ffffffff813758a6>] ? __prop_inc_single+0x46/0x60 [<ffffffff8112da50>] ? dput+0x40/0x320 [<ffffffff812a336c>] xfs_ialloc+0x5c/0x710 [<ffffffff812b381f>] ? xlog_grant_log_space+0x24f/0x530 [<ffffffff81274cd5>] ? kmem_zone_zalloc+0x35/0x50 [<ffffffff812712d5>] xfs_dir_ialloc+0x75/0x290 [<ffffffff812afa39>] ? xfs_trans_reserve+0x99/0x210 [<ffffffff8127390a>] xfs_create+0x46a/0x600 [<ffffffff811228ba>] ? inode_permission+0x7a/0xd0 [<ffffffff81121bd7>] ? do_lookup+0xf7/0x3a0 [<ffffffff81269a7a>] xfs_vn_mknod+0x7a/0x130 [<ffffffff81269b4b>] xfs_vn_create+0xb/0x10 [<ffffffff81124c99>] vfs_create+0x99/0xd0 [<ffffffff8112635b>] do_last+0x69b/0x810 [<ffffffff8112659f>] path_openat+0xcf/0x3f0 [<ffffffff8112401d>] ? user_path_at+0x8d/0xb0 [<ffffffff811269d3>] do_filp_open+0x43/0xa0 [<ffffffff81131d2a>] ? alloc_fd+0x4a/0x140 [<ffffffff81115202>] do_sys_open+0x152/0x1f0 [<ffffffff811152cb>] sys_open+0x1b/0x20 [<ffffffff816be392>] system_call_fastpath+0x16/0x1b
pop3 D ffff88022fc12940 0 4195 4182 0x00000000
ffff880224141648 0000000000000082 ffff880224140010 ffff8802260d0000 0000000000012940 ffff880224141fd8 ffff880224141fd8 0000000000012940 0000000000000000 ffff8802260d0000 ffffffff819b3020 ffff8802260d0380
Call Trace: [<ffffffff812a1181>] ? xfs_iext_bno_to_ext+0x91/0x180 [<ffffffff816b482a>] schedule+0x3a/0x60 [<ffffffff816b4ced>] schedule_timeout+0x21d/0x280 [<ffffffff810d57f0>] ? mempool_alloc+0x60/0x140 [<ffffffff816b5cc0>] __down+0x70/0xb0 [<ffffffff812603ad>] ? _xfs_buf_find+0x16d/0x270 [<ffffffff81080587>] down+0x47/0x50 [<ffffffff8125e816>] xfs_buf_lock+0x66/0xd0 [<ffffffff812603ad>] _xfs_buf_find+0x16d/0x270 [<ffffffff81274c37>] ? kmem_zone_alloc+0x77/0xe0 [<ffffffff81260517>] xfs_buf_get+0x67/0x1a0 [<ffffffff8126067a>] xfs_buf_read+0x2a/0x120 [<ffffffff812b876f>] xfs_trans_read_buf+0x28f/0x3f0 [<ffffffff8129e161>] xfs_read_agi+0x71/0x100 [<ffffffff8129e219>] xfs_ialloc_read_agi+0x29/0xa0 [<ffffffff8129e59b>] xfs_ialloc_ag_select+0x1db/0x2a0 [<ffffffff8129fc95>] xfs_dialloc+0x415/0x8c0 [<ffffffff81265482>] ? xfs_iunlock+0xc2/0x130 [<ffffffff8125c201>] ? __xfs_get_blocks+0x411/0x4a0 [<ffffffff813758a6>] ? __prop_inc_single+0x46/0x60 [<ffffffff8112da50>] ? dput+0x40/0x320 [<ffffffff812a336c>] xfs_ialloc+0x5c/0x710 [<ffffffff812b381f>] ? xlog_grant_log_space+0x24f/0x530 [<ffffffff81274cd5>] ? kmem_zone_zalloc+0x35/0x50 [<ffffffff812712d5>] xfs_dir_ialloc+0x75/0x290 [<ffffffff812afa39>] ? xfs_trans_reserve+0x99/0x210 [<ffffffff8127390a>] xfs_create+0x46a/0x600 [<ffffffff811228ba>] ? inode_permission+0x7a/0xd0 [<ffffffff81121bd7>] ? do_lookup+0xf7/0x3a0 [<ffffffff81269a7a>] xfs_vn_mknod+0x7a/0x130 [<ffffffff81269b4b>] xfs_vn_create+0xb/0x10 [<ffffffff81124c99>] vfs_create+0x99/0xd0 [<ffffffff8112635b>] do_last+0x69b/0x810 [<ffffffff8112659f>] path_openat+0xcf/0x3f0 [<ffffffff8112401d>] ? user_path_at+0x8d/0xb0 [<ffffffff811269d3>] do_filp_open+0x43/0xa0 [<ffffffff81131d2a>] ? alloc_fd+0x4a/0x140 [<ffffffff81115202>] do_sys_open+0x152/0x1f0 [<ffffffff811152cb>] sys_open+0x1b/0x20 [<ffffffff816be392>] system_call_fastpath+0x16/0x1b
pop3 D ffff88022fc12940 0 4196 4182 0x00000000
ffff880224143648 0000000000000086 ffff880224142010 ffff8802260d5900 0000000000012940 ffff880224143fd8 ffff880224143fd8 0000000000012940 0000000000000000 ffff8802260d5900 ffffffff819b3020 ffff8802260d5c80
Call Trace: [<ffffffff810d57f0>] ? mempool_alloc+0x60/0x140 [<ffffffff81111fde>] ? kmem_cache_alloc+0xee/0x100 [<ffffffff816b482a>] schedule+0x3a/0x60 [<ffffffff816b4ced>] schedule_timeout+0x21d/0x280 [<ffffffff810d56e1>] ? mempool_alloc_slab+0x11/0x20 [<ffffffff816b5cc0>] __down+0x70/0xb0 [<ffffffff812603ad>] ? _xfs_buf_find+0x16d/0x270 [<ffffffff81080587>] down+0x47/0x50 [<ffffffff8125e816>] xfs_buf_lock+0x66/0xd0 [<ffffffff812603ad>] _xfs_buf_find+0x16d/0x270 [<ffffffff81274c37>] ? kmem_zone_alloc+0x77/0xe0 [<ffffffff81260517>] xfs_buf_get+0x67/0x1a0 [<ffffffff8126067a>] xfs_buf_read+0x2a/0x120 [<ffffffff812b876f>] xfs_trans_read_buf+0x28f/0x3f0 [<ffffffff8129e161>] xfs_read_agi+0x71/0x100 [<ffffffff8129e219>] xfs_ialloc_read_agi+0x29/0xa0 [<ffffffff8129e59b>] xfs_ialloc_ag_select+0x1db/0x2a0 [<ffffffff8129fc95>] xfs_dialloc+0x415/0x8c0 [<ffffffff8168a5b6>] ? vlan_dev_hard_start_xmit+0x76/0xe0 [<ffffffff815e10f8>] ? dev_hard_start_xmit+0x418/0x6c0 [<ffffffff813758a6>] ? __prop_inc_single+0x46/0x60 [<ffffffff8112da50>] ? dput+0x40/0x320 [<ffffffff812a336c>] xfs_ialloc+0x5c/0x710 [<ffffffff812b381f>] ? xlog_grant_log_space+0x24f/0x530 [<ffffffff81274cd5>] ? kmem_zone_zalloc+0x35/0x50 [<ffffffff812712d5>] xfs_dir_ialloc+0x75/0x290 [<ffffffff812afa39>] ? xfs_trans_reserve+0x99/0x210 [<ffffffff8127390a>] xfs_create+0x46a/0x600 [<ffffffff811228ba>] ? inode_permission+0x7a/0xd0 [<ffffffff81121bd7>] ? do_lookup+0xf7/0x3a0 [<ffffffff81269a7a>] xfs_vn_mknod+0x7a/0x130 [<ffffffff81269b4b>] xfs_vn_create+0xb/0x10 [<ffffffff81124c99>] vfs_create+0x99/0xd0 [<ffffffff8112635b>] do_last+0x69b/0x810 [<ffffffff8112659f>] path_openat+0xcf/0x3f0 [<ffffffff8112401d>] ? user_path_at+0x8d/0xb0 [<ffffffff811269d3>] do_filp_open+0x43/0xa0 [<ffffffff81131d2a>] ? alloc_fd+0x4a/0x140 [<ffffffff81115202>] do_sys_open+0x152/0x1f0 [<ffffffff811152cb>] sys_open+0x1b/0x20 [<ffffffff816be392>] system_call_fastpath+0x16/0x1b
lmtp D ffff88022fc92940 0 4205 4182 0x00000000
ffff88022433f648 0000000000000086 ffff88022433e010 ffff880225481640 0000000000012940 ffff88022433ffd8 ffff88022433ffd8 0000000000012940 0000000000000002 ffff880225481640 ffff880226929640 ffff8802254819c0
Call Trace: [<ffffffff8128ad9d>] ? xfs_bmbt_get_startoff+0xd/0x20 [<ffffffff812a1181>] ? xfs_iext_bno_to_ext+0x91/0x180 [<ffffffff81111fde>] ? kmem_cache_alloc+0xee/0x100 [<ffffffff816b482a>] schedule+0x3a/0x60 [<ffffffff816b4ced>] schedule_timeout+0x21d/0x280 [<ffffffff816b5cc0>] __down+0x70/0xb0 [<ffffffff812603ad>] ? _xfs_buf_find+0x16d/0x270 [<ffffffff81080587>] down+0x47/0x50 [<ffffffff8125e816>] xfs_buf_lock+0x66/0xd0 [<ffffffff812603ad>] _xfs_buf_find+0x16d/0x270 [<ffffffff81274c37>] ? kmem_zone_alloc+0x77/0xe0 [<ffffffff81260517>] xfs_buf_get+0x67/0x1a0 [<ffffffff8126067a>] xfs_buf_read+0x2a/0x120 [<ffffffff812b876f>] xfs_trans_read_buf+0x28f/0x3f0 [<ffffffff8129e161>] xfs_read_agi+0x71/0x100 [<ffffffff8129e219>] xfs_ialloc_read_agi+0x29/0xa0 [<ffffffff8129e59b>] xfs_ialloc_ag_select+0x1db/0x2a0 [<ffffffff8129fc95>] xfs_dialloc+0x415/0x8c0 [<ffffffff81265482>] ? xfs_iunlock+0xc2/0x130 [<ffffffff8125c201>] ? __xfs_get_blocks+0x411/0x4a0 [<ffffffff81011815>] ? __switch_to+0x1a5/0x340 [<ffffffff813758a6>] ? __prop_inc_single+0x46/0x60 [<ffffffff8112da50>] ? dput+0x40/0x320 [<ffffffff812a336c>] xfs_ialloc+0x5c/0x710 [<ffffffff812b381f>] ? xlog_grant_log_space+0x24f/0x530 [<ffffffff81274cd5>] ? kmem_zone_zalloc+0x35/0x50 [<ffffffff812712d5>] xfs_dir_ialloc+0x75/0x290 [<ffffffff812afa39>] ? xfs_trans_reserve+0x99/0x210 [<ffffffff8127390a>] xfs_create+0x46a/0x600 [<ffffffff811228ba>] ? inode_permission+0x7a/0xd0 [<ffffffff81121bd7>] ? do_lookup+0xf7/0x3a0 [<ffffffff81269a7a>] xfs_vn_mknod+0x7a/0x130 [<ffffffff81269b4b>] xfs_vn_create+0xb/0x10 [<ffffffff81124c99>] vfs_create+0x99/0xd0 [<ffffffff8112635b>] do_last+0x69b/0x810 [<ffffffff8112659f>] path_openat+0xcf/0x3f0 [<ffffffff8112401d>] ? user_path_at+0x8d/0xb0 [<ffffffff811269d3>] do_filp_open+0x43/0xa0 [<ffffffff81131d2a>] ? alloc_fd+0x4a/0x140 [<ffffffff81115202>] do_sys_open+0x152/0x1f0 [<ffffffff811152cb>] sys_open+0x1b/0x20 [<ffffffff816be392>] system_call_fastpath+0x16/0x1b
lmtp D ffff88022fc12940 0 4206 4182 0x00000000
ffff88022435f648 0000000000000086 ffff88022435e010 ffff880225482c80 0000000000012940 ffff88022435ffd8 ffff88022435ffd8 0000000000012940 0000000000000000 ffff880225482c80 ffffffff819b3020 ffff880225483000
Call Trace: [<ffffffff8128ad56>] ? xfs_bmbt_get_all+0x16/0x20 [<ffffffff812a1181>] ? xfs_iext_bno_to_ext+0x91/0x180 [<ffffffff816b482a>] schedule+0x3a/0x60 [<ffffffff816b4ced>] schedule_timeout+0x21d/0x280 [<ffffffff816b5cc0>] __down+0x70/0xb0 [<ffffffff812603ad>] ? _xfs_buf_find+0x16d/0x270 [<ffffffff81080587>] down+0x47/0x50 [<ffffffff8125e816>] xfs_buf_lock+0x66/0xd0 [<ffffffff812603ad>] _xfs_buf_find+0x16d/0x270 [<ffffffff81274c37>] ? kmem_zone_alloc+0x77/0xe0 [<ffffffff81260517>] xfs_buf_get+0x67/0x1a0 [<ffffffff8126067a>] xfs_buf_read+0x2a/0x120 [<ffffffff812b876f>] xfs_trans_read_buf+0x28f/0x3f0 [<ffffffff8129e161>] xfs_read_agi+0x71/0x100 [<ffffffff8129e219>] xfs_ialloc_read_agi+0x29/0xa0 [<ffffffff8129e59b>] xfs_ialloc_ag_select+0x1db/0x2a0 [<ffffffff8129fc95>] xfs_dialloc+0x415/0x8c0 [<ffffffff81265482>] ? xfs_iunlock+0xc2/0x130 [<ffffffff8125c201>] ? __xfs_get_blocks+0x411/0x4a0 [<ffffffff813758a6>] ? __prop_inc_single+0x46/0x60 [<ffffffff8112da50>] ? dput+0x40/0x320 [<ffffffff812a336c>] xfs_ialloc+0x5c/0x710 [<ffffffff812b381f>] ? xlog_grant_log_space+0x24f/0x530 [<ffffffff81274cd5>] ? kmem_zone_zalloc+0x35/0x50 [<ffffffff812712d5>] xfs_dir_ialloc+0x75/0x290 [<ffffffff812afa39>] ? xfs_trans_reserve+0x99/0x210 [<ffffffff8127390a>] xfs_create+0x46a/0x600 [<ffffffff811228ba>] ? inode_permission+0x7a/0xd0 [<ffffffff81121bd7>] ? do_lookup+0xf7/0x3a0 [<ffffffff81269a7a>] xfs_vn_mknod+0x7a/0x130 [<ffffffff81269b4b>] xfs_vn_create+0xb/0x10 [<ffffffff81124c99>] vfs_create+0x99/0xd0 [<ffffffff8112635b>] do_last+0x69b/0x810 [<ffffffff8112659f>] path_openat+0xcf/0x3f0 [<ffffffff8112401d>] ? user_path_at+0x8d/0xb0 [<ffffffff811269d3>] do_filp_open+0x43/0xa0 [<ffffffff81131d2a>] ? alloc_fd+0x4a/0x140 [<ffffffff81115202>] do_sys_open+0x152/0x1f0 [<ffffffff811152cb>] sys_open+0x1b/0x20 [<ffffffff816be392>] system_call_fastpath+0x16/0x1b
lmtp D ffff88022fcd2940 0 4207 4182 0x00000000
ffff880224361648 0000000000000082 ffff880224360010 ffff8802261e9640 0000000000012940 ffff880224361fd8 ffff880224361fd8 0000000000012940 0000000000000003 ffff8802261e9640 ffff8802261c42c0 ffff8802261e99c0
Call Trace: [<ffffffff810d57f0>] ? mempool_alloc+0x60/0x140 [<ffffffff812a1181>] ? xfs_iext_bno_to_ext+0x91/0x180 [<ffffffff816b482a>] schedule+0x3a/0x60 [<ffffffff816b4ced>] schedule_timeout+0x21d/0x280 [<ffffffff816b5cc0>] __down+0x70/0xb0 [<ffffffff812603ad>] ? _xfs_buf_find+0x16d/0x270 [<ffffffff81080587>] down+0x47/0x50 [<ffffffff8125e816>] xfs_buf_lock+0x66/0xd0 [<ffffffff812603ad>] _xfs_buf_find+0x16d/0x270 [<ffffffff81274c37>] ? kmem_zone_alloc+0x77/0xe0 [<ffffffff81260517>] xfs_buf_get+0x67/0x1a0 [<ffffffff8126067a>] xfs_buf_read+0x2a/0x120 [<ffffffff812b876f>] xfs_trans_read_buf+0x28f/0x3f0 [<ffffffff8129e161>] xfs_read_agi+0x71/0x100 [<ffffffff8129e219>] xfs_ialloc_read_agi+0x29/0xa0 [<ffffffff8129e59b>] xfs_ialloc_ag_select+0x1db/0x2a0 [<ffffffff8129fc95>] xfs_dialloc+0x415/0x8c0 [<ffffffff81265482>] ? xfs_iunlock+0xc2/0x130 [<ffffffff8125c201>] ? __xfs_get_blocks+0x411/0x4a0 [<ffffffff81011815>] ? __switch_to+0x1a5/0x340 [<ffffffff8112da50>] ? dput+0x40/0x320 [<ffffffff812a336c>] xfs_ialloc+0x5c/0x710 [<ffffffff812b381f>] ? xlog_grant_log_space+0x24f/0x530 [<ffffffff81274cd5>] ? kmem_zone_zalloc+0x35/0x50 [<ffffffff812712d5>] xfs_dir_ialloc+0x75/0x290 [<ffffffff812afa39>] ? xfs_trans_reserve+0x99/0x210 [<ffffffff8127390a>] xfs_create+0x46a/0x600 [<ffffffff811228ba>] ? inode_permission+0x7a/0xd0 [<ffffffff81121bd7>] ? do_lookup+0xf7/0x3a0 [<ffffffff81269a7a>] xfs_vn_mknod+0x7a/0x130 [<ffffffff81269b4b>] xfs_vn_create+0xb/0x10 [<ffffffff81124c99>] vfs_create+0x99/0xd0 [<ffffffff8112635b>] do_last+0x69b/0x810 [<ffffffff8112659f>] path_openat+0xcf/0x3f0 [<ffffffff8112401d>] ? user_path_at+0x8d/0xb0 [<ffffffff811269d3>] do_filp_open+0x43/0xa0 [<ffffffff81131d2a>] ? alloc_fd+0x4a/0x140 [<ffffffff81115202>] do_sys_open+0x152/0x1f0 [<ffffffff811152cb>] sys_open+0x1b/0x20 [<ffffffff816be392>] system_call_fastpath+0x16/0x1b
lmtp D ffff88022fcd2940 0 4208 4182 0x00000000
ffff880224383648 0000000000000086 ffff880224382010 ffff880226a7c2c0 0000000000012940 ffff880224383fd8 ffff880224383fd8 0000000000012940 0000000000000003 ffff880226a7c2c0 ffff8802260d0000 ffff880226a7c640
Call Trace: [<ffffffff812a1181>] ? xfs_iext_bno_to_ext+0x91/0x180 [<ffffffff816b482a>] schedule+0x3a/0x60 [<ffffffff816b4ced>] schedule_timeout+0x21d/0x280 [<ffffffff810d56e1>] ? mempool_alloc_slab+0x11/0x20 [<ffffffff810d57f0>] ? mempool_alloc+0x60/0x140 [<ffffffff81111f65>] ? kmem_cache_alloc+0x75/0x100 [<ffffffff816b5cc0>] __down+0x70/0xb0 [<ffffffff812603ad>] ? _xfs_buf_find+0x16d/0x270 [<ffffffff81080587>] down+0x47/0x50 [<ffffffff8125e816>] xfs_buf_lock+0x66/0xd0 [<ffffffff812603ad>] _xfs_buf_find+0x16d/0x270 [<ffffffff81274c37>] ? kmem_zone_alloc+0x77/0xe0 [<ffffffff81260517>] xfs_buf_get+0x67/0x1a0 [<ffffffff8126067a>] xfs_buf_read+0x2a/0x120 [<ffffffff812b876f>] xfs_trans_read_buf+0x28f/0x3f0 [<ffffffff8129e161>] xfs_read_agi+0x71/0x100 [<ffffffff8129e219>] xfs_ialloc_read_agi+0x29/0xa0 [<ffffffff8129e59b>] xfs_ialloc_ag_select+0x1db/0x2a0 [<ffffffff8129fc95>] xfs_dialloc+0x415/0x8c0 [<ffffffff812654ca>] ? xfs_iunlock+0x10a/0x130 [<ffffffff8125c201>] ? __xfs_get_blocks+0x411/0x4a0 [<ffffffff8112da50>] ? dput+0x40/0x320 [<ffffffff812a336c>] xfs_ialloc+0x5c/0x710 [<ffffffff812b381f>] ? xlog_grant_log_space+0x24f/0x530 [<ffffffff81274cd5>] ? kmem_zone_zalloc+0x35/0x50 [<ffffffff812712d5>] xfs_dir_ialloc+0x75/0x290 [<ffffffff812afa39>] ? xfs_trans_reserve+0x99/0x210 [<ffffffff8127390a>] xfs_create+0x46a/0x600 [<ffffffff811228ba>] ? inode_permission+0x7a/0xd0 [<ffffffff81121bd7>] ? do_lookup+0xf7/0x3a0 [<ffffffff81269a7a>] xfs_vn_mknod+0x7a/0x130 [<ffffffff81269b4b>] xfs_vn_create+0xb/0x10 [<ffffffff81124c99>] vfs_create+0x99/0xd0 [<ffffffff8112635b>] do_last+0x69b/0x810 [<ffffffff8112659f>] path_openat+0xcf/0x3f0 [<ffffffff8112401d>] ? user_path_at+0x8d/0xb0 [<ffffffff811269d3>] do_filp_open+0x43/0xa0 [<ffffffff81131d2a>] ? alloc_fd+0x4a/0x140 [<ffffffff81115202>] do_sys_open+0x152/0x1f0 [<ffffffff811152cb>] sys_open+0x1b/0x20 [<ffffffff816be392>] system_call_fastpath+0x16/0x1b
lmtp D ffff88022fc52940 0 4209 4182 0x00000000
ffff8802243a3648 0000000000000086 ffff8802243a2010 ffff880224035900 0000000000012940 ffff8802243a3fd8 ffff8802243a3fd8 0000000000012940 0000000000000001 ffff880224035900 ffff880226911640 ffff880224035c80
Call Trace: [<ffffffff8128ad56>] ? xfs_bmbt_get_all+0x16/0x20 [<ffffffff812a1181>] ? xfs_iext_bno_to_ext+0x91/0x180 [<ffffffff816b482a>] schedule+0x3a/0x60 [<ffffffff816b4ced>] schedule_timeout+0x21d/0x280 [<ffffffff816b5cc0>] __down+0x70/0xb0 [<ffffffff812603ad>] ? _xfs_buf_find+0x16d/0x270 [<ffffffff81080587>] down+0x47/0x50 [<ffffffff8125e816>] xfs_buf_lock+0x66/0xd0 [<ffffffff812603ad>] _xfs_buf_find+0x16d/0x270 [<ffffffff81274c37>] ? kmem_zone_alloc+0x77/0xe0 [<ffffffff81260517>] xfs_buf_get+0x67/0x1a0 [<ffffffff8126067a>] xfs_buf_read+0x2a/0x120 [<ffffffff812b876f>] xfs_trans_read_buf+0x28f/0x3f0 [<ffffffff8129e161>] xfs_read_agi+0x71/0x100 [<ffffffff8129e219>] xfs_ialloc_read_agi+0x29/0xa0 [<ffffffff8129e59b>] xfs_ialloc_ag_select+0x1db/0x2a0 [<ffffffff8129fc95>] xfs_dialloc+0x415/0x8c0 [<ffffffff812654ca>] ? xfs_iunlock+0x10a/0x130 [<ffffffff8125c250>] ? __xfs_get_blocks+0x460/0x4a0 [<ffffffff813758a6>] ? __prop_inc_single+0x46/0x60 [<ffffffff8112da50>] ? dput+0x40/0x320 [<ffffffff812a336c>] xfs_ialloc+0x5c/0x710 [<ffffffff812b381f>] ? xlog_grant_log_space+0x24f/0x530 [<ffffffff81274cd5>] ? kmem_zone_zalloc+0x35/0x50 [<ffffffff812712d5>] xfs_dir_ialloc+0x75/0x290 [<ffffffff812afa39>] ? xfs_trans_reserve+0x99/0x210 [<ffffffff8127390a>] xfs_create+0x46a/0x600 [<ffffffff811228ba>] ? inode_permission+0x7a/0xd0 [<ffffffff81121bd7>] ? do_lookup+0xf7/0x3a0 [<ffffffff81269a7a>] xfs_vn_mknod+0x7a/0x130 [<ffffffff81269b4b>] xfs_vn_create+0xb/0x10 [<ffffffff81124c99>] vfs_create+0x99/0xd0 [<ffffffff8112635b>] do_last+0x69b/0x810 [<ffffffff8112659f>] path_openat+0xcf/0x3f0 [<ffffffff8112401d>] ? user_path_at+0x8d/0xb0 [<ffffffff811269d3>] do_filp_open+0x43/0xa0 [<ffffffff81131d2a>] ? alloc_fd+0x4a/0x140 [<ffffffff81115202>] do_sys_open+0x152/0x1f0 [<ffffffff811152cb>] sys_open+0x1b/0x20 [<ffffffff816be392>] system_call_fastpath+0x16/0x1b
lmtp D ffff88022fc52940 0 4210 4182 0x00000000
ffff8802243c5648 0000000000000082 ffff8802243c4010 ffff8802243c8000 0000000000012940 ffff8802243c5fd8 ffff8802243c5fd8 0000000000012940 0000000000000001 ffff8802243c8000 ffff880226911640 ffff8802243c8380
Call Trace: [<ffffffff8104beef>] ? set_next_entity+0xaf/0xd0 [<ffffffff812a1e7c>] ? xfs_iext_insert+0xbc/0xe0 [<ffffffff81285f3d>] ? xfs_bmap_add_extent+0xad/0x390 [<ffffffff816b482a>] schedule+0x3a/0x60 [<ffffffff816b4ced>] schedule_timeout+0x21d/0x280 [<ffffffff816b5cc0>] __down+0x70/0xb0 [<ffffffff812603ad>] ? _xfs_buf_find+0x16d/0x270 [<ffffffff81080587>] down+0x47/0x50 [<ffffffff8125e816>] xfs_buf_lock+0x66/0xd0 [<ffffffff812603ad>] _xfs_buf_find+0x16d/0x270 [<ffffffff81274c37>] ? kmem_zone_alloc+0x77/0xe0 [<ffffffff81260517>] xfs_buf_get+0x67/0x1a0 [<ffffffff8126067a>] xfs_buf_read+0x2a/0x120 [<ffffffff812b876f>] xfs_trans_read_buf+0x28f/0x3f0 [<ffffffff8129e161>] xfs_read_agi+0x71/0x100 [<ffffffff8129e219>] xfs_ialloc_read_agi+0x29/0xa0 [<ffffffff8129e59b>] xfs_ialloc_ag_select+0x1db/0x2a0 [<ffffffff8129fc95>] xfs_dialloc+0x415/0x8c0 [<ffffffff813758a6>] ? __prop_inc_single+0x46/0x60 [<ffffffff8112da50>] ? dput+0x40/0x320 [<ffffffff812a336c>] xfs_ialloc+0x5c/0x710 [<ffffffff812b381f>] ? xlog_grant_log_space+0x24f/0x530 [<ffffffff81274cd5>] ? kmem_zone_zalloc+0x35/0x50 [<ffffffff812712d5>] xfs_dir_ialloc+0x75/0x290 [<ffffffff812afa39>] ? xfs_trans_reserve+0x99/0x210 [<ffffffff8127390a>] xfs_create+0x46a/0x600 [<ffffffff811228ba>] ? inode_permission+0x7a/0xd0 [<ffffffff81121bd7>] ? do_lookup+0xf7/0x3a0 [<ffffffff81269a7a>] xfs_vn_mknod+0x7a/0x130 [<ffffffff81269b4b>] xfs_vn_create+0xb/0x10 [<ffffffff81124c99>] vfs_create+0x99/0xd0 [<ffffffff8112635b>] do_last+0x69b/0x810 [<ffffffff8112659f>] path_openat+0xcf/0x3f0 [<ffffffff8112401d>] ? user_path_at+0x8d/0xb0 [<ffffffff811269d3>] do_filp_open+0x43/0xa0 [<ffffffff81131d2a>] ? alloc_fd+0x4a/0x140 [<ffffffff81115202>] do_sys_open+0x152/0x1f0 [<ffffffff811152cb>] sys_open+0x1b/0x20 [<ffffffff816be392>] system_call_fastpath+0x16/0x1b
lmtp D ffff88022fc12940 0 4211 4182 0x00000000
ffff8802243c7648 0000000000000082 ffff8802243c6010 ffff8802243c9640 0000000000012940 ffff8802243c7fd8 ffff8802243c7fd8 0000000000012940 0000000000000000 ffff8802243c9640 ffffffff819b3020 ffff8802243c99c0
Call Trace: [<ffffffff810d56e1>] ? mempool_alloc_slab+0x11/0x20 [<ffffffff810d57f0>] ? mempool_alloc+0x60/0x140 [<ffffffff810d56e1>] ? mempool_alloc_slab+0x11/0x20 [<ffffffff810d57f0>] ? mempool_alloc+0x60/0x140 [<ffffffff816b482a>] schedule+0x3a/0x60 [<ffffffff816b4ced>] schedule_timeout+0x21d/0x280 [<ffffffff810d56e1>] ? mempool_alloc_slab+0x11/0x20 [<ffffffff810d57f0>] ? mempool_alloc+0x60/0x140 [<ffffffff81111f65>] ? kmem_cache_alloc+0x75/0x100 [<ffffffff816b5cc0>] __down+0x70/0xb0 [<ffffffff812603ad>] ? _xfs_buf_find+0x16d/0x270 [<ffffffff81080587>] down+0x47/0x50 [<ffffffff8125e816>] xfs_buf_lock+0x66/0xd0 [<ffffffff812603ad>] _xfs_buf_find+0x16d/0x270 [<ffffffff81274c37>] ? kmem_zone_alloc+0x77/0xe0 [<ffffffff81260517>] xfs_buf_get+0x67/0x1a0 [<ffffffff8126067a>] xfs_buf_read+0x2a/0x120 [<ffffffff812b876f>] xfs_trans_read_buf+0x28f/0x3f0 [<ffffffff8129e161>] xfs_read_agi+0x71/0x100 [<ffffffff8129e219>] xfs_ialloc_read_agi+0x29/0xa0 [<ffffffff8129e59b>] xfs_ialloc_ag_select+0x1db/0x2a0 [<ffffffff8129fc95>] xfs_dialloc+0x415/0x8c0 [<ffffffff81265482>] ? xfs_iunlock+0xc2/0x130 [<ffffffff8125c201>] ? __xfs_get_blocks+0x411/0x4a0 [<ffffffff813758a6>] ? __prop_inc_single+0x46/0x60 [<ffffffff8112da50>] ? dput+0x40/0x320 [<ffffffff812a336c>] xfs_ialloc+0x5c/0x710 [<ffffffff812b381f>] ? xlog_grant_log_space+0x24f/0x530 [<ffffffff81274cd5>] ? kmem_zone_zalloc+0x35/0x50 [<ffffffff812712d5>] xfs_dir_ialloc+0x75/0x290 [<ffffffff812afa39>] ? xfs_trans_reserve+0x99/0x210 [<ffffffff8127390a>] xfs_create+0x46a/0x600 [<ffffffff811228ba>] ? inode_permission+0x7a/0xd0 [<ffffffff81121bd7>] ? do_lookup+0xf7/0x3a0 [<ffffffff81269a7a>] xfs_vn_mknod+0x7a/0x130 [<ffffffff81269b4b>] xfs_vn_create+0xb/0x10 [<ffffffff81124c99>] vfs_create+0x99/0xd0 [<ffffffff8112635b>] do_last+0x69b/0x810 [<ffffffff8112659f>] path_openat+0xcf/0x3f0 [<ffffffff8112401d>] ? user_path_at+0x8d/0xb0 [<ffffffff811269d3>] do_filp_open+0x43/0xa0 [<ffffffff81131d2a>] ? alloc_fd+0x4a/0x140 [<ffffffff81115202>] do_sys_open+0x152/0x1f0 [<ffffffff811152cb>] sys_open+0x1b/0x20 [<ffffffff816be392>] system_call_fastpath+0x16/0x1b
lmtp D ffff88022fc12940 0 4212 4182 0x00000000
ffff8802243f3948 0000000000000082 ffff8802243f2010 ffff8802243cac80 0000000000012940 ffff8802243f3fd8 ffff8802243f3fd8 0000000000012940 0000000000000000 ffff8802243cac80 ffffffff819b3020 ffff8802243cb000
Call Trace: [<ffffffff810695f6>] ? lock_timer_base+0x36/0x70 [<ffffffff81069a78>] ? try_to_del_timer_sync+0xa8/0xd0 [<ffffffff816b482a>] schedule+0x3a/0x60 [<ffffffff816b4c62>] schedule_timeout+0x192/0x280 [<ffffffff81069c60>] ? del_timer+0xd0/0xd0 [<ffffffff816b4d69>] schedule_timeout_uninterruptible+0x19/0x20 [<ffffffff81265b56>] xfs_iget+0x176/0x670 [<ffffffff812a33aa>] xfs_ialloc+0x9a/0x710 [<ffffffff812b381f>] ? xlog_grant_log_space+0x24f/0x530 [<ffffffff812712d5>] xfs_dir_ialloc+0x75/0x290 [<ffffffff812afa39>] ? xfs_trans_reserve+0x99/0x210 [<ffffffff8127390a>] xfs_create+0x46a/0x600 [<ffffffff811228ba>] ? inode_permission+0x7a/0xd0 [<ffffffff81121bd7>] ? do_lookup+0xf7/0x3a0 [<ffffffff81269a7a>] xfs_vn_mknod+0x7a/0x130 [<ffffffff81269b4b>] xfs_vn_create+0xb/0x10 [<ffffffff81124c99>] vfs_create+0x99/0xd0 [<ffffffff8112635b>] do_last+0x69b/0x810 [<ffffffff8112659f>] path_openat+0xcf/0x3f0 [<ffffffff8112401d>] ? user_path_at+0x8d/0xb0 [<ffffffff811269d3>] do_filp_open+0x43/0xa0 [<ffffffff81131d2a>] ? alloc_fd+0x4a/0x140 [<ffffffff81115202>] do_sys_open+0x152/0x1f0 [<ffffffff811152cb>] sys_open+0x1b/0x20 [<ffffffff816be392>] system_call_fastpath+0x16/0x1b
imap D ffff88022fc52940 0 4215 4182 0x00000000
ffff88022043d648 0000000000000082 ffff88022043c010 ffff880225042c80 0000000000012940 ffff88022043dfd8 ffff88022043dfd8 0000000000012940 0000000000000001 ffff880225042c80 ffff880226911640 ffff880225043000
Call Trace: [<ffffffff812a1181>] ? xfs_iext_bno_to_ext+0x91/0x180 [<ffffffff816b482a>] schedule+0x3a/0x60 [<ffffffff816b4ced>] schedule_timeout+0x21d/0x280 [<ffffffff816b5cc0>] __down+0x70/0xb0 [<ffffffff812603ad>] ? _xfs_buf_find+0x16d/0x270 [<ffffffff81080587>] down+0x47/0x50 [<ffffffff8125e816>] xfs_buf_lock+0x66/0xd0 [<ffffffff812603ad>] _xfs_buf_find+0x16d/0x270 [<ffffffff81274c37>] ? kmem_zone_alloc+0x77/0xe0 [<ffffffff81260517>] xfs_buf_get+0x67/0x1a0 [<ffffffff8126067a>] xfs_buf_read+0x2a/0x120 [<ffffffff812b876f>] xfs_trans_read_buf+0x28f/0x3f0 [<ffffffff8129e161>] xfs_read_agi+0x71/0x100 [<ffffffff8129e219>] xfs_ialloc_read_agi+0x29/0xa0 [<ffffffff8129e59b>] xfs_ialloc_ag_select+0x1db/0x2a0 [<ffffffff8129fc95>] xfs_dialloc+0x415/0x8c0 [<ffffffff81047ff0>] ? update_curr+0x100/0x1a0 [<ffffffff8112da50>] ? dput+0x40/0x320 [<ffffffff812a336c>] xfs_ialloc+0x5c/0x710 [<ffffffff812b381f>] ? xlog_grant_log_space+0x24f/0x530 [<ffffffff81274cd5>] ? kmem_zone_zalloc+0x35/0x50 [<ffffffff812712d5>] xfs_dir_ialloc+0x75/0x290 [<ffffffff812afa39>] ? xfs_trans_reserve+0x99/0x210 [<ffffffff8127390a>] xfs_create+0x46a/0x600 [<ffffffff811228ba>] ? inode_permission+0x7a/0xd0 [<ffffffff81121bd7>] ? do_lookup+0xf7/0x3a0 [<ffffffff81269a7a>] xfs_vn_mknod+0x7a/0x130 [<ffffffff81269b4b>] xfs_vn_create+0xb/0x10 [<ffffffff81124c99>] vfs_create+0x99/0xd0 [<ffffffff8112635b>] do_last+0x69b/0x810 [<ffffffff8112659f>] path_openat+0xcf/0x3f0 [<ffffffff8112401d>] ? user_path_at+0x8d/0xb0 [<ffffffff811269d3>] do_filp_open+0x43/0xa0 [<ffffffff81131d2a>] ? alloc_fd+0x4a/0x140 [<ffffffff81115202>] do_sys_open+0x152/0x1f0 [<ffffffff811152cb>] sys_open+0x1b/0x20 [<ffffffff816be392>] system_call_fastpath+0x16/0x1b
imap D ffff88022fcd2940 0 4216 4182 0x00000000
ffff88022045f648 0000000000000082 ffff88022045e010 ffff880220460000 0000000000012940 ffff88022045ffd8 ffff88022045ffd8 0000000000012940 0000000000000003 ffff880220460000 ffff880226949640 ffff880220460380
Call Trace: [<ffffffff812a1181>] ? xfs_iext_bno_to_ext+0x91/0x180 [<ffffffff812a1e7c>] ? xfs_iext_insert+0xbc/0xe0 [<ffffffff81285f3d>] ? xfs_bmap_add_extent+0xad/0x390 [<ffffffff816b482a>] schedule+0x3a/0x60 [<ffffffff816b4ced>] schedule_timeout+0x21d/0x280 [<ffffffff816b5cc0>] __down+0x70/0xb0 [<ffffffff812603ad>] ? _xfs_buf_find+0x16d/0x270 [<ffffffff81080587>] down+0x47/0x50 [<ffffffff8125e816>] xfs_buf_lock+0x66/0xd0 [<ffffffff812603ad>] _xfs_buf_find+0x16d/0x270 [<ffffffff81274c37>] ? kmem_zone_alloc+0x77/0xe0 [<ffffffff81260517>] xfs_buf_get+0x67/0x1a0 [<ffffffff8126067a>] xfs_buf_read+0x2a/0x120 [<ffffffff812b876f>] xfs_trans_read_buf+0x28f/0x3f0 [<ffffffff8129e161>] xfs_read_agi+0x71/0x100 [<ffffffff8129e219>] xfs_ialloc_read_agi+0x29/0xa0 [<ffffffff8129e59b>] xfs_ialloc_ag_select+0x1db/0x2a0 [<ffffffff8129fc95>] xfs_dialloc+0x415/0x8c0 [<ffffffff81371163>] ? cpumask_next_and+0x23/0x40 [<ffffffff812acb44>] ? xfs_perag_get+0x34/0xb0 [<ffffffff81265eef>] ? xfs_iget+0x50f/0x670 [<ffffffff8112da50>] ? dput+0x40/0x320 [<ffffffff812a336c>] xfs_ialloc+0x5c/0x710 [<ffffffff812b381f>] ? xlog_grant_log_space+0x24f/0x530 [<ffffffff81274cd5>] ? kmem_zone_zalloc+0x35/0x50 [<ffffffff812712d5>] xfs_dir_ialloc+0x75/0x290 [<ffffffff812afa39>] ? xfs_trans_reserve+0x99/0x210 [<ffffffff8127390a>] xfs_create+0x46a/0x600 [<ffffffff811228ba>] ? inode_permission+0x7a/0xd0 [<ffffffff81121bd7>] ? do_lookup+0xf7/0x3a0 [<ffffffff81269a7a>] xfs_vn_mknod+0x7a/0x130 [<ffffffff81269b4b>] xfs_vn_create+0xb/0x10 [<ffffffff81124c99>] vfs_create+0x99/0xd0 [<ffffffff8112635b>] do_last+0x69b/0x810 [<ffffffff8112659f>] path_openat+0xcf/0x3f0 [<ffffffff8112401d>] ? user_path_at+0x8d/0xb0 [<ffffffff811269d3>] do_filp_open+0x43/0xa0 [<ffffffff81131d2a>] ? alloc_fd+0x4a/0x140 [<ffffffff81115202>] do_sys_open+0x152/0x1f0 [<ffffffff811152cb>] sys_open+0x1b/0x20 [<ffffffff816be392>] system_call_fastpath+0x16/0x1b
doveadm D ffff88022fc12940 0 12727 11474 0x00000000
ffff880002ce5648 0000000000000082 ffff880002ce4010 ffff880218b30000 0000000000012940 ffff880002ce5fd8 ffff880002ce5fd8 0000000000012940 0000000000000000 ffff880218b30000 ffffffff819b3020 ffff880218b30380
Call Trace: [<ffffffff812a1181>] ? xfs_iext_bno_to_ext+0x91/0x180 [<ffffffff8114959b>] ? bvec_alloc_bs+0x6b/0x110 [<ffffffff816b482a>] schedule+0x3a/0x60 [<ffffffff816b4ced>] schedule_timeout+0x21d/0x280 [<ffffffff816b5cc0>] __down+0x70/0xb0 [<ffffffff812603ad>] ? _xfs_buf_find+0x16d/0x270 [<ffffffff81080587>] down+0x47/0x50 [<ffffffff8125e816>] xfs_buf_lock+0x66/0xd0 [<ffffffff812603ad>] _xfs_buf_find+0x16d/0x270 [<ffffffff81274c37>] ? kmem_zone_alloc+0x77/0xe0 [<ffffffff81260517>] xfs_buf_get+0x67/0x1a0 [<ffffffff8126067a>] xfs_buf_read+0x2a/0x120 [<ffffffff812b876f>] xfs_trans_read_buf+0x28f/0x3f0 [<ffffffff8129e161>] xfs_read_agi+0x71/0x100 [<ffffffff81111fde>] ? kmem_cache_alloc+0xee/0x100 [<ffffffff8129e219>] xfs_ialloc_read_agi+0x29/0xa0 [<ffffffff8129e59b>] xfs_ialloc_ag_select+0x1db/0x2a0 [<ffffffff8129fc95>] xfs_dialloc+0x415/0x8c0 [<ffffffff810b8215>] ? tracing_record_cmdline+0x35/0x110 [<ffffffff816b4385>] ? __schedule+0x585/0x950 [<ffffffff8112da50>] ? dput+0x40/0x320 [<ffffffff812a336c>] xfs_ialloc+0x5c/0x710 [<ffffffff812b381f>] ? xlog_grant_log_space+0x24f/0x530 [<ffffffff81274cd5>] ? kmem_zone_zalloc+0x35/0x50 [<ffffffff812712d5>] xfs_dir_ialloc+0x75/0x290 [<ffffffff812afa39>] ? xfs_trans_reserve+0x99/0x210 [<ffffffff8127390a>] xfs_create+0x46a/0x600 [<ffffffff8112b66f>] ? d_instantiate+0x5f/0x70 [<ffffffff81269a7a>] xfs_vn_mknod+0x7a/0x130 [<ffffffff81269b4b>] xfs_vn_create+0xb/0x10 [<ffffffff81124c99>] vfs_create+0x99/0xd0 [<ffffffff8112635b>] do_last+0x69b/0x810 [<ffffffff8112659f>] path_openat+0xcf/0x3f0 [<ffffffff8112401d>] ? user_path_at+0x8d/0xb0 [<ffffffff811269d3>] do_filp_open+0x43/0xa0 [<ffffffff81131d2a>] ? alloc_fd+0x4a/0x140 [<ffffffff81115202>] do_sys_open+0x152/0x1f0 [<ffffffff811152cb>] sys_open+0x1b/0x20 [<ffffffff816be392>] system_call_fastpath+0x16/0x1b
Quoted 11 lines · Simon Kirby
[<ffffffff8126f205>] xfs_reclaim_inode+0x85/0x2b0 [<ffffffff8126f5b0>] xfs_reclaim_inodes_ag+0x180/0x2f0 [<ffffffff8126f74e>] xfs_reclaim_inodes_nr+0x2e/0x40 [<ffffffff8126ccf0>] xfs_fs_free_cached_objects+0x10/0x20 [<ffffffff81119a70>] prune_super+0x110/0x1b0 [<ffffffff810e4fa5>] shrink_slab+0x1e5/0x2a0 [<ffffffff810e5821>] kswapd+0x7c1/0xba0 [<ffffffff8107ada6>] kthread+0x96/0xb0 [<ffffffff816c0474>] kernel_thread_helper+0x4/0x10[<ffffffffffffffff>]
0xffffffffffffffff
We're stuck in synchronous inode reclaim.
Quoted 9 lines
All of the other processes that get stuck have this stack:
[<ffffffff81080587>] down+0x47/0x50 [<ffffffff8125e816>] xfs_buf_lock+0x66/0xd0 [<ffffffff812603ad>] _xfs_buf_find+0x16d/0x270 [<ffffffff81260517>] xfs_buf_get+0x67/0x1a0 [<ffffffff8126067a>] xfs_buf_read+0x2a/0x120 [<ffffffff812b876f>] xfs_trans_read_buf+0x28f/0x3f0 [<ffffffff8129e161>] xfs_read_agi+0x71/0x100
They are waiting for the AGI buffer to become unlocked. The only reason it is held locked for longer time is when it is under I/O.
Quoted 6 lines
By the way,
xfs_reclaim_inode+0x85(133) disassembles as:...So the next function is
wait_for_completion(), which is marked__schedand thus doesn't show up in the trace.
So we're waiting for the inode to be flushed, aka I/O again.
What is interesting here is that we're always blocking on the AGI buffer - which is used during unlinks of inodes, and thus gets hit fairly heavily for a workload that does a lot of unlinks.
Quoted 10 lines
When the clog happens, "iostat -x -k 1" shows no reads from the XFS devices, though writes keep happening. "vmstat 1" matches. I tried switching schedulers from CFQ to deadline -- no difference. Queue depth is empty on the devices and nothing is actually clogged up at the device -- it's not actually plugged at the controller or disk. I did a sysreq-w while this was happening. About 10 seconds later, everything unclogs and continues. Sysreq-W output below. I poked around at the various XFS tracepoints in
/sys/kernel/debug/tracing/events/xfs, but I'm not sure which tracepoints to use and many of them scroll too fast to see anything. Any suggestions?
Given that you are doing a lot of unlinks I wonder if it is related to the recent ail pushing issues in that area. While your symptoms looks completely different we could be blocking on the flush completion for an inode that gets stuck in the AIL.
Can you run with latest 3.0-stable plus the patches at:
http://oss.sgi.com/pipermail/xfs/2011-October/053464.html
If this doesn't help I'll probably need to come up with some tracing patches for you.
Quoted 29 lines · Christoph Hellwig
Quoted 11 lines · Simon Kirby
[<ffffffff8126f205>] xfs_reclaim_inode+0x85/0x2b0 [<ffffffff8126f5b0>] xfs_reclaim_inodes_ag+0x180/0x2f0 [<ffffffff8126f74e>] xfs_reclaim_inodes_nr+0x2e/0x40 [<ffffffff8126ccf0>] xfs_fs_free_cached_objects+0x10/0x20 [<ffffffff81119a70>] prune_super+0x110/0x1b0 [<ffffffff810e4fa5>] shrink_slab+0x1e5/0x2a0 [<ffffffff810e5821>] kswapd+0x7c1/0xba0 [<ffffffff8107ada6>] kthread+0x96/0xb0 [<ffffffff816c0474>] kernel_thread_helper+0x4/0x10[<ffffffffffffffff>]
0xffffffffffffffffWe're stuck in synchronous inode reclaim.
Quoted 9 lines
All of the other processes that get stuck have this stack:
[<ffffffff81080587>] down+0x47/0x50 [<ffffffff8125e816>] xfs_buf_lock+0x66/0xd0 [<ffffffff812603ad>] _xfs_buf_find+0x16d/0x270 [<ffffffff81260517>] xfs_buf_get+0x67/0x1a0 [<ffffffff8126067a>] xfs_buf_read+0x2a/0x120 [<ffffffff812b876f>] xfs_trans_read_buf+0x28f/0x3f0 [<ffffffff8129e161>] xfs_read_agi+0x71/0x100They are waiting for the AGI buffer to become unlocked. The only reason it is held locked for longer time is when it is under I/O.
Quoted 1 line
Quoted 7 lines
Quoted 5 lines
By the way,
xfs_reclaim_inode+0x85(133) disassembles as:...So the next function is
wait_for_completion(), which is marked__schedand thus doesn't show up in the trace.So we're waiting for the inode to be flushed, aka I/O again.
But I don't seem to see any queued I/O, hmm.
Quoted 3 lines
What is interesting here is that we're always blocking on the AGI buffer - which is used during unlinks of inodes, and thus gets hit fairly heavily for a workload that does a lot of unlinks.
I don't think we do too many unlinks, but there are quite a bit of renames over existing files (dovecot-2.0 w/mdbox).
Quoted 16 lines
Quoted 10 lines
When the clog happens, "iostat -x -k 1" shows no reads from the XFS devices, though writes keep happening. "vmstat 1" matches. I tried switching schedulers from CFQ to deadline -- no difference. Queue depth is empty on the devices and nothing is actually clogged up at the device -- it's not actually plugged at the controller or disk. I did a sysreq-w while this was happening. About 10 seconds later, everything unclogs and continues. Sysreq-W output below. I poked around at the various XFS tracepoints in
/sys/kernel/debug/tracing/events/xfs, but I'm not sure which tracepoints to use and many of them scroll too fast to see anything. Any suggestions?Given that you are doing a lot of unlinks I wonder if it is related to the recent ail pushing issues in that area. While your symptoms looks completely different we could be blocking on the flush completion for an inode that gets stuck in the AIL.
Quoted 6 lines
Can you run with latest 3.0-stable plus the patches at:
http://oss.sgi.com/pipermail/xfs/2011-October/053464.htmlIf this doesn't help I'll probably need to come up with some tracing patches for you.
It seemes 3.0.7+gregkh's stable-queue queue-3.0 patches seems to be running fine without blocking at all on this SSD box, so that should narrow it down significantly.
Hmm, looking at git diff --stat v3.0.7..v3.1-rc10 fs/xfs , maybe not.. :)
Maybe 3.1 fs/xfs would transplant into 3.0 or vice-versa?
Simon-
Quoted 3 lines · Simon Kirby
Quoted 1 line
So we're waiting for the inode to be flushed, aka I/O again.
But I don't seem to see any queued I/O, hmm.
Well, as far as XFS is concerned the inode is beeing flushed and the buffer is locked. It could be stuck in the XFS internal delwri list because a buffer for example is pinned.
If that is the case the big hammer patch I attached below - probably not the final issue, but it should fix the hang if that is the case.
Quoted 10 lines
Quoted 2 lines
If this doesn't help I'll probably need to come up with some tracing patches for you.
It seemes 3.0.7+gregkh's stable-queue queue-3.0 patches seems to be running fine without blocking at all on this SSD box, so that should narrow it down significantly.
Hmm, looking at git diff --stat v3.0.7..v3.1-rc10 fs/xfs , maybe not.. :)
Maybe 3.1 fs/xfs would transplant into 3.0 or vice-versa?
If the patch above doesn't work I'll prepare a backport for you.
fs/xfs/xfs_sync.c +14 -1
@@ -764,7 +764,8 @@ xfs_reclaim_inode( struct xfs_perag *pag, int sync_mode) { -int error; +struct xfs_mount *mp = ip->i_mount; +int error; restart: error =0 ;
@@ -772,6 +773,18 @@ restart:if (!xfs_iflock_nowait (ip)) {if (!(sync_mode &SYNC_WAIT )) goto out; + +/* +* If the inode is flush locked we probably had someone else +* push it to the buffer and the buffer is now sitting in +* the delwri list. +* +* Use the big hammer to force it. +*/ +xfs_log_force (mp,XFS_LOG_SYNC ); +set_bit (XBT_FORCE_FLUSH , &mp->m_ddev_targp->bt_flags); +wake_up_process (mp->m_ddev_targp->bt_task); +xfs_iflock (ip); }
Quoted 48 lines · Christoph Hellwig
Quoted 3 lines · Simon Kirby
Quoted 1 line
So we're waiting for the inode to be flushed, aka I/O again.
But I don't seem to see any queued I/O, hmm.
Well, as far as XFS is concerned the inode is beeing flushed and the buffer is locked. It could be stuck in the XFS internal delwri list because a buffer for example is pinned.
If that is the case the big hammer patch I attached below - probably not the final issue, but it should fix the hang if that is the case.
Quoted 10 lines
Quoted 2 lines
If this doesn't help I'll probably need to come up with some tracing patches for you.
It seemes 3.0.7+gregkh's stable-queue queue-3.0 patches seems to be running fine without blocking at all on this SSD box, so that should narrow it down significantly.
Hmm, looking at git diff --stat v3.0.7..v3.1-rc10 fs/xfs , maybe not.. :)
Maybe 3.1 fs/xfs would transplant into 3.0 or vice-versa?
If the patch above doesn't work I'll prepare a backport for you.
Index:
linux-2.6/fs/xfs/xfs_sync.c
===================================================================fs/xfs/xfs_sync.c +7
-1@@ -764,7 +764,8 @@ xfs_reclaim_inode( struct xfs_perag *pag, int sync_mode) { -int error; +struct xfs_mount *mp = ip->i_mount; +int error; restart: error =0 ;@@ -772,6 +773,18 @@ restart:if (!xfs_iflock_nowait (ip)) {if (!(sync_mode &SYNC_WAIT )) goto out; + +/* +* If the inode is flush locked we probably had someone else +* push it to the buffer and the buffer is now sitting in +* the delwri list.
fs/xfs/xfs_sync.c restart: · line 790
Quoted 10 lines
fs/xfs/xfs_sync.c +7
-0+* +* Use the big hammer to force it. +*/ +xfs_log_force (mp,XFS_LOG_SYNC ); +set_bit (XBT_FORCE_FLUSH , &mp->m_ddev_targp->bt_flags); +wake_up_process (mp->m_ddev_targp->bt_task); +xfs_iflock (ip); }
This patch seems to work, at least on an SSD box. No more hung task warnings, and everything appears normal.
Do we know what caused this regression and/or how to fix it without the big hammer, or do we need to break it down further?
Thanks!
Simon-
Quoted 5 lines · Simon Kirby
This patch seems to work, at least on an SSD box. No more hung task warnings, and everything appears normal.
Do we know what caused this regression and/or how to fix it without the big hammer, or do we need to break it down further?
I have an idea and will send you a refined patch soon. I'm at a conference until tomorrow, so you'll probably have to wait another day or two for it.
Sorry Simon,
I haven't really been able to get back to this as fast as I wanted to do. Can you do another run and check if the patch still helps your issue even if you remove the xfs_log_force line?
Quoted 5 lines · Christoph Hellwig
Sorry Simon,
I haven't really been able to get back to this as fast as I wanted to do. Can you do another run and check if the patch still helps your issue even if you remove the
xfs_log_forceline?
Hello!
Sorry for the delay in testing.
Yes, everything looks fine even with the xfs_log_force line from your patch commented out. So, the changes in xfs_reclaim_inode() are just the set_bit(XBT_FORCE_FLUSH) and wake_up_process(), relative to 3.1.
Simon-
Quoted 5 lines · Simon Kirby
Sorry for the delay in testing.
Yes, everything looks fine even with the
xfs_log_forceline from your patch commented out. So, the changes inxfs_reclaim_inode()are just theset_bit(XBT_FORCE_FLUSH)andwake_up_process(), relative to 3.1.
Dave pointed out that we can do better than the big hammer, and the patch below should fix your issue, too. Can you test it?
---
From: Christoph Hellwig <[email protected]>
Subject: xfs: force buffer writeback before blocking on the ilock in inode reclaim
If we are doing synchronous inode reclaim we block the VM from making progress in memory reclaim. So if we encouter a flush locked inode promote it in the delwri list and wake up xfsbufd to write it out now. Without this we can get hangs of up to 30 seconds during workloads hitting synchronous inode reclaim.
The scheme is copied from what we do for dquot reclaims.
fs/xfs/xfs_sync.c +11 -0
@@ -770,6 +770,17 @@ restart:if (!xfs_iflock_nowait (ip)) {if (!(sync_mode &SYNC_WAIT )) goto out; + +/* +* If we only have a single dirty inode in a cluster there is +* a fair chance that the AIL push may have pushed it into +* the buffer, but xfsbufd won't touch it until 30 seconds +* from now, and thus we will lock up here. +* +* Promote the inode buffer to the front of the delwri list +* and wake up xfsbufd now. +*/ +xfs_promote_inode (ip);xfs_iflock (ip); }
fs/xfs/xfs_inode.c +21 -0
@@ -2835,6 +2835,27 @@ corrupt_out:return XFS_ERROR (EFSCORRUPTED ); } +void +xfs_promote_inode ( +struct xfs_inode *ip) +{ +struct xfs_buf *bp; + +ASSERT (xfs_isilocked (ip,XFS_ILOCK_EXCL |XFS_ILOCK_SHARED )); + + bp =xfs_incore (ip->i_mount->m_ddev_targp, ip->i_imap.im_blkno, + ip->i_imap.im_len,XBF_TRYLOCK ); +if (!bp) +return ; + +if (XFS_BUF_ISDELAYWRITE (bp)) { +xfs_buf_delwri_promote (bp); +wake_up_process (ip->i_mount->m_ddev_targp->bt_task); + } + +xfs_buf_relse (bp); +} +/* * Return a pointer to the extent record at file index idx. */
fs/xfs/xfs_inode.h +1 -0
@@ -498,6 +498,7 @@ int xfs_iunlink(struct xfs_trans *, xfsvoid xfs_iext_realloc (xfs_inode_t *,int ,int );void xfs_iunpin_wait (xfs_inode_t *);int xfs_iflush (xfs_inode_t *,uint ); +void xfs_promote_inode (struct xfs_inode *);void xfs_lock_inodes (xfs_inode_t **,int ,uint );void xfs_lock_two_inodes (xfs_inode_t *,xfs_inode_t *,uint );
_______________________________________________
xfs mailing list
[email protected]
http://oss.sgi.com/mailman/listinfo/xfs
Quoted 9 lines · Christoph Hellwig
Quoted 5 lines · Simon Kirby
Sorry for the delay in testing.
Yes, everything looks fine even with the
xfs_log_forceline from your patch commented out. So, the changes inxfs_reclaim_inode()are just theset_bit(XBT_FORCE_FLUSH)andwake_up_process(), relative to 3.1.Dave pointed out that we can do better than the big hammer, and the patch below should fix your issue, too. Can you test it?
Yes, seems to be fine. No hung task warnings, tested for ~5 days.
Simon-
Quoted 81 lines
---
From: Christoph Hellwig <[email protected]>
Subject: xfs: force buffer writeback before blocking on the ilock in inode reclaimIf we are doing synchronous inode reclaim we block the VM from making progress in memory reclaim. So if we encouter a flush locked inode promote it in the delwri list and wake up xfsbufd to write it out now. Without this we can get hangs of up to 30 seconds during workloads hitting synchronous inode reclaim.
The scheme is copied from what we do for dquot reclaims.
Reported-by Simon Kirby <[email protected]>Signed-off-by Christoph Hellwig <[email protected]>Index:
xfs/fs/xfs/xfs_sync.c
===================================================================fs/xfs/xfs_sync.c +11
-0@@ -770,6 +770,17 @@ restart:if (!xfs_iflock_nowait (ip)) {if (!(sync_mode &SYNC_WAIT )) goto out; + +/* +* If we only have a single dirty inode in a cluster there is +* a fair chance that the AIL push may have pushed it into +* the buffer, but xfsbufd won't touch it until 30 seconds +* from now, and thus we will lock up here. +* +* Promote the inode buffer to the front of the delwri list +* and wake up xfsbufd now. +*/ +xfs_promote_inode (ip);xfs_iflock (ip); }Index:
xfs/fs/xfs/xfs_inode.c
===================================================================fs/xfs/xfs_inode.c +21
-0@@ -2835,6 +2835,27 @@ corrupt_out:return XFS_ERROR (EFSCORRUPTED ); } +void +xfs_promote_inode ( +struct xfs_inode *ip) +{ +struct xfs_buf *bp; + +ASSERT (xfs_isilocked (ip,XFS_ILOCK_EXCL |XFS_ILOCK_SHARED )); + + bp =xfs_incore (ip->i_mount->m_ddev_targp, ip->i_imap.im_blkno, + ip->i_imap.im_len,XBF_TRYLOCK ); +if (!bp) +return ; + +if (XFS_BUF_ISDELAYWRITE (bp)) { +xfs_buf_delwri_promote (bp); +wake_up_process (ip->i_mount->m_ddev_targp->bt_task); + } + +xfs_buf_relse (bp); +} +/* * Return a pointer to the extent record at file index idx. */ Index:
xfs/fs/xfs/xfs_inode.h
===================================================================fs/xfs/xfs_inode.h +1
-0@@ -498,6 +498,7 @@ int xfs_iunlink(struct xfs_trans *, xfsvoid xfs_iext_realloc (xfs_inode_t *,int ,int );void xfs_iunpin_wait (xfs_inode_t *);int xfs_iflush (xfs_inode_t *,uint ); +void xfs_promote_inode (struct xfs_inode *);void xfs_lock_inodes (xfs_inode_t **,int ,uint );void xfs_lock_two_inodes (xfs_inode_t *,xfs_inode_t *,uint );
Christoph Hellwig
Tested-by Simon KirbyQuoted 5 lines · Simon Kirby
Quoted 3 lines · Christoph Hellwig
Quoted 2 lines · Simon Kirby
Sorry for the delay in testing.
Quoted 8 lines
Quoted 6 lines
Quoted 3 lines
Yes, everything looks fine even with the
xfs_log_forceline from your patch commented out. So, the changes inxfs_reclaim_inode()are just theset_bit(XBT_FORCE_FLUSH)andwake_up_process(), relative to 3.1.Dave pointed out that we can do better than the big hammer, and the patch below should fix your issue, too. Can you test it?
Yes, seems to be fine. No hung task warnings, tested for ~5 days.
Thanks a lot for the testing Simon.
Ben, can you add a:
to the patch when applying it?
Hey Christoph,
Quoted 15 lines · Christoph Hellwig
Quoted 5 lines · Simon Kirby
Quoted 3 lines · Christoph Hellwig
Quoted 2 lines · Simon Kirby
Sorry for the delay in testing.
Quoted 8 lines
Quoted 6 lines
Quoted 3 lines
Yes, everything looks fine even with the
xfs_log_forceline from your patch commented out. So, the changes inxfs_reclaim_inode()are just theset_bit(XBT_FORCE_FLUSH)andwake_up_process(), relative to 3.1.Dave pointed out that we can do better than the big hammer, and the patch below should fix your issue, too. Can you test it?
Yes, seems to be fine. No hung task warnings, tested for ~5 days.
Quoted 7 lines
Thanks a lot for the testing Simon.
Ben, can you add a:
Tested-by Simon Kirby <[email protected]>to the patch when applying it?
Yep, I will add Simon's Tested-by:
Thanks Simon! ;)
-Ben
_______________________________________________
xfs mailing list
[email protected]
http://oss.sgi.com/mailman/listinfo/xfs
Quoted 41 lines · Christoph Hellwig
Quoted 11 lines · Simon Kirby
[<ffffffff8126f205>] xfs_reclaim_inode+0x85/0x2b0 [<ffffffff8126f5b0>] xfs_reclaim_inodes_ag+0x180/0x2f0 [<ffffffff8126f74e>] xfs_reclaim_inodes_nr+0x2e/0x40 [<ffffffff8126ccf0>] xfs_fs_free_cached_objects+0x10/0x20 [<ffffffff81119a70>] prune_super+0x110/0x1b0 [<ffffffff810e4fa5>] shrink_slab+0x1e5/0x2a0 [<ffffffff810e5821>] kswapd+0x7c1/0xba0 [<ffffffff8107ada6>] kthread+0x96/0xb0 [<ffffffff816c0474>] kernel_thread_helper+0x4/0x10[<ffffffffffffffff>]
0xffffffffffffffffWe're stuck in synchronous inode reclaim.
Quoted 9 lines
All of the other processes that get stuck have this stack:
[<ffffffff81080587>] down+0x47/0x50 [<ffffffff8125e816>] xfs_buf_lock+0x66/0xd0 [<ffffffff812603ad>] _xfs_buf_find+0x16d/0x270 [<ffffffff81260517>] xfs_buf_get+0x67/0x1a0 [<ffffffff8126067a>] xfs_buf_read+0x2a/0x120 [<ffffffff812b876f>] xfs_trans_read_buf+0x28f/0x3f0 [<ffffffff8129e161>] xfs_read_agi+0x71/0x100They are waiting for the AGI buffer to become unlocked. The only reason it is held locked for longer time is when it is under I/O.
Quoted 6 lines
By the way,
xfs_reclaim_inode+0x85(133) disassembles as:...So the next function is
wait_for_completion(), which is marked__schedand thus doesn't show up in the trace.So we're waiting for the inode to be flushed, aka I/O again.
What is interesting here is that we're always blocking on the AGI buffer - which is used during unlinks of inodes, and thus gets hit fairly heavily for a workload that does a lot of unlinks.
Quoted 6 lines
Given that you are doing a lot of unlinks I wonder if it is related to the recent ail pushing issues in that area. While your symptoms looks completely different we could be blocking on the flush completion for an inode that gets stuck in the AIL.
Can you run with latest 3.0-stable plus the patches at:
Please not that he saw this in 3.1-rc10, too. And this version already contains the fixes:
% git describe --contains 0030807c66f0582
v3.1-rc10~5^2
I just saw similar symptoms while running a weekly rsync backup job. The machine was stuck for a few seconds several times during that time (no response to mouse or keyboard input). It always recovered by itself after a short while.
This is an example output of latencytop during the rsync run:
Cause Maximum Percentage
[xfs_reclaim_inodes_ag] 7847.0 msec 16.6 % Fork() system call 7777.1 msec 25.5 % Creating block layer request 5352.5 msec 18.1 % [xfs_buf_iowait] 2000.4 msec 14.7 % [down] 959.7 msec 2.0 % Page fault 637.3 msec 1.4 % [xfs_iunpin_wait] 557.4 msec 0.7 % Unlinking file 66.8 msec 0.1 %
I also took some "perf timechart" recordings. If there is interest I could post the svg images somewhere.
Signature · 1 line
Markus