[PATCH] blktrace.tex: add description of each possible action
[blktrace.git] / doc / blktrace.tex
CommitLineData
ff8a07c9
JA
1\documentclass{article}
2
3%
4% Copyright (C) 2005 Alan D. Brunelle <Alan.Brunelle@hp.com>
5%
6% This program is free software; you can redistribute it and/or modify
7% it under the terms of the GNU General Public License as published by
8% the Free Software Foundation; either version 2 of the License, or
9% (at your option) any later version.
10%
11% This program is distributed in the hope that it will be useful,
12% but WITHOUT ANY WARRANTY; without even the implied warranty of
13% MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the
14% GNU General Public License for more details.
15%
16% You should have received a copy of the GNU General Public License
17% along with this program; if not, write to the Free Software
18% Foundation, Inc., 59 Temple Place, Suite 330, Boston, MA 02111-1307 USA
19%
20
21\title{blktrace User Guide}
22\author{blktrace: Jens Axboe (axboe@suse.de)\\
23 User Guide: Alan D. Brunelle (Alan.Brunelle@hp.com)}
24\date{4 October 2005}
25
26\begin{document}
27\maketitle
28%---------------------
29\section{\label{sec:intro}Introduction}
30
31blktrace is a block layer IO tracing mechanism which provides detailed
32information about request queue operations up to user space. There are
33three major components that are provided:
34
35\begin{description}
36 \item[Kernel patch] A patch to the Linux kernel which includes the
37 kernel event logging interfaces, and patches to areas within the block
38 layer to emit event traces.
39
40 \item[blktrace] A utility which transfers event traces from the kernel
41 into either long-term on-disk storage, or provides direct formatted
42 output (via blkparse).
43
44 \item[blkparse] A utility which formats events stored in files, or when
45 run in \emph{live} mode directly outputs data collected by blktrace.
46\end{description}
47
ff8a07c9
JA
48\subsection{blktrace Download Area}
49
50The blktrace and blkparse utilities and associated kernel patch are provided
51as part of the following git repository:
52
53rsync://rsync.kernel.org/pub/scm/linux/kernel/git/axboe/blktrace.git
54
55%--------------------------
56\newpage\section{\label{sec:quick-start}Quick Start Guide}
57
58The following sections outline some quick steps towards utilizing
59blktrace. Some of the specific instructions below may need to be tailored
60to your environment.
61
62\subsection{\label{sec:get-blktrace}Retrieving blktrace}
63
64As noted above, the kernel patch along with the blktrace and blkparse utilities are stored in a git repository. One simple way to get going would be:
65
66\begin{verbatim}
67% git clone rsync://rsync.kernel.org/pub/scm/linux/kernel/git/axboe/blktrace.git bt
68% cd bt
69% git-read-tree -m HEAD && git-checkout-cache -q -f -u -a
70\end{verbatim}
71
72\subsection{\label{sec:patching}Patching and configuring the Linux kernel}
73
74A patch for a \emph{specific Linux kernel} is provided in bt/kernel (where
75\emph{bt} is the name of the directory from the above git sequence). The
76detailed actual patching instructions for a Linux kernel is outside the
77scope of this document, but the following may be used as a sample template.
78
79As an example, bt/kernel contains blk-trace-2.6.14-rc1-git-G2, download
80linux-2.6.13.tar.bz2 and patch-2.6.14-rc1.bz2
81
82\begin{verbatim}
83% tar xjf linux-2.6.13.tar.bz2
84% mv linux-2.6.13 linux-2.6.14-rc1
85% cd linux-2.6.14-rc1
86% bunzip2 -c ../patch-2.6.14-rc1.bz2 | patch -p1
87\end{verbatim}
88
89At this point you may (optionally) remove linux-2.6.13.tar.bz2 and
90patch-2.6.14-rc1.bz2.
91
92At this point you should configure the Linux kernel for your specific
93system -- again, outside the scope of this document -- and then enable
94\emph{Support for tracing block io actions.} To do this, run
95
96\begin{verbatim}
97% make menuconfig or make xconfig, or edit .config, or ...
98\end{verbatim}
99
100and navigate through \emph{Device Drivers} and \emph{Block devices}
101and then down to \emph{Support for tracing block io actions} and hit Y.
102
103Install the new kernel (and modules\ldots) and reboot.
104
105\subsection{\label{sec:mount}Mounting the RelayFS file system}
106
107blktrace utilizes files under the Relay file system, and thus must have
108the mount point set up -- mounted on the directory /relay. To do this
109one may do either of the following:
110
111\begin{enumerate}
112 \item Manually mount after each boot:
113\begin{verbatim}
114% mount -t relayfs relayfs /relay
115\end{verbatim}
116
117 \item Add an entry into /etc/fstab, and have it done automatically at
118 each boot\footnote{Note: after adding the entry to /etc/fstab, you
119 could then mount the directory this time only by doing: \% mount /relay}:
120\begin{verbatim}
121relay /relay relayfs default 0 0
122\end{verbatim}
123\end{enumerate}
124
125\subsection{\label{sec:build}Build the tools}
126
127To build and install the tools, execute the following sequence (as root):
128
129\begin{verbatim}
130% cd bt
131% make && make install
132\end{verbatim}
133
134\subsection{\label{sec:live-blktrace}blktrace -- live}
135
136Now to simply watch what is going on for a specific disk (to stop the
137trace, hit control-C):
138
139\begin{verbatim}
140% blktrace -d /dev/sda -o - | blkparse -i -
141 8,0 3 1 0.000000000 697 G W 223490 + 8 [kjournald]
142 8,0 3 2 0.000001829 697 P R [kjournald]
143 8,0 3 3 0.000002197 697 Q W 223490 + 8 [kjournald]
144 8,0 3 4 0.000005533 697 M W 223498 + 8 [kjournald]
145 8,0 3 5 0.000008607 697 M W 223506 + 8 [kjournald]
146 8,0 3 6 0.000011569 697 M W 223514 + 8 [kjournald]
147 8,0 3 7 0.000014407 697 M W 223522 + 8 [kjournald]
148 8,0 3 8 0.000017367 697 M W 223530 + 8 [kjournald]
149 8,0 3 9 0.000020161 697 M W 223538 + 8 [kjournald]
150 8,0 3 10 0.000024062 697 D W 223490 + 56 [kjournald]
151 8,0 1 11 0.009507758 0 C W 223490 + 56 [0]
152 8,0 1 12 0.009538995 697 G W 223546 + 8 [kjournald]
153 8,0 1 13 0.009540033 697 P R [kjournald]
154 8,0 1 14 0.009540313 697 Q W 223546 + 8 [kjournald]
155 8,0 1 15 0.009542980 697 D W 223546 + 8 [kjournald]
156 8,0 1 16 0.013542170 0 C W 223546 + 8 [0]
157...
158^C
159...
160CPU1 (8,0):
161 Reads Queued: 0, 0KiB Writes Queued: 7, 128KiB
162 Read Dispatches: 0, 0KiB Write Dispatches: 7, 128KiB
163 Reads Completed: 0, 0KiB Writes Completed: 11, 168KiB
164 Read Merges: 0 Write Merges: 25
165 IO unplugs: 0 Timer unplugs: 0
166...
167CPU3 (8,0):
168 Reads Queued: 0, 0KiB Writes Queued: 1, 28KiB
169 Read Dispatches: 0, 0KiB Write Dispatches: 1, 28KiB
170 Reads Completed: 0, 0KiB Writes Completed: 0, 0KiB
171 Read Merges: 0 Write Merges: 6
172 IO unplugs: 0 Timer unplugs: 0
173
174Total (8,0):
175 Reads Queued: 0, 0KiB Writes Queued: 11, 168KiB
176 Read Dispatches: 0, 0KiB Write Dispatches: 11, 168KiB
177 Reads Completed: 0, 0KiB Writes Completed: 11, 168KiB
178 Read Merges: 0 Write Merges: 31
179 IO unplugs: 0 Timer unplugs: 3
180
181Events (8,0): 89 entries, 0 skips
182\end{verbatim}
183
184\subsection{\label{sec:blktrace-post}blktrace -- post-processing}
185
186Another way to run blktrace is to have blktrace save data away for later
187formatting by blkparse. This would be useful if you want to get
188measurements while running specific loads.
189
190To do this, one would specify the device (or devices) to be watched. Then
191go run you test cases. Stop the trace, and at your leisure utilize
192blkparse to see the results.
193
194In this example, devices /dev/sdaa, /dev/sdc and /dev/sdo are used in an
195LVM volume called adb3/vol.
196
197\begin{verbatim}
198% blktrace /dev/sdaa /dev/sdc /dev/sdo &
199[1] 9713
200%
201% mkfs -t ext3 /dev/adb3/vol
202mke2fs 1.35 (28-Feb-2004)
203Filesystem label=
204OS type: Linux
205Block size=4096 (log=2)
206Fragment size=4096 (log=2)
20716793600 inodes, 33555456 blocks
2081677772 blocks (5.00%) reserved for the super user
209First data block=0
210Maximum filesystem blocks=4294967296
2111025 block groups
21232768 blocks per group, 32768 fragments per group
21316384 inodes per group
214Superblock backups stored on blocks:
215 32768, 98304, 163840, 229376, 294912, 819200, 884736, 1605632, 2654208,
216 4096000, 7962624, 11239424, 20480000, 23887872
217
218Writing inode tables: done
219Creating journal (8192 blocks): done
220Writing superblocks and filesystem accounting information: done
221
222This filesystem will be automatically checked every 27 mounts or
223180 days, whichever comes first. Use tune2fs -c or -i to override.
224%
225% kill -15 9713
226\end{verbatim}
227
228Then you could process the events later:
229
230\begin{verbatim}
231%
232% blkparse sdaa sdc sdo > events
233% less events
234 8,32 1 1 0.000000000 9728 G R 384 + 32 [mkfs.ext3]
235 8,32 1 2 0.000001959 9728 P R [mkfs.ext3]
236 8,32 1 3 0.000002446 9728 Q R 384 + 32 [mkfs.ext3]
237 8,32 1 4 0.000005110 9728 D R 384 + 32 [mkfs.ext3]
238 8,32 3 5 0.000200570 0 C R 384 + 32 [0]
239 8,224 3 1 0.021658989 9728 G R 384 + 32 [mkfs.ext3]
240...
241 65,160 3 163392 41.117070504 0 C W 87469088 + 1376 [0]
242 8,32 3 163374 41.122683668 0 C W 88168160 + 1376 [0]
243 65,160 3 163393 41.129952433 0 C W 87905984 + 1376 [0]
244 65,160 3 163394 41.130049431 0 D W 89129344 + 1376 [swapper]
245 65,160 3 163395 41.130067135 0 D W 89216704 + 1376 [swapper]
246 65,160 3 163396 41.130083785 0 D W 89304096 + 1376 [swapper]
247 65,160 3 163397 41.130099455 0 D W 89391488 + 1376 [swapper]
248 65,160 3 163398 41.130114732 0 D W 89478848 + 1376 [swapper]
249 65,160 3 163399 41.130128885 0 D W 89481536 + 64 [swapper]
250 8,32 3 163375 41.134758196 0 C W 86333152 + 1376 [0]
251 65,160 3 163400 41.142229726 0 C W 89129344 + 1376 [0]
252 65,160 3 163401 41.144952314 0 C W 89481536 + 64 [0]
253 8,32 3 163376 41.147441930 0 C W 88342912 + 1376 [0]
254 65,160 3 163402 41.155869604 0 C W 89478848 + 1376 [0]
255 8,32 3 163377 41.159466082 0 C W 86245760 + 1376 [0]
256 65,160 3 163403 41.166944976 0 C W 89216704 + 1376 [0]
257 65,160 3 163404 41.178968252 0 C W 89304096 + 1376 [0]
258 65,160 3 163405 41.191860173 0 C W 89391488 + 1376 [0]
259...
260Events (sdo): 0 entries, 0 skips
261
262CPU0 (65,160):
263 Reads Queued: 0, 0KiB Writes Queued: 9, 5,520KiB
264 Read Dispatches: 0, 0KiB Write Dispatches: 0, 0KiB
265 Reads Completed: 0, 0KiB Writes Completed: 0, 0KiB
266 Read Merges: 0 Write Merges: 336
267 IO unplugs: 0 Timer unplugs: 0
268CPU1 (65,160):
269 Reads Queued: 2,411, 38,576KiB Writes Queued: 769, 425,408KiB
270 Read Dispatches: 2,407, 38,512KiB Write Dispatches: 118, 61,680KiB
271 Reads Completed: 0, 0KiB Writes Completed: 0, 0KiB
272 Read Merges: 0 Write Merges: 25,819
273 IO unplugs: 0 Timer unplugs: 4
274CPU2 (65,160):
275 Reads Queued: 2, 32KiB Writes Queued: 18, 10,528KiB
276 Read Dispatches: 2, 32KiB Write Dispatches: 3, 1,344KiB
277 Reads Completed: 0, 0KiB Writes Completed: 0, 0KiB
278 Read Merges: 0 Write Merges: 640
279 IO unplugs: 0 Timer unplugs: 0
280CPU3 (65,160):
281 Reads Queued: 20,572, 329,152KiB Writes Queued: 594, 279,712KiB
282 Read Dispatches: 20,576, 329,216KiB Write Dispatches: 1,474, 740,720KiB
283 Reads Completed: 22,985, 367,760KiB Writes Completed: 1,390, 721,168KiB
284 Read Merges: 0 Write Merges: 16,888
285 IO unplugs: 0 Timer unplugs: 0
286
287Total (65,160):
288 Reads Queued: 22,985, 367,760KiB Writes Queued: 1,390, 721,168KiB
289 Read Dispatches: 22,985, 367,760KiB Write Dispatches: 1,595, 803,744KiB
290 Reads Completed: 22,985, 367,760KiB Writes Completed: 1,390, 721,168KiB
291 Read Merges: 0 Write Merges: 43,683
292 IO unplugs: 0 Timer unplugs: 4
293...
294\end{verbatim}
295
296%----------------------------
297\newpage\section{\label{sec:blktrace-ug}blktrace User Guide}
298
299The \emph{blktrace} utility extracts event traces from the kernel (via
300the relay file system). Some background details concerning the run-time
301behaviour of blktrace will help to understand some of the more arcane
302command line options:
303
304\begin{itemize}
305 \item blktrace receives data from the kernel in buffers passed up
306 through the Relay file system (RelayFS). Each device being traced has
307 a file created in the mounted directory for the RelayFS, which defaults
308 to \emph{/relay} -- this can be overridden with the \emph{-r} command
309 line argument.
310
311 \item blktrace defaults to collecting \emph{all} events that can be
312 traced. To limit the events being captured, you can specify one or
313 more filter masks via the \emph{-a} option.
314
315 Alternatively, one may specify the entire mask utilizing a hexadecimal
316 value that is version-specific. (Requires understanding of the internal
317 representation of the filter mask.)
318
319 \item As noted above, the events are passed up via a series of buffers
320 stored into RelayFS files. The size and number of buffers can be
321 specified via the \emph{-b} and \emph{-n} arguments respectively.
322
323 \item blktrace stores the extracted data into files stored in the
324 \emph{local} directory. The format of the file names is (by default)
325 \emph{device}.blktrace.\emph{cpu}, where \emph{device} is the base
326 device name (e.g, if we are tracing /dev/sda, the base device name would
327 be \emph{sda}); and \emph{cpu} identifies a CPU for the event stream.
328
329 The \emph{device} portion of the event file name can be changed via
330 the \emph{-o} option.
331
332 \item blktrace may also be run concurrently with blkparse to produce
333 \emph{live} output -- to do this specify \emph{-o -} for blktrace.
334
335 \item The default behaviour for blktrace is to run forever until explicitly killed by the user (via a control-C, or \emph{kill} utility invocation). There are two ways to modify this:
336
337 \begin{enumerate}
338 \item You may utilize the blktrace utility itself to \emph{kill}
339 a running trace -- via the \emph{-k} option.
340
341 \item You can specify a run-time duration for blktrace via the
342 \emph{-w} option -- then blktrace will run for the specified number
343 of seconds, and then halt.
344 \end{enumerate}
345\end{itemize}
346
347\subsection{\label{sec:blktrace-args}Command line arguments}
348\begin{tabular}{|l|l|l|}\hline
349Short & Long & Description \\ \hline\hline
350-A \emph{hex-mask} & --set-mask=\emph{hex-mask} & Set filter mask to \emph{hex-mask} \\ \hline
351-a \emph{mask} & --act-mask=\emph{mask} & Add \emph{mask} to current filter (see below for masks) \\ \hline
352-b \emph{size} & --buffer-size=\emph{size} & Specifies buffer size for event extraction (scaled by $2^{10}$) \\ \hline
353-d \emph{dev} & --dev=\emph{dev} & Adds \emph{dev} as a device to trace \\ \hline
354-k & --kill & Kill on-going trace \\ \hline
355-n \emph{num-sub} & --num-sub=\emph{num-sub} & Specifies number of buffers to use \\ \hline
356-o \emph{file} & --output=\emph{file} & Prepend \emph{file} to output file name(s) \\ \hline
357-r \emph{rel-path} & --relay=\emph{rel-path} & Specifies RelayFS mount point \\ \hline
358-v & --version & Outputs version \\ \hline
359-w \emph{seconds} & --stopwatch=\emph{seconds} & Sets run time to the number of seconds specified \\ \hline
360\end{tabular}
361
362\subsubsection{\label{sec:filter-mask}Filter Masks}
363The following masks may be passed with the \emph{-a} command line
364option, multiple filters may be combined via multiple \emph{-a} command
365line options.\smallskip
366
367\begin{tabular}{|l|l|}\hline
368barrier & \emph{barrier} attribute \\ \hline
369complete & \emph{completed} by driver \\ \hline
370fs & \emph{FS} requests \\ \hline
371issue & \emph{issued} to driver \\ \hline
372pc & \emph{packet command} events \\ \hline
373queue & \emph{queue} operations \\ \hline
374read & \emph{read} traces \\ \hline
375requeue & \emph{requeue} operations \\ \hline
376sync & \emph{synchronous} attribute \\ \hline
377write & \emph{write} traces \\ \hline
378\end{tabular}
379
e8ae3d09
JA
380\subsubsection{\label{sec:request-types}Request types}
381blktrace disguingishes between two types of block layer requests,
382file system and scsi commands. The former are dubbed \emph{fs}
383requests, the latter \emph{pc} requests. File system requests are
384normal read/write operations, ie any type of read or write from a
385specific disk location at a given size. These requests typically
386originate from a user process, but they may also be initiated by
387the vm flushing dirty data to disk or the file system syncing
388a super or journal block to disk. \emph{pc} requests are SCSI
389commands. blktrace sends the command data block as a payload
390so that blkparse can decode it.
391
ff8a07c9
JA
392%----------------------------
393\newpage\section{\label{sec:blkparse-ug}blkparse User Guide}
394
395The \emph{blkparse} utility will attempt to combine streams of events
396for various devices on various CPUs, and produce a formatted output of
397the event information. As with blktrace, some details concerning blkparse
398will help in understanding the command line options presented below.
399
400\begin{itemize}
401 \item By default, blkparse expects to run in a post-processing mode
402 -- one where the trace events have been saved by a previous run
403 of blktrace, and blkparse is combining event streams and dumping
404 formatted data.
405
406 blkparse \emph{may} be run in a \emph{live} manner concurrently with
407 blktrace by specifying \emph{-i -} to blkparse, and combining it with
408 the live option for blktrace. An example would be:
409
410 \begin{verbatim}
411 % blktrace -d /dev/sda -o - | blkparse -i -
412 \end{verbatim}
413
414 \item You can set how many blkparse batches event reads via the
415 \emph{-b} option, the default is to handle events in batches of 512.
416
417 \item If you have saved event traces in blktrace with different output
418 names (via the \emph{-o} option to blktrace), you must specify the
419 same \emph{input} name via the \emph{-i} option.
420
421 \item The format of the output data can be controlled via the \emph{-f}
422 or \emph{-F} options -- see section~\ref{sec:blkparse-format} for details.
423
424 By default, blkparse sends formatted data to standard output. This
425 may be changed via the \emph{-o} option.
426
427\end{itemize}
428
429\newpage\subsection{\label{sec:blkparse-args}Command line arguments}
430\begin{tabular}{|l|l|l|}\hline
431Short & Long & Description \\ \hline\hline
432-b \emph{batch} & --batch={batch} & Standard input read batching \\ \hline
433
434-i \emph{file} & --input=\emph{file} & Specifies base name for input files -- default is \emph{device}.blktrace.\emph{cpu}. \\
435 & & As noted above, specifying \emph{-i -} runs in \emph{live} mode with blktrace \\
436 & & (reading data from standard in). \\ \hline
437
438-F \emph{typ,fmt} & --format=\emph{typ,fmt} & Sets output format \\
439-f \emph{fmt} & --format-spec=\emph{fmt} & (See section~\ref{sec:blkparse-format} for details.) \\
440 & & \\
441 & & The -f form specifies a format for all events \\
442 & & \\
443 & & The -F form allows one to specify a format for a specific \\
444 & & event type. The single-character \emph{typ} field is one of the \\
445 & & action specifiers in section~\ref{sec:act-table} \\ \hline
446
447
448-m & --missing & Print missing entries\\ \hline
449
450-n & --hash-by-name & Hash processes by name, not by PID\\ \hline
451
452-o \emph{file} & --output=\emph{file} & Output file \\ \hline
453
454-q & --quiet & Quite mode \\ \hline
455
456-s & --per-program-stats & Displays data sorted by program \\ \hline
457
458-t & --track-ios & Display time deltas per IO \\ \hline
459
460-w \emph{span} & --stopwatch=\emph{span} & Display traces for the \emph{span} specified -- where span can be: \\
461 & & \emph{end-time} -- Display traces from time 0 through \emph{end-time} (in ns) \\
462 & & or \\
463 & & \emph{start:end-time} -- Display traces from time \emph{start} \\
464 & & through {end-time} (in ns). \\ \hline
465
466-v & --version & Display version \\ \hline
467
468\end{tabular}
469
470\newpage
208660b1
JA
471\subsection{\label{sec:blkparse-actions}Trace actions}
472
473\begin{description}
474 \item[C -- complete] A previously issued request has been completed.
475 The output will detail the sector and size of that request, as well
476 as the success or failure of it.
477
478 \item[D -- issued] A request that previously resided on the block layer
479 queue or in the io scheduler has been sent to the driver.
480
481 \item[I -- inserted] A request is being sent to the io scheduler for
482 addition to the internal queue and later service by the driver. The
483 request is fully formed at this time.
484
485 \item[Q -- queued] This notes intent to queue io at the given location.
486 No real requests exists yet.
487
488 \item[W -- bounced] The data pages attached to this \emph{bio} are
489 not reachable by the hardware and must be bounced to a lower memory
490 location. This causes a big slowdown in io performance, since the data
491 must be copied to/from kernel buffers. Usually this can be fixed with
492 using better hardware - either a better io controller, or a platform
493 with an IOMMU.
494
495 \item[B -- back merge] A previously inserted request exists that ends
496 on the boundary of where this io begins, so the io scheduler can merge
497 them together.
498
499 \item[F -- front merge] Same as the back merge, except this io ends
500 where a previously inserted requests starts.
501
502 \item[M -- front or back merge] One of the above.
503
504 \item[G -- get request] To send any type of request to a block device,
505 a \emph{struct request} container must be allocated first.
506
507 \item[S -- sleep] No available request structures were available, so
508 the issuer has to wait for one to be freed.
509
510 \item[P -- plug] When io is queued to a previously empty block device
511 queue, Linux will plug the queue in anticipation of future ios being
512 added before this data is needed.
513
514 \item[U -- unplug] Some request data already queued in the device,
515 start sending requests to the driver. This may happen automatically
516 if a timeout period has passed (see next entry) or if a number of
517 requests have been added to the queue.
518
519 \item[T -- unplug due to timer] If nobody requests the io that was queued
520 after plugging the queue, Linux will automatically unplug it after a
521 defined period has passed.
522
523 \item[X -- split] On raid or device mapper setups, an incoming io may
524 straddle a device or internal zone and needs to be chopped up into
525 smaller pieces for service. This may indicate a performance problem due
526 to a bad setup of that raid/dm device, but may also just be part of
527 normal boundary conditions. dm is notably bad at this and will clone
528 lots of io.
529
530\end{description}
531
ff8a07c9
JA
532\subsection{\label{sec:blkparse-format}Output Description and Formatting}
533
534The output from blkparse can be tailored for specific use - in particular,
535to ease parsing of output, and/or limit output fields to those the user
536wants to see. The data for fields which can be output include:
537
538\smallskip
539\begin{tabular}{|l|l|}\hline
540Field & Description \\
541Specifier & \\ \hline\hline
542\emph{a} & Action, a (small) string (1 or 2 characters) -- see table below for more details \\ \hline
543\emph{c} & CPU id \\ \hline
544\emph{C} & Command \\ \hline
545\emph{d} & RWBS field, a (small) string (1-3 characters) -- see section below for more details \\ \hline
546\emph{D} & 7-character string containing the major and minor numbers of
547the event's device \\
548 & (separated by a comma). \\ \hline
549\emph{e} & Error value \\ \hline
550\emph{m} & Minor number of event's device. \\ \hline
551\emph{M} & Major number of event's device. \\ \hline
552\emph{n} & Number of blocks \\ \hline
553\emph{N} & Number of bytes \\ \hline
554\emph{p} & Process ID \\ \hline
555\emph{P} & Display packet data -- series of hexadecimal values\\ \hline
556\emph{s} & Sequence numbers \\ \hline
557\emph{S} & Sector number \\ \hline
558\emph{t} & Time stamp (nanoseconds) \\ \hline
559\emph{T} & Time stamp (seconds) \\ \hline
560\emph{u} & Elapsed value in microseconds (\emph{-t} command line option) \\ \hline
561\emph{U} & Payload unsigned integer \\ \hline
562\end{tabular}
563
564Note that the user can optionally specify field display width, and
565optionally a left-aligned specifier. These precede field specifiers,
566with a '\%' character, followed by the optional left-alignment specifer
567(-) followed by the width (a decimal number) and then the field.
568
569Thus, to specify the command in a 12-character field that is left aligned:
570
571\begin{verbatim}
572-f "%-12C"
573\end{verbatim}
574
575\newpage
576\subsubsection{\label{sec:act-table}Action Table}
577The following table shows the various actions which may be output.
578
579\begin{tabular}{|l|l|}\hline
580Act & Description \\ \hline\hline
581B & IO back merged with request on queue \\ \hline
582C & IO completion \\ \hline
583D & IO issued to driver \\ \hline
584F & IO front merged with request on queue \\ \hline
585G & Get request \\ \hline
586I & IO inserted onto request queue \\ \hline
587P & Plug request \\ \hline
588Q & IO handled by request queue code \\ \hline
589S & Sleep request \\ \hline
590T & Unplug due to timeout \\ \hline
591U & Unplug request \\ \hline
592W & IO bounced \\ \hline
593X & Split \\ \hline
594\end{tabular}
595
596\subsubsection{\label{sec:act-table}RWBS Description}
597This is a small string containing at least one character ('R' for read,
598'W' for write operation), and optionally either a 'B' (for barrier
599operations) or 'S' (for synchronous operations).
600
601\subsubsection{\label{sec:default-output}Default output}
602
603The standard \emph{header} (or initial fields displayed) include:
604
605\begin{verbatim}
606"%D %2c %8s %5T.%9t %5p %2a %3d "
607\end{verbatim}
608
609Breaking this down:
610
611\begin{description}
612 \item[\%D] Displays the event's device major/minor as: \%3d,\%-3d.
613 \item[\%2c] CPU ID (2-character field).
614 \item[\%8s] Sequence number
615 \item[\%5T.\%9t] 5-charcter field for the seconds portion of the
616 time stamp and a 9-character field for the nanoseconds in the time stamp.
617 \item[\%5p] 5-character field for the process ID.
618 \item[\%2a] 2-character field for one of the actions.
619 \item[\%3d] 3-character field for the RWBS data.
620\end{description}
621
622Seeing this in action:
623
624\begin{verbatim}
625 8,0 3 1 0.000000000 697 G W 223490 + 8 [kjournald]
626\end{verbatim}
627
628The header is the data in this line up to the 223490 (starting block).
629
630The default output for all event types includes this header.
631
632\paragraph{Default output per action}
633
634\begin{description}
635 \item[C -- complete] If a payload is present, this is presented between
636 parenthesis following the header, followed by the error value.
637
638 If no payload is present, the sector and number of blocks are presented
639 (with an intervening plus (+) character). If the \emph{-t} option
640 was specified, then the elapsed time is presented. In either case,
641 it is followed by the error value for the completion.
642
643 \item[D -- issued]
644 \item[I -- inserted]
645 \item[Q -- queued]
646 \item[W -- bounced] If a payload is present, the number of payload bytes
647 is output, followed by the payload in hexadecimal between parenthesis.
648
649 If no payload is present, the sector and number of blocks are presented
650 (with an intervening plus (+) character). If the \emph{-t} option was
651 specified, then the elapsed time is presented (in parenthesis). In
652 either case, it is followed by the command associated with the event
653 (surrounded by square brackets).
654
655 \item[B -- back merge]
656 \item[F -- front merge]
657 \item[G -- get request]
658 \item[M -- front or back merge]
659 \item[S -- sleep] The starting sector and number of blocks is output
660 (with an intervening plus (+) character), followed by the command
661 associated with the event (surrounded by square brackets).
662
663 \item[P -- plug] The command associated with the event (surrounded by
664 square brackets) is output.
665
666 \item[U -- unplug]
667 \item[T -- unplug due to timer] The command associated with the event
668 (surrounded by square brackets) is output, followed by the number of
669 requests outstanding.
670
671 \item[X -- split] The original starting sector followed by the new
672 sector (separated by a slash (/) is output, followed by the command
673 associated with the event (surrounded by square brackets).
674
675\end{description}
676
677%------------------------------
678\newpage
679\newpage\section*{\label{sec:blktrace-kg}Appendix: blktrace Kernel Guide}
680
681The blktrace facility provides an efficient event transfer mechanism which
682supplies block IO layer state transition data via the relay
683filesystem. This section provides some details as to the interfaces
684blktrace utilizes in the kernel to effect this. It is good background data
685to help understand some of the outputs and command-line options above.
686
687\subsection{blktrace.h Definitions}
688Files which include $<linux/blktrace.h>$ are supplied with the following
689definitions:
690
691\subsubsection{Trace Action Specifiers}
692\begin{tabular}{|l|l|}\hline
693 BLK\_TA\_QUEUE & (RQ) Command queued to request\_queue. \\
694 & (BIO) Command queued by elevator. \\ \hline
695 BLK\_TA\_BACKMERGE & Back merging elevator operation \\ \hline
696 BLK\_TA\_FRONTMERGE & Front merging elevator operation \\ \hline
697 BLK\_TA\_GETRQ & Free request retrieved. \\ \hline
698 BLK\_TA\_SLEEPRQ & No requests available, device unplugged. \\ \hline
699 BLK\_TA\_REQUEUE & Request requeued. \\ \hline
700 BLK\_TA\_ISSUE & Command set to driver for request\_queue. \\ \hline
701 BLK\_TA\_COMPLETE & Command completed by driver. \\ \hline
702 BLK\_TA\_PLUG & Device is plugged \\ \hline
703 BLK\_TA\_UNPLUG\_IO & Unplug device as IO is made available. \\ \hline
704 BLK\_TA\_UNPLUG\_TIMER & Unplug device after timer expired. \\ \hline
705 BLK\_TA\_INSERT & Insert request into queue. \\ \hline
706 BLK\_TA\_SPLIT & BIO split into 2 or more requests. \\ \hline
707 BLK\_TA\_BOUNCE & BIO was bounced \\ \hline
708\end{tabular}
709
710%..........................................
711\subsection{blktrace.h Routines}
712Files which include $<linux/blktrace.h>$ are supplied with the following
713kernel routine invocable interfaces:
714
715\begin{description}
716 \item[blk\_add\_trace\_rq(struct request\_queue *q, struct request\_queue
717 *rq, u32 what)]
718 Adds a trace event describing the state change of the passed in
719 request\_queue. The \emph{what} parameter describes the change in
720 the request\_queue state, and is one of the request queue action
721 specifiers -- BLK\_TA\_QUEUE, BLK\_TA\_REQUEUE, BLK\_TA\_ISSUE,
722 or BLK\_TA\_COMPLETE.
723
724 \item[blk\_add\_trace\_bio(struct request\_queue *q, struct bio *bio,
725 u32 what)]
726 Adds a trace event for the BIO passed in. The \emph{what} parameter
727 describes the action being performed on the BIO, and is one of
728 BLK\_TA\_BACKMERGE, BLK\_TA\_FRONTMERGE, or BLK\_TA\_QUEUE.
729
730 \item[blk\_add\_trace\_generic(struct request\_queue *q, struct bio *bio,
731 int rw, u32 what)]
732 Adds a \emph{generic} trace event -- not one of the request queue
733 or BIO traces. The \emph{what} parameter describes the action being
734 performed on the BIO (if bio is non-NULL), and is one of
735 BLK\_TA\_PLUG, BLK\_TA\_GETRQ or BLK\_TA\_SLEEPRQ.
736
737 \item[blk\_add\_trace\_pdu\_int(struct request\_queue *q, u32 what,
738 u32 pdu)]
739 Adds a trace with some payload data -- in this case, an unsigned
740 32-bit entity (the \emph{pdu} parameter). The \emph{what} parameter
741 describes the nature of the payload, and is one of
742 BLK\_TA\_UNPLUG\_IO or BLK\_TA\_UNPLUG\_TIMER.
743
744\end{description}
745\end{document}