axboe / fio

Flexible I/O Tester
GNU General Public License v2.0
5.23k stars 1.26k forks source link

Output two IOPS value not equal #1575

Open favetions opened 1 year ago

favetions commented 1 year ago

Description of the bug: The IOPS value (highlight) not equal, the 111k may looks right by check drive log, it's only happen with --io_amount, timebased is equal ======================================== FIO SCREEN OUTPUT ======================================== nvme0n1-19-2413-6a3e94: (g=0): rw=randwrite, bs=(R) 4096B-4096B, (W) 4096B-4096B, (T) 4096B-4096B, ioengine=libaio, iodepth=8 ... fio-3.32 Starting 16 threads

nvme0n1-19-2413-6a3e94: (groupid=0, jobs=16): err= 0: pid=18715: Wed May 17 15:43:54 2023 write: IOPS=111k, BW=433MiB/s (454MB/s)(375GiB/887769msec); 0 zone resets slat (nsec): min=1192, max=16966k, avg=2472.46, stdev=12555.57 clat (usec): min=17, max=18276, avg=993.97, stdev=896.04 lat (usec): min=20, max=18278, avg=996.45, stdev=896.16 clat percentiles (usec): | 50.0000000th=[ 668], 90.0000000th=[ 2114], 99.0000000th=[ 4293], | 99.9000000th=[ 5014], 99.9900000th=[ 5342], 99.9990000th=[ 7177], | 99.9999000th=[16909], 99.9999900th=[17695], 99.9999990th=[18220], | 99.9999999th=[18220], 100.0000000th=[18220] bw ( KiB/s): min=130492, max=2032610, per=100.00%, avg=529103.39, stdev=26211.62, samples=24516 iops : min=33226, max=502899, avg=132163.42, stdev=6490.34, samples=12253 lat (usec) : 20=0.01%, 50=0.10%, 100=1.36%, 250=1.65%, 500=25.68% lat (usec) : 750=29.61%, 1000=10.42% lat (msec) : 2=20.40%, 4=8.80%, 10=1.97%, 20=0.01% cpu : usr=0.52%, sys=2.28%, ctx=98176922, majf=0, minf=383 IO depths : 1=0.0%, 2=0.0%, 4=0.0%, 8=100.0%, 16=0.0%, 32=0.0%, >=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=100.0%, 8=0.1%, 16=0.0%, 32=0.0%, 64=0.0%, >=64=0.0% issued rwts: total=0,98418190,0,0 short=0,0,0,0 dropped=0,0,0,0 latency : target=0, window=0, percentile=100.00%, depth=8

Run status group 0 (all jobs): WRITE: bw=433MiB/s (454MB/s), 433MiB/s-433MiB/s (454MB/s-454MB/s), io=375GiB (403GB), run=887769-887769msec

Disk stats (read/write): nvme0n1: ios=744/99997893, merge=0/0, ticks=739/99095169, in_queue=99095908, util=99.98%

===================================================================================================

Environment: (CentOS) Linux version 4.18.0-348.7.1.el8_5.x86_64

fio version: 3.32

Reproduction steps fio --name=nvme0n1-19-2413-6a3e94 --filename=/dev/nvme0n1 --thread --ioengine=libaio --stonewall --group_reporting --exitall_on_error=1 --cpus_allowed_policy=split --output-format=normal,json+ --direct=1 --randrepeat=0 --allrandrepeat=0 --randseed=1990278872 --norandommap --rw=randwrite --bs=4k --ba=4k --iodepth=8 --numjobs=16 --io_size=25000000k --ramp_time=10s --percentile_list=50.0:90:99:99.9:99.99:99.999:99.9999:99.99999:99.999999:99.9999999:100

ankit-sam commented 1 year ago

Hi @favetions

I tried your command but could not reproduce the issue which you mentioned. here is the log (highlighted IOPS and BW):

nvme0n1-19-2413-6a3e94: (g=0): rw=randwrite, bs=(R) 4096B-4096B, (W) 4096B-4096B, (T) 4096B-4096B, ioengine=libaio, iodepth=8 fio-3.32 Starting 16 threads .... .... nvme0n1-19-2413-6a3e94: (groupid=0, jobs=16): err= 0: pid=23232: Tue May 23 18:17:17 2023 write: IOPS=269k, BW=1050MiB/s (1101MB/s)(371GiB/361995msec); 0 zone resets slat (nsec): min=730, max=177585, avg=2099.70, stdev=874.17 clat (usec): min=11, max=8602, avg=473.25, stdev=914.05 lat (usec): min=15, max=8604, avg=475.35, stdev=914.03 clat percentiles (usec): | 50.0000000th=[ 145], 90.0000000th=[ 1582], 99.0000000th=[ 4752], | 99.9000000th=[ 6915], 99.9900000th=[ 7504], 99.9990000th=[ 7898], | 99.9999000th=[ 8455], 99.9999900th=[ 8586], 99.9999990th=[ 8586], | 99.9999999th=[ 8586], 100.0000000th=[ 8586] bw ( MiB/s): min= 992, max= 1184, per=100.00%, avg=1050.47, stdev= 1.22, samples=11564 iops : min=254002, max=303298, avg=268918.22, stdev=313.39, samples=11564 lat (usec) : 20=0.01%, 50=0.95%, 100=11.73%, 250=67.00%, 500=3.54% lat (usec) : 750=1.64%, 1000=1.70% lat (msec) : 2=5.75%, 4=5.99%, 10=1.71% cpu : usr=2.22%, sys=4.50%, ctx=22560057, majf=0, minf=0 IO depths : 1=0.0%, 2=0.0%, 4=0.0%, 8=100.0%, 16=0.0%, 32=0.0%, >=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=100.0%, 8=0.1%, 16=0.0%, 32=0.0%, 64=0.0%, >=64=0.0% issued rwts: total=0,97300713,0,0 short=0,0,0,0 dropped=0,0,0,0 latency : target=0, window=0, percentile=100.00%, depth=8

Run status group 0 (all jobs): WRITE: bw=1050MiB/s (1101MB/s), 1050MiB/s-1050MiB/s (1101MB/s-1101MB/s), io=371GiB (399GB), run=361995-361995msec

Disk stats (read/write): nvme0n1: ios=488/99935210, merge=0/0, ticks=483/46303026, in_queue=46303509, util=100.00%

Does this happen with a smaller workload and a single job? Something like --io_size=1G --numjobs=1 and can you also check without specifying --ramp_time=10s ?