Blogs about Deep Learning, Machine Learning, AI, NLP, Security, Oracle Traffic Director,Oracle iPlanet WebServer

  • November 14, 2013

Performance Analysis of Oracle Traffic Director or Web Server

Performance Analysis of Oracle Traffic Director or Oracle iPlanet Web Server using Oracle Sun Solaris Studio Performance Analyzer and DTrace scripts.

In this blog I will show how to use the Sun Studio Collector and Performance Analyzer and DTrace script to measure the performance.

1. Using Oracle Solaris Studio 12.2 Performance Analyzer with Oracle Traffic Director or Oracle iPlanet Web Server

Thanx to Basant for teaching me collector and analyzer and thanx to Julien for his help on DTrace scripts.

Install Sun Studio 12. Lets say is installed in /opt/SUNWSpro.

1.1 setting up ~/.er.rc

cat ~/.er.rc
dmetrics e.user:i.user:e!wall:i!wall:e.total:i.total:e.system:i.system:e!wait: \
dsort e.user
scc basic:version:warn:parallel:query:loop:pipe:inline:memops:fe:cg
dcc basic:version:warn:parallel:query:loop:pipe:inline:memops:fe:cg:src
sthresh 75
dthresh 75
name long
view user
tlmode thread:root:depth=10
tldata sample:clock:hwc:heaptrace:synctrace:mpitrace:msgtrace:datarace
setpath $expts:.
tabs functions:callers-callees:source:disasm:timeline:header:
en_desc on

1.2 Collecting Data Using the collect Command

1.2.1& Run the Collector  using the collect command

# collect collect-options program program-arguments

For OTD or Web Server we edit start script bin/startserv to have a new --collect option as shown below 

Red color lines are the new lines I have added.  Copied all the lines in start option, replaced ${SERVER_BIN} (which is trafficd-wdog) by "trafficd". And added "collect $COLLECT_OPTS" before it.

In the section below replace <profiler directory> by the directory where you want the profiler to collect data.

case $COMMAND in
-u "${SERVER_USER}" ${SVC_OPT} $@
if [ $STATUS -ne 0 ] ; then
exit $STATUS
COLLECT_OPTS="-t 180-300 -F all -d <profiler directory>";
collect $COLLECT_OPTS trafficd
-u "${SERVER_USER}" ${SVC_OPT} $@
if [ $STATUS -ne 0 ] ; then
exit $STATUS

for web server instead of trafficd it will be webservd. 

1.2.2 start the server using --collect option

Since we replaced trafficd-wdog by trafficd, the server will start up without any watchdog process and will run in console, not in background.  

bin/startserv --collect

1.2.3 run some stress tests

1.2.4 After 5-6 minutes stop the server

This will create a directory called (e.g.) 'test.1.er' which contains the experiment.

The default name for a new experiment is test.1.er.

The Collector automatically increments n by one in the names of subsequent experiments.

1.3 Open the profile and start the Oracle Sun Studio 12.2 analyzer

Set DISPLAY env.

$ cd <profiler directory>
$ export JAVA_PATH=/opt/SUNWwbsvr/jdk
$ /opt/SUNWspro/bin/analyzer test.1.er/

1.4 The er_print utility prints an ASCII version of the various displays supported by the Performance Analyzer.

$ /opt/SUNWspro/bin/er_print -outfile er_print1.out -functions test.1.er 

In this, functions are sorted by "Exclusive User CPU Time"


$ /opt/SUNWspro/bin/er_print -outfile er_print2.out \
-metrics e.user:i.user:e.%user:i.%user:e.total:i.total:e.%total:i.%total:name \
-sort i.total -functions test.1.er

In this, functions are sorted by "Inclusive Total LWP Time"

You can look at these files and figure out which function is taking how much time.

These files look like :

Functions sorted by metric: Exclusive User CPU Time 
Excl.     Incl.     Excl.       Incl.       Excl.     Incl.      Name  
User CPU  User CPU  Total LWP   Total LWP   Sys. CPU  Sys. CPU         
   sec.      sec.         sec.        sec.     sec.      sec.     
851.666   851.666   105477.573  105477.573  106.525   106.525    <Total>
493.435   493.435      558.110     558.110   26.368    26.368    fn1
 56.840   326.308       64.015     368.568    3.042    17.352    fn2
 28.280    28.280       34.574      34.574    1.701     1.701    fn3


2. Using DTrace script to see how much time is spent in which function

#!/usr/sbin/dtrace -s
#pragma D option bufsize=1g
#pragma D option specsize=1g
#pragma D option aggsize=1g
#pragma D option dynvarsize=1g
self->ts[probefunc] = timestamp;
@time[probefunc, probemod] = sum(timestamp - self->ts[probefunc]);
self->ts[probefunc] = 0;

Note I have given 1g sizes you can tune it as per your machine.

Run this D script using :

#sudo dtrace -s functime.d -p 27910 -o dtrace.log 

where 27910 is the pid of the process you are examining (in this case webservd or trafficd).

This will generate the output as shown below 

  PListFindValue                       libns-httpd40.so                                        3871
getbucketnum libc.so.1 4995
R_SSL_version libnnz11.so 6106
http_format_server libns-httpd40.so 6807
void SimpleHashTemplateBase::_insert(unsigned long,hashEntry*) libns-httpd40.so 7059
long atoi64(const char*) libns-httpd40.so 7288


I wrote this wrapper script to report percentages.

To get the last column I used logic of looking for spaces after the string "lib". For LM1`ld.so.1, I temporarily added a hack.

$logfile = "dtrace.log";
$tmpfile = "temp";
open(IN,"<",$logfile) || die "Can not open $logfile: $!";
$total = 0;
$total_rounded = 0;
while (<IN>) {
    my ($a, $b) = split('=');
    $total += $b;
print "total = $total\n";
open(OUT,">", $tmpfile) || die "Can not open $tmpfile: $!";
open(IN,"<",$logfile) || die "Can not open $logfile: $!";
while (<IN>) {
    my ($a, $b) = split('=');
    $rounded = sprintf("%.10f", ($b*100)/$total);
    $a =~ s/libld.so.1/LM1-ld.so.1/g;
    print OUT "$b   $rounded%   $a\n";
    $total_rounded += $rounded;
print "total rounded = $total_rounded\n";
`sort -n -r $tmpfile | tee $logfile.sorted`;
`rm $tmpfile`

This produced output of the following format :

20318357230394   16.4117840797%     poll                                      libc.so.1
20317702791746 16.4112554688% _pollsys libc.so.1
20313615393944 16.4079539474% __pollsys libc.so.1
2684593654698 2.1684317735% int DaemonSession::GetConnection() libns-httpd40.so


3. Using DTrace Profile Probes

 #!/usr/sbin/dtrace -s
/pid == $1 && arg1 != NULL/
    @proc[umod(arg1), ufunc(arg1),ustack()] = count(); 

run it as :

dtrace -x ustackframes=20 -s profiler-probes.d <pid> -o dtrace.log

It creates output in the format library name, function name, user stack and the count number of times called, newline

  libc.so.1                                           libc.so.1`mutex_lock_impl        


4. References

Be the first to comment

Comments ( 0 )
Please enter your name.Please provide a valid email address.Please enter a comment.CAPTCHA challenge response provided was incorrect. Please try again.