9 # define dTHR int dummy_thr
12 /*#define DBG_SUB 1 /* */
13 /*#define DBG_TIMER 1 /* */
16 # define DBG_SUB_NOTIFY(A,B) warn( A, B )
18 # define DBG_SUB_NOTIFY(A,B) /* nothing */
22 # define DBG_TIMER_NOTIFY(A) warn( A )
24 # define DBG_TIMER_NOTIFY(A) /* nothing */
27 static U32 dprof_ticks;
29 /* HZ == clock ticks per second */
33 # include <starlet.h> /* prototype for sys$gettim() */
34 clock_t dprof_times(struct tms *bufptr) {
36 /* Get wall time and convert to 10 ms intervals to
37 * produce the return value dprof expects */
38 # if defined(__DECC) && defined (__ALPHA)
41 _ckvmssts(sys$gettim(&vmstime));
43 retval = vmstime & 0x7fffffff;
45 /* (Older hw or ccs don't have an atomic 64-bit type, so we
46 * juggle 32-bit ints (and a float) to produce a time_t result
47 * with minimal loss of information.) */
48 long int vmstime[2],remainder,divisor = 100000;
49 _ckvmssts(sys$gettim((unsigned long int *)vmstime));
50 vmstime[1] &= 0x7fff; /* prevent overflow in EDIV */
51 _ckvmssts(lib$ediv(&divisor,vmstime,(long int *)&retval,&remainder));
53 /* Fill in the struct tms using the CRTL routine . . .*/
54 times((tbuffer_t *)bufptr);
55 return (clock_t) retval;
57 # define Times(ptr) (dprof_times(ptr))
66 # ifdef OS2 /* times() has significant overhead */
67 # define Times(ptr) (dprof_times(ptr))
68 # define INCL_DOSPROFILE
69 # define INCL_DOSERRORS
71 # define toLongLong(arg) (*(long long*)&(arg))
72 # define DPROF_HZ dprof_ticks
75 static long long start_cnt;
77 dprof_times(struct tms *t)
83 if (CheckOSError(DosTmrQueryFreq(&frequ)))
84 croak("DosTmrQueryFreq: %s", SvPV(perl_get_sv("!",TRUE),na));
86 frequ = frequ/DPROF_HZ; /* count per tick */
87 if (CheckOSError(DosTmrQueryTime(&cnt)))
88 croak("DosTmrQueryTime: %s",
89 SvPV(perl_get_sv("!",TRUE),na));
90 start_cnt = toLongLong(cnt);
93 if (CheckOSError(DosTmrQueryTime(&cnt)))
94 croak("DosTmrQueryTime: %s", SvPV(perl_get_sv("!",TRUE),na));
96 return (t->tms_utime = (toLongLong(cnt) - start_cnt)/frequ);
99 # define Times(ptr) (times(ptr))
104 XS(XS_Devel__DProf_END); /* used by prof_mark() */
106 static SV * Sub; /* pointer to $DB::sub */
107 static PerlIO *fp; /* pointer to tmon.out file */
110 static long TIMES_LOCATION=42;/* Where in the file to store the time totals */
111 static int SAVE_STACK = 1<<14; /* How much data to buffer until */
114 static int prof_pid; /* pid of profiled process */
116 /* Everything is built on times(2). See its manpage for a description
121 struct tms prof_start,
125 clock_t rprof_start, /* elapsed real time, in ticks */
127 wprof_u, wprof_s, wprof_r;
130 clock_t tms_utime; /* cpu time spent in user space */
131 clock_t tms_stime; /* cpu time spent in system */
132 clock_t realtime; /* elapsed real time, in ticks */
138 typedef union prof_any PROFANY;
140 static PROFANY *profstack;
141 static int profstack_max = 128;
142 static int profstack_ix = 0;
145 prof_dump(opcode ptype, char *name)
147 if(ptype == OP_LEAVESUB){
148 PerlIO_printf(fp,"- & %s\n", name );
149 } else if(ptype == OP_ENTERSUB) {
150 PerlIO_printf(fp,"+ & %s\n", name );
151 } else if(ptype == OP_DIE) {
152 PerlIO_printf(fp,"/ & %s\n", name );
154 PerlIO_printf(fp,"Profiler unknown prof code %d\n", ptype);
160 prof_dumpa(opcode ptype, U32 id)
162 if(ptype == OP_LEAVESUB){
163 PerlIO_printf(fp,"- %lx\n", id );
164 } else if(ptype == OP_ENTERSUB) {
165 PerlIO_printf(fp,"+ %lx\n", id );
166 } else if(ptype == OP_GOTO) {
167 PerlIO_printf(fp,"* %lx\n", id );
168 } else if(ptype == OP_DIE) {
169 PerlIO_printf(fp,"/ %lx\n", id );
171 PerlIO_printf(fp,"Profiler unknown prof code %d\n", ptype);
176 prof_dumps(U32 id, char *pname, char *gname)
178 PerlIO_printf(fp,"& %lx %s %s\n", id, pname, gname);
181 static clock_t otms_utime, otms_stime, orealtime;
184 prof_dumpt(long tms_utime, long tms_stime, long realtime)
186 PerlIO_printf(fp,"@ %ld %ld %ld\n", tms_utime, tms_stime, realtime);
190 prof_dump_until(long ix)
194 clock_t realtime1, realtime2;
196 realtime1 = Times(&t1);
199 opcode ptype = profstack[base++].ptype;
200 if (ptype == OP_TIME) {
201 long tms_utime = profstack[base++].tms_utime;
202 long tms_stime = profstack[base++].tms_stime;
203 long realtime = profstack[base++].realtime;
205 prof_dumpt(tms_utime, tms_stime, realtime);
206 } else if (ptype == OP_GV) {
207 U32 id = profstack[base++].id;
208 char *pname = profstack[base++].name;
209 char *gname = profstack[base++].name;
211 prof_dumps(id, pname, gname);
213 #ifdef PERLDBf_NONAME
214 U32 id = profstack[base++].id;
215 prof_dumpa(ptype, id);
217 char *name = profstack[base++].name;
218 prof_dump(ptype, name);
223 realtime2 = Times(&t2);
224 if (realtime2 != realtime1 || t1.tms_utime != t2.tms_utime
225 || t1.tms_stime != t2.tms_stime) {
226 wprof_r += realtime2 - realtime1;
227 wprof_u += t2.tms_utime - t1.tms_utime;
228 wprof_s += t2.tms_stime - t1.tms_stime;
230 PerlIO_printf(fp,"+ & Devel::DProf::write\n" );
231 PerlIO_printf(fp,"@ %ld %ld %ld\n",
232 t2.tms_utime - t1.tms_utime, t2.tms_stime - t1.tms_stime,
233 realtime2 - realtime1);
234 PerlIO_printf(fp,"- & Devel::DProf::write\n" );
235 otms_utime = t2.tms_utime;
236 otms_stime = t2.tms_stime;
237 orealtime = realtime2;
243 static U32 total = 0;
250 clock_t realtime, rdelta, udelta, sdelta;
258 if( profstack_ix + 5 > profstack_max ){
259 profstack_max = profstack_max * 3 / 2;
260 Renew( profstack, profstack_max, PROFANY );
264 realtime = Times(&t);
265 rdelta = realtime - orealtime;
266 udelta = t.tms_utime - otms_utime;
267 sdelta = t.tms_stime - otms_stime;
268 if (rdelta || udelta || sdelta) {
270 profstack[profstack_ix++].ptype = OP_TIME;
271 profstack[profstack_ix++].tms_utime = udelta;
272 profstack[profstack_ix++].tms_stime = sdelta;
273 profstack[profstack_ix++].realtime = rdelta;
274 } else { /* Write it to disk now so's not to eat up core */
275 if (prof_pid == (int)getpid()) {
276 prof_dumpt(udelta, sdelta, rdelta);
280 orealtime = realtime;
281 otms_stime = t.tms_stime;
282 otms_utime = t.tms_utime;
285 #ifdef PERLDBf_NONAME
292 cv = (CV*)SvIVX(Sub);
293 svp = hv_fetch(cv_hash, (char*)&cv, sizeof(CV*), TRUE);
297 sv_setiv(*svp, id = ++lastid);
298 pname = ((GvSTASH(gv) && HvNAME(GvSTASH(gv)))
299 ? HvNAME(GvSTASH(gv))
302 if (CvXSUB(cv) == XS_Devel__DProf_END)
304 if (SAVE_STACK) { /* Store it for later recording -JH */
305 profstack[profstack_ix++].ptype = OP_GV;
306 profstack[profstack_ix++].id = id;
307 profstack[profstack_ix++].name = pname;
308 profstack[profstack_ix++].name = gname;
309 } else { /* Write it to disk now so's not to eat up core */
311 /* Only record the parent's info */
312 if (prof_pid == (int)getpid()) {
313 prof_dumps(id, pname, gname);
316 perldb = 0; /* Do not debug the kid. */
323 pv = SvPV( Sub, len );
326 /* Attempt to make CODE refs slightly identifiable by
327 * including their package name.
330 if( sv && SvTYPE(sv) == SVt_PVCV ){
332 hvname = HvNAME(CvSTASH(sv));
334 else if( CvXSUB(sv) == &XS_Devel__DProf_END ){
335 /*warn( "prof_mark() found dprof::end");*/
336 return; /* don't profile Devel::DProf::END */
339 croak( "DProf prof_mark() lost on CODE ref %s\n", pv );
341 len += strlen( hvname ) + 2; /* +2 for ::'s */
345 croak( "DProf prof_mark() lost on supposed CODE ref %s.\n", pv );
347 name = (char *)safemalloc( len * sizeof(char) + 1 );
348 strcpy( name, hvname );
349 strcat( name, "::" );
353 if( *(pv+len-1) == 'D' ){
354 /* It could be an &AUTOLOAD. */
356 /* I measured a bunch of *.pl and *.pm (from Perl
357 * distribution and other misc things) and found
358 * 780 fully-qualified names. They averaged
359 * about 19 chars each. Only 1 of those names
360 * ended with 'D' and wasn't an &AUTOLOAD--it
361 * was &overload::OVERLOAD.
365 if( strcmp( pv+len-9, ":AUTOLOAD" ) == 0 ){
366 /* The sub name is in $AUTOLOAD */
367 sv = perl_get_sv( pv, 0 );
369 croak("DProf prof_mark() lost on AUTOLOAD (%s).\n", pv );
372 DBG_SUB_NOTIFY( " AUTOLOAD(%s)\n", pv );
377 #endif /* PERLDBf_NONAME */
380 if (SAVE_STACK) { /* Store it for later recording -JH */
381 profstack[profstack_ix++].ptype = ptype;
382 #ifdef PERLDBf_NONAME
383 profstack[profstack_ix++].id = id;
385 profstack[profstack_ix++].name = name;
387 /* Only record the parent's info */
388 if (SAVE_STACK < profstack_ix) {
389 if (prof_pid == (int)getpid())
390 prof_dump_until(profstack_ix);
392 perldb = 0; /* Do not debug the kid. */
395 } else { /* Write it to disk now so's not to eat up core */
397 /* Only record the parent's info */
398 if (prof_pid == (int)getpid()) {
399 #ifdef PERLDBf_NONAME
400 prof_dumpa(ptype, id);
402 prof_dump(ptype, name);
406 perldb = 0; /* Do not debug the kid. */
410 static U32 default_perldb;
413 # define defstash PL_defstash
416 /* Counts overhead of prof_mark and extra XS call. */
418 test_time(clock_t *r, clock_t *u, clock_t *s)
421 CV *cv = perl_get_cv("Devel::DProf::NONESUCH_noxs", FALSE);
423 HV *oldstash = curstash;
425 clock_t realtime1, realtime2;
427 U32 ostack = SAVE_STACK;
428 U32 operldb = perldb;
430 SAVE_STACK = 1000000;
431 realtime1 = Times(&t1);
435 /* Disable debugging of perl_call_sv on second pass: */
436 curstash = (k == 0 ? defstash : debstash);
437 perldb = default_perldb;
440 profstack_ix = 0; /* Do not let the stack grow */
442 /* prof_mark( OP_ENTERSUB ); */
444 PUSHMARK( stack_sp );
445 perl_call_sv( (SV*)cv, G_SCALAR );
447 /* prof_mark( OP_LEAVESUB ); */
451 if (k == 0) { /* Put time with debugging */
452 realtime2 = Times(&t2);
453 *r = realtime2 - realtime1;
454 *u = t2.tms_utime - t1.tms_utime;
455 *s = t2.tms_stime - t1.tms_stime;
456 } else { /* Subtract time without debug */
457 realtime1 = Times(&t1);
458 *r -= realtime1 - realtime2;
459 *u -= t1.tms_utime - t2.tms_utime;
460 *s -= t1.tms_stime - t2.tms_stime;
474 /* fp is opened in the BOOT section */
475 PerlIO_printf(fp, "#fOrTyTwO\n" );
476 PerlIO_printf(fp, "$hz=%d;\n", DPROF_HZ );
477 PerlIO_printf(fp, "$XS_VERSION='DProf %s';\n", XS_VERSION );
478 PerlIO_printf(fp, "# All values are given in HZ\n" );
479 test_time(&r, &u, &s);
480 PerlIO_printf(fp, "$over_utime=%ld; $over_stime=%ld; $over_rtime=%ld;\n",
482 PerlIO_printf(fp, "$over_tests=10000;\n");
484 TIMES_LOCATION = ftell(fp);
486 /* Pad with whitespace. */
487 /* This should be enough even for very large numbers. */
488 PerlIO_printf(fp, "%*s\n", 240 , "");
490 PerlIO_printf(fp, "\n");
491 PerlIO_printf(fp, "PART2\n" );
499 /* fp is opened in the BOOT section */
501 /* Now that we know the runtimes, fill them in at the recorded
507 prof_dump_until(profstack_ix);
509 fseek(fp, TIMES_LOCATION, SEEK_SET);
510 /* Write into reserved 240 bytes: */
511 PerlIO_printf(fp, "$rrun_utime=%ld; $rrun_stime=%ld; $rrun_rtime=%ld;",
512 prof_end.tms_utime - prof_start.tms_utime - wprof_u,
513 prof_end.tms_stime - prof_start.tms_stime - wprof_s,
514 rprof_end - rprof_start - wprof_r );
515 PerlIO_printf(fp, "\n$total_marks=%ld;", total);
522 static U32 depth = 0;
525 check_depth(void *foo)
527 U32 need_depth = (U32)foo;
528 if (need_depth != depth) {
529 if (need_depth > depth) {
530 warn("garbled call depth when profiling");
532 I32 marks = depth - need_depth;
534 /* warn("Check_depth: got %d, expected %d\n", depth, need_depth); */
550 HV *oldstash = curstash;
554 DBG_SUB_NOTIFY( "XS DBsub(%s)\n", SvPV(Sub, na) );
556 #ifndef PERLDBf_NONAME /* Was needed on older Perls */
557 sv_setiv( DBsingle, 0 ); /* disable DB single-stepping */
560 SAVEDESTRUCTOR(check_depth, (void*)depth);
563 prof_mark( OP_ENTERSUB );
564 PUSHMARK( ORIGMARK );
567 perl_call_sv( (SV*)SvIV(Sub), GIMME | G_NODEBUG);
569 curstash = debstash; /* To disable debugging of perl_call_sv */
570 #ifdef PERLDBf_NONAME
571 perl_call_sv( (SV*)SvIV(Sub), GIMME );
573 perl_call_sv( Sub, GIMME );
578 prof_mark( OP_LEAVESUB );
588 prof_mark( OP_GOTO );
592 #endif /* for_real */
596 MODULE = Devel::DProf PACKAGE = DB
603 HV *oldstash = curstash;
604 /* SP -= items; added by xsubpp */
605 DBG_SUB_NOTIFY( "XS DBsub(%s)\n", SvPV(Sub, na) );
607 sv_setiv( DBsingle, 0 ); /* disable DB single-stepping */
609 prof_mark( OP_ENTERSUB );
610 PUSHMARK( ORIGMARK );
612 curstash = debstash; /* To disable debugging of perl_call_sv
614 perl_call_sv( Sub, GIMME );
617 prof_mark( OP_LEAVESUB );
619 /* PUTBACK; added by xsubpp */
623 MODULE = Devel::DProf PACKAGE = Devel::DProf
629 /* maybe the process forked--we want only
630 * the parent's profile.
632 if( prof_pid == (int)getpid() ){
633 rprof_end = Times(&prof_end);
634 DBG_TIMER_NOTIFY("Profiler timer is off.\n");
643 /* Before we go anywhere make sure we were invoked
644 * properly, else we'll dump core.
647 croak("DProf: run perl with -d to use DProf.\n");
649 /* When we hook up the XS DB::sub we'll be redefining
650 * the DB::sub from the PM file. Turn off warnings
654 I32 warn_tmp = dowarn;
656 newXS("DB::sub", XS_DB_sub, file);
657 newXS("DB::goto", XS_DB_goto, file);
661 Sub = GvSV(DBsub); /* name of current sub */
662 sv_setiv( DBsingle, 0 ); /* disable DB single-stepping */
665 char *buffer = getenv("PERL_DPROF_BUFFER");
668 SAVE_STACK = atoi(buffer);
671 buffer = getenv("PERL_DPROF_TICKS");
674 dprof_ticks = atoi(buffer); /* Used under OS/2 only */
680 if( (fp = fopen( "tmon.out", "w" )) == NULL )
681 croak("DProf: unable to write tmon.out, errno = %d\n", errno );
682 #ifdef PERLDBf_NONAME
683 default_perldb = PERLDBf_NONAME | PERLDBf_SUB; /* no name needed. */
685 default_perldb = default_perldb | PERLDBf_GOTO;
690 default_perldb = PERLDBf_SUB; /* debug subroutines only. */
693 prof_pid = (int)getpid();
695 New( 0, profstack, profstack_max, PROFANY );
699 DBG_TIMER_NOTIFY("Profiler timer is on.\n");
700 orealtime = rprof_start = Times(&prof_start);
701 otms_utime = prof_start.tms_utime;
702 otms_stime = prof_start.tms_stime;
703 perldb = default_perldb;