Angelo and Michael,

 

Thank you very much , 

 

The results are much better now , don't see the absurd numbers as before , 

 

The thread scoping was the problem .

 

Got mislead by the absurd numbers  and was not able to comprehend the dtrace
output.

 

As a matter of fact the machine I ran on is a multiprocessor machine .

 

Thanks Again

 


Regards

Srikant Ramasubramanian
SWIFTNet Link

Tel: + 1(703) - 365- 6117

Fax: +  1(703) - 365 - 6410

Company name (e.g. 'S.W.I.F.T. SCRL' for users in BE) 

 <http://www.swiftcommunity.net/>
http://www.swift.com/temp/63340/97961/swiftcommunitybutton.gif

This e-mail and any attachments thereto may contain information which is
confidential and/or proprietary and intended for the sole use of the
recipient(s) named above. If you have received this e-mail in error, please
immediately notify the sender and delete the mail. Thank you for your
co-operation. SWIFT reserves the right to retain e-mail messages on its
systems and, under circumstances permitted by applicable law, to monitor and
intercept e-mail messages to and from its systems. Please visit
www.swift.com for more information about SWIFT. 

 

From: dtrace-discuss-boun...@opensolaris.org
[mailto:dtrace-discuss-boun...@opensolaris.org] On Behalf Of Angelo
Rajadurai
Sent: Wednesday, January 05, 2011 12:53 PM
To: Michael Ernest
Cc: dtrace-discuss@opensolaris.org
Subject: Re: [dtrace-discuss] Understand the dtrace quantize output
(RAMASUBRAMANIAN Srikant)

 

This might be nit picking but a small correction in Michael's solution.
Because "pid$1:libswduar::entry" will match with all the functions in the
libswduar library you may want to keep the thread local timestamp for each
function. So something like 

 

pid$1:libswduar::entry
{
       @duarCount[probefunc] = count();
       self->ts[probefunc] = timestamp;
}

pid$1:libswduar::entry
/ self->ts[probefunc] /
{
       @timeBand[probefunc] = quantize(timestamp - self->ts[probefunc]);

            self->ts[probefunc]=0;       

}

 

-Angelo

 

 

On Jan 5, 2011, at 12:46 PM, Michael Ernest wrote:





Hello Srikant -


Apologies for the first send, my browser fu went wrong.

A quantization distributes the results of your aggregation into ranges
ordered by a power-of-two. Presumably what you'd do in your script is
capture the inclusive elapsed time of each function call in your library,
then use this quantization to see how tightly-banded the times are. Perhaps
there's some blocking I/O in some of your calls, for example, in which case
you might expect a wide difference with functions that don't.

I've annotated your code to show what you're actually doing:


pid$1:libswduar::entry
{
       // Associative array indexing timestamps by function call
       duarEntry[probefunc] = timestamp;

       // Aggregation to count each function invoked


       @duarCount[probefunc] = count();
}

pid$1:libswduar::return
{

       // Compute elapsed time in milliseconds


       this->elapsed = (timestamp - duarEntry[probefunc])/1000000;

       // Quantize elapsed time per function call


       @totduarTime[probefunc] = quantize(this->elapsed);

       // Zero out array element
       duarEntry[probefunc] = 0;
}

That said, your output doesn't make sense, unless you are in fact waiting 2
billion-plus milliseconds on 21 of your LDAP searches. Or maybe you're using
ActiveDirectory. Joking aside, I'd guess the problem is that the trace code
assumes a single-threaded, single-CPU model. A more general solution tracks
each function call by thread:

pid$1:libswduar::entry
{
       @duarCount[probefunc] = count();
       self->ts = timestamp;

}

pid$1:libswduar::entry
/ self->ts /
{
       @timeBand[probefunc] = quantize(timestamp - self->ts);       
}

Note I have used a predicate in the return probe to ensure we've seen the
current thread on entry. It's quite possible with a running process to
capture the return only, which will give you some funky values.

I left out the reduction to milliseconds which you can certainly put back
in, although I think microseconds would make more sense on a first pass.
With microseconds you'll clearly see a difference between in-memory ops vs.
I/O ops instead of truncating the former to zeroes.

Hope this helps,

Michael

On Wed, Jan 5, 2011 at 8:48 AM, <dtrace-discuss-requ...@opensolaris.org>
wrote:

Send dtrace-discuss mailing list submissions to
       dtrace-discuss@opensolaris.org

To subscribe or unsubscribe via the World Wide Web, visit
       http://mail.opensolaris.org/mailman/listinfo/dtrace-discuss
or, via email, send a message with subject or body 'help' to
       dtrace-discuss-requ...@opensolaris.org

You can reach the person managing the list at
       dtrace-discuss-ow...@opensolaris.org

When replying, please edit your Subject line so it is more specific
than "Re: Contents of dtrace-discuss digest..."


Today's Topics:

  1. Understand the dtrace quantize output (RAMASUBRAMANIAN Srikant)


----------------------------------------------------------------------

Message: 1
Date: Wed, 5 Jan 2011 17:47:24 +0100
From: RAMASUBRAMANIAN Srikant <srikant.ramasubraman...@swift.com>
To: "dtrace-discuss@opensolaris.org" <dtrace-discuss@opensolaris.org>
Subject: [dtrace-discuss] Understand the dtrace quantize output
Message-ID:
 
<1759decb91276e4083d703a908840be7e140dde...@be-exchange-10.swift.corp>
Content-Type: text/plain; charset="us-ascii"

Hi,



I am kind of new to DTrace , I have written a script to time function calls
in our application library ,



Wanted to know how to interpret the output from quantize of the elapsed time
in each function call  , here is a sample



Here is the entry and return function for the library that is being traced



pid$1:libswduar::entry
{
       duarEntry[probefunc] = timestamp;
       @duarCount[probefunc] = count();
}

pid$1:libswduar::return

{
       this->elapsed = (timestamp - duarEntry[probefunc])/1000000;
       @totduarTime[probefunc] = quantize(this->elapsed);
       duarEntry[probefunc] = 0;
}



LdapSearchRequest



          value  ------------- Distribution ------------- count

             -1 |                                         0

              0 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@      147

              1 |                                         0

              2 |                                         0

              4 |                                         0

              8 |                                         0

             16 |                                         0

             32 |                                         0

             64 |                                         0

            128 |                                         0

            256 |                                         0

            512 |                                         0

           1024 |                                         0

           2048 |                                         0

           4096 |                                         0

           8192 |                                         0

          16384 |                                         0

          32768 |                                         0

          65536 |                                         0

         131072 |                                         0

         262144 |                                         0

         524288 |                                         0

        1048576 |                                         0

        2097152 |                                         0

        4194304 |                                         0

        8388608 |                                         0

       16777216 |                                         0

       33554432 |                                         0

       67108864 |                                         0

      134217728 |                                         0

      268435456 |                                         0

      536870912 |                                         0

     1073741824 |                                         0

     2147483648 |@@@@@                                    21

     4294967296 |                                         0



Thanks & Regards

Srikant Ramasubramanian
SWIFTNet Link

Tel: + 1(703) - 365- 6117

Fax: +  1(703) - 365 - 6410

Company name (e.g. 'S.W.I.F.T. SCRL' for users in BE)

 <http://www.swiftcommunity.net/>
http://www.swift.com/temp/63340/97961/swiftcommunitybutton.gif

This e-mail and any attachments thereto may contain information which is
confidential and/or proprietary and intended for the sole use of the
recipient(s) named above. If you have received this e-mail in error, please
immediately notify the sender and delete the mail. Thank you for your
co-operation. SWIFT reserves the right to retain e-mail messages on its
systems and, under circumstances permitted by applicable law, to monitor and
intercept e-mail messages to and from its systems. Please visit
www.swift.com <http://www.swift.com/>  for more information about SWIFT.



-------------- next part --------------
An HTML attachment was scrubbed...
URL:
<http://mail.opensolaris.org/pipermail/dtrace-discuss/attachments/20110105/0
c91ef92/attachment.html>
-------------- next part --------------
A non-text attachment was scrubbed...
Name: not available
Type: image/gif
Size: 5953 bytes
Desc: not available
URL:
<http://mail.opensolaris.org/pipermail/dtrace-discuss/attachments/20110105/0
c91ef92/attachment.gif>
-------------- next part --------------
A non-text attachment was scrubbed...
Name: smime.p7s
Type: application/x-pkcs7-signature
Size: 5043 bytes
Desc: not available
URL:
<http://mail.opensolaris.org/pipermail/dtrace-discuss/attachments/20110105/0
c91ef92/attachment.bin>

------------------------------

_______________________________________________
dtrace-discuss mailing list
dtrace-discuss@opensolaris.org

End of dtrace-discuss Digest, Vol 69, Issue 2
*********************************************





-- 
Michael Ernest
Inkling Research, Inc.




-- 
Michael Ernest
Inkling Research, Inc.
_______________________________________________
dtrace-discuss mailing list
dtrace-discuss@opensolaris.org

 

<<image001.gif>>

Attachment: smime.p7s
Description: S/MIME cryptographic signature

_______________________________________________
dtrace-discuss mailing list
dtrace-discuss@opensolaris.org

Reply via email to