prex, tnfxtract and tnfdump ...

With Solaris 10, dtrace is the way to go, if you want to probe/profile some system calls. However, if you are still stuck with Solaris running older versions and need to dig deeper into kernel profiling .. then read on

"prex" has been present since Solaris 2.5 days and is part of Solaris tracing architecture that controls probes in a process or the kernel.

root# prex -k
Type "help" for help ...
prex> buffer dealloc
There is no buffer to deallocate
prex> buffer alloc 2M
Buffer of size 2097152 bytes allocated
prex> enable io
prex> trace io
prex> ktrace on

.... wait for sometime to collect data

prex> ktrace off
prex> quit

Extract the data from buffer into a trace file
root# tnfxtract data1.tnf
Convert the "tnf" file into a text file as
root# tnfdump data1.tnf > data1.txt

The output file has two sections 1) header 2) detailed probe data
Here is a sample header, which displays the probes which have been enabled

probe tnf_name: "strategy" tnf_string: "keys io blockio;file ../../common/os/driver.c;line 411;"
probe tnf_name: "pageout" tnf_string: "keys vm pageio io;file ../../common/vm/vm_pvn.c;line 571;"
probe tnf_name: "biodone" tnf_string: "keys io blockio;file ../../common/os/bio.c;line 1222;"
probe tnf_name: "physio_start" tnf_string: "keys io rawio;file ../../common/os/vm_subr.c;line 158;"
probe tnf_name: "physio_end" tnf_string: "keys io rawio;file ../../common/os/vm_subr.c;line 304;"

Little info on above probes:

strategy - strategy() routine is called indectly by kernel to read/write blocks of data on block devices. Its responsibility
is to setup and initiate data transfer. It records i/o start.
biodone - release buffer after buffer I/O transfer and notify blocked threads. It record i/o completion.
pageout - I/o due to paging is recorded as pageoutphysio_start - raw i/o (or) kaio start
physio_end - raw i/o (or) kaio stop These probes record the device number, offset, size, and direction of the I/O transfer.

The contents of the actual probe data is shown below (edited for clarity)
---------------- ---------------- ----- ----- ---------- ---
Elapsed (ms) Delta (ms) PID LWPID TID CPU Probe Name Data / Description . . .
---------------- ---------------- ----- ----- ---------- ---

0.000000 0.000000 15024 12 0x3000bf93c80 3 strategy device: ... buf: 0x3001427dc80 flags: 34078993
8.149680 0.022960 0 0 0x2a10030fcc0 2 biodone device: ..block: 162881792 buf: 0x3001427dc80
8.251120 0.101440 15024 12 0x3000bf93c80 1 pageout vnode: ... pages_pageout: 0 pages_freed: 0 pages_reclaimed: 0
1529.298240 1515.858800 0 0 0x2a10029fcc0 3 strategy device: .. block: 8249 size: 512 buf: 0x60002515d10 flags: 33554689
.
1536.184480 0.007440 0 0 0x2a100af5cc0 9 biodone device: 137438953516 block: 8249 buf: 0x60002515d10
5046.189280 0.121040 68 1 0x30003442380 2 physio_start device: 506806142280 offset: 0 size: 36 rw: 64
5046.461840 0.021520 68 1 0x30003442380 2 physio_end device: 506806142280

From above data, we can observe the block location and size of data transfer – this information can be used to determine if the applications are doing random/sequenctial i/o.

If required to trace only single process, process filter can be turned on using :

prex> pfilter on
Warning: Process filtering on, but pid filter list is empty
prex> pfilter add 936
prex> pfilter
Process filtering is on
Process filter set is {936}

References:

http://developers.sun.com/solaris/developer/support/driver/notes/iotracing.pdf
http://www.brendangregg.com/Perf/paper_diskubyp1.pdf