3.6.2.2. Using blktrace Remotely

Because blktrace traces block I/O and at the same time normally writes its trace data to a block device, and in general because it's not really a great idea to make the device being traced the same as the device the tracer writes to, blktrace provides a way to trace without perturbing the traced device at all by providing native support for sending all trace data over the network.

To have blktrace operate in this mode, start blktrace on the target system being traced with the -l option, along with the device to trace:

     root@crownbay:~# blktrace -l /dev/sdc
     server: waiting for connections...
                

On the host system, use the -h option to connect to the target system, also passing it the device to trace:

     $ blktrace -d /dev/sdc -h 192.168.1.43
     blktrace: connecting to 192.168.1.43
     blktrace: connected!
                

On the target system, you should see this:

     server: connection from 192.168.1.43
                

In another shell, execute a workload you want to trace.

     root@crownbay:/media/sdc# rm linux-2.6.19.2.tar.bz2; wget http://downloads.yoctoproject.org/mirror/sources/linux-2.6.19.2.tar.bz2; sync
     Connecting to downloads.yoctoproject.org (140.211.169.59:80)
     linux-2.6.19.2.tar.b 100% |*******************************| 41727k  0:00:00 ETA
                

When it's done, do a Ctrl-C on the host system to stop the trace:

     ^C=== sdc ===
      CPU  0:                 7691 events,      361 KiB data
      CPU  1:                 4109 events,      193 KiB data
      Total:                 11800 events (dropped 0),      554 KiB data
                

On the target system, you should also see a trace summary for the trace just ended:

     server: end of run for 192.168.1.43:sdc
     === sdc ===
      CPU  0:                 7691 events,      361 KiB data
      CPU  1:                 4109 events,      193 KiB data
      Total:                 11800 events (dropped 0),      554 KiB data
                

The blktrace instance on the host will save the target output inside a hostname-timestamp directory:

     $ ls -al
     drwxr-xr-x   10 root     root          1024 Oct 28 02:40 .
     drwxr-sr-x    4 root     root          1024 Oct 26 18:24 ..
     drwxr-xr-x    2 root     root          1024 Oct 28 02:40 192.168.1.43-2012-10-28-02:40:56
                

cd into that directory to see the output files:

     $ ls -l
     -rw-r--r--    1 root     root        369193 Oct 28 02:44 sdc.blktrace.0
     -rw-r--r--    1 root     root        197278 Oct 28 02:44 sdc.blktrace.1
                

And run blkparse on the host system using the device name:

     $ blkparse sdc

      8,32   1        1     0.000000000  1263  Q  RM 6016 + 8 [ls]
      8,32   1        0     0.000036038     0  m   N cfq1263 alloced
      8,32   1        2     0.000039390  1263  G  RM 6016 + 8 [ls]
      8,32   1        3     0.000049168  1263  I  RM 6016 + 8 [ls]
      8,32   1        0     0.000056152     0  m   N cfq1263 insert_request
      8,32   1        0     0.000061600     0  m   N cfq1263 add_to_rr
      8,32   1        0     0.000075498     0  m   N cfq workload slice:300
      .
      .
      .
      8,32   0        0   177.266385696     0  m   N cfq1267 arm_idle: 8 group_idle: 0
      8,32   0        0   177.266388140     0  m   N cfq schedule dispatch
      8,32   1        0   177.266679239     0  m   N cfq1267 slice expired t=0
      8,32   1        0   177.266689297     0  m   N cfq1267 sl_used=9 disp=6 charge=9 iops=0 sect=56
      8,32   1        0   177.266692649     0  m   N cfq1267 del_from_rr
      8,32   1        0   177.266696560     0  m   N cfq1267 put_queue

     CPU0 (sdc):
      Reads Queued:           0,        0KiB	 Writes Queued:         270,   21,708KiB
      Read Dispatches:       59,    2,628KiB	 Write Dispatches:      495,   39,964KiB
      Reads Requeued:         0		 Writes Requeued:         0
      Reads Completed:       90,    2,752KiB	 Writes Completed:      543,   41,596KiB
      Read Merges:            0,        0KiB	 Write Merges:            9,      344KiB
      Read depth:             2        	 Write depth:             2
      IO unplugs:            20        	 Timer unplugs:           1
     CPU1 (sdc):
      Reads Queued:         688,    2,752KiB	 Writes Queued:         381,   20,652KiB
      Read Dispatches:       31,      124KiB	 Write Dispatches:       59,    2,396KiB
      Reads Requeued:         0		 Writes Requeued:         0
      Reads Completed:        0,        0KiB	 Writes Completed:       11,      764KiB
      Read Merges:          598,    2,392KiB	 Write Merges:           88,      448KiB
      Read depth:             2        	 Write depth:             2
      IO unplugs:            52        	 Timer unplugs:           0

     Total (sdc):
      Reads Queued:         688,    2,752KiB	 Writes Queued:         651,   42,360KiB
      Read Dispatches:       90,    2,752KiB	 Write Dispatches:      554,   42,360KiB
      Reads Requeued:         0		 Writes Requeued:         0
      Reads Completed:       90,    2,752KiB	 Writes Completed:      554,   42,360KiB
      Read Merges:          598,    2,392KiB	 Write Merges:           97,      792KiB
      IO unplugs:            72        	 Timer unplugs:           1

     Throughput (R/W): 15KiB/s / 238KiB/s
     Events (sdc): 9,301 entries
     Skips: 0 forward (0 -   0.0%)
                

You should see the trace events and summary just as you would have if you'd run the same command on the target.