* No IOPS reported when "REPLAY_NO_STALL" is not set
@ 2014-04-10 18:25 Lakshmi
2014-04-10 22:07 ` Jens Axboe
0 siblings, 1 reply; 5+ messages in thread
From: Lakshmi @ 2014-04-10 18:25 UTC (permalink / raw)
To: fio, Jens Axboe
[-- Attachment #1: Type: text/plain, Size: 1714 bytes --]
Hi Jens,
I am seeing a strange problem. I have a 47KB Blkparsed binary file
and I tried replaying it with and without the "replay_no_stall"
option.
With the "replay_no_stall" option, I am seeing some IOPS
happening.Please see below.
WITH "REPLAY_NO_STALL=1"
=====================================================
job9: (g=0): rw=read, bs=4K-4K/4K-4K/4K-4K, ioengine=sync, iodepth=1
fio-2.1.7
Starting 1 process
Jobs: 1 (f=2): [M] [-.-% done] [1064KB/72KB/0KB /s] [266/18/0 iops]
[eta 00m:00s]
job9: (groupid=0, jobs=1): err= 0: pid=34226: Thu Apr 10 12:00:54 2014
read : io=3792.0KB, bw=1126.3KB/s, iops=281, runt= 3367msec
clat (usec): min=88, max=8536, avg=3546.19, stdev=1469.46
lat (usec): min=88, max=8536, avg=3546.35, stdev=1469.47
=====================================================
However, when I don't set the "REPLAY_NO_STALL" option, I see 0
IOPS.Please see below
job9: (g=0): rw=read, bs=4K-4K/4K-4K/4K-4K, ioengine=sync, iodepth=1
fio-2.1.7
Starting 1 process
job9: (groupid=0, jobs=1): err= 0: pid=33979: Thu Apr 10 10:39:42 2014
read : io=3792.0KB, bw=2004B/s, iops=0, runt=1937594msec
clat (usec): min=87, max=14320, avg=4763.37, stdev=2001.45
lat (usec): min=87, max=14320, avg=4763.52, stdev=2001.50
===========================================================
My starting time in the blkparsed binary file is 26.040173218 seconds
and last time is 26.150699031.
Attached is the binary file I am using to replay.
I understand replay_no_stall option doesnt respect the timestamps, but
without this option the job should be executing with the delays, and
not sure why no OPS are reported.
Any idea what is causing this strange behavior?Please help.
Thanks,
Lakshmi
[-- Attachment #2: file_54657438_1000lines.bin --]
[-- Type: application/octet-stream, Size: 48000 bytes --]
^ permalink raw reply [flat|nested] 5+ messages in thread* Re: No IOPS reported when "REPLAY_NO_STALL" is not set
2014-04-10 18:25 No IOPS reported when "REPLAY_NO_STALL" is not set Lakshmi
@ 2014-04-10 22:07 ` Jens Axboe
2014-04-11 15:36 ` Lakshmi
0 siblings, 1 reply; 5+ messages in thread
From: Jens Axboe @ 2014-04-10 22:07 UTC (permalink / raw)
To: Lakshmi, fio
On 04/10/2014 12:25 PM, Lakshmi wrote:
> Hi Jens,
>
> I am seeing a strange problem. I have a 47KB Blkparsed binary file
> and I tried replaying it with and without the "replay_no_stall"
> option.
>
> With the "replay_no_stall" option, I am seeing some IOPS
> happening.Please see below.
> WITH "REPLAY_NO_STALL=1"
> =====================================================
> job9: (g=0): rw=read, bs=4K-4K/4K-4K/4K-4K, ioengine=sync, iodepth=1
> fio-2.1.7
> Starting 1 process
> Jobs: 1 (f=2): [M] [-.-% done] [1064KB/72KB/0KB /s] [266/18/0 iops]
> [eta 00m:00s]
> job9: (groupid=0, jobs=1): err= 0: pid=34226: Thu Apr 10 12:00:54 2014
> read : io=3792.0KB, bw=1126.3KB/s, iops=281, runt= 3367msec
> clat (usec): min=88, max=8536, avg=3546.19, stdev=1469.46
> lat (usec): min=88, max=8536, avg=3546.35, stdev=1469.47
> =====================================================
> However, when I don't set the "REPLAY_NO_STALL" option, I see 0
> IOPS.Please see below
> job9: (g=0): rw=read, bs=4K-4K/4K-4K/4K-4K, ioengine=sync, iodepth=1
> fio-2.1.7
> Starting 1 process
>
> job9: (groupid=0, jobs=1): err= 0: pid=33979: Thu Apr 10 10:39:42 2014
> read : io=3792.0KB, bw=2004B/s, iops=0, runt=1937594msec
> clat (usec): min=87, max=14320, avg=4763.37, stdev=2001.45
> lat (usec): min=87, max=14320, avg=4763.52, stdev=2001.50
> ===========================================================
>
> My starting time in the blkparsed binary file is 26.040173218 seconds
> and last time is 26.150699031.
>
> Attached is the binary file I am using to replay.
>
> I understand replay_no_stall option doesnt respect the timestamps, but
> without this option the job should be executing with the delays, and
> not sure why no OPS are reported.
>
> Any idea what is causing this strange behavior?Please help.
It reports no IOPS, because it's slow enough to not register any. The
first trace in the file is at timestamp 0.00 relative, and the last one
is at 31110.250640101. Check for yourself with:
cat file_54657438_1000lines.bin | blkparse - | less
--
Jens Axboe
^ permalink raw reply [flat|nested] 5+ messages in thread
* Re: No IOPS reported when "REPLAY_NO_STALL" is not set
2014-04-10 22:07 ` Jens Axboe
@ 2014-04-11 15:36 ` Lakshmi
2014-04-11 15:47 ` Jens Axboe
0 siblings, 1 reply; 5+ messages in thread
From: Lakshmi @ 2014-04-11 15:36 UTC (permalink / raw)
To: Jens Axboe; +Cc: fio
[-- Attachment #1: Type: text/plain, Size: 3054 bytes --]
Hi Jens,
Thanks for the command. I was looking for something like this.
However, I am still confused on the time stamp calculation.
My Binary file had the starting time as "26.040173218 seconds" , but
with the below command,
cat file_54657438_1000lines.bin | blkparse - | less
8,0 60 0 0.000000000 54657438 Q R 24014152 + 8 [(null)]
8,0 60 0 66.860158593 54657438 Q R 805379152 +8 [(null)]
8,0 60 0 80.644832628 54657438 Q R 24014160 + 8 [(null)]
The first line starts at 0 timestamp and then 66sec etc. I dont
understand how the 66sec is calculated in the above blkparse command.
Shouldnt it be 26.040173218 sec ?
I do see 26.040173218 in the binary file and checked this using a
binary viewer.Attached is the binary viewer of the file.
Please help me understand.
Thanks,
Lakshmi
On Thu, Apr 10, 2014 at 5:07 PM, Jens Axboe <axboe@kernel.dk> wrote:
> On 04/10/2014 12:25 PM, Lakshmi wrote:
>>
>> Hi Jens,
>>
>> I am seeing a strange problem. I have a 47KB Blkparsed binary file
>> and I tried replaying it with and without the "replay_no_stall"
>> option.
>>
>> With the "replay_no_stall" option, I am seeing some IOPS
>> happening.Please see below.
>> WITH "REPLAY_NO_STALL=1"
>> =====================================================
>> job9: (g=0): rw=read, bs=4K-4K/4K-4K/4K-4K, ioengine=sync, iodepth=1
>> fio-2.1.7
>> Starting 1 process
>> Jobs: 1 (f=2): [M] [-.-% done] [1064KB/72KB/0KB /s] [266/18/0 iops]
>> [eta 00m:00s]
>> job9: (groupid=0, jobs=1): err= 0: pid=34226: Thu Apr 10 12:00:54 2014
>> read : io=3792.0KB, bw=1126.3KB/s, iops=281, runt= 3367msec
>> clat (usec): min=88, max=8536, avg=3546.19, stdev=1469.46
>> lat (usec): min=88, max=8536, avg=3546.35, stdev=1469.47
>> =====================================================
>> However, when I don't set the "REPLAY_NO_STALL" option, I see 0
>> IOPS.Please see below
>> job9: (g=0): rw=read, bs=4K-4K/4K-4K/4K-4K, ioengine=sync, iodepth=1
>> fio-2.1.7
>> Starting 1 process
>>
>> job9: (groupid=0, jobs=1): err= 0: pid=33979: Thu Apr 10 10:39:42 2014
>> read : io=3792.0KB, bw=2004B/s, iops=0, runt=1937594msec
>> clat (usec): min=87, max=14320, avg=4763.37, stdev=2001.45
>> lat (usec): min=87, max=14320, avg=4763.52, stdev=2001.50
>> ===========================================================
>>
>> My starting time in the blkparsed binary file is 26.040173218 seconds
>> and last time is 26.150699031.
>>
>> Attached is the binary file I am using to replay.
>>
>> I understand replay_no_stall option doesnt respect the timestamps, but
>> without this option the job should be executing with the delays, and
>> not sure why no OPS are reported.
>>
>> Any idea what is causing this strange behavior?Please help.
>
>
> It reports no IOPS, because it's slow enough to not register any. The first
> trace in the file is at timestamp 0.00 relative, and the last one is at
> 31110.250640101. Check for yourself with:
>
> cat file_54657438_1000lines.bin | blkparse - | less
>
> --
> Jens Axboe
>
[-- Attachment #2: Binary_view_Timestamp.png --]
[-- Type: image/png, Size: 25344 bytes --]
^ permalink raw reply [flat|nested] 5+ messages in thread
* Re: No IOPS reported when "REPLAY_NO_STALL" is not set
2014-04-11 15:36 ` Lakshmi
@ 2014-04-11 15:47 ` Jens Axboe
0 siblings, 0 replies; 5+ messages in thread
From: Jens Axboe @ 2014-04-11 15:47 UTC (permalink / raw)
To: Lakshmi; +Cc: fio
On 04/11/2014 09:36 AM, Lakshmi wrote:
> Hi Jens,
>
> Thanks for the command. I was looking for something like this.
> However, I am still confused on the time stamp calculation.
> My Binary file had the starting time as "26.040173218 seconds" , but
> with the below command,
>
> cat file_54657438_1000lines.bin | blkparse - | less
>
> 8,0 60 0 0.000000000 54657438 Q R 24014152 + 8 [(null)]
> 8,0 60 0 66.860158593 54657438 Q R 805379152 +8 [(null)]
> 8,0 60 0 80.644832628 54657438 Q R 24014160 + 8 [(null)]
>
> The first line starts at 0 timestamp and then 66sec etc. I dont
> understand how the 66sec is calculated in the above blkparse command.
> Shouldnt it be 26.040173218 sec ?
>
> I do see 26.040173218 in the binary file and checked this using a
> binary viewer.Attached is the binary viewer of the file.
> Please help me understand.
If you look at the binary, the first timestamp is indeed the one you
highlight. This then becomes the time 0, since all the other events are
relative to this one. So 0x403a0a48cac17c2e is time 0, next timestamp is
0x403a0a585bee8aaf, or 66860158593 nanoseconds ahead, which is 66.86s
further ahead in time.
I don't know where you get the 26.04 from?
--
Jens Axboe
^ permalink raw reply [flat|nested] 5+ messages in thread
* No IOPS reported when "Replay_no_stall" is not set
@ 2014-04-10 17:21 Lakshmi
0 siblings, 0 replies; 5+ messages in thread
From: Lakshmi @ 2014-04-10 17:21 UTC (permalink / raw)
To: fio, Jens Axboe
[-- Attachment #1: Type: text/plain, Size: 4869 bytes --]
Hi Jens,
I am seeing a strange problem. I have a 47KB Blkparsed binary file
and I tried replaying it with and without the "replay_no_stall"
option.
With the "replay_no_stall" option, I am seeing some IOPS
happening.Please see below.
WITH "REPLAY_NO_STALL=1"
============================================================
job9: (g=0): rw=read, bs=4K-4K/4K-4K/4K-4K, ioengine=sync, iodepth=1
fio-2.1.7
Starting 1 process
Jobs: 1 (f=2): [M] [-.-% done] [1064KB/72KB/0KB /s] [266/18/0 iops]
[eta 00m:00s]
job9: (groupid=0, jobs=1): err= 0: pid=34226: Thu Apr 10 12:00:54 2014
read : io=3792.0KB, bw=1126.3KB/s, iops=281, runt= 3367msec
clat (usec): min=88, max=8536, avg=3546.19, stdev=1469.46
lat (usec): min=88, max=8536, avg=3546.35, stdev=1469.47
clat percentiles (usec):
| 1.00th=[ 141], 5.00th=[ 270], 10.00th=[ 1800], 20.00th=[ 2320],
| 30.00th=[ 2800], 40.00th=[ 3216], 50.00th=[ 3664], 60.00th=[ 4048],
| 70.00th=[ 4512], 80.00th=[ 4896], 90.00th=[ 5344], 95.00th=[ 5600],
| 99.00th=[ 6176], 99.50th=[ 6560], 99.90th=[ 8512], 99.95th=[ 8512],
| 99.99th=[ 8512]
bw (KB /s): min= 1027, max= 1280, per=100.00%, avg=1129.00, stdev=99.47
write: io=212992B, bw=63258B/s, iops=15, runt= 3367msec
clat (usec): min=39, max=65, avg=44.27, stdev= 4.10
lat (usec): min=40, max=66, avg=44.92, stdev= 4.16
clat percentiles (usec):
| 1.00th=[ 39], 5.00th=[ 39], 10.00th=[ 40], 20.00th=[ 41],
| 30.00th=[ 42], 40.00th=[ 43], 50.00th=[ 43], 60.00th=[ 45],
| 70.00th=[ 46], 80.00th=[ 47], 90.00th=[ 48], 95.00th=[ 50],
| 99.00th=[ 65], 99.50th=[ 65], 99.90th=[ 65], 99.95th=[ 65],
| 99.99th=[ 65]
bw (KB /s): min= 48, max= 79, per=100.00%, avg=63.17, stdev=11.03
lat (usec) : 50=4.90%, 100=0.40%, 250=4.30%, 500=1.40%, 750=0.10%
lat (msec) : 2=6.90%, 4=42.70%, 10=39.30%
cpu : usr=0.00%, sys=0.45%, ctx=1002, majf=0, minf=2
IO depths : 1=100.0%, 2=0.0%, 4=0.0%, 8=0.0%, 16=0.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.0%, 32=0.0%, 64=0.0%, >=64=0.0%
issued : total=r=948/w=52/d=0, short=r=0/w=0/d=0
latency : target=0, window=0, percentile=100.00%, depth=1
=========================================================
However, when I don't set the "REPLAY_NO_STALL" option, I see 0
IOPS.Please see below
job9: (g=0): rw=read, bs=4K-4K/4K-4K/4K-4K, ioengine=sync, iodepth=1
fio-2.1.7
Starting 1 process
job9: (groupid=0, jobs=1): err= 0: pid=33979: Thu Apr 10 10:39:42 2014
read : io=3792.0KB, bw=2004B/s, iops=0, runt=1937594msec
clat (usec): min=87, max=14320, avg=4763.37, stdev=2001.45
lat (usec): min=87, max=14320, avg=4763.52, stdev=2001.50
clat percentiles (usec):
| 1.00th=[ 199], 5.00th=[ 1624], 10.00th=[ 2256], 20.00th=[ 3088],
| 30.00th=[ 3760], 40.00th=[ 4320], 50.00th=[ 4832], 60.00th=[ 5280],
| 70.00th=[ 5728], 80.00th=[ 6496], 90.00th=[ 7264], 95.00th=[ 7840],
| 99.00th=[ 8896], 99.50th=[10304], 99.90th=[14272], 99.95th=[14272],
| 99.99th=[14272]
bw (KB /s): min= 0, max= 23, per=100.00%, avg= 3.24, stdev= 4.87
write: io=212992B, bw=109B/s, iops=0, runt=1937594msec
clat (usec): min=39, max=62, avg=48.46, stdev= 6.93
lat (usec): min=39, max=64, avg=49.19, stdev= 7.36
clat percentiles (usec):
| 1.00th=[ 39], 5.00th=[ 39], 10.00th=[ 40], 20.00th=[ 42],
| 30.00th=[ 44], 40.00th=[ 45], 50.00th=[ 46], 60.00th=[ 50],
| 70.00th=[ 54], 80.00th=[ 57], 90.00th=[ 58], 95.00th=[ 59],
| 99.00th=[ 62], 99.50th=[ 62], 99.90th=[ 62], 99.95th=[ 62],
| 99.99th=[ 62]
bw (KB /s): min= 0, max= 1, per=100.00%, avg= 0.09, stdev= 0.30
lat (usec) : 50=3.10%, 100=2.20%, 250=3.40%, 500=0.40%, 750=0.10%
lat (msec) : 2=3.10%, 4=25.20%, 10=62.00%, 20=0.50%
cpu : usr=0.00%, sys=0.00%, ctx=1066, majf=0, minf=2
IO depths : 1=100.0%, 2=0.0%, 4=0.0%, 8=0.0%, 16=0.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.0%, 32=0.0%, 64=0.0%, >=64=0.0%
issued : total=r=948/w=52/d=0, short=r=0/w=0/d=0
latency : target=0, window=0, percentile=100.00%, depth=1
=============================================================
My starting time in the blkparsed binary file is 26.040173218 seconds
and last time is 26.150699031.
Attached is the binary file I am using to replay.
I understand replay_no_stall option doesnt respect the timestamps, but
without this option the job should be executing with the delays, and
not sure why no OPS are reported.
Any idea what is causing this strange behavior?Please help.
Thanks,
Lakshmi
[-- Attachment #2: file_54657438_1000lines.bin --]
[-- Type: application/octet-stream, Size: 48000 bytes --]
^ permalink raw reply [flat|nested] 5+ messages in thread
end of thread, other threads:[~2014-04-11 15:47 UTC | newest]
Thread overview: 5+ messages (download: mbox.gz / follow: Atom feed)
-- links below jump to the message on this page --
2014-04-10 18:25 No IOPS reported when "REPLAY_NO_STALL" is not set Lakshmi
2014-04-10 22:07 ` Jens Axboe
2014-04-11 15:36 ` Lakshmi
2014-04-11 15:47 ` Jens Axboe
-- strict thread matches above, loose matches on Subject: below --
2014-04-10 17:21 No IOPS reported when "Replay_no_stall" " Lakshmi
This is an external index of several public inboxes,
see mirroring instructions on how to clone and mirror
all data and code used by this external index.
![[-- Attachment #2: Binary_view_Timestamp.png --] [-- Type: image/png, Size: 25344 bytes --]](../../CAEyTGCfybCJ-EoDMouX5puAnicpnk_MVtm+H4JLSzgNAYPQSjw@mail.gmail.com/2-Binary_view_Timestamp.png){kind=link}