Profiling PostgreSQL using DTRACE on Solaris 10

Here are couple of DTRACE scripts that I used in order to profile PostgreSQL on Solaris 10. This scripts are pretty generic and can be used to profile most applications on Solaris.

syscall.d



#!/usr/sbin/dtrace -s
syscall:::entry
/execname== "postgres"/
{
self->ts=timestamp;
}
syscall:::return
/execname== "postgres" && self->ts/
{
@a["Count",probefunc] = count();
@b["Time",probefunc] = sum (timestamp - self->ts);
self->ts=0;
}
tick-10sec
{
exit(0);
}

Since I am counting I was to be close to precise and hence not rely on "when I press CTRL-C". Hence I exit automatically after 10 seconds (Of course it may not be EXACTLY 10 seconds but I can live with that)

This helps me to see if there is any BLOCKING system call which is slowing me down. When I say blocking I mean reads, writes and not polls, recvs, etc.

Similary another script that I use a lot which is very INTRUSIVE but gives a good profile of the User functions is the following script

usrcall.d



#!/usr/sbin/dtrace -s
/* Usage       : usrcall.d `pgrep -n postgres` */
pid$1:::entry
{
self->ts = timestamp;
}
pid$1:::return
/self->ts/
{
@a["Count",probefunc] =  count() ;
@b["Time",probefunc] =  sum(timestamp - self->ts) ;
self->ts = 0;
}
tick-10sec
{
exit(0);
}

This above script is bit intrusive and slows down your process but gives a good profile in that 10-second about the count and approximate time it spent in those function calls to see which function call needs to be investigated more.

Say for example if the output for the earlier example reports too much time spent in memcpy which is a library function in Solaris. In such case you can take a look at what SIZE of chunk of copies are being done using following DTRACE script

memcpysize.d



#!/usr/sbin/dtrace -s
/* Usage       : usrcall.d `pgrep -n postgres` */
pid$1::memcpy:entry
{
@size["Size"] =  quantize(arg2);
}
tick-10sec
{
exit(0);
}

Also you can modify the above script and also count the most commonly followed code path to memcpy.

memcpystack.d



#!/usr/sbin/dtrace -s
/* Usage       : usrcall.d `pgrep -n postgres` */
pid$1::memcpy:entry
{
self->ts = timestamp;
@size["Size"] =  quantize(arg2);
}
pid$1::memcpy:return
/self->ts/
{
@count["Count",ustack()] =  count() ;
/* @b["Time",ustack()] =  sum(timestamp - self->ts) ;*/
self->ts = 0;
}
tick-10sec
{
exit(0);
}

Similarly you can profile your own user function in your application by replacing memcpy with your function name (or if you are using C++ using the mangled C++ function name). This helps to profile the application on Solaris 10 and drill down to bottlenecks in the application/system.

Hope this scripts help you to understand DTRACE in order to profile your systems better too on Solaris 10.