Monthly Archives: August 2015

2. SQL Server Performance Tuning study with HammerDB – Setup HammerDB

In the last post of this performance tuning study the setup of SQL Server has been done which is up and running now. The next part is to install the workload generator HammerDB. I decided to use HammerDB because its open source and implements the TPC-C benchmark defined by http://www.tpc.org/.

Setup HammerDB

I downloaded the version HammerDB-2.18-Win-x86-64 from the website and installed it to the C:\ drive.

The important part of HammerDB is to specify how you set it up and how you run it.

After launching HammerDB I switched to SQL Server and I choose TPC-C as the benchmark option.

Schema Build with 33 warehouses

I used 33 warehouses in this configuration. There is a reason why it is 33 and not for example 100. I will cover this later. The build run took a while.

HammerDB is installed and ready to run synthetic workloads.

Go webmin!

1. SQL Server Performance Tuning study with HammerDB – Setup SQL Server

Leave a reply

Based on a project with Thomas Kejser last year I started a new blog project to showcase a simple SQL Server performance tuning study. The target is to show some basic tuning options you could use to improve the SQL Server performance. I will make use of the 8PP to follow a scientific approach of tuning. But a database system like SQL Server 2014 SP 1 is a complex environment and I will cover only a few topics of the full monitor and performance tuning SQL Server provides.

The Use Case

Learn SQL Server basic tuning based on the 8PP approach!

Because I don’t have a good real world workload to tune I will use the tool HammerDB instead to generate a TPC-C workload. The focus of this study is the tuning itself so it’s not important which workload I use. I agree that the bottlenecks I will encounter may not represent real world workload ones.

The Setup

Hardware:

I will make use of Testverse as the hardware platform.

IMPORTANT!!!!! The active CPU cores have been set to 2 instead of 4.

The reason for this is that I believe there will be a point in time where the CPU will be a bottleneck. Then I will have a chance to show what influence more CPU power will have.

All tests will run on this machine so no network or other systems should be involved. Testverse is connected to the LAN and I will use RDP while running the tests. I keep an eye on the network part and consider this has little to no influence to the testing.

The OS drive Samsung 840 Basic is replaced by OCZ Agility 2 OCZSSD2-2AGTE120G.

The test SSD/PCIe devices will be installed with FOB performance in the beginning.

Operating System:

Windows 2012 R2 DataCenter Edition with all actual patches are installed (24.08.2015). Automatic updates will be deactivated for the test period. The Samsung EcoGreen F4 HDD is formatted with NTFS v3.1 with 512 bytes per Sector with 64k NTFS allocation unit size.

SQL Server 2014 SP1:

The SQL Server will be installed right now. The instance root is set to the Samsung EcoGreen F4 HDD (D:\}. One Requirement is .Net Framework 3.5 SP1 which can be installed via the “Add Roles and Features”.

Feature selection

I select only the features which are really needed for this study. So basically its the “Database Engine Service” and the “Management Tools”. Remember I changed the instance root to the D:\ drive.

Instance Configuration

In this case I make use of the default instance.

Server Configuration

I enable all SQL Server services and set the “Startup Type” to Automatic. The agent and browser services maybe used later.

Database Engine Configuration

I decided to use the Mixed Mode. Last time I used HammerDB it has been difficult to go with Windows authentication mode. The local administrator group will be SQL Server administrators as well. This is not best practices but will work.

Let’s check with the SQL Server Management Studio if we are able to connect and run a simple select.

Okay. SQL Server is up and running with the default configuration. I did not make changes to the default settings of SQL Server 2014 SP1 to make sure this test can be easily reproduced.

Go HammerDB!

Samsung 840 Basic- Baseline tests with FIO based on Windows 2012R2

Leave a reply

This post shows the baseline FOB raw peak performance of the Samsung 840 Basic which is installed in Testverse with Windows 2012R2. I used the “fio” (Flexible IO Tester) for this test. “fio” is my preferred tool to test SSD.

I make use of the Sample Windows “fio” job files. The specifications shows six metrics but I concentrate on (READ/WRITE bandwidth,Ran.READ/WRITE 4K). I tested with the job files:

fio-job-04 = fio random 1M write peak BW
fio-job-09 = fio random 1M read peak BW
fio-job-010 = fio random 4K read peak IOPS
fio-job-011 = fio random 4K write peak IOPS

Command line example:

set DISK=\\.\PhysicalDrive1
fio --output=job04.txt fio-job-09.ini

1 2	set DISK=\\.\PhysicalDrive1 fio --output=job04.txt fio-job-09.ini

Results:

fio-job-09 = fio random 1M read peak BW

fio-job-09: (g=0): rw=randrw, bs=1M-1M/1M-1M/1M-1M, ioengine=windowsaio, iodepth=32
...
fio-2.2.6
Starting 4 threads

fio-job-09: (groupid=0, jobs=4): err= 0: pid=2992: Thu Aug 27 10:56:46 2015
  Description  : [fio random 1M read peak BW]
  read : io=15980MB, bw=544344KB/s, iops=527, runt= 30061msec
    slat (usec): min=16, max=277, avg=19.82, stdev= 4.18
    clat (usec): min=240243, max=243733, avg=242011.38, stdev=468.21
     lat (usec): min=240265, max=243768, avg=242031.11, stdev=468.21
    clat percentiles (msec):
     |  1.00th=[  241],  5.00th=[  241], 10.00th=[  241], 20.00th=[  241],
     | 30.00th=[  243], 40.00th=[  243], 50.00th=[  243], 60.00th=[  243],
     | 70.00th=[  243], 80.00th=[  243], 90.00th=[  243], 95.00th=[  243],
     | 99.00th=[  243], 99.50th=[  243], 99.90th=[  243], 99.95th=[  243],
     | 99.99th=[  243]
    bw (KB  /s): min= 3130, max=159688, per=24.91%, avg=135622.19, stdev=28039.84
    lat (msec) : 250=100.40%
  cpu          : usr=0.00%, sys=0.00%, ctx=0, majf=0, minf=0
  IO depths    : 1=0.0%, 2=0.0%, 4=0.0%, 8=0.0%, 16=0.4%, 32=117.1%, >=64=0.0%
     submit    : 0=0.0%, 4=100.0%, 8=0.0%, 16=0.0%, 32=0.0%, 64=0.0%, >=64=0.0%
     complete  : 0=0.0%, 4=94.1%, 8=0.0%, 16=5.9%, 32=0.0%, 64=0.0%, >=64=0.0%
     issued    : total=r=15856/w=0/d=0, short=r=0/w=0/d=0, drop=r=0/w=0/d=0
     latency   : target=0, window=0, percentile=100.00%, depth=32

Run status group 0 (all jobs):
   READ: io=15980MB, aggrb=544343KB/s, minb=544343KB/s, maxb=544343KB/s, mint=30061msec, maxt=30061msec

fio-job-09: (g=0): rw=randrw, bs=1M-1M/1M-1M/1M-1M, ioengine=windowsaio, iodepth=32

...

fio-2.2.6

Starting 4 threads

fio-job-09: (groupid=0, jobs=4): err= 0: pid=2992: Thu Aug 27 10:56:46 2015

Description : [fio random 1M read peak BW]

read : io=15980MB, bw=544344KB/s, iops=527, runt= 30061msec

slat (usec): min=16, max=277, avg=19.82, stdev= 4.18

clat (usec): min=240243, max=243733, avg=242011.38, stdev=468.21

lat (usec): min=240265, max=243768, avg=242031.11, stdev=468.21

clat percentiles (msec):

| 1.00th=[ 241], 5.00th=[ 241], 10.00th=[ 241], 20.00th=[ 241],

| 30.00th=[ 243], 40.00th=[ 243], 50.00th=[ 243], 60.00th=[ 243],

| 70.00th=[ 243], 80.00th=[ 243], 90.00th=[ 243], 95.00th=[ 243],

| 99.00th=[ 243], 99.50th=[ 243], 99.90th=[ 243], 99.95th=[ 243],

| 99.99th=[ 243]

bw (KB /s): min= 3130, max=159688, per=24.91%, avg=135622.19, stdev=28039.84

lat (msec) : 250=100.40%

cpu : usr=0.00%, sys=0.00%, ctx=0, majf=0, minf=0

IO depths : 1=0.0%, 2=0.0%, 4=0.0%, 8=0.0%, 16=0.4%, 32=117.1%, >=64=0.0%

submit : 0=0.0%, 4=100.0%, 8=0.0%, 16=0.0%, 32=0.0%, 64=0.0%, >=64=0.0%

complete : 0=0.0%, 4=94.1%, 8=0.0%, 16=5.9%, 32=0.0%, 64=0.0%, >=64=0.0%

issued : total=r=15856/w=0/d=0, short=r=0/w=0/d=0, drop=r=0/w=0/d=0

latency : target=0, window=0, percentile=100.00%, depth=32

Run status group 0 (all jobs):

READ: io=15980MB, aggrb=544343KB/s, minb=544343KB/s, maxb=544343KB/s, mint=30061msec, maxt=30061msec

The following graph shows the IO bandwidth for each thread. The average bandwidth for all four threads is 531,59 MB/s

fio-job-04 = fio random 1M write peak BW

fio-job-04: (g=0): rw=randrw, bs=1M-1M/1M-1M/1M-1M, ioengine=windowsaio, iodepth=32
...
fio-2.2.6
Starting 4 threads

fio-job-04: (groupid=0, jobs=4): err= 0: pid=3512: Thu Aug 27 10:59:25 2015
  Description  : [fio random 1M write peak BW]
  write: io=4076.0MB, bw=137950KB/s, iops=130, runt= 30256msec
    slat (usec): min=34, max=1008, avg=60.17, stdev=16.69
    clat (msec): min=954, max=989, avg=971.46, stdev= 5.95
     lat (msec): min=954, max=989, avg=971.52, stdev= 5.95
    clat percentiles (msec):
     |  1.00th=[  955],  5.00th=[  963], 10.00th=[  963], 20.00th=[  963],
     | 30.00th=[  971], 40.00th=[  971], 50.00th=[  971], 60.00th=[  971],
     | 70.00th=[  971], 80.00th=[  979], 90.00th=[  979], 95.00th=[  979],
     | 99.00th=[  988], 99.50th=[  988], 99.90th=[  988], 99.95th=[  988],
     | 99.99th=[  988]
    bw (KB  /s): min= 2786, max=34312, per=23.50%, avg=32419.00, stdev=5774.87
    lat (msec) : 1000=101.62%
  cpu          : usr=0.00%, sys=0.00%, ctx=0, majf=0, minf=0
  IO depths    : 1=0.0%, 2=0.0%, 4=0.0%, 8=0.0%, 16=1.6%, 32=118.2%, >=64=0.0%
     submit    : 0=0.0%, 4=100.0%, 8=0.0%, 16=0.0%, 32=0.0%, 64=0.0%, >=64=0.0%
     complete  : 0=0.0%, 4=94.1%, 8=0.0%, 16=5.9%, 32=0.0%, 64=0.0%, >=64=0.0%
     issued    : total=r=0/w=3952/d=0, short=r=0/w=0/d=0, drop=r=0/w=0/d=0
     latency   : target=0, window=0, percentile=100.00%, depth=32

Run status group 0 (all jobs):
  WRITE: io=4076.0MB, aggrb=137950KB/s, minb=137950KB/s, maxb=137950KB/s, mint=30256msec, maxt=30256msec

fio-job-04: (g=0): rw=randrw, bs=1M-1M/1M-1M/1M-1M, ioengine=windowsaio, iodepth=32

...

fio-2.2.6

Starting 4 threads

fio-job-04: (groupid=0, jobs=4): err= 0: pid=3512: Thu Aug 27 10:59:25 2015

Description : [fio random 1M write peak BW]

write: io=4076.0MB, bw=137950KB/s, iops=130, runt= 30256msec

slat (usec): min=34, max=1008, avg=60.17, stdev=16.69

clat (msec): min=954, max=989, avg=971.46, stdev= 5.95

lat (msec): min=954, max=989, avg=971.52, stdev= 5.95

clat percentiles (msec):

| 1.00th=[ 955], 5.00th=[ 963], 10.00th=[ 963], 20.00th=[ 963],

| 30.00th=[ 971], 40.00th=[ 971], 50.00th=[ 971], 60.00th=[ 971],

| 70.00th=[ 971], 80.00th=[ 979], 90.00th=[ 979], 95.00th=[ 979],

| 99.00th=[ 988], 99.50th=[ 988], 99.90th=[ 988], 99.95th=[ 988],

| 99.99th=[ 988]

bw (KB /s): min= 2786, max=34312, per=23.50%, avg=32419.00, stdev=5774.87

lat (msec) : 1000=101.62%

cpu : usr=0.00%, sys=0.00%, ctx=0, majf=0, minf=0

IO depths : 1=0.0%, 2=0.0%, 4=0.0%, 8=0.0%, 16=1.6%, 32=118.2%, >=64=0.0%

submit : 0=0.0%, 4=100.0%, 8=0.0%, 16=0.0%, 32=0.0%, 64=0.0%, >=64=0.0%

complete : 0=0.0%, 4=94.1%, 8=0.0%, 16=5.9%, 32=0.0%, 64=0.0%, >=64=0.0%

issued : total=r=0/w=3952/d=0, short=r=0/w=0/d=0, drop=r=0/w=0/d=0

latency : target=0, window=0, percentile=100.00%, depth=32

Run status group 0 (all jobs):

WRITE: io=4076.0MB, aggrb=137950KB/s, minb=137950KB/s, maxb=137950KB/s, mint=30256msec, maxt=30256msec

The following graph shows the IO bandwidth for each thread. The average bandwidth for all four threads is 134,72MB/s.

fio-job-010 = fio random 4K read peak IOPS

fio-job-10: (g=0): rw=rw, bs=4K-4K/4K-4K/4K-4K, ioengine=windowsaio, iodepth=32
...
fio-2.2.6
Starting 4 threads

fio-job-10: (groupid=0, jobs=4): err= 0: pid=2476: Thu Aug 27 10:57:48 2015
  Description  : [fio random 4K read peak IOPS]
  read : io=11754MB, bw=401190KB/s, iops=100293, runt= 30000msec
    slat (usec): min=0, max=5516, avg= 3.86, stdev=10.14
    clat (usec): min=20, max=27916, avg=1218.14, stdev=136.43
     lat (usec): min=34, max=27925, avg=1221.99, stdev=136.65
    clat percentiles (usec):
     |  1.00th=[ 1020],  5.00th=[ 1096], 10.00th=[ 1112], 20.00th=[ 1160],
     | 30.00th=[ 1192], 40.00th=[ 1208], 50.00th=[ 1224], 60.00th=[ 1240],
     | 70.00th=[ 1256], 80.00th=[ 1256], 90.00th=[ 1288], 95.00th=[ 1352],
     | 99.00th=[ 1448], 99.50th=[ 1512], 99.90th=[ 1656], 99.95th=[ 1752],
     | 99.99th=[ 4080]
    bw (KB  /s): min=   12, max=101632, per=24.60%, avg=98694.52, stdev=12882.79
    lat (usec) : 50=0.01%, 100=0.01%, 250=0.02%, 500=0.06%, 750=0.08%
    lat (usec) : 1000=0.54%
    lat (msec) : 2=99.26%, 4=0.02%, 10=0.01%, 20=0.01%, 50=0.01%
  cpu          : usr=3.33%, sys=6.67%, ctx=0, majf=0, minf=0
  IO depths    : 1=0.0%, 2=0.0%, 4=0.0%, 8=0.0%, 16=0.1%, 32=116.7%, >=64=0.0%
     submit    : 0=0.0%, 4=100.0%, 8=0.0%, 16=0.0%, 32=0.0%, 64=0.0%, >=64=0.0%
     complete  : 0=0.0%, 4=94.1%, 8=0.0%, 16=5.9%, 32=0.0%, 64=0.0%, >=64=0.0%
     issued    : total=r=3008800/w=0/d=0, short=r=0/w=0/d=0, drop=r=0/w=0/d=0
     latency   : target=0, window=0, percentile=100.00%, depth=32

Run status group 0 (all jobs):
   READ: io=11754MB, aggrb=401189KB/s, minb=401189KB/s, maxb=401189KB/s, mint=30000msec, maxt=30000msec

fio-job-10: (g=0): rw=rw, bs=4K-4K/4K-4K/4K-4K, ioengine=windowsaio, iodepth=32

...

fio-2.2.6

Starting 4 threads

fio-job-10: (groupid=0, jobs=4): err= 0: pid=2476: Thu Aug 27 10:57:48 2015

Description : [fio random 4K read peak IOPS]

read : io=11754MB, bw=401190KB/s, iops=100293, runt= 30000msec

slat (usec): min=0, max=5516, avg= 3.86, stdev=10.14

clat (usec): min=20, max=27916, avg=1218.14, stdev=136.43

lat (usec): min=34, max=27925, avg=1221.99, stdev=136.65

clat percentiles (usec):

| 1.00th=[ 1020], 5.00th=[ 1096], 10.00th=[ 1112], 20.00th=[ 1160],

| 30.00th=[ 1192], 40.00th=[ 1208], 50.00th=[ 1224], 60.00th=[ 1240],

| 70.00th=[ 1256], 80.00th=[ 1256], 90.00th=[ 1288], 95.00th=[ 1352],

| 99.00th=[ 1448], 99.50th=[ 1512], 99.90th=[ 1656], 99.95th=[ 1752],

| 99.99th=[ 4080]

bw (KB /s): min= 12, max=101632, per=24.60%, avg=98694.52, stdev=12882.79

lat (usec) : 50=0.01%, 100=0.01%, 250=0.02%, 500=0.06%, 750=0.08%

lat (usec) : 1000=0.54%

lat (msec) : 2=99.26%, 4=0.02%, 10=0.01%, 20=0.01%, 50=0.01%

cpu : usr=3.33%, sys=6.67%, ctx=0, majf=0, minf=0

IO depths : 1=0.0%, 2=0.0%, 4=0.0%, 8=0.0%, 16=0.1%, 32=116.7%, >=64=0.0%

submit : 0=0.0%, 4=100.0%, 8=0.0%, 16=0.0%, 32=0.0%, 64=0.0%, >=64=0.0%

complete : 0=0.0%, 4=94.1%, 8=0.0%, 16=5.9%, 32=0.0%, 64=0.0%, >=64=0.0%

issued : total=r=3008800/w=0/d=0, short=r=0/w=0/d=0, drop=r=0/w=0/d=0

latency : target=0, window=0, percentile=100.00%, depth=32

Run status group 0 (all jobs):

READ: io=11754MB, aggrb=401189KB/s, minb=401189KB/s, maxb=401189KB/s, mint=30000msec, maxt=30000msec

The following graph shows the IOPS for each thread. The average IOPS for all four threads is 100293.

fio-job-011 = fio random 4K write peak IOPS

fio-job-11: (g=0): rw=rw, bs=4K-4K/4K-4K/4K-4K, ioengine=windowsaio, iodepth=32
...
fio-2.2.6
Starting 4 threads

fio-job-11: (groupid=0, jobs=4): err= 0: pid=1552: Thu Aug 27 10:58:36 2015
  Description  : [fio random 4K write peak IOPS]
  write: io=2615.8MB, bw=89269KB/s, iops=22313, runt= 30005msec
    slat (usec): min=0, max=224, avg= 2.34, stdev= 3.43
    clat (msec): min=1, max=52, avg= 5.70, stdev= 2.28
     lat (msec): min=1, max=52, avg= 5.70, stdev= 2.28
    clat percentiles (usec):
     |  1.00th=[ 5024],  5.00th=[ 5088], 10.00th=[ 5088], 20.00th=[ 5152],
     | 30.00th=[ 5152], 40.00th=[ 5152], 50.00th=[ 5216], 60.00th=[ 5344],
     | 70.00th=[ 5536], 80.00th=[ 5664], 90.00th=[ 6048], 95.00th=[ 7264],
     | 99.00th=[11456], 99.50th=[18816], 99.90th=[41728], 99.95th=[47872],
     | 99.99th=[52480]
    bw (KB  /s): min=   12, max=23808, per=24.59%, avg=21947.81, stdev=3177.28
    lat (msec) : 2=0.01%, 4=0.02%, 10=98.16%, 20=1.36%, 50=0.42%
    lat (msec) : 100=0.04%
  cpu          : usr=0.00%, sys=2.50%, ctx=0, majf=0, minf=0
  IO depths    : 1=0.0%, 2=0.0%, 4=0.0%, 8=0.0%, 16=0.1%, 32=115.7%, >=64=0.0%
     submit    : 0=0.0%, 4=100.0%, 8=0.0%, 16=0.0%, 32=0.0%, 64=0.0%, >=64=0.0%
     complete  : 0=0.0%, 4=94.1%, 8=0.0%, 16=5.9%, 32=0.0%, 64=0.0%, >=64=0.0%
     issued    : total=r=0/w=669504/d=0, short=r=0/w=0/d=0, drop=r=0/w=0/d=0
     latency   : target=0, window=0, percentile=100.00%, depth=32

Run status group 0 (all jobs):
  WRITE: io=2615.8MB, aggrb=89268KB/s, minb=89268KB/s, maxb=89268KB/s, mint=30005msec, maxt=30005msec

fio-job-11: (g=0): rw=rw, bs=4K-4K/4K-4K/4K-4K, ioengine=windowsaio, iodepth=32

...

fio-2.2.6

Starting 4 threads

fio-job-11: (groupid=0, jobs=4): err= 0: pid=1552: Thu Aug 27 10:58:36 2015

Description : [fio random 4K write peak IOPS]

write: io=2615.8MB, bw=89269KB/s, iops=22313, runt= 30005msec

slat (usec): min=0, max=224, avg= 2.34, stdev= 3.43

clat (msec): min=1, max=52, avg= 5.70, stdev= 2.28

lat (msec): min=1, max=52, avg= 5.70, stdev= 2.28

clat percentiles (usec):

| 1.00th=[ 5024], 5.00th=[ 5088], 10.00th=[ 5088], 20.00th=[ 5152],

| 30.00th=[ 5152], 40.00th=[ 5152], 50.00th=[ 5216], 60.00th=[ 5344],

| 70.00th=[ 5536], 80.00th=[ 5664], 90.00th=[ 6048], 95.00th=[ 7264],

| 99.00th=[11456], 99.50th=[18816], 99.90th=[41728], 99.95th=[47872],

| 99.99th=[52480]

bw (KB /s): min= 12, max=23808, per=24.59%, avg=21947.81, stdev=3177.28

lat (msec) : 2=0.01%, 4=0.02%, 10=98.16%, 20=1.36%, 50=0.42%

lat (msec) : 100=0.04%

cpu : usr=0.00%, sys=2.50%, ctx=0, majf=0, minf=0

IO depths : 1=0.0%, 2=0.0%, 4=0.0%, 8=0.0%, 16=0.1%, 32=115.7%, >=64=0.0%

submit : 0=0.0%, 4=100.0%, 8=0.0%, 16=0.0%, 32=0.0%, 64=0.0%, >=64=0.0%

complete : 0=0.0%, 4=94.1%, 8=0.0%, 16=5.9%, 32=0.0%, 64=0.0%, >=64=0.0%

issued : total=r=0/w=669504/d=0, short=r=0/w=0/d=0, drop=r=0/w=0/d=0

latency : target=0, window=0, percentile=100.00%, depth=32

Run status group 0 (all jobs):

WRITE: io=2615.8MB, aggrb=89268KB/s, minb=89268KB/s, maxb=89268KB/s, mint=30005msec, maxt=30005msec

The following graph shows the IOPS for each thread. The average IOPS for all four threads is 22313.

SanDisk ioMemory/Fusion-io ioDrive – Baseline tests with FIO based on Windows 2012R2

Leave a reply

This post shows the baseline FOB raw peak performance of the SanDisk PX600-1000 which is installed in Testverse with Windows 2012R2. I used the “fio” (Flexible IO Tester) for this test. “fio” is the preferred tool to test SanDisk/Fusion-IO ioDrive/ioMemory/SSD.

I make use of the Sample Windows “fio” job files. The specification shows four metrics (READ/WRITE bandwidth,Ran.READ/WRITE 4K) which I tested here with the job files:

fio-job-04 = fio random 1M write peak BW
fio-job-09 = fio random 1M read peak BW
fio-job-010 = fio random 4K read peak IOPS
fio-job-011 = fio random 4K write peak IOPS

Command line example:

set DISK=\\.\PhysicalDrive3
fio --output=job04.txt fio-job-09.ini

1 2	set DISK=\\.\PhysicalDrive3 fio --output=job04.txt fio-job-09.ini

Results:

fio-job-09 = fio random 1M read peak BW

fio-job-09: (g=0): rw=randrw, bs=1M-1M/1M-1M/1M-1M, ioengine=windowsaio, iodepth=32
...
fio-2.2.6
Starting 4 threads

fio-job-09: (groupid=0, jobs=4): err= 0: pid=2408: Thu Aug 27 08:33:00 2015
  Description  : [fio random 1M read peak BW]
  read : io=77804MB, bw=2590.2MB/s, iops=2585, runt= 30040msec
    slat (usec): min=31, max=851, avg=41.91, stdev= 5.82
    clat (usec): min=47894, max=69770, avg=49102.28, stdev=573.33
     lat (usec): min=47952, max=69807, avg=49143.92, stdev=572.40
    clat percentiles (usec):
     |  1.00th=[48384],  5.00th=[48384], 10.00th=[48384], 20.00th=[48896],
     | 30.00th=[48896], 40.00th=[48896], 50.00th=[48896], 60.00th=[49408],
     | 70.00th=[49408], 80.00th=[49408], 90.00th=[49408], 95.00th=[49920],
     | 99.00th=[49920], 99.50th=[49920], 99.90th=[50432], 99.95th=[57088],
     | 99.99th=[69120]
    bw (KB  /s): min= 3247, max=688128, per=24.58%, avg=652000.14, stdev=87758.17
    lat (msec) : 50=98.25%, 100=1.83%
  cpu          : usr=0.00%, sys=2.50%, ctx=0, majf=0, minf=0
  IO depths    : 1=0.0%, 2=0.0%, 4=0.0%, 8=0.0%, 16=0.1%, 32=116.8%, >=64=0.0%
     submit    : 0=0.0%, 4=100.0%, 8=0.0%, 16=0.0%, 32=0.0%, 64=0.0%, >=64=0.0%
     complete  : 0=0.0%, 4=94.1%, 8=0.0%, 16=5.9%, 32=0.0%, 64=0.0%, >=64=0.0%
     issued    : total=r=77680/w=0/d=0, short=r=0/w=0/d=0, drop=r=0/w=0/d=0
     latency   : target=0, window=0, percentile=100.00%, depth=32

Run status group 0 (all jobs):
   READ: io=77804MB, aggrb=2590.2MB/s, minb=2590.2MB/s, maxb=2590.2MB/s, mint=30040msec, maxt=30040msec

fio-job-09: (g=0): rw=randrw, bs=1M-1M/1M-1M/1M-1M, ioengine=windowsaio, iodepth=32

...

fio-2.2.6

Starting 4 threads

fio-job-09: (groupid=0, jobs=4): err= 0: pid=2408: Thu Aug 27 08:33:00 2015

Description : [fio random 1M read peak BW]

read : io=77804MB, bw=2590.2MB/s, iops=2585, runt= 30040msec

slat (usec): min=31, max=851, avg=41.91, stdev= 5.82

clat (usec): min=47894, max=69770, avg=49102.28, stdev=573.33

lat (usec): min=47952, max=69807, avg=49143.92, stdev=572.40

clat percentiles (usec):

| 1.00th=[48384], 5.00th=[48384], 10.00th=[48384], 20.00th=[48896],

| 30.00th=[48896], 40.00th=[48896], 50.00th=[48896], 60.00th=[49408],

| 70.00th=[49408], 80.00th=[49408], 90.00th=[49408], 95.00th=[49920],

| 99.00th=[49920], 99.50th=[49920], 99.90th=[50432], 99.95th=[57088],

| 99.99th=[69120]

bw (KB /s): min= 3247, max=688128, per=24.58%, avg=652000.14, stdev=87758.17

lat (msec) : 50=98.25%, 100=1.83%

cpu : usr=0.00%, sys=2.50%, ctx=0, majf=0, minf=0

IO depths : 1=0.0%, 2=0.0%, 4=0.0%, 8=0.0%, 16=0.1%, 32=116.8%, >=64=0.0%

submit : 0=0.0%, 4=100.0%, 8=0.0%, 16=0.0%, 32=0.0%, 64=0.0%, >=64=0.0%

complete : 0=0.0%, 4=94.1%, 8=0.0%, 16=5.9%, 32=0.0%, 64=0.0%, >=64=0.0%

issued : total=r=77680/w=0/d=0, short=r=0/w=0/d=0, drop=r=0/w=0/d=0

latency : target=0, window=0, percentile=100.00%, depth=32

Run status group 0 (all jobs):

READ: io=77804MB, aggrb=2590.2MB/s, minb=2590.2MB/s, maxb=2590.2MB/s, mint=30040msec, maxt=30040msec

The following graph shows the IO bandwidth for each thread. The average bandwidth for all four threads is 2590.2MB/s

fio-job-04 = fio random 1M write peak BW

fio-job-04: (g=0): rw=randrw, bs=1M-1M/1M-1M/1M-1M, ioengine=windowsaio, iodepth=32
...
fio-2.2.6
Starting 4 threads

fio-job-04: (groupid=0, jobs=4): err= 0: pid=3624: Thu Aug 27 08:35:24 2015
  Description  : [fio random 1M write peak BW]
  write: io=40252MB, bw=1337.1MB/s, iops=1333, runt= 30085msec
    slat (usec): min=47, max=1939, avg=78.08, stdev=12.99
    clat (msec): min=58, max=98, avg=95.13, stdev= 1.56
     lat (msec): min=58, max=98, avg=95.20, stdev= 1.56
    clat percentiles (usec):
     |  1.00th=[90624],  5.00th=[91648], 10.00th=[93696], 20.00th=[94720],
     | 30.00th=[94720], 40.00th=[94720], 50.00th=[95744], 60.00th=[95744],
     | 70.00th=[95744], 80.00th=[95744], 90.00th=[96768], 95.00th=[96768],
     | 99.00th=[97792], 99.50th=[97792], 99.90th=[97792], 99.95th=[98816],
     | 99.99th=[98816]
    bw (KB  /s): min= 3224, max=360448, per=24.55%, avg=336415.58, stdev=46192.80
    lat (msec) : 100=100.16%
  cpu          : usr=0.00%, sys=0.00%, ctx=0, majf=0, minf=0
  IO depths    : 1=0.0%, 2=0.0%, 4=0.0%, 8=0.0%, 16=0.2%, 32=116.8%, >=64=0.0%
     submit    : 0=0.0%, 4=100.0%, 8=0.0%, 16=0.0%, 32=0.0%, 64=0.0%, >=64=0.0%
     complete  : 0=0.0%, 4=94.1%, 8=0.0%, 16=5.9%, 32=0.0%, 64=0.0%, >=64=0.0%
     issued    : total=r=0/w=40128/d=0, short=r=0/w=0/d=0, drop=r=0/w=0/d=0
     latency   : target=0, window=0, percentile=100.00%, depth=32

Run status group 0 (all jobs):
  WRITE: io=40252MB, aggrb=1337.1MB/s, minb=1337.1MB/s, maxb=1337.1MB/s, mint=30085msec, maxt=30085msec

fio-job-04: (g=0): rw=randrw, bs=1M-1M/1M-1M/1M-1M, ioengine=windowsaio, iodepth=32

...

fio-2.2.6

Starting 4 threads

fio-job-04: (groupid=0, jobs=4): err= 0: pid=3624: Thu Aug 27 08:35:24 2015

Description : [fio random 1M write peak BW]

write: io=40252MB, bw=1337.1MB/s, iops=1333, runt= 30085msec

slat (usec): min=47, max=1939, avg=78.08, stdev=12.99

clat (msec): min=58, max=98, avg=95.13, stdev= 1.56

lat (msec): min=58, max=98, avg=95.20, stdev= 1.56

clat percentiles (usec):

| 1.00th=[90624], 5.00th=[91648], 10.00th=[93696], 20.00th=[94720],

| 30.00th=[94720], 40.00th=[94720], 50.00th=[95744], 60.00th=[95744],

| 70.00th=[95744], 80.00th=[95744], 90.00th=[96768], 95.00th=[96768],

| 99.00th=[97792], 99.50th=[97792], 99.90th=[97792], 99.95th=[98816],

| 99.99th=[98816]

bw (KB /s): min= 3224, max=360448, per=24.55%, avg=336415.58, stdev=46192.80

lat (msec) : 100=100.16%

cpu : usr=0.00%, sys=0.00%, ctx=0, majf=0, minf=0

IO depths : 1=0.0%, 2=0.0%, 4=0.0%, 8=0.0%, 16=0.2%, 32=116.8%, >=64=0.0%

submit : 0=0.0%, 4=100.0%, 8=0.0%, 16=0.0%, 32=0.0%, 64=0.0%, >=64=0.0%

complete : 0=0.0%, 4=94.1%, 8=0.0%, 16=5.9%, 32=0.0%, 64=0.0%, >=64=0.0%

issued : total=r=0/w=40128/d=0, short=r=0/w=0/d=0, drop=r=0/w=0/d=0

latency : target=0, window=0, percentile=100.00%, depth=32

Run status group 0 (all jobs):

WRITE: io=40252MB, aggrb=1337.1MB/s, minb=1337.1MB/s, maxb=1337.1MB/s, mint=30085msec, maxt=30085msec

The following graph shows the IO bandwidth for each thread. The average bandwidth for all four threads is 1337.1MB/s.

fio-job-010 = fio random 4K read peak IOPS

fio-job-10: (g=0): rw=rw, bs=4K-4K/4K-4K/4K-4K, ioengine=windowsaio, iodepth=32
...
fio-2.2.6
Starting 4 threads

fio-job-10: (groupid=0, jobs=4): err= 0: pid=4068: Thu Aug 27 08:31:58 2015
  Description  : [fio random 4K read peak IOPS]
  read : io=31824MB, bw=1060.9MB/s, iops=271557, runt= 30000msec
    slat (usec): min=2, max=156479, avg= 8.49, stdev=161.59
    clat (usec): min=3, max=848042, avg=379.80, stdev=4223.08
     lat (usec): min=19, max=855055, avg=388.30, stdev=4237.10
    clat percentiles (usec):
     |  1.00th=[   25],  5.00th=[   64], 10.00th=[  112], 20.00th=[  183],
     | 30.00th=[  207], 40.00th=[  225], 50.00th=[  245], 60.00th=[  266],
     | 70.00th=[  290], 80.00th=[  366], 90.00th=[  564], 95.00th=[  732],
     | 99.00th=[  836], 99.50th=[  876], 99.90th=[14272], 99.95th=[46336],
     | 99.99th=[195584]
    bw (KB  /s): min=   12, max=434432, per=24.66%, avg=267893.32, stdev=90770.13
    lat (usec) : 4=0.02%, 10=0.10%, 20=0.48%, 50=2.82%, 100=5.19%
    lat (usec) : 250=43.80%, 500=32.25%, 750=10.94%, 1000=4.06%
    lat (msec) : 2=0.13%, 4=0.06%, 10=0.04%, 20=0.03%, 50=0.04%
    lat (msec) : 100=0.02%, 250=0.02%, 500=0.01%, 750=0.01%, 1000=0.01%
  cpu          : usr=14.17%, sys=43.33%, ctx=0, majf=0, minf=0
  IO depths    : 1=0.0%, 2=0.0%, 4=0.0%, 8=0.0%, 16=0.1%, 32=116.4%, >=64=0.0%
     submit    : 0=0.0%, 4=100.0%, 8=0.0%, 16=0.0%, 32=0.0%, 64=0.0%, >=64=0.0%
     complete  : 0=0.0%, 4=94.1%, 8=0.0%, 16=5.9%, 32=0.1%, 64=0.0%, >=64=0.0%
     issued    : total=r=8146737/w=0/d=0, short=r=0/w=0/d=0, drop=r=0/w=0/d=0
     latency   : target=0, window=0, percentile=100.00%, depth=32

Run status group 0 (all jobs):
   READ: io=31824MB, aggrb=1060.9MB/s, minb=1060.9MB/s, maxb=1060.9MB/s, mint=30000msec, maxt=30000msec

fio-job-10: (g=0): rw=rw, bs=4K-4K/4K-4K/4K-4K, ioengine=windowsaio, iodepth=32

...

fio-2.2.6

Starting 4 threads

fio-job-10: (groupid=0, jobs=4): err= 0: pid=4068: Thu Aug 27 08:31:58 2015

Description : [fio random 4K read peak IOPS]

read : io=31824MB, bw=1060.9MB/s, iops=271557, runt= 30000msec

slat (usec): min=2, max=156479, avg= 8.49, stdev=161.59

clat (usec): min=3, max=848042, avg=379.80, stdev=4223.08

lat (usec): min=19, max=855055, avg=388.30, stdev=4237.10

clat percentiles (usec):

| 1.00th=[ 25], 5.00th=[ 64], 10.00th=[ 112], 20.00th=[ 183],

| 30.00th=[ 207], 40.00th=[ 225], 50.00th=[ 245], 60.00th=[ 266],

| 70.00th=[ 290], 80.00th=[ 366], 90.00th=[ 564], 95.00th=[ 732],

| 99.00th=[ 836], 99.50th=[ 876], 99.90th=[14272], 99.95th=[46336],

| 99.99th=[195584]

bw (KB /s): min= 12, max=434432, per=24.66%, avg=267893.32, stdev=90770.13

lat (usec) : 4=0.02%, 10=0.10%, 20=0.48%, 50=2.82%, 100=5.19%

lat (usec) : 250=43.80%, 500=32.25%, 750=10.94%, 1000=4.06%

lat (msec) : 2=0.13%, 4=0.06%, 10=0.04%, 20=0.03%, 50=0.04%

lat (msec) : 100=0.02%, 250=0.02%, 500=0.01%, 750=0.01%, 1000=0.01%

cpu : usr=14.17%, sys=43.33%, ctx=0, majf=0, minf=0

IO depths : 1=0.0%, 2=0.0%, 4=0.0%, 8=0.0%, 16=0.1%, 32=116.4%, >=64=0.0%

submit : 0=0.0%, 4=100.0%, 8=0.0%, 16=0.0%, 32=0.0%, 64=0.0%, >=64=0.0%

complete : 0=0.0%, 4=94.1%, 8=0.0%, 16=5.9%, 32=0.1%, 64=0.0%, >=64=0.0%

issued : total=r=8146737/w=0/d=0, short=r=0/w=0/d=0, drop=r=0/w=0/d=0

latency : target=0, window=0, percentile=100.00%, depth=32

Run status group 0 (all jobs):

READ: io=31824MB, aggrb=1060.9MB/s, minb=1060.9MB/s, maxb=1060.9MB/s, mint=30000msec, maxt=30000msec

The following graph shows the IOPS for each thread. The average IOPS for all four threads is 271557.

fio-job-011 = fio random 4K write peak IOPS

fio-job-11: (g=0): rw=rw, bs=4K-4K/4K-4K/4K-4K, ioengine=windowsaio, iodepth=32
...
fio-2.2.6
Starting 4 threads

fio-job-11: (groupid=0, jobs=4): err= 0: pid=1240: Thu Aug 27 08:33:57 2015
  Description  : [fio random 4K write peak IOPS]
  write: io=33344MB, bw=1111.7MB/s, iops=284429, runt= 30011msec
    slat (usec): min=2, max=4307, avg= 5.54, stdev= 6.99
    clat (usec): min=3, max=215195, avg=387.92, stdev=257.62
     lat (usec): min=23, max=215201, avg=393.44, stdev=257.85
    clat percentiles (usec):
     |  1.00th=[  153],  5.00th=[  193], 10.00th=[  215], 20.00th=[  247],
     | 30.00th=[  278], 40.00th=[  314], 50.00th=[  366], 60.00th=[  430],
     | 70.00th=[  482], 80.00th=[  524], 90.00th=[  564], 95.00th=[  620],
     | 99.00th=[  764], 99.50th=[  828], 99.90th=[ 1080], 99.95th=[ 1560],
     | 99.99th=[ 4704]
    bw (KB  /s): min=   12, max=398720, per=24.70%, avg=281036.42, stdev=53668.79
    lat (usec) : 4=0.01%, 10=0.01%, 20=0.01%, 50=0.02%, 100=0.17%
    lat (usec) : 250=21.07%, 500=53.12%, 750=24.38%, 1000=1.11%
    lat (msec) : 2=0.10%, 4=0.02%, 10=0.01%, 20=0.01%, 50=0.01%
    lat (msec) : 100=0.01%, 250=0.01%
  cpu          : usr=13.33%, sys=45.00%, ctx=0, majf=0, minf=0
  IO depths    : 1=0.0%, 2=0.0%, 4=0.0%, 8=0.0%, 16=0.1%, 32=116.8%, >=64=0.0%
     submit    : 0=0.0%, 4=100.0%, 8=0.0%, 16=0.0%, 32=0.0%, 64=0.0%, >=64=0.0%
     complete  : 0=0.0%, 4=94.1%, 8=0.0%, 16=5.9%, 32=0.1%, 64=0.0%, >=64=0.0%
     issued    : total=r=0/w=8536005/d=0, short=r=0/w=0/d=0, drop=r=0/w=0/d=0
     latency   : target=0, window=0, percentile=100.00%, depth=32

Run status group 0 (all jobs):
  WRITE: io=33344MB, aggrb=1111.7MB/s, minb=1111.7MB/s, maxb=1111.7MB/s, mint=30011msec, maxt=30011msec

fio-job-11: (g=0): rw=rw, bs=4K-4K/4K-4K/4K-4K, ioengine=windowsaio, iodepth=32

...

fio-2.2.6

Starting 4 threads

fio-job-11: (groupid=0, jobs=4): err= 0: pid=1240: Thu Aug 27 08:33:57 2015

Description : [fio random 4K write peak IOPS]

write: io=33344MB, bw=1111.7MB/s, iops=284429, runt= 30011msec

slat (usec): min=2, max=4307, avg= 5.54, stdev= 6.99

clat (usec): min=3, max=215195, avg=387.92, stdev=257.62

lat (usec): min=23, max=215201, avg=393.44, stdev=257.85

clat percentiles (usec):

| 1.00th=[ 153], 5.00th=[ 193], 10.00th=[ 215], 20.00th=[ 247],

| 30.00th=[ 278], 40.00th=[ 314], 50.00th=[ 366], 60.00th=[ 430],

| 70.00th=[ 482], 80.00th=[ 524], 90.00th=[ 564], 95.00th=[ 620],

| 99.00th=[ 764], 99.50th=[ 828], 99.90th=[ 1080], 99.95th=[ 1560],

| 99.99th=[ 4704]

bw (KB /s): min= 12, max=398720, per=24.70%, avg=281036.42, stdev=53668.79

lat (usec) : 4=0.01%, 10=0.01%, 20=0.01%, 50=0.02%, 100=0.17%

lat (usec) : 250=21.07%, 500=53.12%, 750=24.38%, 1000=1.11%

lat (msec) : 2=0.10%, 4=0.02%, 10=0.01%, 20=0.01%, 50=0.01%

lat (msec) : 100=0.01%, 250=0.01%

cpu : usr=13.33%, sys=45.00%, ctx=0, majf=0, minf=0

IO depths : 1=0.0%, 2=0.0%, 4=0.0%, 8=0.0%, 16=0.1%, 32=116.8%, >=64=0.0%

submit : 0=0.0%, 4=100.0%, 8=0.0%, 16=0.0%, 32=0.0%, 64=0.0%, >=64=0.0%

complete : 0=0.0%, 4=94.1%, 8=0.0%, 16=5.9%, 32=0.1%, 64=0.0%, >=64=0.0%

issued : total=r=0/w=8536005/d=0, short=r=0/w=0/d=0, drop=r=0/w=0/d=0

latency : target=0, window=0, percentile=100.00%, depth=32

Run status group 0 (all jobs):

WRITE: io=33344MB, aggrb=1111.7MB/s, minb=1111.7MB/s, maxb=1111.7MB/s, mint=30011msec, maxt=30011msec

The following graph shows the IOPS for each thread. The average IOPS for all four threads is 284429.

FIO (Flexible I/O Tester) Part8 – Interpret and understand the result/output

Leave a reply

The result/output of “fio” can be overwhelming because this decent tool does a lot for you. Your job is to feed “fio” with the right options and then interpret the result/output. This posting will help you to understand the result/output in detail. I know it’s difficult to read but I am limited by the WordPress design here a little bit and may improve it in the future.

The official documentation

The HOWTO provides some insights about the result/output of “fio”. I copy&paste some parts of the HOWTO and give you some more details or summarize other parts.

Output while running

fio spits out a lot of output. While running, fio will display the

status of the jobs created. An example of that would be:

Threads: 1: [_r] [24.8% done] [ 13509/ 8334 kb/s] [eta 00h:01m:31s]

The characters inside the square brackets denote the current status of

each thread. The possible values (in typical life cycle order) are:

Idle	Run	Description
P		Thread setup, but not started.
C		Thread created.
I		Thread initialized, waiting or generating necessary data.
	p	Thread running pre-reading file(s).
	R	Running, doing sequential reads.
	r	Running, doing random reads.
	W	Running, doing sequential writes.
	w	Running, doing random writes.
	M	Running, doing mixed sequential reads/writes.
	m	Running, doing mixed random reads/writes.
	F	Running, currently waiting for fsync()
	f	Running, finishing up (writing IO logs, etc)
	V	Running, doing verification of written data.
E		Thread exited, not reaped by main thread yet.
_		Thread reaped, or
X		Thread reaped, exited with an error.
K		Thread reaped, exited due to signal.

Job overview output

This will give you an overview about the jobs and the option used. It’s useful to check the heading if you receive only the results of a run but not the command line call or job file.

job-1: (g=0): rw=read, bs=4K-4K/4K-4K/4K-4K, ioengine=sync, iodepth=1

job-2: (g=0): rw=read, bs=4K-4K/4K-4K/4K-4K, ioengine=sync, iodepth=1

fio-2.2.9-26-g669e

Starting 2 processes

Data direction output

All details for each data direction will be shown here. Most important numbers are:

io=
bw=
iops=
issued =
lat =

Details inside the box.

When fio is done (or interrupted by ctrl-c), it will show the data for

each thread, group of threads, and disks in that order. For each data

direction, the output looks like:

Client1 (g=0): err= 0:

write: io= 32MB, bw= 666KB/s, iops=89 , runt= 50320msec

slat (msec): min= 0, max= 136, avg= 0.03, stdev= 1.92

clat (msec): min= 0, max= 631, avg=48.50, stdev=86.82

bw (KB/s) : min= 0, max= 1196, per=51.00%, avg=664.02, stdev=681.68

cpu : usr=1.49%, sys=0.25%, ctx=7969, majf=0, minf=17

IO depths : 1=0.1%, 2=0.3%, 4=0.5%, 8=99.0%, 16=0.0%, 32=0.0%, >32=0.0%

submit : 0=0.0%, 4=100.0%, 8=0.0%, 16=0.0%, 32=0.0%, 64=0.0%, >=64=0.0%

complete : 0=0.0%, 4=100.0%, 8=0.0%, 16=0.0%, 32=0.0%, 64=0.0%, >=64=0.0%

issued r/w: total=0/32768, short=0/0

lat (msec): 2=1.6%, 4=0.0%, 10=3.2%, 20=12.8%, 50=38.4%, 100=24.8%,

lat (msec): 250=15.2%, 500=0.0%, 750=0.0%, 1000=0.0%, >=2048=0.0%

io= Number of megabytes io performed

bw= Average bandwidth rate

iops= Average IOs performed per second

runt= The runtime of that thread

slat= Submission latency (avg being the average, stdev being the

standard deviation). This is the time it took to submit

the io. For sync io, the slat is really the completion

latency, since queue/complete is one operation there. This

value can be in milliseconds or microseconds, fio will choose

the most appropriate base and print that. In the example

above, milliseconds is the best scale. Note: in --minimal mode

latencies are always expressed in microseconds.

clat= Completion latency. Same names as slat, this denotes the

time from submission to completion of the io pieces. For

sync io, clat will usually be equal (or very close) to 0,

as the time from submit to complete is basically just

CPU time (io has already been done, see slat explanation).

bw= Bandwidth. Same names as the xlat stats, but also includes

an approximate percentage of total aggregate bandwidth

this thread received in this group. This last value is

only really useful if the threads in this group are on the

same disk, since they are then competing for disk access.

cpu= CPU usage. User and system time, along with the number

of context switches this thread went through, usage of

system and user time, and finally the number of major

and minor page faults.

IO depths= The distribution of io depths over the job life time. The

numbers are divided into powers of 2, so for example the

16= entries includes depths up to that value but higher

than the previous entry. In other words, it covers the

range from 16 to 31.

IO submit= How many pieces of IO were submitting in a single submit

call. Each entry denotes that amount and below, until

the previous entry - eg, 8=100% mean that we submitted

anywhere in between 5-8 ios per submit call.

IO complete= Like the above submit number, but for completions instead.

IO issued= The number of read/write requests issued, and how many

of them were short.

IO latencies= The distribution of IO completion latencies. This is the

time from when IO leaves fio and when it gets completed.

The numbers follow the same pattern as the IO depths,

meaning that 2=1.6% means that 1.6% of the IO completed

within 2 msecs, 20=12.8% means that 12.8% of the IO

took more than 10 msecs, but less than (or equal to) 20 msecs.

Group statistics

After each client has been listed, the group statistics are printed. They

will look like this:

Run status group 0 (all jobs):

READ: io=64MB, aggrb=22178, minb=11355, maxb=11814, mint=2840msec, maxt=2955msec

WRITE: io=64MB, aggrb=1302, minb=666, maxb=669, mint=50093msec, maxt=50320msec

For each data direction, it prints:

io= Number of megabytes io performed.

aggrb= Aggregate bandwidth of threads in this group.

minb= The minimum average bandwidth a thread saw.

maxb= The maximum average bandwidth a thread saw.

mint= The smallest runtime of the threads in that group.

maxt= The longest runtime of the threads in that group.

Disk statistics

Disk stats (read/write):

sda: ios=16398/16511, merge=30/162, ticks=6853/819634, in_queue=826487, util=100.00%

Each value is printed for both reads and writes, with reads first. The

numbers denote:

ios= Number of ios performed by all groups.

merge= Number of merges io the io scheduler.

ticks= Number of ticks we kept the disk busy.

io_queue= Total time spent in the disk queue.

util= The disk utilization. A value of 100% means we kept the disk

busy constantly, 50% would be a disk idling half of the time.

Example: Interpret the result/output of SanDisk PX600-1000 and Samsung EVO 840

I ran the linux raw peak performance test: job-fio-11.ini which is included in the “fio” sample linux files on Testverse.

[global]
readwrite=rw
rwmixread=0
blocksize=4K
ioengine=libaio
numjobs=4
thread=1
direct=1
iodepth=32
iodepth_batch=16
iodepth_batch_complete=16
group_reporting=1
ramp_time=5
norandommap=1
description=fio random 4K write peak IOPS
time_based=1
runtime=30
randrepeat=0
write_bw_log=fio-job-11
write_lat_log=fio-job-11
write_iops_log=fio-job-11

[fio-job-11]
filename=${DISK}        ; example /dev/fioa
cpus_allowed=1-4

[global]

readwrite=rw

rwmixread=0

blocksize=4K

ioengine=libaio

numjobs=4

thread=1

direct=1

iodepth=32

iodepth_batch=16

iodepth_batch_complete=16

group_reporting=1

ramp_time=5

norandommap=1

description=fio random 4K write peak IOPS

time_based=1

runtime=30

randrepeat=0

write_bw_log=fio-job-11

write_lat_log=fio-job-11

write_iops_log=fio-job-11

[fio-job-11]

filename=${DISK} ; example /dev/fioa

cpus_allowed=1-4

This means a 4K random write test to show the peak 4K write IOPS.

I invoked the script:

sudo DISK=/dev/fioa fio fio-job-11.ini

1	sudo DISK=/dev/fioa fio fio-job-11.ini

sudo DISK=/dev/sda fio fio-job-11.ini

1	sudo DISK=/dev/sda fio fio-job-11.ini

Result for SanDisk PX600-1000:

fio-job-11: (g=0): rw=rw, bs=4K-4K/4K-4K/4K-4K, ioengine=libaio, iodepth=32

...

fio-2.2.9-26-g669e

Starting 4 threads

fio-job-11: (groupid=0, jobs=4): err= 0: pid=2377: Sun Aug 23 12:56:42 2015

Description : [fio random 4K write peak IOPS]

write: io=41119MB, bw=1370.5MB/s, iops=350728, runt= 30013msec

slat (usec): min=11, max=230, avg=15.62, stdev= 1.79

clat (usec): min=20, max=13505, avg=344.55, stdev=224.87

lat (usec): min=66, max=13523, avg=360.23, stdev=224.84

clat percentiles (usec):

| 1.00th=[ 262], 5.00th=[ 262], 10.00th=[ 262], 20.00th=[ 266],

| 30.00th=[ 266], 40.00th=[ 270], 50.00th=[ 274], 60.00th=[ 274],

| 70.00th=[ 278], 80.00th=[ 282], 90.00th=[ 374], 95.00th=[ 1020],

| 99.00th=[ 1192], 99.50th=[ 1208], 99.90th=[ 1256], 99.95th=[ 1272],

| 99.99th=[ 1304]

bw (KB /s): min= 12, max=356608, per=24.60%, avg=345090.77, stdev=45012.87

lat (usec) : 50=0.01%, 100=0.01%, 250=0.24%, 500=91.01%, 750=0.04%

lat (usec) : 1000=3.31%

lat (msec) : 2=5.39%, 20=0.01%

cpu : usr=5.66%, sys=12.09%, ctx=2783241, majf=0, minf=32689

IO depths : 1=0.0%, 2=0.0%, 4=0.0%, 8=0.0%, 16=0.1%, 32=116.7%, >=64=0.0%

submit : 0=0.0%, 4=0.0%, 8=0.0%, 16=100.0%, 32=0.0%, 64=0.0%, >=64=0.0%

complete : 0=0.0%, 4=0.0%, 8=0.0%, 16=100.0%, 32=0.0%, 64=0.0%, >=64=0.0%

issued : total=r=0/w=10526416/d=0, short=r=0/w=0/d=0, drop=r=0/w=0/d=0

latency : target=0, window=0, percentile=100.00%, depth=32

Run status group 0 (all jobs):

WRITE: io=41119MB, aggrb=1370.5MB/s, minb=1370.5MB/s, maxb=1370.5MB/s, mint=30013msec, maxt=30013msec

Disk stats (read/write):

fioa: ios=71/767604, merge=0/0, ticks=0/259476, in_queue=256816, util=94.63%

Result for Samsung EVO 840:

fio-job-11: (g=0): rw=rw, bs=4K-4K/4K-4K/4K-4K, ioengine=libaio, iodepth=32
...
fio-2.2.9-26-g669e
Starting 4 threads

fio-job-11: (groupid=0, jobs=4): err= 0: pid=2881: Sun Aug 23 13:20:28 2015
  Description  : [fio random 4K write peak IOPS]
  write: io=2453.5MB, bw=83721KB/s, iops=20926, runt= 30008msec
    slat (usec): min=11, max=63, avg=15.57, stdev= 4.97
    clat (msec): min=4, max=35, avg= 6.09, stdev= 2.30
     lat (msec): min=4, max=35, avg= 6.10, stdev= 2.30
    clat percentiles (usec):
     |  1.00th=[ 4640],  5.00th=[ 4704], 10.00th=[ 4768], 20.00th=[ 4832],
     | 30.00th=[ 4832], 40.00th=[ 5152], 50.00th=[ 5344], 60.00th=[ 5472],
     | 70.00th=[ 5664], 80.00th=[ 6240], 90.00th=[10176], 95.00th=[10688],
     | 99.00th=[12096], 99.50th=[15808], 99.90th=[30080], 99.95th=[32384],
     | 99.99th=[34560]
    bw (KB  /s): min=   12, max=24733, per=24.59%, avg=20583.40, stdev=2925.28
    lat (msec) : 10=88.51%, 20=11.17%, 50=0.33%
  cpu          : usr=1.00%, sys=0.79%, ctx=47811, majf=0, minf=11528
  IO depths    : 1=0.0%, 2=0.0%, 4=0.0%, 8=0.0%, 16=0.1%, 32=117.3%, >=64=0.0%
     submit    : 0=0.0%, 4=0.0%, 8=0.0%, 16=100.0%, 32=0.0%, 64=0.0%, >=64=0.0%
     complete  : 0=0.0%, 4=0.0%, 8=0.0%, 16=100.0%, 32=0.0%, 64=0.0%, >=64=0.0%
     issued    : total=r=0/w=627952/d=0, short=r=0/w=0/d=0, drop=r=0/w=0/d=0
     latency   : target=0, window=0, percentile=100.00%, depth=32

Run status group 0 (all jobs):
  WRITE: io=2453.5MB, aggrb=83721KB/s, minb=83721KB/s, maxb=83721KB/s, mint=30008msec, maxt=30008msec

Disk stats (read/write):
  sda: ios=91/45915, merge=0/688845, ticks=16/277508, in_queue=277588, util=99.81%

fio-job-11: (g=0): rw=rw, bs=4K-4K/4K-4K/4K-4K, ioengine=libaio, iodepth=32

...

fio-2.2.9-26-g669e

Starting 4 threads

fio-job-11: (groupid=0, jobs=4): err= 0: pid=2881: Sun Aug 23 13:20:28 2015

Description : [fio random 4K write peak IOPS]

write: io=2453.5MB, bw=83721KB/s, iops=20926, runt= 30008msec

slat (usec): min=11, max=63, avg=15.57, stdev= 4.97

clat (msec): min=4, max=35, avg= 6.09, stdev= 2.30

lat (msec): min=4, max=35, avg= 6.10, stdev= 2.30

clat percentiles (usec):

| 1.00th=[ 4640], 5.00th=[ 4704], 10.00th=[ 4768], 20.00th=[ 4832],

| 30.00th=[ 4832], 40.00th=[ 5152], 50.00th=[ 5344], 60.00th=[ 5472],

| 70.00th=[ 5664], 80.00th=[ 6240], 90.00th=[10176], 95.00th=[10688],

| 99.00th=[12096], 99.50th=[15808], 99.90th=[30080], 99.95th=[32384],

| 99.99th=[34560]

bw (KB /s): min= 12, max=24733, per=24.59%, avg=20583.40, stdev=2925.28

lat (msec) : 10=88.51%, 20=11.17%, 50=0.33%

cpu : usr=1.00%, sys=0.79%, ctx=47811, majf=0, minf=11528

IO depths : 1=0.0%, 2=0.0%, 4=0.0%, 8=0.0%, 16=0.1%, 32=117.3%, >=64=0.0%

submit : 0=0.0%, 4=0.0%, 8=0.0%, 16=100.0%, 32=0.0%, 64=0.0%, >=64=0.0%

complete : 0=0.0%, 4=0.0%, 8=0.0%, 16=100.0%, 32=0.0%, 64=0.0%, >=64=0.0%

issued : total=r=0/w=627952/d=0, short=r=0/w=0/d=0, drop=r=0/w=0/d=0

latency : target=0, window=0, percentile=100.00%, depth=32

Run status group 0 (all jobs):

WRITE: io=2453.5MB, aggrb=83721KB/s, minb=83721KB/s, maxb=83721KB/s, mint=30008msec, maxt=30008msec

Disk stats (read/write):

sda: ios=91/45915, merge=0/688845, ticks=16/277508, in_queue=277588, util=99.81%

Part 1: Job overview output

fio-job-11: (g=0): rw=rw, bs=4K-4K/4K-4K/4K-4K, ioengine=libaio, iodepth=32
...
fio-2.2.9-26-g669e
Starting 4 threads

fio-job-11: (g=0): rw=rw, bs=4K-4K/4K-4K/4K-4K, ioengine=libaio, iodepth=32

...

fio-2.2.9-26-g669e

Starting 4 threads

“g=0”
- this job belongs to group 0 – Groups can be used to aggregate job results.
“rw=rw”
- the IO pattern is “random write”
“bs=4K-4K/4K-4K/4K-4K”
- the block size is 4K for all types (read,write,discard). This test is only scheduling writes. The important part for this job is 4K-4K in the middle.
“ioengine=libaio”
- the used ioengine is libaio which means parallel writes will be scheduled. This is not a good test for the file system performance because it skips the page cache.
“iodepth=32”
- there will be up to “32 IO units” in flight against the device. So there will be a queue filled up to 32 outstanding IOs most of the time.
the version is “fio-2.2.9-26-g669e”
4 threads will be started.

Part 2: Data direction output

fio-job-11: (groupid=0, jobs=4): err= 0: pid=2377: Sun Aug 23 12:56:42 2015

Description : [fio random 4K write peak IOPS]

write: io=41119MB, bw=1370.5MB/s, iops=350728, runt= 30013msec

slat (usec): min=11, max=230, avg=15.62, stdev= 1.79

clat (usec): min=20, max=13505, avg=344.55, stdev=224.87

lat (usec): min=66, max=13523, avg=360.23, stdev=224.84

clat percentiles (usec):

| 1.00th=[ 262], 5.00th=[ 262], 10.00th=[ 262], 20.00th=[ 266],

| 30.00th=[ 266], 40.00th=[ 270], 50.00th=[ 274], 60.00th=[ 274],

| 70.00th=[ 278], 80.00th=[ 282], 90.00th=[ 374], 95.00th=[ 1020],

| 99.00th=[ 1192], 99.50th=[ 1208], 99.90th=[ 1256], 99.95th=[ 1272],

| 99.99th=[ 1304]

bw (KB /s): min= 12, max=356608, per=24.60%, avg=345090.77, stdev=45012.87

lat (usec) : 50=0.01%, 100=0.01%, 250=0.24%, 500=91.01%, 750=0.04%

lat (usec) : 1000=3.31%

lat (msec) : 2=5.39%, 20=0.01%

cpu : usr=5.66%, sys=12.09%, ctx=2783241, majf=0, minf=32689

IO depths : 1=0.0%, 2=0.0%, 4=0.0%, 8=0.0%, 16=0.1%, 32=116.7%, >=64=0.0%

submit : 0=0.0%, 4=0.0%, 8=0.0%, 16=100.0%, 32=0.0%, 64=0.0%, >=64=0.0%

complete : 0=0.0%, 4=0.0%, 8=0.0%, 16=100.0%, 32=0.0%, 64=0.0%, >=64=0.0%

issued : total=r=0/w=10526416/d=0, short=r=0/w=0/d=0, drop=r=0/w=0/d=0

latency : target=0, window=0, percentile=100.00%, depth=32

The header is self explaining: Job name = fio-job-11 …

The detailed IO statistics for the job:

“write” (remember the job schedules 100% random writes)
“io=41119MB”
- number of MB transfered
“bw=1370.5MB/s”
- write data at a speed of 1370.5MB per second in average
“iops=350728”
- is the average IO per second (4K in this case).
“runt=30013msec”
- The job ran ~30 seconds
“slat”, “clat”,”lat” min,max,avg,stdev
- slat means submission latency and presents the time it took to submit this IO to the kernel for processing.
- clat means completion latency and presents the time that passes between submission to the kernel and when the IO is complete, not including submission latency.
- lat is the best metric which represents the whole latency an application would experience. The avg slat+ avg clat = ~ avg lat.
- Keep an eye if the numbers are usec or msec ..etc.! Compare PX600-1000 to EVO 840.
- See Al Tobey blog for some more details.
“clat percentile” gives a detailed explanation how much IO in percentage completed in which time frame. In this case: 99% of the IO completed in <=1192 usec = 1,2 msec. This value is often used to ignore the few spikes when testing. The maximum clat has been 13505 which has been ~14x longer than the average of 344.
“bw” min, max, per,avg, stdev
- In this case the bandwidth has been 345090 KB/s = ~337 MB/s
“lat” this is like the clat part.
- In this case 91.01% of the IO completed between 500usec and >250usec. This is in line with the avg latency of 360.23usec. Only ~ 8,7% of the IO took between 2ms and >750usec. Both together is nearly 99,8% of all IO.
“cpu”
- this line is dedicated to the CPU usage of the running the job
  - “usr=5.66%”
    - this is the percentage of CPU usage of the running job at user level
    - 100% would mean that one CPU core will be at 100% workload, depending if HT on/off
  - “sys=12.09%”
    - this is the percentage of CPU usage of the running job at system/kernel level
  - “ctx=2783241”
    - The number of context switches this thread encountered while running
  - “majf=0” and “minf=32689”
    - The number of major and minor page faults
    - majf should be zero. Understanding page faults.
“IO depths :
- “32=116.7%… ”
  - this number showed that this job was able to have ~32 IO units in flight
  - I am not sure why it’s >100%
  - “submit: …..16=100.0%….”
    - shows how many IO were submitted in a single submit call. In this case it could be in the range of 8 to 16
    - This is in line with the script which used iodepth_batch values
- - “complete: …. 16=100.0%….”
    - same like submit but for completed calls.
  - “issued:….total=w=10526416/w=0/d=0″…
    - 10526416 write IO have been issued, no reads, no discards and none of them have been short or dropped

Part 3: Group statistics

1 2	Run status group 0 (all jobs): WRITE: io=41119MB, aggrb=1370.5MB/s, minb=1370.5MB/s, maxb=1370.5MB/s, mint=30013msec, maxt=30013msec

WRITE
- “io=41119MB”
  - As in the job statistics the same amount of transfered MB here because its only one job
- “aggrb=1370.5MB/s”
  - aggregated bandwidth of all jobs/threads for group 0
- “minb=1370.5MB/s maxb=1370.5MB/s”
  - The minimum and maximum bandwidth one thread saw. In this case is the minimum the same as the maximum.I don’t think this is correct! Will clarify this.
- “mint=30008msec” and “maxt=30008msec”
  - Smallest and longest runtime of one of the jobs. The same because we ran only one job

Part 4: Disk statistics

1 2	Disk stats (read/write): fioa: ios=71/767604, merge=0/0, ticks=0/259476, in_queue=256816, util=94.63%

“fioa: ios=71/767604”
- 71 read IO and 767604 write IO on /dev/fioa
- I am not sure why there are 71 read IO. I am pretty sure i didn’t run anything myself in the background. Who knows?
“merge=0/0” number of merges the IO from the IO scheduler
- no merges here
“ticks=0/259476”
- number of ticks we kept the drive busy. A sign that the device is saturated.
- A tick is related to one jiffy. The next lines are only a approximation. read about Kernel Timer for more details.
- In this example I checked the value for CONFIG_HZ
  
  cat /boot/config-`uname -r` | grep HZ
  
  1
  
  cat /boot/config-`uname -r` | grep HZ
  - CONFIG_HZ is set to 250 which means 1 second / 250 = 0,004s = 4ms
  - 259476 ticks * 4ms = 1037s ???
  - I believe this is the cumulated wait time all IO spend in the queue. If you increase only the iodepth the value increase linear.
  - 1037s / 32 (iodepth) = ~32,4s its a little bit more than the runtime of 30s
“io_queue=256816”
- total time spend in the disk queue
“util=94.63%”
- the utilization of the drive is 94.63 means the drive seems to be nearly saturated with this workload.

This should give you a good idea which parts of a result/output exist and some insights how to interpret them. And yes its a tough one.

Go GIMP.

FIO (Flexible I/O Tester) Part7 – Steady State of SSD,NVMe,PCIe Flash with TKperf

Leave a reply

The real world performance of a Flash device is shown when the Steady State is reached. In most cases these are not the performance values which are shown on the vendors website.

The SNIA organization defined a specification how to test flash devices or Solid State Storage. The industry would like to have a methodology to compare NAND Flash devices with a scientific approach. The reason why there is a need for this specification is that the NAND Flash devices write performance heavily depends on the write history of the device. There are three write phases of a NAND Flash device:

FOB (Fresh- Out of the Box)
Transition
Steady State

FOB (Fresh- Out of the Box) or Secure Erase(Sanitize?)

A device taken fresh out of the box should provide the best possible write performance for a while. Why? A flash device writes data in 4 KB pages inside of 256 KB blocks. To add additional pages to a partially filled block, the solid-state drive must erase the entire block before writing data back to it.

If the flash device fills up, fewer and fewer empty blocks are available. In their place are partially filled blocks. The NAND Flash device can’t just write the new data to these partially filled blocks — that would erase the existing data. Instead of a simple write operation, the NAND Flash device has to read the value of the block into its cache, modify the value with the new data, and then write it back. (Write Amplification)

Often when you would like to test a device some data has already been written to it. This means you can’t test the FOB performance anymore. For this it is possible to “Secure Erase” the device. This feature was original introduced to delete all data on a flash device securely which means that all pages/blocks will be zeroed even the blocks which are over-provisioned (not visible to the OS). But it can also be used to optimize the performance and restore the FOB performance for a while. The vendors provide tools for this. Be careful. Some vendors make us of Sanitize and Secure Erase as features. But the implementation is different. So a Secure Erase may only delete the mapping table and not the blocks them self.

Transition

The transition is the phase between the good performance of FOB and Steady State. Most of the time the performance drops continuously over time and the write cliff appears till the Steady State is reached.

Steady State

The scientific definition for Steady State is:

Steady State:

A device is said to be in Steady State when, for the dependent variable

(y) being tracked:

a) Range(y) is less than 20% of Ave(y): Max(y)-Min(y) within the Measurement Window

is no more than 20% of the Ave(y) within the Measurement Window; and

b) Slope(y) is less than 10%: Max(y)-Min(y), where Max(y) and Min(y) are the maximum

and minimum values on the best linear curve fit of the y-values within the

Measurement Window,is within 10% of Ave(y) value within the Measurement Window.

Basically this means: Use a predefined write/read pattern and run this against the device until the performance of the device will be stable over time.

But should you run the test yourself? First a little bit math:

The pseudo code for IOPS states:

For (R/W Mix % = 100/0, 95/5, 65/35, 50/50, 35/65, 5/95, 0/100)

For (Block Size = 1024KiB, 128KiB, 64KiB, 32KiB, 16KiB, 8KiB, 4KiB,0.5KiB)

- Execute random IO, per (R/W Mix %, Block Size), for 1 minute

- Record Ave IOPS(R/W Mix%, Block Size)

The whole block will be run up to 25 times depending if Steady State is already reached. Each run will be for 1 Minute.

25 (maximum runs) * 7 (R/W mixes) * 8 (block sizes) = 1400 minutes = 23,3h

The test could run for ~24h and it will write a lot. I strongly advice that you don´t run the tests yourself as long as you agree that the device looses lifetime.

There are some scripts and tools which can be useful to test the device which are based on “fio”.

a bash script by James Bowen. This scripts run for ~24 hours and does not stop even Steady State is reached
tkperf by Georg Schönberger which I prefer
block-storage git project by Jason Read which is aimed for cloud environments. A full implementation of PTS can’t be done in cloud environments. (For example: Secure Erase)

Using TKperf with SanDisk PX600-1000

TKperf is a python script which implements the full SNIA PTS specification. With Ubuntu its really easy to install.

After tkperf is installed and all dependencies as well I started a test. I tested a SanDisk PX600-1000 installed in Testverse. Because for the PX600 PCIe device you can’t run “hdparm” to Secure Erase, Georg Schöneberger implemented a new option “-i fusion” which leverages the SanDisk Command-line tools to Secure Erase the device. Again: Thank you @devtux_at

The following command runs all four SNIA PTS tests (IOPS,Latency,Throughput,Write Saturation). I ran with 4 jobs, an iodepth of 16 and used refill buffers to avoid compression of the device. The file test.dsc is a simple text file which describes the drive because “hdparm” can’t get infos about the PX600.

REMEMBER: ALL data will be lost and your device looses lifetime or maybe destroyed!

sudo tkperf -i fusion ssd PX600-1000 /dev/fioa -nj 4 -iod 16 -rfb -dsc test.dsc

1	sudo tkperf -i fusion ssd PX600-1000 /dev/fioa -nj 4 -iod 16 -rfb -dsc test.dsc

Results:

tkperf generates some nice png files which summarizes the testing. And the tests reached steady state after 4-5 rounds.

The device was formatted with 512 bytes sector size. This was needed to run all tests. It would improve the performance for all bigger block sizes to format the device with 4k sector size!

IOPS

Latency

This is the reason why these cards are that nice. Providing < 0,2 ms latency is great!

Throughput

Write Saturation

Go tkperf!

FIO (Flexible I/O Tester) Part6 – Sequential read and readahead

Leave a reply

In the last read tests I found that the sequential read IOPS have been higher than expected. I left “invalidate” on default, that means that the used file for the test should be dropped out of the page cache when the test starts. So why are the IOPS higher then the raw device performance? I found that the readahead is responsible for this.

Important: readahead will only come into the play when the read is using the page cache. This means “direct=0”.

Set and get the readahead value

You can use the tool “blockdev” to show the readahead value:

sudo blockdev --getra /dev/sda1

1	sudo blockdev --getra /dev/sda1

or set the size with:

sudo blockdev --setra 128 /dev/sda1

1	sudo blockdev --setra 128 /dev/sda1

Example with different readahead values:

I set the readahead value to 128 and run this file: readahead

[readahead]
rw=read
ioengine=sync
direct=0
invalidate=1
size=100MB
filename=/840/testfile1 ; This is Samsung EVO 840 with ext4 defaults

[readahead]

rw=read

ioengine=sync

direct=0

invalidate=1

size=100MB

filename=/840/testfile1 ; This is Samsung EVO 840 with ext4 defaults

“issued: total=r=25600” shows that 25600 IOPS have been issued but “sda : ios=561” shows that only 561 hit the device.So we can estimate that to read 100MB with 561 IOPS each IOPS needs to be ~182KB. This seems to be higher then 128 (read ahead value) * 512Bytes (default sector size) = 64KB. Something is wrong! I run:

sudo blockdev --getbsz /dev/sda1

1	sudo blockdev --getbsz /dev/sda1

With an output of 4096. Okay the physical block size is 4096 Bytes and not 512 Bytes. 128 (read ahead value) * 4096 Bytes (physical block sector size) = 256KB. This would fit much better with the value of ~182KB.

I set the readahead value to 256 and run the same test again.

296 IOPS means around the half of the IOPS than the last test.

I set the readahead value to 512 and run the same test again.

Again around the half.

So this value can have an impact on the sequential read performance of your device. But most of the times sequential read are not the bottleneck in a typical environment. Even HDD’s can provide really fast sequential reads as long the fragmentation is under control.

Go leofs.

FIO (Flexible I/O Tester) Part5 – Direct I/O or buffered (page cache) or raw performance?

Leave a reply

Before you start to run tests against devices you should know that most operating systems make use of a DRAM caches for IO devices. So for example page cache in Linux which is: “sometimes also called disk cache, is a transparent cache for the pages originating from a secondary storage device such as a hard disk drive (HDD)”. Windows uses a similar but other approach to page cache but for my convenience I will use page cache as synonym for both approaches.

Direct I/O means an IO access where you bypass the cache (page cache).

RAW performance

If we want to measure the performance of an IO device, should we use these caching techniques or avoid them? I believe it makes sense to run a baseline of your device without the influence of any file system or page cache. The implementation of page caches are different in each OS which means the same device may vary a lot. File systems also introduce a huge variance when running tests. For example: “If someone says that a device with NTFS reaches ~50.000 IOPS/4K” Have you ever asked which version of NTFS? You should have. See Memory changes in NTFS with Windows Server 2012 compared to version 1.0.

For sure in a real world workload the influence of a page cache maybe really important and should not be underestimated or uncared. But to measure the raw performance of an device ignore any file system or page cache.

Page caching vs Direct I/O vs RAW performance

Linux Page Caching:

“fio” per default invalidates the buffer/page cache for the used files when it starts. I believe this is done to avoid the influence of the page cache when running. But remember, while “fio” is running, the page cache will build up and may have an influence on your test.

We need to set the option “invalidate=0” to keep the page/buffer in memory to test with the page cache.

Page cache in action on Testverse:

jobfile: cache-run

[cache-run]
rw=randread
ioengine=sync
direct=0
invalidate=0
size=10MB
filename=/mnt/fioa/testfile1 ; This is a SanDisk ioMemory with ext4 and defaults

[cache-run]

rw=randread

ioengine=sync

direct=0

invalidate=0

size=10MB

filename=/mnt/fioa/testfile1 ; This is a SanDisk ioMemory with ext4 and defaults

The first run looked like that:

The marked parts show that 2560 IO of 4K have been issued. But only 1121 IO hit the device. So 1439 IO seems to be answered via the page cache. So lets run it again because the file should be in page cache now.

The second run proved it. Zero IO hit the device. Means 100% of the IO was handle by the page cache. And WOHOOO : 853333 IOPS 🙂

How to monitor the page cache?

There is a nice tool called cachestat written by Brendan D. Gregg which is part of the perf-tools. The tool is just a script so there is no need to compile it. Just download and run 🙂

The marked part shows a “cache-run”.

free -m can give you some details as well.

You can run this command to clear the page cache.

sync && echo 3 | sudo tee /proc/sys/vm/drop_caches

1	sync && echo 3 \| sudo tee /proc/sys/vm/drop_caches

Example:

I ran “free -m” to show the actual state. Then ran 2x the “cache-run” with a size of 1000MB. The second run was MUCH faster. Then “free -m” shows that “used” and “cached” is increased by 1000. This means the testfile1 is fully cached. Then I cleared the cache with echo 3 to /proc/sys/vm/drop_caches. “free -m” shows that cached is near zero.

Windows Page Caching/System cache

This chapter is even more complicated. I will update it soon!

Direct I/O

Direct I/O means an IO access where you bypass the cache (page cache). You are able to force a direct I/O with the option “direct=1”.

jobfile: cache-run-direct

[cache-run-direct]
rw=randread
ioengine=sync
direct=1
size=10MB
filename=/mnt/fioa/testfile1 ; This is a SanDisk ioMemory with ext4 and defaults

[cache-run-direct]

rw=randread

ioengine=sync

direct=1

size=10MB

filename=/mnt/fioa/testfile1 ; This is a SanDisk ioMemory with ext4 and defaults

Direct I/O is the first step in measuring storage devices raw performance. The IOPS dropped a lot compared to the page cache second run. Direct 8767 IOPS vs Buffered 853333 IOPS. You may think that 8767 are too less IOPS for a SanDisk ioMemory device? Remember this is a random read with 1 job/thread and sync with an iodepth with 1. This means each read IO need to wait that the IO before is completed.

RAW performance

RAW performance means you schedule workloads against the native block device without a page cache or a file system. This is the way how most vendors measure their own performance values and present them on their website.

The option “filename=/dev/sdb” (Linux) or “filename=\\.\PhysicalDrive1” (Windows) uses the second device of your system.

WARNING: The data on the selected device can be lost!!!!!

Please double check that you selected the right device. Re-check any files you downloaded.

[raw-run]
rw=randread
ioengine=sync
direct=1
size=10MB
filename=/dev/fioa ; This is a SanDisk ioMemory. Use /dev/sdb instead?

[raw-run]

rw=randread

ioengine=sync

direct=1

size=10MB

filename=/dev/fioa ; This is a SanDisk ioMemory. Use /dev/sdb instead?

You may noticed that the IOPS slightly increased to 9142 compared to the direct test run.

Go tomcat.

FIO (Flexible I/O Tester) Part4 – fixed, ranges or finer grained block sizes?

Leave a reply

Using fixed block sizes is the most common way when doing storage (device) tests. There is more then one reason for that. The obvious reason is that a lot of tools only support fixed block size. Another reason is that the storage vendors present their performance counters mostly based on fixed block sizes with 4K. But this doesn’t means it’s the best way to test or measure your storage (device).

There are two common tests which you would like to perform:

RAW peak performance
Simulating production workload

Raw peak performance means a test where you try to test your storage (device) to achieve the same or similar values as the vendor presents on his website/documentation. This is by nature the highest possible value (peak) without the influence of page caches or file systems. Why should you do this? It is not to make sure the numbers at the vendor website are true or false. It is to make sure the device is running as expected and all best practices have been done.

Simulating production workload means a test where you try to test your storage (device) against a workload production. But most of the time you are not able to run the production workload directly on the storage (device). So then you need to simulate the production workload with a tool like “fio”,”sqlio“,”swingbench“… etc. If possible always test with real production workloads instead of simulations.

Fixed block size

You may used the option “blocksize=4K” or “bs=4K” which is the way to specify a fixed block size of 4K. But the output shows “BS=4K-4K/4K-4K/4K-4K”. So why 6 numbers instead of one?

There are three parts ( / is the separator) in the output. The first is related to the block size for reads, the second for writes and the third for discards. 4K-4K means use a block size from the range of 4K to 4K which is exactly 4K. But this gives you an idea that ranges could be used. There is even more then ranges. Block sizes can be fine grained.

You are able to specify fixed block size with different values for read,write,discard.

Example: Lets run a job with 50% reads and 50% writes. The read should use a fixed block size of 4K but the writes should use 64K. So we need to set the option “rw=readwrite” or “rw=rw” and the option “rwmixread=50” or “rwmixwrite=50”.

file: read-4K-write-64K

[read-4k-write-64k]
blocksize=4K,64K
rw=readwrite
rwmixread=50           ; or rwmixwrite=50  Means a 50-50 split between R/W
size=10M
filename=/840/testfile1

[read-4k-write-64k]

blocksize=4K,64K

rw=readwrite

rwmixread=50 ; or rwmixwrite=50 Means a 50-50 split between R/W

size=10M

filename=/840/testfile1

Block size ranges

Instead of using a fixed block size you can specify a range.

Example: Let’s run a read workload with a block size in the range of 1K to 16K. This can be done by set the “blocksize_range=1K:16K” or “bsrange=1K:16K”. But how will the mix look like?

file: read_bs1K-16K

[read-bs1K-16K]
rw=read
bsrange=1K:16K
size=10M
filename=/840/testfile1

[read-bs1K-16K]

rw=read

bsrange=1K:16K

size=10M

filename=/840/testfile1

1400 IO have been issued. At this point I am note sure about the real distribution. I tried a few calculation but have not been able to provide an explanation yet.The documentation states:

fio will mix the issued io block sizes. The issued io unit will always be a multiple of the minimum value given (also see bs_unaligned).

Finer grained block sizes

Sometimes it maybe useful to control how the weight for a block size within a range should be set. This can be done with the option “bssplit”. What could be the reason why you would like to control the block size? Lets assume you know a production workload and would like to use “fio” to act similar inside a new VM/container to evaluate if the production workload would run fine.

The format for this option is:
bssplit=blocksize/percentage:blocksize/percentage

for as many block sizes as needed.

Example: Let’s run a read workload with a block size 10% 1K, 80% 4k, 10% 16K. This can be done by set the option “bssplit=1K/10:4K/80:16K/10”.

file: read_bs1K10p_4K80p_16K10p

[read_bs1K10p_4K80p_16K10p]
rw=read
bssplit=1K/10:4K/80:16K/10
size=10M
filename=/840/testfile1

[read_bs1K10p_4K80p_16K10p]

rw=read

bssplit=1K/10:4K/80:16K/10

size=10M

filename=/840/testfile1

2029 IO issued. The simple math is:

2029 * 0,8 (80% of IO) * 4K (is 4K) = 6492,8 K
2029 * 0,1 (10% of IO) * 1K (is 1K) = 202,9 K
2029 * 0,1 (10% of IO) * 16K (is 16K) = 3246,4 K
6492,8K + 202,9K + 3246,4K = 9942,1K ~ 10MB

Yes there is a derivation with means my approach is only a simple approximation of the real algorithm. Remember you can not issue one half of an IO 🙂

Go Zookeeper.

FIO (Flexible I/O Tester) Part3 – Environment variables and keywords

Leave a reply

FIO is able to make us of environment variables and reserved keywords in job files. This can avoid some work so that you don´t need to change the job files each time you call them.

Define a variable in a job file

The documentation is pretty nice:

Any sub-string of the form "${VARNAME}" as part of an option value (in other

words, on the right of the `='), will be expanded to the value of the

environment variable called VARNAME. If no such environment variable

is defined, or VARNAME is the empty string, the empty string will be

substituted.

So for example this is an entry in the job file where the size should be set via an environment variable.

size=${SIZE}

1	size=${SIZE}

Example of using environment variables

I would like to run four different job files and use for each run a different size (1MB,10MB,100MB,1G,10G,100G).

Job1 is sequential read / 4 KB / 1 thread / ioengine=sync / iodepth=1
Job2 is sequential write/ 4 KB / 1 thread / ioengine=sync / iodepth=1
Job3 is random read / 4 KB / 1 thread / ioengine=sync / iodepth=1
Job4 is random write / 4 KB / 1 thread / ioengine=sync / iodepth=1

I make use of the default settings under linux. For example I did not specify the block size which is 4K per default, but it is best practice to define them in case a default value may be changed.

Files:

jobfile1: read_4KB_numjob1_sync_iodepth1

[global]
rw=read
size=${SIZE}

[read_4KB_numjob1_sync_iodepth1]

[global]

rw=read

size=${SIZE}

[read_4KB_numjob1_sync_iodepth1]

jobfile2: write_4KB_numjob1_sync_iodepth1

[global]
rw=write
size=${SIZE}

[write_4KB_numjob1_sync_iodepth1]

[global]

rw=write

size=${SIZE}

[write_4KB_numjob1_sync_iodepth1]

jobfile3: randread_4KB_numjob1_sync_iodepth1

[global]
rw=randread
size=${SIZE}

[randread_4KB_numjob1_sync_iodepth1]

[global]

rw=randread

size=${SIZE}

[randread_4KB_numjob1_sync_iodepth1]

jobfile3: randwrite_4KB_numjob1_sync_iodepth1

[global]
rw=randwrite
size=${SIZE}

[randwrite_4KB_numjob1_sync_iodepth1]

[global]

rw=randwrite

size=${SIZE}

[randwrite_4KB_numjob1_sync_iodepth1]

Run fio:

1) Run with SIZE of 1M

  SIZE=1M fio read_4KB_numjob1_sync_iodepth1 write_4KB_numjob1_sync_iodepth1 randread_4KB_numjob1_sync_iodepth1 randwrite_4KB_numjob1_sync_iodepth1

1	SIZE=1M fio read_4KB_numjob1_sync_iodepth1 write_4KB_numjob1_sync_iodepth1 randread_4KB_numjob1_sync_iodepth1 randwrite_4KB_numjob1_sync_iodepth1

Yes this could be done in one job file but often you are using predefined files from a vendor or a website like this and just want to call them with your size settings.

2) Run with SIZE of 10M

SIZE=10M fio read_4KB_numjob1_sync_iodepth1 write_4KB_numjob1_sync_iodepth1 randread_4KB_numjob1_sync_iodepth1 randwrite_4KB_numjob1_sync_iodepth1

1	SIZE=10M fio read_4KB_numjob1_sync_iodepth1 write_4KB_numjob1_sync_iodepth1 randread_4KB_numjob1_sync_iodepth1 randwrite_4KB_numjob1_sync_iodepth1

…. and so on.

Reserved keywords:

There are 3 documented reserved keywords:

$pagesize The architecture page size of the running system
$mb_memory Megabytes of total memory in the system
$ncpus Number of online available CPUs

You can use them in the command line or in the jobs files. They are substituted with the current system values when you run the job.

Use cases?

Lets say you would like to run a job with as much threads as online available CPUs.

file: read-x-threads

[read-x-threads]
size=1M
numjobs=$ncpus

[read-x-threads]

size=1M

numjobs=$ncpus

fio read-x-threads

1	fio read-x-threads

In my case (Testverse) there are 4 CPU cores with Hyper-Threading(HT) on. Means 8 threads.

Go Jenkins!

tfindelkind.com

@tfindelkind

Monthly Archives: August 2015

2. SQL Server Performance Tuning study with HammerDB – Setup HammerDB

Setup HammerDB

1. SQL Server Performance Tuning study with HammerDB – Setup SQL Server

The Use Case

The Setup

Samsung 840 Basic- Baseline tests with FIO based on Windows 2012R2

Command line example:

Results:

SanDisk ioMemory/Fusion-io ioDrive – Baseline tests with FIO based on Windows 2012R2

Command line example:

Results:

FIO (Flexible I/O Tester) Part8 – Interpret and understand the result/output

The official documentation

Example: Interpret the result/output of SanDisk PX600-1000 and Samsung EVO 840

FIO (Flexible I/O Tester) Part7 – Steady State of SSD,NVMe,PCIe Flash with TKperf

FOB (Fresh- Out of the Box) or Secure Erase(Sanitize?)

Transition

Steady State

Using TKperf with SanDisk PX600-1000

Results:

FIO (Flexible I/O Tester) Part6 – Sequential read and readahead

Set and get the readahead value

FIO (Flexible I/O Tester) Part5 – Direct I/O or buffered (page cache) or raw performance?

Page caching vs Direct I/O vs RAW performance

Linux Page Caching:

Windows Page Caching/System cache

Direct I/O

RAW performance

FIO (Flexible I/O Tester) Part4 – fixed, ranges or finer grained block sizes?

Fixed block size

Block size ranges

Finer grained block sizes

FIO (Flexible I/O Tester) Part3 – Environment variables and keywords

Define a variable in a job file

Example of using environment variables

Reserved keywords:

Use cases?