Bandwidth from bw logs does not match total average bandwidth

[sgf-dma]

Hi.

I can't understand fio results from writing to 2230 ssd connected through JMS583 enclosure. The job was:

[global]
ioengine=libaio
direct=1
group_reporting
filename=/dev/disk/by-name/jms

[sequential-fill]
description=Sequential fill phase
rw=write
iodepth=16
bs=64K
write_bw_log=write-iodepth-16-numjobs-1
write_lat_log=write-iodepth-16-numjobs-1
write_iops_log=write-iodepth-16-numjobs-1

and the results:

sequential-fill: (g=0): rw=write, bs=(R) 64.0KiB-64.0KiB, (W) 64.0KiB-64.0KiB, (T) 64.0KiB-64.0KiB, ioengine=libaio, iodepth=16
fio-3.33
Starting 1 process
Jobs: 1 (f=1): [W(1)][97.2%][w=422MiB/s][w=6757 IOPS][eta 01m:03s]
Jobs: 1 (f=1): [W(1)][97.3%][w=423MiB/s][w=6760 IOPS][eta 01m:02s]

Jobs: 1 (f=0): [f(1)][100.0%][eta 00m:00s]
sequential-fill: (groupid=0, jobs=1): err= 0: pid=88221: Fri Jun 20 23:22:00 2025
  Description  : [Sequential fill phase]
  write: IOPS=6582, BW=411MiB/s (431MB/s)(932GiB/2318609msec); 0 zone resets
    slat (usec): min=7, max=509, avg=10.91, stdev= 3.00
    clat (usec): min=207, max=43432, avg=2417.28, stdev=1154.06
     lat (usec): min=220, max=43443, avg=2428.19, stdev=1155.07
    clat percentiles (usec):
     |  1.00th=[ 2343],  5.00th=[ 2343], 10.00th=[ 2343], 20.00th=[ 2343],
     | 30.00th=[ 2343], 40.00th=[ 2343], 50.00th=[ 2343], 60.00th=[ 2343],
     | 70.00th=[ 2376], 80.00th=[ 2376], 90.00th=[ 2376], 95.00th=[ 2376],
     | 99.00th=[ 2442], 99.50th=[ 2507], 99.90th=[26346], 99.95th=[27395],
     | 99.99th=[29492]
   bw (  KiB/s): min= 1508, max=315515, per=6.59%, avg=27748.77, stdev=1488.98, samples=15261915
   iops        : min=    1, max=    1, avg= 1.00, stdev= 0.00, samples=15261915
  lat (usec)   : 250=0.01%, 500=0.01%, 750=0.01%, 1000=0.01%
  lat (msec)   : 2=0.04%, 4=99.62%, 10=0.06%, 20=0.04%, 50=0.25%
  cpu          : usr=1.28%, sys=7.33%, ctx=15259540, majf=0, minf=48812
  IO depths    : 1=0.1%, 2=0.1%, 4=0.1%, 8=0.1%, 16=100.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.0%, 16=0.1%, 32=0.0%, 64=0.0%, >=64=0.0%
     issued rwts: total=0,15261915,0,0 short=0,0,0,0 dropped=0,0,0,0
     latency   : target=0, window=0, percentile=100.00%, depth=16

Run status group 0 (all jobs):
  WRITE: bw=411MiB/s (431MB/s), 411MiB/s-411MiB/s (431MB/s-431MB/s), io=932GiB (1000GB), run=2318609-2318609msec

as far as i understand fio output, total average bandwidth is 411mb/s and this matches with what i've seen in iotop. But the bw line showing per-thread (or group? group_reporting was enable) bandwidth:

   bw (  KiB/s): min= 1508, max=315515, per=6.59%, avg=27748.77, stdev=1488.98, samples=15261915

states completely different speed - 27748kb/s. If i recalculate average bandwidth from fio bw logs, i also get this same value! But it can't be true, because it's impossible to overwrite whole 1tb ssd for just 40 minutes with that speed.

The per value in bw line also seems strange to me: there was only one job, so why does this job take only 6.59% of total bandwidth in a group? And who takes the rest 93%? Shouldn't this percent be 100%?

Thanks.

[sitsofe]

Hello @sgf-dma,

It's important to understand:

• The BW bandwidth in the write line is calculated by taking the total I/O done and dividing by the total time the job ran.
• The bw line (below the latency) is calculated by averaging out the samples that fio takes.

This difference in methodology can lead to discrepancy in numbers when calculation is happening over different periods.

I'm going to quote myself from the Differences in "BW" and "bw" results fio mailing list thread:

BW is an average per second. bw is an average of averages...

BW is calculated by summing all the I/O you did (1189MiB) and dividing
by time in seconds so (1189*1024.0)/(13001/1000.0)/1024 ~ 91.5

bw is calculated by summing all the "values" in the bw log and
dividing by the number of those values. Each value is itself some sort
of average but you don't know what period it is over. This can lead to
a big discrepancy.

[...]

By default write_bw_log logs per each I/O. It's going to be tough to
reach speeds of 100MBytes/s with only a few I/Os so let's ratchet the
numbers down to 1KByte/s [...]. Also the first column is
milliseconds so we need larger numbers there.

Imagine we do 1KByte/s in the first second and 2KByte/s in the second.
Also imagine we have a fixed block size of 512 bytes.

0, 1100, 0, 512
1, 1100, 0, 512
1000, 1100, 0, 512
1250, 1100, 0, 512
1500, 1100, 0, 512
1990, 1100, 0, 512

The last column gives us the size of each I/O done so 512 * 6 is the
total bytes we did and we were going for two seconds so: 512 * 6 / 2
= 1536 making the BW the job achieved 1.5KByte/s. On the other hand
each individual I/O is reporting a bandwidth of 1100KBytes/s but for
whatever reason in the first second we only managed to do two 512Byte
I/Os and in the second we manage 4 (perhaps there's throttling in
place which means they process fast but have big spaces between them).
1100 * 6 / 6 = 1100 KBytes/s so bw is 1100 KByte/s - radically
different from BW.

With a higher iodepth perhaps each individual I/O finishes slower
making per I/O average bandwidth (bw) go down but so many complete in
parallel that the total bandwidth achieved (BW) goes up.

To your questions:

But the bw line showing per-thread (or group? group_reporting was enable) bandwidth:

It's per job - notice how it's in the job section rather than the group summary.

If i recalculate average bandwidth from fio bw logs, i also get this same value!

Indeed but see above - you likely aren't manually grouping I/Os done into each second followed by working out the total transfer size that happened in that second and then averaging over all those seconds. You're likely averaging the per I/O value so you end up with the same value as bw...

The per value in bw line also seems strange to me: there was only one job, so why does this job take only 6.59% of total bandwidth in a group? And who takes the rest 93%? Shouldn't this percent be 100%?

Good questions - that (should be 100% with one job) is what I would have expected too! Playing around, it seems the per= value starts to vary depending on the iodepth when per I/O logging is being used so I wonder what period is being used to work out what the aggregate is - perhaps it's the sum of the count of I/Os that happened in the same millisecond within the log divided by the count lines of said I/Os in that millisecond averaged out over all the milliseconds? I think like a lot of the values on the bw line the per value will only really make sense when you use windowed logging (see log_avg_msec).

Does this answer your question?