dtrace discuss - Mar 2008 - Peeking into an already executing function

Hello,

I''ve read the example code in /usr/demo/dtrace and the "DTrace
user
guide". I can write simple D scripts which use :::entry and :::return
but cannot figure out how to peek into a function that has already begun
executing. This function would typically be a few levels down the stack
and the app is multi-threaded.


Can someone please help? Even a rough pointer into the docs for me to
RTFM would be good.

Thanks

-Gautam

Hi,
> I''ve read the example code in /usr/demo/dtrace and the
"DTrace user
> guide". I can write simple D scripts which use :::entry and :::return
> but cannot figure out how to peek into a function that has already begun
> executing. This function would typically be a few levels down the stack
> and the app is multi-threaded.
I''m afraid your question is not good enough to give good enough answer
;) My understanding is that you want to know how to place probe into
random position inside function, not just :::begin and :::end.

Are you talking about userland or kernel?



If you are talking about kernel _fbt_ provider, it gives you fbt:::entry
and fbt:::return, which corresponds to first and last instruction in the
function (the last function is not very exact as there may be several
returns in the code).



If you are talking about userland, the _pid_ provider, it gives you
access to nearly every instruction in the code. For example, listing
every assembly instruction in the grep(1), function ''succeed'',
you may
do

$ dtrace -l -n ''pid$target:grep:succeed:'' -c grep | head
   ID   PROVIDER            MODULE                          FUNCTION NAME
73886    pid5865              grep                           succeed return
73887    pid5865              grep                           succeed entry
73888    pid5865              grep                           succeed 0
73889    pid5865              grep                           succeed 1
73890    pid5865              grep                           succeed 3
73891    pid5865              grep                           succeed 6
73892    pid5865              grep                           succeed a
73893    pid5865              grep                           succeed c
73894    pid5865              grep                           succeed 13
...

So if you know where to place the probe, you may use

$ dtrace -n ''pid$target:grep:succeed:13''



There is another option, called static probes.

http://docs.sun.com/app/docs/doc/817-6223/chp-usdt?a=view

This lets you to create placeholder for possible named probes at
arbitrary places. But if you want to create new one, you have to
recompile the module/application.

I hope I answered you question. If not, sorry :)

-- 
	Vlad
-------------- next part --------------
A non-text attachment was scrubbed...
Name: not available
Type: application/pgp-signature
Size: 193 bytes
Desc: not available
URL:
<http://mail.opensolaris.org/pipermail/dtrace-discuss/attachments/20080331/76c08a30/attachment.bin>

> I''m afraid your question is not good enough to give good enough
answer
Doh!
> Are you talking about userland or kernel?
I am talking about a userland application which does database queries.
To simplify, let''s say main() calls A(). Sometimes A takes too long to
return, so I want to know what parameters were passed (maybe the query
is too broad or inefficient). If I run a DTrace script at this point,
the pid$1::A:entry fbt provider will not be triggered and
pid$1::A:return will be too late (because the problem does not exist
anymore). If A() is a small function, then I could put a probe on every
instruction but in this case it is complex and calls many other functions.
> There is another option, called static probes.
I can''t recompile the application :( I''m just a support guy.
> I hope I answered you question. If not, sorry :)
Thank you, much appreciated.

Regards
-Gautam

Gautam Gopalakrishnan wrote:
> I am talking about a userland application which does database queries.
> To simplify, let''s say main() calls A(). Sometimes A takes too
long to
> return, so I want to know what parameters were passed (maybe the query
> is too broad or inefficient).
So far, it sounds like what you''re looking for is simply a good old 
fashioned debugger.  For example, "mdb -p <pid>" will attach to
the
process of choice and stop it, and "$c" will print a stack backtrace.

-Seb

Gautam Gopalakrishnan wrote:
>> I''m afraid your question is not good enough to give good
enough answer
> 
> Doh!
> 
>> Are you talking about userland or kernel?
> 
> I am talking about a userland application which does database queries.
> To simplify, let''s say main() calls A(). Sometimes A takes too
long to
> return, so I want to know what parameters were passed (maybe the query
> is too broad or inefficient). If I run a DTrace script at this point,
> the pid$1::A:entry fbt provider will not be triggered and
> pid$1::A:return will be too late (because the problem does not exist
> anymore). If A() is a small function, then I could put a probe on every
> instruction but in this case it is complex and calls many other functions.
there is a standard technique of "set a flag when you enter a function,
reset it when you leave; then, while the flag is set, trace *every*
function"
that can help at answering questions like this.  It''s got to be example
3 in
nearly every DTrace presentation.

If you app is spinning in userland, you want to try profiling.

  profile-1001/{pid == <targetpid>/{@[ustack()] = count()}

That should give you an idea of what the busiest userland stack look
like.  You can then use mdb or the pid provider to zoom in on that
function.

On Tue, Apr 1, 2008 at 6:45 AM, Gautam Gopalakrishnan
<Gautam.Gopalakrishnan at sun.com> wrote:
> > I''m afraid your question is not good enough to give good
enough answer
>
>  Doh!
>
>
>  > Are you talking about userland or kernel?
>
>  I am talking about a userland application which does database queries.
>  To simplify, let''s say main() calls A(). Sometimes A takes too
long to
>  return, so I want to know what parameters were passed (maybe the query
>  is too broad or inefficient). If I run a DTrace script at this point,
>  the pid$1::A:entry fbt provider will not be triggered and
>  pid$1::A:return will be too late (because the problem does not exist
>  anymore). If A() is a small function, then I could put a probe on every
>  instruction but in this case it is complex and calls many other functions.
>
>
>  > There is another option, called static probes.
>
>  I can''t recompile the application :( I''m just a support
guy.
>
>
>  > I hope I answered you question. If not, sorry :)
>
>  Thank you, much appreciated.
>
>  Regards
>
>
> -Gautam
>  _______________________________________________
>  dtrace-discuss mailing list
>  dtrace-discuss at opensolaris.org
>


-- 
Just me,
Wire ...
Blog: <prstat.blogspot.com>

> > Are you talking about userland or kernel?
> 
> I am talking about a userland application which does database queries.
> To simplify, let''s say main() calls A(). Sometimes A takes too
long to
> return, so I want to know what parameters were passed (maybe the query
> is too broad or inefficient).
[...]

With dtrace you are out of luck at this time. But would it be too
inefficient to run DTrace all the time and log parameters every time you
enter the function ? If you set probe to both begin and end of the
function, you can easily measure the time it took, and log something
like

"param a, param b, param c -> 123 ms"

for every A() call you do.

Instead of running

$ query blah blah

You do

$ dtrace -o /var/tmp/log \
  -c ''query blah blah'' \
  -n ''
   pid$target::A:entry
   {
	self->start = timestamp;
	trace(arg0);
	trace(arg1)
   }

   pid$target::A:return
   /self->start/
   {
	trace(timestamp - self->start);
	self->start=0;
   }''

> If I run a DTrace script at this point,
> the pid$1::A:entry fbt provider will not be triggered and
> pid$1::A:return will be too late (because the problem does not exist
> anymore). If A() is a small function, then I could put a probe on every
> instruction but in this case it is complex and calls many other functions.
Hmm, one way to tackle this might be to find out first what makes the
query to take long (if possible, it might not be caused by the client
but rather by the server, in which case sampling client will not help).

Hope this helps

-- 
	Vlad
-------------- next part --------------
A non-text attachment was scrubbed...
Name: not available
Type: application/pgp-signature
Size: 193 bytes
Desc: not available
URL:
<http://mail.opensolaris.org/pipermail/dtrace-discuss/attachments/20080401/531bc815/attachment.bin>

Hi Gautam,
> I am talking about a userland application which does database
> queries. To simplify, let''s say main() calls A(). Sometimes A
takes
> too long to return, so I want to know what parameters were passed
> (maybe the query is too broad or inefficient). If I run a DTrace
> script at this point, the pid$1::A:entry fbt provider will not be
> triggered and pid$1::A:return will be too late (because the problem
> does not exist anymore). If A() is a small function, then I could put
> a probe on every instruction but in this case it is complex and calls
> many other functions.
You could use speculations. In other words, trace every entry to A() as 
a speculation but only commit if the return probe fires late.

-- Peter

-------------- next part --------------
A non-text attachment was scrubbed...
Name: smime.p7s
Type: application/x-pkcs7-signature
Size: 3249 bytes
Desc: S/MIME Cryptographic Signature
URL:
<http://mail.opensolaris.org/pipermail/dtrace-discuss/attachments/20080402/6ebfd4f3/attachment.bin>