Hi Dave,
many thanks.
On 22/09/2015 23:27, Dave Chinner wrote:
Urk, the command should be "fsync", not "sync". Regardless, the
last bmap/fiemap pair shows something interesting:
bmap-vp:
/media/p6/testfile:
EXT: FILE-OFFSET BLOCK-RANGE AG AG-OFFSET TOTAL FLAGS
0: [0..127]: 96..223 0 (96..223) 128 00000
1: [128..2047]: hole 1920
2: [2048..2559]: 2144..2655 0 (2144..2655) 512 10000
fiemap -v:
/media/p6/testfile:
EXT: FILE-OFFSET BLOCK-RANGE TOTAL FLAGS
0: [0..127]: 96..223 128 0x0
1: [128..2047]: hole 1920
2: [2048..2175]: 2144..2271 128 0x800
3: [2176..2303]: 2272..2399 128 0x0
4: [2304..2559]: 2400..2655 256 0x801
Note that they are different - the former shows an unwritten extent
of 256k @ offset 1MB, the later shows that extent split by 64k of
data @ 1088k.
The bmap -vp output is incorrect - it is supposed to sync data first
and so should look the same as the fiemap output. Can you run this
test again, this time with s/sync/fsync so the files are clean when
bmap/fiemap are run? Can you run it a second time (umount/mkfs
again) but with fiemap run first? i.e '-c "fiemap -v" -c "bmap -vp" \'
instead of the original order?
Next, can you compile your kernel with CONFIG_XFS_DEBUG=y and rerun
the tests? Does anything interesting appear in dmesg during the test
run?
Done, see mkfs_output_2.txt attached
Not actually useful - I need to know what is happening inside the
unlinkat() call. I'm going to need a trace-cmd event dump of that
xfs_io command and the subsequent rm (at least for the first couple
of seconds of the rm). Please put the output file from the trace-cmd
record command on a tmpfs filesystem so it doesn't pollute the xfs
event trace ;)
I set some traces inside fs/namei.c do_unlinkat()
root[243] vpc24 (master) /home/angelo/xfstests
# ./start_xfs_test.sh
QA output created by 308
[ 144.822616] XFS (mmcblk0p5): Mounting V4 Filesystem
[ 145.074537] XFS (mmcblk0p5): Starting recovery (logdev: internal)
[ 145.107298] XFS (mmcblk0p5): Ending recovery (logdev: internal)
Silence is golden
[ 145.413606] do_unlinkat(): entering
[ 145.417124] do_unlinkat(): retry
[ 145.421156] do_unlinkat(): retry_delegate
[ 145.425920] do_unlinkat(): vfs_unlink returns 0
[ 145.430950] do_unlinkat(): exit2
At least that function "seems" to complete, but, as from my previous
message
looks like strace was not showing nothig over it.
I captured about 10 seconds of events after the "hang" on 308. Hope they
are
enough.
File is quite long, so you can read it from here:
http://sysam.it/~angelo/events.txt
bye,
--
Best regards,
Angelo Dureghello
# # xfs_io -f -c "pwrite 0 64k" -c fsync \
-c "bmap -vp" -c "fiemap -v" \
-c "falloc 1024k 256k" -c fsync \
-c "pwrite 1088k 64k" -c fsync \
-c "bmap -vp" -c "fiemap -v" \
/media/p6/testfile
# xfs_io -f -c "pwrite 0 64k" -c fsync \
> -c "bmap -vp" -c "fiemap -v" \
> -c "falloc 1024k 256k" -c fsync \
> -c "pwrite 1088k 64k" -c fsync \
> -c "bmap -vp" -c "fiemap -v" \
> /media/p6/testfile
wrote 65536/65536 bytes at offset 0
64 KiB, 16 ops; 0.0000 sec (10.271 MiB/sec and 2629.4166 ops/sec)
/media/p6/testfile:
EXT: FILE-OFFSET BLOCK-RANGE AG AG-OFFSET TOTAL FLAGS
0: [0..127]: 96..223 0 (96..223) 128 00000
/media/p6/testfile:
EXT: FILE-OFFSET BLOCK-RANGE TOTAL FLAGS
0: [0..127]: 96..223 128 0x1
wrote 65536/65536 bytes at offset 1114112
64 KiB, 16 ops; 0.0000 sec (11.857 MiB/sec and 3035.4771 ops/sec)
/media/p6/testfile:
EXT: FILE-OFFSET BLOCK-RANGE AG AG-OFFSET TOTAL FLAGS
0: [0..127]: 96..223 0 (96..223) 128 00000
1: [128..2047]: hole 1920
2: [2048..2175]: 2144..2271 0 (2144..2271) 128 10000
3: [2176..2303]: 2272..2399 0 (2272..2399) 128 00000
4: [2304..2559]: 2400..2655 0 (2400..2655) 256 10000
/media/p6/testfile:
EXT: FILE-OFFSET BLOCK-RANGE TOTAL FLAGS
0: [0..127]: 96..223 128 0x0
1: [128..2047]: hole 1920
2: [2048..2175]: 2144..2271 128 0x800
3: [2176..2303]: 2272..2399 128 0x0
4: [2304..2559]: 2400..2655 256 0x801
root[251] host ~
# mkfs.xfs -f /dev/mmcblk0p6
meta-data=/dev/mmcblk0p6 isize=256 agcount=4, agsize=551008 blks
= sectsz=512 attr=2, projid32bit=1
= crc=0 finobt=0
data = bsize=4096 blocks=2204032, imaxpct=25
= sunit=0 swidth=0 blks
naming =version 2 bsize=4096 ascii-ci=0 ftype=0
log =internal log bsize=4096 blocks=2560, version=2
= sectsz=512 sunit=0 blks, lazy-count=1
realtime =none extsz=4096 blocks=0, rtextents=0
root[252] host ~
# mount /dev/mmcblk0p6 /media/p6
[ 1000.531021] XFS (mmcblk0p6): Mounting V4 Filesystem
[ 1000.813339] XFS (mmcblk0p6): Ending clean mount
root[253] host ~
# xfs_io -f -c "pwrite 0 64k" -c fsync \
> -c "bmap -vp" -c "fiemap -v" \
> -c "falloc 1024k 256k" -c fsync \
> -c "pwrite 1088k 64k" -c fsync \
> -c "fiemap -v" -c "bmap -vp" \
> /media/p6/testfile
wrote 65536/65536 bytes at offset 0
64 KiB, 16 ops; 0.0000 sec (10.126 MiB/sec and 2592.3526 ops/sec)
/media/p6/testfile:
EXT: FILE-OFFSET BLOCK-RANGE AG AG-OFFSET TOTAL FLAGS
0: [0..127]: 96..223 0 (96..223) 128 00000
/media/p6/testfile:
EXT: FILE-OFFSET BLOCK-RANGE TOTAL FLAGS
0: [0..127]: 96..223 128 0x1
wrote 65536/65536 bytes at offset 1114112
64 KiB, 16 ops; 0.0000 sec (11.519 MiB/sec and 2948.7652 ops/sec)
/media/p6/testfile:
EXT: FILE-OFFSET BLOCK-RANGE TOTAL FLAGS
0: [0..127]: 96..223 128 0x0
1: [128..2047]: hole 1920
2: [2048..2175]: 2144..2271 128 0x800
3: [2176..2303]: 2272..2399 128 0x0
4: [2304..2559]: 2400..2655 256 0x801
/media/p6/testfile:
EXT: FILE-OFFSET BLOCK-RANGE AG AG-OFFSET TOTAL FLAGS
0: [0..127]: 96..223 0 (96..223) 128 00000
1: [128..2047]: hole 1920
2: [2048..2175]: 2144..2271 0 (2144..2271) 128 10000
3: [2176..2303]: 2272..2399 0 (2272..2399) 128 00000
4: [2304..2559]: 2400..2655 0 (2400..2655) 256 10000
root[254] host ~
_______________________________________________
xfs mailing list
xfs@xxxxxxxxxxx
http://oss.sgi.com/mailman/listinfo/xfs
