On 11/22/12 21:24, Dave Chinner wrote:
From: Dave Chinner<dchinner@xxxxxxxxxx>
The direct IO path can do a nested transaction reservation when
writing past the EOF. The first transaction is the append
transaction for setting the filesize at IO completion, but we can
also need a transaction for allocation of blocks. If the log is low
on space due to reservations and small log, the append transaction
can be granted after wating for space as the only active transaction
in the system. This then attempts a reservation for an allocation,
which there isn't space in the log for, and the reservation sleeps.
The result is that there is nothing left in the system to wake up
all the processes waiting for log space to come free.
The stack trace that shows this deadlock is relatively innocuous:
xlog_grant_head_wait
xlog_grant_head_check
xfs_log_reserve
xfs_trans_reserve
xfs_iomap_write_direct
__xfs_get_blocks
xfs_get_blocks_direct
do_blockdev_direct_IO
__blockdev_direct_IO
xfs_vm_direct_IO
generic_file_direct_write
xfs_file_dio_aio_writ
xfs_file_aio_write
do_sync_write
vfs_write
This was discovered on a filesystem with a log of only 10MB, and a
log stripe unit of 256k whih increased the base reservations by
512k. Hence a allocation transaction requires 1.2MB of log space to
be available instead of only 260k, and so greatly increased the
chance that there wouldn't be enough log space available for the
nested transaction to succeed. The key to reproducing it is this
mkfs command:
mkfs.xfs -f -d agcount=16,su=256k,sw=12 -l su=256k,size=2560b $SCRATCH_DEV
The test case was a 1000 fsstress processes running with random
freeze and unfreezes every few seconds. Thanks to Eryu Guan
(eguan@xxxxxxxxxx) for writing the test that found this on a system
with a somewhat unique default configuration....
cc:<stable@xxxxxxxxxxxxxxx>
Signed-off-by: Dave Chinner<dchinner@xxxxxxxxxx>
Signed-off-by: Dave Chinner<david@xxxxxxxxxxxxx>
---
This is a good work-around but with a bit more filesystem traffic (I
used your filesystem, fsstress and added the rm/copies from bug 922
because I knew it stressed the log), we can easily (couple hours) hang
the filesystem. There are many processes waiting for log space, here is
one in xfs_end_io():
PID: 20256 TASK: ffff88034c5b4140 CPU: 2 COMMAND: "fsstress"
#0 [ffff88034b8dd688] __schedule at ffffffff8142fbbe
#1 [ffff88034b8dd710] schedule at ffffffff8142ffe4
#2 [ffff88034b8dd720] xlog_grant_head_wait at ffffffffa05231f8 [xfs]
#3 [ffff88034b8dd790] xlog_grant_head_check at ffffffffa05233fc [xfs]
#4 [ffff88034b8dd7d0] xfs_log_reserve at ffffffffa05249c2 [xfs]
#5 [ffff88034b8dd830] xfs_trans_reserve at ffffffffa0520b43 [xfs]
#6 [ffff88034b8dd890] xfs_iomap_write_unwritten at ffffffffa04c874e [xfs]
#7 [ffff88034b8dd960] xfs_end_io at ffffffffa04b6e62 [xfs]
#8 [ffff88034b8dd990] xfs_finish_ioend_sync at ffffffffa04b6f81 [xfs]
#9 [ffff88034b8dd9a0] xfs_end_io_direct_write at ffffffffa04b6fd9 [xfs]
#10 [ffff88034b8dd9b0] dio_complete at ffffffff81184f8e
#11 [ffff88034b8dd9d0] do_blockdev_direct_IO at ffffffff81187578
#12 [ffff88034b8ddba0] __blockdev_direct_IO at ffffffff81187850
#13 [ffff88034b8ddbe0] xfs_vm_direct_IO at ffffffffa04b71a8 [xfs]
#14 [ffff88034b8ddc70] generic_file_direct_write at ffffffff810f8b9e
#15 [ffff88034b8ddce0] xfs_file_dio_aio_write at ffffffffa04bf9b4 [xfs]
#16 [ffff88034b8ddd80] xfs_file_aio_write at ffffffffa04bfeea [xfs]
#17 [ffff88034b8ddde0] do_sync_write at ffffffff8114cf83
#18 [ffff88034b8ddf00] vfs_write at ffffffff8114d5fe
#19 [ffff88034b8ddf30] sys_write at ffffffff8114d91d
#20 [ffff88034b8ddf80] system_call_fastpath at ffffffff814391e9
I still believe we should continue to push the AIL when the last push
was not enough to satisfy the first waiter, but that is just a minor
optimization so we do not have to wait until the next sync.
Now that Brian fixed the locking issue, the current hangs happen because
the sync worker is responsible to force the writing of the CIL but the
sync worker needs log space for the dummy record.
xfs_ail ffff88034c798640:
struct xfs_ail {
xa_mount = 0xffff88034fdd3000,
xa_task = 0xffff88034fe364c0,
xa_ail = {
next = 0xffff88034c798650, <- empty
prev = 0xffff88034c798650
},
The CIL is hold some entries,
xfs_cil_ctx ffff88035159b7c0
struct xfs_cil_ctx {
cil = 0xffff88034c159ec0,
sequence = 0x1de0,
start_lsn = 0x0,
commit_lsn = 0x0,
ticket = 0xffff8802b80c0e30,
nvecs = 0xa9,
space_used = 0x3d30,
busy_extents = {
next = 0xffff880333ae2f98,
prev = 0xffff880333ae2f98
},
lv_chain = 0x0,
log_cb = {
cb_next = 0x0,
cb_func = 0,
cb_arg = 0x0
},
committing = {
next = 0xffff88035159b820,
prev = 0xffff88035159b820
}
}
PID: 21396 TASK: ffff8802b816e080 CPU: 0 COMMAND: "kworker/0:0"
#0 [ffff8802b8361b78] __schedule at ffffffff8142fbbe
#1 [ffff8802b8361c00] schedule at ffffffff8142ffe4
#2 [ffff8802b8361c10] xlog_grant_head_wait at ffffffffa05231f8 [xfs]
#3 [ffff8802b8361c80] xlog_grant_head_check at ffffffffa05233fc [xfs]
#4 [ffff8802b8361cc0] xfs_log_reserve at ffffffffa05249c2 [xfs]
#5 [ffff8802b8361d20] xfs_trans_reserve at ffffffffa0520b43 [xfs]
#6 [ffff8802b8361d80] xfs_fs_log_dummy at ffffffffa04c28ae [xfs]
#7 [ffff8802b8361db0] xfs_log_worker at ffffffffa0525ea8 [xfs]
#8 [ffff8802b8361dd0] process_one_work at ffffffff8105afc6
#9 [ffff8802b8361e50] worker_thread at ffffffff8105be00
#10 [ffff8802b8361ec0] kthread at ffffffff81061b1b
#11 [ffff8802b8361f50] ret_from_fork at ffffffff8143913c
This patch is a good band aid, but we need to do a log rework as
discussed in:
http://oss.sgi.com/archives/xfs/2012-09/msg00020.html
--Mark.
_______________________________________________
xfs mailing list
xfs@xxxxxxxxxxx
http://oss.sgi.com/mailman/listinfo/xfs
