Re: [zfs-discuss] Filebench Performance is weird

Tue, 02 Mar 2010 01:20:06 -0800 

On 02/03/2010 08:38, Abdullah Al-Dahlawi wrote:

Greeting All
I am using Filebench benchmark in an "Interactive mode" to test ZFS performance with randomread wordload. 
My Filebench setting & run results are as follwos
------------------------------------------------------------------------------------------
filebench> set $filesize=5g
filebench> set $dir=/hdd/fs32k
filebench> set $iosize=32k
filebench> set $workingset=10m
filebench> set $function=generic
filebench> set $filesystem=zfs
filebench> run 100
 1062: 106.866: Creating/pre-allocating files and filesets
 1062: 106.867: File largefile1: mbytes=5120
 1062: 106.867: Re-using file largefile1.
 1062: 106.867: Creating file largefile1...
 1062: 108.612: Preallocated 1 of 1 of file largefile1 in 2 seconds
 1062: 108.612: waiting for fileset pre-allocation to finish
 1062: 108.612: Starting 1 rand-read instances
 1063: 109.617: Starting 1 rand-thread threads
 1062: 112.627: Running...
 1062: 213.627: Run took 100 seconds...
 1062: 213.628: Per-Operation Breakdown
rand-rate 0ops/s 0.0mb/s 0.0ms/op 0us/op-cpu rand-read1 41845ops/s *1307.7mb/s* 0.0ms/op 20us/op-cpu 

 1062: 213.628:
IO Summary: 4226337 ops, 41845.0 ops/s, (41845/0 r/w) 1307.7mb/s, 21us cpu/op, 0.0ms latency 
 1062: 213.628: Shutting down processes
---------------------------------------------------------------------------------------------
The output looks GREAT so far .... notice the 1307.7 mb/s

**** HOWEVER *****
When I run the SAME workload using Filebench "config file" in batch mode, the performance dropped significantly !!!!!!!! 

Here is my config file & filebench results.


# Copyright 2007 Sun Microsystems, Inc.  All rights reserved.
# Use is subject to license terms.
#
# ident    "%Z%%M%    %I%    %E% SMI"

DEFAULTS {
    runtime = 30;
        dir = /hdd/fs32k;
        $statsdir=/export/home/abdullah/bench.stat/woow87;
        stats = /export/home/abdullah/bench.stat;
    filesystem = zfs;
    description = "ZFS-RR-WS-10M";
}

CONFIG rr32k {
    function = generic;
    personality = randomread;
    filesize = 5g;
    iosize = 32k;
    nthreads = 1;
     workingset=10m;
}

And the Run result ....

abdul...@hp_hdx_16:/usr/benchmarks/filebench/config# filebench rrws10m
parsing profile for config: rr32k
Creating Client Script /export/home/abdullah/bench.stat/HP_HDX_16-zfs-rrws10m-Mar_2_2010-03h_10m_46s/rr32k/thisrun.f Running /export/home/abdullah/bench.stat/HP_HDX_16-zfs-rrws10m-Mar_2_2010-03h_10m_46s/rr32k/thisrun.f 
FileBench Version 1.4.4
 1147: 0.004: Random Read Version 2.0 IO personality successfully loaded
 1147: 0.004: Creating/pre-allocating files and filesets
 1147: 0.005: File largefile1: mbytes=5120
 1147: 0.005: Re-using file largefile1.
 1147: 0.005: Creating file largefile1...
 1147: 1.837: Preallocated 1 of 1 of file largefile1 in 2 seconds
 1147: 1.837: waiting for fileset pre-allocation to finish
1147: 1.837: Running '/usr/benchmarks/filebench/scripts/fs_flush zfs /hdd/fs32k' 1147: 1.845: Change dir to /export/home/abdullah/bench.stat/HP_HDX_16-zfs-rrws10m-Mar_2_2010-03h_10m_46s/rr32k 
 1147: 1.845: Starting 1 rand-read instances
 1149: 2.850: Starting 1 rand-thread threads
 1147: 5.860: Running...
 1147: 36.159: Run took 30 seconds...
 1147: 36.160: Per-Operation Breakdown
rand-rate 0ops/s 0.0mb/s 0.0ms/op 0us/op-cpu rand-read1 88ops/s *2.7mb/s** * 11.4ms/op 35us/op-cpu 

 1147: 36.160:
IO Summary: 2660 ops, 87.8 ops/s, (88/0 r/w) 2.7mb/s, 443us cpu/op, 11.4ms latency 
 1147: 36.160: Stats dump to file 'stats.rr32k.out'
 1147: 36.160: in statsdump stats.rr32k.out
 1147: 36.415: Shutting down processes
Generating html for /export/home/abdullah/bench.stat/HP_HDX_16-zfs-rrws10m-Mar_2_2010-03h_10m_46s file = /export/home/abdullah/bench.stat/HP_HDX_16-zfs-rrws10m-Mar_2_2010-03h_10m_46s/rr32k/stats.rr32k.out 
------------------------------------------------------------------------------------------------
The output for the same workload is disappointing , notice that the throughput dropped from 1307.7 mb/s to 2.7 mb/s !!!!!!!!!!!!!!!!!!!!!!1 

My ARC_max is 3G

Here is a snapshot of my arcstat output in case of high throughput ---
notice the 100% hits ratio


arcsz,read,hits,Hit%,miss,miss%,dhit,dh%,dmis,dm%,phit,ph%,pmis,pm%,mhit,mh%,mmis,mm%,mfug,mrug,
1G, 31M, 31M, 99,111K, 0, 28M, 99, 99K, 0, 2M, 99, 12K, 0, 1M, 98, 13K, 1, 43, 43, 1G,147K,145K, 99, 1K, 0, 14K, 99, 2, 0,131K, 99, 1K, 0, 0, 0, 0, 0, 0, 0, 1G,166K,166K, 100, 0, 0, 37K,100, 0, 0,128K,100, 0, 0, 0, 0, 0, 0, 0, 0, 1G, 42K, 42K, 100, 0, 0, 42K,100, 0, 0, 256,100, 0, 0, 0, 0, 0, 0, 0, 0, 1G, 42K, 42K, 100, 0, 0, 42K,100, 0, 0, 256,100, 0, 0, 0, 0, 0, 0, 0, 0, 1G, 42K, 42K, 100, 0, 0, 41K,100, 0, 0, 256,100, 0, 0, 0, 0, 0, 0, 0, 0, 1G, 42K, 42K, 100, 0, 0, 42K,100, 0, 0, 256,100, 0, 0, 0, 0, 0, 0, 0, 0, 1G, 42K, 42K, 100, 0, 0, 42K,100, 0, 0, 256,100, 0, 0, 0, 0, 0, 0, 0, 0, 1G, 42K, 42K, 100, 0, 0, 41K,100, 0, 0, 256,100, 0, 0, 0, 0, 0, 0, 0, 0, 1G, 42K, 42K, 100, 0, 0, 42K,100, 0, 0, 256,100, 0, 0, 10,100, 0, 0, 0, 0, 1G, 42K, 42K, 100, 0, 0, 42K,100, 0, 0, 256,100, 0, 0, 0, 0, 0, 0, 0, 0, 1G, 42K, 42K, 100, 0, 0, 42K,100, 0, 0, 256,100, 0, 0, 0, 0, 0, 0, 0, 0, 1G, 42K, 42K, 100, 0, 0, 42K,100, 0, 0, 256,100, 0, 0, 0, 0, 0, 0, 0, 0, 1G, 42K, 42K, 100, 0, 0, 42K,100, 0, 0, 256,100, 0, 0, 0, 0, 0, 0, 0, 0, 1G, 42K, 42K, 100, 0, 0, 42K,100, 0, 0, 256,100, 0, 0, 0, 0, 0, 0, 0, 0, 1G, 42K, 42K, 100, 0, 0, 42K,100, 0, 0, 256,100, 0, 0, 0, 0, 0, 0, 0, 0, 1G, 42K, 42K, 100, 0, 0, 41K,100, 0, 0, 256,100, 0, 0, 0, 0, 0, 0, 0, 0, 1G, 42K, 42K, 100, 0, 0, 41K,100, 0, 0, 256,100, 0, 0, 0, 0, 0, 0, 0, 0, 1G, 42K, 42K, 100, 0, 0, 42K,100, 0, 0, 256,100, 0, 0, 0, 0, 0, 0, 0, 0, 1G, 42K, 42K, 100, 0, 0, 42K,100, 0, 0, 256,100, 0, 0, 0, 0, 0, 0, 0, 0, 1G, 42K, 42K, 100, 0, 0, 42K,100, 0, 0, 256,100, 0, 0, 0, 0, 0, 0, 0, 0, 

and a snapshot in case of low throughput
notice the low hit ratio !!
arcsz,read,hits,Hit%,miss,miss%,dhit,dh%,dmis,dm%,phit,ph%,pmis,pm%,mhit,mh%,mmis,mm%,mfug,mrug,
1G, 3, 3, 100, 0, 0, 3,100, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 1G, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 1G, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 1G, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 1G, 40, 3, 7, 37, 92, 3, 7, 37, 92, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 1G, 113, 12, 10, 101, 89, 12, 10, 101, 89, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 1G, 105, 14, 13, 91, 86, 14, 13, 91, 86, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 1G, 108, 15, 13, 93, 86, 15, 13, 93, 86, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 1G, 99, 11, 11, 88, 88, 11, 11, 88, 88, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 1G, 103, 11, 10, 92, 89, 11, 10, 92, 89, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 1G, 101, 13, 12, 88, 87, 13, 12, 88, 87, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 1G, 107, 12, 11, 95, 88, 12, 11, 95, 88, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 1G, 99, 12, 12, 87, 87, 12, 12, 87, 87, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 1G, 100, 5, 5, 95, 95, 5, 5, 95, 95, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 1G, 114, 17, 14, 97, 85, 17, 14, 97, 85, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 1G, 106, 17, 16, 89, 83, 17, 16, 89, 83, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 1G, 107, 7, 6, 100, 93, 7, 6, 100, 93, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 1G, 100, 11, 11, 89, 89, 11, 11, 89, 89, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 1G, 99, 8, 8, 91, 91, 8, 8, 91, 91, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 1G, 101, 9, 8, 92, 91, 9, 8, 92, 91, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 1G, 101, 9, 8, 92, 91, 9, 8, 92, 91, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 


Any Feed Back !!!!!!!!!!!!



Ok!, you will get some feedback!!!! :)
In the batch mode it seems you have specified 'personality = randomread;' while you haven't in the interactive one. So it looks like whatever kind of workload you end up with in the interactive mode you get basically 100% hit in memory cache so your over 1GB/s is probably your limit of CPU/memory for a single thread. In the batch mode you are doing random reads and since you are limiting ARC to be less than your working set which is 5GB your hit ratio is low. You get 88 IOPS with 11.4ms average service time - are testing a single SATA disk? Because if you do then the numbers you get are perfectly fine. 

--
Robert Milkowski
http://milek.blogspot.com



_______________________________________________
zfs-discuss mailing list
zfs-discuss@opensolaris.org
http://mail.opensolaris.org/mailman/listinfo/zfs-discuss

Reply via email to