Xfs delaylog hanged up
Spelic
spelic at shiftmail.org
Mon Nov 22 13:27:14 CST 2010
Hi there
EXCELLENT speed improvement with delaylog! My congratulations.
Now there's a problem: it hanged on me (not sure it was because of
delaylog, but anyway...)
I am on 2.6.37rc2
16 disk MD raid-5
mkfs line
mkfs.xfs -l size=128m -d agcount=16 <device>
(then lvm2, all aligned to stripes)
mount line:
/dev/mapper/perftestvg-xfslv /perftest/xfs xfs
rw,relatime,attr2,delaylog,nobarrier,inode64,logbufs=8,logbsize=256k,noquota
0 0
deadline scheduler, nr_requests 1024
I was doing a parallel-kernel-unpack benchmark:
/perftest/xfs# mkdir dir{1,2,3,4,5,6,7,8,9,10}
/perftest/xfs# for i in {1..10} ; do time tar -jxf
linux-2.6.37-rc2.tar.bz2 -C dir$i & done ; echo waiting now ; time wait;
echo syncing now ; time sync
[1] 3400
[2] 3401
[3] 3402
[4] 3404
[5] 3407
[6] 3409
[7] 3410
[8] 3413
[9] 3415
[10] 3417
waiting now
[unfortunately I hit ctrl-C here by mistake after a while and it
might have unlocked the situation]
[These are the final times for tars: 6 minutes, while it usually
takes about 1min20sec]
real 6m34.883s
user 0m19.770s
sys 0m5.610s
real 6m45.220s
user 0m20.600s
sys 0m5.750s
real 6m46.638s
user 0m20.920s
sys 0m5.800s
real 6m46.731s
user 0m20.640s
sys 0m5.840s
real 6m46.743s
user 0m20.860s
sys 0m5.950s
real 6m46.857s
user 0m20.330s
sys 0m6.000s
real 6m47.885s
user 0m21.000s
sys 0m6.010s
real 6m48.718s
user 0m20.780s
sys 0m5.700s
real 6m51.915s
user 0m19.530s
sys 0m4.680s
real 7m0.249s
user 0m20.330s
sys 0m6.290s
Iostat showed everything totally still.
Computer was responsive for the rest (OS is on other filesystems)
Look at the stack traces in the 5 minutes they were hanged:
# ps aux | grep tar
root 875 0.0 0.0 12688 556 ? S 16:47 0:00
upstart-udev-bridge --daemon
root 3403 1.9 0.0 18224 1168 pts/1 D 18:58 0:04
tar -jxf linux-2.6.37-rc2.tar.bz2 -C dir1
root 3405 1.8 0.0 18224 1168 pts/1 D 18:58 0:04
tar -jxf linux-2.6.37-rc2.tar.bz2 -C dir2
root 3406 0.9 0.0 18224 1164 pts/1 D 18:58 0:02
tar -jxf linux-2.6.37-rc2.tar.bz2 -C dir3
root 3408 1.7 0.0 18224 1164 pts/1 D 18:58 0:04
tar -jxf linux-2.6.37-rc2.tar.bz2 -C dir4
root 3411 1.8 0.0 18224 1164 pts/1 D 18:58 0:04
tar -jxf linux-2.6.37-rc2.tar.bz2 -C dir5
root 3412 1.6 0.0 18224 1164 pts/1 D 18:58 0:04
tar -jxf linux-2.6.37-rc2.tar.bz2 -C dir6
root 3414 1.7 0.0 18224 1164 pts/1 D 18:58 0:04
tar -jxf linux-2.6.37-rc2.tar.bz2 -C dir7
root 3416 1.8 0.0 18224 1164 pts/1 D 18:58 0:04
tar -jxf linux-2.6.37-rc2.tar.bz2 -C dir8
root 3418 1.8 0.0 18224 1168 pts/1 D 18:58 0:04
tar -jxf linux-2.6.37-rc2.tar.bz2 -C dir9
root 3419 1.7 0.0 18224 1164 pts/1 D 18:58 0:04
tar -jxf linux-2.6.37-rc2.tar.bz2 -C dir10
# cat /proc/3403/stack
[<ffffffffa02c607b>] xlog_grant_log_space+0x19b/0x5e0 [xfs]
[<ffffffffa02c65be>] xfs_log_reserve+0xfe/0x160 [xfs]
[<ffffffffa02d25cb>] xfs_trans_reserve+0x9b/0x210 [xfs]
[<ffffffffa02d80fa>] xfs_setattr+0x81a/0xa10 [xfs]
[<ffffffffa02e3df6>] xfs_vn_setattr+0x16/0x20 [xfs]
[<ffffffff8114de68>] notify_change+0x168/0x2d0
[<ffffffff811346e7>] sys_fchmodat+0xd7/0x110
[<ffffffff81134733>] sys_chmod+0x13/0x20
[<ffffffff8100af42>] system_call_fastpath+0x16/0x1b
[<ffffffffffffffff>] 0xffffffffffffffff
# cat /proc/3405/stack
[<ffffffffa02c607b>] xlog_grant_log_space+0x19b/0x5e0 [xfs]
[<ffffffffa02c65be>] xfs_log_reserve+0xfe/0x160 [xfs]
[<ffffffffa02d25cb>] xfs_trans_reserve+0x9b/0x210 [xfs]
[<ffffffffa02d6db5>] xfs_free_eofblocks+0x175/0x270 [xfs]
[<ffffffffa02d782d>] xfs_release+0x10d/0x1c0 [xfs]
[<ffffffffa02dfa90>] xfs_file_release+0x10/0x20 [xfs]
[<ffffffff81137405>] fput+0xd5/0x280
[<ffffffff81133bf8>] filp_close+0x58/0x90
[<ffffffff81133ce9>] sys_close+0xb9/0x110
[<ffffffff8100af42>] system_call_fastpath+0x16/0x1b
[<ffffffffffffffff>] 0xffffffffffffffff
# cat /proc/3406/stack
[<ffffffffa02c607b>] xlog_grant_log_space+0x19b/0x5e0 [xfs]
[<ffffffffa02c65be>] xfs_log_reserve+0xfe/0x160 [xfs]
[<ffffffffa02d25cb>] xfs_trans_reserve+0x9b/0x210 [xfs]
[<ffffffffa02c05ed>] xfs_iomap_write_allocate+0x21d/0x360 [xfs]
[<ffffffffa02c09bf>] xfs_iomap+0x28f/0x340 [xfs]
[<ffffffffa02da287>] xfs_map_blocks+0x37/0x40 [xfs]
[<ffffffffa02dbae0>] xfs_vm_writepage+0x3f0/0x5d0 [xfs]
[<ffffffff810f00d2>] __writepage+0x12/0x40
[<ffffffff810f1198>] write_cache_pages+0x1f8/0x490
[<ffffffff810f144f>] generic_writepages+0x1f/0x30
[<ffffffffa02da8a8>] xfs_vm_writepages+0x58/0x70 [xfs]
[<ffffffff810f147c>] do_writepages+0x1c/0x40
[<ffffffff81158ddd>] writeback_single_inode+0x9d/0x260
[<ffffffff811591e4>] writeback_sb_inodes+0xd4/0x170
[<ffffffff81159324>] writeback_inodes_wb+0xa4/0x170
[<ffffffff810f0a60>] balance_dirty_pages_ratelimited_nr+0x390/0x4a0
[<ffffffff810e71b3>] generic_file_buffered_write+0x1b3/0x250
[<ffffffffa02e09b8>] xfs_file_aio_write+0x7b8/0xa60 [xfs]
[<ffffffff81135582>] do_sync_write+0xd2/0x110
[<ffffffff81135878>] vfs_write+0xc8/0x190
[<ffffffff811361ac>] sys_write+0x4c/0x80
[<ffffffff8100af42>] system_call_fastpath+0x16/0x1b
[<ffffffffffffffff>] 0xffffffffffffffff
# cat /proc/3408/stack
[<ffffffffa02c607b>] xlog_grant_log_space+0x19b/0x5e0 [xfs]
[<ffffffffa02c65be>] xfs_log_reserve+0xfe/0x160 [xfs]
[<ffffffffa02d25cb>] xfs_trans_reserve+0x9b/0x210 [xfs]
[<ffffffffa02d666b>] xfs_create+0x17b/0x650 [xfs]
[<ffffffffa02e3868>] xfs_vn_mknod+0xa8/0x1c0 [xfs]
[<ffffffffa02e399b>] xfs_vn_create+0xb/0x10 [xfs]
[<ffffffff81140f97>] vfs_create+0xa7/0xd0
[<ffffffff811420e8>] do_last+0x658/0x720
[<ffffffff8114414b>] do_filp_open+0x1fb/0x650
[<ffffffff81133da3>] do_sys_open+0x63/0x120
[<ffffffff81133e8b>] sys_open+0x1b/0x20
[<ffffffff8100af42>] system_call_fastpath+0x16/0x1b
[<ffffffffffffffff>] 0xffffffffffffffff
# cat /proc/3411/stack
[<ffffffffa02c607b>] xlog_grant_log_space+0x19b/0x5e0 [xfs]
[<ffffffffa02c65be>] xfs_log_reserve+0xfe/0x160 [xfs]
[<ffffffffa02d25cb>] xfs_trans_reserve+0x9b/0x210 [xfs]
[<ffffffffa02d6db5>] xfs_free_eofblocks+0x175/0x270 [xfs]
[<ffffffffa02d782d>] xfs_release+0x10d/0x1c0 [xfs]
[<ffffffffa02dfa90>] xfs_file_release+0x10/0x20 [xfs]
[<ffffffff81137405>] fput+0xd5/0x280
[<ffffffff81133bf8>] filp_close+0x58/0x90
[<ffffffff81133ce9>] sys_close+0xb9/0x110
[<ffffffff8100af42>] system_call_fastpath+0x16/0x1b
[<ffffffffffffffff>] 0xffffffffffffffff
# cat /proc/3412/stack
[<ffffffffa02c607b>] xlog_grant_log_space+0x19b/0x5e0 [xfs]
[<ffffffffa02c65be>] xfs_log_reserve+0xfe/0x160 [xfs]
[<ffffffffa02d25cb>] xfs_trans_reserve+0x9b/0x210 [xfs]
[<ffffffffa02d666b>] xfs_create+0x17b/0x650 [xfs]
[<ffffffffa02e3868>] xfs_vn_mknod+0xa8/0x1c0 [xfs]
[<ffffffffa02e399b>] xfs_vn_create+0xb/0x10 [xfs]
[<ffffffff81140f97>] vfs_create+0xa7/0xd0
[<ffffffff811420e8>] do_last+0x658/0x720
[<ffffffff8114414b>] do_filp_open+0x1fb/0x650
[<ffffffff81133da3>] do_sys_open+0x63/0x120
[<ffffffff81133e8b>] sys_open+0x1b/0x20
[<ffffffff8100af42>] system_call_fastpath+0x16/0x1b
[<ffffffffffffffff>] 0xffffffffffffffff
# cat /proc/3414/stack
[<ffffffffa02c607b>] xlog_grant_log_space+0x19b/0x5e0 [xfs]
[<ffffffffa02c65be>] xfs_log_reserve+0xfe/0x160 [xfs]
[<ffffffffa02d25cb>] xfs_trans_reserve+0x9b/0x210 [xfs]
[<ffffffffa02d80fa>] xfs_setattr+0x81a/0xa10 [xfs]
[<ffffffffa02e3df6>] xfs_vn_setattr+0x16/0x20 [xfs]
[<ffffffff8114de68>] notify_change+0x168/0x2d0
[<ffffffff8115dc57>] utimes_common+0xd7/0x1b0
[<ffffffff8115ddc0>] do_utimes+0x90/0xf0
[<ffffffff8115dece>] sys_utimensat+0x2e/0x80
[<ffffffff8100af42>] system_call_fastpath+0x16/0x1b
[<ffffffffffffffff>] 0xffffffffffffffff
# cat /proc/3416/stack
[<ffffffffa02c607b>] xlog_grant_log_space+0x19b/0x5e0 [xfs]
[<ffffffffa02c65be>] xfs_log_reserve+0xfe/0x160 [xfs]
[<ffffffffa02d25cb>] xfs_trans_reserve+0x9b/0x210 [xfs]
[<ffffffffa02d80fa>] xfs_setattr+0x81a/0xa10 [xfs]
[<ffffffffa02e3df6>] xfs_vn_setattr+0x16/0x20 [xfs]
[<ffffffff8114de68>] notify_change+0x168/0x2d0
[<ffffffff811346e7>] sys_fchmodat+0xd7/0x110
[<ffffffff81134733>] sys_chmod+0x13/0x20
[<ffffffff8100af42>] system_call_fastpath+0x16/0x1b
[<ffffffffffffffff>] 0xffffffffffffffff
# cat /proc/3418/stack
[<ffffffffa02c607b>] xlog_grant_log_space+0x19b/0x5e0 [xfs]
[<ffffffffa02c65be>] xfs_log_reserve+0xfe/0x160 [xfs]
[<ffffffffa02d25cb>] xfs_trans_reserve+0x9b/0x210 [xfs]
[<ffffffffa02d6db5>] xfs_free_eofblocks+0x175/0x270 [xfs]
[<ffffffffa02d782d>] xfs_release+0x10d/0x1c0 [xfs]
[<ffffffffa02dfa90>] xfs_file_release+0x10/0x20 [xfs]
[<ffffffff81137405>] fput+0xd5/0x280
[<ffffffff81133bf8>] filp_close+0x58/0x90
[<ffffffff81133ce9>] sys_close+0xb9/0x110
[<ffffffff8100af42>] system_call_fastpath+0x16/0x1b
[<ffffffffffffffff>] 0xffffffffffffffff
# cat /proc/3419/stack
[<ffffffffa02c6195>] xlog_grant_log_space+0x2b5/0x5e0 [xfs]
[<ffffffffa02c65be>] xfs_log_reserve+0xfe/0x160 [xfs]
[<ffffffffa02d25cb>] xfs_trans_reserve+0x9b/0x210 [xfs]
[<ffffffffa02d6db5>] xfs_free_eofblocks+0x175/0x270 [xfs]
[<ffffffffa02d782d>] xfs_release+0x10d/0x1c0 [xfs]
[<ffffffffa02dfa90>] xfs_file_release+0x10/0x20 [xfs]
[<ffffffff81137405>] fput+0xd5/0x280
[<ffffffff81133bf8>] filp_close+0x58/0x90
[<ffffffff81133ce9>] sys_close+0xb9/0x110
[<ffffffff8100af42>] system_call_fastpath+0x16/0x1b
[<ffffffffffffffff>] 0xffffffffffffffff
dmesg:
[ 8042.770130] xfsaild/dm-6 D 00000001000b92b8 0 2979 2
0x00000000
[ 8042.770135] ffff88082c11ba90 0000000000000046 ffff88083140de08
0000000000000000
[ 8042.770140] 00000000000138c0 ffff88083dfa5a80 ffff88083dfa5e18
ffff88082c11bfd8
[ 8042.770144] ffff88083dfa5e20 00000000000138c0 ffff88082c11a010
00000000000138c0
[ 8042.770148] Call Trace:
[ 8042.770187] [<ffffffffa02c4a8f>]
xlog_state_get_iclog_space+0xdf/0x2c0 [xfs]
[ 8042.770205] [<ffffffffa02c422a>] ? xlog_sync+0x1fa/0x3d0 [xfs]
[ 8042.770213] [<ffffffff810538d0>] ? default_wake_function+0x0/0x10
[ 8042.770231] [<ffffffffa02c5708>] xlog_write+0x198/0x6c0 [xfs]
[ 8042.770249] [<ffffffffa02c6fd2>] xlog_cil_push+0x252/0x3b0 [xfs]
[ 8042.770267] [<ffffffffa02c7636>] xlog_cil_force_lsn+0x116/0x120 [xfs]
[ 8042.770286] [<ffffffffa02dd3dc>] ? xfs_buf_delwri_queue+0xcc/0x150 [xfs]
[ 8042.770291] [<ffffffff81033209>] ? default_spin_lock_flags+0x9/0x10
[ 8042.770296] [<ffffffff810808d2>] ? down_trylock+0x32/0x50
[ 8042.770314] [<ffffffffa02c4543>] _xfs_log_force+0x63/0x230 [xfs]
[ 8042.770332] [<ffffffffa02c4933>] xfs_log_force+0x13/0x40 [xfs]
[ 8042.770351] [<ffffffffa02d38e4>] xfsaild_push+0x3b4/0x400 [xfs]
[ 8042.770357] [<ffffffff81571c26>] ? schedule_timeout+0x196/0x2f0
[ 8042.770377] [<ffffffffa02e67a4>] xfsaild+0x74/0xb0 [xfs]
[ 8042.770395] [<ffffffffa02e6730>] ? xfsaild+0x0/0xb0 [xfs]
[ 8042.770400] [<ffffffff8107b076>] kthread+0x96/0xa0
[ 8042.770404] [<ffffffff8100bd64>] kernel_thread_helper+0x4/0x10
[ 8042.770408] [<ffffffff8107afe0>] ? kthread+0x0/0xa0
[ 8042.770411] [<ffffffff8100bd60>] ? kernel_thread_helper+0x0/0x10
[ 8042.770414] INFO: task xfssyncd/dm-6:2980 blocked for more than 120
seconds.
[ 8042.770449] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs"
disables this message.
[ 8042.770501] xfssyncd/dm-6 D ffff88083dfa0000 0 2980 2
0x00000000
[ 8042.770505] ffff88015d98fcf0 0000000000000046 ffff88015d98fc80
ffffffffa02cdb39
[ 8042.770510] 00000000000138c0 ffff88083dfa0000 ffff88083dfa0398
ffff88015d98ffd8
[ 8042.770514] ffff88083dfa03a0 00000000000138c0 ffff88015d98e010
00000000000138c0
[ 8042.770518] Call Trace:
[ 8042.770537] [<ffffffffa02cdb39>] ? xfs_perag_get_tag+0x39/0xc0 [xfs]
[ 8042.770555] [<ffffffffa02c607b>] xlog_grant_log_space+0x19b/0x5e0 [xfs]
[ 8042.770574] [<ffffffffa02d97e5>] ? kmem_zone_zalloc+0x35/0x50 [xfs]
[ 8042.770578] [<ffffffff810538d0>] ? default_wake_function+0x0/0x10
[ 8042.770595] [<ffffffffa02c65be>] xfs_log_reserve+0xfe/0x160 [xfs]
[ 8042.770614] [<ffffffffa02d25cb>] xfs_trans_reserve+0x9b/0x210 [xfs]
[ 8042.770631] [<ffffffffa02b5ac9>] xfs_fs_log_dummy+0x49/0xb0 [xfs]
[ 8042.770649] [<ffffffffa02c3c46>] ? xfs_log_need_covered+0x66/0xd0 [xfs]
[ 8042.770668] [<ffffffffa02e82e3>] xfs_sync_worker+0x83/0x90 [xfs]
[ 8042.770686] [<ffffffffa02e70b3>] xfssyncd+0x183/0x230 [xfs]
[ 8042.770705] [<ffffffffa02e6f30>] ? xfssyncd+0x0/0x230 [xfs]
[ 8042.770709] [<ffffffff8107b076>] kthread+0x96/0xa0
[ 8042.770712] [<ffffffff8100bd64>] kernel_thread_helper+0x4/0x10
[ 8042.770715] [<ffffffff8107afe0>] ? kthread+0x0/0xa0
[ 8042.770718] [<ffffffff8100bd60>] ? kernel_thread_helper+0x0/0x10
[ 8042.770721] INFO: task flush-252:6:3320 blocked for more than 120
seconds.
[ 8042.770756] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs"
disables this message.
[ 8042.770808] flush-252:6 D 00000001000b92b0 0 3320 2
0x00000000
[ 8042.770812] ffff8808329776b0 0000000000000046 0000000000000286
ffff880800000000
[ 8042.770817] 00000000000138c0 ffff88083dbe96a0 ffff88083dbe9a38
ffff880832977fd8
[ 8042.770821] ffff88083dbe9a40 00000000000138c0 ffff880832976010
00000000000138c0
[ 8042.770825] Call Trace:
[ 8042.770843] [<ffffffffa02c607b>] xlog_grant_log_space+0x19b/0x5e0 [xfs]
[ 8042.770861] [<ffffffffa02d97e5>] ? kmem_zone_zalloc+0x35/0x50 [xfs]
[ 8042.770865] [<ffffffff810538d0>] ? default_wake_function+0x0/0x10
[ 8042.770883] [<ffffffffa02c65be>] xfs_log_reserve+0xfe/0x160 [xfs]
[ 8042.770901] [<ffffffffa02d25cb>] xfs_trans_reserve+0x9b/0x210 [xfs]
[ 8042.770920] [<ffffffffa02d28b7>] ? xfs_trans_alloc+0x97/0xb0 [xfs]
[ 8042.770937] [<ffffffffa02c05ed>]
xfs_iomap_write_allocate+0x21d/0x360 [xfs]
[ 8042.770957] [<ffffffffa02d31f1>] ? xfs_trans_unlocked_item+0x31/0x50
[xfs]
[ 8042.770974] [<ffffffffa02c09bf>] xfs_iomap+0x28f/0x340 [xfs]
[ 8042.770992] [<ffffffffa02da287>] xfs_map_blocks+0x37/0x40 [xfs]
[ 8042.771011] [<ffffffffa02dbae0>] xfs_vm_writepage+0x3f0/0x5d0 [xfs]
[ 8042.771017] [<ffffffff810f00d2>] __writepage+0x12/0x40
[ 8042.771020] [<ffffffff810f1198>] write_cache_pages+0x1f8/0x490
[ 8042.771024] [<ffffffff810f00c0>] ? __writepage+0x0/0x40
[ 8042.771027] [<ffffffff8157130c>] ? schedule+0x44c/0xa80
[ 8042.771045] [<ffffffffa02d31f1>] ? xfs_trans_unlocked_item+0x31/0x50
[xfs]
[ 8042.771050] [<ffffffff810f144f>] generic_writepages+0x1f/0x30
[ 8042.771068] [<ffffffffa02da8a8>] xfs_vm_writepages+0x58/0x70 [xfs]
[ 8042.771071] [<ffffffff810f147c>] do_writepages+0x1c/0x40
[ 8042.771077] [<ffffffff81158ddd>] writeback_single_inode+0x9d/0x260
[ 8042.771080] [<ffffffff811591e4>] writeback_sb_inodes+0xd4/0x170
[ 8042.771083] [<ffffffff81158258>] ? queue_io+0x98/0x1b0
[ 8042.771087] [<ffffffff81159324>] writeback_inodes_wb+0xa4/0x170
[ 8042.771090] [<ffffffff8115967b>] wb_writeback+0x28b/0x400
[ 8042.771094] [<ffffffff8105477b>] ? dequeue_task_fair+0x8b/0x90
[ 8042.771099] [<ffffffff810095fb>] ? __switch_to+0xcb/0x350
[ 8042.771103] [<ffffffff812a7ab9>] ? __percpu_counter_sum+0x69/0x80
[ 8042.771106] [<ffffffff8115998b>] wb_do_writeback+0x19b/0x1e0
[ 8042.771110] [<ffffffff81159a7a>] bdi_writeback_thread+0xaa/0x270
[ 8042.771113] [<ffffffff811599d0>] ? bdi_writeback_thread+0x0/0x270
[ 8042.771117] [<ffffffff8107b076>] kthread+0x96/0xa0
[ 8042.771120] [<ffffffff8100bd64>] kernel_thread_helper+0x4/0x10
[ 8042.771123] [<ffffffff8107afe0>] ? kthread+0x0/0xa0
[ 8042.771126] [<ffffffff8100bd60>] ? kernel_thread_helper+0x0/0x10
[ 8042.771130] INFO: task tar:3403 blocked for more than 120 seconds.
[ 8042.771163] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs"
disables this message.
[ 8042.771216] tar D ffff88083d04ad40 0 3403 3400
0x00000000
[ 8042.771220] ffff88015e7a9c68 0000000000000082 0000000000000001
ffff880832815f00
[ 8042.771224] 00000000000138c0 ffff88083d04ad40 ffff88083d04b0d8
ffff88015e7a9fd8
[ 8042.771228] ffff88083d04b0e0 00000000000138c0 ffff88015e7a8010
00000000000138c0
[ 8042.771232] Call Trace:
[ 8042.771250] [<ffffffffa02c607b>] xlog_grant_log_space+0x19b/0x5e0 [xfs]
[ 8042.771268] [<ffffffffa02d97e5>] ? kmem_zone_zalloc+0x35/0x50 [xfs]
[ 8042.771272] [<ffffffff810538d0>] ? default_wake_function+0x0/0x10
[ 8042.771290] [<ffffffffa02c65be>] xfs_log_reserve+0xfe/0x160 [xfs]
[ 8042.771308] [<ffffffffa02d25cb>] xfs_trans_reserve+0x9b/0x210 [xfs]
[ 8042.771326] [<ffffffffa02d28b7>] ? xfs_trans_alloc+0x97/0xb0 [xfs]
[ 8042.771345] [<ffffffffa02d80fa>] xfs_setattr+0x81a/0xa10 [xfs]
[ 8042.771363] [<ffffffffa02e3df6>] xfs_vn_setattr+0x16/0x20 [xfs]
[ 8042.771368] [<ffffffff8114de68>] notify_change+0x168/0x2d0
[ 8042.771373] [<ffffffff811346e7>] sys_fchmodat+0xd7/0x110
[ 8042.771377] [<ffffffff815737e9>] ? _raw_spin_lock+0x9/0x10
[ 8042.771381] [<ffffffff811345e8>] ? sys_chown+0x68/0x90
[ 8042.771384] [<ffffffff81134733>] sys_chmod+0x13/0x20
[ 8042.771387] [<ffffffff8100af42>] system_call_fastpath+0x16/0x1b
[ 8042.771390] INFO: task tar:3405 blocked for more than 120 seconds.
[ 8042.771424] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs"
disables this message.
[ 8042.771476] tar D 00000001000b92b6 0 3405 3401
0x00000000
[ 8042.771480] ffff88018e975cc8 0000000000000086 ffff88018e975cd8
0000000000000000
[ 8042.771484] 00000000000138c0 ffff880832b98000 ffff880832b98398
ffff88018e975fd8
[ 8042.771489] ffff880832b983a0 00000000000138c0 ffff88018e974010
00000000000138c0
[ 8042.771493] Call Trace:
[ 8042.771510] [<ffffffffa02c607b>] xlog_grant_log_space+0x19b/0x5e0 [xfs]
[ 8042.771528] [<ffffffffa02d97e5>] ? kmem_zone_zalloc+0x35/0x50 [xfs]
[ 8042.771532] [<ffffffff810538d0>] ? default_wake_function+0x0/0x10
[ 8042.771550] [<ffffffffa02c65be>] xfs_log_reserve+0xfe/0x160 [xfs]
[ 8042.771568] [<ffffffffa02d25cb>] xfs_trans_reserve+0x9b/0x210 [xfs]
[ 8042.771587] [<ffffffffa02e0dab>] ? xfs_tosspages+0x1b/0x20 [xfs]
[ 8042.771605] [<ffffffffa02d6db5>] xfs_free_eofblocks+0x175/0x270 [xfs]
[ 8042.771624] [<ffffffffa02d782d>] xfs_release+0x10d/0x1c0 [xfs]
[ 8042.771642] [<ffffffffa02dfa90>] xfs_file_release+0x10/0x20 [xfs]
[ 8042.771646] [<ffffffff81137405>] fput+0xd5/0x280
[ 8042.771650] [<ffffffff81133bf8>] filp_close+0x58/0x90
[ 8042.771653] [<ffffffff81133ce9>] sys_close+0xb9/0x110
[ 8042.771656] [<ffffffff8100af42>] system_call_fastpath+0x16/0x1b
[ 8042.771659] INFO: task tar:3406 blocked for more than 120 seconds.
[ 8042.771692] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs"
disables this message.
[ 8042.771745] tar D 00000001000b92b0 0 3406 3402
0x00000008
[ 8042.771749] ffff8801202c94c8 0000000000000086 0000000000000282
ffff880800000001
[ 8042.771754] 00000000000138c0 ffff880832af2d40 ffff880832af30d8
ffff8801202c9fd8
[ 8042.771758] ffff880832af30e0 00000000000138c0 ffff8801202c8010
00000000000138c0
[ 8042.771762] Call Trace:
[ 8042.771779] [<ffffffffa02c607b>] xlog_grant_log_space+0x19b/0x5e0 [xfs]
[ 8042.771798] [<ffffffffa02d97e5>] ? kmem_zone_zalloc+0x35/0x50 [xfs]
[ 8042.771801] [<ffffffff810538d0>] ? default_wake_function+0x0/0x10
[ 8042.771819] [<ffffffffa02c65be>] xfs_log_reserve+0xfe/0x160 [xfs]
[ 8042.771838] [<ffffffffa02d25cb>] xfs_trans_reserve+0x9b/0x210 [xfs]
[ 8042.771856] [<ffffffffa02d28b7>] ? xfs_trans_alloc+0x97/0xb0 [xfs]
[ 8042.771874] [<ffffffffa02c05ed>]
xfs_iomap_write_allocate+0x21d/0x360 [xfs]
[ 8042.771892] [<ffffffffa02d31f1>] ? xfs_trans_unlocked_item+0x31/0x50
[xfs]
[ 8042.771910] [<ffffffffa02c09bf>] xfs_iomap+0x28f/0x340 [xfs]
[ 8042.771928] [<ffffffffa02da287>] xfs_map_blocks+0x37/0x40 [xfs]
[ 8042.771946] [<ffffffffa02ddc18>] ? _xfs_buf_lookup_pages+0x288/0x360
[xfs]
[ 8042.771965] [<ffffffffa02dbae0>] xfs_vm_writepage+0x3f0/0x5d0 [xfs]
[ 8042.771969] [<ffffffff810f00d2>] __writepage+0x12/0x40
[ 8042.771972] [<ffffffff810f1198>] write_cache_pages+0x1f8/0x490
[ 8042.771975] [<ffffffff810f00c0>] ? __writepage+0x0/0x40
[ 8042.771993] [<ffffffffa02bea94>] ? xfs_iflush+0x214/0x220 [xfs]
[ 8042.772011] [<ffffffffa02dd86e>] ? xfs_bdwrite+0x3e/0x80 [xfs]
[ 8042.772030] [<ffffffffa02d31f1>] ? xfs_trans_unlocked_item+0x31/0x50
[xfs]
[ 8042.772034] [<ffffffff810f144f>] generic_writepages+0x1f/0x30
[ 8042.772052] [<ffffffffa02da8a8>] xfs_vm_writepages+0x58/0x70 [xfs]
[ 8042.772056] [<ffffffff810f147c>] do_writepages+0x1c/0x40
[ 8042.772059] [<ffffffff81158ddd>] writeback_single_inode+0x9d/0x260
[ 8042.772063] [<ffffffff811591e4>] writeback_sb_inodes+0xd4/0x170
[ 8042.772066] [<ffffffff81159324>] writeback_inodes_wb+0xa4/0x170
[ 8042.772070] [<ffffffff810f0a60>]
balance_dirty_pages_ratelimited_nr+0x390/0x4a0
[ 8042.772074] [<ffffffff810e6db1>] ?
iov_iter_copy_from_user_atomic+0x91/0x160
[ 8042.772077] [<ffffffff810e71b3>] generic_file_buffered_write+0x1b3/0x250
[ 8042.772097] [<ffffffffa02e09b8>] xfs_file_aio_write+0x7b8/0xa60 [xfs]
[ 8042.772101] [<ffffffff81135582>] do_sync_write+0xd2/0x110
[ 8042.772106] [<ffffffff81243a4e>] ? security_file_permission+0x1e/0x90
[ 8042.772109] [<ffffffff81135878>] vfs_write+0xc8/0x190
[ 8042.772112] [<ffffffff811361ac>] sys_write+0x4c/0x80
[ 8042.772116] [<ffffffff8100af42>] system_call_fastpath+0x16/0x1b
[ 8042.772119] INFO: task tar:3408 blocked for more than 120 seconds.
[ 8042.772152] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs"
disables this message.
[ 8042.772205] tar D 00000001000b92b0 0 3408 3404
0x00000000
[ 8042.772209] ffff88082c331a98 0000000000000082 0000000000000000
0000000000000000
[ 8042.772213] 00000000000138c0 ffff88083cca43e0 ffff88083cca4778
ffff88082c331fd8
[ 8042.772217] ffff88083cca4780 00000000000138c0 ffff88082c330010
00000000000138c0
[ 8042.772221] Call Trace:
[ 8042.772239] [<ffffffffa02c607b>] xlog_grant_log_space+0x19b/0x5e0 [xfs]
[ 8042.772257] [<ffffffffa02d97e5>] ? kmem_zone_zalloc+0x35/0x50 [xfs]
[ 8042.772261] [<ffffffff810538d0>] ? default_wake_function+0x0/0x10
[ 8042.772279] [<ffffffffa02c65be>] xfs_log_reserve+0xfe/0x160 [xfs]
[ 8042.772297] [<ffffffffa02d25cb>] xfs_trans_reserve+0x9b/0x210 [xfs]
[ 8042.772315] [<ffffffffa02d28b7>] ? xfs_trans_alloc+0x97/0xb0 [xfs]
[ 8042.772334] [<ffffffffa02d666b>] xfs_create+0x17b/0x650 [xfs]
[ 8042.772338] [<ffffffff815737e9>] ? _raw_spin_lock+0x9/0x10
[ 8042.772356] [<ffffffffa02e3868>] xfs_vn_mknod+0xa8/0x1c0 [xfs]
[ 8042.772375] [<ffffffffa02e399b>] xfs_vn_create+0xb/0x10 [xfs]
[ 8042.772379] [<ffffffff81140f97>] vfs_create+0xa7/0xd0
[ 8042.772382] [<ffffffff811420e8>] do_last+0x658/0x720
[ 8042.772386] [<ffffffff8114414b>] do_filp_open+0x1fb/0x650
[ 8042.772389] [<ffffffff81243286>] ? security_d_instantiate+0x16/0x30
[ 8042.772393] [<ffffffff8114a371>] ? d_instantiate+0x51/0x60
[ 8042.772397] [<ffffffff8114ef92>] ? alloc_fd+0x102/0x150
[ 8042.772400] [<ffffffff81133da3>] do_sys_open+0x63/0x120
[ 8042.772403] [<ffffffff8100c15d>] ? math_state_restore+0x3d/0x60
[ 8042.772407] [<ffffffff81133e8b>] sys_open+0x1b/0x20
[ 8042.772410] [<ffffffff8100af42>] system_call_fastpath+0x16/0x1b
[ 8042.772413] INFO: task tar:3411 blocked for more than 120 seconds.
[ 8042.772446] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs"
disables this message.
[ 8042.772499] tar D ffff88083d40ad40 0 3411 3407
0x00000000
[ 8042.772503] ffff880832545cc8 0000000000000086 ffff880832545cd8
0000000000000004
[ 8042.772507] 00000000000138c0 ffff88083d40ad40 ffff88083d40b0d8
ffff880832545fd8
[ 8042.772512] ffff88083d40b0e0 00000000000138c0 ffff880832544010
00000000000138c0
[ 8042.772516] Call Trace:
[ 8042.772533] [<ffffffffa02c607b>] xlog_grant_log_space+0x19b/0x5e0 [xfs]
[ 8042.772551] [<ffffffffa02d97e5>] ? kmem_zone_zalloc+0x35/0x50 [xfs]
[ 8042.772555] [<ffffffff810538d0>] ? default_wake_function+0x0/0x10
[ 8042.772573] [<ffffffffa02c65be>] xfs_log_reserve+0xfe/0x160 [xfs]
[ 8042.772591] [<ffffffffa02d25cb>] xfs_trans_reserve+0x9b/0x210 [xfs]
[ 8042.772610] [<ffffffffa02e0dab>] ? xfs_tosspages+0x1b/0x20 [xfs]
[ 8042.772628] [<ffffffffa02d6db5>] xfs_free_eofblocks+0x175/0x270 [xfs]
[ 8042.772646] [<ffffffffa02d782d>] xfs_release+0x10d/0x1c0 [xfs]
[ 8042.772665] [<ffffffffa02dfa90>] xfs_file_release+0x10/0x20 [xfs]
[ 8042.772669] [<ffffffff81137405>] fput+0xd5/0x280
[ 8042.772672] [<ffffffff81133bf8>] filp_close+0x58/0x90
[ 8042.772675] [<ffffffff81133ce9>] sys_close+0xb9/0x110
[ 8042.772678] [<ffffffff8100af42>] system_call_fastpath+0x16/0x1b
[ 8042.772681] INFO: task tar:3412 blocked for more than 120 seconds.
[ 8042.772714] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs"
disables this message.
[ 8042.772767] tar D 00000001000b92ae 0 3412 3409
0x00000000
[ 8042.772771] ffff8802b0811a98 0000000000000082 0000000000000000
0000000000000000
[ 8042.772775] 00000000000138c0 ffff8808400aad40 ffff8808400ab0d8
ffff8802b0811fd8
[ 8042.772780] ffff8808400ab0e0 00000000000138c0 ffff8802b0810010
00000000000138c0
[ 8042.772784] Call Trace:
[ 8042.772802] [<ffffffffa02c607b>] xlog_grant_log_space+0x19b/0x5e0 [xfs]
[ 8042.772820] [<ffffffffa02d97e5>] ? kmem_zone_zalloc+0x35/0x50 [xfs]
[ 8042.772824] [<ffffffff810538d0>] ? default_wake_function+0x0/0x10
[ 8042.772841] [<ffffffffa02c65be>] xfs_log_reserve+0xfe/0x160 [xfs]
[ 8042.772860] [<ffffffffa02d25cb>] xfs_trans_reserve+0x9b/0x210 [xfs]
[ 8042.772878] [<ffffffffa02d28b7>] ? xfs_trans_alloc+0x97/0xb0 [xfs]
[ 8042.772896] [<ffffffffa02d666b>] xfs_create+0x17b/0x650 [xfs]
[ 8042.772913] [<ffffffffa02b8ef6>] ? xfs_iunlock+0x96/0x130 [xfs]
[ 8042.772932] [<ffffffffa02d6bcd>] ? xfs_lookup+0x8d/0x100 [xfs]
[ 8042.772950] [<ffffffffa02e3868>] xfs_vn_mknod+0xa8/0x1c0 [xfs]
[ 8042.772969] [<ffffffffa02e399b>] xfs_vn_create+0xb/0x10 [xfs]
[ 8042.772972] [<ffffffff81140f97>] vfs_create+0xa7/0xd0
[ 8042.772976] [<ffffffff811420e8>] do_last+0x658/0x720
[ 8042.772979] [<ffffffff8114414b>] do_filp_open+0x1fb/0x650
[ 8042.772983] [<ffffffff815737e9>] ? _raw_spin_lock+0x9/0x10
[ 8042.772986] [<ffffffff815737e9>] ? _raw_spin_lock+0x9/0x10
[ 8042.772990] [<ffffffff8114ef92>] ? alloc_fd+0x102/0x150
[ 8042.772993] [<ffffffff81133da3>] do_sys_open+0x63/0x120
[ 8042.772996] [<ffffffff8100c15d>] ? math_state_restore+0x3d/0x60
[ 8042.773000] [<ffffffff81133e8b>] sys_open+0x1b/0x20
[ 8042.773003] [<ffffffff8100af42>] system_call_fastpath+0x16/0x1b
[ 8042.773006] INFO: task tar:3414 blocked for more than 120 seconds.
[ 8042.773039] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs"
disables this message.
[ 8042.773092] tar D 00000001000b92aa 0 3414 3410
0x00000000
[ 8042.773096] ffff8802b0a19c08 0000000000000086 ffff88015d090800
0000000500000000
[ 8042.773100] 00000000000138c0 ffff880832af0000 ffff880832af0398
ffff8802b0a19fd8
[ 8042.773104] ffff880832af03a0 00000000000138c0 ffff8802b0a18010
00000000000138c0
[ 8042.773108] Call Trace:
[ 8042.773126] [<ffffffffa02c607b>] xlog_grant_log_space+0x19b/0x5e0 [xfs]
[ 8042.773144] [<ffffffffa02d97e5>] ? kmem_zone_zalloc+0x35/0x50 [xfs]
[ 8042.773148] [<ffffffff810538d0>] ? default_wake_function+0x0/0x10
[ 8042.773166] [<ffffffffa02c65be>] xfs_log_reserve+0xfe/0x160 [xfs]
[ 8042.773184] [<ffffffffa02d25cb>] xfs_trans_reserve+0x9b/0x210 [xfs]
[ 8042.773202] [<ffffffffa02d28b7>] ? xfs_trans_alloc+0x97/0xb0 [xfs]
[ 8042.773221] [<ffffffffa02d80fa>] xfs_setattr+0x81a/0xa10 [xfs]
[ 8042.773239] [<ffffffffa02e3df6>] xfs_vn_setattr+0x16/0x20 [xfs]
[ 8042.773243] [<ffffffff8114de68>] notify_change+0x168/0x2d0
[ 8042.773247] [<ffffffff8115dc57>] utimes_common+0xd7/0x1b0
[ 8042.773252] [<ffffffff81292a3d>] ? _atomic_dec_and_lock+0x4d/0x80
[ 8042.773255] [<ffffffff8115ddc0>] do_utimes+0x90/0xf0
[ 8042.773259] [<ffffffff8115dece>] sys_utimensat+0x2e/0x80
[ 8042.773262] [<ffffffff8100af42>] system_call_fastpath+0x16/0x1b
What do you think?
Is it the delaylog? is it not stable?
Thank you
More information about the xfs
mailing list