1 \documentclass{article}
4 % Copyright (C) 2005, 2006 Alan D. Brunelle <Alan.Brunelle@hp.com>
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.
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.
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
21 \title{blktrace User Guide}
22 \author{blktrace: Jens Axboe (jens.axboe@oracle.com)\\
23 User Guide: Alan D. Brunelle (Alan.Brunelle@hp.com)}
28 %---------------------
29 \section{\label{sec:intro}Introduction}
31 blktrace is a block layer IO tracing mechanism which provides detailed
32 information about request queue operations up to user space. There are
33 three major components that are provided:
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. If you run a 2.6.17-rc1 or newer kernel,
39 you don't need to patch blktrace support as it is already included.
41 \item[blktrace] A utility which transfers event traces from the kernel
42 into either long-term on-disk storage, or provides direct formatted
43 output (via blkparse).
45 \item[blkparse] A utility which formats events stored in files, or when
46 run in \emph{live} mode directly outputs data collected by blktrace.
49 \subsection{blktrace Download Area}
51 The blktrace and blkparse utilities and associated kernel patch are provided
52 as part of the following git repository:
54 git://git.kernel.org/pub/scm/linux/kernel/git/axboe/blktrace.git bt
56 %--------------------------
57 \newpage\section{\label{sec:quick-start}Quick Start Guide}
59 The following sections outline some quick steps towards utilizing
60 blktrace. Some of the specific instructions below may need to be tailored
63 \subsection{\label{sec:get-blktrace}Retrieving blktrace}
65 As 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:
68 % git clone git://git.kernel.org/pub/scm/linux/kernel/git/axboe/blktrace.git bt
73 \subsection{\label{sec:patching}Patching and configuring the Linux kernel}
75 A patch for a \emph{specific Linux kernel} is provided in bt/kernel (where
76 \emph{bt} is the name of the directory from the above git sequence). The
77 detailed actual patching instructions for a Linux kernel is outside the
78 scope of this document, but the following may be used as a sample template.
79 Note that you may skip this step, if you kernel is at least 2.6.17-rc1.
81 As an example, bt/kernel contains blk-trace-2.6.14-rc1-git-G2, download
82 linux-2.6.13.tar.bz2 and patch-2.6.14-rc1.bz2
85 % tar xjf linux-2.6.13.tar.bz2
86 % mv linux-2.6.13 linux-2.6.14-rc1
88 % bunzip2 -c ../patch-2.6.14-rc1.bz2 | patch -p1
91 At this point you may (optionally) remove linux-2.6.13.tar.bz2 and
94 At this point you should configure the Linux kernel for your specific
95 system -- again, outside the scope of this document -- and then enable
96 \emph{Support for tracing block io actions.} To do this, run
99 % make menuconfig or make xconfig, or edit .config, or ...
102 and navigate through \emph{Device Drivers} and \emph{Block devices}
103 and then down to \emph{Support for tracing block io actions} and hit Y.
105 Install the new kernel (and modules\ldots) and reboot.
107 \subsection{\label{sec:mount}Mounting the debugfs file system}
109 blktrace utilizes files under the debug file system, and thus must have
110 the mount point set up -- mounted on the directory /sys/kernel/debug.
111 To do this one may do either of the following:
114 \item Manually mount after each boot:
116 % mount -t debugfs debugfs /sys/kernel/debug
119 \item Add an entry into /etc/fstab, and have it done automatically at
120 each boot\footnote{Note: after adding the entry to /etc/fstab, you
121 could then mount the directory this time only by doing: \% mount debug}:
123 debug /sys/kernel/debug debugfs default 0 0
127 \subsection{\label{sec:build}Build the tools}
129 To build and install the tools, execute the following sequence (as root):
133 % make && make install
136 \subsection{\label{sec:live-blktrace}blktrace -- live}
138 Now to simply watch what is going on for a specific disk (to stop the
139 trace, hit control-C):
142 % blktrace -d /dev/sda -o - | blkparse -i -
143 8,0 3 1 0.000000000 697 G W 223490 + 8 [kjournald]
144 8,0 3 2 0.000001829 697 P R [kjournald]
145 8,0 3 3 0.000002197 697 Q W 223490 + 8 [kjournald]
146 8,0 3 4 0.000005533 697 M W 223498 + 8 [kjournald]
147 8,0 3 5 0.000008607 697 M W 223506 + 8 [kjournald]
148 8,0 3 6 0.000011569 697 M W 223514 + 8 [kjournald]
149 8,0 3 7 0.000014407 697 M W 223522 + 8 [kjournald]
150 8,0 3 8 0.000017367 697 M W 223530 + 8 [kjournald]
151 8,0 3 9 0.000020161 697 M W 223538 + 8 [kjournald]
152 8,0 3 10 0.000024062 697 D W 223490 + 56 [kjournald]
153 8,0 1 11 0.009507758 0 C W 223490 + 56 [0]
154 8,0 1 12 0.009538995 697 G W 223546 + 8 [kjournald]
155 8,0 1 13 0.009540033 697 P R [kjournald]
156 8,0 1 14 0.009540313 697 Q W 223546 + 8 [kjournald]
157 8,0 1 15 0.009542980 697 D W 223546 + 8 [kjournald]
158 8,0 1 16 0.013542170 0 C W 223546 + 8 [0]
163 Reads Queued: 0, 0KiB Writes Queued: 7, 128KiB
164 Read Dispatches: 0, 0KiB Write Dispatches: 7, 128KiB
165 Reads Completed: 0, 0KiB Writes Completed: 11, 168KiB
166 Read Merges: 0 Write Merges: 25
167 IO unplugs: 0 Timer unplugs: 0
170 Reads Queued: 0, 0KiB Writes Queued: 1, 28KiB
171 Read Dispatches: 0, 0KiB Write Dispatches: 1, 28KiB
172 Reads Completed: 0, 0KiB Writes Completed: 0, 0KiB
173 Read Merges: 0 Write Merges: 6
174 IO unplugs: 0 Timer unplugs: 0
177 Reads Queued: 0, 0KiB Writes Queued: 11, 168KiB
178 Read Dispatches: 0, 0KiB Write Dispatches: 11, 168KiB
179 Reads Completed: 0, 0KiB Writes Completed: 11, 168KiB
180 Read Merges: 0 Write Merges: 31
181 IO unplugs: 0 Timer unplugs: 3
183 Events (8,0): 89 entries, 0 skips
186 A \emph{btrace} script is included in the distribution to ease live
187 tracing of devices. The above could also be accomplished by issuing:
193 By default, \emph{btrace} runs the trace in quiet mode so it will not
194 include statistics when you break the run. Add the \emph{-S} option to
195 get that dumped as well.
197 \subsection{\label{sec:pc-blktrace}blktrace -- SCSI commands}
199 The previous section showed typical file system io actions, but blktrace
200 can also show SCSI commands going in and out of the queue as submitted
201 by applications using the SCSI Generic (\emph{sg}) interface.
206 3,0 0 25 0.004884107 13528 G R 0 + 0 [inquiry]
207 3,0 0 26 0.004890361 13528 I R 56 (12 00 00 00 38 ..) [inquiry]
208 3,0 0 27 0.004891223 13528 P R [inquiry]
209 3,0 0 28 0.004893250 13528 D R 56 (12 00 00 00 38 ..) [inquiry]
210 3,0 0 29 0.005344910 0 C R (12 00 00 00 38 ..) [0]
213 Here we see a program issuing an INQUIRY command to the CDROM device.
214 The program requested a read of 56 bytes of data, the CDB is included
215 in parenthesis after the data length. The completion event shows shows
216 that the command completed successfully. Tracing SCSI commands can be
217 very useful for debugging problems with programs talking directly to the
218 device. An example of that would be \emph{cdrecord} burning.
220 \subsection{\label{sec:blktrace-post}blktrace -- post-processing}
222 Another way to run blktrace is to have blktrace save data away for later
223 formatting by blkparse. This would be useful if you want to get
224 measurements while running specific loads.
226 To do this, one would specify the device (or devices) to be watched. Then
227 go run you test cases. Stop the trace, and at your leisure utilize
228 blkparse to see the results.
230 In this example, devices /dev/sdaa, /dev/sdc and /dev/sdo are used in an
231 LVM volume called adb3/vol.
234 % blktrace /dev/sdaa /dev/sdc /dev/sdo &
237 % mkfs -t ext3 /dev/adb3/vol
238 mke2fs 1.35 (28-Feb-2004)
241 Block size=4096 (log=2)
242 Fragment size=4096 (log=2)
243 16793600 inodes, 33555456 blocks
244 1677772 blocks (5.00%) reserved for the super user
246 Maximum filesystem blocks=4294967296
248 32768 blocks per group, 32768 fragments per group
249 16384 inodes per group
250 Superblock backups stored on blocks:
251 32768, 98304, 163840, 229376, 294912, 819200, 884736, 1605632, 2654208,
252 4096000, 7962624, 11239424, 20480000, 23887872
254 Writing inode tables: done
255 Creating journal (8192 blocks): done
256 Writing superblocks and filesystem accounting information: done
258 This filesystem will be automatically checked every 27 mounts or
259 180 days, whichever comes first. Use tune2fs -c or -i to override.
264 Then you could process the events later:
268 % blkparse sdaa sdc sdo > events
270 8,32 1 1 0.000000000 9728 G R 384 + 32 [mkfs.ext3]
271 8,32 1 2 0.000001959 9728 P R [mkfs.ext3]
272 8,32 1 3 0.000002446 9728 Q R 384 + 32 [mkfs.ext3]
273 8,32 1 4 0.000005110 9728 D R 384 + 32 [mkfs.ext3]
274 8,32 3 5 0.000200570 0 C R 384 + 32 [0]
275 8,224 3 1 0.021658989 9728 G R 384 + 32 [mkfs.ext3]
277 65,160 3 163392 41.117070504 0 C W 87469088 + 1376 [0]
278 8,32 3 163374 41.122683668 0 C W 88168160 + 1376 [0]
279 65,160 3 163393 41.129952433 0 C W 87905984 + 1376 [0]
280 65,160 3 163394 41.130049431 0 D W 89129344 + 1376 [swapper]
281 65,160 3 163395 41.130067135 0 D W 89216704 + 1376 [swapper]
282 65,160 3 163396 41.130083785 0 D W 89304096 + 1376 [swapper]
283 65,160 3 163397 41.130099455 0 D W 89391488 + 1376 [swapper]
284 65,160 3 163398 41.130114732 0 D W 89478848 + 1376 [swapper]
285 65,160 3 163399 41.130128885 0 D W 89481536 + 64 [swapper]
286 8,32 3 163375 41.134758196 0 C W 86333152 + 1376 [0]
287 65,160 3 163400 41.142229726 0 C W 89129344 + 1376 [0]
288 65,160 3 163401 41.144952314 0 C W 89481536 + 64 [0]
289 8,32 3 163376 41.147441930 0 C W 88342912 + 1376 [0]
290 65,160 3 163402 41.155869604 0 C W 89478848 + 1376 [0]
291 8,32 3 163377 41.159466082 0 C W 86245760 + 1376 [0]
292 65,160 3 163403 41.166944976 0 C W 89216704 + 1376 [0]
293 65,160 3 163404 41.178968252 0 C W 89304096 + 1376 [0]
294 65,160 3 163405 41.191860173 0 C W 89391488 + 1376 [0]
296 Events (sdo): 0 entries, 0 skips
299 Reads Queued: 0, 0KiB Writes Queued: 9, 5,520KiB
300 Read Dispatches: 0, 0KiB Write Dispatches: 0, 0KiB
301 Reads Completed: 0, 0KiB Writes Completed: 0, 0KiB
302 Read Merges: 0 Write Merges: 336
303 IO unplugs: 0 Timer unplugs: 0
305 Reads Queued: 2,411, 38,576KiB Writes Queued: 769, 425,408KiB
306 Read Dispatches: 2,407, 38,512KiB Write Dispatches: 118, 61,680KiB
307 Reads Completed: 0, 0KiB Writes Completed: 0, 0KiB
308 Read Merges: 0 Write Merges: 25,819
309 IO unplugs: 0 Timer unplugs: 4
311 Reads Queued: 2, 32KiB Writes Queued: 18, 10,528KiB
312 Read Dispatches: 2, 32KiB Write Dispatches: 3, 1,344KiB
313 Reads Completed: 0, 0KiB Writes Completed: 0, 0KiB
314 Read Merges: 0 Write Merges: 640
315 IO unplugs: 0 Timer unplugs: 0
317 Reads Queued: 20,572, 329,152KiB Writes Queued: 594, 279,712KiB
318 Read Dispatches: 20,576, 329,216KiB Write Dispatches: 1,474, 740,720KiB
319 Reads Completed: 22,985, 367,760KiB Writes Completed: 1,390, 721,168KiB
320 Read Merges: 0 Write Merges: 16,888
321 IO unplugs: 0 Timer unplugs: 0
324 Reads Queued: 22,985, 367,760KiB Writes Queued: 1,390, 721,168KiB
325 Read Dispatches: 22,985, 367,760KiB Write Dispatches: 1,595, 803,744KiB
326 Reads Completed: 22,985, 367,760KiB Writes Completed: 1,390, 721,168KiB
327 Read Merges: 0 Write Merges: 43,683
328 IO unplugs: 0 Timer unplugs: 4
332 %----------------------------
333 \newpage\section{\label{sec:blktrace-ug}blktrace User Guide}
335 The \emph{blktrace} utility extracts event traces from the kernel (via
336 the relaying through the debug file system). Some background details
337 concerning the run-time behaviour of blktrace will help to understand some
338 of the more arcane command line options:
341 \item blktrace receives data from the kernel in buffers passed up
342 through the debug file system (relay). Each device being traced has
343 a file created in the mounted directory for the debugfs, which defaults
344 to \emph{/sys/kernel/debug} -- this can be overridden with the \emph{-r}
345 command line argument.
347 \item blktrace defaults to collecting \emph{all} events that can be
348 traced. To limit the events being captured, you can specify one or
349 more filter masks via the \emph{-a} option.
351 Alternatively, one may specify the entire mask utilizing a hexadecimal
352 value that is version-specific. (Requires understanding of the internal
353 representation of the filter mask.)
355 \item As noted above, the events are passed up via a series of buffers
356 stored into debugfs files. The size and number of buffers can be
357 specified via the \emph{-b} and \emph{-n} arguments respectively.
359 \item blktrace stores the extracted data into files stored in the
360 \emph{local} directory. The format of the file names is (by default)
361 \emph{device}.blktrace.\emph{cpu}, where \emph{device} is the base
362 device name (e.g, if we are tracing /dev/sda, the base device name would
363 be \emph{sda}); and \emph{cpu} identifies a CPU for the event stream.
365 The \emph{device} portion of the event file name can be changed via
366 the \emph{-o} option.
368 \item blktrace may also be run concurrently with blkparse to produce
369 \emph{live} output -- to do this specify \emph{-o -} for blktrace.
371 \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:
374 \item You may utilize the blktrace utility itself to \emph{kill}
375 a running trace -- via the \emph{-k} option.
377 \item You can specify a run-time duration for blktrace via the
378 \emph{-w} option -- then blktrace will run for the specified number
379 of seconds, and then halt.
383 \subsection{\label{sec:blktrace-args}Command line arguments}
384 \begin{tabular}{|l|l|l|}\hline
385 Short & Long & Description \\ \hline\hline
386 -A \emph{hex-mask} & --set-mask=\emph{hex-mask} & Set filter mask to \emph{hex-mask} \\ \hline
387 -a \emph{mask} & --act-mask=\emph{mask} & Add \emph{mask} to current filter (see below for masks) \\ \hline
388 -b \emph{size} & --buffer-size=\emph{size} & Specifies buffer size for event extraction (scaled by $2^{10}$) \\ \hline
389 -d \emph{dev} & --dev=\emph{dev} & Adds \emph{dev} as a device to trace \\ \hline
390 -k & --kill & Kill on-going trace \\ \hline
391 -n \emph{num-sub} & --num-sub=\emph{num-sub} & Specifies number of buffers to use \\ \hline
392 -o \emph{file} & --output=\emph{file} & Prepend \emph{file} to output file name(s) \\ \hline
393 -r \emph{rel-path} & --relay=\emph{rel-path} & Specifies debugfs mount point \\ \hline
394 -V & --version & Outputs version \\ \hline
395 -w \emph{seconds} & --stopwatch=\emph{seconds} & Sets run time to the number of seconds specified \\ \hline
396 -I \emph{devs file}& --input-devs=\emph{devs file}& Adds devices found in \emph{devs file} to list of devices to trace. \\
397 & & (One device per line.) \\ \hline
400 \subsubsection{\label{sec:filter-mask}Filter Masks}
401 The following masks may be passed with the \emph{-a} command line
402 option, multiple filters may be combined via multiple \emph{-a} command
403 line options.\smallskip
405 \begin{tabular}{|l|l|}\hline
406 barrier & \emph{barrier} attribute \\ \hline
407 complete & \emph{completed} by driver \\ \hline
408 fs & \emph{FS} requests \\ \hline
409 issue & \emph{issued} to driver \\ \hline
410 pc & \emph{packet command} events \\ \hline
411 queue & \emph{queue} operations \\ \hline
412 read & \emph{read} traces \\ \hline
413 requeue & \emph{requeue} operations \\ \hline
414 sync & \emph{synchronous} attribute \\ \hline
415 write & \emph{write} traces \\ \hline
418 \subsubsection{\label{sec:request-types}Request types}
419 blktrace disguingishes between two types of block layer requests,
420 file system and scsi commands. The former are dubbed \emph{fs}
421 requests, the latter \emph{pc} requests. File system requests are
422 normal read/write operations, ie any type of read or write from a
423 specific disk location at a given size. These requests typically
424 originate from a user process, but they may also be initiated by
425 the vm flushing dirty data to disk or the file system syncing
426 a super or journal block to disk. \emph{pc} requests are SCSI
427 commands. blktrace sends the command data block as a payload
428 so that blkparse can decode it.
430 %----------------------------
431 \newpage\section{\label{sec:blkparse-ug}blkparse User Guide}
433 The \emph{blkparse} utility will attempt to combine streams of events
434 for various devices on various CPUs, and produce a formatted output of
435 the event information. As with blktrace, some details concerning blkparse
436 will help in understanding the command line options presented below.
439 \item By default, blkparse expects to run in a post-processing mode
440 -- one where the trace events have been saved by a previous run
441 of blktrace, and blkparse is combining event streams and dumping
444 blkparse \emph{may} be run in a \emph{live} manner concurrently with
445 blktrace by specifying \emph{-i -} to blkparse, and combining it with
446 the live option for blktrace. An example would be:
449 % blktrace -d /dev/sda -o - | blkparse -i -
452 \item You can set how many blkparse batches event reads via the
453 \emph{-b} option, the default is to handle events in batches of 512.
455 \item If you have saved event traces in blktrace with different output
456 names (via the \emph{-o} option to blktrace), you must specify the
457 same \emph{input} name via the \emph{-i} option.
459 \item The format of the output data can be controlled via the \emph{-f}
460 or \emph{-F} options -- see section~\ref{sec:blkparse-format} for details.
462 By default, blkparse sends formatted data to standard output. This may
463 be changed via the \emph{-o} option, or text output can be disabled
464 via the\emph{-O} option. A merged binary stream can be produced using
465 the \emph{-d} option.
469 \newpage\subsection{\label{sec:blkparse-args}Command line arguments}
470 \begin{tabular}{|l|l|l|}\hline
471 Short & Long & Description \\ \hline\hline
472 -b \emph{batch} & --batch={batch} & Standard input read batching \\ \hline
474 -i \emph{file} & --input=\emph{file} & Specifies base name for input files -- default is \emph{device}.blktrace.\emph{cpu}. \\
475 & & As noted above, specifying \emph{-i -} runs in \emph{live} mode with blktrace \\
476 & & (reading data from standard in). \\ \hline
478 -F \emph{typ,fmt} & --format=\emph{typ,fmt} & Sets output format \\
479 -f \emph{fmt} & --format-spec=\emph{fmt} & (See section~\ref{sec:blkparse-format} for details.) \\
481 & & The -f form specifies a format for all events \\
483 & & The -F form allows one to specify a format for a specific \\
484 & & event type. The single-character \emph{typ} field is one of the \\
485 & & action specifiers in section~\ref{sec:act-table} \\ \hline
488 -m & --missing & Print missing entries\\ \hline
490 -h & --hash-by-name & Hash processes by name, not by PID\\ \hline
492 -o \emph{file} & --output=\emph{file} & Output file \\ \hline
493 -O & --no-text-output & Do \emph{not} produce text output, used for binary (-d) only \\ \hline
495 -d \emph{file} & --dump-binary=\emph{file} & Binary output file \\ \hline
497 -q & --quiet & Quite mode \\ \hline
499 -s & --per-program-stats & Displays data sorted by program \\ \hline
501 -t & --track-ios & Display time deltas per IO \\ \hline
503 -w \emph{span} & --stopwatch=\emph{span} & Display traces for the \emph{span} specified -- where span can be: \\
504 & & \emph{end-time} -- Display traces from time 0 through \emph{end-time} (in ns) \\
506 & & \emph{start:end-time} -- Display traces from time \emph{start} \\
507 & & through {end-time} (in ns). \\ \hline
509 -v & --verbose & More verbose marginal on marginal errors \\ \hline
510 -V & --version & Display version \\ \hline
515 \subsection{\label{sec:blkparse-actions}Trace actions}
518 \item[C -- complete] A previously issued request has been completed.
519 The output will detail the sector and size of that request, as well
520 as the success or failure of it.
522 \item[D -- issued] A request that previously resided on the block layer
523 queue or in the io scheduler has been sent to the driver.
525 \item[I -- inserted] A request is being sent to the io scheduler for
526 addition to the internal queue and later service by the driver. The
527 request is fully formed at this time.
529 \item[Q -- queued] This notes intent to queue io at the given location.
530 No real requests exists yet.
532 \item[B -- bounced] The data pages attached to this \emph{bio} are
533 not reachable by the hardware and must be bounced to a lower memory
534 location. This causes a big slowdown in io performance, since the data
535 must be copied to/from kernel buffers. Usually this can be fixed with
536 using better hardware - either a better io controller, or a platform
539 \item[m -- message] Text message generated via kernel call to
540 \texttt{blk\_add\_trace\_msg}.
542 \item[M -- back merge] A previously inserted request exists that ends
543 on the boundary of where this io begins, so the io scheduler can merge
546 \item[F -- front merge] Same as the back merge, except this io ends
547 where a previously inserted requests starts.
549 \item[G -- get request] To send any type of request to a block device,
550 a \emph{struct request} container must be allocated first.
552 \item[S -- sleep] No available request structures were available, so
553 the issuer has to wait for one to be freed.
555 \item[P -- plug] When io is queued to a previously empty block device
556 queue, Linux will plug the queue in anticipation of future ios being
557 added before this data is needed.
559 \item[U -- unplug] Some request data already queued in the device,
560 start sending requests to the driver. This may happen automatically
561 if a timeout period has passed (see next entry) or if a number of
562 requests have been added to the queue.
564 \item[T -- unplug due to timer] If nobody requests the io that was queued
565 after plugging the queue, Linux will automatically unplug it after a
566 defined period has passed.
568 \item[X -- split] On raid or device mapper setups, an incoming io may
569 straddle a device or internal zone and needs to be chopped up into
570 smaller pieces for service. This may indicate a performance problem due
571 to a bad setup of that raid/dm device, but may also just be part of
572 normal boundary conditions. dm is notably bad at this and will clone
575 \item[A -- remap] For stacked devices, incoming io is remapped to device
576 below it in the io stack. The remap action details what exactly is
577 being remapped to what.
581 \subsection{\label{sec:blkparse-format}Output Description and Formatting}
583 The output from blkparse can be tailored for specific use - in particular,
584 to ease parsing of output, and/or limit output fields to those the user
585 wants to see. The data for fields which can be output include:
588 \begin{tabular}{|l|l|}\hline
589 Field & Description \\
590 Specifier & \\ \hline\hline
591 \emph{a} & Action, a (small) string (1 or 2 characters) -- see table below for more details \\ \hline
592 \emph{c} & CPU id \\ \hline
593 \emph{C} & Command \\ \hline
594 \emph{d} & RWBS field, a (small) string (1-3 characters) -- see section below for more details \\ \hline
595 \emph{D} & 7-character string containing the major and minor numbers of
596 the event's device \\
597 & (separated by a comma). \\ \hline
598 \emph{e} & Error value \\ \hline
599 \emph{m} & Minor number of event's device. \\ \hline
600 \emph{M} & Major number of event's device. \\ \hline
601 \emph{n} & Number of blocks \\ \hline
602 \emph{N} & Number of bytes \\ \hline
603 \emph{p} & Process ID \\ \hline
604 \emph{P} & Display packet data -- series of hexadecimal values\\ \hline
605 \emph{s} & Sequence numbers \\ \hline
606 \emph{S} & Sector number \\ \hline
607 \emph{t} & Time stamp (nanoseconds) \\ \hline
608 \emph{T} & Time stamp (seconds) \\ \hline
609 \emph{u} & Elapsed value in microseconds (\emph{-t} command line option) \\ \hline
610 \emph{U} & Payload unsigned integer \\ \hline
613 Note that the user can optionally specify field display width, and
614 optionally a left-aligned specifier. These precede field specifiers,
615 with a '\%' character, followed by the optional left-alignment specifer
616 (-) followed by the width (a decimal number) and then the field.
618 Thus, to specify the command in a 12-character field that is left aligned:
625 \subsubsection{\label{sec:act-table}Action Table}
626 The following table shows the various actions which may be output.
628 \begin{tabular}{|l|l|}\hline
629 Act & Description \\ \hline\hline
630 A & IO was remapped to a different device \\ \hline
631 B & IO bounced \\ \hline
632 C & IO completion \\ \hline
633 D & IO issued to driver \\ \hline
634 F & IO front merged with request on queue \\ \hline
635 G & Get request \\ \hline
636 I & IO inserted onto request queue \\ \hline
637 M & IO back merged with request on queue \\ \hline
638 P & Plug request \\ \hline
639 Q & IO handled by request queue code \\ \hline
640 S & Sleep request \\ \hline
641 T & Unplug due to timeout \\ \hline
642 U & Unplug request \\ \hline
646 \subsubsection{\label{sec:act-table}RWBS Description}
647 This is a small string containing at least one character ('R' for read,
648 'W' for write, or 'D' for block discard operation), and optionally either
649 a 'B' (for barrier operations) or 'S' (for synchronous operations).
651 \subsubsection{\label{sec:default-output}Default output}
653 The standard \emph{header} (or initial fields displayed) include:
656 "%D %2c %8s %5T.%9t %5p %2a %3d "
662 \item[\%D] Displays the event's device major/minor as: \%3d,\%-3d.
663 \item[\%2c] CPU ID (2-character field).
664 \item[\%8s] Sequence number
665 \item[\%5T.\%9t] 5-charcter field for the seconds portion of the
666 time stamp and a 9-character field for the nanoseconds in the time stamp.
667 \item[\%5p] 5-character field for the process ID.
668 \item[\%2a] 2-character field for one of the actions.
669 \item[\%3d] 3-character field for the RWBS data.
672 Seeing this in action:
675 8,0 3 1 0.000000000 697 G W 223490 + 8 [kjournald]
678 The header is the data in this line up to the 223490 (starting block).
680 The default output for all event types includes this header.
682 \paragraph{Default output per action}
685 \item[C -- complete] If a payload is present, this is presented between
686 parenthesis following the header, followed by the error value.
688 If no payload is present, the sector and number of blocks are presented
689 (with an intervening plus (+) character). If the \emph{-t} option
690 was specified, then the elapsed time is presented. In either case,
691 it is followed by the error value for the completion.
696 \item[B -- bounced] If a payload is present, the number of payload bytes
697 is output, followed by the payload in hexadecimal between parenthesis.
699 If no payload is present, the sector and number of blocks are presented
700 (with an intervening plus (+) character). If the \emph{-t} option was
701 specified, then the elapsed time is presented (in parenthesis). In
702 either case, it is followed by the command associated with the event
703 (surrounded by square brackets).
705 \item[M -- back merge]
706 \item[F -- front merge]
707 \item[G -- get request]
708 \item[S -- sleep] The starting sector and number of blocks is output
709 (with an intervening plus (+) character), followed by the command
710 associated with the event (surrounded by square brackets).
712 \item[P -- plug] The command associated with the event (surrounded by
713 square brackets) is output.
716 \item[T -- unplug due to timer] The command associated with the event
717 (surrounded by square brackets) is output, followed by the number of
718 requests outstanding.
720 \item[X -- split] The original starting sector followed by the new
721 sector (separated by a slash (/) is output, followed by the command
722 associated with the event (surrounded by square brackets).
724 \item[A -- remap] Sector and length is output, along with the original
725 device and sector offset.
727 \item[m -- message] The supplied message is appended to the end of
732 %------------------------------
734 \newpage\section*{\label{sec:blktrace-kg}Appendix: blktrace Kernel Guide}
736 The blktrace facility provides an efficient event transfer mechanism which
737 supplies block IO layer state transition data via the relay
738 filesystem. This section provides some details as to the interfaces
739 blktrace utilizes in the kernel to effect this. It is good background data
740 to help understand some of the outputs and command-line options above.
742 \subsection{blktrace.h Definitions}
743 Files which include $<linux/blktrace.h>$ are supplied with the following
746 \subsubsection{Trace Action Specifiers}
747 \begin{tabular}{|l|l|}\hline
748 BLK\_TA\_QUEUE & (RQ) Command queued to request\_queue. \\
749 & (BIO) Command queued by elevator. \\ \hline
750 BLK\_TA\_BACKMERGE & Back merging elevator operation \\ \hline
751 BLK\_TA\_FRONTMERGE & Front merging elevator operation \\ \hline
752 BLK\_TA\_GETRQ & Free request retrieved. \\ \hline
753 BLK\_TA\_SLEEPRQ & No requests available, device unplugged. \\ \hline
754 BLK\_TA\_REQUEUE & Request requeued. \\ \hline
755 BLK\_TA\_ISSUE & Command set to driver for request\_queue. \\ \hline
756 BLK\_TA\_COMPLETE & Command completed by driver. \\ \hline
757 BLK\_TA\_PLUG & Device is plugged \\ \hline
758 BLK\_TA\_UNPLUG\_IO & Unplug device as IO is made available. \\ \hline
759 BLK\_TA\_UNPLUG\_TIMER & Unplug device after timer expired. \\ \hline
760 BLK\_TA\_INSERT & Insert request into queue. \\ \hline
761 BLK\_TA\_SPLIT & BIO split into 2 or more requests. \\ \hline
762 BLK\_TA\_BOUNCE & BIO was bounced \\ \hline
763 BLK\_TA\_REMAP & BIO was remapped \\ \hline
766 %..........................................
767 \subsection{blktrace.h Routines}
768 Files which include $<linux/blktrace.h>$ are supplied with the following
769 kernel routine invocable interfaces:
772 \item[blk\_add\_trace\_rq(struct request\_queue *q, struct request\_queue
774 Adds a trace event describing the state change of the passed in
775 request\_queue. The \emph{what} parameter describes the change in
776 the request\_queue state, and is one of the request queue action
777 specifiers -- BLK\_TA\_QUEUE, BLK\_TA\_REQUEUE, BLK\_TA\_ISSUE,
778 or BLK\_TA\_COMPLETE.
780 \item[blk\_add\_trace\_bio(struct request\_queue *q, struct bio *bio,
782 Adds a trace event for the BIO passed in. The \emph{what} parameter
783 describes the action being performed on the BIO, and is one of
784 BLK\_TA\_BACKMERGE, BLK\_TA\_FRONTMERGE, or BLK\_TA\_QUEUE.
786 \item[blk\_add\_trace\_generic(struct request\_queue *q, struct bio *bio,
788 Adds a \emph{generic} trace event -- not one of the request queue
789 or BIO traces. The \emph{what} parameter describes the action being
790 performed on the BIO (if bio is non-NULL), and is one of
791 BLK\_TA\_PLUG, BLK\_TA\_GETRQ or BLK\_TA\_SLEEPRQ.
793 \item[blk\_add\_trace\_pdu\_int(struct request\_queue *q, u32 what,
795 Adds a trace with some payload data -- in this case, an unsigned
796 32-bit entity (the \emph{pdu} parameter). The \emph{what} parameter
797 describes the nature of the payload, and is one of
798 BLK\_TA\_UNPLUG\_IO or BLK\_TA\_UNPLUG\_TIMER.
800 \item[blk\_add\_trace\_remap(struct request\_queue *q, struct bio *bio,
801 dev\_t dev, sector\_t sector)]
802 Adds a trace with a remap event. \emph{dev} and \emph{sector} denote
803 the original device this \emph{bio} was mapped from.
805 \item[blk\_add\_trace\_msg(struct request\_queue *q, char *fmt, ...)]
806 Adds a formatted message to the output stream. The total message
807 size can not exceed BLK\_TN\_MSG\_MSG characters (currently
808 1024). Standard format conversions are supported (as supplied
809 by \texttt{vscnprintf}.