Understanding the fio output for write operation

[raj-prince]

Fio Output:

4_thread: (g=0): rw=write, bs=(R) 16.0KiB-16.0KiB, (W) 16.0KiB-16.0KiB, (T) 16.0KiB-16.0KiB, ioengine=libaio, iodepth=64
...
fio-3.35-139-gc5d8
Starting 40 threads
Jobs: 1 (f=1): [W(1),_(39)][100.0%][eta 00m:00s]                                                                                                                 
4_thread: (groupid=0, jobs=40): err= 0: pid=562556: Mon Nov  6 04:07:30 2023
  write: IOPS=29, BW=986KiB/s (1010kB/s)(76.1MiB/79037msec); 0 zone resets
    slat (usec): min=306, max=735217, avg=59917.76, stdev=39694.55
    clat (usec): min=6, max=94396k, avg=41163568.65, stdev=21078844.63
     lat (msec): min=63, max=94396, avg=41197.21, stdev=21078.47
    clat percentiles (msec):
     |  1.00th=[  877],  5.00th=[10402], 10.00th=[12550], 20.00th=[17113],
     | 30.00th=[17113], 40.00th=[17113], 50.00th=[17113], 60.00th=[17113],
     | 70.00th=[17113], 80.00th=[17113], 90.00th=[17113], 95.00th=[17113],
     | 99.00th=[17113], 99.50th=[17113], 99.90th=[17113], 99.95th=[17113],
     | 99.99th=[17113]
   bw (  KiB/s): min= 1270, max= 4705, per=100.00%, avg=3203.18, stdev=26.81, samples=919
   iops        : min=   78, max=  290, avg=198.16, stdev= 1.67, samples=919
  lat (usec)   : 10=0.09%
  lat (msec)   : 100=0.17%, 250=0.38%, 500=0.72%, 750=0.43%, 1000=0.47%
  lat (msec)   : 2000=0.72%, >=2000=204.26%
  fsync/fdatasync/sync_file_range:
    sync (msec): min=9709, max=94396, avg=43189.49, stdev=19686.84
    sync percentiles (msec):
     |  1.00th=[10402],  5.00th=[12416], 10.00th=[15368], 20.00th=[17113],
     | 30.00th=[17113], 40.00th=[17113], 50.00th=[17113], 60.00th=[17113],
     | 70.00th=[17113], 80.00th=[17113], 90.00th=[17113], 95.00th=[17113],
     | 99.00th=[17113], 99.50th=[17113], 99.90th=[17113], 99.95th=[17113],
     | 99.99th=[17113]
  cpu          : usr=0.00%, sys=0.00%, ctx=9399, majf=0, minf=0
  IO depths    : 1=0.0%, 2=0.0%, 4=0.0%, 8=0.0%, 16=0.0%, 32=0.0%, >=64=199.9%
     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=98.3%, 8=0.0%, 16=0.0%, 32=0.0%, 64=1.7%, >=64=0.0%
     issued rwts: total=0,2350,0,2348 short=0,0,0,0 dropped=0,0,0,0
     latency   : target=0, window=0, percentile=100.00%, depth=64

Run status group 0 (all jobs):
  WRITE: bw=986KiB/s (1010kB/s), 986KiB/s-986KiB/s (1010kB/s-1010kB/s), io=76.1MiB (79.8MB), run=79037-79037msec

Here,
runtime = 79.0s
Bandwidth = 985 KiB/s
IO size = 16 KiB (assuming block size)

IOPS = Bandwidth / IO size = (985 / 16) = 61 but in the output it's 29.

I think, fsync count is not part of IOPS but it decides the overall throughput. If yes then how do we calculate overall bandwidth? And what's the relationship b/w IOPS, fsync, and bandwidth?

Could anyone help me in understanding the output?

[vincentkfu]

This does seem strange.

The issued rwts line at the bottom says that there were 2350 write operations. With a 79 sec job, 2350/79 gives you the IOPS=29 value but that does not agree with the reported bandwidth.

Can you share your job file? Please simplify it to the smallest set of options that produce this problem. Consider also running with --debug=io,file to gain more insight into what fio is doing.

[raj-prince]

Thanks @vincentkfu!!

I am assuming in issued rwts, rwts means read, write, trim and sync respectively.

Here, fsync is also taking same amount of time as write operation. And while calculating IOPS we are not considering fsync, but it is being calculate in throughput calculation.

Currently it assumes (write + sync) = write;
if we start considering sync operation and given - latency of write ~ latency of sync.
So, the time only write operation was being performed = 38.5s (calculated using average latency of write and sync)

In that case IOPS = (2350 / 38.5) = 61.03

Bandwidth = IOPS * block_size = 61.03 * 16 KiB/s = 976.48 KiB/s

Please correct me if my understanding is wrong.