Back to index

lightning-sunbird  0.9+nobinonly
trace.cpp
Go to the documentation of this file.
00001 /* ***** BEGIN LICENSE BLOCK *****
00002 /* Version: MPL 1.1/GPL 2.0/LGPL 2.1
00003 /*
00004 /* The contents of this file are subject to the Mozilla Public License Version
00005 /* 1.1 (the "License"); you may not use this file except in compliance with
00006 /* the License. You may obtain a copy of the License at
00007 /* http://www.mozilla.org/MPL/
00008 /*
00009 /* Software distributed under the License is distributed on an "AS IS" basis,
00010 /* WITHOUT WARRANTY OF ANY KIND, either express or implied. See the License
00011 /* for the specific language governing rights and limitations under the
00012 /* License.
00013 /*
00014 /* The Original Code is mozilla.org code.
00015 /*
00016 /* The Initial Developer of the Original Code is
00017 /* Netscape Communications Corporation.
00018 /* Portions created by the Initial Developer are Copyright (C) 1998
00019 /* the Initial Developer. All Rights Reserved.
00020 /*
00021 /* Contributor(s):
00022 /*   Garrett Arch Blythe, 03/04/2002  Added interval hit counting.
00023 /*
00024 /* Alternatively, the contents of this file may be used under the terms of
00025 /* either of the GNU General Public License Version 2 or later (the "GPL"),
00026 /* or the GNU Lesser General Public License Version 2.1 or later (the "LGPL"),
00027 /* in which case the provisions of the GPL or the LGPL are applicable instead
00028 /* of those above. If you wish to allow use of your version of this file only
00029 /* under the terms of either the GPL or the LGPL, and not to allow others to
00030 /* use your version of this file under the terms of the MPL, indicate your
00031 /* decision by deleting the provisions above and replace them with the notice
00032 /* and other provisions required by the GPL or the LGPL. If you do not delete
00033 /* the provisions above, a recipient may use your version of this file under
00034 /* the terms of any one of the MPL, the GPL or the LGPL.
00035 /*
00036 /* ***** END LICENSE BLOCK ***** */
00037 
00038 /* 
00039    This is part of a MOZ_COVERAGE build.  (set MOZ_COVERAGE=1 and rebuild)
00040    When trace.dll is linked in to the build, it counts the number of times 
00041    each function is called.  When the program exits, it breaks out the 
00042    functions by module, sorts them by number of calls, then dumps them into 
00043    win32.order where the module is built.  The order files are used by the
00044    liker to rearrange the functions in the library.  
00045 */
00046 
00047 #include <windows.h>
00048 #include <imagehlp.h>
00049 #include <stdio.h>
00050 
00051 #include "pldhash.h"
00052 
00053 //
00054 //  HIT_INTERVAL
00055 //
00056 //  Interval for which we will count hits, in milliseconds.
00057 //  This tends to sample the need for a particular function over time.
00058 //
00059 //  Decreasing the interval makes the code act more like call count
00060 //      ordering.
00061 //  Increasing the interval makes the code act more like no ordering
00062 //      at all.
00063 //  Some middle ground in between is best.  Tweak away....
00064 //
00065 //  We all know that not ordering the link order at all is not an
00066 //      optimal scenario.
00067 //  The folly of call count sorting is that you may group together
00068 //      methods which are rarely used but often called with rountines that
00069 //      are actually needed during the entire run of the application.
00070 //      If you can apply a time filter to smooth out the "page level" or
00071 //      "working set" needs to have a function in memory, then you should
00072 //      get a much better real world ordering.
00073 //
00074 #define HIT_INTERVAL 1000
00075 
00076 class Reporter {
00077 public:
00078     ~Reporter();
00079 };
00080 
00081 static Reporter theReporter;
00082 static FILE* logfile;
00083 
00084 /* 
00085    Hash of function names, and call counts]
00086  */
00087 static PLDHashTable Calls;
00088 
00089 struct CallEntry {
00090     struct PLDHashEntryHdr hdr;
00091     const void*            addr;
00092     unsigned               count;
00093     unsigned               hits; // interval hits.
00094     DWORD                  tick; // last valid tick, used to count hits.
00095 };
00096 
00097 static PLDHashTableOps Ops = {
00098     PL_DHashAllocTable,
00099     PL_DHashFreeTable,
00100     PL_DHashGetKeyStub,
00101     PL_DHashVoidPtrKeyStub,
00102     PL_DHashMatchEntryStub,
00103     PL_DHashMoveEntryStub,
00104     PL_DHashClearEntryStub,
00105     PL_DHashFinalizeStub
00106 };
00107 
00108 class Node {
00109 public:
00110     Node() {function = 0; count = 0; hits = 0; next = 0;};
00111     char* function;
00112     unsigned   count;
00113     unsigned   hits;
00114     Node* next;
00115 };
00116 
00117 
00118 /* 
00119    Hash of each module.  Contains a sorted linked list of each function and
00120    its number of calls for that module.
00121 */
00122 
00123 static PLDHashTable Modules;
00124 
00125 struct ModulesEntry {
00126     struct PLDHashEntryHdr hdr;
00127     char*                  moduleName;
00128     Node*                  byCount;
00129 };
00130 
00131 static PLDHashTableOps ModOps = {
00132     PL_DHashAllocTable,
00133     PL_DHashFreeTable,
00134     PL_DHashGetKeyStub,
00135     PL_DHashStringKey,
00136     PL_DHashMatchStringKey,
00137     PL_DHashMoveEntryStub,
00138     PL_DHashClearEntryStub,
00139     PL_DHashFinalizeStub
00140 };
00141 
00142 
00143 /*
00144    Counts the number of times a function is called.
00145 */
00146 extern "C"
00147 static void
00148 Log(void* addr)
00149 {
00150 static int initialized = 0;
00151 
00152     addr = (void*) ((unsigned) addr - 5);
00153 
00154     if (!initialized) {
00155         initialized = PL_DHashTableInit(&Calls, &Ops, 0, sizeof(CallEntry), 16);
00156         if (!initialized) 
00157             return;
00158     }
00159 
00160     entry = (CallEntry*) PL_DHashTableOperate(&Calls, addr, PL_DHASH_ADD);
00161     if (!entry)
00162         return; // OOM
00163 
00164     if (!entry->addr)
00165         entry->addr = addr;
00166 
00167     //
00168     //  Another call recorded.
00169     //
00170     ++entry->count;
00171 
00172     //
00173     // Only record a hit if the appropriate amount of time has passed.
00174     //
00175     DWORD curtick = GetTickCount();
00176     if(curtick >= (entry->tick + HIT_INTERVAL))
00177     {
00178         //
00179         //  Record the interval hit.
00180         //  Update the tick.
00181         //
00182         entry->hits++;
00183         entry->tick = curtick;
00184     }
00185 }
00186 
00187 /*
00188    assembly to call Log, and count this function
00189 */
00190 
00191 extern "C"
00192 __declspec(naked dllexport)
00193 void _penter()
00194 {
00195     __asm {
00196         push ecx               // save ecx for caller
00197         push dword ptr [esp+4] // the caller's address is the only param
00198         call Log               // ...to Log()
00199         add  esp,4
00200         pop  ecx               // restore ecx for caller
00201         ret
00202     }
00203 }
00204 
00205 /*
00206    Steps through the hash of modules and dumps the function counts out to 
00207    win32.order
00208 */
00209 
00210 static PLDHashOperator PR_CALLBACK
00211 DumpFiles(PLDHashTable* table, PLDHashEntryHdr* hdr,
00212           PRUint32 number, void* arg)
00213 {
00214     ModulesEntry* entry = (ModulesEntry*) hdr;    
00215     Node*         cur = entry->byCount;
00216     char          dest[MAX_PATH];
00217     char          pdbName[MAX_PATH];
00218     FILE*         orderFile;
00219 
00220     strcpy(pdbName, entry->moduleName);
00221     strcat(pdbName, ".pdb");
00222 
00223     if (!::SearchTreeForFile(MOZ_SRC, pdbName, dest) ) {
00224         fprintf(logfile,"+++ERROR Could not find %s\n",pdbName);
00225         return PL_DHASH_NEXT;
00226     }
00227     dest[strlen(dest)-strlen(pdbName)-strlen("WIN32_D.OBJ\\")] = 0;
00228     strcat(dest,"win32.order");
00229     orderFile = fopen(dest,"w");
00230     fprintf(logfile,"Creating order file %s\n",dest);
00231     
00232     while (cur) {
00233         if (cur->function[0] == '_')  // demangle "C" style function names
00234             fprintf(orderFile,"%s ; %d %d\n", cur->function+1, cur->hits, cur->count );
00235         else
00236             fprintf(orderFile,"%s ; %d %d\n", cur->function, cur->hits, cur->count );
00237         cur = cur->next;
00238     }
00239 
00240     fflush(orderFile);
00241     fclose(orderFile);
00242     return PL_DHASH_NEXT;
00243 }
00244 
00245 /*
00246    We have a function name.  Figure out which module it is from.  Then add that
00247    function and its call count into the module's sorted list.
00248 */
00249 
00250 static PLDHashOperator PR_CALLBACK
00251 ListCounts(PLDHashTable* table, PLDHashEntryHdr* hdr,
00252            PRUint32 number, void* arg)
00253 {
00254     BOOL ok;
00255     CallEntry* entry = (CallEntry*) hdr;
00256 
00257     IMAGEHLP_MODULE module;
00258     module.SizeOfStruct = sizeof(module);
00259 
00260     ok = ::SymGetModuleInfo(::GetCurrentProcess(),
00261                             (unsigned) entry->addr,
00262                             &module);
00263 
00264     char buf[sizeof(IMAGEHLP_SYMBOL) + 512];
00265     PIMAGEHLP_SYMBOL symbol = (PIMAGEHLP_SYMBOL) buf;
00266     symbol->SizeOfStruct = sizeof(buf);
00267     symbol->MaxNameLength = 512;
00268 
00269     DWORD displacement;
00270     ok = ::SymGetSymFromAddr(::GetCurrentProcess(),
00271                              (unsigned) entry->addr,
00272                              &displacement,
00273                              symbol);
00274 
00275     if (ok)
00276     {
00277         if (displacement > 0) 
00278             return PL_DHASH_NEXT;
00279         static int modInitialized = 0;
00280         if (!modInitialized) {
00281             modInitialized = PL_DHashTableInit(&Modules, &ModOps, 0, sizeof(ModulesEntry), 16);
00282             if (!modInitialized)
00283                 return PL_DHASH_NEXT;
00284         }
00285 
00286         ModulesEntry* mod
00287             = (ModulesEntry*) PL_DHashTableOperate(&Modules,
00288                                                    module.ModuleName,
00289                                                    PL_DHASH_ADD);
00290         if (!mod)
00291             return PL_DHASH_STOP;       // OOM
00292 
00293         if (!mod->moduleName) {
00294             mod->moduleName = strdup(module.ModuleName);
00295             mod->byCount = new Node();
00296             mod->byCount->function = strdup(symbol->Name);
00297             mod->byCount->count = entry->count;
00298             mod->byCount->hits = entry->hits;
00299         } else {
00300             // insertion sort.
00301             Node* cur = mod->byCount;
00302             Node* foo = new Node();
00303             foo->function = strdup(symbol->Name);
00304             foo->count = entry->count;
00305             foo->hits = entry->hits;
00306 
00307             if
00308 #if defined(SORT_BY_CALL_COUNT)
00309                 (cur->count < entry->count)
00310 #else
00311                 ((cur->hits < entry->hits) || (cur->hits == entry->hits && cur->count < entry->count))
00312 #endif
00313             {
00314                 if (!strcmp(cur->function,symbol->Name)) 
00315                     return PL_DHASH_NEXT;
00316                 foo->next = mod->byCount;
00317                 mod->byCount = foo;                
00318             } else {
00319                 while (cur->next) {
00320                     if (!strcmp(cur->function,symbol->Name)) 
00321                         return PL_DHASH_NEXT;
00322                     if
00323 #if defined(SORT_BY_CALL_COUNT)
00324                         (cur->next->count > entry->count)
00325 #else
00326                         ((cur->next->hits > entry->hits) || (cur->next->hits == entry->hits && cur->next->count > entry->count))
00327 #endif
00328                     { cur = cur->next; }
00329                     else { break; }
00330                 }
00331                 foo->next = cur->next;  
00332                 cur->next = foo;
00333             }
00334         }
00335     } // if (ok)
00336     return PL_DHASH_NEXT;
00337 }
00338 
00339 Reporter::~Reporter()
00340 {
00341     SymInitialize(GetCurrentProcess(), 0, TRUE);
00342     
00343     DWORD options = SymGetOptions();
00344 
00345     // We want the nasty name, as we'll have to pass it back to the
00346     // linker.
00347     options &= ~SYMOPT_UNDNAME;
00348     SymSetOptions(options);
00349 
00350     char logName[MAX_PATH];
00351     strcpy(logName,MOZ_SRC);
00352     strcat(logName,"\\tracelog");
00353     logfile = fopen(logName,"w");
00354 
00355     // break the function names out by module and sort them.
00356     PL_DHashTableEnumerate(&Calls, ListCounts, NULL);
00357     // dump the order files for each module.
00358     PL_DHashTableEnumerate(&Modules, DumpFiles, NULL);
00359 
00360     fclose(logfile);
00361     SymCleanup(GetCurrentProcess());
00362 }