Re: Dtrace provider for perl?
Robert Spier wrote: The speaker at OSCON (name escapes me, and I'm somewhere over Northern California watching cloud to cloud lighting) who talked about dtrace (and demonstrated php) seems to have done some digging into this. He mentioned that doing this for perl will not be easy. Bryan Cantrill si the chap and as Dave already pointed out, he's right ;-) However it is far from impossible, and I think it is worth having a go. -- Alan Burlison --
Dtrace provider for perl?
Anyone interested in doing this? See http://blogs.sun.com/roller/page/bmc?entry=dtrace_and_php. Someone is already asking if this can be done from perl, see the comments to http://blogs.sun.com/roller/comments/bmc/Weblog/dtrace_and_php_demonstrated. Do we actually have enough information to give the same sort of output as for PHP (i.e. function/file/line number) without building a debugging perl? -- Alan Burlison --
Re: Dtrace provider for perl?
On Fri, Aug 05, 2005 at 08:22:58PM +0100, Alan Burlison wrote: Do we actually have enough information to give the same sort of output as for PHP (i.e. function/file/line number) without building a debugging perl? yes. -- My get-up-and-go just got up and went.
Re: Dtrace provider for perl?
Dave Mitchell wrote: yes. That's the kind of answer I like ;-) -- Alan Burlison --
Re: Dtrace provider for perl?
On Fri, Aug 05, 2005 at 08:32:43PM +0100, Alan Burlison wrote: That's the kind of answer I like ;-) Would you like me to elaborate? :-) -- In England there is a special word which means the last sunshine of the summer. That word is spring.
Re: Dtrace provider for perl?
Dave Mitchell wrote: Do we actually have enough information to give the same sort of output as for PHP (i.e. function/file/line number) without building a debugging perl? Hmm, having looked a the 165 lines of code needed to implement caller() I'm not sure that this is going to be lightweight enough to be practical. -- Alan Burlison --
Re: Dtrace provider for perl?
Dave Mitchell wrote: Would you like me to elaborate? :-) Yes :-) -- Alan Burlison --
Re: Dtrace provider for perl?
On Fri, Aug 05, 2005 at 09:24:29PM +0100, Alan Burlison wrote: Hmm, having looked a the 165 lines of code needed to implement caller() I'm not sure that this is going to be lightweight enough to be practical. Caller is mostly doing hard stuff. A lot depends on the detail of when and how the dtrace stuff gets called, but: in principle, at the point a sub is called, the associated CV can be found using cv=find_runcv(); CvGV(cv) will then give the typeglob associated with it, and thus the name; the first op pointed to by CvSTART(cv) should be a control op, which will give you the filename and line number of the start of the function. The hard bit is getting the dtrace stuff called at the right point. Not knowing how dtrace works, I can't really comment further. -- Fire extinguisher (n) a device for holding open fire doors.
Re: Dtrace provider for perl?
Dave Mitchell wrote: in principle, at the point a sub is called, the associated CV can be found using cv=find_runcv(); CvGV(cv) will then give the typeglob associated with it, and thus the name; the first op pointed to by CvSTART(cv) should be a control op, which will give you the filename and line number of the start of the function. Thanks, thet helps a whole bunch. The hard bit is getting the dtrace stuff called at the right point. Not knowing how dtrace works, I can't really comment further. It's as simple as inserting two calls to a macro to pass the relevant info through to dtrace. The rest is magic that takes place behind the scenes ;-) In the case of the PHP stuff I'd guess they are just passing the function name, filename and line number to dtrace at every function entry and exit. I guess we'd want to do the same - tracing each op dispatch would be way too expensive. -- Alan Burlison --
Re: Dtrace provider for perl?
On Fri, Aug 05, 2005 at 10:19:58PM +0100, Alan Burlison wrote: In the case of the PHP stuff I'd guess they are just passing the function name, filename and line number to dtrace at every function entry and exit. I guess we'd want to do the same - tracing each op dispatch would be way too expensive. If you're talking about producing a special perl binary that does this, it would be trivial - just a quick mod to pp_entersub. - wouldn't even need to call find_runcv, since entersub knws the CV its calling. Doing something via dynamically loadable XS would be harder - not sure how that could be done. -- Justice is when you get what you deserve. Law is when you get what you pay for.
Re: Dtrace provider for perl?
Dave Mitchell wrote: If you're talking about producing a special perl binary that does this, it would be trivial - just a quick mod to pp_entersub. - wouldn't even need to call find_runcv, since entersub knws the CV its calling. And a corresponding mod to pp_leavesub I guess and pp_leavesubv? Any suggestions for the best place to insert the trace call into pp_entersub? Somewhere around the 'now we have permission to enter the sub' comment? Doing something via dynamically loadable XS would be harder - not sure how that could be done. The whole point of dtrace probes is to leave them in place as they are lightweight enough to do so - the laptop I'm typing this on has 40,877 of them available in stock Solaris kernel, for example. I'm envisioning this being a Solaris-only build time option rather than a loadable module - as you point out it would be v. hard to do this from an XSUB. -- Alan Burlison --
Re: Dtrace provider for perl?
On Fri, Aug 05, 2005 at 10:57:11PM +0100, Alan Burlison wrote: Dave Mitchell wrote: If you're talking about producing a special perl binary that does this, it would be trivial - just a quick mod to pp_entersub. - wouldn't even need to call find_runcv, since entersub knws the CV its calling. And a corresponding mod to pp_leavesub I guess and pp_leavesubv? if you want to record leaving too, then you also need pp_return, pp_goto, *and* you need to handle all the cases of a non-normal exit from a sub, eg die trapped by eval, next LABEL where LABEL is outside the sub etc. This would be quite hard. Any suggestions for the best place to insert the trace call into pp_entersub? Somewhere around the 'now we have permission to enter the sub' comment? You're looking at 5.8.x code: in particular that comment is within a 5.005threads section that has been excised from bleed! In bleedperl, I'd suggest just before the RETURNOP(CvSTART(cv)); line. You'll also need to decide what to do when pp_enterusb is calling an XS sub; in this case there's no CvSTART(cv) op and so no way to deternine filename and line number (which makes sense, as there isn't a line number!). You also need to allow for perl -d, which causes pp_entersub to call DB::sub() each time rather than the real sub (it expects DB::Sub to call the real sub on your behalf) -- But Sidley Park is already a picture, and a most amiable picture too. The slopes are green and gentle. The trees are companionably grouped at intervals that show them to advantage. The rill is a serpentine ribbon unwound from the lake peaceably contained by meadows on which the right amount of sheep are tastefully arranged. -- Lady Croom - Arcadia
Re: Dtrace provider for perl?
Dave Mitchell wrote: If you're talking about producing a special perl binary that does this, it would be trivial - just a quick mod to pp_entersub. - wouldn't even need to call find_runcv, since entersub knws the CV its calling. And a corresponding mod to pp_leavesub I guess and pp_leavesubv? if you want to record leaving too, then you also need pp_return, pp_goto, *and* you need to handle all the cases of a non-normal exit from a sub, eg die trapped by eval, next LABEL where LABEL is outside the sub etc. This would be quite hard. Bah, there's always a catch. However 'hard' != 'impossible'. How easy is it to get the same info on the sub name, file and line at the various exit points? Any suggestions for the best place to insert the trace call into pp_entersub? Somewhere around the 'now we have permission to enter the sub' comment? You're looking at 5.8.x code: in particular that comment is within a 5.005threads section that has been excised from bleed! Yeah, I figured that out pretty soon after my last post ;-) In bleedperl, I'd suggest just before the RETURNOP(CvSTART(cv)); line. Done, thanks. You'll also need to decide what to do when pp_enterusb is calling an XS sub; in this case there's no CvSTART(cv) op and so no way to deternine filename and line number (which makes sense, as there isn't a line number!). You also need to allow for perl -d, which causes pp_entersub to call DB::sub() each time rather than the real sub (it expects DB::Sub to call the real sub on your behalf) Hmm, I think the sub name and XSUB as the filename, 0 as the number would be OK. As for running under the debugger, I'm not *too* worried about that, the purpose of dtrace is to let you trace whilst running normally, and the debugger isn't normal usage. I don't know exactly how the debugger works - does it eventually call back into pp_entersub to dispatch the sub 'for real'? Thanks for all your help BTW :-) -- Alan Burlison --
Re: Dtrace provider for perl?
On Sat, Aug 06, 2005 at 12:38:49AM +0100, Alan Burlison wrote:
Dave Mitchell wrote:
if you want to record leaving too, then you also need pp_return, pp_goto,
*and* you need to handle all the cases of a non-normal exit from a sub,
eg die trapped by eval, next LABEL where LABEL is outside the sub etc.
This would be quite hard.
Bah, there's always a catch. However 'hard' != 'impossible'. How easy
is it to get the same info on the sub name, file and line at the various
exit points?
You have to find all the places where perl pops the context stack (eg
Perl_dounwind() in pp_ctl.c), and each time it does a POPSUB(cx,sv), the
cx-blk_sub.cv field of the just-popped CX struct is the cv of the sub
being exited from.
Some subtle notes about popping the CX stack.
Some code just scans back through the context stack till it finds what
it's after (eg an eval block), and returns the index, *without* actually
popping anything, then later code actually does the popping.
macros like POPSUB don't actually decrement the context stack pointer;
they rely on something else to have already done it (eg POPBLOCK,
or an explicit cxstack_ix-- in the case of Perl_dounwind); all they
actually do is extract various values from the context block now perched
precariously one above the current stack top.
Perl actually has a stack of stacks. Whenever perl is about to do
something nasty (like call tie magic, or overload functions), it pushes a
new set of stacks, including a new context stack.
Some stack-unwinding functions (eg 'next LABEL_OUTSIDE_SUB') only scan
back through the current context stack; some (like eval/die) search back
through *all* context stacks.
Welcome to the whacky world of perl context!
I don't know exactly how the debugger works - does it eventually call
back into pp_entersub to dispatch the sub 'for real'?
No, it calls DB::sub() *instead* of the real sub, and sets $DB::sub to the
name of the sub which should be called. DB::sub() is then supposed to call
this sub on your behalf, and return any values; ie a minimal one would
look like
sub DB::sub { $DB::sub(@_) }
So the worst that will happen is that dtrace will show DB:sub being called
as well as the real sub
Thanks for all your help BTW :-)
No prob. Now, if only you could convince your superiors that my
consultancy fee is a twin-CPU V20z ;-)
--
Any [programming] language that doesn't occasionally surprise the
novice will pay for it by continually surprising the expert.
-- Larry Wall
Re: Dtrace provider for perl?
thinking further, your best strategy is probably to include the dtrace code in the PUSHSUB and POPSUB macros. -- This email is confidential, and now that you have read it you are legally obliged to shoot yourself. Or shoot a lawyer, if you prefer. If you have received this email in error, place it in its original wrapping and return for a full refund. By opening this email, you accept that Elvis lives.
Re: Dtrace provider for perl?
Dave Mitchell wrote:
[Lots of frightening stuff snipped]
Welcome to the whacky world of perl context!
Indeed.
I don't know exactly how the debugger works - does it eventually call
back into pp_entersub to dispatch the sub 'for real'?
No, it calls DB::sub() *instead* of the real sub, and sets $DB::sub to the
name of the sub which should be called. DB::sub() is then supposed to call
this sub on your behalf, and return any values; ie a minimal one would
look like
sub DB::sub { $DB::sub(@_) }
So the worst that will happen is that dtrace will show DB:sub being called
as well as the real sub
That would be fine.
Thanks for all your help BTW :-)
No prob. Now, if only you could convince your superiors that my
consultancy fee is a twin-CPU V20z ;-)
I'd want to convince them to supply one to me first ;-)
--
Alan Burlison
--
Re: Dtrace provider for perl?
Dave Mitchell wrote:
thinking further, your best strategy is probably to include the dtrace
code in the PUSHSUB and POPSUB macros.
Would that catch everything, or would I still have to instrument (for
example) pp_entersub?
As a taster, here's a trace of the following perl script:
--
#!/bin/perl
sub a { sleep(1); b(); }
sub b { sleep(1); c(); }
sub c { sleep(1); d(); }
sub d { sleep(1); }
while (1) { a(); }
--
which I instrumented with the following primitive D script:
--
#pragma D option quiet
perl_dtrace_execute$target:::function-entry
{
printf(PERL: %s %s:%d\n, copyinstr(arg0), copyinstr(arg1),
arg2);
}
pid$target:libc.so.1::entry
{
printf(LIBC: %s\n, probefunc);
}
fbt:genunix::entry
/pid == $target/
{
printf(KERNEL: %s\n, probefunc);
}
--
It isn't pretty-indented as I've only implemented the entry point
tracing, but you get the idea - you can follow the process down from
perl, into libc, across the syscall barrier, into the kernel and back
out again. Not only could you use dtrace to profile your perl script,
you could use it to profile the OS at the same time. And if you want to
know what the kernel code is doing, go to http://opensolaris.org where
the source is available, e.g.
http://cvs.opensolaris.org/source/xref/usr/src/uts/common/os/callout.c#106
# LD_LIBRARY_PATH=$PWD PERL5LIB=$PWD/lib ./perl upanddown
[1] 16508
# dtrace -s ./bryan.d -p 16508 | less
:
:
PERL: b upanddown:3
LIBC: time
LIBC: __time
KERNEL: syscall_mstate
KERNEL: gethrtime_unscaled
KERNEL: syscall_entry
KERNEL: pre_syscall
KERNEL: gtime
KERNEL: gethrestime
KERNEL: gethrtime
KERNEL: syscall_mstate
KERNEL: gethrtime_unscaled
KERNEL: syscall_mstate
KERNEL: gethrtime_unscaled
KERNEL: syscall_exit
KERNEL: post_syscall
KERNEL: thread_lock
KERNEL: disp_lock_exit
KERNEL: syscall_mstate
KERNEL: gethrtime_unscaled
LIBC: sleep
LIBC: ___nanosleep
KERNEL: syscall_mstate
KERNEL: gethrtime_unscaled
KERNEL: syscall_entry
KERNEL: pre_syscall
KERNEL: copyin_args32
KERNEL: copyin_nowatch
KERNEL: watch_disable_addr
KERNEL: nanosleep
KERNEL: gethrestime
KERNEL: gethrtime
KERNEL: timespecadd
KERNEL: cv_waituntil_sig
KERNEL: gethrestime
KERNEL: gethrtime
KERNEL: timespectohz_adj
KERNEL: timespecsub
KERNEL: timespecadd
KERNEL: cv_timedwait_sig
KERNEL: realtime_timeout
KERNEL: timeout_common
KERNEL: thread_lock
KERNEL: cv_block
KERNEL: new_mstate
KERNEL: gethrtime_unscaled
KERNEL: cpu_update_pct
KERNEL: scalehrtime
KERNEL: cpu_grow
KERNEL: cpu_decay
KERNEL: disp_lock_enter_high
KERNEL: disp_lock_exit_high
KERNEL: disp_lock_exit_nopreempt
KERNEL: disp_lock_enter
KERNEL: disp_lock_exit
KERNEL: restore_mstate
KERNEL: savectx
KERNEL: restorectx
KERNEL: untimeout
KERNEL: gethrestime
KERNEL: gethrtime
KERNEL: cv_waituntil_sig
KERNEL: gethrestime
KERNEL: gethrtime
KERNEL: timespectohz_adj
KERNEL: timespecsub
KERNEL: timespecadd
KERNEL: cv_timedwait_sig
KERNEL: realtime_timeout
KERNEL: timeout_common
KERNEL: thread_lock
KERNEL: cv_block
KERNEL: new_mstate
KERNEL: gethrtime_unscaled
KERNEL: cpu_update_pct
KERNEL: scalehrtime
KERNEL: cpu_grow
KERNEL: cpu_decay
KERNEL: disp_lock_enter_high
KERNEL: disp_lock_exit_high
KERNEL: disp_lock_exit_nopreempt
KERNEL: disp_lock_enter
KERNEL: disp_lock_exit
KERNEL: restore_mstate
KERNEL: savectx
KERNEL: restorectx
KERNEL: untimeout
KERNEL: gethrestime
KERNEL: gethrtime
KERNEL: syscall_mstate
KERNEL: gethrtime_unscaled
KERNEL: syscall_mstate
KERNEL: gethrtime_unscaled
KERNEL: syscall_exit
KERNEL: post_syscall
KERNEL: thread_lock
KERNEL: disp_lock_exit
KERNEL: syscall_mstate
KERNEL: gethrtime_unscaled
LIBC: time
LIBC: __time
KERNEL: syscall_mstate
KERNEL: gethrtime_unscaled
KERNEL: syscall_entry
KERNEL: pre_syscall
KERNEL: gtime
KERNEL: gethrestime
KERNEL: gethrtime
KERNEL: syscall_mstate
KERNEL: gethrtime_unscaled
KERNEL: syscall_mstate
KERNEL: gethrtime_unscaled
KERNEL: syscall_exit
KERNEL: post_syscall
KERNEL: thread_lock
KERNEL: disp_lock_exit
KERNEL: syscall_mstate
KERNEL: gethrtime_unscaled
LIBC: memcpy
PERL: c
Re: Dtrace provider for perl?
Do we actually have enough information to give the same sort of output as for PHP (i.e. function/file/line number) without building a debugging perl? Hmm, having looked a the 165 lines of code needed to implement caller() I'm not sure that this is going to be lightweight enough to be practical. The speaker at OSCON (name escapes me, and I'm somewhere over Northern California watching cloud to cloud lighting) who talked about dtrace (and demonstrated php) seems to have done some digging into this. He mentioned that doing this for perl will not be easy. -R
