Date: Thu, 11 Apr 2013 18:52:19 +0200 From: Adam Nowacki <nowakpl@platinum.linux.pl> To: freebsd-fs@freebsd.org Subject: ZFS slow reads for unallocated blocks Message-ID: <5166EA43.7050700@platinum.linux.pl>
next in thread | raw e-mail | index | archive | help
This one is quite weird - reads from files that were created and resized
with ftruncate (so no actual data on disk) are considerably slower and
use more CPU time than files with data. If compression is enabled this
will also affect files with long runs of zeroes as ZFS won't write any
data to disk in this case. There is no I/O on the pool during the read
tests - all fits into 10GB ARC.
FreeBSD storage 9.1-RELEASE FreeBSD 9.1-RELEASE #0: Sat Feb 23 15:51:26
UTC 2013 root@storage:/usr/obj/usr/src/sys/GENERIC amd64
Mem: 264M Active, 82M Inact, 12G Wired, 100M Cache, 13M Buf, 3279M Free
Swap: 5120M Total, 5120M Free
# zfs create -o atime=off -o recordsize=128k -o compression=off -o
mountpoint=/home/testfs home/testfs
--- truncated file:
# time truncate -s 1G /home/testfs/trunc1g
0.000u 0.000s 0:00.00 0.0% 0+0k 0+0io 0pf+0w
# time dd if=/home/testfs/trunc1g of=/dev/null bs=1024k
1024+0 records in
1024+0 records out
1073741824 bytes transferred in 0.434817 secs (2469410435 bytes/sec)
0.000u 0.435s 0:00.43 100.0% 26+2813k 0+0io 0pf+0w
# time dd if=/home/testfs/trunc1g of=/dev/null bs=16k
65536+0 records in
65536+0 records out
1073741824 bytes transferred in 3.809560 secs (281854564 bytes/sec)
0.000u 3.779s 0:03.81 98.9% 25+2755k 0+0io 0pf+0w
# time cat /home/testfs/trunc1g > /dev/null
0.070u 14.031s 0:14.19 99.3% 15+2755k 0+0io 0pf+0w
^^^^^^^ 14 seconds compared to 1 second for random data
--- file filled with zeroes:
# time dd if=/dev/zero of=/home/testfs/zero1g bs=1024k count=1024
1024+0 records in
1024+0 records out
1073741824 bytes transferred in 2.375426 secs (452020732 bytes/sec)
0.000u 0.525s 0:02.37 21.9% 23+2533k 1+1io 0pf+0w
# time dd if=/home/testfs/zero1g of=/dev/null bs=1024k
1024+0 records in
1024+0 records out
1073741824 bytes transferred in 0.199078 secs (5393571244 bytes/sec)
0.000u 0.200s 0:00.20 100.0% 26+2808k 0+0io 0pf+0w
# time dd if=/home/testfs/zero1g of=/dev/null bs=16k
65536+0 records in
65536+0 records out
1073741824 bytes transferred in 0.436472 secs (2460046434 bytes/sec)
0.015u 0.421s 0:00.43 100.0% 26+2813k 0+0io 0pf+0w
# time cat /home/testfs/zero1g > /dev/null
0.023u 1.156s 0:01.18 99.1% 15+2779k 0+0io 0pf+0w
--- file filled with random bytes:
# time dd if=/dev/random of=/home/testfs/random1g bs=1024k count=1024
1024+0 records in
1024+0 records out
1073741824 bytes transferred in 16.116569 secs (66623474 bytes/sec)
0.000u 13.214s 0:16.11 81.9% 25+2750k 0+1io 0pf+0w
# time dd if=/home/testfs/random1g of=/dev/null bs=1024k
1024+0 records in
1024+0 records out
1073741824 bytes transferred in 0.207115 secs (5184280044 bytes/sec)
0.000u 0.208s 0:00.20 100.0% 26+2808k 0+0io 0pf+0w
# time dd if=/home/testfs/random1g of=/dev/null bs=16k
65536+0 records in
65536+0 records out
1073741824 bytes transferred in 0.432518 secs (2482536705 bytes/sec)
0.023u 0.409s 0:00.43 97.6% 26+2828k 0+0io 0pf+0w
# time cat /home/testfs/random1g > /dev/null
0.031u 1.053s 0:01.08 100.0% 15+2770k 0+0io 0pf+0w
--- compression on:
# zfs create -o atime=off -o recordsize=128k -o compression=lzjb -o
mountpoint=/home/testfs home/testfs
--- file filled with zeroes:
# time dd if=/dev/zero of=/home/testfs/zero1g bs=1024k count=1024
1024+0 records in
1024+0 records out
1073741824 bytes transferred in 1.007765 secs (1065468404 bytes/sec)
0.000u 0.458s 0:01.01 44.5% 26+2880k 1+1io 0pf+0w
# time dd if=/home/testfs/zero1g of=/dev/null bs=1024k
1024+0 records in
1024+0 records out
1073741824 bytes transferred in 0.630737 secs (1702360431 bytes/sec)
0.000u 0.630s 0:00.63 100.0% 25+2742k 0+0io 0pf+0w
# time dd if=/home/testfs/zero1g of=/dev/null bs=16k
65536+0 records in
65536+0 records out
1073741824 bytes transferred in 4.089175 secs (262581530 bytes/sec)
0.015u 4.036s 0:04.09 98.7% 25+2758k 0+0io 0pf+0w
# time cat /home/testfs/zero1g > /dev/null
0.031u 15.863s 0:15.95 99.6% 15+2754k 0+0io 0pf+0w
^^^^^^^
--- it appears recordsize has a huge effect on this (recordsize=32k):
# zfs create -o atime=off -o recordsize=32k -o compression=off -o
mountpoint=/home/testfs home/testfs
# time truncate -s 1G testfs/trunc1g
0.000u 0.000s 0:00.01 0.0% 0+0k 1+0io 0pf+0w
# time cat /home/testfs/trunc1g > /dev/null
0.047u 5.842s 0:05.93 99.1% 15+2761k 0+0io 0pf+0w
^^^^^^
--- recordsize=4k:
# zfs create -o atime=off -o recordsize=4k -o compression=off -o
mountpoint=/home/testfs home/testfs
# time truncate -s 1G testfs/trunc1g
0.000u 0.000s 0:00.00 0.0% 0+0k 0+0io 0pf+0w
# time cat /home/testfs/trunc1g > /dev/null
0.047u 1.441s 0:01.52 97.3% 15+2768k 0+0io 0pf+0w
^^^^^^
Want to link to this message? Use this URL: <https://mail-archive.FreeBSD.org/cgi/mid.cgi?5166EA43.7050700>