#include #include #include #include #include #include #include #include #include #include #include #include #include #include #include #include "maputil.h" using namespace std; typedef map mapint; static bool do_timing = false; static void print_timing (const char *msg, ...) { if (do_timing){ static long long last = 0; struct timeval t; if (gettimeofday(&t,NULL)!=-1){ long long now = (long long)t.tv_sec*1000000 + t.tv_usec; if (last != 0){ long long diff = now - last; va_list list; va_start (list,msg); char buf[1000]; vsnprintf (buf,sizeof(buf)-1,msg,list); va_end (list); fprintf (stderr,"%40s %5ld.%06ld\n",buf ,(long)(diff/1000000),(long)(diff % 1000000)); } last = now; } } } struct MALLOC_STATS{ MALLOC_STATS_BASE all; // All allocations MALLOC_STATS_BASE some; // Only "close" allocation (based on distance) MALLOC_STATS(){} void add (long size, bool guilty){ all.add (size); if (guilty) some.add (size); } void del (long size){ all.del (size); } }; static int scope=0; #define MAXSCOPE 20 struct SCOPE{ long addr[MAXSCOPE]; SCOPE(){ memset (addr,0,sizeof(addr)); } SCOPE(const SCOPE &sc){ memcpy (addr,sc.addr,sizeof(addr)); } void operator = (const SCOPE &sc){ memcpy (addr,sc.addr,sizeof(addr)); } bool operator < (const SCOPE &s) const { bool ret = false; for (int i=0; i dirs; ALLOCITEM(int _size) { size = _size; } ALLOCITEM(){ size = 0; } }; struct SYMBOL{ unsigned long addr; char *sym; char *file; bool match; MALLOC_STATS *dirstats; }; static int cmp_symbol (const void *p1, const void *p2) { SYMBOL *s1 = (SYMBOL*)p1; SYMBOL *s2 = (SYMBOL*)p2; return s1->addr - s2->addr; } static int cmp_key (const void *p1, const void *p2) { unsigned long addr = (unsigned long)p1; SYMBOL *s2 = (SYMBOL*)p2; // printf ("cmp_key %08lx %08lx\n",addr,s2->addr); int ret = 1; if (addr >= s2->addr && addr < s2[1].addr){ ret = 0; }else if (addr < s2->addr){ ret = -1; } return ret; } static bool maplog_inlist (list &l, MALLOC_STATS *s) { bool ret = false; for (list::iterator it=l.begin(); it != l.end() ; it++){ if (*it == s){ ret = true; break; } } return ret; } static bool process_free ( map &items, map &scopes, MALLOC_STATS_BASE &stats, MALLOC_STATS_BASE &msg, unsigned long addr) { bool ret = false; map::iterator it = items.find(addr); if (it != items.end()){ stats.del (it->second.size); msg.del (it->second.size); for (list::iterator i=it->second.dirs.begin() ;i!=it->second.dirs.end(); i++){ (*i)->del (it->second.size); } items.erase(it); if (scope != 0){ MALLOC_STATS_BASE &b = scopes[it->second.scope]; b.del (it->second.size); } ret = true; } return ret; } typedef map MAPITEMS; #define to_page(x) ((x)&(~(PAGE_SIZE-1))) static void print_density( const char *title, MAPITEMS &items) { if (items.size() > 0){ unsigned long notused = 0; MAPITEMS::iterator it = items.begin(); //while (it->first >= 0x40000000 && it != items.end()) it++; unsigned long last = it->first; unsigned long start = last; for (; it != items.end(); it++){ unsigned long cur_addr = it->first; if (cur_addr >= 0x40000000) break; unsigned long diff = cur_addr - last; if (diff >= 4096){ unsigned long last_page = to_page(last); if (last_page < last) last_page += 4096; unsigned long cur_page = to_page(cur_addr); if (cur_page > last_page){ notused += (cur_page - last_page); } } last = cur_addr + it->second.size; } unsigned long used = last - start; printf ("%30s: used %8lu unused pages %8lu\n",title,used/PAGE_SIZE ,notused/PAGE_SIZE); } } int main (int argc, char *argv[]) { glocal bool format = false; glocal bool dostatdirs = false; glocal bool dostatfiles = false; glocal bool dostatfuncs = false; glocal bool leaks = false; glocal bool showsource = false; glocal bool density = false; glocal int distance = 1; glocal const char *dirfilter = NULL; glocal const char *mapcmd = NULL; glocal SSTRINGS mapmsgs; int ret = (argc,argv); setproginfo ("maplog",PACKAGE_REV ,"maplog [ options ] program logfile\n" "\n" "Convert logs produced by btmalloc.so in various format.\n" "If logfile is -, then stdin is used.\n"); setarg ('c',"scope","Calling scope level (go figure)",scope,false); setarg ('d',"distance","Guiltyness stack distance (default 1)",glocal.distance,false); setarg ('f',"format","Format the backtrace one function per line" ,glocal.format,false); setarg ('i',"filter","Show stack trace only for this directory",glocal.dirfilter,false); setgrouparg ("Task selection"); setarg ('s',"statdirs","Produce some statistics, including per directory",glocal.dostatdirs,false); setarg ('t',"statfiles","Produce some statistics, including per file",glocal.dostatfiles,false); setarg ('u',"statfuncs","Produce some statistics, including per function",glocal.dostatfuncs,false); setarg ('l',"leaks","Show leaks",glocal.leaks,false); setgrouparg ("Others"); setarg ('D',"density","Show memory density",glocal.density,false); setarg ('S',"source","Show the source file owning a function",glocal.showsource,false); setarg ('m',"mapsym","Command used to get the symbols",glocal.mapcmd,false); setarg ('M',"mapmsg","Process a message file produced by mapmsg",glocal.mapmsgs,false); setarg ('T',"timing","Report processing time",do_timing,false); int ret = -1; if (argc != 2){ usage(); }else if (scope < 0 || scope > MAXSCOPE){ tlmp_error ("scope must be between 0 and %d\n",MAXSCOPE); }else{ glocal SYMBOL *tb = NULL; glocal int nbsym = 0; glocal int maxsym = 0; glocal map dirs; glocal vector msgs; glocal mapint distrib; print_timing (""); maputil_readmsgs (glocal.mapmsgs,glocal.msgs); maputil_setends (glocal.msgs,true); // Lecture des symboles du programme print_timing ("Lecture des messages"); const char *mapcmd = glocal.mapcmd; SSTRING cmd; cmd.setfromf ("nm -n %s --demangle %s" ,glocal.showsource ? "-l" : "" ,argv[0]); if (mapcmd == NULL) mapcmd = cmd.get(); ret = (mapcmd,20,true); fprintf (stderr,"%s\n",line); return 0; static bool fixformat = false; static int coltype = 9; static int colsym = 11; static int offaddr = 0; if (!fixformat){ fixformat = true; if (isxdigit(line[8])){ coltype += 8; colsym += 8; offaddr += 8; // Only work in 32 bits on 64 bits machine } } if (isdigit(line[0]) && (line[coltype] == 't' || line[coltype] == 'T' || line[coltype] == 'W') && strncmp(line+colsym,"gcc2_compiled.",14)!=0){ if (glocal.nbsym == glocal.maxsym){ glocal.maxsym += 1000; glocal.tb = (SYMBOL*)realloc(glocal.tb,(glocal.maxsym+1)*sizeof(SYMBOL)); assert (glocal.tb!=NULL); } unsigned long addr; sscanf(line+offaddr,"%08lx",&addr); char *sym = strdup(line+colsym); char *file = strchr(sym,'\t'); if (file != NULL){ *file++ = '\0'; }else{ file = ""; } // printf ("line %08x %s:%s\n",addr,file,sym); SYMBOL *ptsym = &glocal.tb[glocal.nbsym++]; ptsym->addr = addr; ptsym->sym = sym;; ptsym->file = file; char dir[10000]; strcpy_cut (dir,file,sizeof(dir)-1); // Strip the file, keep the directory char *pt = strrchr(dir,'/'); if (pt != NULL) *pt = '\0'; ptsym->match = glocal.dirfilter != NULL && strcmp(dir,glocal.dirfilter)==0; if (glocal.dostatdirs){ // Nothing to do, use dir as is }else if (glocal.dostatfiles){ strcpy_cut (dir,file,sizeof(dir)-1); char *pt = strrchr(dir,':'); if (pt != NULL) *pt = '\0'; }else if (glocal.dostatfuncs){ strcpy_cut (dir,file,sizeof(dir)-1); char *pt = strrchr(dir,':'); if (pt != NULL) *pt = '\0'; strcat (dir,":"); strcat (dir,sym); } if (dir[0] == '\0') strcpy (dir,"unknown"); string pdir(dir); map::iterator it = glocal.dirs.find(pdir); MALLOC_STATS *dirstats; if (it == glocal.dirs.end()){ dirstats = &(glocal.dirs[pdir] = MALLOC_STATS()); }else{ dirstats = &it->second; } ptsym->dirstats = dirstats; } return 0; print_timing ("Lecture des symboles"); // Lecture du journal des allocations. if (ret > 0){ glocal map scopes; glocal MAPITEMS items; glocal MALLOC_STATS_BASE stats; glocal int nomsg = 0; glocal MALLOC_STATS_MSG *cur_msg = &glocal.msgs[0]; // Met un marqueur pour que cmp_key test quelque chose // de valide (il test l'item et le suivant) glocal.tb[glocal.nbsym].addr = 0x3fffffff; qsort (glocal.tb,glocal.nbsym,sizeof(SYMBOL),cmp_symbol); if (glocal.density){ printf ("Malloc density\n"); } (argv[1],false); bool is_realloc = false; const char *cmd = line + 18; long long stamp = map_s2ll(line); while (stamp < glocal.cur_msg->start || stamp > glocal.cur_msg->end){ glocal.cur_msg = &glocal.msgs[++glocal.nomsg]; if (glocal.density){ print_density(glocal.cur_msg->msg.c_str(),glocal.items); } } if (strncmp(cmd,"free",4)==0){ unsigned long addr; sscanf (cmd+4,"%8lx",&addr); process_free (glocal.items,glocal.scopes,glocal.stats,*glocal.cur_msg,addr); if (glocal.format){ char *pt = strchr(line,':'); if (pt != NULL){ printf ("%s\n",line); pt++; while (isspace(*pt)) pt++; while (*pt != '\0'){ unsigned long addr; sscanf (pt,"%08lx",&addr); SYMBOL *s = (SYMBOL*)bsearch ((const void*)addr,glocal.tb,glocal.nbsym,sizeof(SYMBOL) ,cmp_key); if (s != NULL){ printf ("\t%s\n",s->sym,s->file); } while (*pt > ' ') pt++; while (isspace(*pt))pt++; } } } }else if (strncmp(cmd,"malloc",6)==0 || strncmp(cmd,"calloc",6)==0 || strncmp(cmd,"strdup",6)==0 || (is_realloc=(strncmp(cmd,"realloc",7)==0))){ unsigned long addr; int size; if (is_realloc){ unsigned long oldaddr; sscanf (cmd+7,"%8lx %8lx %d",&oldaddr,&addr,&size); process_free (glocal.items,glocal.scopes,glocal.stats,*glocal.cur_msg,oldaddr); }else{ sscanf (cmd+6,"%8lx %d",&addr,&size); } glocal.distrib[size]++; glocal.stats.add (size); glocal.cur_msg->add (size); ALLOCITEM *px = &(glocal.items[addr] = ALLOCITEM(size)); char *pt = strchr(line,':'); if (pt != NULL){ *pt++ = '\0'; while (isspace(*pt)) pt++; SSTRINGS tbformat; bool filter_match = glocal.dirfilter == NULL; if (glocal.format){ SSTRING *s = new SSTRING; s->setfromf ("%s:\n",line); tbformat.add (s); } const char *ctl = " {%s}"; const char *ctln = " %08x"; if (glocal.format){ ctl = "\t%s\t%s\n"; ctln = "\t%08x\n"; } int distance = 0; SCOPE &sc = px->scope; while (*pt != '\0'){ unsigned long addr; sscanf (pt,"%08lx",&addr); sc.set (distance,addr); if (scope == 0){ SYMBOL *s = (SYMBOL*)bsearch ((const void*)addr,glocal.tb,glocal.nbsym,sizeof(SYMBOL) ,cmp_key); if (s != NULL){ if (glocal.format){ SSTRING *ss = new SSTRING; ss->setfromf (ctl,s->sym,s->file); tbformat.add (ss); if (s->match){ filter_match = true; } } if (s->dirstats != NULL && !maplog_inlist(px->dirs,s->dirstats)){ px->dirs.push_front(s->dirstats); s->dirstats->add (size,distance ' ') pt++; while (isspace(*pt))pt++; } if (filter_match){ for (int i=0; iget(),stdout); } } if (scope != 0){ MALLOC_STATS_BASE &b = glocal.scopes[sc]; b.add (size); } } }else if (strncmp(cmd,"appmsg",6)!=0){ fprintf (stderr,"ligne inconnu %d: %s\n",noline,line); } return 0; if (glocal.density){ glocal.nomsg++; for (; glocal.nomsg < glocal.msgs.size(); glocal.nomsg++){ print_density (glocal.msgs[glocal.nomsg].msg.c_str() ,glocal.items); } printf ("\n"); } print_timing ("Traitement du log"); if (glocal.dostatdirs || glocal.dostatfiles || glocal.dostatfuncs){ printf ("nbmalloc : %lu\n",glocal.stats.nbmalloc); printf ("total : %lu\n",glocal.stats.total); printf ("peakalloc: %lu\n",glocal.stats.maxalloc); fflush (stdout); static const char *dash = "-------------------------"; if (scope == 0){ // Print the report by function/source/directory static const char *ctl = "%7d %8d %8d %7d %8d %8d %s\n"; static const char *cth = "%7s %8s %8s %7s %8s %8s %s\n"; printf ("%16s%9s %16s\n","Total","","Guilty"); printf ("%s %s\n",dash,dash); printf (cth,"Nb.","Size","Max","Nb.","Size","Max","Item"); for (map::iterator it=glocal.dirs.begin() ;it != glocal.dirs.end(); it++){ if (it->second.all.nbmalloc > 0){ printf (ctl ,it->second.all.nbmalloc,it->second.all.total ,it->second.all.maxalloc ,it->second.some.nbmalloc,it->second.some.total ,it->second.some.maxalloc ,it->first.c_str()); } } }else{ static const char *ctl = "%7d %8d %8d %s\n"; static const char *cth = "%7s %8s %8s %s\n"; printf ("%16s\n","Total"); printf ("%s\n",dash); printf (cth,"Nb.","Size","Max","Item"); vector tbs; for (map::iterator it=glocal.scopes.begin() ; it != glocal.scopes.end(); it++){ tbs.push_back (SCOPESTAT(it->first,it->second)); } sort (tbs.rbegin(),tbs.rend()); for (int i=0; isym); }else{ tmp.appendf ("%s%08lx",slash,sc.addr[j]); } slash = " / "; } printf (ctl,p.st.nbmalloc,p.st.total,p.st.maxalloc ,tmp.get()); } } // Print the report split by message if (glocal.msgs.size() > 2){ static const char *dash = "-------------------------"; static const char *ctl = "%7d %8d %8d %s\n"; static const char *cth = "%7s %8s %8s %s\n"; printf ("\n"); printf ("%16s\n","Total"); printf ("%s\n",dash); printf (cth,"Nb.","Size","Max","Message"); for (vector::iterator it=glocal.msgs.begin() ;it != glocal.msgs.end(); it++){ printf (ctl ,it->nbmalloc,it->total ,it->maxalloc ,it->msg.c_str()); } } printf ("\n"); printf ("Allocation distribution\n"); printf ("%10s %10s %10s\n","Size","Nb.","Total"); for (mapint::iterator it=glocal.distrib.begin(); it!=glocal.distrib.end(); it++){ printf ("%10d %10d %10d\n",it->first,it->second ,it->first*it->second); } } } } return ret; return ret; }