Commit | Line | Data |
---|---|---|
512566d4 | 1 | \documentclass{article} |
69040794 | 2 | \usepackage{epsfig,placeins} |
512566d4 AB |
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)} | |
e47ada10 | 25 | \date{30 October 2008} |
512566d4 AB |
26 | |
27 | \begin{document} | |
28 | \maketitle | |
29 | %-------------- | |
30 | \section{\label{sec:intro}Introduction} | |
31 | ||
ae6d30f4 AB |
32 | \texttt{btt} is a post-processing tool for the block layer IO tracing |
33 | tool called blktrace. As noted in its Users Guide, blktrace | |
34 | ||
512566d4 AB |
35 | \begin{quotation} |
36 | is a block layer IO tracing mechanism which provides detailed | |
37 | information about request queue operations up to user space. | |
38 | \end{quotation} | |
39 | ||
40 | blktrace is capable of producing tremendous amounts of output in the | |
41 | form of multiple individual traces per IO executed during the traced | |
42 | run. It is also capable of producing some general statistics concerning | |
43 | IO rates and the like. \texttt{btt} goes further and produces a variety | |
44 | of overall statistics about each of the individual handling of IOs, and | |
45 | provides data we believe is useful to plot to provide visual comparisons | |
46 | for evaluation. | |
47 | ||
48 | This document will discuss \texttt{btt} usage, provide some sample output, | |
49 | and also show some interesting plots generated from the data provided | |
50 | by the \texttt{btt} utility. | |
51 | ||
52 | \bigskip | |
53 | A short note on the ordering of this document -- the actual | |
54 | command-line usage section occurs relatively late in the document (see | |
55 | section~\ref{sec:cmd-line}), as we felt that discussing some of the | |
56 | capabilities and output formats would make the parameter discussion | |
57 | easier. | |
58 | ||
59 | \bigskip | |
60 | This document refers to the output formats generated by \texttt{btt} | |
50f73899 | 61 | version 2.00. However, the descriptions are general enough to cover |
512566d4 AB |
62 | output formats prior to that. |
63 | ||
64 | \newpage\tableofcontents | |
65 | ||
66 | \newpage\section{\label{sec:getting-started}Getting Started} | |
67 | ||
68 | The simple pipeline to get going with \texttt{btt} is to perform the | |
69 | following steps: | |
70 | ||
71 | \begin{enumerate} | |
72 | \item Run \texttt{blktrace}, specifying whatever devices and other | |
73 | parameters you want. You must save the traces to disk in this step, | |
74 | btt does not work in live mode. | |
75 | ||
76 | \item After tracing completes, run \texttt{blkrawverify}, specifying | |
77 | all devices that were traced (or at least on all devices that you | |
78 | will use \texttt{btt} with -- section~\ref{sec:o-D} shows how you | |
79 | can dictate which devices to use with btt). If blkrawverify finds | |
80 | errors in the trace streams saved, it is best to recapture the data | |
81 | -- utilizing \texttt{btt} on \emph{unclean} trace files produces | |
82 | inconsistent results. | |
83 | ||
84 | While this step is optional, we have found that performing this | |
85 | helps to ensure data coming from \texttt{btt} makes the most sense. | |
86 | ||
87 | \item Run \texttt{blkparse} with the \texttt{-d} option specifying | |
88 | a file to store the combined binary stream. (e.g.: \texttt{blkparse | |
89 | -d bp.bin ...}). | |
90 | ||
91 | \texttt{blktrace} produces a series of binary files | |
92 | containing parallel trace streams -- one file per CPU per | |
93 | device. \texttt{blkparse} provides the ability to combine all the | |
94 | files into one time-ordered stream of traces for all devices. | |
95 | ||
96 | \item Run \texttt{btt} specifying the file produced by | |
97 | \texttt{blkparse} utilizing the \texttt{-i} option (e.g.: \texttt{btt | |
98 | -i bp.bin ...}). | |
99 | ||
100 | \end{enumerate} | |
101 | ||
102 | \newpage\section{\label{sec:output-overview}Output Overview} | |
103 | ||
104 | The major default areas of output provided by \texttt{btt} | |
105 | include\label{tl-defs}: | |
106 | ||
107 | \begin{description} | |
108 | \item[average component times across all IOs] The time line of each IO | |
109 | is broken down into 3 major regions: | |
110 | ||
111 | \begin{enumerate} | |
112 | \item Time needed to insert or merge an incoming IO onto the request | |
113 | queue. This is the average time from when the IO enters the block | |
ae6d30f4 | 114 | IO layer (queue trace) until it is inserted (insert trace). |
512566d4 AB |
115 | |
116 | This is denoted as \emph{Q2I} time. | |
117 | ||
354db430 AB |
118 | This is also broken down into two component times\footnote{On |
119 | occasion there are also some time spent \emph{sleeping} waiting | |
120 | for a request. That occurs between the Q and G operations. You | |
121 | will see these listed as \texttt{S2G} times.}: | |
ae6d30f4 AB |
122 | |
123 | \begin{description} | |
124 | \item[Q2G] Time needed to \emph{get} a request (get request | |
125 | trace). | |
126 | ||
b70a6642 | 127 | \item[G2I] Time needed to put that request onto the request |
ae6d30f4 AB |
128 | queue (insert trace). |
129 | \end{description} | |
130 | ||
131 | For \emph{merged} requests -- an incoming request that is merged | |
132 | with a previously submitted request -- we calculate \emph{Q2M}, the | |
133 | amount of time between the queue trace and the merge trace. | |
134 | ||
512566d4 AB |
135 | \item Time spent on the request queue. The average time from when |
136 | the IO is inserted or merged onto the request queue, until it is | |
137 | issued (issue trace) to the lower level driver. | |
138 | ||
139 | Referred to as \emph{I2D} time\footnote{The \emph{issue} trace | |
140 | is represented by a D in the blkparse output, hence its usage in | |
141 | btt to refer to issue traces. Note that an I is used to refer to | |
142 | \emph{insert} traces.}. | |
143 | ||
144 | \item Driver and device time -- the average time from when the | |
145 | actual IO was issued to the driver until is completed (completion | |
146 | trace) back to the block IO layer. | |
147 | ||
148 | This is referred to as the \emph{D2C} time\ | |
149 | \end{enumerate} | |
150 | ||
151 | Two other sets of results are presented in this section: | |
152 | ||
153 | \begin{enumerate} | |
154 | \item \emph{Q2Q} which measures the time between queue traces | |
155 | in the system. This provides some idea as to how quickly IOs are | |
156 | being handed to the block IO layer. | |
157 | ||
158 | \item \emph{Q2C} which measures the times for the complete life cycle | |
159 | of IOs during the run\footnote{One of the areas that needs some | |
160 | work in \texttt{btt} is to better understand the multiplex nature of | |
161 | IOs during a run. In theory, one would like ${Q2I} + {I2D} + {D2C} | |
162 | = {Q2C}$ however, typically there are multiple queue traces that | |
163 | are combined via merges into a single IO issued and completed. We | |
164 | currently average the queue-to-insert and queue-to-merge times, | |
165 | and thus tend to be quite close to the expected equation.} | |
166 | ||
167 | \end{enumerate} | |
168 | ||
169 | For each row in this output, we provide a minimum, average, maximum | |
170 | (which are all presented in seconds), and overall count. As an | |
171 | example\footnote{As with this display, the author has taken some liberty | |
172 | in reformatting the output for better display on the printed page.}: | |
173 | ||
174 | \begin{verbatim} | |
175 | ALL MIN AVG MAX N | |
176 | ---- ------------- ------------- ------------- ----------- | |
177 | Q2Q 0.000000058 0.000012761 9.547941661 2262310 | |
178 | Q2I 0.000000272 0.000005995 0.104588839 2262311 | |
179 | I2D 0.000001446 0.094992714 0.239636864 2262311 | |
180 | D2C 0.000193721 0.030406554 1.634221408 2262311 | |
181 | Q2C 0.000207665 0.125405263 1.830917198 2262311 | |
182 | \end{verbatim} | |
183 | ||
ae6d30f4 AB |
184 | When tracking \emph{device mapper} devices, we also break down the |
185 | \emph{Q2A} and \emph{Q2C} times for those IOs. | |
186 | ||
512566d4 AB |
187 | \item[Device Overhead] |
188 | ||
189 | Using the data from the previous chart, we can then provide some idea | |
190 | as to where IO spend most of the time on average. The following output | |
ae6d30f4 AB |
191 | shows the percentage of time spent in each of the phases of an |
192 | IO\footnote{It should be noted that incoming requests either go through: | |
193 | ||
194 | \begin{enumerate} | |
b70a6642 | 195 | \item Q2G + Q2I |
ae6d30f4 AB |
196 | |
197 | or | |
198 | ||
199 | \item Q2M | |
200 | \end{enumerate} | |
201 | before proceeding to I2D and D2C.} | |
512566d4 AB |
202 | |
203 | \begin{verbatim} | |
ae6d30f4 AB |
204 | DEV | Q2G G2I Q2M I2D D2C |
205 | ---------- | --------- --------- --------- --------- --------- | |
206 | ( 8, 80) | 0.0013% 0.0004% 0.0006% 88.5005% 11.4988% | |
207 | ---------- | --------- --------- --------- --------- --------- | |
208 | Overall | 0.0003% 0.0001% 0.0041% 21.4998% 78.4958% | |
512566d4 AB |
209 | \end{verbatim} |
210 | ||
211 | \item[Device Merge Information] | |
212 | ||
213 | A key measurement when making changes in the system (software \emph{or} | |
214 | hardware) is to understand the block IO layer ends up merging incoming | |
215 | requests into fewer, but larger, IOs to the underlying driver. In this | |
216 | section, we show the number of incoming requests (Q), the number of | |
217 | issued requests (D) and the resultant ratio. We also provide values | |
218 | for the minimum, average and maximum IOs generated. | |
219 | ||
220 | Looking at the following example: | |
221 | ||
222 | \begin{verbatim} | |
223 | DEV | #Q #D Ratio | BLKmin BLKavg BLKmax Total | |
224 | ---------- | ------- ----- ----- | ------ ------ ------ ------- | |
225 | ( 68, 64) | 2262311 18178 124.5 | 2 124 128 2262382 | |
226 | \end{verbatim} | |
227 | ||
228 | we see that (on average) the block IO layer is combining upwards of | |
229 | 125 incoming requests into a single request down the IO stack. The | |
230 | resultant average IO size is 124 blocks. | |
231 | ||
232 | \item[Device Seek Information] | |
233 | ||
234 | Another useful measure is the variability in the sector distances | |
ef144239 | 235 | between consecutively \emph{received -- queued} and \emph{submitted |
4c48f14e | 236 | -- issued} IOs. The next two sections provides some rudimentary |
512566d4 AB |
237 | statistics to gauge the general nature of the sector differences |
238 | between IOs. Values provided include the number of seeks (number of IOs | |
239 | submitted to lower level drivers), the \emph{mean} distance between | |
240 | IOs, the \emph{median} value for all seeks, and the \emph{mode} - | |
241 | the value(s) and the counts are provided for the latter. | |
242 | ||
4c48f14e AB |
243 | The first of the two sections displays values for Q2Q seek distances -- |
244 | providing a set of indicators showing how close incoming IO requests | |
245 | are to each other. The second section shows D2D seek distances -- | |
246 | providing a set of indicators showing how close the IO requests are | |
247 | that are handled by underlying drivers. | |
248 | ||
512566d4 AB |
249 | \begin{verbatim} |
250 | DEV | NSEEKS MEAN MEDIAN | MODE | |
251 | --------- | ------ ------- ------ | ------- | |
252 | ( 68, 64) | 18178 19611.3 0 | 0(17522) | |
253 | \end{verbatim} | |
254 | ||
255 | We have almost exclusively seen median and mode values of 0, indicating | |
256 | that seeks tend to have an equal amount of forward and backwards | |
257 | seeks. The larger the count for the mode in comparison to the total | |
258 | number of seeks is indicative as to how many IOs are coming out of | |
259 | the block IO layer in adjacent sectors. (Obviously, the higher this | |
260 | percentage, the better the underlying subsystems can handle them.) | |
261 | ||
512566d4 AB |
262 | \item[Request Queue Plug Information] |
263 | ||
264 | During normal operation, requests queues are \emph{plugged} and during | |
265 | such times the IO request queue elements are not able to be processed | |
266 | by underlying drivers. The next section shows how often the request | |
267 | queue was in such a state. | |
268 | ||
269 | \begin{verbatim} | |
270 | DEV | # Plugs # Timer Us | % Time Q Plugged | |
271 | --------- | ------- ---------- | ---------------- | |
272 | ( 68, 64) | 833( 0) | 0.356511895% | |
273 | \end{verbatim} | |
274 | ||
275 | There are two major reasons why request queues are unplugged, and both | |
276 | are represented in the above table. | |
277 | ||
278 | \begin{enumerate} | |
279 | \item Explicit unplug request from some subsystem in the kernel. | |
280 | ||
281 | \item Timed unplugs, due to a request queue exceeding some temporal | |
b70a6642 | 282 | limit for being plugged. |
512566d4 AB |
283 | \end{enumerate} |
284 | ||
285 | The total number of unplugs is equal to the number of plugs less the | |
286 | ones due to timer unplugs. | |
50f73899 | 287 | |
b70a6642 AB |
288 | \item[IOs per Unplug \& Unplugs-due-to-timeout] |
289 | ||
290 | In this subsection one can see the average number of IOs on the request | |
291 | queue at the time of an unplug or unplug due to a timeout. The following | |
292 | sample shows a sample of both unplug sections: | |
293 | ||
294 | \begin{verbatim} | |
295 | ==================== Plug Information ==================== | |
296 | ||
297 | DEV | # Plugs # Timer Us | % Time Q Plugged | |
298 | ---------- | ---------- ---------- | ---------------- | |
299 | ( 8, 0) | 1171( 123) | 0.280946640% | |
300 | ( 8, 32) | 4( 0) | 0.000325469% | |
301 | ---------- | ---------- ---------- | ---------------- | |
302 | Overall | # Plugs # Timer Us | % Time Q Plugged | |
303 | Average | 587( 61) | 0.140636055% | |
304 | ||
305 | DEV | IOs/Unp IOs/Unp(to) | |
306 | ---------- | ---------- ---------- | |
307 | ( 8, 0) | 9.2 8.8 | |
308 | ( 8, 32) | 2.5 0.0 | |
309 | ---------- | ---------- ---------- | |
310 | DEV | IOs/Unp IOs/Unp(to) | |
311 | Overall | 9.2 8.8 | |
312 | \end{verbatim} | |
313 | ||
314 | This table and the preceding one have to be considered together -- | |
315 | in the sample output in the immediately preceding table one can see | |
316 | how the larger number of data values for device (8,0) dominates in | |
317 | the overall average. | |
318 | ||
50f73899 AB |
319 | \item[Active Requests At Q Information] |
320 | ||
321 | An important consideration when analyzing block IO schedulers is to | |
322 | know how many requests the scheduler has to work with. The metric | |
323 | provided in this section details how many requests (on average) were | |
324 | being held by the IO scheduler when an incoming IO request was being | |
325 | handled. To determine this, \texttt{btt} keeps track of how many Q | |
ef144239 | 326 | requests came in, and subtracts requests that have been issued (D). |
50f73899 AB |
327 | |
328 | Here is a sample output of this sections: | |
329 | ||
330 | \begin{verbatim} | |
331 | ==================== Active Requests At Q Information ==================== | |
332 | ||
333 | DEV | Avg Reqs @ Q | |
334 | ---------- | ------------- | |
335 | ( 65, 80) | 12.0 | |
336 | ( 65,240) | 16.9 | |
337 | ... | |
338 | ( 66,112) | 44.2 | |
339 | ---------- | ------------- | |
340 | Overall | Avgs Reqs @ Q | |
341 | Average | 17.4 | |
342 | \end{verbatim} | |
343 | ||
512566d4 AB |
344 | \end{description} |
345 | ||
4c48f14e | 346 | \newpage |
ef144239 | 347 | \subsection*{\label{sec:detailed-data}Detailed Data} |
512566d4 AB |
348 | |
349 | In addition to the default sections output, if one supplies the | |
350 | \texttt{--all-data} or \texttt{-A} argument (see section~\ref{sec:o-A}) | |
351 | to \texttt{btt} further sections are output: | |
352 | ||
353 | \begin{description} | |
354 | \item[Per Process] As traces are emitted, they are tagged with the | |
355 | process ID of the currently running thread in the kernel. The process | |
356 | names are also preserved, and mapped to the ID. For each of the parts | |
357 | of the time line discussed above on page~\pageref{tl-defs}, a chart is | |
358 | provided which breaks down the traces according to process ID (name). | |
359 | ||
360 | One must be aware, however, that the process ID may not have anything | |
361 | to do with the originating IO. For example, if an application is | |
362 | doing buffered IO, then the actual submitted IOs will most likely | |
363 | come from some page buffer management daemon thread (like pdflush, | |
364 | or kjournald for example). Similarly, completion traces are rarely | |
365 | (if ever?) going to be associated with the process which submitted | |
366 | the IO in the first place. | |
367 | ||
368 | Here is a sample portion of this type of chart, showing Q2Q times | |
369 | per process: | |
370 | ||
371 | \begin{verbatim} | |
372 | Q2Q MIN AVG MAX N | |
373 | ------------- ----------- ----------- ----------- ------- | |
374 | mkfs.ext3 0.000000778 0.000009074 1.797176188 1899371 | |
375 | mount 0.000000885 0.000672513 0.030638128 73 | |
376 | pdflush 0.000000790 0.000006752 0.247231307 179791 | |
377 | \end{verbatim} | |
378 | ||
379 | \item[Per Process Averages] The average columns from the above charts, | |
380 | are also presented in their own chart. | |
381 | ||
382 | \item[Per Device] Similar to the per-process display, \texttt{btt} | |
383 | will also break down the various parts of an IOs time line based upon a | |
384 | per-device criteria. Here's a portion of this area, displayed showing | |
385 | the issued to complete times (D2C). | |
386 | ||
387 | \begin{verbatim} | |
388 | D2C MIN AVG MAX N | |
389 | --------- ----------- ----------- ----------- ------ | |
390 | ( 65, 80) 0.000140488 0.001076906 0.149739869 169112 | |
391 | ( 65, 96) 0.000142762 0.001215221 0.173263182 155488 | |
392 | ( 65,112) 0.000145221 0.001254966 0.124929936 165726 | |
393 | ( 65,128) 0.000141896 0.001159596 0.775231052 169015 | |
394 | ( 65,144) 0.000140832 0.001290985 0.211384698 210661 | |
395 | ( 65,160) 0.000139915 0.001175554 0.073512063 133973 | |
396 | ( 65,176) 0.000141254 0.001104870 0.073231310 145764 | |
397 | ( 65,192) 0.000141453 0.001234460 0.167622507 140618 | |
512566d4 AB |
398 | ... |
399 | \end{verbatim} | |
400 | ||
401 | \item[Per Device Averages] The average columns from the above charts, | |
402 | are also presented in their own chart. | |
951ea56c AB |
403 | |
404 | \item[Q2D Histogram] A display of histogram buckets for the Q to D times | |
405 | -- basically, from where an IO enters the block IO layer for a given | |
406 | device, and when it is dispatched. The buckets are arranged via the | |
407 | time in seconds, as in: | |
408 | ||
409 | \begin{verbatim} | |
410 | ==================== Q2D Histogram ==================== | |
411 | ||
412 | DEV | <.005 <.010 <.025 <.050 <.075 <.100 <.250 <.500 < 1.0 >=1.0 | |
413 | --------- | ===== ===== ===== ===== ===== ===== ===== ===== ===== ===== | |
414 | ( 66, 80) | 61.2 7.9 12.1 7.9 3.0 1.4 1.5 0.2 0.0 4.6 | |
415 | ( 65,192) | 42.3 5.0 8.7 30.0 8.9 3.0 1.8 0.1 0.0 0.1 | |
416 | ( 65,128) | 34.3 5.3 8.9 32.0 9.7 3.7 5.3 0.6 0.0 0.1 | |
417 | ... | |
418 | ( 65, 64) | 59.9 4.2 6.0 24.6 4.2 0.8 0.1 0.0 0.0 0.1 | |
419 | ( 66, 64) | 62.6 8.1 12.7 7.9 2.4 0.6 0.1 0.0 0.0 5.4 | |
420 | ========== | ===== ===== ===== ===== ===== ===== ===== ===== ===== ===== | |
421 | AVG | 52.9 6.2 10.0 20.1 5.3 1.7 1.4 0.2 0.0 2.1 | |
422 | \end{verbatim} | |
423 | ||
512566d4 AB |
424 | \end{description} |
425 | ||
426 | \newpage\section{\label{sec:data-files}Data Files Output} | |
427 | ||
428 | Besides the averages output by default, the following 3 files are also | |
429 | created with data points which may be plotted. | |
430 | ||
431 | \begin{description} | |
432 | \item[\emph{file}.dat] This file provides a notion of \emph{activity} | |
433 | for the system, devices and processes. The details of this file are | |
434 | provided in section~\ref{sec:activity}. | |
435 | ||
436 | \item[\emph{file}\_qhist.dat] Provides histogram data for the size of | |
437 | incoming IO requests, for more information see section~\ref{sec:qhist}. | |
438 | ||
439 | \item[\emph{file}\_dhist.dat] Provides histogram data for the size | |
440 | of IO requests submitted to lower layer drivers, for more information | |
441 | see section~\ref{sec:dhist}. | |
442 | ||
443 | \end{description} | |
444 | ||
f028c958 AB |
445 | In addition to the default data files output, there are optional data |
446 | files which can be generated by btt. These include: | |
512566d4 AB |
447 | |
448 | \begin{description} | |
f028c958 AB |
449 | \item[subset of \texttt{.avg} data, easily parsed ] When the |
450 | \texttt{-X} option is specified \emph{and} the \texttt{-o} has also | |
451 | been specified, then a subset of the data produced by default is | |
452 | copied to another file that is \emph{more easily parsed.} Refer to | |
453 | section~\ref{sec:o-X} for full details. | |
454 | ||
512566d4 AB |
455 | \item[iostat] iostat-like data can be distilled by btt, and is |
456 | described in section~\ref{sec:iostat}. | |
457 | ||
458 | \item[per IO detail] Each and every IO traced can be output in a form | |
459 | that shows each of the IO components on consecutive lines (rather | |
460 | than grepping through a blkparse output file for example). The | |
461 | details on this file is included in section~\ref{sec:per-io}. | |
462 | ||
e47ada10 | 463 | \item[iostat] Latency information -- both Q2d, D2c and Q2C -- |
512566d4 | 464 | on a per-IO basis can be generated. These are described in |
e47ada10 | 465 | section~\ref{sec:lat}. |
512566d4 | 466 | |
4c48f14e | 467 | \item[seek details] A set of data files containing all IO-to-IO |
512566d4 AB |
468 | sector differences can be output, with details found in |
469 | section~\ref{sec:seek}. | |
fc16a815 AB |
470 | |
471 | \item[unplug histogram details] A data file per device containing | |
472 | histogram output for the amount of IOs released at unplug time. | |
473 | Section~\ref{sec:o-u} has more details. | |
512566d4 AB |
474 | \end{description} |
475 | ||
476 | \newpage\section{\label{sec:activity}Activity Data File} | |
477 | ||
478 | The activity data file contains a series of data values that indicate | |
479 | those periods of time when queue and complete traces are being | |
480 | processed. The values happen to be in a format easily handled by | |
481 | xmgrace\footnote{\texttt{http://plasma-gate.weizmann.ac.il/Grace/} | |
482 | ``Grace is a WYSIWYG 2D plotting tool for the X Window System and | |
483 | M*tif.''}, but is easy to parse for other plotting and/or analysis | |
484 | programs. | |
485 | ||
486 | The file is split into pairs of sets of data points, where each pair | |
487 | contains a set of queue activity and a set of completion activity. The | |
488 | points are presented with the first column (X values) being the time | |
489 | (in seconds), and the second column (Y values) providing an on/off | |
490 | type of setting. For each pair, the Y values have two settings off | |
491 | (low) and on (high). For example, here is a snippet of a file showing | |
492 | some Q activity: | |
493 | ||
494 | \begin{verbatim} | |
495 | # Total System | |
496 | # Total System : q activity | |
497 | 0.000000000 0.0 | |
498 | 0.000000000 0.4 | |
499 | 0.000070381 0.4 | |
500 | 0.000070381 0.0 | |
501 | 1.023482637 0.0 | |
502 | 1.023482637 0.4 | |
503 | 6.998746618 0.4 | |
504 | 6.998746618 0.0 | |
505 | 7.103336799 0.0 | |
506 | 7.103336799 0.4 | |
507 | 17.235419786 0.4 | |
508 | 17.235419786 0.0 | |
509 | 26.783361447 0.0 | |
510 | 26.783361447 0.4 | |
511 | 26.832454929 0.4 | |
512 | 26.832454929 0.0 | |
513 | 28.870431266 0.0 | |
514 | 28.870431266 0.4 | |
515 | 28.870431266 0.4 | |
516 | 28.870431266 0.0 | |
517 | \end{verbatim} | |
518 | ||
519 | What this indicates is that there was q activity for the system | |
520 | from 0.000000000 through 0.000070381, but was inactive from there to | |
521 | 1.023482637, and so on. Section~\ref{sec:o-d} contains details on how | |
522 | to adjust btt's notion of what constitutes activity. | |
523 | ||
524 | The pairs are arranged as follows: | |
525 | ||
526 | \begin{itemize} | |
527 | \item First there is the total system activity -- meaning activity | |
528 | in either queue or completion traces across all devices. | |
529 | ||
530 | \item Next comes per-device activity information -- for each device | |
531 | being traced, that request queues Q and C traces are presented. | |
532 | ||
533 | \item Last we present pairs per-process. | |
534 | \end{itemize} | |
535 | ||
536 | Using this, one is then able to plot regions of activity versus | |
537 | inactivity -- and one can gather a sense of deltas between the queueing | |
538 | of IOs and when they are completed. Figure~\ref{fig:activity} shows | |
539 | a very simplistic chart showing some activity: | |
540 | ||
541 | \begin{figure}[hb] | |
542 | \leavevmode\centering | |
7174703f | 543 | \epsfig{file=activity.eps,width=4.5in} |
512566d4 AB |
544 | \caption{\label{fig:activity}Simple Activity Chart} |
545 | \end{figure} | |
546 | ||
7174703f AB |
547 | When the black line (system Q activity) is \emph{high}, then the system |
548 | is seeing relatively continuous incoming queues. Conversely, when it is | |
549 | low, it represents an extended period of time where no queue requests | |
550 | were coming in. Similarly for the red line and C activity. | |
512566d4 AB |
551 | |
552 | \newpage\section{\label{sec:hist}Histogram Data Files} | |
553 | ||
554 | The histogram data files provide information concerning incoming and | |
555 | outgoing IO sizes (in blocks). For simplicity, the histogram buckets | |
556 | are one-for-one for sizes up to 1,024 blocks in the IO, and then a | |
557 | single bucket for all sizes greater than or equal to 1,024 blocks. | |
558 | ||
559 | The files are again in grace-friendly format, with the first set | |
560 | containing data for the first 1,023 buckets, and a separate set | |
561 | representing sizes $\ge 1024$ blocks. (This is done so that one can | |
562 | easily use a separate formatting specification for the latter set.) | |
563 | ||
564 | The first column (X values) is the various IO sizes, and the second | |
565 | column (Y values) represents the number of IOs of that size. | |
566 | ||
ef144239 | 567 | \subsection*{\label{sec:qhist}Q Histogram Data File} |
512566d4 AB |
568 | |
569 | Figure~\ref{fig:qhist} is a sample graph generated from data used during | |
570 | some real-world analysis\footnote{Note the logarithmic nature of the | |
571 | Y axis for this chart.}. With the visual representation provided by | |
572 | this, one can quickly discern some different characteristics between | |
573 | the 3 runs -- in particular, one can see that there is only a single | |
574 | red point (representing 8 blocks per IO), whereas the other two had | |
575 | multiple data points greater than 8 blocks. | |
576 | ||
577 | \begin{figure}[hb] | |
578 | \leavevmode\centering | |
7174703f | 579 | \epsfig{file=qhist.eps,width=4.5in} |
512566d4 AB |
580 | \caption{\label{fig:qhist}Q Histogram} |
581 | \end{figure} | |
582 | ||
ef144239 | 583 | \subsection*{\label{sec:dhist}D Histogram Data File} |
512566d4 AB |
584 | |
585 | Figure~\ref{fig:dhist} is a sample graph generated from data used during | |
586 | some real-world analysis\footnote{Note the logarithmic nature of the | |
587 | Y axis for this chart.}. Again, visually, one can see that the black | |
588 | and blue dots are somewhat similar below about 192 blocks per IO going | |
589 | out. And then one can make the broad generalization of higher reds, | |
590 | lower blues and blacks in the middle. | |
591 | ||
592 | \begin{figure}[hb] | |
593 | \leavevmode\centering | |
7174703f | 594 | \epsfig{file=dhist.eps,width=4.5in} |
512566d4 AB |
595 | \caption{\label{fig:dhist}D Histogram} |
596 | \end{figure} | |
597 | ||
598 | \newpage\section{\label{sec:iostat}iostat Data File} | |
599 | \texttt{btt} attempts to produce the results from running an | |
600 | \texttt{iostat -x} command in parallel with the system as it is being | |
601 | traced. The fields (columns) generated by the \texttt{--iostat} or | |
602 | \texttt{-I} option can be seen from the following output snippet -- | |
603 | note that the line has been split to fit on the printed page: | |
604 | ||
605 | \begin{verbatim} | |
606 | Device: rrqm/s wrqm/s r/s w/s rsec/s wsec/s | |
607 | rkB/s wkB/s avgrq-sz avgqu-sz await svctm %util Stamp | |
608 | ... | |
b70a6642 | 609 | ( 8, 16) 0.00 0.00 0.00 1005.30 0.00 152806.36 |
512566d4 AB |
610 | 0.00 76403.18 152.00 31.00 0.00 0.00 0.00 71.79 |
611 | ... | |
612 | ( 8, 16) 1.02 5.80 0.34 1.07 4.03 55.62 | |
613 | 2.02 27.81 42.13 0.61 0.00 21.90 0.00 TOTAL | |
614 | \end{verbatim} | |
615 | ||
616 | Note that the STAMP field contains the runtime (in seconds) for that | |
617 | line of data. | |
618 | ||
619 | \newpage\section{\label{sec:per-io}Per-IO Data File} | |
620 | ||
621 | \texttt{btt} can produce a text file containing time line data for each | |
622 | IO processed. The time line data contains rudimentary information for | |
623 | the following stages: | |
624 | ||
625 | \begin{itemize} | |
626 | \item queue traces | |
627 | \item get request traces | |
628 | \item insert traces | |
629 | \item merge traces | |
630 | \item issue traces | |
631 | \item completion traces | |
632 | \item remap traces | |
633 | \end{itemize} | |
634 | ||
635 | The \emph{--per-io-dump} or \emph{-p} option triggers this behavior, | |
636 | and will produce a file containing streams of IOs (separated by blank | |
4c48f14e AB |
637 | spaces). As an example, here is a snippet of 4 IOs that were merged |
638 | together, you will note there are 3 merged IOs, and 1 inserted in the | |
639 | stream. The issue and completion traces are replicated per IO. | |
512566d4 AB |
640 | |
641 | \begin{verbatim} | |
b70a6642 AB |
642 | 66,0 : 0.763283556 Q 6208+8 |
643 | 0.763300157 I 6208+8 | |
644 | 0.763296365 G 6208+8 | |
645 | 0.763338848 D 6208+32 | |
646 | 0.763705760 C 6208+32 | |
647 | ||
648 | 66,0 : 0.763314550 Q 6224+8 | |
649 | 0.763315341 M 6224+8 | |
650 | 0.763338848 D 6208+32 | |
651 | 0.763705760 C 6208+32 | |
652 | ||
653 | 66,0 : 0.763321010 Q 6232+8 | |
654 | 0.763321775 M 6232+8 | |
655 | 0.763338848 D 6208+32 | |
656 | 0.763705760 C 6208+32 | |
657 | ||
658 | 65,240: 0.763244173 Q 6216+8 | |
659 | 0.763244974 M 6216+8 | |
660 | 0.763374288 D 6208+32 | |
661 | 0.763826610 C 6208+32 | |
512566d4 AB |
662 | \end{verbatim} |
663 | ||
664 | The columns provide the following information: | |
665 | ||
666 | \begin{enumerate} | |
512566d4 AB |
667 | \item Device major/minor. |
668 | ||
4c48f14e AB |
669 | \item Time of the trace (seconds from the start of the run) |
670 | ||
b70a6642 | 671 | \item Trace type |
512566d4 AB |
672 | |
673 | \item start block + number of blocks | |
674 | \end{enumerate} | |
b70a6642 | 675 | |
e47ada10 | 676 | \newpage\section{\label{sec:lat}\label{sec:lat-q2d}\label{sec:lat-q2c}\label{sec:lat-d2c}Latency Data Files} |
512566d4 AB |
677 | |
678 | The latency data files which can be optionally produced by \texttt{btt} | |
e47ada10 AB |
679 | provide per-IO latency information, one for queue time (Q2D), one |
680 | for total IO time (Q2C) and one for latencies induced by lower layer | |
681 | drivers and devices (D2C). | |
512566d4 AB |
682 | |
683 | In both cases, the first column (X values) represent runtime (seconds), | |
684 | while the second column (Y values) shows the actual latency for a | |
e47ada10 | 685 | command at that time (either Q2D, D2C or Q2C). |
512566d4 | 686 | |
ccf6d55e | 687 | \newpage\section{\label{sec:seek}Seek Data Files} |
512566d4 | 688 | |
4c48f14e | 689 | \texttt{btt} can also produce two data files containing all IO-to-IO sector |
512566d4 AB |
690 | deltas, providing seek information which can then be plotted. The |
691 | produced data file contains 3 sets of data: | |
692 | ||
693 | \begin{enumerate} | |
694 | \item Combined data -- all read and write IOs | |
695 | ||
696 | \item Read data -- just seek deltas for reads | |
697 | ||
698 | \item Write data -- just seek deltas for writes | |
699 | \end{enumerate} | |
700 | ||
b70a6642 | 701 | The format of the output file names is to have the name generated by |
4c48f14e | 702 | the following fields separated by underscores (\texttt{\_}): |
b70a6642 | 703 | |
4c48f14e AB |
704 | \begin{itemize} |
705 | \item The prefix provided as the argument to the \texttt{-s} option. | |
706 | \item The major and minor numbers of the device separated by a comma. | |
b70a6642 | 707 | \item The string \texttt{q2q} or \texttt{d2d}, indicating the Q2Q or |
4c48f14e AB |
708 | D2D seeks, respectively. |
709 | \item One of the following characters: | |
710 | \begin{description} | |
711 | \item[r] For read (device to system) IOs | |
712 | \item[w] For write (system to device) IOs | |
713 | \item[c] Combined -- both read and write IOs | |
714 | \end{description} | |
715 | \end{itemize} | |
716 | ||
717 | An example name would be after specifying \texttt{-s seek} would be: | |
718 | \texttt{seek\_065,048\_q2q\_w.dat}. | |
719 | ||
512566d4 AB |
720 | The format of the data is to have the runtime values (seconds since |
721 | the start of the run) in column 1 (X values); and the difference in | |
722 | sectors from the previous IO in column 2 (Y values). Here is a snippet | |
723 | of the first few items from a file: | |
724 | ||
725 | \begin{verbatim} | |
726 | # Combined | |
727 | 0.000034733 35283790.0 | |
728 | 0.000106453 35283790.0 | |
729 | 0.005239009 35283950.0 | |
730 | 0.006968575 35283886.0 | |
731 | 0.007218709 35283694.0 | |
732 | 0.012145393 35283566.0 | |
733 | 0.014980835 -35848914.0 | |
734 | 0.024239323 -35848914.0 | |
735 | 0.024249402 -35848914.0 | |
736 | 0.025707095 -35849072.0 | |
737 | ... | |
738 | \end{verbatim} | |
739 | ||
740 | Figure~\ref{fig:seek} shows a simple graph that can be produced which | |
741 | provides visual details concerning seek patterns. | |
742 | ||
7174703f | 743 | \begin{figure}[h!] |
512566d4 | 744 | \leavevmode\centering |
7174703f | 745 | \epsfig{file=seek.eps,width=4.5in} |
512566d4 AB |
746 | \caption{\label{fig:seek}Seek Chart} |
747 | \end{figure} | |
69040794 AB |
748 | \FloatBarrier |
749 | ||
750 | The seek difference is calculated in one of two ways: | |
751 | ||
752 | \begin{description} | |
753 | \item[default] By default, the seek distance is calculated as the | |
754 | \emph{closest} distance between the previous IO and this IO. The | |
755 | concept of \emph{closeness} means that it could either be the | |
756 | \emph{end} of the previous IO and the beginning of the next, or the | |
757 | end of this IO and the start of the next. | |
758 | ||
759 | \item[\texttt{-a}] If the \texttt{-a} or \texttt{--seek-absolute} | |
760 | option is specified, then the seek distance is simply the difference | |
761 | between the end of the previous IO and the start of this IO. | |
762 | \end{description} | |
512566d4 | 763 | |
ccf6d55e AB |
764 | \newpage\subsection{\label{sec:sps-spec}Seeks Per Second} |
765 | ||
766 | When the \texttt{-m} option provides a name, Q2Q and/or D2D seeks | |
767 | will trigger \texttt{btt} to output seeks-per-second information. The | |
768 | first column will contain a time value (seconds), and the second column | |
769 | will indicate the number of seeks per second at that point. | |
770 | ||
771 | When there is only a single data point within a 1-second window, | |
772 | \texttt{btt} will just output the time value for the point, and the | |
5bebfd16 AB |
773 | value 1.0 in the second column. If there is no perceived difference |
774 | in the times present for the current sample, then the second columns | |
775 | value is the number of seeks present at that time. | |
ccf6d55e AB |
776 | |
777 | Otherwise, if $\alpha$ and $\Omega$ are the first and last times | |
778 | seen within a 1-second window, and $\nu$ are the number of seeks seen | |
779 | in that time frame, then: | |
780 | ||
781 | \begin{description} | |
782 | \item[column 1] Midway point in time for this span, or: \hfill$\alpha + | |
783 | {{(\Omega - \alpha)} / 2}$ | |
784 | ||
785 | \item[column 2] Average seeks per second over this span, or: \hfill$\nu / | |
786 | {(\Omega - \alpha)}$ | |
787 | \end{description} | |
788 | ||
789 | Figure~\ref{fig:sps} shows a simple pair of graphs generated from | |
790 | \texttt{-m} output: | |
791 | ||
792 | \begin{figure}[h!] | |
793 | \leavevmode\centering | |
794 | \epsfig{file=sps.eps,width=4.5in} | |
795 | \caption{\label{fig:sps}Seeks-per-second Chart} | |
796 | \end{figure} | |
797 | \FloatBarrier | |
798 | ||
512566d4 AB |
799 | \newpage\section{\label{sec:cmd-line}Command Line} |
800 | ||
801 | \begin{verbatim} | |
a22df989 | 802 | Usage: btt 2.07 |
69040794 | 803 | [ -a | --seek-absolute ] |
512566d4 | 804 | [ -A | --all-data ] |
69040794 | 805 | [ -B <output name> | --dump-blocknos=<output name> ] |
512566d4 AB |
806 | [ -d <seconds> | --range-delta=<seconds> ] |
807 | [ -D <dev;...> | --devices=<dev;...> ] | |
808 | [ -e <exe,...> | --exes=<exe,...> ] | |
809 | [ -h | --help ] | |
810 | [ -i <input name> | --input-file=<input name> ] | |
811 | [ -I <output name> | --iostat=<output name> ] | |
812 | [ -l <output name> | --d2c-latencies=<output name> ] | |
2baef508 | 813 | [ -L <freq> | --periodic-latencies=<freq> ] |
ccf6d55e | 814 | [ -m <output name> | --seeks-per-second=<output name> ] |
512566d4 AB |
815 | [ -M <dev map> | --dev-maps=<dev map> |
816 | [ -o <output name> | --output-file=<output name> ] | |
817 | [ -p <output name> | --per-io-dump=<output name> ] | |
a22df989 | 818 | [ -P <output name> | --per-io-trees=<output name> ] |
512566d4 | 819 | [ -q <output name> | --q2c-latencies=<output name> ] |
4ae2c3c6 | 820 | [ -Q <output name> | --active-queue-depth=<output name> ] |
512566d4 AB |
821 | [ -s <output name> | --seeks=<output name> ] |
822 | [ -S <interval> | --iostat-interval=<interval> ] | |
823 | [ -t <sec> | --time-start=<sec> ] | |
824 | [ -T <sec> | --time-end=<sec> ] | |
b70a6642 | 825 | [ -u <output name> | --unplug-hist=<output name> ] |
512566d4 AB |
826 | [ -V | --version ] |
827 | [ -v | --verbose ] | |
f028c958 | 828 | [ -X | --easy-parse-avgs ] |
e47ada10 | 829 | [ -z <output name> | --q2d-latencies=<output name> ] |
512566d4 AB |
830 | \end{verbatim} |
831 | ||
69040794 AB |
832 | \subsection{\label{sec:o-a}\texttt{--seek-absolute}/\texttt{-a}} |
833 | ||
834 | When specified on the command line, this directs btt to calculate | |
835 | seek distances based solely upon the ending block address of one IO, | |
836 | and the start of the next. By default \texttt{btt} uses the concept | |
837 | of the closeness to either the beginning or end of the previous IO. See | |
838 | section~\ref{sec:seek} for more details about seek distances. | |
839 | ||
512566d4 AB |
840 | \subsection{\label{sec:o-A}\texttt{--all-data}/\texttt{-A}} |
841 | ||
842 | Normally \texttt{btt} will not print out verbose information | |
843 | concerning per-process and per-device data (as outlined in | |
b70a6642 | 844 | section~\ref{sec:detailed-data}). If you desire that level of |
512566d4 AB |
845 | detail you can specify this option. |
846 | ||
69040794 AB |
847 | \subsection{\label{sec:o-B}\texttt{--dump-blocknos}/\texttt{-B}} |
848 | ||
849 | This option will output absolute block numbers to three files prefixed | |
850 | by the specified output name: | |
851 | ||
852 | \begin{description} | |
853 | \item[\emph{prefix}\_\emph{device}\_r.dat] All read block numbers are | |
854 | output, first column is time (seconds), second is the block number, | |
855 | and the third column is the ending block number. | |
856 | ||
857 | \item[\emph{prefix}\_\emph{device}\_w.dat] All write block numbers are | |
858 | output, first column is time (seconds), second is the block number, | |
859 | and the third column is the ending block number. | |
860 | ||
861 | \item[\emph{prefix}\_\emph{device}\_c.dat] All block numbers (read | |
862 | and write) are output, first column is time (seconds), second is | |
863 | the block number, and the third column is the ending block number. | |
864 | \end{description} | |
865 | ||
512566d4 AB |
866 | \subsection{\label{sec:o-d}\texttt{--range-delta}/\texttt{-d}} |
867 | ||
868 | Section~\ref{sec:activity} discussed how \texttt{btt} outputs a file | |
869 | containing Q and C activity, the notion of \emph{active} traces simply | |
870 | means that there are Q or C traces occurring within a certain period | |
871 | of each other. The default values is 0.1 seconds; with this option | |
872 | allowing one to change that granularity. The smaller the value, the | |
873 | more data points provided. | |
874 | ||
875 | \subsection{\label{sec:o-D}\texttt{--devices}/\texttt{-D}} | |
876 | ||
877 | Normally, \texttt{btt} will produce data for all devices detected in | |
878 | the traces parsed. With this option, one can reduce the analysis to | |
879 | one or more devices provided in the string passed to this option. The | |
880 | device identifiers are the major and minor number of each device, and | |
881 | each device identifier is separated by a colon (:). A valid specifier | |
882 | for devices 8,0 and 8,8 would then be: \texttt{"8,0:8,8"}. | |
883 | ||
884 | \subsection{\label{sec:o-e}\texttt{--exes}/\texttt{-e}} | |
885 | ||
886 | Likewise, \texttt{btt} will produce data for all processes (executables) | |
887 | found in the traces. With this option, one can specify which processes | |
888 | you want displayed in the output. The format of the string passed is | |
889 | a list of executable \emph{names} separated by commas (,). An example | |
890 | would be \texttt{"-e mkfs.ext3,mount"}. | |
891 | ||
892 | \subsection{\label{sec:o-h}\texttt{--help}/\texttt{-h}} | |
893 | ||
894 | Prints out the simple help information, as seen at the top of | |
895 | section~\ref{sec:cmd-line}. | |
896 | ||
897 | \subsection{\label{sec:o-i}\texttt{--input-file}/\texttt{-i}} | |
898 | ||
899 | Specifies the binary input file that \texttt{btt} will interpret traces | |
900 | in. See section~\ref{sec:getting-started} for information concerning | |
901 | binary trace files. | |
902 | ||
903 | \subsection{\label{sec:o-I}\texttt{--iostat}/\texttt{-I}} | |
904 | ||
905 | This option triggers \texttt{btt} to generate iostat-like output to the | |
906 | file specified. Refer to section~\ref{sec:iostat} for more information | |
907 | on the output produced. | |
908 | ||
909 | \subsection{\label{sec:o-l}\texttt{--d2c-latencies}/\texttt{-l}} | |
910 | ||
911 | This option instructs \texttt{btt} to generate the D2C latency file | |
912 | discussed in section~\ref{sec:lat-d2c}. | |
913 | ||
2baef508 AB |
914 | \subsection{\label{sec:o-L}\texttt{--periodic-latencies}/\texttt{-L}} |
915 | ||
916 | When given a value greater than 0, this option will create two data | |
917 | files (q2c \& d2c) per device containing a periodic timestamp \& | |
918 | average latency over that period. | |
919 | ||
ccf6d55e AB |
920 | \subsection{\label{sec:o-m}\texttt{--seeks-per-second}\texttt{-m}} |
921 | ||
922 | Tells \texttt{btt} to output seeks per second information. Each device | |
923 | being measured can have up to 2 files output: One with Q2Q information | |
924 | and one with D2D seek information. Information on the output produced | |
925 | can be found in section~\ref{sec:sps-spec}. | |
926 | ||
927 | \begin{quote} | |
928 | \textbf{Note: This requires seek output to be selected -- see | |
929 | section~\ref{sec:seek}.} | |
930 | \end{quote} | |
931 | ||
512566d4 AB |
932 | \subsection{\label{sec:o-M}\texttt{--dev-maps}/\texttt{-M}} |
933 | ||
934 | Internal option, still under construction. | |
935 | ||
936 | \subsection{\label{sec:o-o}\texttt{--output-file}/\texttt{-o}} | |
937 | ||
938 | Normally \texttt{btt} sends the statistical output (covered in | |
939 | section~\ref{sec:output-overview}) to standard out, if you specify | |
940 | this option this data is redirected to the file specified. | |
941 | ||
942 | \subsection{\label{sec:o-p}\texttt{--per-io-dump}/\texttt{-p}} | |
943 | ||
944 | This option tells \texttt{btt} to generate the per IO dump file as | |
945 | discussed in section~\ref{sec:per-io}. | |
946 | ||
a22df989 AB |
947 | \subsection{\label{sec:o-P}\texttt{--per-io-tress}/\texttt{-P}} |
948 | ||
949 | The \texttt{-P} option will generate a file that contains a list of all IO | |
950 | "sequences" - showing only the Q, D \& C operation times. The D \& C | |
951 | time values are separated from the Q time values with a vertical bar. | |
952 | ||
512566d4 AB |
953 | \subsection{\label{sec:o-q}\texttt{--q2c-latencies}/\texttt{-q}} |
954 | ||
955 | This option instructs \texttt{btt} to generate the Q2C latency file | |
956 | discussed in section~\ref{sec:lat-q2c}. | |
957 | ||
4ae2c3c6 AB |
958 | \subsection{\label{sec:o-Q}\texttt{--active-queue-depth}/\texttt{-Q}} |
959 | ||
960 | This option tells \texttt{btt} to generate a data file (using the given | |
961 | name as a base) which contains: A time stamp in the first column, | |
962 | and then the number of \emph{active} requests issued to the device | |
963 | driver. (The value is incremented when an \emph{issue} is performend, | |
964 | and decremented when a \emph{complete} is performed. | |
965 | ||
512566d4 AB |
966 | \subsection{\label{sec:o-s}\texttt{--seeks}/\texttt{-s}} |
967 | ||
fc16a815 | 968 | This option instructs \texttt{btt} to generate the seek data file |
512566d4 AB |
969 | discussed in section~\ref{sec:seek}. |
970 | ||
971 | \subsection{\label{sec:o-S}\texttt{--iostat-interval}/\texttt{-S}} | |
972 | ||
973 | The normal \texttt{iostat} command allows one to specify the snapshot | |
974 | interval, likewise, \texttt{btt} allows one to specify how many seconds | |
975 | between its generation of snapshots of the data via this option. Details | |
976 | about the iostat-like capabilities of \texttt{btt} may be found in | |
7174703f | 977 | section~\ref{sec:iostat}. |
512566d4 AB |
978 | |
979 | \subsection{\label{sec:o-tT}\texttt{--time-start}/\texttt{-t} and | |
980 | \texttt{--time-end}/\texttt{T}} | |
981 | ||
982 | \begin{quote} | |
983 | \emph{This \texttt{btt} capability is still under construction, results are | |
984 | not always consistent at this point in time.} | |
985 | \end{quote} | |
986 | ||
987 | These options allow one to dictate to \texttt{btt} when to start and stop | |
988 | parsing of trace data in terms of seconds since the start of the run. The | |
989 | trace chosen will be between the start time (or 0.0 if not | |
b70a6642 | 990 | specified) and end time (or the end of the run) specified. |
512566d4 | 991 | |
fc16a815 AB |
992 | \subsection{\label{sec:o-u}\texttt{--unplug-hist}/\texttt{-u}} |
993 | ||
994 | This option instructs \texttt{btt} to generate a data file containing | |
995 | histogram information for \emph{unplug} traces on a per device | |
996 | basis. It shows how many times an unplug was hit with a specified | |
997 | number of IOs released. There are 21 output values into the file, as | |
998 | follows: | |
999 | ||
1000 | \medskip | |
1001 | \begin{tabular}{ll} | |
1002 | \textbf{X value} & \textbf{Representing Counts} \\\hline | |
1003 | 0 & 0\dots\/4 \\ | |
1004 | 1 & 5\dots\/9 \\ | |
1005 | 2 & 10\dots\/14 \\ | |
1006 | \dots & \dots\dots\\ | |
1007 | 19 & 95\dots\/99 \\ | |
1008 | 20 & 100+ \\ | |
1009 | \end{tabular} | |
1010 | ||
1011 | \medskip | |
1012 | The file name(s) generated use the text string passed as an argument for | |
1013 | the prefix, followed by the device identifier in \texttt{major,minor} | |
1014 | form, with a \texttt{.dat} extension (as an example, with \texttt{-u | |
1015 | up\_hist} specified on the command line: \texttt{up\_hist\_008,032.dat}. | |
1016 | ||
512566d4 AB |
1017 | \subsection{\label{sec:o-V}\texttt{--version}/\texttt{-V}} |
1018 | ||
1019 | Prints out the \texttt{btt} version, and exits. | |
1020 | ||
1021 | \subsection{\label{sec:o-v}\texttt{--verbose}/\texttt{-v}} | |
1022 | ||
1023 | While \texttt{btt} is processing data, it will put out periodic (1-second | |
1024 | granularity) values describing the progress it is making through the | |
1025 | input trace stream. The value describes how many traces have been | |
1026 | processed. At the end of the run, the overall number of traces, trace | |
1027 | rate (number of thousands of traces per second), and the real time for | |
1028 | trace processing and output are displayed. Example (note: the interim | |
1029 | trace counts are put out with carriage returns, hence, they overwrite | |
1030 | each time): | |
1031 | ||
1032 | \begin{verbatim} | |
1033 | # btt -i bp.bin -o btt -v | |
1034 | Sending range data to bttX.dat | |
1035 | Sending stats data to bttX.avg | |
1036 | 287857 t | |
1037 | 1414173 t | |
1038 | 1691581 t | |
1039 | ... | |
1040 | 4581291 traces @ 279.7 Ktps | |
1041 | 16.379036+0.000005=16.379041 | |
1042 | \end{verbatim} | |
1043 | ||
f028c958 AB |
1044 | \subsection{\label{sec:o-X}\texttt{--easy-parse-avgs}/\texttt{-X}} |
1045 | ||
1046 | \emph{Some} of the data produced by default can also be shipped | |
1047 | simultaneously to another file in an easy to parse form. When | |
1048 | the \texttt{-o} option is selected (thus producing a file with a | |
1049 | \texttt{.avg} exentsion), \emph{and} the \texttt{-X} flag is present, | |
1050 | then \texttt{btt} will generate this file. | |
1051 | ||
1052 | The format is space-delimited values starting with a 3-character | |
1053 | \emph{record} indicator, then the device information (either major,minor | |
1054 | or the device name when \texttt{-M} is specified), and then a number of | |
1055 | fields representing data values. The following table shows the record | |
1056 | identifiers and the fields provided: | |
1057 | ||
1058 | \bigskip | |
1059 | \begin{tabular}{|l|l|}\hline | |
1060 | \textbf{Record} & \textbf{Description}\\\hline | |
1061 | \texttt{DMI} & Device Merge Information:\\ | |
1062 | & \#Q \#D Ratio BLKmin BLKavg BLKmax Total\\\hline | |
1063 | \texttt{QSK} & Device Q2Q Seek Information:\\ | |
1064 | & NSEEKS MEAN MEDIAN MODE N-MODE mode\ldots\\\hline | |
1065 | \texttt{DSK} & Device D2D Seek Information:\\ | |
1066 | & NSEEKS MEAN MEDIAN MODE N-MODE mode\ldots\\\hline | |
1067 | \texttt{PLG} & Plug Information:\\ | |
1068 | & \#Plugs \#TimerUnplugs \%TimeQPlugged\\\hline | |
1069 | \texttt{UPG} & Unplug Information:\\ | |
1070 | & IOsPerUnplug IOsPerUnplugTimeout\\\hline | |
1071 | \texttt{ARQ} & Active Requests at Q Information:\\ | |
354db430 AB |
1072 | & AvgReqs@Q\\\hline\hline |
1073 | \texttt{Q2Q} & Queue-to-Queue times:\\ | |
1074 | \texttt{Q2G} & Queue-to-GetRequest times:\\ | |
1075 | \texttt{S2G} & Sleep-to-GetRequest times:\\ | |
1076 | \texttt{G2I} & GetRequest-to-Insert times:\\ | |
1077 | \texttt{Q2M} & Queue-to-Merge times:\\ | |
1078 | \texttt{I2D} & Insert-to-Issue times:\\ | |
1079 | \texttt{M2D} & Merge-to-Issue times:\\ | |
1080 | \texttt{D2C} & Issue-to-Complete times:\\ | |
1081 | \texttt{Q2C} & Queue-to-Complete times:\\ | |
1082 | & MIN AVG MAX N\\\hline | |
f028c958 AB |
1083 | \end{tabular} |
1084 | ||
1085 | \bigskip | |
1086 | A sample output file would look like: | |
1087 | ||
1088 | \begin{verbatim} | |
354db430 AB |
1089 | Q2Q 0.000000001 0.003511356 9.700000000 309906 |
1090 | Q2G 0.000000001 0.774586535 805.300000000 106732 | |
1091 | S2G 0.000000001 0.072525952 0.370000000 578 | |
1092 | G2I 0.000000001 0.000001125 0.010000000 106732 | |
1093 | Q2M 0.000000001 0.730763626 751.820000000 204040 | |
1094 | I2D 0.000000001 1.270720538 612.880000000 106948 | |
1095 | M2D 0.000000001 0.992355230 428.930000000 203114 | |
1096 | D2C 0.000000001 0.008681311 137.020000000 307343 | |
1097 | Q2C 0.000000001 1.304370794 805.660000000 308921 | |
1098 | DMI 8,16 309907 106729 2.903681286 8 182 1024 19504768 | |
1099 | QSK 8,16 309907 167200.935561314 0 0 235708 | |
f028c958 | 1100 | DSK 8,16 106729 433247.436563633 0 0 33974 |
354db430 | 1101 | PLG 8,16 40824 382 0.008881420 |
f028c958 | 1102 | UPG 8,16 1.993361748 1.866492147 |
354db430 | 1103 | ARQ 8,16 12.938165321 |
f028c958 AB |
1104 | \end{verbatim} |
1105 | ||
e47ada10 AB |
1106 | \subsection{\label{sec:o-z}\texttt{--q2d-latencies}/\texttt{-l}} |
1107 | ||
1108 | This option instructs \texttt{btt} to generate the Q2D latency file | |
1109 | discussed in section~\ref{sec:lat-q2d}. | |
1110 | ||
ef144239 AB |
1111 | \newpage\section{\label{sec:bno_plot}bno\_plot.py} |
1112 | ||
1113 | Included with the distribution is a simple 3D plotting utility based | |
1114 | upon the block numbers output when \texttt{-B} is specified (see | |
1115 | section~\ref{sec:o-B} for more details about the \texttt{-B option}). The | |
1116 | display will display \emph{each} IO generated, with the time (seconds) | |
1117 | along the X-axis, the block number (start) along the Y-axis and the | |
1118 | number of blocks transferred in the IO represented along the Z-axis. | |
1119 | ||
1120 | The script requires Python\footnote{\texttt{www.python.org}} and | |
1121 | gnuplot\footnote{\texttt{www.gnuplot.info}}, and will enter interactive | |
1122 | mode after the image is produced. In this interactive mode one can enter | |
1123 | gnuplot commands at the \texttt{'gnuplot>'} prompt, and/or can change | |
1124 | the viewpoint within the 3D image by \emph{left-click-hold} and moving | |
1125 | the mouse. A sample screen shot can be seen in figure~\ref{fig:bno_plot} on | |
1126 | page~\pageref{fig:bno_plot}. | |
1127 | ||
1128 | \subsection*{\texttt{bno\_plot.py} Command Line Options} | |
1129 | ||
1130 | \begin{quotation} | |
1131 | \begin{verbatim} | |
1132 | ||
1133 | $ bno_plot.py --help | |
1134 | ||
1135 | bno_plot.py | |
1136 | [ -h | --help ] | |
1137 | [ -K | --keys-below ] | |
1138 | [ -v | --verbose ] | |
1139 | [ <file...> ] | |
1140 | ||
1141 | Utilizes gnuplot to generate a 3D plot of the block number | |
1142 | output from btt. If no <files> are specified, it will | |
1143 | utilize all files generated after btt was run with -B | |
1144 | blknos (meaning: all files of the form blknos*[rw].dat). | |
1145 | ||
1146 | The -K option forces bno_plot.py to put the keys below the | |
1147 | graph, typically all keys for input files are put in the | |
1148 | upper right corner of the graph. If the number of devices | |
1149 | exceed 10, then bno_plot.py will automatically push the | |
1150 | keys under the graph. | |
1151 | ||
1152 | To exit the plotter, enter 'quit' or ^D at the 'gnuplot> ' | |
1153 | prompt. | |
1154 | \end{verbatim} | |
1155 | \end{quotation} | |
1156 | ||
1157 | \begin{figure}[b] | |
1158 | \leavevmode\centering | |
1159 | \epsfig{file=bno_plot.eps,width=5.5in} | |
1160 | \caption{\label{fig:bno_plot}Sample \texttt{bno\_plot.py} Screen Shot} | |
1161 | \end{figure} | |
1162 | ||
1163 | \clearpage | |
1164 | \newpage\section{\label{sec:appendix}Sample \texttt{btt} | |
512566d4 | 1165 | Output} |
512566d4 AB |
1166 | Here is a complete output file from a btt run, illustrating a lot of the |
1167 | capabilities of btt. | |
4c48f14e | 1168 | \input{sample-btt-output.tex} |
ef144239 | 1169 | |
512566d4 | 1170 | \end{document} |
ef144239 | 1171 | \subsection{\label{sec:o-B}\texttt{--dump-blocknos}/\texttt{-B}} |