2008-06-08

vdbench - disk I/O workload generator

There are several tools which allow to test performance of filesystems like Iozone, Bonnie, FileBench. There is also one unknown widely called vdbench. It is disk I/O workload generator written by Sun's employee, Henk Vandenbergh and used internally at Sun and its customers.

How does it differ from the others tools ? We'll see ... :-)

Vdbench, besides classical CLI has also GUI which simplifies its usage. However I am going to show how to use it via CLI. After downloading one need to install it. Vdbench has optional, -t, parameter which allows to specify target directory:

kruk:/tmp/vdbench# ./install_unix.sh -t /opt/vdbench
Sun Microsystems, Inc. ("Sun") ENTITLEMENT for SOFTWARE

Licensee/Company: Entity receiving Software.

Efective Date: Date Sun delivers the Software to You.

Software: Sun StorageTek vdbench 4.07

[...]

Please contact Sun Microsystems, Inc. 4150 Network Circle, Santa
Clara, California 95054 if you have questions.




Accept User License Agreement (yes/no): yes
08:51:47.887 plog(): execute(): tar -tf /tmp/vdbench/vdbench407.tar

********************************************************************************
[...]

Tool will expire on: sobota, kwiecień 25 2009, 23:27:38


********************************************************************************



Tool installation to /opt/vdbench successful

Now its time to write parameter file with description of needed workload. There are same examples within vdbench directory (example*). But let's begin with the following, simple one:

sd=sd1,lun=/vdb/file1
sd=sd2,lun=/vdb/file2
sd=sd3,lun=/vdb/file3
sd=sd4,lun=/vdb/file4

wd=rg-1,sd=sd*,rdpct=70,rhpct=0,whpct=0,xfersize=8k,seekpct=70

rd=rd_rg-1,wd=rg-1,interval=1,iorate=max,elapsed=30,forthreads=(64)

How to interpret that file ? For example:
sd - Storage Definition (where the I/O is going to/from - storage, disks, files)
wd - Workload Definition (precise definition of workload) - some explanations:
  • rdpct - read percentage; 70 means that 70% of time is spent on reading and the rest, 30%, on writing
  • xfersize - size of each I/O
  • seekpct - percentage of random seeks
rd - Run Definition (in general - which and for how long run Workload Definition)
Of course we need to create needed files:

kruk:/root# cd /opt/vdbench/
kruk:/opt/vdbench# mkdir /vdb
kruk:/opt/vdbench# mkfile 100m /vdb/file1
kruk:/opt/vdbench# mkfile 100m /vdb/file2
kruk:/opt/vdbench# mkfile 100m /vdb/file3
kruk:/opt/vdbench# mkfile 100m /vdb/file4

What I like in this tool is the ability to show IOPS in each second of test what gives excellent view of tested environment. Let's see the example:

kruk:/opt/vdbench# ./vdbench -f my-parm.cfg
[...]
interval i/o MB/sec bytes read resp resp resp cpu% cpu%
rate 1024**2 i/o pct time max stddev sys+usr sys
14:50:41.208 1 1770,85 13,83 8192 79,48 104,913 774,921 170,206 20,8 10,5
14:50:42.097 2 1600,90 12,51 8192 67,65 159,721 961,760 225,067 20,0 11,8
14:50:43.103 3 1302,75 10,18 8192 68,05 184,123 1439,223 262,792 13,7 8,0
14:50:44.085 4 1112,86 8,69 8192 68,20 219,451 1954,038 315,391 12,6 7,1
14:50:45.080 5 1210,84 9,46 8192 68,83 220,502 1511,942 322,902 12,0 7,8
14:50:46.078 6 1192,25 9,31 8192 70,59 213,559 1474,794 318,486 11,7 7,2
14:50:47.081 7 899,99 7,03 8192 70,48 253,603 1654,079 378,854 10,3 6,0
14:50:48.058 8 1251,91 9,78 8192 71,13 219,671 1831,191 340,373 11,8 7,5
14:50:49.049 9 1004,77 7,85 8192 68,77 251,295 1668,598 364,461 10,0 6,7
14:50:50.049 10 1124,07 8,78 8192 68,28 229,389 1804,713 329,042 10,5 6,5
14:50:51.047 11 1099,94 8,59 8192 68,47 236,588 1699,419 344,097 10,0 6,7
14:50:52.040 12 629,53 4,92 8192 69,45 265,482 1742,241 374,407 7,7 4,7
14:50:53.043 13 1042,71 8,15 8192 69,05 344,049 2308,431 532,435 8,8 6,0
14:50:54.042 14 1452,97 11,35 8192 68,11 174,344 2086,119 251,800 11,8 8,8
14:50:55.075 15 1175,48 9,18 8192 69,67 212,452 1504,912 312,161 9,8 6,8
14:50:56.046 16 1048,33 8,19 8192 68,92 227,462 1595,952 325,352 10,8 7,0
14:50:57.047 17 881,26 6,88 8192 68,19 264,582 1160,291 365,083 9,2 5,7
14:50:58.068 18 1023,81 8,00 8192 71,98 282,999 1757,541 435,796 12,3 6,5
14:50:59.056 19 1076,79 8,41 8192 71,47 218,663 1339,287 339,072 11,8 7,8
14:51:00.044 20 1177,03 9,20 8192 68,99 231,724 1469,797 339,442 11,2 7,2
14:51:01.037 21 1136,34 8,88 8192 72,33 221,309 1807,646 343,556 10,3 6,8
14:51:02.043 22 655,37 5,12 8192 69,91 279,581 1286,680 402,433 6,5 4,5
14:51:03.040 23 1022,76 7,99 8192 70,30 336,784 1886,443 511,220 9,8 6,3
14:51:04.047 24 1322,93 10,34 8192 70,74 198,405 1732,970 295,461 11,8 8,0
14:51:05.049 25 1028,04 8,03 8192 68,67 228,957 1436,083 321,115 9,7 6,7
14:51:06.039 26 1075,99 8,41 8192 69,78 241,907 1642,574 349,677 9,5 6,3
14:51:07.046 27 908,38 7,10 8192 70,23 248,514 1661,609 363,362 9,0 6,0
14:51:08.044 28 827,90 6,47 8192 70,35 331,738 1898,630 486,697 7,8 5,3
14:51:09.046 29 1208,92 9,44 8192 68,49 225,420 1581,279 321,723 10,9 7,2
14:51:10.042 30 1025,04 8,01 8192 70,23 239,669 1502,131 347,456 9,3 6,5
14:51:10.055 avg_2-30 1086,79 8,49 8192 69,51 234,502 2308,431 353,760 10,7 6,9

iostat during the run:

extended device statistics
r/s w/s kr/s kw/s wait actv wsvc_t asvc_t %w %b device
395.0 178.0 3160.0 1424.0 0.0 2.6 0.0 4.6 0 92 c1
395.0 178.0 3160.0 1424.0 0.0 2.6 0.0 4.6 1 92 c1t50060E8000444540d4
394.0 173.0 3152.1 1384.1 0.0 3.3 0.0 5.7 0 99 c3
394.0 173.0 3152.2 1384.1 0.0 3.3 0.0 5.7 1 99 c3t50060E8000444542d4
extended device statistics
r/s w/s kr/s kw/s wait actv wsvc_t asvc_t %w %b device
484.1 188.0 3872.8 1504.3 0.0 3.0 0.0 4.5 0 98 c1
484.1 188.0 3872.8 1504.3 0.0 3.0 0.0 4.5 1 98 c1t50060E8000444540d4
418.1 177.0 3344.7 1416.3 0.0 3.0 0.0 5.0 0 97 c3
418.1 177.0 3344.6 1416.3 0.0 3.0 0.0 5.0 1 97 c3t50060E8000444542d4

In OLTP environments the column i/o rate is one of the most important while in DSS world MB/sec is probably more important. "Ok", you say, "you have stable io rate. Nothing really interesting." Are you sure ? Can you show me another, non-commercial tool which shows the same: io rate in each second ? How about this example:

interval i/o MB/sec bytes read resp resp resp
rate 1024**2 i/o pct time max stddev
15:04:15.746 1 27558,72 215,30 8192 69,72 1,089 338,684 10,493
15:04:16.465 2 42955,58 335,59 8192 69,66 ,219 903,236 5,504
15:04:17.170 3 45265,34 353,64 8192 69,63 ,132 384,352 3,121
15:04:17.692 4 41596,08 324,97 8192 69,99 ,119 148,012 2,091
15:04:18.322 5 38974,35 304,49 8192 69,98 ,210 570,820 5,815
15:04:19.385 6 22774,35 177,92 8192 69,32 1,830 1040,743 22,121
15:04:20.565 7 28552,81 223,07 8192 69,48 1,651 1539,927 28,605
15:04:21.079 8 38379,22 299,84 8192 69,30 ,181 340,999 3,756
15:04:22.159 9 40825,13 318,95 8192 70,07 ,134 319,363 2,655
15:04:23.187 10 37296,62 291,38 8192 69,91 ,161 186,869 2,589
15:04:24.334 11 23630,10 184,61 8192 70,29 ,894 352,045 6,997
15:04:25.087 12 24689,14 192,88 8192 70,14 ,192 604,120 7,659
15:04:26.334 13 33136,76 258,88 8192 70,22 ,094 66,819 ,870
15:04:27.046 14 40521,35 316,57 8192 69,89 ,128 348,961 2,395
15:04:29.072 15 35763,25 279,40 8192 69,60 ,394 264,676 4,571
15:04:29.290 16 28473,31 222,45 8192 69,65 1,433 730,685 14,482
15:04:30.206 17 31505,71 246,14 8192 69,62 ,979 914,484 15,763
15:04:31.259 18 40196,17 314,03 8192 69,67 ,125 234,910 1,692
15:04:32.116 19 35458,59 277,02 8192 69,77 ,116 138,638 1,540
15:04:33.249 20 43064,86 336,44 8192 69,97 ,128 390,286 2,813
15:04:34.234 21 24776,40 193,57 8192 70,12 1,947 231,994 12,754
15:04:35.554 22 35134,31 274,49 8192 69,80 ,451 703,214 6,932
15:04:36.261 23 33361,52 260,64 8192 69,50 ,444 898,570 11,638
15:04:37.557 24 38474,73 300,58 8192 70,05 ,225 322,527 4,602
15:04:38.234 25 41275,28 322,46 8192 69,74 ,170 206,164 2,687
15:04:39.097 26 22927,25 179,12 8192 70,44 1,345 665,988 11,805
15:04:40.258 27 32228,28 251,78 8192 70,14 ,540 752,539 9,812
15:04:41.296 28 39111,23 305,56 8192 70,15 ,196 271,594 3,369
15:04:42.200 29 41695,78 325,75 8192 69,74 ,210 282,547 3,677
15:04:43.110 30 46167,28 360,68 8192 69,80 ,156 356,567 2,871
15:04:43.131 avg_2-30 35532,33 277,60 8192 69,84 ,420 1539,927 8,438

And iostat:

extended device statistics
r/s w/s kr/s kw/s wait actv wsvc_t asvc_t %w %b device
0.0 827.7 0.0 105947.0 0.0 34.9 0.0 42.2 0 100 c1
0.0 827.7 0.0 105944.1 0.0 34.9 0.0 42.2 1 100 c1t50060E8000444540d3
extended device statistics
r/s w/s kr/s kw/s wait actv wsvc_t asvc_t %w %b device
0.0 439.1 0.0 49615.6 0.0 12.1 0.0 27.5 0 45 c1
0.0 439.1 0.0 49615.6 0.0 12.1 0.0 27.5 1 45 c1t50060E8000444540d3
extended device statistics
r/s w/s kr/s kw/s wait actv wsvc_t asvc_t %w %b device
extended device statistics
r/s w/s kr/s kw/s wait actv wsvc_t asvc_t %w %b device
0.0 919.3 0.0 116434.0 0.0 26.9 0.0 29.3 0 85 c1
0.0 919.3 0.0 116434.2 0.0 26.9 0.0 29.3 1 85 c1t50060E8000444540d3

Quite interesting, isn't it ? "What did you change to get so high io rate", you might ask ? Hmmm, I am not sure if I want to reveal ... ;-)

Seriously: the first test was on Veritas File System while the second one on ZFS. Does it mean that ZFS is faster then VxFS ? I don't think so. But using vdbench you can watch two different nature of mentioned filesystems. If you look closer at ZFS you will see that there is no reads from filesystem. Why ? Vdbench parameter "rdpct=70" forces to generate 70% reads and 30% writes.
It is because intensive kernel memory usage in ZFS.

Another example: have a look at first vdbench output. It is interesting that io rate goes up and down. I tracked it down earlier and revealed that hardware array, which I had put the filesystems on, has some bizarre behaviour using RAID-5.

Anyway you can see that without any sophisticated (and expansive) tool you are able to bring to light new, performance related information about your storage and filesystem.

Vdbench was released to the public a few weeks ago so we can download it over here.