RE: "No I/O performed by <engine>" reporting bug?

[Date Prev][Date Next][Thread Prev][Thread Next][Date Index][Thread Index]

 



Sitsofe, 

Thanks.   I gave it a try and no longer see the error message.   However, it doesn't appear that the loop count is being used any longer when number_ios option is set.  The following runs is less about a second: 

$ fio --ioengine=libaio --loops=32 --direct=1 --numjobs=1 --norandommap --randrepeat=0 --size=16GB --filename=/dev/sdb --name=Random-read-4K-QD1 --rw=randread --bs=4K --iodepth=1 --number_ios=8192
Random-read-4K-QD1: (g=0): rw=randread, bs=(R) 4096B-4096B, (W) 4096B-4096B, (T) 4096B-4096B, ioengine=libaio, iodepth=1
fio-3.5
Starting 1 process
Jobs: 1 (f=1)
Random-read-4K-QD1: (groupid=0, jobs=1): err= 0: pid=31578: Mon Mar 26 10:37:06 2018
   read: IOPS=7433, BW=29.0MiB/s (30.4MB/s)(32.0MiB/1102msec)
    slat (nsec): min=4564, max=43459, avg=6011.65, stdev=662.43
...
Run status group 0 (all jobs):
   READ: bw=29.0MiB/s (30.4MB/s), 29.0MiB/s-29.0MiB/s (30.4MB/s-30.4MB/s), io=32.0MiB (33.6MB), run=1102-1102msec



But, if I use io_size=32MB, it does actually run for about 30 seconds as expected:

$  fio --ioengine=libaio --loops=32 --direct=1 --numjobs=1 --norandommap --randrepeat=0 --size=16GB --filename=/dev/sdb --name=Random-read-4K-QD1 --rw=randread --bs=4K --iodepth=1 --io_size=32MB
Random-read-4K-QD1: (g=0): rw=randread, bs=(R) 4096B-4096B, (W) 4096B-4096B, (T) 4096B-4096B, ioengine=libaio, iodepth=1
fio-3.5
Starting 1 process
Random-read-4K-QD1: No I/O performed by libaio, perhaps try --debug=io option for details?

Random-read-4K-QD1: (groupid=0, jobs=1): err= 0: pid=31998: Mon Mar 26 10:46:45 2018
   read: IOPS=7790, BW=30.4MiB/s (31.9MB/s)(1024MiB/33650msec)
    slat (nsec): min=4443, max=43457, avg=4831.99, stdev=286.39
...
Run status group 0 (all jobs):
   READ: bw=30.4MiB/s (31.9MB/s), 30.4MiB/s-30.4MiB/s (31.9MB/s-31.9MB/s), io=1024MiB (1074MB), run=33650-33650msec

Disk stats (read/write):
  sdb: ios=262130/0, merge=0/0, ticks=31453/0, in_queue=31396, util=93.06%


Thanks again.

Kris Davis

-----Original Message-----
From: Sitsofe Wheeler [mailto:sitsofe@xxxxxxxxx] 
Sent: Saturday, March 24, 2018 12:33 PM
To: Kris Davis <Kris.Davis@xxxxxxx>
Cc: fio@xxxxxxxxxxxxxxx; Itay Ben Yaacov <Itay.BenYaacov@xxxxxxx>
Subject: Re: "No I/O performed by <engine>" reporting bug?

On 23 March 2018 at 21:45, Sitsofe Wheeler <sitsofe@xxxxxxxxx> wrote:
> On 23 March 2018 at 16:08, Kris Davis <Kris.Davis@xxxxxxx> wrote:
>> In fio version 2.20 a test seems to have been added to backend.c which "may" falsely report that no I/O has occurred.
[...]
>> In the following fio test, the error message is logged, even though 
>> it appears that everything has run ok (fio built from main below, but results appear to be the same with at least fio version 2.21) (It's also interesting to note that the estimated "eta" is also grossly inaccurate [captured while running below] - but that is a different issue I think).

Yeah that's going to be a separate issue. The thread_eta() in eta.c doesn't look at the number of I/Os only the guessed total bytes and how far through fio has progressed through that.

>> You can see the " Random-read-4K-QD1: No I/O performed by libaio, perhaps try --debug=io option for details?" error message below, which "appears" to be false.
>>
>>     $ fio --ioengine=libaio --loops=32 --direct=1 --numjobs=1--norandommap --randrepeat=0 --size=16GB --filename=/dev/sdb --name=Random-read-4K-QD1 --rw=randread --bs=4K --iodepth=1 --number_ios=8192
>>     Random-read-4K-QD1: (g=0): rw=randread, bs=(R) 4096B-4096B, (W) 4096B-4096B, (T) 4096B-4096B, ioengine=libaio, iodepth=1
>>     fio-3.5-60-g69c5
>>     Starting 1 process
>>     Jobs: 1 (f=1): [r(1)][0.2%][r=30.9MiB/s,w=0KiB/s][r=7898,w=0 
>> IOPS][eta 04h:45m:35s]
>>
>>     Random-read-4K-QD1: No I/O performed by libaio, perhaps try --debug=io option for details?
>>
> [...]
>>
>> I added a print message which showed that both ddir_rw_sum(bytes_done) and did_some_io values were zero at that point in the code.
>> I didn't try to dig into the operation of the bytes_done and did_some_io values further, yet.
>>
>>
>> Also, I noticed that if option "--io_size=32M" was used instead of "number_ios=8192", then the eta appeared to be accurate - so the eta issue does "appear" to be independent - I can open a separate discussion or issue if desired.

A separate discussion would be good.

> Just quickly looking I think this is down to number_ios=<val> being 
> paired with loops=32 but I haven't had time to dig further...

After getting the wrong end of the stick and wondering if Jens was trying to make number_ios only account for the current loop's I/O with
https://github.com/axboe/fio/commit/cf8a46a75f38afe07ebf823210f95543999e3116
("Make 'loops' honor full write+verify loops") I think one of the changes there was just a simple mistake while fixing other areas up.
Can you see if https://github.com/sitsofe/fio/tree/loops_numberios
fixes what you were seeing?

--
Sitsofe | http://sucs.org/~sits/
��.n��������+%������w��{.n�������^n�r������&��z�ޗ�zf���h���~����������_��+v���)ߣ�

[Index of Archives]     [Linux Kernel]     [Linux SCSI]     [Linux IDE]     [Linux USB Devel]     [Video for Linux]     [Linux Audio Users]     [Yosemite News]     [Linux SCSI]

  Powered by Linux