Output logs and keep command line display

Output logs and keep command line display

[Gavin Martin]

Hi,

Not sure if I am missing a special argument somewhere, but I like the
command line display we get from Fio when it runs showing the type of
workload and job descriptions and percentage complete, etc.  Is it
possible to get the outputs that you get when using the --minimal
argument (in JSON, CSV formats) whilst still keeping the command line
display.

Having this would make it similar to Iometer, not in a graphical
sense, but in a way that you can see exactly what is occurring (and if
it has halted or crashed) whilst still having logs that could be
charted or plotted into reports.  Especially useful for extended test
runs (over several hours!)

Thanks,
Gavin

-- 


------------------------------
For additional information including the registered office and the treatment of Xyratex confidential information please visit www.xyratex.com

------------------------------

Re: Output logs and keep command line display

[Jens Axboe]

On Thu, Jan 31 2013, Gavin Martin wrote:
> Hi,
> 
> Not sure if I am missing a special argument somewhere, but I like the
> command line display we get from Fio when it runs showing the type of
> workload and job descriptions and percentage complete, etc.  Is it
> possible to get the outputs that you get when using the --minimal
> argument (in JSON, CSV formats) whilst still keeping the command line
> display.
> 
> Having this would make it similar to Iometer, not in a graphical
> sense, but in a way that you can see exactly what is occurring (and if
> it has halted or crashed) whilst still having logs that could be
> charted or plotted into reports.  Especially useful for extended test
> runs (over several hours!)

--eta=always

should do the trick for you, if I understand your request correctly. I
suppose for that to be useful, you want to redirect the csv/json output
to a file as well?

Might be useful to have the behaviour of:

--output-format=type [file]

where if 'file' is given, then output goes to that file in the specified
format, and fio still uses stdout for the ETA output.

-- 
Jens Axboe

Re: Output logs and keep command line display

[Jens Axboe]

On Thu, Jan 31 2013, Jens Axboe wrote:
> On Thu, Jan 31 2013, Gavin Martin wrote:
> > Hi,
> > 
> > Not sure if I am missing a special argument somewhere, but I like the
> > command line display we get from Fio when it runs showing the type of
> > workload and job descriptions and percentage complete, etc.  Is it
> > possible to get the outputs that you get when using the --minimal
> > argument (in JSON, CSV formats) whilst still keeping the command line
> > display.
> > 
> > Having this would make it similar to Iometer, not in a graphical
> > sense, but in a way that you can see exactly what is occurring (and if
> > it has halted or crashed) whilst still having logs that could be
> > charted or plotted into reports.  Especially useful for extended test
> > runs (over several hours!)
> 
> --eta=always
> 
> should do the trick for you, if I understand your request correctly. I
> suppose for that to be useful, you want to redirect the csv/json output
> to a file as well?
> 
> Might be useful to have the behaviour of:
> 
> --output-format=type [file]
> 
> where if 'file' is given, then output goes to that file in the specified
> format, and fio still uses stdout for the ETA output.

So we already have --output, so we don't need the extra argument to the
format option. What is missing is just the below - that will continue to
use the ETA running output to stdout, if a file was chosen for the
output of the results.

IOW, if you do:

$ fio --output-format=json --output=somefile

then fio (with the below patch) would output results to 'somefile' while
still doing the running stdout output.

That should do what you need, correct?


diff --git a/eta.c b/eta.c
index 39fe10f..cfb8679 100644
--- a/eta.c
+++ b/eta.c
@@ -285,7 +285,8 @@ int calc_thread_status(struct jobs_eta *je, int force)
 	static struct timeval rate_prev_time, disp_prev_time;
 
 	if (!force) {
-		if (output_format != FIO_OUTPUT_NORMAL)
+		if (output_format != FIO_OUTPUT_NORMAL &&
+		    f_out == stdout)
 			return 0;
 		if (temp_stall_ts || eta_print == FIO_ETA_NEVER)
 			return 0;

-- 
Jens Axboe

Re: Output logs and keep command line display

[Gavin Martin]

On 31 January 2013 14:08, Jens Axboe <axboe@kernel.dk> wrote:
> On Thu, Jan 31 2013, Jens Axboe wrote:
>> On Thu, Jan 31 2013, Gavin Martin wrote:
>> > Hi,
>> >
>> > Not sure if I am missing a special argument somewhere, but I like the
>> > command line display we get from Fio when it runs showing the type of
>> > workload and job descriptions and percentage complete, etc.  Is it
>> > possible to get the outputs that you get when using the --minimal
>> > argument (in JSON, CSV formats) whilst still keeping the command line
>> > display.
>> >
>> > Having this would make it similar to Iometer, not in a graphical
>> > sense, but in a way that you can see exactly what is occurring (and if
>> > it has halted or crashed) whilst still having logs that could be
>> > charted or plotted into reports.  Especially useful for extended test
>> > runs (over several hours!)
>>
>> --eta=always
>>
>> should do the trick for you, if I understand your request correctly. I
>> suppose for that to be useful, you want to redirect the csv/json output
>> to a file as well?
>>
>> Might be useful to have the behaviour of:
>>
>> --output-format=type [file]
>>
>> where if 'file' is given, then output goes to that file in the specified
>> format, and fio still uses stdout for the ETA output.
>
> So we already have --output, so we don't need the extra argument to the
> format option. What is missing is just the below - that will continue to
> use the ETA running output to stdout, if a file was chosen for the
> output of the results.
>
> IOW, if you do:
>
> $ fio --output-format=json --output=somefile
>
> then fio (with the below patch) would output results to 'somefile' while
> still doing the running stdout output.
>
> That should do what you need, correct?
>
>
> diff --git a/eta.c b/eta.c
> index 39fe10f..cfb8679 100644
> --- a/eta.c
> +++ b/eta.c
> @@ -285,7 +285,8 @@ int calc_thread_status(struct jobs_eta *je, int force)
>         static struct timeval rate_prev_time, disp_prev_time;
>
>         if (!force) {
> -               if (output_format != FIO_OUTPUT_NORMAL)
> +               if (output_format != FIO_OUTPUT_NORMAL &&
> +                   f_out == stdout)
>                         return 0;
>                 if (temp_stall_ts || eta_print == FIO_ETA_NEVER)
>                         return 0;
>
> --
> Jens Axboe
>
> --
> To unsubscribe from this list: send the line "unsubscribe fio" in
> the body of a message to majordomo@vger.kernel.org
> More majordomo info at  http://vger.kernel.org/majordomo-info.html

Hi Jens,

You are quick, I was half-way through a reply when you came back with
an answer :)

Yes keeping the std output as per normal, and also having the CSV/JSON
output to a file that we can use to create graphs and reports. As you
suggest above that would work.

 The only problem I can see is from increasing the memory usage due to
the extra logging.  Would implementing this increase the memory usage?

-- 


------------------------------
For additional information including the registered office and the treatment of Xyratex confidential information please visit www.xyratex.com

------------------------------

Re: Output logs and keep command line display

[Jens Axboe]

On Thu, Jan 31 2013, Gavin Martin wrote:
> On 31 January 2013 14:08, Jens Axboe <axboe@kernel.dk> wrote:
> > On Thu, Jan 31 2013, Jens Axboe wrote:
> >> On Thu, Jan 31 2013, Gavin Martin wrote:
> >> > Hi,
> >> >
> >> > Not sure if I am missing a special argument somewhere, but I like the
> >> > command line display we get from Fio when it runs showing the type of
> >> > workload and job descriptions and percentage complete, etc.  Is it
> >> > possible to get the outputs that you get when using the --minimal
> >> > argument (in JSON, CSV formats) whilst still keeping the command line
> >> > display.
> >> >
> >> > Having this would make it similar to Iometer, not in a graphical
> >> > sense, but in a way that you can see exactly what is occurring (and if
> >> > it has halted or crashed) whilst still having logs that could be
> >> > charted or plotted into reports.  Especially useful for extended test
> >> > runs (over several hours!)
> >>
> >> --eta=always
> >>
> >> should do the trick for you, if I understand your request correctly. I
> >> suppose for that to be useful, you want to redirect the csv/json output
> >> to a file as well?
> >>
> >> Might be useful to have the behaviour of:
> >>
> >> --output-format=type [file]
> >>
> >> where if 'file' is given, then output goes to that file in the specified
> >> format, and fio still uses stdout for the ETA output.
> >
> > So we already have --output, so we don't need the extra argument to the
> > format option. What is missing is just the below - that will continue to
> > use the ETA running output to stdout, if a file was chosen for the
> > output of the results.
> >
> > IOW, if you do:
> >
> > $ fio --output-format=json --output=somefile
> >
> > then fio (with the below patch) would output results to 'somefile' while
> > still doing the running stdout output.
> >
> > That should do what you need, correct?
> >
> >
> > diff --git a/eta.c b/eta.c
> > index 39fe10f..cfb8679 100644
> > --- a/eta.c
> > +++ b/eta.c
> > @@ -285,7 +285,8 @@ int calc_thread_status(struct jobs_eta *je, int force)
> >         static struct timeval rate_prev_time, disp_prev_time;
> >
> >         if (!force) {
> > -               if (output_format != FIO_OUTPUT_NORMAL)
> > +               if (output_format != FIO_OUTPUT_NORMAL &&
> > +                   f_out == stdout)
> >                         return 0;
> >                 if (temp_stall_ts || eta_print == FIO_ETA_NEVER)
> >                         return 0;
> >
> > --
> > Jens Axboe
> >
> > --
> > To unsubscribe from this list: send the line "unsubscribe fio" in
> > the body of a message to majordomo@vger.kernel.org
> > More majordomo info at  http://vger.kernel.org/majordomo-info.html
> 
> Hi Jens,
> 
> You are quick, I was half-way through a reply when you came back with
> an answer :)
> 
> Yes keeping the std output as per normal, and also having the CSV/JSON
> output to a file that we can use to create graphs and reports. As you
> suggest above that would work.

Thought so, I will commit it.

>  The only problem I can see is from increasing the memory usage due to
> the extra logging.  Would implementing this increase the memory usage?

The ETA logging carries no additional memory overhead, so that is not a
concern.

-- 
Jens Axboe

Re: Output logs and keep command line display

[Gavin Martin]

On 31 January 2013 14:24, Jens Axboe <axboe@kernel.dk> wrote:
> On Thu, Jan 31 2013, Gavin Martin wrote:
>> On 31 January 2013 14:08, Jens Axboe <axboe@kernel.dk> wrote:
>> > On Thu, Jan 31 2013, Jens Axboe wrote:
>> >> On Thu, Jan 31 2013, Gavin Martin wrote:
>> >> > Hi,
>> >> >
>> >> > Not sure if I am missing a special argument somewhere, but I like the
>> >> > command line display we get from Fio when it runs showing the type of
>> >> > workload and job descriptions and percentage complete, etc.  Is it
>> >> > possible to get the outputs that you get when using the --minimal
>> >> > argument (in JSON, CSV formats) whilst still keeping the command line
>> >> > display.
>> >> >
>> >> > Having this would make it similar to Iometer, not in a graphical
>> >> > sense, but in a way that you can see exactly what is occurring (and if
>> >> > it has halted or crashed) whilst still having logs that could be
>> >> > charted or plotted into reports.  Especially useful for extended test
>> >> > runs (over several hours!)
>> >>
>> >> --eta=always
>> >>
>> >> should do the trick for you, if I understand your request correctly. I
>> >> suppose for that to be useful, you want to redirect the csv/json output
>> >> to a file as well?
>> >>
>> >> Might be useful to have the behaviour of:
>> >>
>> >> --output-format=type [file]
>> >>
>> >> where if 'file' is given, then output goes to that file in the specified
>> >> format, and fio still uses stdout for the ETA output.
>> >
>> > So we already have --output, so we don't need the extra argument to the
>> > format option. What is missing is just the below - that will continue to
>> > use the ETA running output to stdout, if a file was chosen for the
>> > output of the results.
>> >
>> > IOW, if you do:
>> >
>> > $ fio --output-format=json --output=somefile
>> >
>> > then fio (with the below patch) would output results to 'somefile' while
>> > still doing the running stdout output.
>> >
>> > That should do what you need, correct?
>> >
>> >
>> > diff --git a/eta.c b/eta.c
>> > index 39fe10f..cfb8679 100644
>> > --- a/eta.c
>> > +++ b/eta.c
>> > @@ -285,7 +285,8 @@ int calc_thread_status(struct jobs_eta *je, int force)
>> >         static struct timeval rate_prev_time, disp_prev_time;
>> >
>> >         if (!force) {
>> > -               if (output_format != FIO_OUTPUT_NORMAL)
>> > +               if (output_format != FIO_OUTPUT_NORMAL &&
>> > +                   f_out == stdout)
>> >                         return 0;
>> >                 if (temp_stall_ts || eta_print == FIO_ETA_NEVER)
>> >                         return 0;
>> >
>> > --
>> > Jens Axboe
>> >
>> > --
>> > To unsubscribe from this list: send the line "unsubscribe fio" in
>> > the body of a message to majordomo@vger.kernel.org
>> > More majordomo info at  http://vger.kernel.org/majordomo-info.html
>>
>> Hi Jens,
>>
>> You are quick, I was half-way through a reply when you came back with
>> an answer :)
>>
>> Yes keeping the std output as per normal, and also having the CSV/JSON
>> output to a file that we can use to create graphs and reports. As you
>> suggest above that would work.
>
> Thought so, I will commit it.
>
>>  The only problem I can see is from increasing the memory usage due to
>> the extra logging.  Would implementing this increase the memory usage?
>
> The ETA logging carries no additional memory overhead, so that is not a
> concern.
>
> --
> Jens Axboe
>

Hi Jens,

I've only just had time to test out this feature and with the
arguments from above "--output-format=json --output=somefile" it
writes to the file, but does not display the normal stdout.

If I run Fio as per normal on the command line, I get this:-

{quote}
[root@localhost ~]# fio-2.0.13-122 iometer.fio
iometer: (g=0): rw=randrw, bs=512-64K/512-64K/512-64K,
ioengine=libaio, iodepth=64
fio-2.0.13-122-g6d0e
Starting 1 process
Jobs: 1 (f=1): [m] [-.-% done] [4112K/790K/0K /s] [976 /220 /0  iops]
[eta 00m:00s]
iometer: (groupid=0, jobs=1): err= 0: pid=6313: Tue Feb 12 02:37:03 2013
  Description  : [Emulation of Intel IOmeter File Server Access Pattern]
  read : io=8401.6KB, bw=3770.9KB/s, iops=855 , runt=  2228msec
    slat (usec): min=3 , max=94 , avg=16.40, stdev= 5.85
    clat (usec): min=380 , max=534304 , avg=52967.40, stdev=69114.82
     lat (usec): min=395 , max=534324 , avg=52984.40, stdev=69114.86
    clat percentiles (usec):
     |  1.00th=[  572],  5.00th=[ 1432], 10.00th=[ 3344], 20.00th=[ 8512],
     | 30.00th=[15168], 40.00th=[22656], 50.00th=[30336], 60.00th=[41216],
     | 70.00th=[55040], 80.00th=[76288], 90.00th=[123392], 95.00th=[177152],
     | 99.00th=[358400], 99.50th=[395264], 99.90th=[477184], 99.95th=[536576],
     | 99.99th=[536576]
    bw (KB/s)  : min= 3701, max= 4194, per=100.00%, avg=3968.25, stdev=221.70
  write: io=1838.6KB, bw=844983 B/s, iops=188 , runt=  2228msec
    slat (usec): min=4 , max=54 , avg=19.80, stdev= 5.82
    clat (msec): min=2 , max=914 , avg=98.35, stdev=100.41
     lat (msec): min=2 , max=914 , avg=98.38, stdev=100.41
    clat percentiles (msec):
     |  1.00th=[    5],  5.00th=[   11], 10.00th=[   16], 20.00th=[   26],
     | 30.00th=[   39], 40.00th=[   56], 50.00th=[   70], 60.00th=[   92],
     | 70.00th=[  115], 80.00th=[  149], 90.00th=[  215], 95.00th=[  273],
     | 99.00th=[  445], 99.50th=[  553], 99.90th=[  914], 99.95th=[  914],
     | 99.99th=[  914]
    bw (KB/s)  : min=  665, max= 1063, per=100.00%, avg=871.25, stdev=188.88
    lat (usec) : 500=0.39%, 750=1.50%, 1000=1.07%
    lat (msec) : 2=2.84%, 4=3.65%, 10=10.49%, 20=12.81%, 50=28.66%
    lat (msec) : 100=20.93%, 250=13.62%, 500=3.87%, 750=0.09%, 1000=0.09%
  cpu          : usr=2.11%, sys=3.19%, ctx=1972, majf=0, minf=25
  IO depths    : 1=0.1%, 2=0.1%, 4=0.2%, 8=0.3%, 16=0.7%, 32=1.4%, >=64=97.3%
     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.0%, 32=0.0%, 64=0.1%, >=64=0.0%
     issued    : total=r=1907/w=420/d=0, short=r=0/w=0/d=0

Run status group 0 (all jobs):
   READ: io=8401KB, aggrb=3770KB/s, minb=3770KB/s, maxb=3770KB/s,
mint=2228msec, maxt=2228msec
  WRITE: io=1838KB, aggrb=824KB/s, minb=824KB/s, maxb=824KB/s,
mint=2228msec, maxt=2228msec

Disk stats (read/write):
  sda: ios=1565/371, merge=136/5, ticks=73336/33855, in_queue=113886,
util=94.83%
{/quote}

I would still like this but at the same time have the json output in a
file, if I run the command with the arguments for output, all I get
is:-

{quote}
[root@localhost ~]# fio-2.0.13-122 iometer.fio --output=test.log
--output-format=json
[root@localhost ~]# -.-% done] [4558K/798K/0K /s] [1100 /224 /0  iops]
[eta 00m:00s]
{/quote}

The output file is created as normal, so no issue there, just no
stdout display, am I doing something wrong?.

Thanks,
Gavin

-- 


------------------------------
For additional information including the registered office and the treatment of Xyratex confidential information please visit www.xyratex.com

------------------------------

Re: Output logs and keep command line display

[Jens Axboe]

On Tue, Feb 12 2013, Gavin Martin wrote:
> On 31 January 2013 14:24, Jens Axboe <axboe@kernel.dk> wrote:
> > On Thu, Jan 31 2013, Gavin Martin wrote:
> >> On 31 January 2013 14:08, Jens Axboe <axboe@kernel.dk> wrote:
> >> > On Thu, Jan 31 2013, Jens Axboe wrote:
> >> >> On Thu, Jan 31 2013, Gavin Martin wrote:
> >> >> > Hi,
> >> >> >
> >> >> > Not sure if I am missing a special argument somewhere, but I like the
> >> >> > command line display we get from Fio when it runs showing the type of
> >> >> > workload and job descriptions and percentage complete, etc.  Is it
> >> >> > possible to get the outputs that you get when using the --minimal
> >> >> > argument (in JSON, CSV formats) whilst still keeping the command line
> >> >> > display.
> >> >> >
> >> >> > Having this would make it similar to Iometer, not in a graphical
> >> >> > sense, but in a way that you can see exactly what is occurring (and if
> >> >> > it has halted or crashed) whilst still having logs that could be
> >> >> > charted or plotted into reports.  Especially useful for extended test
> >> >> > runs (over several hours!)
> >> >>
> >> >> --eta=always
> >> >>
> >> >> should do the trick for you, if I understand your request correctly. I
> >> >> suppose for that to be useful, you want to redirect the csv/json output
> >> >> to a file as well?
> >> >>
> >> >> Might be useful to have the behaviour of:
> >> >>
> >> >> --output-format=type [file]
> >> >>
> >> >> where if 'file' is given, then output goes to that file in the specified
> >> >> format, and fio still uses stdout for the ETA output.
> >> >
> >> > So we already have --output, so we don't need the extra argument to the
> >> > format option. What is missing is just the below - that will continue to
> >> > use the ETA running output to stdout, if a file was chosen for the
> >> > output of the results.
> >> >
> >> > IOW, if you do:
> >> >
> >> > $ fio --output-format=json --output=somefile
> >> >
> >> > then fio (with the below patch) would output results to 'somefile' while
> >> > still doing the running stdout output.
> >> >
> >> > That should do what you need, correct?
> >> >
> >> >
> >> > diff --git a/eta.c b/eta.c
> >> > index 39fe10f..cfb8679 100644
> >> > --- a/eta.c
> >> > +++ b/eta.c
> >> > @@ -285,7 +285,8 @@ int calc_thread_status(struct jobs_eta *je, int force)
> >> >         static struct timeval rate_prev_time, disp_prev_time;
> >> >
> >> >         if (!force) {
> >> > -               if (output_format != FIO_OUTPUT_NORMAL)
> >> > +               if (output_format != FIO_OUTPUT_NORMAL &&
> >> > +                   f_out == stdout)
> >> >                         return 0;
> >> >                 if (temp_stall_ts || eta_print == FIO_ETA_NEVER)
> >> >                         return 0;
> >> >
> >> > --
> >> > Jens Axboe
> >> >
> >> > --
> >> > To unsubscribe from this list: send the line "unsubscribe fio" in
> >> > the body of a message to majordomo@vger.kernel.org
> >> > More majordomo info at  http://vger.kernel.org/majordomo-info.html
> >>
> >> Hi Jens,
> >>
> >> You are quick, I was half-way through a reply when you came back with
> >> an answer :)
> >>
> >> Yes keeping the std output as per normal, and also having the CSV/JSON
> >> output to a file that we can use to create graphs and reports. As you
> >> suggest above that would work.
> >
> > Thought so, I will commit it.
> >
> >>  The only problem I can see is from increasing the memory usage due to
> >> the extra logging.  Would implementing this increase the memory usage?
> >
> > The ETA logging carries no additional memory overhead, so that is not a
> > concern.
> >
> > --
> > Jens Axboe
> >
> 
> Hi Jens,
> 
> I've only just had time to test out this feature and with the
> arguments from above "--output-format=json --output=somefile" it
> writes to the file, but does not display the normal stdout.
> 
> If I run Fio as per normal on the command line, I get this:-
> 
> {quote}
> [root@localhost ~]# fio-2.0.13-122 iometer.fio
> iometer: (g=0): rw=randrw, bs=512-64K/512-64K/512-64K,
> ioengine=libaio, iodepth=64
> fio-2.0.13-122-g6d0e
> Starting 1 process
> Jobs: 1 (f=1): [m] [-.-% done] [4112K/790K/0K /s] [976 /220 /0  iops]
> [eta 00m:00s]
> iometer: (groupid=0, jobs=1): err= 0: pid=6313: Tue Feb 12 02:37:03 2013
>   Description  : [Emulation of Intel IOmeter File Server Access Pattern]
>   read : io=8401.6KB, bw=3770.9KB/s, iops=855 , runt=  2228msec
>     slat (usec): min=3 , max=94 , avg=16.40, stdev= 5.85
>     clat (usec): min=380 , max=534304 , avg=52967.40, stdev=69114.82
>      lat (usec): min=395 , max=534324 , avg=52984.40, stdev=69114.86
>     clat percentiles (usec):
>      |  1.00th=[  572],  5.00th=[ 1432], 10.00th=[ 3344], 20.00th=[ 8512],
>      | 30.00th=[15168], 40.00th=[22656], 50.00th=[30336], 60.00th=[41216],
>      | 70.00th=[55040], 80.00th=[76288], 90.00th=[123392], 95.00th=[177152],
>      | 99.00th=[358400], 99.50th=[395264], 99.90th=[477184], 99.95th=[536576],
>      | 99.99th=[536576]
>     bw (KB/s)  : min= 3701, max= 4194, per=100.00%, avg=3968.25, stdev=221.70
>   write: io=1838.6KB, bw=844983 B/s, iops=188 , runt=  2228msec
>     slat (usec): min=4 , max=54 , avg=19.80, stdev= 5.82
>     clat (msec): min=2 , max=914 , avg=98.35, stdev=100.41
>      lat (msec): min=2 , max=914 , avg=98.38, stdev=100.41
>     clat percentiles (msec):
>      |  1.00th=[    5],  5.00th=[   11], 10.00th=[   16], 20.00th=[   26],
>      | 30.00th=[   39], 40.00th=[   56], 50.00th=[   70], 60.00th=[   92],
>      | 70.00th=[  115], 80.00th=[  149], 90.00th=[  215], 95.00th=[  273],
>      | 99.00th=[  445], 99.50th=[  553], 99.90th=[  914], 99.95th=[  914],
>      | 99.99th=[  914]
>     bw (KB/s)  : min=  665, max= 1063, per=100.00%, avg=871.25, stdev=188.88
>     lat (usec) : 500=0.39%, 750=1.50%, 1000=1.07%
>     lat (msec) : 2=2.84%, 4=3.65%, 10=10.49%, 20=12.81%, 50=28.66%
>     lat (msec) : 100=20.93%, 250=13.62%, 500=3.87%, 750=0.09%, 1000=0.09%
>   cpu          : usr=2.11%, sys=3.19%, ctx=1972, majf=0, minf=25
>   IO depths    : 1=0.1%, 2=0.1%, 4=0.2%, 8=0.3%, 16=0.7%, 32=1.4%, >=64=97.3%
>      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.0%, 32=0.0%, 64=0.1%, >=64=0.0%
>      issued    : total=r=1907/w=420/d=0, short=r=0/w=0/d=0
> 
> Run status group 0 (all jobs):
>    READ: io=8401KB, aggrb=3770KB/s, minb=3770KB/s, maxb=3770KB/s,
> mint=2228msec, maxt=2228msec
>   WRITE: io=1838KB, aggrb=824KB/s, minb=824KB/s, maxb=824KB/s,
> mint=2228msec, maxt=2228msec
> 
> Disk stats (read/write):
>   sda: ios=1565/371, merge=136/5, ticks=73336/33855, in_queue=113886,
> util=94.83%
> {/quote}
> 
> I would still like this but at the same time have the json output in a
> file, if I run the command with the arguments for output, all I get
> is:-
> 
> {quote}
> [root@localhost ~]# fio-2.0.13-122 iometer.fio --output=test.log
> --output-format=json
> [root@localhost ~]# -.-% done] [4558K/798K/0K /s] [1100 /224 /0  iops]
> [eta 00m:00s]
> {/quote}
> 
> The output file is created as normal, so no issue there, just no
> stdout display, am I doing something wrong?.

There's currently no support for using multiple types of output. It
could be accomplished with something ala:

--output-format=json,normal

or something like that, but that would influence --output as well (which
one goes there? Both?).

I'd be happy to provide support for this, I can see how it would be
useful. Even better if ideas were suggested on how best to implement
this, from the users perspective.

-- 
Jens Axboe

RE: Output logs and keep command line display

[Carl Zwanzig]

While we're on the subject-

For some long-running tests*, I hacked the ETA display to appear every 60 seconds and with a trailing newline. This isn't much of a code change, but since I haven't figured out how the option processing works, I haven't created a patch.

* Needed to watch the write speed over the entire range of a 3tb drive. On some drives, it drops quite a bit from low LBAs to high ones.

z!

Re: Output logs and keep command line display

[Jens Axboe]

On Fri, Feb 22 2013, Carl Zwanzig wrote:
> While we're on the subject-
> 
> For some long-running tests*, I hacked the ETA display to appear every 60 seconds and with a trailing newline. This isn't much of a code change, but since I haven't figured out how the option processing works, I haven't created a patch.
> 
> * Needed to watch the write speed over the entire range of a 3tb drive. On some drives, it drops quite a bit from low LBAs to high ones.

Something like the below should do the trick, you should be able to use
either --eta-newline=60s or --eta-newline=1m to get that behavior. It
also shows you how to add a command line option, which are different
from the job options. So now you know! In general, if in doubt on how to
add a new option, it helps a lot to browse git log for a commit that
added a new option. Eg do git log init.c, find the first commit, then
run a git show on that commit id. For a job options, do the same but use
options.c instead.

Let me know how it works for you and I will get it committed.

diff --git a/README b/README
index 4f796e3..b662e71 100644
--- a/README
+++ b/README
@@ -152,6 +152,7 @@ $ fio
 				writes
 	--eta=when		When ETA estimate should be printed
 				May be "always", "never" or "auto"
+	--eta-newline=time	Force a new line for every 'time' period passed
 	--section=name		Only run specified section in job file.
 				Multiple sections can be specified.
 	--alloc-size=kb		Set smalloc pool to this size in kb (def 1024)
diff --git a/eta.c b/eta.c
index 5ef31c6..f90d428 100644
--- a/eta.c
+++ b/eta.c
@@ -422,12 +422,13 @@ int calc_thread_status(struct jobs_eta *je, int force)
 
 	je->nr_threads = thread_number;
 	memcpy(je->run_str, run_str, thread_number * sizeof(char));
-
 	return 1;
 }
 
 void display_thread_status(struct jobs_eta *je)
 {
+	static struct timeval disp_eta_new_line;
+	static int eta_new_line_init, eta_new_line_pending;
 	static int linelen_last;
 	static int eta_good;
 	char output[REAL_MAX_JOBS + 512], *p = output;
@@ -439,6 +440,11 @@ void display_thread_status(struct jobs_eta *je)
 		eta_to_str(eta_str, je->eta_sec);
 	}
 
+	if (eta_new_line_pending) {
+		eta_new_line_pending = 0;
+		p += sprintf(p, "\n");
+	}
+
 	p += sprintf(p, "Jobs: %d (f=%d)", je->nr_running, je->files_open);
 	if (je->m_rate || je->t_rate) {
 		char *tr, *mr;
@@ -492,6 +498,16 @@ void display_thread_status(struct jobs_eta *je)
 	p += sprintf(p, "\r");
 
 	printf("%s", output);
+
+	if (!eta_new_line_init) {
+		fio_gettime(&disp_eta_new_line, NULL);
+		eta_new_line_init = 1;
+	} else if (eta_new_line &&
+		   mtime_since_now(&disp_eta_new_line) > eta_new_line * 1000) {
+		fio_gettime(&disp_eta_new_line, NULL);
+		eta_new_line_pending = 1;
+	}
+
 	fflush(stdout);
 }
 
diff --git a/fio.h b/fio.h
index 43f4854..d7eb6de 100644
--- a/fio.h
+++ b/fio.h
@@ -594,6 +594,7 @@ extern unsigned long long mlock_size;
 extern uintptr_t page_mask, page_size;
 extern int read_only;
 extern int eta_print;
+extern int eta_new_line;
 extern unsigned long done_secs;
 extern char *job_section;
 extern int fio_gtod_offload;
diff --git a/init.c b/init.c
index 4709ff2..32da42c 100644
--- a/init.c
+++ b/init.c
@@ -41,6 +41,7 @@ struct thread_data *threads = NULL;
 int exitall_on_terminate = 0;
 int output_format = FIO_OUTPUT_NORMAL;
 int eta_print = FIO_ETA_AUTO;
+int eta_new_line = 0;
 unsigned long long mlock_size = 0;
 FILE *f_out = NULL;
 FILE *f_err = NULL;
@@ -140,6 +141,11 @@ static struct option l_opts[FIO_NR_OPTIONS] = {
 		.val		= 'e' | FIO_CLIENT_FLAG,
 	},
 	{
+		.name		= (char *) "eta-newline",
+		.has_arg	= required_argument,
+		.val		= 'E' | FIO_CLIENT_FLAG,
+	},
+	{
 		.name		= (char *) "debug",
 		.has_arg	= required_argument,
 		.val		= 'd' | FIO_CLIENT_FLAG,
@@ -1264,6 +1270,8 @@ static void usage(const char *name)
 	printf("  --showcmd\t\tTurn a job file into command line options\n");
 	printf("  --eta=when\t\tWhen ETA estimate should be printed\n");
 	printf("            \t\tMay be \"always\", \"never\" or \"auto\"\n");
+	printf("  --eta-newline=time\tForce a new line for every 'time'");
+	printf(" period passed\n");
 	printf("  --readonly\t\tTurn on safety read-only checks, preventing"
 		" writes\n");
 	printf("  --section=name\tOnly run specified section in job file\n");
@@ -1505,6 +1513,17 @@ int parse_cmd_line(int argc, char *argv[])
 			else if (!strcmp("never", optarg))
 				eta_print = FIO_ETA_NEVER;
 			break;
+		case 'E': {
+			long long t = 0;
+
+			if (str_to_decimal(optarg, &t, 0, NULL)) {
+				log_err("fio: failed parsing eta time %s\n", optarg);
+				exit_val = 1;
+				do_exit++;
+			}
+			eta_new_line = t;
+			break;
+			}
 		case 'd':
 			if (set_debug(optarg))
 				do_exit++;

-- 
Jens Axboe