8 #define smCommand "smap 2> /dev/null < "
28 #define unlikely(x) __builtin_expect(!!(x), 0)
29 #define dprintf(s...) do { if( unlikely(prof_debug!=0) ) fprintf(s); } while(0)
31 int profileMain(int ac,char **av,char **ev);
32 void profileStart(void);
33 void profileStop(void);
34 void profileClear(void);
35 void profileShow(void);
36 void profileDone(void);
46 #include <sys/times.h>
52 #define SYM2MAX 1024*256
53 #define SYMINCR 1024*16
55 static volatile long prof_debug = 1;
56 static volatile long prof_type = 0;
57 static volatile long prof_tmrval = 10000;
58 static volatile unsigned long prof_stkptr = INT_MAX-0x1000;
59 static volatile char prof_output[256] = { "-" };
61 static volatile long prof_debug; /* enable debug output */
62 static volatile long prof_type; /* 0=usr+sys, 1=usr only, 2=real time */
63 static volatile long prof_tmrval; /* profile timer interval in usecs */
64 static volatile unsigned long prof_stkptr; /* top of stack at profileStart */
65 static volatile char prof_output[256]; /* profile output file name */
68 static FILE *prof_fp = NULL;
107 static tSymTbl *tsym = NULL;
108 static tModTbl *tmod = NULL;
109 static tMapTbl *tmap = NULL;
110 static int nTicks; /* profile timer tick count */
111 static struct tms start_cpu; /* cpu time at profile_start */
112 static struct tms stop_cpu; /* cpu time at profile_stop */
113 static struct timeval start_clk; /* real time at profile_start */
114 static struct timeval stop_clk; /* real time at profile_stop */
116 int profileActive = 0; /* flag, true if profile handler active */
117 static struct sigaction oldSig; /* orignal profile handler data */
118 static struct sigaction oldSegv; /* orignal segv handler data */
124 if( (tp=malloc(sizeof(*tp))) != NULL ) {
126 tp->m = sizeof(tp->map)/sizeof(tp->map[0]);
135 if( (tp=malloc(sizeof(*tp))) != NULL ) {
137 tp->m = sizeof(tp->mod)/sizeof(tp->mod[0]);
146 if( (tp=malloc(sizeof(*tp))) != NULL ) {
148 tp->m = sizeof(tp->sym)/sizeof(tp->sym[0]);
154 newSym(tSymTbl **ptp,const char *name,unsigned long adr,int mod)
162 m = m < SYM2MAX ? m*2 : m+SYMINCR;
163 l = sizeof(*tp)-sizeof(tp->sym)+m*sizeof(tp->sym[0]);
164 rp = (tSymTbl*) realloc(tp,l);
165 if( rp == NULL ) return NULL;
172 sp->name = strdup(name);
175 sp->count = sp->calls = 0;
176 sp->tick = sp->tcalls = 0;
181 newMod(tModTbl **ptp, const char *name, unsigned long offs)
189 m = m < MOD2MAX ? m*2 : m+MODINCR;
190 l = sizeof(*tp)-sizeof(tp->mod)+m*sizeof(tp->mod[0]);
191 rp = (tModTbl*) realloc(tp,l);
199 mp->name = strdup(name);
201 mp->count = mp->calls = 0;
206 findMod(tModTbl *tp, const char *nm)
209 while( --n >= 0 && strcmp(nm,tp->mod[n].name) );
214 newMap(tMapTbl **ptp, const char *name, unsigned long offs)
222 m = m < MAP2MAX ? m*2 : m+MAPINCR;
223 l = sizeof(*tp)-sizeof(tp->map)+m*sizeof(tp->map[0]);
224 rp = (tMapTbl*) realloc(tp,l);
232 mp->name = strdup(name);
238 delMapTbl(tMapTbl **ptp)
241 tMapTbl *tp; tMap *mp;
242 if( (tp=*ptp) == NULL ) return;
244 for( i=tp->n; --i>=0; ++mp ) {
245 if( (name=mp->name) != NULL )
253 delModTbl(tModTbl **ptp)
256 tModTbl *tp; tMod *mp;
257 if( (tp=*ptp) == NULL ) return;
259 for( i=tp->n; --i>=0; ++mp ) {
260 if( (name=mp->name) != NULL )
268 delSymTbl(tSymTbl **ptp)
271 tSymTbl *tp; tSym *sp;
272 if( (tp=*ptp) == NULL ) return;
274 for( i=tp->n; --i>=0; ++sp ) {
275 if( (name=sp->name) != NULL )
291 mapLkup(tMapTbl *tp,const char *nm)
293 tMap *mp = &tp->map[0];
295 while( --n >= 0 && strcmp(nm,mp->name)!=0 )
301 findMap(tMapTbl *tp,char *nm)
303 int ret = mapLkup(tp,nm);
305 dprintf(stderr,"cant find map '%s'\n",nm);
310 findSymAdr(tSymTbl *tp,const char *nm,unsigned long *adr)
313 while( --n >= 0 && strcmp(nm,tp->sym[n].name) );
314 if( n < 0 ) return 1;
315 *adr = tp->sym[n].adr;
320 isSymNm(char *cp, char *bp)
323 while( (ch=*cp++) != 0 ) {
324 if( ch == '\n' ) break;
326 if( ch == '#' || ch == '$' || ch == '.' ) return 0;
333 hex(char *cp, unsigned long *val)
336 *val = strtoul(cp,&bp,16);
341 mapMod(char *fn,tSymTbl **ptp, int mod)
343 char nmLine[512], nmCmd[512], *lp;
344 unsigned long adr, ofs; int typ;
346 if( access(fn, R_OK) < 0 ) return -1;
347 strcpy(&nmCmd[0],smCommand);
348 strcat(&nmCmd[0],fn);
350 if( (fp=popen(&nmCmd[0],"r")) == NULL ) return -1;
351 mp = &tmod->mod[mod]; ofs = mp->offs;
352 while((lp=fgets(&nmLine[0],sizeof nmLine,fp)) != NULL ) {
353 typ = nmLine[nmType];
354 if( typ != 'T' && typ != 't' ) continue;
355 if( isSymNm(&nmLine[nmName],&nmCmd[0]) == 0 ) continue;
356 if( hex(&nmLine[nmAddr],&adr) != nmType-1 ) continue;
358 if( newSym(ptp,&nmCmd[0],adr,mod) == NULL ) break;
359 } while((lp=fgets(&nmLine[0],sizeof nmLine,fp)) != NULL );
361 return lp != NULL ? -1 : 0;
365 adrCmpr(const void *a, const void *b)
367 unsigned long aadr = ((tSym*)a)->adr;
368 unsigned long badr = ((tSym*)b)->adr;
369 if( aadr > badr ) return 1;
370 if( aadr < badr ) return -1;
375 cntCmpr(const void *a, const void *b)
377 int acnt = ((tSym*)a)->count;
378 int bcnt = ((tSym*)b)->count;
383 tclCmpr(const void *a, const void *b)
385 int atcl = ((tSym*)a)->tcalls;
386 int btcl = ((tSym*)b)->tcalls;
391 modCmpr(const void *a, const void *b)
393 int acnt = ((tMod*)a)->count;
394 int bcnt = ((tMod*)b)->count;
399 profile_tally(unsigned long pc, int cnt)
405 sp = tp = &tsym->sym[0];
407 /* find function containing pc */
411 if( sp->adr == pc ) break;
412 if( sp->adr < pc ) l = m;
415 if( sp->adr != pc ) {
420 tMod *mp = &tmod->mod[sp->mod];
421 /* incr function/module calls/counts */
424 /* only 1 call per unwinding */
425 if( sp->tick < nTicks ) {
437 unsigned long rf_fp; /* frame pointer */
438 unsigned long rf_rtn; /* return addr */
441 static int readProcMaps(unsigned long *fwa)
443 int ret, n, m, fd, len;
444 unsigned long vm_start, vm_end, ino;
445 char mr, mw, mx, ms, *bp;
447 unsigned int maj, min;
448 char mfn[PATH_MAX], ifn[PATH_MAX];
450 pid_t pid = getpid();
452 snprintf(&mfn[0],sizeof mfn,"/proc/%d/maps",pid);
453 fd = open(&mfn[0],O_RDONLY);
455 len = read(fd,bp=&bfr[0],sizeof bfr);
458 m = sscanf(bp, "%lx-%lx %c%c%c%c %lx %x:%x %lu%n",
459 &vm_start,&vm_end,&mr,&mw,&mx,&ms,&pgoff,&maj,&min,&ino,&n);
460 if( m == 10 && fwa ) { *fwa = vm_start; fwa = 0; }
461 if( m == 10 && mx == 'x' && pgoff == 0 ) {
462 for( bp+=n,len-=n ; len>0 && *bp!='\n' && *bp==' '; ++bp,--len );
463 for( m=0 ; len>0 && *bp!='\n' && m<PATH_MAX-1; ++bp,--len )
466 if( maj !=0 || min != 0 ) {
467 dprintf(stderr," map "_LX" %s\n",vm_start,&ifn[0]);
468 newMap(&tmap,&ifn[0],vm_start);
471 while( --len>=0 && *bp++!='\n' );
478 static int readNmMaps(unsigned long fwa)
482 char dfn[PATH_MAX], efn[PATH_MAX], pfn[PATH_MAX];
484 struct r_debug *rdebug = &_r_debug;
485 for( so=rdebug->r_map; so!=NULL; so=so->l_next ) {
487 char *nm = &so->l_name[0];
488 if( nm[0] == 0 ) nm = "/proc/self/exe";
489 dprintf(stderr,"resolving %s\n",nm);
490 if( nm[0] == '.' && nm[1] == '/' ) {
491 getcwd(&pfn[0],sizeof(pfn));
492 strcat(&pfn[0],&nm[1]);
495 while( (i=readlink(nm,&efn[0],sizeof(efn)-1)) >= 0 ) {
497 dprintf(stderr," link %s\n",&efn[0]);
498 if( efn[0] != '/' ) { /* get dirname */
499 for( k=-1,i=0; i<sizeof(dfn)-1 && (dfn[i++]=*nm)!=0; ++nm )
500 if( *nm == '/' ) k = i;
501 if( k >= 0 ) { /* add link name */
502 for( i=0; k<sizeof(dfn)-1 && (dfn[k++]=efn[i])!=0; ++i );
504 strncpy(&efn[0],&dfn[0],sizeof(efn));
507 dprintf(stderr," path %s\n",nm);
509 if( findMod(tmod,nm) >= 0 ) continue;
510 int map = !so->l_name[0] ? -1 : findMap(tmap, nm);
511 tMap *mp = map>=0 ? &tmap->map[map] : 0;
512 adr = mp ? mp->offs : (unsigned long) so->l_addr;
513 if( !adr ) adr = fwa;
514 dprintf(stderr," map %s adr = 0x"_LX" ofs = 0x"_LX"\n",
515 nm,adr,(unsigned long)so->l_addr);
516 int mod = newMod(&tmod,nm,adr);
518 if( mapMod(nm,&tsym,mod) < 0 || tsym->n == n ) {
519 char dfn[PATH_MAX]; memset(dfn,0,sizeof(dfn));
520 strcpy(&dfn[0],"/usr/lib/debug");
521 strncat(&dfn[0],nm,sizeof(dfn)-1);
522 strncat(&dfn[0],".debug",sizeof(dfn)-1);
523 dprintf(stderr,", %s",&dfn[0]);
524 if( mapMod(&dfn[0],&tsym,mod) < 0 )
528 dprintf(stderr,", %d symbols\n",tsym->n - n);
529 if( mod < 0 && strncmp("linux-vdso.so.",nm,14) ) {
530 fprintf(stderr,"profile - Cannot map module - %s\n",nm);
536 /* sort the symbols by address */
537 qsort(&tsym->sym[0],tsym->n,sizeof(tsym->sym[0]),adrCmpr);
538 if( prof_debug != 0 ) {
541 for( i=tsym->n; --i>=0; ++sp ) {
542 tMod *mp = &tmod->mod[sp->mod];
543 fprintf(stdout,_LX" %-24s %s\n",sp->adr,
544 &sp->name[0],&mp->name[0]);
550 /** profile_handler(sign,c)
551 * profile periodic timer signal handler.
552 * decodes pc/fp from sigcontext, and tallys pc (count)
553 * and stack trace (calls).
555 #define LOW_TEXT 0x01000UL
557 static void profile_handler(int n, siginfo_t * info, void *sc)
559 ucontext_t *uc = (ucontext_t *)sc;
560 struct sigcontext *c = (struct sigcontext *)&uc->uc_mcontext;
561 struct reg_frame *fp, *last_fp;
563 /* tid marks top of thread stack (currently) */
564 unsigned long tid = (unsigned long)pthread_self();
568 pc = (unsigned long)c->eip;
572 pc = (unsigned long)c->rip;
578 if( pc < LOW_TEXT ) return;
579 if( profile_tally(pc,1) != 0 ) return;
581 /* access frame pointer and validate */
583 fp = (struct reg_frame *)c->ebp;
584 if( (unsigned long)fp < c->esp ) return;
587 fp = (struct reg_frame *)c->rbp;
588 if( (unsigned long)fp < c->rsp ) return;
590 if( (unsigned long)fp > prof_stkptr) return;
591 if( (unsigned long)fp > tid) return;
592 dprintf(stderr,"unwind "_LX"",(unsigned long)pc);
593 /* unwind the stack frames, and tally pc values */
594 while( (last_fp=fp) != 0 ) {
596 dprintf(stderr," "_LX"",(unsigned long)pc);
597 if( pc < LOW_TEXT ) break;
598 if( profile_tally(pc,0) != 0 ) break;
599 fp = (struct reg_frame *)fp->rf_fp;
600 if( ((long)fp & 3) != 0 ) break;
601 if( fp <= last_fp ) break;
602 if( (unsigned long)fp > prof_stkptr ) break;
603 if( (unsigned long)fp > tid ) break;
605 dprintf(stderr,"\n");
610 void profileExit(void)
617 static void profile_segv(int n, siginfo_t * info, void *sc)
619 ucontext_t *uc = (ucontext_t *)sc;
620 struct sigcontext *c = (struct sigcontext *)&uc->uc_mcontext;
622 fprintf(stderr,"segv at 0x"_LX"\n",
632 void profileStart(void)
638 struct sigaction act;
639 struct sigaction segv;
642 if( profileActive != 0 ) return;
644 if( tmod == NULL || tsym == NULL || tmap == NULL ) {
646 dprintf(stderr,"start profile\n");
648 unsetenv("LD_PRELOAD");
650 fn = (char *)&prof_output[0];
651 if( strcmp("-",&fn[0]) == 0 )
653 else if( strcmp("--",&fn[0]) == 0 )
656 prof_fp = fopen(&fn[0],"w");
657 if( prof_fp == NULL ) {
659 fprintf(stderr,"profile: no output path\n");
662 tmap = newMapTbl(); fwa = 0;
663 if( tmap != NULL && readProcMaps(&fwa) == 0 ) {
664 tmod = newModTbl(); tsym = newSymTbl();
665 if( tmod == NULL || tsym == NULL || readNmMaps(fwa) != 0 ) {
666 fprintf(stderr,"profile: unable to read nm maps\n");
667 delModTbl(&tmod); delSymTbl(&tsym);
671 fprintf(stderr,"profile: unable to read proc maps\n");
675 if( tmap == NULL || tmod == NULL || tsym == NULL ) {
680 switch( prof_type ) {
681 case 1: typ = ITIMER_VIRTUAL; sig = SIGVTALRM; break;
682 case 2: typ = ITIMER_REAL; sig = SIGALRM; break;
683 default: typ = ITIMER_PROF; sig = SIGPROF; break;
686 /* record the start time (cpu/real). */
688 gettimeofday(&start_clk,&tz);
690 /* enable the profile timer signal handler. */
692 memset(&act,0,sizeof(act));
693 act.sa_sigaction = profile_handler;
694 act.sa_flags = SA_RESTART + SA_SIGINFO;
695 sigaction(sig, &act, &oldSig);
696 memset(&segv,0,sizeof(segv));
697 segv.sa_sigaction = profile_segv;
698 segv.sa_flags = SA_SIGINFO;
699 sigaction(SIGSEGV,&segv,&oldSegv);
701 /* start the periodic profile timer signal */
702 if( prof_tmrval == 0 ) prof_tmrval = 1;
704 it.it_interval.tv_sec = prof_tmrval / 1000000;
705 it.it_value.tv_usec =
706 it.it_interval.tv_usec = prof_tmrval % 1000000;
707 setitimer(typ, &it, NULL);
708 dprintf(stderr,"starting profile.\n");
711 static void sigusr1(int n)
719 int profileMain(int ac,char **av,char **ev)
721 int (*fmain)(int ac,char **av,char **ev);
724 if( findSymAdr(tsym,"main",&adr) != 0 ) {
725 fprintf(stderr,"cant locate sym \"main\"\n");
729 signal(SIGUSR1, sigusr1);
730 fmain = (int (*)(int,char **,char **))adr;
731 dprintf(stderr,"starting \"main\" at: %p\n",fmain);
732 int ret = fmain(ac,av,ev);
733 dprintf(stderr,"ended \"main\" = %d\n",ret);
737 void profileStop(void)
741 struct sigaction act;
743 if( profileActive == 0 ) return;
744 dprintf(stderr,"stopping profile.\n");
746 /* records the stop time (cpu/real). */
748 gettimeofday(&stop_clk,&tz);
750 /* disables the profile timer signal handler. */
751 it.it_interval.tv_sec = 0;
752 it.it_interval.tv_usec = 0;
753 it.it_value.tv_sec = 0;
754 it.it_value.tv_usec = 0;
755 setitimer(ITIMER_PROF, &it, NULL);
757 /* restore the original profile signal handler. */
758 sigaction(SIGPROF, &oldSig, &act);
759 sigaction(SIGSEGV, &oldSegv, &act);
765 void profileClear(void)
770 tSym *sp = &tsym->sym[0];
771 for( i=tsym->n; --i>=0; ++sp ) {
772 sp->count = sp->calls = 0;
773 sp->tick = sp->tcalls = 0;
777 tMod *mp = &tmod->mod[0];
778 for( i=tmod->n; --i>=0; ++mp )
779 mp->count = mp->calls = 0;
784 void profileShow(void)
787 double userDt, systDt;
788 double tickDt, realDt;
789 if( tsym == NULL || tmod == NULL ) return;
791 qsort(&tsym->sym[0],tsym->n,sizeof(tsym->sym[0]),cntCmpr);
792 /* outputs sorted (by count) list of functions called. */
793 fprintf(fp,"---- profile start ----\n");
794 fprintf(fp," %d ticks %d modules %d syms\n",nTicks,tmod->n,tsym->n);
795 tSym *sp = &tsym->sym[0];
796 for( i=tsym->n; --i>=0; ++sp ) {
797 if( !sp->count ) continue;
798 tMod *mp = &tmod->mod[sp->mod];
799 fprintf(fp,"%8.3fs %5.1f%% %-24s %s\n",
800 prof_tmrval*sp->count/1000000.0,
801 sp->count*100.0/nTicks,&sp->name[0],
805 qsort(&tsym->sym[0],tsym->n,sizeof(tsym->sym[0]),tclCmpr);
806 /* outputs sorted (by calls) list of functions called. */
807 fprintf(fp,"---- profile calls ----\n");
809 for( i=tsym->n; --i>=0; ++sp ) {
810 if( !sp->tcalls ) continue;
811 tMod *mp = &tmod->mod[sp->mod];
812 fprintf(fp,"%8.3fs %5.1f%% %-24s %5.1f %s\n",
813 prof_tmrval*sp->tcalls/1000000.0,
814 sp->tcalls*100.0/nTicks,&sp->name[0],
815 (double)sp->calls/sp->tcalls,&mp->name[0]);
818 realDt = ((stop_clk.tv_sec - start_clk.tv_sec) * 1000000.0 +
819 (stop_clk.tv_usec - start_clk.tv_usec) ) / 1000000.0;
820 /* output sorted (by count) list of modules called. */
821 qsort(&tmod->mod[0],tmod->n,sizeof(tmod->mod[0]),modCmpr);
822 fprintf(fp,"----\n");
823 tMod *mp = &tmod->mod[0];
824 for( i=tmod->n; --i>=0; ++mp ) {
825 if( mp->count != 0 && mp->name != NULL ) {
826 double dt = prof_tmrval*mp->count/1000000.0;
827 fprintf(fp,"%8.3fs %5.1f%%/%5.1f%% %s\n",
828 dt,mp->count*100.0/nTicks,dt*100.0/realDt,mp->name);
832 /* output tick time, cpu user/kernal time, real time. */
833 tickDt = prof_tmrval*nTicks / 1000000.0;
834 userDt = (stop_cpu.tms_utime - start_cpu.tms_utime) / (double)CLOCKS_PER_SEC;
835 systDt = (stop_cpu.tms_stime - start_cpu.tms_stime) / (double)CLOCKS_PER_SEC;
837 fprintf(fp,"%8.3ft %0.3fu+%0.3fs %0.3fr %5.1f%%\n",
838 tickDt, userDt, systDt, realDt, tickDt*100.0/realDt);
839 fprintf(fp,"---- profile end ----\n\n");
840 qsort(&tsym->sym[0],tsym->n,sizeof(tsym->sym[0]),adrCmpr);
843 void profileDone(void)
848 if( prof_fp != NULL && prof_fp != stdout && prof_fp != stderr ) {
849 fclose(prof_fp); prof_fp = NULL;