Disk utilization statistics in terse format

Disk utilization statistics in terse format

[Vasily Tarasov]

Hi All,

When I run fio as a standalone application (without using a
server-client model) and use terse output format, disk utilization is
never printed. Here are the results of my analysis:

1) show_thread_status_terse_v2() does not call show_disk_util() at all.

2) show_thread_status_terse_v3_v4() does call show_disk_util(), but
only if is_backend variable is true (which is not, in case of a
standalone run).

3) __show_run_stats() call show_disk_util() only in case of
FIO_OUTPUT_JSON or FIO_OUTPUT_NORMAL formats.

There are several ways to fix this issue. I think the best way is to
call show_disk_util() from __show_run_stats() in case of terse format.
This will break the current terse format: disk utilization fields will
be printed in the end of the lines (after thread statistics), which is
not how the HOWTO defines it. But, it seems like the v2 format is
already inconsistent with HOWTO. And for v3 format, if client-server
model is used, disk utilization fields will be printed in the end of
the terse line anyway (at least this is my current understanding of
the code). So, what I suggest will bring consistency accross
client-server and standalone runs. We will also need to fix HOWTO.

Let me know what is the best way to fix this, and I'll be happy to send a patch.

Thanks,
Vasily

Re: Disk utilization statistics in terse format

[Jens Axboe]

On 2014-07-09 16:21, Vasily Tarasov wrote:
> Hi All,
>
> When I run fio as a standalone application (without using a
> server-client model) and use terse output format, disk utilization is
> never printed. Here are the results of my analysis:
>
> 1) show_thread_status_terse_v2() does not call show_disk_util() at all.
>
> 2) show_thread_status_terse_v3_v4() does call show_disk_util(), but
> only if is_backend variable is true (which is not, in case of a
> standalone run).
>
> 3) __show_run_stats() call show_disk_util() only in case of
> FIO_OUTPUT_JSON or FIO_OUTPUT_NORMAL formats.
>
> There are several ways to fix this issue. I think the best way is to
> call show_disk_util() from __show_run_stats() in case of terse format.
> This will break the current terse format: disk utilization fields will
> be printed in the end of the lines (after thread statistics), which is
> not how the HOWTO defines it. But, it seems like the v2 format is
> already inconsistent with HOWTO. And for v3 format, if client-server
> model is used, disk utilization fields will be printed in the end of
> the terse line anyway (at least this is my current understanding of
> the code). So, what I suggest will bring consistency accross
> client-server and standalone runs. We will also need to fix HOWTO.
>
> Let me know what is the best way to fix this, and I'll be happy to send a patch.

Seems like the is_backend check in _v3_v4 should just go. Can't come up 
with a good reason why that is there, it already knows if it should do 
json output, or normal output (and in terse format, if asked).

-- 
Jens Axboe

Re: Disk utilization statistics in terse format

[Vasily Tarasov]

If we just remove is_backend in the _v3_v4, then there will be
inconsistencies in the terse output between server-client and
standalone modes. In the server-client mode disk utilization will be
printed in the very end, while in the standalone mode corresponding
fields will be somewhere in the middle.

Actually, there are more inconsistencies between these modes. Check this out:

In the client-server mode:

<snip starts>
[user@frontend fios-24-reads]$ fio --minimal --status-interval=10
--client frontend 1.fio
hostname=bison01, be=0, 64-bit, os=Linux, arch=x86-64, fio=fio-2.1.10, flags=1
<bison01> sdaa: (g=0): rw=read, bs=1M-1M/1M-1M/1M-1M, ioengine=sync, iodepth=1
<bison01> Starting 1 process
<bison01> =1): [] [11.9% done] [191.2M/0K/0K /s] [186/0/0 iops] [eta 10m:50s]
fio: terminating on signal 2
<bison01>
3;fio-2.1.10;sdaa;0;0;17233920;195675;191;88074;0;0;0.000000;0.000000;4829;10900;5228.857219;220.162611;1.000000%=4896;5.000000%=4960;10.000000%=4960;20.000000%=5024;30.000000%=5088;40.000000%=5152;50.000000%=5280;60.000000%=5280;70.000000%=5344;80.000000%=5408;90.000000%=5472;95.000000%=5472;99.000000%=5536;99.500000%=5856;99.900000%=6432;99.950000%=9024;99.990000%=9408;0%=0;0%=0;0%=0;4830;10900;5229.256982;220.166861;188039;206023;100.000000%;195845.737143;5595.466346;0;0;0;0;0;0;0.000000;0.000000;0;0;0.000000;0.000000;1.000000%=0;5.000000%=0;10.000000%=0;20.000000%=0;30.000000%=0;40.000000%=0;50.000000%=0;60.000000%=0;70.000000%=0;80.000000%=0;90.000000%=0;95.000000%=0;99.000000%=0;99.500000%=0;99.900000%=0;99.950000%=0;99.990000%=0;0%=0;0%=0;0%=0;0;0;0.000000;0.000000;0;0;0.000000%;0.000000;0.000000;0.130574%;1.704268%;18221;0;286;100.0%;0.0%;0.0%;0.0%;0.0%;0.0%;0.0%;0.00%;0.00%;0.00%;0.00%;0.00%;0.00%;0.00%;0.00%;0.00%;0.00%;0.00%;0.00%;99.99%;0.01%;0.00%;0.00%;0.00%;0.00%;0.00%;0.00%;0.00%;0.00%

Run status group 0 (all jobs):
   READ: io=16830MB, aggrb=195675KB/s, minb=195675KB/s,
maxb=195675KB/s, mint=88074msec, maxt=88074msec

Disk stats (read/write):
;sdaa;33614;0;0;0;130703;0;130681;99.31%client: host=bison01 disconnected
<snip ends>

In the server mode:

<snip starts>
root@backend fios-24-reads]# fio --minimal --status-interval=10  1.fio
3;fio-2.1.10;sdaa;0;0;1943552;196278;191;9902;0;0;0.000000;0.000000;4835;9504;5210.884676;307.928200;1.000000%=4896;5.000000%=4896;10.000000%=4960;20.000000%=4960;30.000000%=4960;40.000000%=5024;50.000000%=5280;60.000000%=5344;70.000000%=5344;80.000000%=5408;90.000000%=5472;95.000000%=5536;99.000000%=5600;99.500000%=5984;99.900000%=9408;99.950000%=9536;99.990000%=9536;0%=0;0%=0;0%=0;4836;9504;5211.332807;307.944109;188039;206023;99.949829%;196179.526316;7200.889724;0;0;0;0;0;0;0.000000;0.000000;0;0;0.000000;0.000000;1.000000%=0;5.000000%=0;10.000000%=0;20.000000%=0;30.000000%=0;40.000000%=0;50.000000%=0;60.000000%=0;70.000000%=0;80.000000%=0;90.000000%=0;95.000000%=0;99.000000%=0;99.500000%=0;99.900000%=0;99.950000%=0;99.990000%=0;0%=0;0%=0;0%=0;0;0;0.000000;0.000000;0;0;0.000000%;0.000000;0.000000;0.090891%;1.959200%;2046;0;287;100.0%;0.0%;0.0%;0.0%;0.0%;0.0%;0.0%;0.00%;0.00%;0.00%;0.00%;0.00%;0.00%;0.00%;0.00%;0.00%;0.00%;0.00%;0.00%;100.00%;0.00%;0.00%;0.00%;0.00%;0.00%;0.00%;0.00%;0.00%;0.00%
3;fio-2.1.10;sdaa;0;0;3913728;196620;192;19905;0;0;0.000000;0.000000;4835;9543;5203.414596;282.073042;1.000000%=4896;5.000000%=4896;10.000000%=4960;20.000000%=4960;30.000000%=4960;40.000000%=5024;50.000000%=5280;60.000000%=5344;70.000000%=5344;80.000000%=5408;90.000000%=5472;95.000000%=5536;99.000000%=5536;99.500000%=5920;99.900000%=9280;99.950000%=9536;99.990000%=9536;0%=0;0%=0;0%=0;4836;9543;5203.836254;282.086563;187665;206023;100.000000%;196695.435897;7344.748539;0;0;0;0;0;0;0.000000;0.000000;0;0;0.000000;0.000000;1.000000%=0;5.000000%=0;10.000000%=0;20.000000%=0;30.000000%=0;40.000000%=0;50.000000%=0;60.000000%=0;70.000000%=0;80.000000%=0;90.000000%=0;95.000000%=0;99.000000%=0;99.500000%=0;99.900000%=0;99.950000%=0;99.990000%=0;0%=0;0%=0;0%=0;0;0;0.000000;0.000000;0;0;0.000000%;0.000000;0.000000;0.110525%;1.914092%;4106;0;288;100.0%;0.0%;0.0%;0.0%;0.0%;0.0%;0.0%;0.00%;0.00%;0.00%;0.00%;0.00%;0.00%;0.00%;0.00%;0.00%;0.00%;0.00%;0.00%;100.00%;0.00%;0.00%;0.00%;0.00%;0.00%;0.00%;0.00%;0.00%;0.00%
3;fio-2.1.10;sdaa;0;0;5872640;196356;191;29908;0;0;0.000000;0.000000;4835;44944;5210.319038;585.202403;1.000000%=4896;5.000000%=4896;10.000000%=4960;20.000000%=4960;30.000000%=4960;40.000000%=5088;50.000000%=5280;60.000000%=5344;70.000000%=5344;80.000000%=5408;90.000000%=5472;95.000000%=5536;99.000000%=5536;99.500000%=5792;99.900000%=9152;99.950000%=9536;99.990000%=44800;0%=0;0%=0;0%=0;4836;44945;5210.726464;585.217778;185256;206023;100.000000%;196535.135593;7198.734852;0;0;0;0;0;0;0.000000;0.000000;0;0;0.000000;0.000000;1.000000%=0;5.000000%=0;10.000000%=0;20.000000%=0;30.000000%=0;40.000000%=0;50.000000%=0;60.000000%=0;70.000000%=0;80.000000%=0;90.000000%=0;95.000000%=0;99.000000%=0;99.500000%=0;99.900000%=0;99.950000%=0;99.990000%=0;0%=0;0%=0;0%=0;0;0;0.000000;0.000000;0;0;0.000000%;0.000000;0.000000;0.103651%;1.895814%;6174;0;288;100.0%;0.0%;0.0%;0.0%;0.0%;0.0%;0.0%;0.00%;0.00%;0.00%;0.00%;0.00%;0.00%;0.00%;0.00%;0.00%;0.00%;0.00%;0.00%;99.98%;0.00%;0.02%;0.00%;0.00%;0.00%;0.00%;0.00%;0.00%;0.00%
^C
fio: terminating on signal 2
3;fio-2.1.10;sdaa;0;0;7492608;196275;191;38174;0;0;0.000000;0.000000;4835;44944;5212.864015;523.029154;1.000000%=4896;5.000000%=4960;10.000000%=4960;20.000000%=4960;30.000000%=5024;40.000000%=5088;50.000000%=5280;60.000000%=5344;70.000000%=5344;80.000000%=5408;90.000000%=5472;95.000000%=5472;99.000000%=5536;99.500000%=5792;99.900000%=6432;99.950000%=9408;99.990000%=44800;0%=0;0%=0;0%=0;4836;44945;5213.266366;523.043881;185256;206023;100.000000%;196534.373333;6663.858266;0;0;0;0;0;0;0.000000;0.000000;0;0;0.000000;0.000000;1.000000%=0;5.000000%=0;10.000000%=0;20.000000%=0;30.000000%=0;40.000000%=0;50.000000%=0;60.000000%=0;70.000000%=0;80.000000%=0;90.000000%=0;95.000000%=0;99.000000%=0;99.500000%=0;99.900000%=0;99.950000%=0;99.990000%=0;0%=0;0%=0;0%=0;0;0;0.000000;0.000000;0;0;0.000000%;0.000000;0.000000;0.110025%;1.888770%;7891;0;288;100.0%;0.0%;0.0%;0.0%;0.0%;0.0%;0.0%;0.00%;0.00%;0.00%;0.00%;0.00%;0.00%;0.00%;0.00%;0.00%;0.00%;0.00%;0.00%;99.99%;0.00%;0.01%;0.00%;0.00%;0.00%;0.00%;0.00%;0.00%;0.00%
<snip ends>

Notice, it seems like  --status-interval does not work at all in the
client-server mode.

So, I would say that there are two problems:

1) --status-interval does not  work in the client server mode

2) Terse output should look the same in both modes

Do you think what I say is reasonable?..

Thanks,
Vasily

On Thu, Jul 10, 2014 at 4:48 AM, Jens Axboe <axboe@kernel.dk> wrote:
> On 2014-07-09 16:21, Vasily Tarasov wrote:
>>
>> Hi All,
>>
>> When I run fio as a standalone application (without using a
>> server-client model) and use terse output format, disk utilization is
>> never printed. Here are the results of my analysis:
>>
>> 1) show_thread_status_terse_v2() does not call show_disk_util() at all.
>>
>> 2) show_thread_status_terse_v3_v4() does call show_disk_util(), but
>> only if is_backend variable is true (which is not, in case of a
>> standalone run).
>>
>> 3) __show_run_stats() call show_disk_util() only in case of
>> FIO_OUTPUT_JSON or FIO_OUTPUT_NORMAL formats.
>>
>> There are several ways to fix this issue. I think the best way is to
>> call show_disk_util() from __show_run_stats() in case of terse format.
>> This will break the current terse format: disk utilization fields will
>> be printed in the end of the lines (after thread statistics), which is
>> not how the HOWTO defines it. But, it seems like the v2 format is
>> already inconsistent with HOWTO. And for v3 format, if client-server
>> model is used, disk utilization fields will be printed in the end of
>> the terse line anyway (at least this is my current understanding of
>> the code). So, what I suggest will bring consistency accross
>> client-server and standalone runs. We will also need to fix HOWTO.
>>
>> Let me know what is the best way to fix this, and I'll be happy to send a
>> patch.
>
>
> Seems like the is_backend check in _v3_v4 should just go. Can't come up with
> a good reason why that is there, it already knows if it should do json
> output, or normal output (and in terse format, if asked).
>
> --
> Jens Axboe
>

Re: Disk utilization statistics in terse format

[Jens Axboe]

On 2014-07-12 01:25, Vasily Tarasov wrote:
> If we just remove is_backend in the _v3_v4, then there will be
> inconsistencies in the terse output between server-client and
> standalone modes. In the server-client mode disk utilization will be
> printed in the very end, while in the standalone mode corresponding
> fields will be somewhere in the middle.
>
> Actually, there are more inconsistencies between these modes. Check this out:
>
> In the client-server mode:
>
> <snip starts>
> [user@frontend fios-24-reads]$ fio --minimal --status-interval=10
> --client frontend 1.fio
> hostname=bison01, be=0, 64-bit, os=Linux, arch=x86-64, fio=fio-2.1.10, flags=1
> <bison01> sdaa: (g=0): rw=read, bs=1M-1M/1M-1M/1M-1M, ioengine=sync, iodepth=1
> <bison01> Starting 1 process
> <bison01> =1): [] [11.9% done] [191.2M/0K/0K /s] [186/0/0 iops] [eta 10m:50s]
> fio: terminating on signal 2
> <bison01>
> 3;fio-2.1.10;sdaa;0;0;17233920;195675;191;88074;0;0;0.000000;0.000000;4829;10900;5228.857219;220.162611;1.000000%=4896;5.000000%=4960;10.000000%=4960;20.000000%=5024;30.000000%=5088;40.000000%=5152;50.000000%=5280;60.000000%=5280;70.000000%=5344;80.000000%=5408;90.000000%=5472;95.000000%=5472;99.000000%=5536;99.500000%=5856;99.900000%=6432;99.950000%=9024;99.990000%=9408;0%=0;0%=0;0%=0;4830;10900;5229.256982;220.166861;188039;206023;100.000000%;195845.737143;5595.466346;0;0;0;0;0;0;0.000000;0.000000;0;0;0.000000;0.000000;1.000000%=0;5.000000%=0;10.000000%=0;20.000000%=0;30.000000%=0;40.000000%=0;50.000000%=0;60.000000%=0;70.000000%=0;80.000000%=0;90.000000%=0;95.000000%=0;99.000000%=0;99.500000%=0;99.900000%=0;99.950000%=0;99.990000%=0;0%=0;0%=0;0%=0;0;0;0.000000;0.000000;0;0;0.000000%;0.000000;0.000000;0.130574%;1.704268%;18221;0;286;100.0%;0.0%;0.0%;0.0%;0.0%;0.0%;0.0%;0.00%;0.00%;0.00%;0.00%;0.00%;0.00%;0.00%;0.00%;0.00%;0.00%;0.00%;0.00%;99.99%;0.01%;0.00%;0.00%;0.00%;0.00%;0.00
%;0.00%;0.00%;0.00%
>
> Run status group 0 (all jobs):
>     READ: io=16830MB, aggrb=195675KB/s, minb=195675KB/s,
> maxb=195675KB/s, mint=88074msec, maxt=88074msec
>
> Disk stats (read/write):
> ;sdaa;33614;0;0;0;130703;0;130681;99.31%client: host=bison01 disconnected
> <snip ends>
>
> In the server mode:
>
> <snip starts>
> root@backend fios-24-reads]# fio --minimal --status-interval=10  1.fio
> 3;fio-2.1.10;sdaa;0;0;1943552;196278;191;9902;0;0;0.000000;0.000000;4835;9504;5210.884676;307.928200;1.000000%=4896;5.000000%=4896;10.000000%=4960;20.000000%=4960;30.000000%=4960;40.000000%=5024;50.000000%=5280;60.000000%=5344;70.000000%=5344;80.000000%=5408;90.000000%=5472;95.000000%=5536;99.000000%=5600;99.500000%=5984;99.900000%=9408;99.950000%=9536;99.990000%=9536;0%=0;0%=0;0%=0;4836;9504;5211.332807;307.944109;188039;206023;99.949829%;196179.526316;7200.889724;0;0;0;0;0;0;0.000000;0.000000;0;0;0.000000;0.000000;1.000000%=0;5.000000%=0;10.000000%=0;20.000000%=0;30.000000%=0;40.000000%=0;50.000000%=0;60.000000%=0;70.000000%=0;80.000000%=0;90.000000%=0;95.000000%=0;99.000000%=0;99.500000%=0;99.900000%=0;99.950000%=0;99.990000%=0;0%=0;0%=0;0%=0;0;0;0.000000;0.000000;0;0;0.000000%;0.000000;0.000000;0.090891%;1.959200%;2046;0;287;100.0%;0.0%;0.0%;0.0%;0.0%;0.0%;0.0%;0.00%;0.00%;0.00%;0.00%;0.00%;0.00%;0.00%;0.00%;0.00%;0.00%;0.00%;0.00%;100.00%;0.00%;0.00%;0.00%;0.00%;0.00%;0.00%;0.0
0%;0.00%;0.00%
> 3;fio-2.1.10;sdaa;0;0;3913728;196620;192;19905;0;0;0.000000;0.000000;4835;9543;5203.414596;282.073042;1.000000%=4896;5.000000%=4896;10.000000%=4960;20.000000%=4960;30.000000%=4960;40.000000%=5024;50.000000%=5280;60.000000%=5344;70.000000%=5344;80.000000%=5408;90.000000%=5472;95.000000%=5536;99.000000%=5536;99.500000%=5920;99.900000%=9280;99.950000%=9536;99.990000%=9536;0%=0;0%=0;0%=0;4836;9543;5203.836254;282.086563;187665;206023;100.000000%;196695.435897;7344.748539;0;0;0;0;0;0;0.000000;0.000000;0;0;0.000000;0.000000;1.000000%=0;5.000000%=0;10.000000%=0;20.000000%=0;30.000000%=0;40.000000%=0;50.000000%=0;60.000000%=0;70.000000%=0;80.000000%=0;90.000000%=0;95.000000%=0;99.000000%=0;99.500000%=0;99.900000%=0;99.950000%=0;99.990000%=0;0%=0;0%=0;0%=0;0;0;0.000000;0.000000;0;0;0.000000%;0.000000;0.000000;0.110525%;1.914092%;4106;0;288;100.0%;0.0%;0.0%;0.0%;0.0%;0.0%;0.0%;0.00%;0.00%;0.00%;0.00%;0.00%;0.00%;0.00%;0.00%;0.00%;0.00%;0.00%;0.00%;100.00%;0.00%;0.00%;0.00%;0.00%;0.00%;0.00%;0
.00%;0.00%;0.00%
> 3;fio-2.1.10;sdaa;0;0;5872640;196356;191;29908;0;0;0.000000;0.000000;4835;44944;5210.319038;585.202403;1.000000%=4896;5.000000%=4896;10.000000%=4960;20.000000%=4960;30.000000%=4960;40.000000%=5088;50.000000%=5280;60.000000%=5344;70.000000%=5344;80.000000%=5408;90.000000%=5472;95.000000%=5536;99.000000%=5536;99.500000%=5792;99.900000%=9152;99.950000%=9536;99.990000%=44800;0%=0;0%=0;0%=0;4836;44945;5210.726464;585.217778;185256;206023;100.000000%;196535.135593;7198.734852;0;0;0;0;0;0;0.000000;0.000000;0;0;0.000000;0.000000;1.000000%=0;5.000000%=0;10.000000%=0;20.000000%=0;30.000000%=0;40.000000%=0;50.000000%=0;60.000000%=0;70.000000%=0;80.000000%=0;90.000000%=0;95.000000%=0;99.000000%=0;99.500000%=0;99.900000%=0;99.950000%=0;99.990000%=0;0%=0;0%=0;0%=0;0;0;0.000000;0.000000;0;0;0.000000%;0.000000;0.000000;0.103651%;1.895814%;6174;0;288;100.0%;0.0%;0.0%;0.0%;0.0%;0.0%;0.0%;0.00%;0.00%;0.00%;0.00%;0.00%;0.00%;0.00%;0.00%;0.00%;0.00%;0.00%;0.00%;99.98%;0.00%;0.02%;0.00%;0.00%;0.00%;0.00%
;0.00%;0.00%;0.00%
> ^C
> fio: terminating on signal 2
> 3;fio-2.1.10;sdaa;0;0;7492608;196275;191;38174;0;0;0.000000;0.000000;4835;44944;5212.864015;523.029154;1.000000%=4896;5.000000%=4960;10.000000%=4960;20.000000%=4960;30.000000%=5024;40.000000%=5088;50.000000%=5280;60.000000%=5344;70.000000%=5344;80.000000%=5408;90.000000%=5472;95.000000%=5472;99.000000%=5536;99.500000%=5792;99.900000%=6432;99.950000%=9408;99.990000%=44800;0%=0;0%=0;0%=0;4836;44945;5213.266366;523.043881;185256;206023;100.000000%;196534.373333;6663.858266;0;0;0;0;0;0;0.000000;0.000000;0;0;0.000000;0.000000;1.000000%=0;5.000000%=0;10.000000%=0;20.000000%=0;30.000000%=0;40.000000%=0;50.000000%=0;60.000000%=0;70.000000%=0;80.000000%=0;90.000000%=0;95.000000%=0;99.000000%=0;99.500000%=0;99.900000%=0;99.950000%=0;99.990000%=0;0%=0;0%=0;0%=0;0;0;0.000000;0.000000;0;0;0.000000%;0.000000;0.000000;0.110025%;1.888770%;7891;0;288;100.0%;0.0%;0.0%;0.0%;0.0%;0.0%;0.0%;0.00%;0.00%;0.00%;0.00%;0.00%;0.00%;0.00%;0.00%;0.00%;0.00%;0.00%;0.00%;99.99%;0.00%;0.01%;0.00%;0.00%;0.00%;0.00%
;0.00%;0.00%;0.00%
> <snip ends>
>
> Notice, it seems like  --status-interval does not work at all in the
> client-server mode.
>
> So, I would say that there are two problems:
>
> 1) --status-interval does not  work in the client server mode
>
> 2) Terse output should look the same in both modes
>
> Do you think what I say is reasonable?..

Yes, that sounds very reasonable. It's the main reason I hate the terse 
format, it's just impossible to both verify and present nicely (and 
uniformly). I usually encourage people to use the json output, which has 
the nice property of being easily readable for both humans and 
computers. And it's easily extendable.

-- 
Jens Axboe