From: Brett Russ <bruss@netezza.com>
To: linux-btrace@vger.kernel.org
Subject: blkparse not displaying all events when tracing >1 devices?
Date: Wed, 15 Sep 2010 22:29:19 +0000 [thread overview]
Message-ID: <4C9148BF.1000306@netezza.com> (raw)
Hello,
If I trace *2* block devices (I only tried 1 or 2, not > 2) using a
single blktrace command, then blkparse the resulting output file set, I
get an abridged display of events to only one of the devices.
If I instead launch two separate blktrace commands, each to a single
block device and unique output file, then blkparse the resulting output
files independently, I appear to get all the events on each device.
FWIW, the two block devices are actually two paths to the same HDD but I
doubt that is relevant to this problem.
I'm pasting in my notes below. This was done using a build from a clone
of the blktrace git repo taken this afternoon.
> spu0103# blktrace -V
> blktrace version 2.0.0
First tried the multi-device syntax shown in the PDF users guide:
> spu0103# blktrace /dev/sdbk /dev/sdam -o 5 &
This program initiates SCSI commands to both devices and reads to one of
them:
> spu0103# nzgeninventory > nzgi.5 2>&1
> spu0103# killall blktrace
Evidently blktrace captured everything:
> spu0103# == sdbk => CPU 0: 0 events, 0 KiB data
> CPU 1: 4 events, 1 KiB data
> CPU 2: 5 events, 1 KiB data
> CPU 3: 5 events, 1 KiB data
> CPU 4: 5 events, 1 KiB data
> CPU 5: 0 events, 0 KiB data
> CPU 6: 1 events, 1 KiB data
> CPU 7: 1 events, 1 KiB data
> Total: 21 events (dropped 0), 2 KiB data
> == sdam => CPU 0: 9 events, 1 KiB data
> CPU 1: 7 events, 1 KiB data
> CPU 2: 6 events, 1 KiB data
> CPU 3: 6 events, 1 KiB data
> CPU 4: 6 events, 1 KiB data
> CPU 5: 10 events, 1 KiB data
> CPU 6: 6 events, 1 KiB data
> CPU 7: 11 events, 1 KiB data
> Total: 61 events (dropped 0), 4 KiB data
>
> [1]+ Done blktrace /dev/sdbk /dev/sdam -o 5
But blkparse shows me only some events from one of the devices:
> spu0103# blkparse -q -i 5
> Input file 5.blktrace.1 added
> Input file 5.blktrace.2 added
> Input file 5.blktrace.3 added
> Input file 5.blktrace.4 added
> Input file 5.blktrace.6 added
> Input file 5.blktrace.7 added
> 66,96 1 1 0.000000000 3786 G N [nzgeninventory.]
> 66,96 1 2 0.000002043 3786 P N [nzgeninventory.]
> 66,96 3 1 0.000496874 0 C R (12 00 00 00 24 00 ..) [0]
> 66,96 3 2 0.000597626 3786 G N [nzgeninventory.]
> 66,96 3 3 0.000599460 3786 P N [nzgeninventory.]
> 66,96 2 1 0.001022051 0 C R (12 00 00 00 a4 00 ..) [0]
> 66,96 2 2 0.001094954 3786 G N [nzgeninventory.]
> 66,96 2 3 0.001096781 3786 P N [nzgeninventory.]
> 66,96 4 1 0.001705551 0 C R (12 01 83 00 fc 00 ..) [0]
> 66,96 4 2 0.002156748 3786 G N [nzgeninventory.]
> 66,96 4 3 0.002158788 3786 P N [nzgeninventory.]
Let's try two separate instances of blktrace?
> spu0103# blktrace /dev/sdbk -o 6a &
> spu0103# blktrace /dev/sdam -o 6b &
> spu0103# nzgeninventory > nzgi.6 2>&1
> spu0103# killall blktrace
Same # of events captured:
> spu0103# == sdbk => CPU 0: 1 events, 1 KiB data
> CPU 1: 0 events, 0 KiB data
> CPU 2: 1 events, 1 KiB data
> CPU 3: 0 events, 0 KiB data
> CPU 4: 4 events, 1 KiB data
> CPU 5: 5 events, 1 KiB data
> CPU 6: 5 events, 1 KiB data
> CPU 7: 5 events, 1 KiB data
> Total: 21 events (dropped 0), 2 KiB data
> == sdam => CPU 0: 10 events, 1 KiB data
> CPU 1: 9 events, 1 KiB data
> CPU 2: 7 events, 1 KiB data
> CPU 3: 9 events, 1 KiB data
> CPU 4: 6 events, 1 KiB data
> CPU 5: 6 events, 1 KiB data
> CPU 6: 6 events, 1 KiB data
> CPU 7: 8 events, 1 KiB data
> Total: 61 events (dropped 0), 4 KiB data
>
> [2]+ Done blktrace /dev/sdam -o 6b
> [1]+ Done blktrace /dev/sdbk -o 6a
But this time the blkparse output is what I expect:
> spu0103# blkparse -q -i 6a
> Input file 6a.blktrace.0 added
> Input file 6a.blktrace.2 added
> Input file 6a.blktrace.4 added
> Input file 6a.blktrace.5 added
> Input file 6a.blktrace.6 added
> Input file 6a.blktrace.7 added
> 67,224 4 1 0.000000000 4247 G N [(null)]
> 67,224 4 2 0.000002179 4247 P N [(null)]
> 67,224 4 3 0.000002361 4247 I R 36 (12 00 00 00 24 00 ..) [(null)]
> 67,224 4 4 0.000003055 4247 D R 36 (12 00 00 00 24 00 ..) [(null)]
> 67,224 6 1 0.000498033 0 C R (12 00 00 00 24 00 ..) [0]
> 67,224 6 2 0.000583480 4247 G N [(null)]
> 67,224 6 3 0.000585724 4247 P N [(null)]
> 67,224 6 4 0.000585880 4247 I R 164 (12 00 00 00 a4 00 ..) [(null)]
> 67,224 6 5 0.000586369 4247 D R 164 (12 00 00 00 a4 00 ..) [(null)]
> 67,224 5 1 0.000996791 0 C R (12 00 00 00 a4 00 ..) [0]
> 67,224 5 2 0.001057014 4247 G N [(null)]
> 67,224 5 3 0.001059622 4247 P N [(null)]
> 67,224 5 4 0.001059775 4247 I R 252 (12 01 83 00 fc 00 ..) [(null)]
> 67,224 5 5 0.001065073 4247 D R 252 (12 01 83 00 fc 00 ..) [(null)]
> 67,224 7 1 0.001683205 0 C R (12 01 83 00 fc 00 ..) [0]
> 67,224 7 2 0.001989782 4247 G N [(null)]
> 67,224 7 3 0.001991606 4247 P N [(null)]
> 67,224 7 4 0.001991753 4247 I R 252 (12 01 80 00 fc 00 ..) [(null)]
> 67,224 7 5 0.001992269 4247 D R 252 (12 01 80 00 fc 00 ..) [(null)]
> 67,224 0 1 0.002599310 0 C R (12 01 80 00 fc 00 ..) [0]
>
> spu0103# blkparse -q -i 6b
> Input file 6b.blktrace.0 added
> Input file 6b.blktrace.1 added
> Input file 6b.blktrace.2 added
> Input file 6b.blktrace.3 added
> Input file 6b.blktrace.4 added
> Input file 6b.blktrace.5 added
> Input file 6b.blktrace.6 added
> Input file 6b.blktrace.7 added
> 66,96 2 1 0.000000000 4247 G N [nzgeninventory.]
> 66,96 2 2 0.000002148 4247 P N [nzgeninventory.]
> 66,96 2 3 0.000002316 4247 I R 36 (12 00 00 00 24 00 ..) [nzgeninventory.]
> 66,96 2 4 0.000002955 4247 D R 36 (12 00 00 00 24 00 ..) [nzgeninventory.]
> 66,96 4 1 0.000419015 0 C R (12 00 00 00 24 00 ..) [0]
> 66,96 4 2 0.000490802 4247 G N [nzgeninventory.]
> 66,96 4 3 0.000493304 4247 P N [nzgeninventory.]
> 66,96 4 4 0.000493454 4247 I R 164 (12 00 00 00 a4 00 ..) [nzgeninventory.]
> 66,96 4 5 0.000493973 4247 D R 164 (12 00 00 00 a4 00 ..) [nzgeninventory.]
> 66,96 6 1 0.000909171 0 C R (12 00 00 00 a4 00 ..) [0]
> 66,96 6 2 0.000967297 4247 G N [nzgeninventory.]
> 66,96 6 3 0.000969818 4247 P N [nzgeninventory.]
> 66,96 6 4 0.000970016 4247 I R 252 (12 01 83 00 fc 00 ..) [nzgeninventory.]
> 66,96 6 5 0.000970634 4247 D R 252 (12 01 83 00 fc 00 ..) [nzgeninventory.]
> 66,96 5 1 0.001573121 0 C R (12 01 83 00 fc 00 ..) [0]
> 66,96 5 2 0.001883295 4247 G N [nzgeninventory.]
> 66,96 5 3 0.001885647 4247 P N [nzgeninventory.]
> 66,96 5 4 0.001885878 4247 I R 252 (12 01 80 00 fc 00 ..) [nzgeninventory.]
> 66,96 5 5 0.001886469 4247 D R 252 (12 01 80 00 fc 00 ..) [nzgeninventory.]
> 66,96 7 1 0.002486674 0 C R (12 01 80 00 fc 00 ..) [0]
> 66,96 7 2 0.002682738 4247 G N [nzgeninventory.]
> 66,96 7 3 0.002684715 4247 P N [nzgeninventory.]
> 66,96 7 4 0.002684877 4247 I R 252 (25 00 ..) [nzgeninventory.]
> 66,96 7 5 0.002685351 4247 D R 252 (25 00 ..) [nzgeninventory.]
> 66,96 0 1 0.003222215 0 C R (25 00 ..) [0]
> 66,96 0 2 0.003387279 4247 A R 2112 + 1 <- (66,97) 2049
> 66,96 0 3 0.003387516 4247 Q R 2112 + 1 [nzgeninventory.]
> 66,96 0 4 0.003388578 4247 G R 2112 + 1 [nzgeninventory.]
> 66,96 0 5 0.003389361 4247 P N [nzgeninventory.]
> 66,96 0 6 0.003389889 4247 I R 2112 + 1 [nzgeninventory.]
> 66,96 0 7 0.003390646 4247 U N [nzgeninventory.] 1
> 66,96 0 8 0.003391420 4247 D R 2112 + 1 [nzgeninventory.]
> 66,96 1 1 0.003547936 0 C R 2112 + 1 [0]
> 66,96 1 2 0.003743980 4247 A R 1197744189 + 1 <- (66,99) 2049
> 66,96 1 3 0.003744226 4247 Q R 1197744189 + 1 [nzgeninventory.]
> 66,96 1 4 0.003745333 4247 G R 1197744189 + 1 [nzgeninventory.]
> 66,96 1 5 0.003746269 4247 P N [nzgeninventory.]
> 66,96 1 6 0.003746782 4247 I R 1197744189 + 1 [nzgeninventory.]
> 66,96 1 7 0.003747532 4247 U N [nzgeninventory.] 1
> 66,96 1 8 0.003748303 4247 D R 1197744189 + 1 [nzgeninventory.]
> 66,96 3 1 0.003903074 0 C R 1197744189 + 1 [0]
> 66,96 3 2 0.004043041 4247 A R 1944782754 + 1 <- (66,100) 2049
> 66,96 3 3 0.004043263 4247 Q R 1944782754 + 1 [nzgeninventory.]
> 66,96 3 4 0.004044337 4247 G R 1944782754 + 1 [nzgeninventory.]
> 66,96 3 5 0.004045072 4247 P N [nzgeninventory.]
> 66,96 3 6 0.004045558 4247 I R 1944782754 + 1 [nzgeninventory.]
> 66,96 3 7 0.004046260 4247 U N [nzgeninventory.] 1
> 66,96 3 8 0.004047013 4247 D R 1944782754 + 1 [nzgeninventory.]
> 66,96 2 5 0.004201336 0 C R 1944782754 + 1 [0]
I tried the '-m' (show missing events) option shown in the PDF for
blkparse, but it doesn't appear to be a valid option. I don't think
that it was intended for this purpose anyway...
> spu0103# blkparse -q -m -i 7
> blkparse: invalid option -- 'm'
I also tried an alternate form of launching blktrace, this had no impact:
> spu0103# blktrace -d /dev/sdbk -d /dev/sdam -o 7 &
I assume the problem lies in blkparse. At least I have a workaround.
Thanks,
Brett
next reply other threads:[~2010-09-15 22:29 UTC|newest]
Thread overview: 2+ messages / expand[flat|nested] mbox.gz Atom feed top
2010-09-15 22:29 Brett Russ [this message]
2010-09-16 11:54 ` blkparse not displaying all events when tracing >1 devices? Alan D. Brunelle
Reply instructions:
You may reply publicly to this message via plain-text email
using any one of the following methods:
* Save the following mbox file, import it into your mail client,
and reply-to-all from there: mbox
Avoid top-posting and favor interleaved quoting:
https://en.wikipedia.org/wiki/Posting_style#Interleaved_style
* Reply using the --to, --cc, and --in-reply-to
switches of git-send-email(1):
git send-email \
--in-reply-to=4C9148BF.1000306@netezza.com \
--to=bruss@netezza.com \
--cc=linux-btrace@vger.kernel.org \
/path/to/YOUR_REPLY
https://kernel.org/pub/software/scm/git/docs/git-send-email.html
* If your mail client supports setting the In-Reply-To header
via mailto: links, try the mailto: link
Be sure your reply has a Subject: header at the top and a blank line
before the message body.
This is a public inbox, see mirroring instructions
for how to clone and mirror all data and code used for this inbox;
as well as URLs for NNTP newsgroup(s).