On Thu, Dec 28 2006, Tom Zanussi wrote:
> Vasily Tarasov writes:
>  > Hello all,
>  > 
>  > I was playing with block device io tracing recently, and have
>  > encountered some strange things.
>  > (kernel 2.6.18 and blktrace just from git)
>  > 
>  > So there is one (dominant) reader on HN: fio tool with such job file:
>  > 
>  > [global]
>  > rw=randread
>  > direct=0
>  > timeout=200
>  > 
>  > [reader0]
>  > filename=file0 ;file of size 1 gb
>  > 
>  > Here is a piece of decoded blktrace output:
>  > 
>  >   8,0    0   105919   200.287000000     0  C   R 338688739 + 8 [0]
>  >   8,0    0   105920   200.287000000  7017  Q   R 339904179 + 8 [fio]
>  >   8,0    0   105921   200.287000000  7017  B   R 339904179 + 8 [fio]
>  >   8,0    0   105922   200.287000000  7017  G   R 339904179 + 8 [fio]
>  >   8,0    0   105923   200.287000000  7017  P   R [fio]
>  >   8,0    0   105924   200.287000000  7017  I   R 339904179 + 8 [fio]
>  >   8,0    0   105925   200.287000000  7017  D   R 339904179 + 8 [fio]
>  >   8,0    0   105926   200.287000000  7017  U   R [fio] 1
>  >   8,0    0   105927   200.291000000     0  C   R 339904179 + 8 [0]
>  >   8,0    0   105928   200.291000000  7017  Q   R 340230323 + 8 [fio]
>  >   8,0    0   105929   200.291000000  7017  B   R 340230323 + 8 [fio]
>  >   8,0    0   105930   200.291000000  7017  G   R 340230323 + 8 [fio]
>  >   8,0    0   105931   200.291000000  7017  P   R [fio]
>  >   8,0    0   105932   200.291000000  7017  I   R 340230323 + 8 [fio]
>  >   8,0    0   105933   200.291000000  7017  D   R 340230323 + 8 [fio]
>  >   8,0    0   105934   200.291000000  7017  U   R [fio] 1
>  >   8,0    0   105935   200.302000000     0  C   R 340230323 + 8 [0]
>  >   8,0    0   105936   200.302000000  7017  Q   R 340265211 + 8 [fio]
>  >   8,0    0   105937   200.302000000  7017  B   R 340265211 + 8 [fio]
>  >   8,0    0   105938   200.302000000  7017  G   R 340265211 + 8 [fio]
>  >   8,0    0   105939   200.302000000  7017  P   R [fio]
>  >   8,0    0   105940   200.302000000  7017  I   R 340265211 + 8 [fio]
>  >   8,0    0   105941   200.302000000  7017  D   R 340265211 + 8 [fio]
>  >   8,0    0   105942   200.302000000  7017  U   R [fio] 1
>  >   8,0    0   105943   200.306000000     0  C   R 340265211 + 8 [0]
>  >   8,0    0   105944   200.306000000  7017  Q   R 338171203 + 8 [fio]
>  >   8,0    0   105945   200.306000000  7017  B   R 338171203 + 8 [fio]
>  >   8,0    0   105946   200.306000000  7017  G   R 338171203 + 8 [fio]
>  >   8,0    0   105947   200.306000000  7017  P   R [fio]
>  >   8,0    0   105948   200.306000000  7017  I   R 338171203 + 8 [fio]
>  >   8,0    0   105949   200.306000000  7017  D   R 338171203 + 8 [fio]
>  >   8,0    0   105950   200.306000000  7017  U   R [fio] 1
>  >   8,0    0   105951   200.312000000     0  C   R 338171203 + 8 [0]
>  >   8,0    0   105952   200.312000000  7017  Q   R 339044731 + 8 [fio]
>  >   8,0    0   105953   200.312000000  7017  B   R 339044731 + 8 [fio]
>  >   8,0    0   105954   200.312000000  7017  G   R 339044731 + 8 [fio]
>  > 
>  > As you see, there is a lot of "B" - back merges according to documentation.
>  > But in final results:
>  > 
>  > CPU0 (8,0):
>  >  Reads Queued:      13,244,   53,084KiB  Writes Queued:
>  > 42,      188KiB
>  >  Read Dispatches:   13,243,   53,080KiB  Write Dispatches:
>  > 26,      120KiB
>  >  Reads Requeued:         0               Writes Requeued:         0
>  >  Reads Completed:   13,243,   53,080KiB  Writes Completed:
>  > 26,      120KiB
>  >  Read Merges:            1               Write Merges:            4
>  >  Read depth:             2               Write depth:             2
>  >  IO unplugs:        13,243               Timer unplugs:           6
>  > 
>  > Throughput (R/W): 258KiB/s / 0KiB/s
>  > Events (8,0): 106,136 entries
>  > Skips: 0 forward (0 -   0.0%)
>  > 
>  > Only one read merge?
>  > So the first question is why does this happen?
>  > And the second one. As you can see fio produces randread, so actually
>  > not a lot of merges
>  > should be there. But there is a plenty of "B".
>  > 
> 
> Hi,
> 
> It looks like the documentation is wrong - from the blkparse code,
> apparently 'B' means 'Bounce', and is what's actually used instead of
> the 'W' the documentation has.  'Backmerge' according to the code is
> actually 'M', and is used instead of the 'B' the documentation has for
> that.  There doesn't seem to be anything that uses 'front or back
> merge' as described for 'M' in the documentation.  There also seems to
> be the same mixup in the formatting code.
> 
> The patch below makes those changes according to my understanding of
> how they're actually used in the code...

Tom, you are correct, the 'B' is a bounce and not a backmerge. Vasily,
you may want to look into your setup, bouncing is very harmful to io
performance.

I've applied the patch, thanks!

-- 
Jens Axboe

-
To unsubscribe from this list: send the line "unsubscribe linux-btrace" in
the body of a message to [EMAIL PROTECTED]
More majordomo info at  http://vger.kernel.org/majordomo-info.html

Reply via email to