Add in unplug IO count histogram
[blktrace.git] / btt / doc / btt.tex
1 \documentclass{article}
2 \usepackage{epsfig,placeins}
3
4 %
5 % Copyright (C) 2007 Alan D. Brunelle <Alan.Brunelle@hp.com>
6 %
7 %  This program is free software; you can redistribute it and/or modify
8 %  it under the terms of the GNU General Public License as published by
9 %  the Free Software Foundation; either version 2 of the License, or
10 %  (at your option) any later version.
11 %
12 %  This program is distributed in the hope that it will be useful,
13 %  but WITHOUT ANY WARRANTY; without even the implied warranty of
14 %  MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.  See the
15 %  GNU General Public License for more details.
16 %
17 %  You should have received a copy of the GNU General Public License
18 %  along with this program; if not, write to the Free Software
19 %  Foundation, Inc., 59 Temple Place, Suite 330, Boston, MA  02111-1307  USA
20 %
21 %  vi :set textwidth=75
22
23 \title{\texttt{btt} User Guide}
24 \author{Alan D. Brunelle (Alan.Brunelle@hp.com)}
25 \date{16 April 2007}
26
27 \begin{document}
28 \maketitle
29 %--------------
30 \section{\label{sec:intro}Introduction}
31
32 \texttt{btt} is a post-processing tool for the block layer IO tracing tool called blktrace. As noted in its Users Guide, blktrace 
33   \begin{quotation}
34     is a block layer IO tracing mechanism which provides detailed
35     information about request queue operations up to user space.
36   \end{quotation}
37
38 blktrace is capable of producing tremendous amounts of output in the
39 form of multiple individual traces per IO executed during the traced
40 run. It is also capable of producing some general statistics concerning
41 IO rates and the like. \texttt{btt} goes further and produces a variety
42 of overall statistics about each of the individual handling of IOs, and
43 provides data we believe is useful to plot to provide visual comparisons
44 for evaluation.
45
46 This document will discuss \texttt{btt} usage, provide some sample output,
47 and also show some interesting plots generated from the data provided
48 by the \texttt{btt} utility.
49
50 \bigskip
51 A short note on the ordering of this document -- the actual
52 command-line usage section occurs relatively late in the document (see
53 section~\ref{sec:cmd-line}), as we felt that discussing some of the
54 capabilities and output formats would make the parameter discussion
55 easier.
56
57 \bigskip
58   This document refers to the output formats generated by \texttt{btt}
59   version 0.99.1.  However, the descriptions are general enough to cover
60   output formats prior to that.
61
62 \newpage\tableofcontents
63
64 \newpage\section{\label{sec:getting-started}Getting Started}
65
66   The simple pipeline to get going with \texttt{btt} is to perform the
67   following steps:
68
69   \begin{enumerate}
70     \item Run \texttt{blktrace}, specifying whatever devices and other
71     parameters you want. You must save the traces to disk in this step,
72     btt does not work in live mode.
73
74     \item After tracing completes, run \texttt{blkrawverify}, specifying
75     all devices that were traced (or at least on all devices that you
76     will use \texttt{btt} with -- section~\ref{sec:o-D} shows how you
77     can dictate which devices to use with btt). If blkrawverify finds
78     errors in the trace streams saved, it is best to recapture the data
79     -- utilizing \texttt{btt} on \emph{unclean} trace files produces
80     inconsistent results.
81
82     While this step is optional, we have found that performing this
83     helps to ensure data coming from \texttt{btt} makes the most sense.
84
85     \item Run \texttt{blkparse} with the \texttt{-d} option specifying
86     a file to store the combined binary stream. (e.g.: \texttt{blkparse
87     -d bp.bin ...}).
88
89     \texttt{blktrace} produces a series of binary files
90     containing parallel trace streams -- one file per CPU per
91     device. \texttt{blkparse} provides the ability to combine all the
92     files into one time-ordered stream of traces for all devices.
93
94     \item Run \texttt{btt} specifying the file produced by
95     \texttt{blkparse} utilizing the \texttt{-i} option (e.g.: \texttt{btt
96     -i bp.bin ...}).
97
98   \end{enumerate}
99
100 \newpage\section{\label{sec:output-overview}Output Overview}
101
102   The major default areas of output provided by \texttt{btt}
103   include\label{tl-defs}:
104
105 \begin{description}
106   \item[average component times across all IOs] The time line of each IO
107   is broken down into 3 major regions:
108
109     \begin{enumerate}
110       \item Time needed to insert or merge an incoming IO onto the request
111       queue. This is the average time from when the IO enters the block
112       IO layer (queue trace) until it is inserted (insert trace) or merged
113       (back merge or front merge trace).
114
115       This is denoted as \emph{Q2I} time.
116
117       \item Time spent on the request queue. The average time from when
118       the IO is inserted or merged onto the request queue, until it is
119       issued (issue trace) to the lower level driver.
120
121       Referred to as \emph{I2D} time\footnote{The \emph{issue} trace
122       is represented by a D in the blkparse output, hence its usage in
123       btt to refer to issue traces. Note that an I is used to refer to
124       \emph{insert} traces.}.
125
126       \item Driver and device time -- the average time from when the
127       actual IO was issued to the driver until is completed (completion
128       trace) back to the block IO layer.
129
130       This is referred to as the \emph{D2C} time\
131     \end{enumerate}
132
133   Two other sets of results are presented in this section:
134
135     \begin{enumerate}
136       \item \emph{Q2Q} which measures the time between queue traces
137       in the system. This provides some idea as to how quickly IOs are
138       being handed to the block IO layer.
139
140       \item \emph{Q2C} which measures the times for the complete life cycle
141       of IOs during the run\footnote{One of the areas that needs some
142       work in \texttt{btt} is to better understand the multiplex nature of
143       IOs during a run. In theory, one would like ${Q2I} + {I2D} + {D2C}
144       = {Q2C}$ however, typically there are multiple queue traces that
145       are combined via merges into a single IO issued and completed. We
146       currently average the queue-to-insert and queue-to-merge times,
147       and thus tend to be quite close to the expected equation.}
148
149     \end{enumerate}
150
151   For each row in this output, we provide a minimum, average, maximum
152   (which are all presented in seconds), and overall count. As an
153   example\footnote{As with this display, the author has taken some liberty
154   in reformatting the output for better display on the printed page.}:
155
156 \begin{verbatim}
157 ALL            MIN           AVG           MAX           N
158 ---- ------------- ------------- ------------- -----------
159 Q2Q    0.000000058   0.000012761   9.547941661     2262310
160 Q2I    0.000000272   0.000005995   0.104588839     2262311
161 I2D    0.000001446   0.094992714   0.239636864     2262311
162 D2C    0.000193721   0.030406554   1.634221408     2262311
163 Q2C    0.000207665   0.125405263   1.830917198     2262311
164 \end{verbatim}
165
166   \item[Device Overhead]
167
168   Using the data from the previous chart, we can then provide some idea
169   as to where IO spend most of the time on average. The following output
170   shows the percentage of time spent in each of the 3 phases of an IO:
171
172 \begin{verbatim}
173        DEV |    Q2I    I2D    D2C
174 ---------- | ------ ------ ------
175  ( 68, 64) |   0.0%  75.7%  24.2%
176 \end{verbatim}
177
178   \item[Device Merge Information]
179
180   A key measurement when making changes in the system (software \emph{or}
181   hardware) is to understand the block IO layer ends up merging incoming
182   requests into fewer, but larger, IOs to the underlying driver. In this
183   section, we show the number of incoming requests (Q), the number of
184   issued requests (D) and the resultant ratio. We also provide values
185   for the minimum, average and maximum IOs generated.
186
187   Looking at the following example:
188
189 \begin{verbatim}
190        DEV |      #Q    #D Ratio | BLKmin BLKavg BLKmax   Total
191 ---------- | ------- ----- ----- | ------ ------ ------ -------
192  ( 68, 64) | 2262311 18178 124.5 |      2    124    128 2262382
193 \end{verbatim}
194
195   we see that (on average) the block IO layer is combining upwards of
196   125 incoming requests into a single request down the IO stack. The
197   resultant average IO size is 124 blocks.
198
199   \item[Device Seek Information]
200
201   Another useful measure is the variability in the sector distances
202   between consecutive IOs. The next session provides some rudimentary
203   statistics to gauge the general nature of the sector differences
204   between IOs. Values provided include the number of seeks (number of IOs
205   submitted to lower level drivers), the \emph{mean} distance between
206   IOs, the \emph{median} value for all seeks, and the \emph{mode} -
207   the value(s) and the counts are provided for the latter.
208
209 \begin{verbatim}
210       DEV | NSEEKS    MEAN MEDIAN | MODE
211 --------- | ------ ------- ------ | -------
212 ( 68, 64) |  18178 19611.3      0 | 0(17522)
213 \end{verbatim}
214
215   We have almost exclusively seen median and mode values of 0, indicating
216   that seeks tend to have an equal amount of forward and backwards
217   seeks. The larger the count for the mode in comparison to the total
218   number of seeks is indicative as to how many IOs are coming out of
219   the block IO layer in adjacent sectors. (Obviously, the higher this
220   percentage, the better the underlying subsystems can handle them.)
221
222
223   \item[Request Queue Plug Information]
224
225   During normal operation, requests queues are \emph{plugged} and during
226   such times the IO request queue elements are not able to be processed
227   by underlying drivers. The next section shows how often the request
228   queue was in such a state.
229
230 \begin{verbatim}
231       DEV | # Plugs # Timer Us  | % Time Q Plugged
232 --------- | ------- ----------  | ----------------
233 ( 68, 64) |     833(         0) |   0.356511895%
234 \end{verbatim}
235
236   There are two major reasons why request queues are unplugged, and both
237   are represented in the above table.
238
239   \begin{enumerate}
240     \item Explicit unplug request from some subsystem in the kernel.
241
242     \item Timed unplugs, due to a request queue exceeding some temporal
243     limit for being plugged. 
244   \end{enumerate}
245
246   The total number of unplugs is equal to the number of plugs less the
247   ones due to timer unplugs.
248 \end{description}
249
250 \subsection{\label{sec:detailed-data}Detailed Data}
251
252   In addition to the default sections output, if one supplies the
253   \texttt{--all-data} or \texttt{-A} argument (see section~\ref{sec:o-A})
254   to \texttt{btt} further sections are output:
255
256 \begin{description}
257   \item[Per Process] As traces are emitted, they are tagged with the
258   process ID of the currently running thread in the kernel. The process
259   names are also preserved, and mapped to the ID. For each of the parts
260   of the time line discussed above on page~\pageref{tl-defs}, a chart is
261   provided which breaks down the traces according to process ID (name).
262
263   One must be aware, however, that the process ID may not have anything
264   to do with the originating IO. For example, if an application is
265   doing buffered IO, then the actual submitted IOs will most likely
266   come from some page buffer management daemon thread (like pdflush,
267   or kjournald for example). Similarly, completion traces are rarely
268   (if ever?) going to be associated with the process which submitted
269   the IO in the first place.
270
271   Here is a sample portion of this type of chart, showing Q2Q times
272   per process:
273
274 \begin{verbatim}
275           Q2Q         MIN         AVG         MAX       N
276 ------------- ----------- ----------- ----------- -------
277 mkfs.ext3     0.000000778 0.000009074 1.797176188 1899371
278 mount         0.000000885 0.000672513 0.030638128      73
279 pdflush       0.000000790 0.000006752 0.247231307  179791
280 \end{verbatim}
281
282   \item[Per Process Averages] The average columns from the above charts,
283   are also presented in their own chart.
284
285   \item[Per Device] Similar to the per-process display, \texttt{btt}
286   will also break down the various parts of an IOs time line based upon a
287   per-device criteria. Here's a portion of this area, displayed showing
288   the issued to complete times (D2C).
289
290 \begin{verbatim}
291       D2C         MIN         AVG         MAX      N
292 --------- ----------- ----------- ----------- ------
293 ( 65, 80) 0.000140488 0.001076906 0.149739869 169112
294 ( 65, 96) 0.000142762 0.001215221 0.173263182 155488
295 ( 65,112) 0.000145221 0.001254966 0.124929936 165726
296 ( 65,128) 0.000141896 0.001159596 0.775231052 169015
297 ( 65,144) 0.000140832 0.001290985 0.211384698 210661
298 ( 65,160) 0.000139915 0.001175554 0.073512063 133973
299 ( 65,176) 0.000141254 0.001104870 0.073231310 145764
300 ( 65,192) 0.000141453 0.001234460 0.167622507 140618
301 ( 65,208) 0.000143901 0.001126610 0.144651899 178548
302 ( 65,224) 0.000145020 0.001226478 0.124902029 206241
303 ( 65,240) 0.000144315 0.001199571 0.102415459 129154
304 ...
305 \end{verbatim}
306
307   \item[Per Device Averages] The average columns from the above charts,
308   are also presented in their own chart.
309 \end{description}
310
311 \newpage\section{\label{sec:data-files}Data Files Output}
312
313   Besides the averages output by default, the following 3 files are also
314   created with data points which may be plotted.
315
316 \begin{description}
317   \item[\emph{file}.dat] This file provides a notion of \emph{activity}
318   for the system, devices and processes. The details of this file are
319   provided in section~\ref{sec:activity}.
320
321   \item[\emph{file}\_qhist.dat] Provides histogram data for the size of
322   incoming IO requests, for more information see section~\ref{sec:qhist}.
323
324   \item[\emph{file}\_dhist.dat] Provides histogram data for the size
325   of IO requests submitted to lower layer drivers, for more information
326   see section~\ref{sec:dhist}.
327
328 \end{description}
329
330   Besides the default data files output, there are optional data files
331   which can be generated by btt. These include:
332
333   \begin{description}
334     \item[iostat] iostat-like data can be distilled by btt, and is
335     described in section~\ref{sec:iostat}.
336
337     \item[per IO detail] Each and every IO traced can be output in a form
338     that shows each of the IO components on consecutive lines (rather
339     than grepping through a blkparse output file for example). The
340     details on this file is included in section~\ref{sec:per-io}.
341
342     \item[iostat] Latency information -- both Q2C and D2C --
343     on a per-IO basis can be generated. These are described in
344     sections~\ref{sec:lat-q2c} and~\ref{sec:lat-d2c}.
345
346     \item[seek details] A data file containing all IO-to-IO
347     sector differences can be output, with details found in
348     section~\ref{sec:seek}.
349
350     \item[unplug histogram details] A data file per device containing
351     histogram output for the amount of IOs released at unplug time.
352     Section~\ref{sec:o-u} has more details.
353   \end{description}
354
355 \newpage\section{\label{sec:activity}Activity Data File}
356
357   The activity data file contains a series of data values that indicate
358   those periods of time when queue and complete traces are being
359   processed.  The values happen to be in a format easily handled by
360   xmgrace\footnote{\texttt{http://plasma-gate.weizmann.ac.il/Grace/}
361   ``Grace is a WYSIWYG 2D plotting tool for the X Window System and
362   M*tif.''}, but is easy to parse for other plotting and/or analysis
363   programs.
364
365   The file is split into pairs of sets of data points, where each pair
366   contains a set of queue activity and a set of completion activity. The
367   points are presented with the first column (X values) being the time
368   (in seconds), and the second column (Y values) providing an on/off
369   type of setting. For each pair, the Y values have two settings off
370   (low) and on (high). For example, here is a snippet of a file showing
371   some Q activity:
372
373 \begin{verbatim}
374 # Total System
375 #     Total System : q activity
376 0.000000000   0.0
377 0.000000000   0.4
378 0.000070381   0.4
379 0.000070381   0.0
380 1.023482637   0.0
381 1.023482637   0.4
382 6.998746618   0.4
383 6.998746618   0.0
384 7.103336799   0.0
385 7.103336799   0.4
386 17.235419786   0.4
387 17.235419786   0.0
388 26.783361447   0.0
389 26.783361447   0.4
390 26.832454929   0.4
391 26.832454929   0.0
392 28.870431266   0.0
393 28.870431266   0.4
394 28.870431266   0.4
395 28.870431266   0.0
396 \end{verbatim}
397
398   What this indicates is that there was q activity for the system
399   from 0.000000000 through 0.000070381, but was inactive from there to
400   1.023482637, and so on. Section~\ref{sec:o-d} contains details on how
401   to adjust btt's notion of what constitutes activity.
402
403   The pairs are arranged as follows:
404
405   \begin{itemize}
406     \item First there is the total system activity -- meaning activity
407     in either queue or completion traces across all devices.
408
409     \item Next comes per-device activity information -- for each device
410     being traced, that request queues Q and C traces are presented.
411
412     \item Last we present pairs per-process.
413   \end{itemize}
414
415   Using this, one is then able to plot regions of activity versus
416   inactivity -- and one can gather a sense of deltas between the queueing
417   of IOs and when they are completed. Figure~\ref{fig:activity} shows
418   a very simplistic chart showing some activity:
419
420   \begin{figure}[hb]
421   \leavevmode\centering
422   \epsfig{file=activity.eps,width=4.5in}
423   \caption{\label{fig:activity}Simple Activity Chart}
424   \end{figure}
425
426   When the black line (system Q activity) is \emph{high}, then the system
427   is seeing relatively continuous incoming queues. Conversely, when it is
428   low, it represents an extended period of time where no queue requests
429   were coming in. Similarly for the red line and C activity.
430
431 \newpage\section{\label{sec:hist}Histogram Data Files}
432
433   The histogram data files provide information concerning incoming and
434   outgoing IO sizes (in blocks). For simplicity, the histogram buckets
435   are one-for-one for sizes up to 1,024 blocks in the IO, and then a
436   single bucket for all sizes greater than or equal to 1,024 blocks.
437
438   The files are again in grace-friendly format, with the first set
439   containing data for the first 1,023 buckets, and a separate set
440   representing sizes $\ge 1024$ blocks. (This is done so that one can
441   easily use a separate formatting specification for the latter set.)
442
443   The first column (X values) is the various IO sizes, and the second
444   column (Y values) represents the number of IOs of that size.
445
446 \subsection{\label{sec:qhist}Q Histogram Data File}
447
448   Figure~\ref{fig:qhist} is a sample graph generated from data used during
449   some real-world analysis\footnote{Note the logarithmic nature of the
450   Y axis for this chart.}. With the visual representation provided by
451   this, one can quickly discern some different characteristics between
452   the 3 runs -- in particular, one can see that there is only a single
453   red point (representing 8 blocks per IO), whereas the other two had
454   multiple data points greater than 8 blocks.
455
456   \begin{figure}[hb]
457   \leavevmode\centering
458   \epsfig{file=qhist.eps,width=4.5in}
459   \caption{\label{fig:qhist}Q Histogram}
460   \end{figure}
461
462 \subsection{\label{sec:dhist}D Histogram Data File}
463
464   Figure~\ref{fig:dhist} is a sample graph generated from data used during
465   some real-world analysis\footnote{Note the logarithmic nature of the
466   Y axis for this chart.}. Again, visually, one can see that the black
467   and blue dots are somewhat similar below about 192 blocks per IO going
468   out. And then one can make the broad generalization of higher reds,
469   lower blues and blacks in the middle.
470
471   \begin{figure}[hb]
472   \leavevmode\centering
473   \epsfig{file=dhist.eps,width=4.5in}
474   \caption{\label{fig:dhist}D Histogram}
475   \end{figure}
476
477 \newpage\section{\label{sec:iostat}iostat Data File}
478   \texttt{btt} attempts to produce the results from running an
479   \texttt{iostat -x} command in parallel with the system as it is being
480   traced. The fields (columns) generated by the \texttt{--iostat} or
481   \texttt{-I} option can be seen from the following output snippet --
482   note that the line has been split to fit on the printed page:
483
484 \begin{verbatim}
485 Device:       rrqm/s   wrqm/s     r/s     w/s    rsec/s    wsec/s
486              rkB/s     wkB/s avgrq-sz avgqu-sz   await   svctm  %util   Stamp
487 ...
488 (  8, 16)       0.00     0.00    0.00 1005.30      0.00 152806.36      
489               0.00  76403.18   152.00    31.00    0.00    0.00   0.00   71.79
490 ...
491 (  8, 16)       1.02     5.80    0.34    1.07      4.03     55.62
492               2.02     27.81    42.13     0.61    0.00   21.90   0.00   TOTAL
493 \end{verbatim}
494
495   Note that the STAMP field contains the runtime (in seconds) for that
496   line of data.
497
498 \newpage\section{\label{sec:per-io}Per-IO Data File}
499
500   \texttt{btt} can produce a text file containing time line data for each
501   IO processed. The time line data contains rudimentary information for
502   the following stages:
503
504   \begin{itemize}
505     \item queue traces
506     \item get request traces
507     \item insert traces
508     \item merge traces
509     \item issue traces
510     \item completion traces
511     \item remap traces
512   \end{itemize}
513
514   The \emph{--per-io-dump} or \emph{-p} option triggers this behavior,
515   and will produce a file containing streams of IOs (separated by blank
516   spaces), here is an example:
517
518 \begin{verbatim}
519    20.002179731   8,32  Q         34+8
520    20.002181199   8,32  I         34+8
521    20.098329567   8,32  D         34+16
522    20.002182760   8,32  Q         42+8
523    20.002183613   8,32  M         42+8
524    20.098329567   8,32  D         34+16
525    20.692643206   8,32  C         34+16
526 \end{verbatim}
527
528   The columns provide the following information:
529
530   \begin{enumerate}
531     \item Time of the trace (seconds from the start of the run)
532
533     \item Device major/minor.
534
535     \item Trace type 
536
537     \item start block + number of blocks
538   \end{enumerate}
539   
540   For this pair of initial IOs (Q traces at 20.002179731 and
541   20.002182760), we can follow the insert and merge traces (20.002181199
542   and 20.002183613 respectively), and the issue (duplicate entries for
543   20.098329567), and the completion at 20.692643206. Every Q has its
544   corresponding issue trace bounding any insert or merge operations.
545
546 \newpage\section{\label{sec:lat}\label{sec:lat-q2c}\label{sec:lat-d2c}Latency Data Files}
547
548   The latency data files which can be optionally produced by \texttt{btt}
549   provide per-IO latency information, one for total IO time (Q2C) and
550   one for latencies induced by lower layer drivers and devices (D2C).
551
552   In both cases, the first column (X values) represent runtime (seconds),
553   while the second column (Y values) shows the actual latency for a
554   command at that time (either Q2C or D2C).
555
556 \newpage\section{\label{sec:seek}Seek Data File}
557
558   \texttt{btt} can also produce a data file containing all IO-to-IO sector
559   deltas, providing seek information which can then be plotted. The
560   produced data file contains 3 sets of data:
561
562   \begin{enumerate}
563      \item Combined data -- all read and write IOs
564
565      \item Read data -- just seek deltas for reads
566
567      \item Write data -- just seek deltas for writes
568   \end{enumerate}
569
570   The format of the data is to have the runtime values (seconds since
571   the start of the run) in column 1 (X values); and the difference in
572   sectors from the previous IO in column 2 (Y values). Here is a snippet
573   of the first few items from a file:
574
575 \begin{verbatim}
576 # Combined
577      0.000034733           35283790.0
578      0.000106453           35283790.0
579      0.005239009           35283950.0
580      0.006968575           35283886.0
581      0.007218709           35283694.0
582      0.012145393           35283566.0
583      0.014980835          -35848914.0
584      0.024239323          -35848914.0
585      0.024249402          -35848914.0
586      0.025707095          -35849072.0
587      ...
588 \end{verbatim}
589
590   Figure~\ref{fig:seek} shows a simple graph that can be produced which
591   provides visual details concerning seek patterns.
592
593   \begin{figure}[h!]
594   \leavevmode\centering
595   \epsfig{file=seek.eps,width=4.5in}
596   \caption{\label{fig:seek}Seek Chart}
597   \end{figure}
598   \FloatBarrier
599
600   The seek difference is calculated in one of two ways:
601
602   \begin{description}
603     \item[default] By default, the seek distance is calculated as the
604     \emph{closest} distance between the previous IO and this IO. The
605     concept of \emph{closeness} means that it could either be the
606     \emph{end} of the previous IO and the beginning of the next, or the
607     end of this IO and the start of the next.
608
609     \item[\texttt{-a}] If the \texttt{-a} or \texttt{--seek-absolute}
610     option is specified, then the seek distance is simply the difference
611     between the end of the previous IO and the start of this IO.
612   \end{description}
613
614 \newpage\section{\label{sec:cmd-line}Command Line}
615
616 \begin{verbatim}
617 Usage: \texttt{btt} 0.99.1 
618 [ -a               | --seek-absolute ]
619 [ -A               | --all-data ]
620 [ -B <output name> | --dump-blocknos=<output name> ]
621 [ -d <seconds>     | --range-delta=<seconds> ]
622 [ -D <dev;...>     | --devices=<dev;...> ]
623 [ -e <exe,...>     | --exes=<exe,...>  ]
624 [ -h               | --help ]
625 [ -i <input name>  | --input-file=<input name> ]
626 [ -I <output name> | --iostat=<output name> ]
627 [ -l <output name> | --d2c-latencies=<output name> ]
628 [ -M <dev map>     | --dev-maps=<dev map>
629 [ -o <output name> | --output-file=<output name> ]
630 [ -p <output name> | --per-io-dump=<output name> ]
631 [ -q <output name> | --q2c-latencies=<output name> ]
632 [ -s <output name> | --seeks=<output name> ]
633 [ -S <interval>    | --iostat-interval=<interval> ]
634 [ -t <sec>         | --time-start=<sec> ]
635 [ -T <sec>         | --time-end=<sec> ]
636 [ -u <output name> | --unplug-hist=<output name> ] 
637 [ -V               | --version ]
638 [ -v               | --verbose ]
639 \end{verbatim}
640
641 \subsection{\label{sec:o-a}\texttt{--seek-absolute}/\texttt{-a}}
642
643   When specified on the command line, this directs btt to calculate
644   seek distances based solely upon the ending block address of one IO,
645   and the start of the next.  By default \texttt{btt} uses the concept
646   of the closeness to either the beginning or end of the previous IO. See
647   section~\ref{sec:seek} for more details about seek distances.
648
649 \subsection{\label{sec:o-A}\texttt{--all-data}/\texttt{-A}}
650
651   Normally \texttt{btt} will not print out verbose information
652   concerning per-process and per-device data (as outlined in
653   section~\ref{sec:detailed-data}). If you desire that level of 
654   detail you can specify this option.
655
656 \subsection{\label{sec:o-B}\texttt{--dump-blocknos}/\texttt{-B}}
657
658   This option will output absolute block numbers to three files prefixed
659   by the specified output name:
660
661   \begin{description}
662     \item[\emph{prefix}\_\emph{device}\_r.dat] All read block numbers are
663     output, first column is time (seconds), second is the block number,
664     and the third column is the ending block number.
665
666     \item[\emph{prefix}\_\emph{device}\_w.dat] All write block numbers are
667     output, first column is time (seconds), second is the block number,
668     and the third column is the ending block number.
669
670     \item[\emph{prefix}\_\emph{device}\_c.dat] All block numbers (read
671     and write) are output, first column is time (seconds), second is
672     the block number, and the third column is the ending block number.
673   \end{description}
674
675 \subsection{\label{sec:o-d}\texttt{--range-delta}/\texttt{-d}}
676
677   Section~\ref{sec:activity} discussed how \texttt{btt} outputs a file
678   containing Q and C activity, the notion of \emph{active} traces simply
679   means that there are Q or C traces occurring within a certain period
680   of each other. The default values is 0.1 seconds; with this option
681   allowing one to change that granularity. The smaller the value, the
682   more data points provided.
683
684 \subsection{\label{sec:o-D}\texttt{--devices}/\texttt{-D}}
685
686   Normally, \texttt{btt} will produce data for all devices detected in
687   the traces parsed. With this option, one can reduce the analysis to
688   one or more devices provided in the string passed to this option. The
689   device identifiers are the major and minor number of each device, and
690   each device identifier is separated by a colon (:). A valid specifier
691   for devices 8,0 and 8,8 would then be: \texttt{"8,0:8,8"}.
692
693 \subsection{\label{sec:o-e}\texttt{--exes}/\texttt{-e}}
694
695   Likewise, \texttt{btt} will produce data for all processes (executables)
696   found in the traces. With this option, one can specify which processes
697   you want displayed in the output. The format of the string passed is
698   a list of executable \emph{names} separated by commas (,). An example
699   would be \texttt{"-e mkfs.ext3,mount"}.
700
701 \subsection{\label{sec:o-h}\texttt{--help}/\texttt{-h}}
702
703   Prints out the simple help information, as seen at the top of
704   section~\ref{sec:cmd-line}.
705
706 \subsection{\label{sec:o-i}\texttt{--input-file}/\texttt{-i}}
707
708   Specifies the binary input file that \texttt{btt} will interpret traces
709   in. See section~\ref{sec:getting-started} for information concerning
710   binary trace files.
711
712 \subsection{\label{sec:o-I}\texttt{--iostat}/\texttt{-I}}
713
714   This option triggers \texttt{btt} to generate iostat-like output to the
715   file specified. Refer to section~\ref{sec:iostat} for more information
716   on the output produced.
717
718 \subsection{\label{sec:o-l}\texttt{--d2c-latencies}/\texttt{-l}}
719
720   This option instructs \texttt{btt} to generate the D2C latency file
721   discussed in section~\ref{sec:lat-d2c}.
722
723 \subsection{\label{sec:o-M}\texttt{--dev-maps}/\texttt{-M}}
724
725   Internal option, still under construction.
726
727 \subsection{\label{sec:o-o}\texttt{--output-file}/\texttt{-o}}
728
729   Normally \texttt{btt} sends the statistical output (covered in
730   section~\ref{sec:output-overview}) to standard out, if you specify
731   this option this data is redirected to the file specified.
732
733 \subsection{\label{sec:o-p}\texttt{--per-io-dump}/\texttt{-p}}
734
735   This option tells \texttt{btt} to generate the per IO dump file as
736   discussed in section~\ref{sec:per-io}.
737
738 \subsection{\label{sec:o-q}\texttt{--q2c-latencies}/\texttt{-q}}
739
740   This option instructs \texttt{btt} to generate the Q2C latency file
741   discussed in section~\ref{sec:lat-q2c}.
742
743 \subsection{\label{sec:o-s}\texttt{--seeks}/\texttt{-s}}
744
745   This option instructs \texttt{btt} to generate the seek data file
746   discussed in section~\ref{sec:seek}.
747
748 \subsection{\label{sec:o-S}\texttt{--iostat-interval}/\texttt{-S}}
749
750   The normal \texttt{iostat} command allows one to specify the snapshot
751   interval, likewise, \texttt{btt} allows one to specify how many seconds
752   between its generation of snapshots of the data via this option. Details
753   about the iostat-like capabilities of \texttt{btt} may be found in
754   section~\ref{sec:iostat}.
755
756 \subsection{\label{sec:o-tT}\texttt{--time-start}/\texttt{-t} and
757 \texttt{--time-end}/\texttt{T}}
758
759   \begin{quote}
760     \emph{This \texttt{btt} capability is still under construction, results are
761     not always consistent at this point in time.}
762   \end{quote}
763
764   These options allow one to dictate to \texttt{btt} when to start and stop
765   parsing of trace data in terms of seconds since the start of the run. The
766   trace chosen will be between the start time (or 0.0 if not
767   specified) and end time (or the end of the run) specified. 
768
769 \subsection{\label{sec:o-u}\texttt{--unplug-hist}/\texttt{-u}}
770
771   This option instructs \texttt{btt} to generate a data file containing
772   histogram information for \emph{unplug} traces on a per device
773   basis. It shows how many times an unplug was hit with a specified
774   number of IOs released. There are 21 output values into the file, as
775   follows:
776
777   \medskip
778   \begin{tabular}{ll}
779 \textbf{X value} & \textbf{Representing Counts} \\\hline
780 0 & 0\dots\/4 \\
781 1 & 5\dots\/9 \\
782 2 & 10\dots\/14 \\
783 \dots & \dots\dots\\
784 19 & 95\dots\/99 \\
785 20 & 100+ \\
786   \end{tabular}
787
788   \medskip
789   The file name(s) generated use the text string passed as an argument for
790   the prefix, followed by the device identifier in \texttt{major,minor}
791   form, with a \texttt{.dat} extension (as an example, with \texttt{-u
792   up\_hist} specified on the command line: \texttt{up\_hist\_008,032.dat}.
793
794 \subsection{\label{sec:o-V}\texttt{--version}/\texttt{-V}}
795
796   Prints out the \texttt{btt} version, and exits.
797
798 \subsection{\label{sec:o-v}\texttt{--verbose}/\texttt{-v}}
799
800   While \texttt{btt} is processing data, it will put out periodic (1-second
801   granularity) values describing the progress it is making through the
802   input trace stream. The value describes how many traces have been
803   processed. At the end of the run, the overall number of traces, trace
804   rate (number of thousands of traces per second), and the real time for
805   trace processing and output are displayed. Example (note: the interim
806   trace counts are put out with carriage returns, hence, they overwrite
807   each time):
808
809 \begin{verbatim}
810 # btt -i bp.bin -o btt -v
811 Sending range data to bttX.dat
812 Sending stats data to bttX.avg
813  287857 t
814 1414173 t
815 1691581 t
816 ...
817 4581291 traces @ 279.7 Ktps
818 16.379036+0.000005=16.379041
819 \end{verbatim}
820
821 \newpage\section*{\label{sec:appendix}Appendix: Sample \texttt{btt}
822 Output}
823   
824   Here is a complete output file from a btt run, illustrating a lot of the
825   capabilities of btt.
826
827 \begin{verbatim}
828 ==================== All Devices ====================
829
830             ALL           MIN           AVG           MAX           N
831 --------------- ------------- ------------- ------------- -----------
832 Q2Q               0.000000001   0.000015439   0.067431982     4485897
833 Q2I               0.000000277   0.000005085  12.844603081     4485736
834 I2D               0.000000869   0.000721745  12.845117057     4485736
835 D2C               0.000151807   0.005254051   0.097569048     4485736
836 Q2C               0.000156268   0.005980882  12.864868116     4485736
837
838 \end{verbatim}
839 \newpage\begin{verbatim}
840
841 ==================== Device Overhead ====================
842
843        DEV |    Q2I    I2D    D2C
844 ---------- | ------ ------ ------
845  (  8,160) |   0.0%   1.6%  98.4%
846  (  8,176) |   0.1%  20.0%  79.9%
847  (  8,208) |   1.2%  69.2%  29.5%
848  ( 65, 32) |   0.0%   1.1%  98.8%
849  ( 65, 64) |   0.0%   3.6%  96.4%
850  ( 65,176) |   0.0%   2.5%  97.4%
851  ( 65, 96) |   0.0%  15.3%  84.6%
852  (  8,224) |   0.0%   1.7%  98.3%
853  ( 65,112) |   0.0%   2.4%  97.6%
854  (  8,240) |   0.0%   2.3%  97.7%
855  ( 65,192) |   0.0%  19.4%  80.6%
856  ( 65,240) |   0.0%   1.3%  98.7%
857  ( 65, 48) |   0.0%   2.3%  97.7%
858  (  8, 32) |   0.0%   7.0%  93.0%
859  ( 66, 80) |   0.1%   9.9%  90.0%
860  ( 66, 32) |   0.0%   0.7%  99.3%
861  ( 65,224) |   0.0%  18.1%  81.9%
862  ( 65,144) |   0.1%  39.5%  60.5%
863  (  8,144) |   0.0%   0.7%  99.3%
864  ( 66,144) |   0.0%   1.5%  98.5%
865  ( 66,128) |   0.0%   3.0%  97.0%
866  ( 66,176) |   0.0%  12.5%  87.4%
867  ( 66,224) |   0.0%  10.2%  89.8%
868  ( 66,192) |   0.0%   2.1%  97.9%
869  ( 66,160) |   0.0%   9.4%  90.5%
870  ( 66,240) |   0.0%   9.8%  90.2%
871  ( 66,112) |   0.1%  24.2%  75.7%
872  (  8, 64) |   0.0%   9.6%  90.4%
873  ( 65,160) |   0.2%  26.2%  73.7%
874  ( 65,208) |   0.0%   2.0%  98.0%
875  ( 66, 16) |   0.0%   4.5%  95.5%
876  ( 65,  0) |   0.0%   2.2%  97.8%
877  ( 65, 16) |   0.0%   1.8%  98.1%
878  ( 66,208) |   0.0%   2.7%  97.3%
879  (  8,128) |   0.2%  23.7%  76.1%
880  ( 65, 80) |   0.0%  20.0%  80.0%
881  (  8,112) |   0.0%   1.2%  98.7%
882  ( 65,128) |   0.0%   1.9%  98.1%
883  ( 66, 64) |   0.0%  12.1%  87.9%
884  ( 66,  0) |   0.0%   7.2%  92.8%
885  ( 66, 48) |   0.0%   2.6%  97.4%
886  (  8,192) |   0.0%   2.3%  97.7%
887  ( 67, 16) |   0.0%   0.8%  99.2%
888  ( 66, 96) |   0.0%  12.3%  87.7%
889  (  8, 96) |   0.0%  10.3%  89.7%
890  (  8, 80) |   0.0%   1.7%  98.3%
891  (  8, 48) |   0.0%   0.7%  99.2%
892  ( 67,  0) |   0.0%   2.6%  97.4%
893
894 \end{verbatim}
895 \newpage\begin{verbatim}
896
897 ==================== Device Merge Information ====================
898
899        DEV |       #Q       #D   Ratio |   BLKmin   BLKavg   BLKmax    Total
900 ---------- | -------- -------- ------- | -------- -------- -------- --------
901  (  8,160) |    75145    47890     1.6 |        8       12     1024   601160
902  (  8,176) |    91374    55492     1.6 |        8       13     1024   730992
903  (  8,208) |   101039    63944     1.6 |        8       12     1024   809256
904  ( 65, 32) |    67919    44494     1.5 |        8       12     1024   543352
905  ( 65, 64) |   114614    77396     1.5 |        8       11     1024   916968
906  ( 65,176) |    93808    62746     1.5 |        8       11     1024   750464
907  ( 65, 96) |    95537    51705     1.8 |        8       14     1024   764296
908  (  8,224) |    95435    49753     1.9 |        8       15     1024   765560
909  ( 65,112) |   100020    63530     1.6 |        8       12     1024   800160
910  (  8,240) |    72282    44700     1.6 |        8       12     1024   578256
911  ( 65,192) |    95175    59010     1.6 |        8       12     1024   761400
912  ( 65,240) |    86334    53548     1.6 |        8       12     1024   690984
913  ( 65, 48) |    69623    44652     1.6 |        8       12     1024   556984
914  (  8, 32) |    97816    63116     1.5 |        8       12     1024   782528
915  ( 66, 80) |   110873    71526     1.6 |        8       12     1024   886984
916  ( 66, 32) |    79242    53134     1.5 |        8       11     1024   633936
917  ( 65,224) |   122788    66180     1.9 |        8       14     1024   982304
918  ( 65,144) |   116636    70205     1.7 |        8       13     1024   933416
919  (  8,144) |    72014    49047     1.5 |        8       11     1024   576112
920  ( 66,144) |   109244    70613     1.5 |        8       12     1024   873952
921  ( 66,128) |   104688    65381     1.6 |        8       12     1024   837504
922  ( 66,176) |    79627    47894     1.7 |        8       13     1024   637016
923  ( 66,224) |    88754    58159     1.5 |        8       12     1024   710032
924  ( 66,192) |    88919    55417     1.6 |        8       12     1024   711464
925  ( 66,160) |   102908    71156     1.4 |        8       11     1024   823264
926  ( 66,240) |    94190    66472     1.4 |        8       11     1024   753520
927  ( 66,112) |   138799    82027     1.7 |        8       13     1024  1110392
928  (  8, 64) |   105011    63892     1.6 |        8       13     1024   840112
929  ( 65,160) |    93383    55579     1.7 |        8       13     1024   747064
930  ( 65,208) |   109771    67987     1.6 |        8       12     1024   878168
931  ( 66, 16) |    96703    56613     1.7 |        8       13     1024   773624
932  ( 65,  0) |    83752    51532     1.6 |        8       13     1024   670032
933  ( 65, 16) |    64538    35982     1.8 |        8       14     1024   516320
934  ( 66,208) |    90636    54306     1.7 |        8       13     1024   725088
935  (  8,128) |    96202    59653     1.6 |        8       13     1024   776192
936  ( 65, 80) |   107945    65672     1.6 |        8       13     1024   863704
937  (  8,112) |    78235    52847     1.5 |        8       11     1024   625880
938  ( 65,128) |   104631    63106     1.7 |        8       13     1024   837048
939  ( 66, 64) |    86365    50956     1.7 |        8       13     1024   690920
940  ( 66,  0) |    90413    46722     1.9 |        8       15     1024   723304
941  ( 66, 48) |   106631    65219     1.6 |        8       13     1024   853048
942  (  8,192) |    80591    47154     1.7 |        8       13     1024   644728
943  ( 67, 16) |    72314    48487     1.5 |        8       11     1024   578512
944  ( 66, 96) |    90990    54454     1.7 |        8       13     1024   727920
945  (  8, 96) |   110805    73522     1.5 |        8       12     1024   886440
946  (  8, 80) |    85032    56643     1.5 |        8       12     1024   680400
947  (  8, 48) |    87374    57544     1.5 |        8       12     1024   698992
948  ( 67,  0) |    79611    53515     1.5 |        8       11     1024   636888
949 ---------- | -------- -------- ------- | -------- -------- -------- --------
950        DEV |       #Q       #D   Ratio |   BLKmin   BLKavg   BLKmax    Total
951      TOTAL |  4485736  2790572     1.6 |        8       12     1024 35896640
952
953 \end{verbatim}
954 \newpage\begin{verbatim}
955
956 ==================== Device Seek Information ====================
957
958        DEV |          NSEEKS            MEAN          MEDIAN | MODE           
959 ---------- | --------------- --------------- --------------- | ---------------
960  (  8,160) |           47890        203945.5               0 | 0(2496)
961  (  8,176) |           55492        252948.8               0 | 0(2360)
962  (  8,208) |           63944        167845.3               0 | 0(4327)
963  ( 65, 32) |           44494        224708.3               0 | 0(2683)
964  ( 65, 64) |           77396        197838.0               0 | 0(2532)
965  ( 65,176) |           62746        168400.5               0 | 0(2675)
966  ( 65, 96) |           51705        162500.2               0 | 0(2778)
967  (  8,224) |           49753        206665.7               0 | 0(2753)
968  ( 65,112) |           63530        146289.8               0 | 0(2598)
969  (  8,240) |           44700        167258.3               0 | 0(2735)
970  ( 65,192) |           59010        217004.7               0 | 0(2724)
971  ( 65,240) |           53548        278194.8               0 | 0(2415)
972  ( 65, 48) |           44652        180710.3               0 | 0(2660)
973  (  8, 32) |           63116        234049.5               0 | 0(2473)
974  ( 66, 80) |           71526        184981.9               0 | 0(2455)
975  ( 66, 32) |           53134        198369.5               0 | 0(2415)
976  ( 65,224) |           66180        157948.5               0 | 0(2859)
977  ( 65,144) |           70205        195689.7               0 | 0(2734)
978  (  8,144) |           49047        169282.7               0 | 0(2574)
979  ( 66,144) |           70613        149265.7               0 | 0(2717)
980  ( 66,128) |           65381        165931.1               0 | 0(2687)
981  ( 66,176) |           47894        199744.8               0 | 0(3096)
982  ( 66,224) |           58159        161603.9               0 | 0(2738)
983  ( 66,192) |           55417        153055.3               0 | 0(2828)
984  ( 66,160) |           71156        126479.4               0 | 0(2739)
985  ( 66,240) |           66472        142014.0               0 | 0(2933)
986  ( 66,112) |           82027        115471.3               0 | 0(2961)
987  (  8, 64) |           63892        136632.0               0 | 0(2655)
988  ( 65,160) |           55579        154668.3               0 | 0(3377)
989  ( 65,208) |           67987        152829.1               0 | 0(2523)
990  ( 66, 16) |           56613        150652.8               0 | 0(2886)
991  ( 65,  0) |           51532        186889.7               0 | 0(2765)
992  ( 65, 16) |           35982        327187.6               0 | 0(2756)
993  ( 66,208) |           54306        243784.1               0 | 0(3076)
994  (  8,128) |           59653        170797.2               0 | 0(2800)
995  ( 65, 80) |           65672        224501.4               0 | 0(2452)
996  (  8,112) |           52847        213100.3               0 | 0(2417)
997  ( 65,128) |           63106        207821.8               0 | 0(2686)
998  ( 66, 64) |           50956        198045.0               0 | 0(2896)
999  ( 66,  0) |           46722        205476.3               0 | 0(3159)
1000  ( 66, 48) |           65219        142716.6               0 | 0(2869)
1001  (  8,192) |           47154        248778.6               0 | 0(2584)
1002  ( 67, 16) |           48487        193335.5               0 | 0(2879)
1003  ( 66, 96) |           54454        185100.7               0 | 0(2158)
1004  (  8, 96) |           73522        216187.1               0 | 0(2476)
1005  (  8, 80) |           56643        172561.8               0 | 0(2612)
1006  (  8, 48) |           57544        219104.1               0 | 0(2472)
1007  ( 67,  0) |           53515        161613.8               0 | 0(2990)
1008 ---------- | --------------- --------------- --------------- | ---------------
1009    Overall |          NSEEKS            MEAN          MEDIAN | MODE           
1010    Average |         2790572        185170.0               0 | 0(131433)
1011
1012 \end{verbatim}
1013 \newpage\begin{verbatim}
1014 ==================== Plug Information ====================
1015
1016        DEV |    # Plugs # Timer Us  | % Time Q Plugged
1017 ---------- | ---------- ----------  | ----------------
1018  (  8,160) |      45092(         0) |   0.003021834%
1019  (  8,176) |      49430(         0) |   0.003724997%
1020  (  8,208) |      58950(         0) |   0.004506453%
1021  ( 65, 32) |      41617(         0) |   0.002710008%
1022  ( 65, 64) |      74294(         0) |   0.004971739%
1023  ( 65,176) |      59764(         0) |   0.003827258%
1024  ( 65, 96) |      47495(         0) |   0.004012641%
1025  (  8,224) |      46806(         0) |   0.003724031%
1026  ( 65,112) |      60539(         0) |   0.004272802%
1027  (  8,240) |      41797(         0) |   0.002832794%
1028  ( 65,192) |      54754(         0) |   0.004049758%
1029  ( 65,240) |      50757(         0) |   0.003466684%
1030  ( 65, 48) |      41749(         0) |   0.002783118%
1031  (  8, 32) |      59486(         0) |   0.004102902%
1032  ( 66, 80) |      67519(         0) |   0.004698104%
1033  ( 66, 32) |      50441(         0) |   0.003229586%
1034  ( 65,224) |      60219(         0) |   0.005114778%
1035  ( 65,144) |      64699(         0) |   0.005185315%
1036  (  8,144) |      46237(         0) |   0.002824578%
1037  ( 66,144) |      67605(         0) |   0.004459997%
1038  ( 66,128) |      62418(         0) |   0.004598612%
1039  ( 66,176) |      43007(         0) |   0.003277143%
1040  ( 66,224) |      54724(         0) |   0.003682546%
1041  ( 66,192) |      52395(         0) |   0.003611178%
1042  ( 66,160) |      67775(         0) |   0.004347445%
1043  ( 66,240) |      62892(         0) |   0.003906526%
1044  ( 66,112) |      72351(         0) |   0.005906198%
1045  (  8, 64) |      59642(         0) |   0.004275726%
1046  ( 65,160) |      50303(         0) |   0.003841735%
1047  ( 65,208) |      64750(         0) |   0.004655374%
1048  ( 66, 16) |      53443(         0) |   0.003936557%
1049  ( 65,  0) |      48450(         0) |   0.003301599%
1050  ( 65, 16) |      33047(         0) |   0.002447028%
1051  ( 66,208) |      51060(         0) |   0.003674090%
1052  (  8,128) |      52664(         0) |   0.004009472%
1053  ( 65, 80) |      61974(         0) |   0.004623080%
1054  (  8,112) |      50106(         0) |   0.003284028%
1055  ( 65,128) |      60047(         0) |   0.004267589%
1056  ( 66, 64) |      47590(         0) |   0.003646022%
1057  ( 66,  0) |      43413(         0) |   0.003600655%
1058  ( 66, 48) |      61984(         0) |   0.004440717%
1059  (  8,192) |      44294(         0) |   0.003120507%
1060  ( 67, 16) |      45482(         0) |   0.002852274%
1061  ( 66, 96) |      50099(         0) |   0.003970858%
1062  (  8, 96) |      70266(         0) |   0.004743310%
1063  (  8, 80) |      53676(         0) |   0.003530690%
1064  (  8, 48) |      54672(         0) |   0.003527266%
1065  ( 67,  0) |      50418(         0) |   0.003217817%
1066 ---------- | ---------- ----------  | ----------------
1067        DEV |    # Plugs # Timer Us  | % Time Q Plugged
1068    OVERALL |      54420(         0) |   0.003871155%
1069 \end{verbatim}
1070 \end{document}