Home | History | Annotate | Download | only in dmtracedump 
      1 /* //device/tools/dmtracedump/TraceDump.c
      2 **
      3 ** Copyright 2006, The Android Open Source Project
      4 **
      5 ** Licensed under the Apache License, Version 2.0 (the "License");
      6 ** you may not use this file except in compliance with the License.
      7 ** You may obtain a copy of the License at
      8 **
      9 **     http://www.apache.org/licenses/LICENSE-2.0
     10 **
     11 ** Unless required by applicable law or agreed to in writing, software
     12 ** distributed under the License is distributed on an "AS IS" BASIS,
     13 ** WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
     14 ** See the License for the specific language governing permissions and
     15 ** limitations under the License.
     16 */
     17 
     18 /*
     19  * Process dmtrace output.
     20  *
     21  * This is the wrong way to go about it -- C is a clumsy language for
     22  * shuffling data around.  It'll do for a first pass.
     23  */
     24 #define NOT_VM
     25 #include "Profile.h"        // from VM header
     26 
     27 #include <stdio.h>
     28 #include <stdlib.h>
     29 #include <string.h>
     30 #include <unistd.h>
     31 #include <inttypes.h>
     32 #include <time.h>
     33 #include <errno.h>
     34 #include <assert.h>
     35 
     36 /* Version number in the key file.  Version 1 uses one byte for the thread id.
     37  * Version 2 uses two bytes for the thread ids.
     38  */
     39 int versionNumber;
     40 
     41 /* arbitrarily limit indentation */
     42 #define MAX_STACK_DEPTH 10000
     43 
     44 /* thread list in key file is not reliable, so just max out */
     45 #define MAX_THREADS     32768
     46 
     47 /* Size of temporary buffers for escaping html strings */
     48 #define HTML_BUFSIZE 10240
     49 
     50 /* Size of methodId->method cache */
     51 #define METHOD_CACHE_SIZE 2048
     52 #define METHOD_CACHE_SIZE_MASK (METHOD_CACHE_SIZE - 1)
     53 
     54 /* Some filter constants */
     55 #define FILTER_TAG '*'
     56 #define FILTER_FLAG_THREAD '+'
     57 #define FILTER_TYPE_CLASS 0
     58 #define FILTER_TYPE_METHOD 1
     59 
     60 #define DEFAULT_ACTIVE_THREADS 8
     61 
     62 char *htmlHeader =
     63 "<html>\n<head>\n<script type=\"text/javascript\" src=\"%ssortable.js\"></script>\n"
     64 "<script langugage=\"javascript\">\n"
     65 "function toggle(item) {\n"
     66 "    obj=document.getElementById(item);\n"
     67 "    visible=(obj.style.display!=\"none\" && obj.style.display!=\"\");\n"
     68 "    key=document.getElementById(\"x\" + item);\n"
     69 "    if (visible) {\n"
     70 "        obj.style.display=\"none\";\n"
     71 "        key.innerHTML=\"+\";\n"
     72 "    } else {\n"
     73 "        obj.style.display=\"block\";\n"
     74 "        key.innerHTML=\"-\";\n"
     75 "    }\n"
     76 "}\n"
     77 "function onMouseOver(obj) {\n"
     78 "    obj.style.background=\"lightblue\";\n"
     79 "}\n"
     80 "function onMouseOut(obj) {\n"
     81 "    obj.style.background=\"white\";\n"
     82 "}\n"
     83 "</script>\n"
     84 "<style type=\"text/css\">\n"
     85 "div { font-family: courier; font-size: 13 }\n"
     86 "div.parent { margin-left: 15; display: none }\n"
     87 "div.leaf { margin-left: 10 }\n"
     88 "div.header { margin-left: 10 }\n"
     89 "div.link { margin-left: 10; cursor: move }\n"
     90 "span.parent { padding-right: 10; }\n"
     91 "span.leaf { padding-right: 10; }\n"
     92 "a img { border: 0;}\n"
     93 "table.sortable th { border-width: 0px 1px 1px 1px; background-color: #ccc;}\n"
     94 "a { text-decoration: none; }\n"
     95 "a:hover { text-decoration: underline; }\n"
     96 "table.sortable th, table.sortable td { text-align: left;}"
     97 "table.sortable tr.odd td { background-color: #ddd; }\n"
     98 "table.sortable tr.even td { background-color: #fff; }\n"
     99 "</style>\n"
    100 "</head><body>\n\n";
    101 
    102 char *htmlFooter = "\n</body>\n</html>\n";
    103 char *profileSeparator =
    104     "======================================================================";
    105 
    106 const char* tableHeader =
    107     "<table class='sortable' id='%s'><tr>\n"
    108     "<th>Method</th>\n"
    109     "<th>Run 1 (us)</th>\n"
    110     "<th>Run 2 (us)</th>\n"
    111     "<th>Diff (us)</th>\n"
    112     "<th>Diff (%%)</th>\n"
    113     "<th>1: # calls</th>\n"
    114     "<th>2: # calls</th>\n"
    115     "</tr>\n";
    116 
    117 const char* tableHeaderMissing =
    118     "<table class='sortable' id='%s'>\n"
    119     "<th>Method</th>\n"
    120     "<th>Exclusive</th>\n"
    121     "<th>Inclusive</th>\n"
    122     "<th># calls</th>\n";
    123 
    124 #define GRAPH_LABEL_VISITED 0x0001
    125 #define GRAPH_NODE_VISITED  0x0002
    126 
    127 /*
    128  * Values from the header of the data file.
    129  */
    130 typedef struct DataHeader {
    131     unsigned int magic;
    132     short version;
    133     short offsetToData;
    134     long long startWhen;
    135 } DataHeader;
    136 
    137 /*
    138  * Entry from the thread list.
    139  */
    140 typedef struct ThreadEntry {
    141     int         threadId;
    142     const char* threadName;
    143     uint64_t    elapsedTime;
    144 } ThreadEntry;
    145 
    146 struct MethodEntry;
    147 typedef struct TimedMethod {
    148     struct TimedMethod *next;
    149     uint64_t elapsedInclusive;
    150     int numCalls;
    151     struct MethodEntry *method;
    152 } TimedMethod;
    153 
    154 typedef struct ClassEntry {
    155     const char *className;
    156     uint64_t elapsedExclusive;
    157     int numMethods;
    158     struct MethodEntry **methods;       /* list of methods in this class */
    159     int numCalls[2];                    /* 0=normal, 1=recursive */
    160 } ClassEntry;
    161 
    162 typedef struct UniqueMethodEntry {
    163     uint64_t elapsedExclusive;
    164     int numMethods;
    165     struct MethodEntry **methods;       /* list of methods with same name */
    166     int numCalls[2];                    /* 0=normal, 1=recursive */
    167 } UniqueMethodEntry;
    168 
    169 /*
    170  * Entry from the method list.
    171  */
    172 typedef struct MethodEntry {
    173     unsigned int methodId;
    174     const char* className;
    175     const char* methodName;
    176     const char* signature;
    177     const char* fileName;
    178     int lineNum;
    179     uint64_t elapsedExclusive;
    180     uint64_t elapsedInclusive;
    181     uint64_t topExclusive;              /* non-recursive exclusive time */
    182     uint64_t recursiveInclusive;
    183     struct TimedMethod *parents[2];     /* 0=normal, 1=recursive */
    184     struct TimedMethod *children[2];    /* 0=normal, 1=recursive */
    185     int numCalls[2];                    /* 0=normal, 1=recursive */
    186     int index;                  /* used after sorting to number methods */
    187     int recursiveEntries;       /* number of entries on the stack */
    188     int graphState;             /* used when graphing to see if this method has been visited before */
    189 } MethodEntry;
    190 
    191 /*
    192  * The parsed contents of the key file.
    193  */
    194 typedef struct DataKeys {
    195     char*        fileData;      /* contents of the entire file */
    196     long         fileLen;
    197     int          numThreads;
    198     ThreadEntry* threads;
    199     int          numMethods;
    200     MethodEntry* methods;       /* 2 extra methods: "toplevel" and "unknown" */
    201     int*         methodCache;   /* methodId->methodIndex mapping */
    202     // TODO change to map methodId->method itself
    203 } DataKeys;
    204 
    205 #define TOPLEVEL_INDEX 0
    206 #define UNKNOWN_INDEX 1
    207 
    208 typedef struct StackEntry {
    209     MethodEntry *method;
    210     uint64_t    entryTime;
    211 } StackEntry;
    212 
    213 typedef struct CallStack {
    214     int           top;
    215     StackEntry    calls[MAX_STACK_DEPTH];
    216     uint64_t      lastEventTime;
    217     uint64_t      threadStartTime;
    218     uint64_t*     remTimes;
    219     // Note: remTimes keeps a sum of 'un-allocated' time for each thread, in case
    220     // we need to allocate it to one (or many) filter later. This would happen when
    221     // we see a method exit that maches a filter, but whose entry we hadn't seen.
    222     // TODO: consider moving remTimes into FilterTimes and change logic appropriately
    223 } CallStack;
    224 
    225 typedef struct DiffEntry {
    226     MethodEntry* method1;
    227     MethodEntry* method2;
    228     int64_t differenceExclusive;
    229     int64_t differenceInclusive;
    230     double differenceExclusivePercentage;
    231     double differenceInclusivePercentage;
    232 } DiffEntry;
    233 
    234 // Global options
    235 typedef struct Options {
    236     const char* traceFileName;
    237     const char* diffFileName;
    238     const char* graphFileName;
    239     const char* filterFileName;
    240     int keepDotFile;
    241     int dump;
    242     int outputHtml;
    243     const char* sortableUrl;
    244     int threshold;
    245 } Options;
    246 
    247 typedef struct TraceData {
    248     int numClasses;
    249     ClassEntry *classes;
    250     CallStack *stacks[MAX_THREADS];
    251     int depth[MAX_THREADS];
    252     int numUniqueMethods;
    253     UniqueMethodEntry *uniqueMethods;
    254 } TraceData;
    255 
    256 typedef struct FilterKey {
    257     int       type[2];    /* 0=class, 1=method; 2 needed for start and end keys */
    258     uint32_t  flags;      /* 1st bit = include cross-thread time */
    259     char*     keys[2];    /* 2 needed for start and end keys */
    260 } FilterKey;
    261 
    262 typedef struct FilterTimes {
    263     uint64_t   totalWaitTime;
    264     uint64_t*  threadWaitTimes;
    265     uint64_t*  threadExecutionTimesWhileWaiting;
    266     uint64_t*  threadExecutionTimes;
    267 } FilterTimes;
    268 
    269 typedef struct Filter {
    270     char*       filterName;
    271     FilterKey*  filterKeys;
    272     int         numKeys;
    273     int         activeCount;
    274     int*        activeThreads;
    275     int*        activationKeys;
    276     FilterTimes times;
    277 } Filter;
    278 
    279 int numFilters = 0; // global
    280 
    281 static Options gOptions;
    282 
    283 /* Escapes characters in the source string that are html special entities.
    284  * The escaped string is written to "dest" which must be large enough to
    285  * hold the result.  A pointer to "dest" is returned.  The characters and
    286  * their corresponding escape sequences are:
    287  *  '<'  &lt;
    288  *  '>'  &gt;
    289  *  '&'  &amp;
    290  */
    291 char *htmlEscape(const char *src, char *dest, int len)
    292 {
    293     char *destStart = dest;
    294 
    295     if (src == NULL)
    296         return NULL;
    297 
    298     int nbytes = 0;
    299     while (*src) {
    300         if (*src == '<') {
    301             nbytes += 4;
    302             if (nbytes >= len)
    303                 break;
    304             *dest++ = '&';
    305             *dest++ = 'l';
    306             *dest++ = 't';
    307             *dest++ = ';';
    308         } else if (*src == '>') {
    309             nbytes += 4;
    310             if (nbytes >= len)
    311                 break;
    312             *dest++ = '&';
    313             *dest++ = 'g';
    314             *dest++ = 't';
    315             *dest++ = ';';
    316         } else if (*src == '&') {
    317             nbytes += 5;
    318             if (nbytes >= len)
    319                 break;
    320             *dest++ = '&';
    321             *dest++ = 'a';
    322             *dest++ = 'm';
    323             *dest++ = 'p';
    324             *dest++ = ';';
    325         } else {
    326             nbytes += 1;
    327             if (nbytes >= len)
    328                 break;
    329             *dest++ = *src;
    330         }
    331         src += 1;
    332     }
    333     if (nbytes >= len) {
    334         fprintf(stderr, "htmlEscape(): buffer overflow\n");
    335         exit(1);
    336     }
    337     *dest = 0;
    338 
    339     return destStart;
    340 }
    341 
    342 /* Initializes a MethodEntry
    343  */
    344 void initMethodEntry(MethodEntry *method, unsigned int methodId,
    345                      const char *className, const char *methodName,
    346                      const char *signature, const char* fileName,
    347                      const char* lineNumStr)
    348 {
    349     method->methodId = methodId;
    350     method->className = className;
    351     method->methodName = methodName;
    352     method->signature = signature;
    353     method->fileName = fileName;
    354     method->lineNum = (lineNumStr != NULL) ? atoi(lineNumStr) : -1;
    355     method->elapsedExclusive = 0;
    356     method->elapsedInclusive = 0;
    357     method->topExclusive = 0;
    358     method->recursiveInclusive = 0;
    359     method->parents[0] = NULL;
    360     method->parents[1] = NULL;
    361     method->children[0] = NULL;
    362     method->children[1] = NULL;
    363     method->numCalls[0] = 0;
    364     method->numCalls[1] = 0;
    365     method->index = 0;
    366     method->recursiveEntries = 0;
    367 }
    368 
    369 /*
    370  * This comparison function is called from qsort() to sort
    371  * methods into decreasing order of exclusive elapsed time.
    372  */
    373 int compareElapsedExclusive(const void *a, const void *b) {
    374     uint64_t elapsed1, elapsed2;
    375     int result;
    376 
    377     const MethodEntry *methodA = *(const MethodEntry**)a;
    378     const MethodEntry *methodB = *(const MethodEntry**)b;
    379     elapsed1 = methodA->elapsedExclusive;
    380     elapsed2 = methodB->elapsedExclusive;
    381     if (elapsed1 < elapsed2)
    382         return 1;
    383     if (elapsed1 > elapsed2)
    384         return -1;
    385 
    386     /* If the elapsed times of two methods are equal, then sort them
    387      * into alphabetical order.
    388      */
    389     result = strcmp(methodA->className, methodB->className);
    390     if (result == 0) {
    391         if (methodA->methodName == NULL || methodB->methodName == NULL) {
    392             unsigned int idA = methodA->methodId;
    393             unsigned int idB = methodB->methodId;
    394             if (idA < idB)
    395                 return -1;
    396             if (idA > idB)
    397                 return 1;
    398             return 0;
    399         }
    400         result = strcmp(methodA->methodName, methodB->methodName);
    401         if (result == 0)
    402             result = strcmp(methodA->signature, methodB->signature);
    403     }
    404     return result;
    405 }
    406 
    407 /*
    408  * This comparison function is called from qsort() to sort
    409  * methods into decreasing order of inclusive elapsed time.
    410  */
    411 int compareElapsedInclusive(const void *a, const void *b) {
    412     const MethodEntry *methodA, *methodB;
    413     uint64_t elapsed1, elapsed2;
    414     int result;
    415 
    416     methodA = *(MethodEntry const **)a;
    417     methodB = *(MethodEntry const **)b;
    418     elapsed1 = methodA->elapsedInclusive;
    419     elapsed2 = methodB->elapsedInclusive;
    420     if (elapsed1 < elapsed2)
    421         return 1;
    422     if (elapsed1 > elapsed2)
    423         return -1;
    424 
    425     /* If the elapsed times of two methods are equal, then sort them
    426      * into alphabetical order.
    427      */
    428     result = strcmp(methodA->className, methodB->className);
    429     if (result == 0) {
    430         if (methodA->methodName == NULL || methodB->methodName == NULL) {
    431             unsigned int idA = methodA->methodId;
    432             unsigned int idB = methodB->methodId;
    433             if (idA < idB)
    434                 return -1;
    435             if (idA > idB)
    436                 return 1;
    437             return 0;
    438         }
    439         result = strcmp(methodA->methodName, methodB->methodName);
    440         if (result == 0)
    441             result = strcmp(methodA->signature, methodB->signature);
    442     }
    443     return result;
    444 }
    445 
    446 /*
    447  * This comparison function is called from qsort() to sort
    448  * threads into decreasing order of elapsed time.
    449  */
    450 int compareElapsed(const void *a, const void *b) {
    451     const ThreadEntry *threadA, *threadB;
    452     uint64_t elapsed1, elapsed2;
    453     int result = 0;
    454 
    455     threadA = (ThreadEntry const *)a;
    456     threadB = (ThreadEntry const *)b;
    457     elapsed1 = threadA->elapsedTime;
    458     elapsed2 = threadB->elapsedTime;
    459     if (elapsed1 < elapsed2)
    460         return 1;
    461     if (elapsed1 > elapsed2)
    462         return -1;
    463 
    464     /* If the elapsed times of two threads are equal, then sort them
    465      * by thread id.
    466      */
    467     int idA = threadA->threadId;
    468     int idB = threadB->threadId;
    469     if (idA < idB)
    470         result = -1;
    471     if (idA > idB)
    472         result = 1;
    473 
    474     return result;
    475 }
    476 
    477 /*
    478  * This comparison function is called from qsort() to sort
    479  * TimedMethods into decreasing order of inclusive elapsed time.
    480  */
    481 int compareTimedMethod(const void *a, const void *b) {
    482     const TimedMethod *timedA, *timedB;
    483     uint64_t elapsed1, elapsed2;
    484     int result;
    485 
    486     timedA = (TimedMethod const *)a;
    487     timedB = (TimedMethod const *)b;
    488     elapsed1 = timedA->elapsedInclusive;
    489     elapsed2 = timedB->elapsedInclusive;
    490     if (elapsed1 < elapsed2)
    491         return 1;
    492     if (elapsed1 > elapsed2)
    493         return -1;
    494 
    495     /* If the elapsed times of two methods are equal, then sort them
    496      * into alphabetical order.
    497      */
    498     MethodEntry *methodA = timedA->method;
    499     MethodEntry *methodB = timedB->method;
    500     result = strcmp(methodA->className, methodB->className);
    501     if (result == 0) {
    502         if (methodA->methodName == NULL || methodB->methodName == NULL) {
    503             unsigned int idA = methodA->methodId;
    504             unsigned int idB = methodB->methodId;
    505             if (idA < idB)
    506                 return -1;
    507             if (idA > idB)
    508                 return 1;
    509             return 0;
    510         }
    511         result = strcmp(methodA->methodName, methodB->methodName);
    512         if (result == 0)
    513             result = strcmp(methodA->signature, methodB->signature);
    514     }
    515     return result;
    516 }
    517 
    518 /*
    519  * This comparison function is called from qsort() to sort
    520  * MethodEntry pointers into alphabetical order of class names.
    521  */
    522 int compareClassNames(const void *a, const void *b) {
    523     int result;
    524 
    525     const MethodEntry *methodA = *(const MethodEntry**)a;
    526     const MethodEntry *methodB = *(const MethodEntry**)b;
    527     result = strcmp(methodA->className, methodB->className);
    528     if (result == 0) {
    529         unsigned int idA = methodA->methodId;
    530         unsigned int idB = methodB->methodId;
    531         if (idA < idB)
    532             return -1;
    533         if (idA > idB)
    534             return 1;
    535         return 0;
    536     }
    537     return result;
    538 }
    539 
    540 /*
    541  * This comparison function is called from qsort() to sort
    542  * classes into decreasing order of exclusive elapsed time.
    543  */
    544 int compareClassExclusive(const void *a, const void *b) {
    545     uint64_t elapsed1, elapsed2;
    546     int result;
    547 
    548     const ClassEntry *classA = *(const ClassEntry**)a;
    549     const ClassEntry *classB = *(const ClassEntry**)b;
    550     elapsed1 = classA->elapsedExclusive;
    551     elapsed2 = classB->elapsedExclusive;
    552     if (elapsed1 < elapsed2)
    553         return 1;
    554     if (elapsed1 > elapsed2)
    555         return -1;
    556 
    557     /* If the elapsed times of two classs are equal, then sort them
    558      * into alphabetical order.
    559      */
    560     result = strcmp(classA->className, classB->className);
    561     if (result == 0) {
    562         /* Break ties with the first method id.  This is probably not
    563          * needed.
    564          */
    565         unsigned int idA = classA->methods[0]->methodId;
    566         unsigned int idB = classB->methods[0]->methodId;
    567         if (idA < idB)
    568             return -1;
    569         if (idA > idB)
    570             return 1;
    571         return 0;
    572     }
    573     return result;
    574 }
    575 
    576 /*
    577  * This comparison function is called from qsort() to sort
    578  * MethodEntry pointers into alphabetical order by method name,
    579  * then by class name.
    580  */
    581 int compareMethodNames(const void *a, const void *b) {
    582     int result;
    583 
    584     const MethodEntry *methodA = *(const MethodEntry**)a;
    585     const MethodEntry *methodB = *(const MethodEntry**)b;
    586     if (methodA->methodName == NULL || methodB->methodName == NULL) {
    587         return compareClassNames(a, b);
    588     }
    589     result = strcmp(methodA->methodName, methodB->methodName);
    590     if (result == 0) {
    591         result = strcmp(methodA->className, methodB->className);
    592         if (result == 0) {
    593             unsigned int idA = methodA->methodId;
    594             unsigned int idB = methodB->methodId;
    595             if (idA < idB)
    596                 return -1;
    597             if (idA > idB)
    598                 return 1;
    599             return 0;
    600         }
    601     }
    602     return result;
    603 }
    604 
    605 /*
    606  * This comparison function is called from qsort() to sort
    607  * unique methods into decreasing order of exclusive elapsed time.
    608  */
    609 int compareUniqueExclusive(const void *a, const void *b) {
    610     uint64_t elapsed1, elapsed2;
    611     int result;
    612 
    613     const UniqueMethodEntry *uniqueA = *(const UniqueMethodEntry**)a;
    614     const UniqueMethodEntry *uniqueB = *(const UniqueMethodEntry**)b;
    615     elapsed1 = uniqueA->elapsedExclusive;
    616     elapsed2 = uniqueB->elapsedExclusive;
    617     if (elapsed1 < elapsed2)
    618         return 1;
    619     if (elapsed1 > elapsed2)
    620         return -1;
    621 
    622     /* If the elapsed times of two methods are equal, then sort them
    623      * into alphabetical order.
    624      */
    625     result = strcmp(uniqueA->methods[0]->className,
    626                     uniqueB->methods[0]->className);
    627     if (result == 0) {
    628         unsigned int idA = uniqueA->methods[0]->methodId;
    629         unsigned int idB = uniqueB->methods[0]->methodId;
    630         if (idA < idB)
    631             return -1;
    632         if (idA > idB)
    633             return 1;
    634         return 0;
    635     }
    636     return result;
    637 }
    638 
    639 /*
    640  * Free a DataKeys struct.
    641  */
    642 void freeDataKeys(DataKeys* pKeys)
    643 {
    644     if (pKeys == NULL)
    645         return;
    646 
    647     free(pKeys->fileData);
    648     free(pKeys->threads);
    649     free(pKeys->methods);
    650     free(pKeys->methodCache);
    651     free(pKeys);
    652 }
    653 
    654 /*
    655  * Find the offset to the next occurrence of the specified character.
    656  *
    657  * "data" should point somewhere within the current line.  "len" is the
    658  * number of bytes left in the buffer.
    659  *
    660  * Returns -1 if we hit the end of the buffer.
    661  */
    662 int findNextChar(const char* data, int len, char lookFor)
    663 {
    664     const char* start = data;
    665 
    666     while (len > 0) {
    667         if (*data == lookFor)
    668             return data - start;
    669 
    670         data++;
    671         len--;
    672     }
    673 
    674     return -1;
    675 }
    676 
    677 int countLinesToChar(const char* data, int len, const char toFind)
    678 {
    679     int count = 0;
    680     int next;
    681 
    682     while (*data != toFind) {
    683         next = findNextChar(data, len, '\n');
    684         if (next < 0)
    685 	    return count;
    686         count++;
    687         data += next+1;
    688         len -= next+1;
    689     }
    690 
    691     return count;
    692 }
    693 
    694 /*
    695  * Count the number of lines until the next token.
    696  *
    697  * Returns 0 if none found before EOF.
    698  */
    699 int countLinesToToken(const char* data, int len)
    700 {
    701     return countLinesToChar(data, len, TOKEN_CHAR);
    702 }
    703 
    704 /*
    705  * Make sure we're at the start of the right section.
    706  *
    707  * Returns the length of the token line, or -1 if something is wrong.
    708  */
    709 int checkToken(const char* data, int len, const char* cmpStr)
    710 {
    711     int cmpLen = strlen(cmpStr);
    712     int next;
    713 
    714     if (*data != TOKEN_CHAR) {
    715         fprintf(stderr,
    716             "ERROR: not at start of %s (found '%.10s')\n", cmpStr, data);
    717         return -1;
    718     }
    719 
    720     next = findNextChar(data, len, '\n');
    721     if (next < cmpLen+1)
    722         return -1;
    723 
    724     if (strncmp(data+1, cmpStr, cmpLen) != 0) {
    725         fprintf(stderr, "ERROR: '%s' not found (got '%.7s')\n", cmpStr, data+1);
    726         return -1;
    727     }
    728 
    729     return next+1;
    730 }
    731 
    732 /*
    733  * Parse the "*version" section.
    734  */
    735 long parseVersion(DataKeys* pKeys, long offset, int verbose)
    736 {
    737     char* data;
    738     char* dataEnd;
    739     int i, count, next;
    740 
    741     if (offset < 0)
    742         return -1;
    743 
    744     data = pKeys->fileData + offset;
    745     dataEnd = pKeys->fileData + pKeys->fileLen;
    746     next = checkToken(data, dataEnd - data, "version");
    747     if (next <= 0)
    748         return -1;
    749 
    750     data += next;
    751 
    752     /*
    753      * Count the number of items in the "version" section.
    754      */
    755     count = countLinesToToken(data, dataEnd - data);
    756     if (count <= 0) {
    757         fprintf(stderr,
    758             "ERROR: failed while reading version (found %d)\n", count);
    759         return -1;
    760     }
    761 
    762     /* find the end of the line */
    763     next = findNextChar(data, dataEnd - data, '\n');
    764     if (next < 0)
    765         return -1;
    766 
    767     data[next] = '\0';
    768     versionNumber = strtoul(data, NULL, 0);
    769     if (verbose)
    770         printf("VERSION: %d\n", versionNumber);
    771 
    772     data += next+1;
    773 
    774     /* skip over the rest of the stuff, which is "name=value" lines */
    775     for (i = 1; i < count; i++) {
    776         next = findNextChar(data, dataEnd - data, '\n');
    777         if (next < 0)
    778             return -1;
    779         //data[next] = '\0';
    780         //printf("IGNORING: '%s'\n", data);
    781         data += next+1;
    782     }
    783 
    784     return data - pKeys->fileData;
    785 }
    786 
    787 /*
    788  * Parse the "*threads" section.
    789  */
    790 long parseThreads(DataKeys* pKeys, long offset)
    791 {
    792     char* data;
    793     char* dataEnd;
    794     int i, next, tab, count;
    795 
    796     if (offset < 0)
    797         return -1;
    798 
    799     data = pKeys->fileData + offset;
    800     dataEnd = pKeys->fileData + pKeys->fileLen;
    801     next = checkToken(data, dataEnd - data, "threads");
    802 
    803     data += next;
    804 
    805     /*
    806      * Count the number of thread entries (one per line).
    807      */
    808     count = countLinesToToken(data, dataEnd - data);
    809     if (count <= 0) {
    810         fprintf(stderr,
    811             "ERROR: failed while reading threads (found %d)\n", count);
    812         return -1;
    813     }
    814 
    815     //printf("+++ found %d threads\n", count);
    816     pKeys->threads = (ThreadEntry*) malloc(sizeof(ThreadEntry) * count);
    817     if (pKeys->threads == NULL)
    818         return -1;
    819 
    820     /*
    821      * Extract all entries.
    822      */
    823     for (i = 0; i < count; i++) {
    824         next = findNextChar(data, dataEnd - data, '\n');
    825         assert(next > 0);
    826         data[next] = '\0';
    827 
    828         tab = findNextChar(data, next, '\t');
    829         data[tab] = '\0';
    830 
    831         pKeys->threads[i].threadId = atoi(data);
    832         pKeys->threads[i].threadName = data + tab +1;
    833 
    834         data += next+1;
    835     }
    836 
    837     pKeys->numThreads = count;
    838     return data - pKeys->fileData;
    839 }
    840 
    841 /*
    842  * Parse the "*methods" section.
    843  */
    844 long parseMethods(DataKeys* pKeys, long offset)
    845 {
    846     char* data;
    847     char* dataEnd;
    848     int i, next, count;
    849 
    850     if (offset < 0)
    851         return -1;
    852 
    853     data = pKeys->fileData + offset;
    854     dataEnd = pKeys->fileData + pKeys->fileLen;
    855     next = checkToken(data, dataEnd - data, "methods");
    856     if (next < 0)
    857         return -1;
    858 
    859     data += next;
    860 
    861     /*
    862      * Count the number of method entries (one per line).
    863      */
    864     count = countLinesToToken(data, dataEnd - data);
    865     if (count <= 0) {
    866         fprintf(stderr,
    867             "ERROR: failed while reading methods (found %d)\n", count);
    868         return -1;
    869     }
    870 
    871     /* Reserve an extra method at location 0 for the "toplevel" method,
    872      * and another extra method for all other "unknown" methods.
    873      */
    874     count += 2;
    875     pKeys->methods = (MethodEntry*) malloc(sizeof(MethodEntry) * count);
    876     if (pKeys->methods == NULL)
    877         return -1;
    878     initMethodEntry(&pKeys->methods[TOPLEVEL_INDEX], 0, "(toplevel)",
    879         NULL, NULL, NULL, NULL);
    880     initMethodEntry(&pKeys->methods[UNKNOWN_INDEX], 0, "(unknown)",
    881         NULL, NULL, NULL, NULL);
    882 
    883     /*
    884      * Extract all entries, starting with index 2.
    885      */
    886     for (i = UNKNOWN_INDEX + 1; i < count; i++) {
    887         int tab1, tab2, tab3, tab4, tab5;
    888         unsigned int id;
    889         char* endptr;
    890 
    891         next = findNextChar(data, dataEnd - data, '\n');
    892         assert(next > 0);
    893         data[next] = '\0';
    894 
    895         tab1 = findNextChar(data, next, '\t');
    896         tab2 = findNextChar(data+(tab1+1), next-(tab1+1), '\t');
    897         tab3 = findNextChar(data+(tab1+tab2+2), next-(tab1+tab2+2), '\t');
    898         tab4 = findNextChar(data+(tab1+tab2+tab3+3),
    899                             next-(tab1+tab2+tab3+3), '\t');
    900         tab5 = findNextChar(data+(tab1+tab2+tab3+tab4+4),
    901                             next-(tab1+tab2+tab3+tab4+4), '\t');
    902         if (tab1 < 0) {
    903             fprintf(stderr, "ERROR: missing field on method line: '%s'\n",
    904                     data);
    905             return -1;
    906         }
    907         assert(data[tab1] == '\t');
    908         data[tab1] = '\0';
    909 
    910         id = strtoul(data, &endptr, 0);
    911         if (*endptr != '\0') {
    912             fprintf(stderr, "ERROR: bad method ID '%s'\n", data);
    913             return -1;
    914         }
    915 
    916         // Allow files that specify just a function name, instead of requiring
    917         // "class \t method \t signature"
    918         if (tab2 > 0 && tab3 > 0) {
    919             tab2 += tab1+1;
    920             tab3 += tab2+1;
    921             assert(data[tab2] == '\t');
    922             assert(data[tab3] == '\t');
    923             data[tab2] = data[tab3] = '\0';
    924 
    925             // This is starting to get awkward.  Allow filename and line #.
    926             if (tab4 > 0 && tab5 > 0) {
    927                 tab4 += tab3+1;
    928                 tab5 += tab4+1;
    929 
    930                 assert(data[tab4] == '\t');
    931                 assert(data[tab5] == '\t');
    932                 data[tab4] = data[tab5] = '\0';
    933 
    934                 initMethodEntry(&pKeys->methods[i], id, data + tab1 +1,
    935                         data + tab2 +1, data + tab3 +1, data + tab4 +1,
    936                         data + tab5 +1);
    937             } else {
    938                 initMethodEntry(&pKeys->methods[i], id, data + tab1 +1,
    939                         data + tab2 +1, data + tab3 +1, NULL, NULL);
    940             }
    941         } else {
    942             initMethodEntry(&pKeys->methods[i], id, data + tab1 +1,
    943                 NULL, NULL, NULL, NULL);
    944         }
    945 
    946         data += next+1;
    947     }
    948 
    949     pKeys->numMethods = count;
    950     return data - pKeys->fileData;
    951 }
    952 
    953 /*
    954  * Parse the "*end" section.
    955  */
    956 long parseEnd(DataKeys* pKeys, long offset)
    957 {
    958     char* data;
    959     char* dataEnd;
    960     int next;
    961 
    962     if (offset < 0)
    963         return -1;
    964 
    965     data = pKeys->fileData + offset;
    966     dataEnd = pKeys->fileData + pKeys->fileLen;
    967     next = checkToken(data, dataEnd - data, "end");
    968     if (next < 0)
    969         return -1;
    970 
    971     data += next;
    972 
    973     return data - pKeys->fileData;
    974 }
    975 
    976 /*
    977  * Sort the thread list entries.
    978  */
    979 static int compareThreads(const void* thread1, const void* thread2)
    980 {
    981     return ((const ThreadEntry*) thread1)->threadId -
    982             ((const ThreadEntry*) thread2)->threadId;
    983 }
    984 
    985 void sortThreadList(DataKeys* pKeys)
    986 {
    987     qsort(pKeys->threads, pKeys->numThreads, sizeof(pKeys->threads[0]),
    988         compareThreads);
    989 }
    990 
    991 /*
    992  * Sort the method list entries.
    993  */
    994 static int compareMethods(const void* meth1, const void* meth2)
    995 {
    996     unsigned int id1, id2;
    997 
    998     id1 = ((const MethodEntry*) meth1)->methodId;
    999     id2 = ((const MethodEntry*) meth2)->methodId;
   1000     if (id1 < id2)
   1001         return -1;
   1002     if (id1 > id2)
   1003         return 1;
   1004     return 0;
   1005 }
   1006 
   1007 void sortMethodList(DataKeys* pKeys)
   1008 {
   1009     qsort(pKeys->methods, pKeys->numMethods, sizeof(MethodEntry),
   1010         compareMethods);
   1011 }
   1012 
   1013 /*
   1014  * Parse the key section, and return a copy of the parsed contents.
   1015  */
   1016 DataKeys* parseKeys(FILE *fp, int verbose)
   1017 {
   1018     DataKeys* pKeys = NULL;
   1019     long offset;
   1020     int i;
   1021 
   1022     pKeys = (DataKeys*) calloc(1, sizeof(DataKeys));
   1023     if (pKeys == NULL)
   1024         goto fail;
   1025 
   1026     /*
   1027      * We load the entire file into memory.  We do this, rather than memory-
   1028      * mapping it, because we want to change some whitespace to NULs.
   1029      */
   1030     if (fseek(fp, 0L, SEEK_END) != 0) {
   1031         perror("fseek");
   1032         goto fail;
   1033     }
   1034     pKeys->fileLen = ftell(fp);
   1035     if (pKeys->fileLen == 0) {
   1036         fprintf(stderr, "Key file is empty.\n");
   1037         goto fail;
   1038     }
   1039     rewind(fp);
   1040 
   1041     pKeys->fileData = (char*) malloc(pKeys->fileLen);
   1042     if (pKeys->fileData == NULL) {
   1043         fprintf(stderr, "ERROR: unable to alloc %ld bytes\n", pKeys->fileLen);
   1044         goto fail;
   1045     }
   1046 
   1047     if (fread(pKeys->fileData, 1, pKeys->fileLen, fp) != (size_t) pKeys->fileLen)
   1048     {
   1049         fprintf(stderr, "ERROR: unable to read %ld bytes from trace file\n",
   1050             pKeys->fileLen);
   1051         goto fail;
   1052     }
   1053 
   1054     offset = 0;
   1055 
   1056     offset = parseVersion(pKeys, offset, verbose);
   1057     offset = parseThreads(pKeys, offset);
   1058     offset = parseMethods(pKeys, offset);
   1059     offset = parseEnd(pKeys, offset);
   1060     if (offset < 0)
   1061         goto fail;
   1062 
   1063     /* Reduce our allocation now that we know where the end of the key section is. */
   1064     pKeys->fileData = (char *)realloc(pKeys->fileData, offset);
   1065     pKeys->fileLen = offset;
   1066     /* Leave fp pointing to the beginning of the data section. */
   1067     fseek(fp, offset, SEEK_SET);
   1068 
   1069     sortThreadList(pKeys);
   1070     sortMethodList(pKeys);
   1071 
   1072     /*
   1073      * Dump list of threads.
   1074      */
   1075     if (verbose) {
   1076         printf("Threads (%d):\n", pKeys->numThreads);
   1077         for (i = 0; i < pKeys->numThreads; i++) {
   1078             printf("%2d %s\n",
   1079                    pKeys->threads[i].threadId, pKeys->threads[i].threadName);
   1080         }
   1081     }
   1082 
   1083 #if 0
   1084     /*
   1085      * Dump list of methods.
   1086      */
   1087     if (verbose) {
   1088         printf("Methods (%d):\n", pKeys->numMethods);
   1089         for (i = 0; i < pKeys->numMethods; i++) {
   1090             printf("0x%08x %s : %s : %s\n",
   1091                    pKeys->methods[i].methodId >> 2, pKeys->methods[i].className,
   1092                    pKeys->methods[i].methodName, pKeys->methods[i].signature);
   1093         }
   1094     }
   1095 #endif
   1096 
   1097     return pKeys;
   1098 
   1099 fail:
   1100     freeDataKeys(pKeys);
   1101     return NULL;
   1102 }
   1103 
   1104 
   1105 /*
   1106  * Read values from the binary data file.
   1107  */
   1108 
   1109 /* Make the return value "unsigned int" instead of "unsigned short" so that
   1110  * we can detect EOF.
   1111  */
   1112 unsigned int read2LE(FILE* fp)
   1113 {
   1114     unsigned int val;
   1115 
   1116     val = getc(fp);
   1117     val |= getc(fp) << 8;
   1118     return val;
   1119 }
   1120 unsigned int read4LE(FILE* fp)
   1121 {
   1122     unsigned int val;
   1123 
   1124     val = getc(fp);
   1125     val |= getc(fp) << 8;
   1126     val |= getc(fp) << 16;
   1127     val |= getc(fp) << 24;
   1128     return val;
   1129 }
   1130 unsigned long long read8LE(FILE* fp)
   1131 {
   1132     unsigned long long val;
   1133 
   1134     val = getc(fp);
   1135     val |= (unsigned long long) getc(fp) << 8;
   1136     val |= (unsigned long long) getc(fp) << 16;
   1137     val |= (unsigned long long) getc(fp) << 24;
   1138     val |= (unsigned long long) getc(fp) << 32;
   1139     val |= (unsigned long long) getc(fp) << 40;
   1140     val |= (unsigned long long) getc(fp) << 48;
   1141     val |= (unsigned long long) getc(fp) << 56;
   1142     return val;
   1143 }
   1144 
   1145 /*
   1146  * Parse the header of the data section.
   1147  *
   1148  * Returns with the file positioned at the start of the record data.
   1149  */
   1150 int parseDataHeader(FILE *fp, DataHeader* pHeader)
   1151 {
   1152     pHeader->magic = read4LE(fp);
   1153     pHeader->version = read2LE(fp);
   1154     pHeader->offsetToData = read2LE(fp);
   1155     pHeader->startWhen = read8LE(fp);
   1156 
   1157     if (fseek(fp, pHeader->offsetToData - 16, SEEK_CUR) != 0) {
   1158         return -1;
   1159     }
   1160 
   1161     return 0;
   1162 }
   1163 
   1164 /*
   1165  * Look up a method by its method ID (using binary search).
   1166  *
   1167  * Returns NULL if no matching method was found.
   1168  */
   1169 MethodEntry* lookupMethod(DataKeys* pKeys, unsigned int methodId)
   1170 {
   1171     int hi, lo, mid;
   1172     unsigned int id;
   1173     int hashedId;
   1174 
   1175     /* Create cache if it doesn't already exist */
   1176     if (pKeys->methodCache == NULL) {
   1177         pKeys->methodCache = (int*) malloc(sizeof(int) * METHOD_CACHE_SIZE);
   1178     }
   1179 
   1180     // ids are multiples of 4, so shift
   1181     hashedId = (methodId >> 2) & METHOD_CACHE_SIZE_MASK;
   1182     if (pKeys->methodCache[hashedId]) /* cache hit */
   1183         if (pKeys->methods[pKeys->methodCache[hashedId]].methodId == methodId)
   1184 	    return &pKeys->methods[pKeys->methodCache[hashedId]];
   1185 
   1186     lo = 0;
   1187     hi = pKeys->numMethods - 1;
   1188 
   1189     while (hi >= lo) {
   1190         mid = (hi + lo) / 2;
   1191 
   1192         id = pKeys->methods[mid].methodId;
   1193         if (id == methodId) {         /* match, put in cache */
   1194 	    hashedId = (methodId >> 2) & METHOD_CACHE_SIZE_MASK;
   1195 	    pKeys->methodCache[hashedId] = mid;
   1196 	    return &pKeys->methods[mid];
   1197 	} else if (id < methodId)       /* too low */
   1198             lo = mid + 1;
   1199         else                          /* too high */
   1200             hi = mid - 1;
   1201     }
   1202 
   1203     return NULL;
   1204 }
   1205 
   1206 /*
   1207  * Reads the next data record, and assigns the data values to threadId,
   1208  * methodVal and elapsedTime.  On end-of-file, the threadId, methodVal,
   1209  * and elapsedTime are unchanged.  Returns 1 on end-of-file, otherwise
   1210  * returns 0.
   1211  */
   1212 int readDataRecord(FILE *dataFp, int *threadId, unsigned int *methodVal,
   1213                    uint64_t *elapsedTime)
   1214 {
   1215     int id;
   1216 
   1217     /*
   1218      * TODO:
   1219      * This SHOULD NOT be keyed off of the global version number!  Use
   1220      * a name=value setting in the version area instead!
   1221      */
   1222     if (versionNumber == 1) {
   1223         id = getc(dataFp);
   1224     } else {
   1225         id = read2LE(dataFp);
   1226     }
   1227     if (id == EOF)
   1228         return 1;
   1229     *threadId = id;
   1230 
   1231     *methodVal = read4LE(dataFp);
   1232     *elapsedTime = read4LE(dataFp);
   1233     if (feof(dataFp)) {
   1234         fprintf(stderr, "WARNING: hit EOF mid-record\n");
   1235         return 1;
   1236     }
   1237     return 0;
   1238 }
   1239 
   1240 /*
   1241  * Read the key file and use it to produce formatted output from the
   1242  * data file.
   1243  */
   1244 void dumpTrace()
   1245 {
   1246     static const char* actionStr[] = { "ent", "xit", "unr", "???" };
   1247     MethodEntry bogusMethod = { 0, "???", "???", "???", "???", -1, 0, 0, 0, 0,
   1248                                 {NULL, NULL}, {NULL, NULL}, {0, 0}, 0, 0, -1 };
   1249     char bogusBuf[80];
   1250     char spaces[MAX_STACK_DEPTH+1];
   1251     FILE* dataFp = NULL;
   1252     DataHeader dataHeader;
   1253     DataKeys* pKeys = NULL;
   1254     int i;
   1255     TraceData traceData;
   1256 
   1257     //printf("Dumping '%s' '%s'\n", dataFileName, keyFileName);
   1258 
   1259     memset(spaces, '.', MAX_STACK_DEPTH);
   1260     spaces[MAX_STACK_DEPTH] = '\0';
   1261 
   1262     for (i = 0; i < MAX_THREADS; i++)
   1263         traceData.depth[i] = 2;       // adjust for return from start function
   1264 
   1265     dataFp = fopen(gOptions.traceFileName, "r");
   1266     if (dataFp == NULL)
   1267         goto bail;
   1268 
   1269     if ((pKeys = parseKeys(dataFp, 1)) == NULL)
   1270         goto bail;
   1271 
   1272     if (parseDataHeader(dataFp, &dataHeader) < 0)
   1273         goto bail;
   1274 
   1275     printf("Trace (threadID action usecs class.method signature):\n");
   1276 
   1277     while (1) {
   1278         MethodEntry* method;
   1279         int threadId;
   1280         unsigned int methodVal;
   1281         uint64_t elapsedTime;
   1282         int action, printDepth;
   1283         unsigned int methodId, lastEnter = 0;
   1284         int mismatch = 0;
   1285         char depthNote;
   1286 
   1287         /*
   1288          * Extract values from file.
   1289          */
   1290         if (readDataRecord(dataFp, &threadId, &methodVal, &elapsedTime))
   1291             break;
   1292 
   1293         action = METHOD_ACTION(methodVal);
   1294         methodId = METHOD_ID(methodVal);
   1295 
   1296         /*
   1297          * Generate a line of output.
   1298          */
   1299         if (action == METHOD_TRACE_ENTER) {
   1300             traceData.depth[threadId]++;
   1301             lastEnter = methodId;
   1302         } else {
   1303             /* quick test for mismatched adjacent enter/exit */
   1304             if (lastEnter != 0 && lastEnter != methodId)
   1305                 mismatch = 1;
   1306         }
   1307 
   1308         printDepth = traceData.depth[threadId];
   1309         depthNote = ' ';
   1310         if (printDepth < 0) {
   1311             printDepth = 0;
   1312             depthNote = '-';
   1313         } else if (printDepth > MAX_STACK_DEPTH) {
   1314             printDepth = MAX_STACK_DEPTH;
   1315             depthNote = '+';
   1316         }
   1317 
   1318         method = lookupMethod(pKeys, methodId);
   1319         if (method == NULL) {
   1320             method = &bogusMethod;
   1321             sprintf(bogusBuf, "methodId: 0x%x", methodId);
   1322             method->signature = bogusBuf;
   1323         }
   1324 
   1325 	if (method->methodName) {
   1326 	    printf("%2d %s%c %8lld%c%s%s.%s %s\n", threadId,
   1327 		   actionStr[action], mismatch ? '!' : ' ',
   1328 		   elapsedTime, depthNote,
   1329 		   spaces + (MAX_STACK_DEPTH - printDepth),
   1330 		   method->className, method->methodName, method->signature);
   1331 	} else {
   1332 	    printf("%2d %s%c %8lld%c%s%s\n", threadId,
   1333 		   actionStr[action], mismatch ? '!' : ' ',
   1334 		   elapsedTime, depthNote,
   1335 		   spaces + (MAX_STACK_DEPTH - printDepth),
   1336 		   method->className);
   1337 	}
   1338 
   1339         if (action != METHOD_TRACE_ENTER) {
   1340             traceData.depth[threadId]--;  /* METHOD_TRACE_EXIT or METHOD_TRACE_UNROLL */
   1341             lastEnter = 0;
   1342         }
   1343 
   1344         mismatch = 0;
   1345     }
   1346 
   1347 bail:
   1348     if (dataFp != NULL)
   1349         fclose(dataFp);
   1350     if (pKeys != NULL)
   1351         freeDataKeys(pKeys);
   1352 }
   1353 
   1354 /* This routine adds the given time to the parent and child methods.
   1355  * This is called when the child routine exits, after the child has
   1356  * been popped from the stack.  The elapsedTime parameter is the
   1357  * duration of the child routine, including time spent in called routines.
   1358  */
   1359 void addInclusiveTime(MethodEntry *parent, MethodEntry *child,
   1360                       uint64_t elapsedTime)
   1361 {
   1362     TimedMethod *pTimed;
   1363 
   1364 #if 0
   1365     bool verbose = false;
   1366     if (strcmp(child->className, debugClassName) == 0)
   1367         verbose = true;
   1368 #endif
   1369 
   1370     int childIsRecursive = (child->recursiveEntries > 0);
   1371     int parentIsRecursive = (parent->recursiveEntries > 1);
   1372 
   1373     if (child->recursiveEntries == 0) {
   1374         child->elapsedInclusive += elapsedTime;
   1375     } else if (child->recursiveEntries == 1) {
   1376         child->recursiveInclusive += elapsedTime;
   1377     }
   1378     child->numCalls[childIsRecursive] += 1;
   1379 
   1380 #if 0
   1381     if (verbose) {
   1382         fprintf(stderr,
   1383                 "%s %d elapsedTime: %lld eI: %lld, rI: %lld\n",
   1384                 child->className, child->recursiveEntries,
   1385                 elapsedTime, child->elapsedInclusive,
   1386                 child->recursiveInclusive);
   1387     }
   1388 #endif
   1389 
   1390     /* Find the child method in the parent */
   1391     TimedMethod *children = parent->children[parentIsRecursive];
   1392     for (pTimed = children; pTimed; pTimed = pTimed->next) {
   1393         if (pTimed->method == child) {
   1394             pTimed->elapsedInclusive += elapsedTime;
   1395             pTimed->numCalls += 1;
   1396             break;
   1397         }
   1398     }
   1399     if (pTimed == NULL) {
   1400         /* Allocate a new TimedMethod */
   1401         pTimed = (TimedMethod *) malloc(sizeof(TimedMethod));
   1402         pTimed->elapsedInclusive = elapsedTime;
   1403         pTimed->numCalls = 1;
   1404         pTimed->method = child;
   1405 
   1406         /* Add it to the front of the list */
   1407         pTimed->next = children;
   1408         parent->children[parentIsRecursive] = pTimed;
   1409     }
   1410 
   1411     /* Find the parent method in the child */
   1412     TimedMethod *parents = child->parents[childIsRecursive];
   1413     for (pTimed = parents; pTimed; pTimed = pTimed->next) {
   1414         if (pTimed->method == parent) {
   1415             pTimed->elapsedInclusive += elapsedTime;
   1416             pTimed->numCalls += 1;
   1417             break;
   1418         }
   1419     }
   1420     if (pTimed == NULL) {
   1421         /* Allocate a new TimedMethod */
   1422         pTimed = (TimedMethod *) malloc(sizeof(TimedMethod));
   1423         pTimed->elapsedInclusive = elapsedTime;
   1424         pTimed->numCalls = 1;
   1425         pTimed->method = parent;
   1426 
   1427         /* Add it to the front of the list */
   1428         pTimed->next = parents;
   1429         child->parents[childIsRecursive] = pTimed;
   1430     }
   1431 
   1432 #if 0
   1433     if (verbose) {
   1434         fprintf(stderr,
   1435                 "  %s %d eI: %lld\n",
   1436                 parent->className, parent->recursiveEntries,
   1437                 pTimed->elapsedInclusive);
   1438     }
   1439 #endif
   1440 }
   1441 
   1442 /* Sorts a linked list and returns a newly allocated array containing
   1443  * the sorted entries.
   1444  */
   1445 TimedMethod *sortTimedMethodList(TimedMethod *list, int *num)
   1446 {
   1447     int ii;
   1448     TimedMethod *pTimed, *sorted;
   1449 
   1450     /* Count the elements */
   1451     int num_entries = 0;
   1452     for (pTimed = list; pTimed; pTimed = pTimed->next)
   1453         num_entries += 1;
   1454     *num = num_entries;
   1455     if (num_entries == 0)
   1456         return NULL;
   1457 
   1458     /* Copy all the list elements to a new array and sort them */
   1459     sorted = (TimedMethod *) malloc(sizeof(TimedMethod) * num_entries);
   1460     for (ii = 0, pTimed = list; pTimed; pTimed = pTimed->next, ++ii)
   1461         memcpy(&sorted[ii], pTimed, sizeof(TimedMethod));
   1462     qsort(sorted, num_entries, sizeof(TimedMethod), compareTimedMethod);
   1463 
   1464     /* Fix up the "next" pointers so that they work. */
   1465     for (ii = 0; ii < num_entries - 1; ++ii)
   1466         sorted[ii].next = &sorted[ii + 1];
   1467     sorted[num_entries - 1].next = NULL;
   1468 
   1469     return sorted;
   1470 }
   1471 
   1472 /* Define flag values for printInclusiveMethod() */
   1473 static const int kIsRecursive = 1;
   1474 
   1475 /* This prints the inclusive stats for all the parents or children of a
   1476  * method, depending on the list that is passed in.
   1477  */
   1478 void printInclusiveMethod(MethodEntry *method, TimedMethod *list, int numCalls,
   1479                           int flags)
   1480 {
   1481     int num;
   1482     TimedMethod *pTimed;
   1483     char buf[80];
   1484     char *anchor_close;
   1485     char *spaces = "      ";    /* 6 spaces */
   1486     int num_spaces = strlen(spaces);
   1487     char *space_ptr = &spaces[num_spaces];
   1488     char *className, *methodName, *signature;
   1489     char classBuf[HTML_BUFSIZE], methodBuf[HTML_BUFSIZE];
   1490     char signatureBuf[HTML_BUFSIZE];
   1491 
   1492     anchor_close = "";
   1493     if (gOptions.outputHtml)
   1494         anchor_close = "</a>";
   1495 
   1496     TimedMethod *sorted = sortTimedMethodList(list,  &num);
   1497     double methodTotal = method->elapsedInclusive;
   1498     for (pTimed = sorted; pTimed; pTimed = pTimed->next) {
   1499         MethodEntry *relative = pTimed->method;
   1500         className = (char*)(relative->className);
   1501         methodName = (char*)(relative->methodName);
   1502         signature = (char*)(relative->signature);
   1503         double per = 100.0 * pTimed->elapsedInclusive / methodTotal;
   1504         sprintf(buf, "[%d]", relative->index);
   1505         if (gOptions.outputHtml) {
   1506             int len = strlen(buf);
   1507             if (len > num_spaces)
   1508                 len = num_spaces;
   1509             sprintf(buf, "<a href=\"#m%d\">[%d]",
   1510                     relative->index, relative->index);
   1511             space_ptr = &spaces[len];
   1512             className = htmlEscape(className, classBuf, HTML_BUFSIZE);
   1513             methodName = htmlEscape(methodName, methodBuf, HTML_BUFSIZE);
   1514             signature = htmlEscape(signature, signatureBuf, HTML_BUFSIZE);
   1515         }
   1516         int nCalls = numCalls;
   1517         if (nCalls == 0)
   1518             nCalls = relative->numCalls[0] + relative->numCalls[1];
   1519         if (relative->methodName) {
   1520             if (flags & kIsRecursive) {
   1521                 // Don't display percentages for recursive functions
   1522                 printf("%6s %5s   %6s %s%6s%s %6d/%-6d %9llu %s.%s %s\n",
   1523                        "", "", "",
   1524                        space_ptr, buf, anchor_close,
   1525                        pTimed->numCalls, nCalls,
   1526                        pTimed->elapsedInclusive,
   1527                        className, methodName, signature);
   1528             } else {
   1529                 printf("%6s %5s   %5.1f%% %s%6s%s %6d/%-6d %9llu %s.%s %s\n",
   1530                        "", "", per,
   1531                        space_ptr, buf, anchor_close,
   1532                        pTimed->numCalls, nCalls,
   1533                        pTimed->elapsedInclusive,
   1534                        className, methodName, signature);
   1535             }
   1536         } else {
   1537             if (flags & kIsRecursive) {
   1538                 // Don't display percentages for recursive functions
   1539                 printf("%6s %5s   %6s %s%6s%s %6d/%-6d %9llu %s\n",
   1540                        "", "", "",
   1541                        space_ptr, buf, anchor_close,
   1542                        pTimed->numCalls, nCalls,
   1543                        pTimed->elapsedInclusive,
   1544                        className);
   1545             } else {
   1546                 printf("%6s %5s   %5.1f%% %s%6s%s %6d/%-6d %9llu %s\n",
   1547                        "", "", per,
   1548                        space_ptr, buf, anchor_close,
   1549                        pTimed->numCalls, nCalls,
   1550                        pTimed->elapsedInclusive,
   1551                        className);
   1552             }
   1553         }
   1554     }
   1555 }
   1556 
   1557 void countRecursiveEntries(CallStack *pStack, int top, MethodEntry *method)
   1558 {
   1559     int ii;
   1560 
   1561     method->recursiveEntries = 0;
   1562     for (ii = 0; ii < top; ++ii) {
   1563         if (pStack->calls[ii].method == method)
   1564             method->recursiveEntries += 1;
   1565     }
   1566 }
   1567 
   1568 void stackDump(CallStack *pStack, int top)
   1569 {
   1570     int ii;
   1571 
   1572     for (ii = 0; ii < top; ++ii) {
   1573         MethodEntry *method = pStack->calls[ii].method;
   1574         uint64_t entryTime = pStack->calls[ii].entryTime;
   1575         if (method->methodName) {
   1576             fprintf(stderr, "  %2d: %8llu %s.%s %s\n", ii, entryTime,
   1577                    method->className, method->methodName, method->signature);
   1578         } else {
   1579             fprintf(stderr, "  %2d: %8llu %s\n", ii, entryTime, method->className);
   1580         }
   1581     }
   1582 }
   1583 
   1584 void outputTableOfContents()
   1585 {
   1586     printf("<a name=\"contents\"></a>\n");
   1587     printf("<h2>Table of Contents</h2>\n");
   1588     printf("<ul>\n");
   1589     printf("  <li><a href=\"#exclusive\">Exclusive profile</a></li>\n");
   1590     printf("  <li><a href=\"#inclusive\">Inclusive profile</a></li>\n");
   1591     printf("  <li><a href=\"#thread\">Thread profile</a></li>\n");
   1592     printf("  <li><a href=\"#class\">Class/method profile</a></li>\n");
   1593     printf("  <li><a href=\"#method\">Method/class profile</a></li>\n");
   1594     printf("</ul>\n\n");
   1595 }
   1596 
   1597 void outputNavigationBar()
   1598 {
   1599     printf("<a href=\"#contents\">[Top]</a>\n");
   1600     printf("<a href=\"#exclusive\">[Exclusive]</a>\n");
   1601     printf("<a href=\"#inclusive\">[Inclusive]</a>\n");
   1602     printf("<a href=\"#thread\">[Thread]</a>\n");
   1603     printf("<a href=\"#class\">[Class]</a>\n");
   1604     printf("<a href=\"#method\">[Method]</a>\n");
   1605     printf("<br><br>\n");
   1606 }
   1607 
   1608 void printExclusiveProfile(MethodEntry **pMethods, int numMethods,
   1609                            uint64_t sumThreadTime)
   1610 {
   1611     int ii;
   1612     MethodEntry* method;
   1613     double total, sum, per, sum_per;
   1614     char classBuf[HTML_BUFSIZE], methodBuf[HTML_BUFSIZE];
   1615     char signatureBuf[HTML_BUFSIZE];
   1616     char anchor_buf[80];
   1617     char *anchor_close = "";
   1618 
   1619     total = sumThreadTime;
   1620     anchor_buf[0] = 0;
   1621     if (gOptions.outputHtml) {
   1622         anchor_close = "</a>";
   1623         printf("<a name=\"exclusive\"></a>\n");
   1624         printf("<hr>\n");
   1625         outputNavigationBar();
   1626     } else {
   1627         printf("\n%s\n", profileSeparator);
   1628     }
   1629 
   1630     /* First, sort the methods into decreasing order of inclusive
   1631      * elapsed time so that we can assign the method indices.
   1632      */
   1633     qsort(pMethods, numMethods, sizeof(MethodEntry*), compareElapsedInclusive);
   1634 
   1635     for (ii = 0; ii < numMethods; ++ii)
   1636         pMethods[ii]->index = ii;
   1637 
   1638     /* Sort the methods into decreasing order of exclusive elapsed time.
   1639      */
   1640     qsort(pMethods, numMethods, sizeof(MethodEntry*),
   1641           compareElapsedExclusive);
   1642 
   1643     printf("Total cycles: %llu\n\n", sumThreadTime);
   1644     if (gOptions.outputHtml) {
   1645         printf("<br><br>\n");
   1646     }
   1647     printf("Exclusive elapsed times for each method, not including time spent in\n");
   1648     printf("children, sorted by exclusive time.\n\n");
   1649     if (gOptions.outputHtml) {
   1650         printf("<br><br>\n<pre>\n");
   1651     }
   1652 
   1653     printf("    Usecs  self %%  sum %%  Method\n");
   1654     sum = 0;
   1655 
   1656     for (ii = 0; ii < numMethods; ++ii) {
   1657         char *className, *methodName, *signature;
   1658 
   1659         method = pMethods[ii];
   1660         /* Don't show methods with zero cycles */
   1661         if (method->elapsedExclusive == 0)
   1662             break;
   1663         className = (char*)(method->className);
   1664         methodName = (char*)(method->methodName);
   1665         signature = (char*)(method->signature);
   1666         sum += method->elapsedExclusive;
   1667         per = 100.0 * method->elapsedExclusive / total;
   1668         sum_per = 100.0 * sum / total;
   1669         if (gOptions.outputHtml) {
   1670             sprintf(anchor_buf, "<a href=\"#m%d\">", method->index);
   1671             className = htmlEscape(className, classBuf, HTML_BUFSIZE);
   1672             methodName = htmlEscape(methodName, methodBuf, HTML_BUFSIZE);
   1673             signature = htmlEscape(signature, signatureBuf, HTML_BUFSIZE);
   1674         }
   1675         if (method->methodName) {
   1676             printf("%9llu  %6.2f %6.2f  %s[%d]%s %s.%s %s\n",
   1677                    method->elapsedExclusive, per, sum_per,
   1678                    anchor_buf, method->index, anchor_close,
   1679                    className, methodName, signature);
   1680         } else {
   1681             printf("%9llu  %6.2f %6.2f  %s[%d]%s %s\n",
   1682                    method->elapsedExclusive, per, sum_per,
   1683                    anchor_buf, method->index, anchor_close,
   1684                    className);
   1685         }
   1686     }
   1687     if (gOptions.outputHtml) {
   1688         printf("</pre>\n");
   1689     }
   1690 }
   1691 
   1692 /* check to make sure that the child method meets the threshold of the parent */
   1693 int checkThreshold(MethodEntry* parent, MethodEntry* child)
   1694 {
   1695     double parentTime = parent->elapsedInclusive;
   1696     double childTime = child->elapsedInclusive;
   1697     int64_t percentage = (childTime / parentTime) * 100.0;
   1698     return (percentage < gOptions.threshold) ? 0 : 1;
   1699 }
   1700 
   1701 void createLabels(FILE* file, MethodEntry* method)
   1702 {
   1703     fprintf(file, "node%d[label = \"[%d] %s.%s (%llu, %llu, %d)\"]\n",
   1704              method->index, method->index, method->className, method->methodName,
   1705              method->elapsedInclusive / 1000,
   1706              method->elapsedExclusive / 1000,
   1707              method->numCalls[0]);
   1708 
   1709     method->graphState = GRAPH_LABEL_VISITED;
   1710 
   1711     TimedMethod* child;
   1712     for (child = method->children[0] ; child ; child = child->next) {
   1713         MethodEntry* childMethod = child->method;
   1714 
   1715         if ((childMethod->graphState & GRAPH_LABEL_VISITED) == 0 && checkThreshold(method, childMethod)) {
   1716             createLabels(file, child->method);
   1717         }
   1718     }
   1719 }
   1720 
   1721 void createLinks(FILE* file, MethodEntry* method)
   1722 {
   1723     method->graphState |= GRAPH_NODE_VISITED;
   1724 
   1725     TimedMethod* child;
   1726     for (child = method->children[0] ; child ; child = child->next) {
   1727         MethodEntry* childMethod = child->method;
   1728         if (checkThreshold(method, child->method)) {
   1729             fprintf(file, "node%d -> node%d\n", method->index, child->method->index);
   1730             // only visit children that haven't been visited before
   1731             if ((childMethod->graphState & GRAPH_NODE_VISITED) == 0) {
   1732                 createLinks(file, child->method);
   1733             }
   1734         }
   1735     }
   1736 }
   1737 
   1738 void createInclusiveProfileGraphNew(DataKeys* dataKeys)
   1739 {
   1740     // create a temporary file in /tmp
   1741     char path[FILENAME_MAX];
   1742     if (gOptions.keepDotFile) {
   1743         snprintf(path, FILENAME_MAX, "%s.dot", gOptions.graphFileName);
   1744     } else {
   1745         snprintf(path, FILENAME_MAX, "/tmp/dot-%d-%d.dot", (int)time(NULL), rand());
   1746     }
   1747 
   1748     FILE* file = fopen(path, "w+");
   1749 
   1750     fprintf(file, "digraph g {\nnode [shape = record,height=.1];\n");
   1751 
   1752     createLabels(file, dataKeys->methods);
   1753     createLinks(file, dataKeys->methods);
   1754 
   1755     fprintf(file, "}");
   1756     fclose(file);
   1757 
   1758     // now that we have the dot file generate the image
   1759     char command[1024];
   1760     snprintf(command, 1024, "dot -Tpng -o '%s' '%s'", gOptions.graphFileName, path);
   1761 
   1762     system(command);
   1763 
   1764     if (! gOptions.keepDotFile) {
   1765         remove(path);
   1766     }
   1767 }
   1768 
   1769 void printInclusiveProfile(MethodEntry **pMethods, int numMethods,
   1770                            uint64_t sumThreadTime)
   1771 {
   1772     int ii;
   1773     MethodEntry* method;
   1774     double total, sum, per, sum_per;
   1775     char classBuf[HTML_BUFSIZE], methodBuf[HTML_BUFSIZE];
   1776     char signatureBuf[HTML_BUFSIZE];
   1777     char anchor_buf[80];
   1778 
   1779     total = sumThreadTime;
   1780     anchor_buf[0] = 0;
   1781     if (gOptions.outputHtml) {
   1782         printf("<a name=\"inclusive\"></a>\n");
   1783         printf("<hr>\n");
   1784         outputNavigationBar();
   1785     } else {
   1786         printf("\n%s\n", profileSeparator);
   1787     }
   1788 
   1789     /* Sort the methods into decreasing order of inclusive elapsed time. */
   1790     qsort(pMethods, numMethods, sizeof(MethodEntry*),
   1791           compareElapsedInclusive);
   1792 
   1793     printf("\nInclusive elapsed times for each method and its parents and children,\n");
   1794     printf("sorted by inclusive time.\n\n");
   1795 
   1796     if (gOptions.outputHtml) {
   1797         printf("<br><br>\n<pre>\n");
   1798     }
   1799 
   1800     printf("index  %%/total %%/self  index     calls         usecs name\n");
   1801     for (ii = 0; ii < numMethods; ++ii) {
   1802         int num;
   1803         TimedMethod *pTimed;
   1804         double excl_per;
   1805         char buf[40];
   1806         char *className, *methodName, *signature;
   1807 
   1808         method = pMethods[ii];
   1809         /* Don't show methods with zero cycles */
   1810         if (method->elapsedInclusive == 0)
   1811             break;
   1812 
   1813         className = (char*)(method->className);
   1814         methodName = (char*)(method->methodName);
   1815         signature = (char*)(method->signature);
   1816 
   1817         if (gOptions.outputHtml) {
   1818             printf("<a name=\"m%d\"></a>", method->index);
   1819             className = htmlEscape(className, classBuf, HTML_BUFSIZE);
   1820             methodName = htmlEscape(methodName, methodBuf, HTML_BUFSIZE);
   1821             signature = htmlEscape(signature, signatureBuf, HTML_BUFSIZE);
   1822         }
   1823         printf("----------------------------------------------------\n");
   1824 
   1825         /* Sort and print the parents */
   1826         int numCalls = method->numCalls[0] + method->numCalls[1];
   1827         printInclusiveMethod(method, method->parents[0], numCalls, 0);
   1828         if (method->parents[1]) {
   1829             printf("               +++++++++++++++++++++++++\n");
   1830             printInclusiveMethod(method, method->parents[1], numCalls,
   1831                                  kIsRecursive);
   1832         }
   1833 
   1834         per = 100.0 * method->elapsedInclusive / total;
   1835         sprintf(buf, "[%d]", ii);
   1836         if (method->methodName) {
   1837             printf("%-6s %5.1f%%   %5s %6s %6d+%-6d %9llu %s.%s %s\n",
   1838                    buf,
   1839                    per, "", "", method->numCalls[0], method->numCalls[1],
   1840                    method->elapsedInclusive,
   1841                    className, methodName, signature);
   1842         } else {
   1843             printf("%-6s %5.1f%%   %5s %6s %6d+%-6d %9llu %s\n",
   1844                    buf,
   1845                    per, "", "", method->numCalls[0], method->numCalls[1],
   1846                    method->elapsedInclusive,
   1847                    className);
   1848         }
   1849         excl_per = 100.0 * method->topExclusive / method->elapsedInclusive;
   1850         printf("%6s %5s   %5.1f%% %6s %6s %6s %9llu\n",
   1851                "", "", excl_per, "excl", "", "", method->topExclusive);
   1852 
   1853         /* Sort and print the children */
   1854         printInclusiveMethod(method, method->children[0], 0, 0);
   1855         if (method->children[1]) {
   1856             printf("               +++++++++++++++++++++++++\n");
   1857             printInclusiveMethod(method, method->children[1], 0,
   1858                                  kIsRecursive);
   1859         }
   1860     }
   1861     if (gOptions.outputHtml) {
   1862         printf("</pre>\n");
   1863     }
   1864 }
   1865 
   1866 void printThreadProfile(ThreadEntry *pThreads, int numThreads, uint64_t sumThreadTime, Filter** filters)
   1867 {
   1868     int ii, jj;
   1869     ThreadEntry thread;
   1870     double total, per, sum_per;
   1871     uint64_t sum;
   1872     char threadBuf[HTML_BUFSIZE];
   1873     char anchor_buf[80];
   1874     int drawTable;
   1875 
   1876     total = sumThreadTime;
   1877     anchor_buf[0] = 0;
   1878     if (gOptions.outputHtml) {
   1879         printf("<a name=\"thread\"></a>\n");
   1880         printf("<hr>\n");
   1881         outputNavigationBar();
   1882     } else {
   1883         printf("\n%s\n", profileSeparator);
   1884     }
   1885 
   1886     /* Sort the threads into decreasing order of elapsed time. */
   1887     qsort(pThreads, numThreads, sizeof(ThreadEntry), compareElapsed);
   1888 
   1889     printf("\nElapsed times for each thread, sorted by elapsed time.\n");
   1890     printf("Also includes percentage of time spent during the <i>execution</i> of any filters.\n\n");
   1891 
   1892     if (gOptions.outputHtml) {
   1893         printf("<br><br>\n<pre>\n");
   1894     }
   1895 
   1896     printf("    Usecs   self %%  sum %%");
   1897     for (ii = 0; ii < numFilters; ++ii) {
   1898         printf("  %s %%", filters[ii]->filterName);
   1899     }
   1900     printf("  tid   ThreadName\n");
   1901     sum = 0;
   1902 
   1903     for (ii = 0; ii < numThreads; ++ii) {
   1904         int threadId;
   1905         char *threadName;
   1906         uint64_t time;
   1907 
   1908         thread = pThreads[ii];
   1909 
   1910         threadId = thread.threadId;
   1911         threadName = (char*)(thread.threadName);
   1912         time = thread.elapsedTime;
   1913 
   1914         sum += time;
   1915         per = 100.0 * time / total;
   1916         sum_per = 100.0 * sum / total;
   1917 
   1918         if (gOptions.outputHtml) {
   1919 	    threadName = htmlEscape(threadName, threadBuf, HTML_BUFSIZE);
   1920         }
   1921 
   1922 	printf("%9llu  %6.2f %6.2f", time, per, sum_per);
   1923 	for (jj = 0; jj < numFilters; jj++) {
   1924 	    printf(" %6.2f", 100.0 * filters[jj]->times.threadExecutionTimes[threadId] / time);
   1925 	}
   1926 	printf("    %3d %s\n", threadId, threadName);
   1927     }
   1928 
   1929     if (gOptions.outputHtml)
   1930         printf("</pre><br />");
   1931 
   1932     printf("\n\nBreak-down of portion of time spent by each thread while waiting on a filter method.\n");
   1933 
   1934     for (ii = 0; ii < numFilters; ++ii) {
   1935         // Draw a table for each filter that measures wait time
   1936         drawTable = 0;
   1937 	for (jj = 0; jj < filters[ii]->numKeys; jj++)
   1938 	    if (filters[ii]->filterKeys[jj].flags == 1)
   1939 	        drawTable = 1;
   1940 
   1941 	if (drawTable) {
   1942 
   1943 	    if (gOptions.outputHtml)
   1944 	        printf("<br/><br/>\n<pre>\n");
   1945 	    printf("Filter: %s\n", filters[ii]->filterName);
   1946 	    printf("Total waiting cycles: %llu (%6.2f%% of total)\n",
   1947 		   filters[ii]->times.totalWaitTime,
   1948 		   100.0 * filters[ii]->times.totalWaitTime / sum);
   1949 
   1950 	    if (filters[ii]->times.totalWaitTime > 0) {
   1951 
   1952 	        printf("Details: \n\n");
   1953 
   1954 		printf(" Waiting cycles    %% of total waiting time   execution time while waiting    thread name\n");
   1955 
   1956 		for (jj = 0; jj < numThreads; jj++) {
   1957 
   1958 		    thread = pThreads[jj];
   1959 
   1960 		    char *threadName;
   1961 		    threadName = (char*) thread.threadName;
   1962 		    if (gOptions.outputHtml) {
   1963 		        threadName = htmlEscape(threadName, threadBuf, HTML_BUFSIZE);
   1964 		    }
   1965 
   1966 		    printf(" %9llu                   %6.2f                     %6.2f               %s\n",
   1967 			   filters[ii]->times.threadWaitTimes[thread.threadId],
   1968 			   100.0 * filters[ii]->times.threadWaitTimes[thread.threadId] / filters[ii]->times.totalWaitTime,
   1969 			   100.0 * filters[ii]->times.threadExecutionTimesWhileWaiting[thread.threadId] / filters[ii]->times.totalWaitTime,
   1970 			   threadName);
   1971 		}
   1972 	    }
   1973 
   1974 	    if (gOptions.outputHtml)
   1975 	        printf("</pre>\n");
   1976 
   1977 	}
   1978     }
   1979 
   1980 }
   1981 
   1982 void createClassList(TraceData* traceData, MethodEntry **pMethods, int numMethods)
   1983 {
   1984     int ii;
   1985 
   1986     /* Sort the methods into alphabetical order to find the unique class
   1987      * names.
   1988      */
   1989     qsort(pMethods, numMethods, sizeof(MethodEntry*), compareClassNames);
   1990 
   1991     /* Count the number of unique class names. */
   1992     const char *currentClassName = "";
   1993     const char *firstClassName = NULL;
   1994     traceData->numClasses = 0;
   1995     for (ii = 0; ii < numMethods; ++ii) {
   1996         if (pMethods[ii]->methodName == NULL) {
   1997             continue;
   1998         }
   1999         if (strcmp(pMethods[ii]->className, currentClassName) != 0) {
   2000             // Remember the first one
   2001             if (firstClassName == NULL) {
   2002                 firstClassName = pMethods[ii]->className;
   2003             }
   2004             traceData->numClasses += 1;
   2005             currentClassName = pMethods[ii]->className;
   2006         }
   2007     }
   2008 
   2009     if (traceData->numClasses == 0) {
   2010         traceData->classes = NULL;
   2011         return;
   2012     }
   2013 
   2014     /* Allocate space for all of the unique class names */
   2015     traceData->classes = (ClassEntry *) malloc(sizeof(ClassEntry) * traceData->numClasses);
   2016 
   2017     /* Initialize the classes array */
   2018     memset(traceData->classes, 0, sizeof(ClassEntry) * traceData->numClasses);
   2019     ClassEntry *pClass = traceData->classes;
   2020     pClass->className = currentClassName = firstClassName;
   2021     int prevNumMethods = 0;
   2022     for (ii = 0; ii < numMethods; ++ii) {
   2023         if (pMethods[ii]->methodName == NULL) {
   2024             continue;
   2025         }
   2026         if (strcmp(pMethods[ii]->className, currentClassName) != 0) {
   2027             pClass->numMethods = prevNumMethods;
   2028             (++pClass)->className = currentClassName = pMethods[ii]->className;
   2029             prevNumMethods = 0;
   2030         }
   2031         prevNumMethods += 1;
   2032     }
   2033     pClass->numMethods = prevNumMethods;
   2034 
   2035     /* Create the array of MethodEntry pointers for each class */
   2036     pClass = NULL;
   2037     currentClassName = "";
   2038     int nextMethod = 0;
   2039     for (ii = 0; ii < numMethods; ++ii) {
   2040         if (pMethods[ii]->methodName == NULL) {
   2041             continue;
   2042         }
   2043         if (strcmp(pMethods[ii]->className, currentClassName) != 0) {
   2044             currentClassName = pMethods[ii]->className;
   2045             if (pClass == NULL)
   2046                 pClass = traceData->classes;
   2047             else
   2048                 pClass++;
   2049             /* Allocate space for the methods array */
   2050             int nbytes = sizeof(MethodEntry*) * pClass->numMethods;
   2051             pClass->methods = (MethodEntry**) malloc(nbytes);
   2052             nextMethod = 0;
   2053         }
   2054         pClass->methods[nextMethod++] = pMethods[ii];
   2055     }
   2056 }
   2057 
   2058 /* Prints a number of html non-breaking spaces according so that the length
   2059  * of the string "buf" is at least "width" characters wide.  If width is
   2060  * negative, then trailing spaces are added instead of leading spaces.
   2061  */
   2062 void printHtmlField(char *buf, int width)
   2063 {
   2064     int ii;
   2065 
   2066     int leadingSpaces = 1;
   2067     if (width < 0) {
   2068         width = -width;
   2069         leadingSpaces = 0;
   2070     }
   2071     int len = strlen(buf);
   2072     int numSpaces = width - len;
   2073     if (numSpaces <= 0) {
   2074         printf("%s", buf);
   2075         return;
   2076     }
   2077     if (leadingSpaces == 0)
   2078         printf("%s", buf);
   2079     for (ii = 0; ii < numSpaces; ++ii)
   2080         printf("&nbsp;");
   2081     if (leadingSpaces == 1)
   2082         printf("%s", buf);
   2083 }
   2084 
   2085 void printClassProfiles(TraceData* traceData, uint64_t sumThreadTime)
   2086 {
   2087     int ii, jj;
   2088     MethodEntry* method;
   2089     double total, sum, per, sum_per;
   2090     char classBuf[HTML_BUFSIZE], methodBuf[HTML_BUFSIZE];
   2091     char signatureBuf[HTML_BUFSIZE];
   2092 
   2093     total = sumThreadTime;
   2094     if (gOptions.outputHtml) {
   2095         printf("<a name=\"class\"></a>\n");
   2096         printf("<hr>\n");
   2097         outputNavigationBar();
   2098     } else {
   2099         printf("\n%s\n", profileSeparator);
   2100     }
   2101 
   2102     if (traceData->numClasses == 0) {
   2103         printf("\nNo classes.\n");
   2104         if (gOptions.outputHtml) {
   2105             printf("<br><br>\n");
   2106         }
   2107         return;
   2108     }
   2109 
   2110     printf("\nExclusive elapsed time for each class, summed over all the methods\n");
   2111     printf("in the class.\n\n");
   2112     if (gOptions.outputHtml) {
   2113         printf("<br><br>\n");
   2114     }
   2115 
   2116     /* For each class, sum the exclusive times in all of the methods
   2117      * in that class.  Also sum the number of method calls.  Also
   2118      * sort the methods so the most expensive appear at the top.
   2119      */
   2120     ClassEntry *pClass = traceData->classes;
   2121     for (ii = 0; ii < traceData->numClasses; ++ii, ++pClass) {
   2122         //printf("%s %d methods\n", pClass->className, pClass->numMethods);
   2123         int numMethods = pClass->numMethods;
   2124         for (jj = 0; jj < numMethods; ++jj) {
   2125             method = pClass->methods[jj];
   2126             pClass->elapsedExclusive += method->elapsedExclusive;
   2127             pClass->numCalls[0] += method->numCalls[0];
   2128             pClass->numCalls[1] += method->numCalls[1];
   2129         }
   2130 
   2131         /* Sort the methods into decreasing order of exclusive time */
   2132         qsort(pClass->methods, numMethods, sizeof(MethodEntry*),
   2133               compareElapsedExclusive);
   2134     }
   2135 
   2136     /* Allocate an array of pointers to the classes for more efficient
   2137      * sorting.
   2138      */
   2139     ClassEntry **pClasses;
   2140     pClasses = (ClassEntry**) malloc(sizeof(ClassEntry*) * traceData->numClasses);
   2141     for (ii = 0; ii < traceData->numClasses; ++ii)
   2142         pClasses[ii] = &traceData->classes[ii];
   2143 
   2144     /* Sort the classes into decreasing order of exclusive time */
   2145     qsort(pClasses, traceData->numClasses, sizeof(ClassEntry*), compareClassExclusive);
   2146 
   2147     if (gOptions.outputHtml) {
   2148         printf("<div class=\"header\"><span class=\"parent\">&nbsp;</span>&nbsp;&nbsp;&nbsp;");
   2149         printf("Cycles %%/total Cumul.%% &nbsp;Calls+Recur&nbsp; Class</div>\n");
   2150     } else {
   2151         printf("   Cycles %%/total Cumul.%%  Calls+Recur  Class\n");
   2152     }
   2153 
   2154     sum = 0;
   2155     for (ii = 0; ii < traceData->numClasses; ++ii) {
   2156         char *className, *methodName, *signature;
   2157 
   2158         /* Skip classes with zero cycles */
   2159         pClass = pClasses[ii];
   2160         if (pClass->elapsedExclusive == 0)
   2161             break;
   2162 
   2163         per = 100.0 * pClass->elapsedExclusive / total;
   2164         sum += pClass->elapsedExclusive;
   2165         sum_per = 100.0 * sum / total;
   2166         className = (char*)(pClass->className);
   2167         if (gOptions.outputHtml) {
   2168             char buf[80];
   2169 
   2170             className = htmlEscape(className, classBuf, HTML_BUFSIZE);
   2171             printf("<div class=\"link\" onClick=\"javascript:toggle('d%d')\" onMouseOver=\"javascript:onMouseOver(this)\" onMouseOut=\"javascript:onMouseOut(this)\"><span class=\"parent\" id=\"xd%d\">+</span>", ii, ii);
   2172             sprintf(buf, "%llu", pClass->elapsedExclusive);
   2173             printHtmlField(buf, 9);
   2174             printf(" ");
   2175             sprintf(buf, "%.1f", per);
   2176             printHtmlField(buf, 7);
   2177             printf(" ");
   2178             sprintf(buf, "%.1f", sum_per);
   2179             printHtmlField(buf, 7);
   2180             printf(" ");
   2181             sprintf(buf, "%d", pClass->numCalls[0]);
   2182             printHtmlField(buf, 6);
   2183             printf("+");
   2184             sprintf(buf, "%d", pClass->numCalls[1]);
   2185             printHtmlField(buf, -6);
   2186             printf(" ");
   2187             printf("%s", className);
   2188             printf("</div>\n");
   2189             printf("<div class=\"parent\" id=\"d%d\">\n", ii);
   2190         } else {
   2191             printf("---------------------------------------------\n");
   2192             printf("%9llu %7.1f %7.1f %6d+%-6d %s\n",
   2193                    pClass->elapsedExclusive, per, sum_per,
   2194                    pClass->numCalls[0], pClass->numCalls[1],
   2195                    className);
   2196         }
   2197 
   2198         int numMethods = pClass->numMethods;
   2199         double classExclusive = pClass->elapsedExclusive;
   2200         double sumMethods = 0;
   2201         for (jj = 0; jj < numMethods; ++jj) {
   2202             method = pClass->methods[jj];
   2203             methodName = (char*)(method->methodName);
   2204             signature = (char*)(method->signature);
   2205             per = 100.0 * method->elapsedExclusive / classExclusive;
   2206             sumMethods += method->elapsedExclusive;
   2207             sum_per = 100.0 * sumMethods / classExclusive;
   2208             if (gOptions.outputHtml) {
   2209                 char buf[80];
   2210 
   2211                 methodName = htmlEscape(methodName, methodBuf, HTML_BUFSIZE);
   2212                 signature = htmlEscape(signature, signatureBuf, HTML_BUFSIZE);
   2213                 printf("<div class=\"leaf\"><span class=\"leaf\">&nbsp;</span>");
   2214                 sprintf(buf, "%llu", method->elapsedExclusive);
   2215                 printHtmlField(buf, 9);
   2216                 printf("&nbsp;");
   2217                 sprintf(buf, "%llu", method->elapsedInclusive);
   2218                 printHtmlField(buf, 9);
   2219                 printf("&nbsp;");
   2220                 sprintf(buf, "%.1f", per);
   2221                 printHtmlField(buf, 7);
   2222                 printf("&nbsp;");
   2223                 sprintf(buf, "%.1f", sum_per);
   2224                 printHtmlField(buf, 7);
   2225                 printf("&nbsp;");
   2226                 sprintf(buf, "%d", method->numCalls[0]);
   2227                 printHtmlField(buf, 6);
   2228                 printf("+");
   2229                 sprintf(buf, "%d", method->numCalls[1]);
   2230                 printHtmlField(buf, -6);
   2231                 printf("&nbsp;");
   2232                 printf("<a href=\"#m%d\">[%d]</a>&nbsp;%s&nbsp;%s",
   2233                        method->index, method->index, methodName, signature);
   2234                 printf("</div>\n");
   2235             } else {
   2236                 printf("%9llu %9llu %7.1f %7.1f %6d+%-6d [%d] %s %s\n",
   2237                        method->elapsedExclusive,
   2238                        method->elapsedInclusive,
   2239                        per, sum_per,
   2240                        method->numCalls[0], method->numCalls[1],
   2241                        method->index, methodName, signature);
   2242             }
   2243         }
   2244         if (gOptions.outputHtml) {
   2245             printf("</div>\n");
   2246         }
   2247     }
   2248 }
   2249 
   2250 void createUniqueMethodList(TraceData* traceData, MethodEntry **pMethods, int numMethods)
   2251 {
   2252     int ii;
   2253 
   2254     /* Sort the methods into alphabetical order of method names
   2255      * to find the unique method names.
   2256      */
   2257     qsort(pMethods, numMethods, sizeof(MethodEntry*), compareMethodNames);
   2258 
   2259     /* Count the number of unique method names, ignoring class and
   2260      * signature.
   2261      */
   2262     const char *currentMethodName = "";
   2263     traceData->numUniqueMethods = 0;
   2264     for (ii = 0; ii < numMethods; ++ii) {
   2265         if (pMethods[ii]->methodName == NULL)
   2266             continue;
   2267         if (strcmp(pMethods[ii]->methodName, currentMethodName) != 0) {
   2268             traceData->numUniqueMethods += 1;
   2269             currentMethodName = pMethods[ii]->methodName;
   2270         }
   2271     }
   2272     if (traceData->numUniqueMethods == 0)
   2273         return;
   2274 
   2275     /* Allocate space for pointers to all of the unique methods */
   2276     int nbytes = sizeof(UniqueMethodEntry) * traceData->numUniqueMethods;
   2277     traceData->uniqueMethods = (UniqueMethodEntry *) malloc(nbytes);
   2278 
   2279     /* Initialize the uniqueMethods array */
   2280     memset(traceData->uniqueMethods, 0, nbytes);
   2281     UniqueMethodEntry *pUnique = traceData->uniqueMethods;
   2282     currentMethodName = NULL;
   2283     int prevNumMethods = 0;
   2284     for (ii = 0; ii < numMethods; ++ii) {
   2285         if (pMethods[ii]->methodName == NULL)
   2286             continue;
   2287         if (currentMethodName == NULL)
   2288             currentMethodName = pMethods[ii]->methodName;
   2289         if (strcmp(pMethods[ii]->methodName, currentMethodName) != 0) {
   2290             currentMethodName = pMethods[ii]->methodName;
   2291             pUnique->numMethods = prevNumMethods;
   2292             pUnique++;
   2293             prevNumMethods = 0;
   2294         }
   2295         prevNumMethods += 1;
   2296     }
   2297     pUnique->numMethods = prevNumMethods;
   2298 
   2299     /* Create the array of MethodEntry pointers for each unique method */
   2300     pUnique = NULL;
   2301     currentMethodName = "";
   2302     int nextMethod = 0;
   2303     for (ii = 0; ii < numMethods; ++ii) {
   2304         if (pMethods[ii]->methodName == NULL)
   2305             continue;
   2306         if (strcmp(pMethods[ii]->methodName, currentMethodName) != 0) {
   2307             currentMethodName = pMethods[ii]->methodName;
   2308             if (pUnique == NULL)
   2309                 pUnique = traceData->uniqueMethods;
   2310             else
   2311                 pUnique++;
   2312             /* Allocate space for the methods array */
   2313             int nbytes = sizeof(MethodEntry*) * pUnique->numMethods;
   2314             pUnique->methods = (MethodEntry**) malloc(nbytes);
   2315             nextMethod = 0;
   2316         }
   2317         pUnique->methods[nextMethod++] = pMethods[ii];
   2318     }
   2319 }
   2320 
   2321 void printMethodProfiles(TraceData* traceData, uint64_t sumThreadTime)
   2322 {
   2323     int ii, jj;
   2324     MethodEntry* method;
   2325     double total, sum, per, sum_per;
   2326     char classBuf[HTML_BUFSIZE], methodBuf[HTML_BUFSIZE];
   2327     char signatureBuf[HTML_BUFSIZE];
   2328 
   2329     if (traceData->numUniqueMethods == 0)
   2330         return;
   2331 
   2332     total = sumThreadTime;
   2333     if (gOptions.outputHtml) {
   2334         printf("<a name=\"method\"></a>\n");
   2335         printf("<hr>\n");
   2336         outputNavigationBar();
   2337     } else {
   2338         printf("\n%s\n", profileSeparator);
   2339     }
   2340 
   2341     printf("\nExclusive elapsed time for each method, summed over all the classes\n");
   2342     printf("that contain a method with the same name.\n\n");
   2343     if (gOptions.outputHtml) {
   2344         printf("<br><br>\n");
   2345     }
   2346 
   2347     /* For each unique method, sum the exclusive times in all of the methods
   2348      * with the same name.  Also sum the number of method calls.  Also
   2349      * sort the methods so the most expensive appear at the top.
   2350      */
   2351     UniqueMethodEntry *pUnique = traceData->uniqueMethods;
   2352     for (ii = 0; ii < traceData->numUniqueMethods; ++ii, ++pUnique) {
   2353         int numMethods = pUnique->numMethods;
   2354         for (jj = 0; jj < numMethods; ++jj) {
   2355             method = pUnique->methods[jj];
   2356             pUnique->elapsedExclusive += method->elapsedExclusive;
   2357             pUnique->numCalls[0] += method->numCalls[0];
   2358             pUnique->numCalls[1] += method->numCalls[1];
   2359         }
   2360 
   2361         /* Sort the methods into decreasing order of exclusive time */
   2362         qsort(pUnique->methods, numMethods, sizeof(MethodEntry*),
   2363               compareElapsedExclusive);
   2364     }
   2365 
   2366     /* Allocate an array of pointers to the methods for more efficient
   2367      * sorting.
   2368      */
   2369     UniqueMethodEntry **pUniqueMethods;
   2370     int nbytes = sizeof(UniqueMethodEntry*) * traceData->numUniqueMethods;
   2371     pUniqueMethods = (UniqueMethodEntry**) malloc(nbytes);
   2372     for (ii = 0; ii < traceData->numUniqueMethods; ++ii)
   2373         pUniqueMethods[ii] = &traceData->uniqueMethods[ii];
   2374 
   2375     /* Sort the methods into decreasing order of exclusive time */
   2376     qsort(pUniqueMethods, traceData->numUniqueMethods, sizeof(UniqueMethodEntry*),
   2377           compareUniqueExclusive);
   2378 
   2379     if (gOptions.outputHtml) {
   2380         printf("<div class=\"header\"><span class=\"parent\">&nbsp;</span>&nbsp;&nbsp;&nbsp;");
   2381         printf("Cycles %%/total Cumul.%% &nbsp;Calls+Recur&nbsp; Method</div>\n");
   2382     } else {
   2383         printf("   Cycles %%/total Cumul.%%  Calls+Recur  Method\n");
   2384     }
   2385 
   2386     sum = 0;
   2387     for (ii = 0; ii < traceData->numUniqueMethods; ++ii) {
   2388         char *className, *methodName, *signature;
   2389 
   2390         /* Skip methods with zero cycles */
   2391         pUnique = pUniqueMethods[ii];
   2392         if (pUnique->elapsedExclusive == 0)
   2393             break;
   2394 
   2395         per = 100.0 * pUnique->elapsedExclusive / total;
   2396         sum += pUnique->elapsedExclusive;
   2397         sum_per = 100.0 * sum / total;
   2398         methodName = (char*)(pUnique->methods[0]->methodName);
   2399         if (gOptions.outputHtml) {
   2400             char buf[80];
   2401 
   2402             methodName = htmlEscape(methodName, methodBuf, HTML_BUFSIZE);
   2403             printf("<div class=\"link\" onClick=\"javascript:toggle('e%d')\" onMouseOver=\"javascript:onMouseOver(this)\" onMouseOut=\"javascript:onMouseOut(this)\"><span class=\"parent\" id=\"xe%d\">+</span>", ii, ii);
   2404             sprintf(buf, "%llu", pUnique->elapsedExclusive);
   2405             printHtmlField(buf, 9);
   2406             printf(" ");
   2407             sprintf(buf, "%.1f", per);
   2408             printHtmlField(buf, 7);
   2409             printf(" ");
   2410             sprintf(buf, "%.1f", sum_per);
   2411             printHtmlField(buf, 7);
   2412             printf(" ");
   2413             sprintf(buf, "%d", pUnique->numCalls[0]);
   2414             printHtmlField(buf, 6);
   2415             printf("+");
   2416             sprintf(buf, "%d", pUnique->numCalls[1]);
   2417             printHtmlField(buf, -6);
   2418             printf(" ");
   2419             printf("%s", methodName);
   2420             printf("</div>\n");
   2421             printf("<div class=\"parent\" id=\"e%d\">\n", ii);
   2422         } else {
   2423             printf("---------------------------------------------\n");
   2424             printf("%9llu %7.1f %7.1f %6d+%-6d %s\n",
   2425                    pUnique->elapsedExclusive, per, sum_per,
   2426                    pUnique->numCalls[0], pUnique->numCalls[1],
   2427                    methodName);
   2428         }
   2429         int numMethods = pUnique->numMethods;
   2430         double methodExclusive = pUnique->elapsedExclusive;
   2431         double sumMethods = 0;
   2432         for (jj = 0; jj < numMethods; ++jj) {
   2433             method = pUnique->methods[jj];
   2434             className = (char*)(method->className);
   2435             signature = (char*)(method->signature);
   2436             per = 100.0 * method->elapsedExclusive / methodExclusive;
   2437             sumMethods += method->elapsedExclusive;
   2438             sum_per = 100.0 * sumMethods / methodExclusive;
   2439             if (gOptions.outputHtml) {
   2440                 char buf[80];
   2441 
   2442                 className = htmlEscape(className, classBuf, HTML_BUFSIZE);
   2443                 signature = htmlEscape(signature, signatureBuf, HTML_BUFSIZE);
   2444                 printf("<div class=\"leaf\"><span class=\"leaf\">&nbsp;</span>");
   2445                 sprintf(buf, "%llu", method->elapsedExclusive);
   2446                 printHtmlField(buf, 9);
   2447                 printf("&nbsp;");
   2448                 sprintf(buf, "%llu", method->elapsedInclusive);
   2449                 printHtmlField(buf, 9);
   2450                 printf("&nbsp;");
   2451                 sprintf(buf, "%.1f", per);
   2452                 printHtmlField(buf, 7);
   2453                 printf("&nbsp;");
   2454                 sprintf(buf, "%.1f", sum_per);
   2455                 printHtmlField(buf, 7);
   2456                 printf("&nbsp;");
   2457                 sprintf(buf, "%d", method->numCalls[0]);
   2458                 printHtmlField(buf, 6);
   2459                 printf("+");
   2460                 sprintf(buf, "%d", method->numCalls[1]);
   2461                 printHtmlField(buf, -6);
   2462                 printf("&nbsp;");
   2463                 printf("<a href=\"#m%d\">[%d]</a>&nbsp;%s.%s&nbsp;%s",
   2464                        method->index, method->index,
   2465                        className, methodName, signature);
   2466                 printf("</div>\n");
   2467             } else {
   2468                 printf("%9llu %9llu %7.1f %7.1f %6d+%-6d [%d] %s.%s %s\n",
   2469                        method->elapsedExclusive,
   2470                        method->elapsedInclusive,
   2471                        per, sum_per,
   2472                        method->numCalls[0], method->numCalls[1],
   2473                        method->index, className, methodName, signature);
   2474             }
   2475         }
   2476         if (gOptions.outputHtml) {
   2477             printf("</div>\n");
   2478         }
   2479     }
   2480 }
   2481 
   2482 /*
   2483  * Determines whether the given FilterKey matches the method. The FilterKey's
   2484  * key that is used to match against the method is determined by index.
   2485  */
   2486 int keyMatchesMethod(FilterKey filterKey, MethodEntry* method, int index)
   2487 {
   2488     if (filterKey.type[index] == 0) { // Class
   2489 #if 0
   2490         fprintf(stderr, "  class is %s; filter key is %s\n", method->className, filterKey.keys[index]);
   2491 #endif
   2492         if (strcmp(method->className, filterKey.keys[index]) == 0) {
   2493 	    return 1;
   2494 	}
   2495     } else { // Method
   2496         if (method->methodName != NULL) {
   2497 	    // Get fully-qualified name
   2498             // TODO: parse class name and method name an put them in structure to avoid
   2499             // allocating memory here
   2500 	    char* str = malloc ((strlen(method->className) + strlen(method->methodName) + 2) * sizeof(char));
   2501 	    strcpy(str, method->className);
   2502 	    strcat(str, ".");
   2503 	    strcat(str, method->methodName);
   2504 #if 0
   2505 	    fprintf(stderr, "  method is %s; filter key is %s\n", str, filterKey.keys[index]);
   2506 #endif
   2507 	    if (strcmp(str, filterKey.keys[index]) == 0) {
   2508 	        free(str);
   2509 	        return 1;
   2510 	    }
   2511 	    free(str);
   2512 	}
   2513     }
   2514     return 0;
   2515 }
   2516 
   2517 /*
   2518  * Adds the appropriate times to the given filter based on the given method. Activates and
   2519  * de-activates filters as necessary.
   2520  *
   2521  * A filter is activated when the given method matches the 'entry' key of one of its FilterKeys.
   2522  * It is de-activated when the method matches the 'exit' key of the same FilterKey that activated it
   2523  * in the first place. Thus, a filter may be active more than once on the same thread (activated by
   2524  * different FilterKeys). A filter may also be active on different threads at the same time.
   2525  *
   2526  * While the filter is active on thread 1, elapsed time is allocated to different buckets which
   2527  * include: thread execution time (i.e., time thread 1 spent executing while filter was active),
   2528  * thread waiting time (i.e., time thread 1 waited while other threads executed), and execution
   2529  * time while waiting (i.e., time thread x spent executing while thread 1 was waiting). We also
   2530  * keep track of the total waiting time for a given filter.
   2531  *
   2532  * Lastly, we keep track of remaining (un-allocated) time for cases in which we exit a method we
   2533  * had not entered before, and that method happens to match the 'exit' key of a FilterKey.
   2534  */
   2535 int filterMethod(MethodEntry* method, Filter* filter, int entry, int threadId, int numThreads,
   2536 		 uint64_t elapsed, uint64_t remTime)
   2537 {
   2538     int ii, jj;
   2539     int activeCount, addedWaitTimeThreadsCount;
   2540     int* activeThreads;
   2541     int* activationKeys;
   2542     int* addedWaitTimeThreads;
   2543 
   2544     // flags
   2545     int addWaitTime = 0;
   2546     int deactivation = 0;
   2547     int addedExecutionTime = 0;
   2548     int addedExecutionTimeWhileWaiting = 0;
   2549     int addedWaitTime;
   2550     int addedRemTime = 0;
   2551     int threadKeyPairActive = 0;
   2552 
   2553     if (filter->times.threadWaitTimes == NULL && filter->times.threadExecutionTimes == NULL &&
   2554 	filter->times.threadExecutionTimesWhileWaiting == NULL) {
   2555         filter->times.threadWaitTimes = (uint64_t*) calloc(MAX_THREADS, sizeof(uint64_t));
   2556 	filter->times.threadExecutionTimesWhileWaiting =
   2557           (uint64_t*) calloc(MAX_THREADS, sizeof(uint64_t));
   2558 	filter->times.threadExecutionTimes = (uint64_t*) calloc(MAX_THREADS, sizeof(uint64_t));
   2559     }
   2560 
   2561     int verbose = 0;
   2562 
   2563     if (verbose)
   2564         fprintf(stderr,
   2565                 "Running %s filter for class %s method %s, thread %d; activeCount: %d time: %llu\n",
   2566                 filter->filterName, method->className, method->methodName, threadId,
   2567                 filter->activeCount, elapsed);
   2568 
   2569     // If active on some thread
   2570     if (filter->activeCount > 0) {
   2571 
   2572         // Initialize active structures in case there are any de-activations
   2573         activeThreads = (int*) calloc(filter->activeCount, sizeof(int));
   2574 	activationKeys = (int*) calloc(filter->activeCount, sizeof(int));
   2575 	activeCount = 0;
   2576 
   2577 	// Initialize structure to help us determine which threads we've already added wait time to
   2578 	addedWaitTimeThreads = (int*) calloc(filter->activeCount, sizeof(int));
   2579 	addedWaitTimeThreadsCount = 0;
   2580 
   2581         // Add times to appropriate sums and de-activate (if necessary)
   2582         for (ii = 0; ii < filter->activeCount; ii++) {
   2583 
   2584 	    if (verbose) {
   2585 	        fprintf(stderr, "  Analyzing active thread with id %d, activated by key [%s, %s]\n",
   2586 			filter->activeThreads[ii],
   2587                         filter->filterKeys[filter->activationKeys[ii]].keys[0],
   2588 			filter->filterKeys[filter->activationKeys[ii]].keys[1]);
   2589 	    }
   2590 
   2591 	    // If active on THIS thread -> add to execution time (only add once!)
   2592 	    if (filter->activeThreads[ii] == threadId && !addedExecutionTime) {
   2593 	        if (verbose)
   2594 		    fprintf(stderr, "  Adding execution time to this thead\n");
   2595 	        filter->times.threadExecutionTimes[threadId] += elapsed;
   2596 		addedExecutionTime = 1;
   2597 	    }
   2598 
   2599 	    // If active on ANOTHER thread (or this one too) with CROSS_THREAD_FLAG -> add to
   2600             // both thread's waiting time + total
   2601 	    if (filter->filterKeys[filter->activationKeys[ii]].flags == 1) {
   2602 
   2603 	        // Add time to thread that is waiting (add to each waiting thread at most once!)
   2604 	        addedWaitTime = 0;
   2605 		for (jj = 0; jj < addedWaitTimeThreadsCount; jj++) {
   2606 		    if (addedWaitTimeThreads[jj] == filter->activeThreads[ii])
   2607 		        addedWaitTime = 1;
   2608 		}
   2609 	        if (!addedWaitTime) {
   2610 		    if (verbose)
   2611 		        fprintf(stderr, "  Adding wait time to waiting thread\n");
   2612 		    filter->times.threadWaitTimes[filter->activeThreads[ii]] += elapsed;
   2613 		    addedWaitTimeThreads[addedWaitTimeThreadsCount++] = filter->activeThreads[ii];
   2614 		}
   2615 
   2616                 // Add execution time to this thread while the other is waiting (only add once!)
   2617                 // [Flag is needed only because outside for loop might iterate through same
   2618                 // thread twice?] TODO: verify
   2619 		if (!addedExecutionTimeWhileWaiting) {
   2620 		    if (verbose)
   2621 		        fprintf(stderr, "  Adding exec time to this thread while thread waits\n");
   2622 		    filter->times.threadExecutionTimesWhileWaiting[threadId] += elapsed;
   2623 		    addedExecutionTimeWhileWaiting = 1;
   2624 		}
   2625 
   2626 		addWaitTime = 1;
   2627 	    }
   2628 
   2629 	    // If a method exit matches the EXIT method of an ACTIVE key -> de-activate
   2630             // the KEY (not the entire filter!!)
   2631 	    if (!entry && keyMatchesMethod(filter->filterKeys[filter->activationKeys[ii]],
   2632 					   method, 1)) {
   2633 	        if (verbose)
   2634 		    fprintf(stderr, "  Exit key matched!\n");
   2635 
   2636 	        // Deactivate by removing (NOT adding) entries from activeThreads and activationKeys
   2637 	        deactivation = 1; // singal that lists should be replaced
   2638 	    } else {
   2639 	        // No de-activation -> copy old entries into new lists
   2640 	        activeThreads[activeCount] = filter->activeThreads[ii];
   2641 		activationKeys[activeCount++] = filter->activationKeys[ii];
   2642 	    }
   2643 	}
   2644 
   2645 	// If waiting on ANY thread, add wait time to total (but only ONCE!)
   2646 	if (addWaitTime) {
   2647 	    filter->times.totalWaitTime += elapsed;
   2648 	}
   2649 
   2650 	// If de-activation occurred, replace lists
   2651 	if (deactivation) {
   2652 	    // TODO: Free memory from old lists
   2653 
   2654 	    // Set new lists
   2655 	    filter->activeThreads = activeThreads;
   2656 	    filter->activationKeys = activationKeys;
   2657 	    filter->activeCount = activeCount;
   2658 	} else {
   2659 	    // TODO: Free memory from new lists
   2660 	}
   2661 
   2662     }  // Else, continue (we might be activating the filter on a different thread)
   2663 
   2664 
   2665     if (entry) { // ENTRY
   2666         if (verbose)
   2667 	    fprintf(stderr, "  Here at the entry\n");
   2668         // If method matches entry key -> activate thread (do not add time since it's a new entry!)
   2669         for (ii = 0; ii < filter->numKeys; ii++) {
   2670 	    if (keyMatchesMethod(filter->filterKeys[ii], method, 0)) {
   2671 	        if (verbose)
   2672 		    fprintf(stderr, "  Entry key matched!\n");
   2673 	        // Activate thread only if thread/key pair is not already active
   2674 	        for (jj = 0; jj < filter->activeCount; jj++) {
   2675 		    if (filter->activeThreads[jj] == threadId && filter->activationKeys[jj] == ii)
   2676 		        threadKeyPairActive = 1;
   2677 		}
   2678 	        // TODO: WORRY ABOUT MEMORY WHEN ACTIVE_COUNT > DEFAULT_ACTIVE_THREAD (unlikely)
   2679 	        // TODO: what if the same thread is active multiple times by different keys?
   2680 		// nothing, we just have to make sure we dont double-add, and we dont..
   2681 		if (!threadKeyPairActive) {
   2682 		    filter->activeThreads[filter->activeCount] = threadId;
   2683 		    filter->activationKeys[filter->activeCount++] = ii;
   2684 		}
   2685 	    }
   2686 	}
   2687     } else { // EXIT
   2688         // If method matches a terminal key -> add remTime to total (no need to active/de-activate)
   2689         for (ii = 0; ii < filter->numKeys; ii++) {
   2690 	    if (!deactivation && keyMatchesMethod(filter->filterKeys[ii], method, 1) &&
   2691 		keyMatchesMethod(filter->filterKeys[ii], method, 0)) {
   2692 	        // Add remTime(s)
   2693 	        // TODO: think about how we should add remTimes.. should we add remTime to threads
   2694 	        // that were waiting or being waited on? for now, keep it simple and just add the
   2695 	        // execution time to the current thread.
   2696 	        filter->times.threadExecutionTimes[threadId] += remTime;
   2697 		addedRemTime = 1;
   2698 	    }
   2699 	}
   2700     }
   2701 
   2702     return addedExecutionTime | (addedRemTime << 1);
   2703 }
   2704 
   2705 void dumpFilters(Filter** filters) {
   2706     int i;
   2707     for (i = 0; i < numFilters; i++) {
   2708         int j;
   2709 	fprintf(stderr, "FILTER %s\n", filters[i]->filterName);
   2710 	for (j = 0; j < filters[i]->numKeys; j++) {
   2711 	    fprintf(stderr, "Keys: %s, type %d", filters[i]->filterKeys[j].keys[0],
   2712 		    filters[i]->filterKeys[j].type[0]);
   2713 	    if (filters[i]->filterKeys[j].keys[1] != NULL) {
   2714 	        fprintf(stderr, " AND %s, type %d", filters[i]->filterKeys[j].keys[1],
   2715 			filters[i]->filterKeys[j].type[1]);
   2716 	    }
   2717 	    fprintf(stderr, "; flags: %d\n", filters[i]->filterKeys[j].flags);
   2718 	}
   2719     }
   2720 }
   2721 
   2722 /*
   2723  * See parseFilters for required data format.
   2724  * 'data' must point to the beginning of a filter definition.
   2725  */
   2726 char* parseFilter(char* data, char* dataEnd, Filter** filters, int num) {
   2727 
   2728     Filter* filter;
   2729     int next, count, i;
   2730     int tmpOffset, tmpKeyLen;
   2731     char* tmpKey;
   2732     char* key1;
   2733     char* key2;
   2734 
   2735     filter = (Filter*) malloc(sizeof(Filter));
   2736     filter->activeCount = 0;
   2737     filter->activeThreads = (int*) calloc(DEFAULT_ACTIVE_THREADS, sizeof(int));
   2738     filter->activationKeys = (int*) calloc(DEFAULT_ACTIVE_THREADS, sizeof(int));
   2739 
   2740     next = findNextChar(data + 1, dataEnd - data - 1, '\n');
   2741     if (next < 0) {
   2742         // TODO: what should we do here?
   2743         // End of file reached...
   2744     }
   2745     data[next+1] = '\0';
   2746     filter->filterName = data + 1;
   2747     data += next + 2; // Careful
   2748 
   2749     /*
   2750      * Count the number of keys (one per line).
   2751      */
   2752     count = countLinesToChar(data, dataEnd - data, FILTER_TAG);
   2753     if (count <= 0) {
   2754         fprintf(stderr,
   2755 		"ERROR: failed while parsing filter %s (found %d keys)\n",
   2756 		filter->filterName, count);
   2757 	return NULL; // TODO: Should do something else
   2758 	// Could return filter with 0 keys instead (probably better to avoid random segfaults)
   2759     }
   2760 
   2761     filter->filterKeys = (FilterKey*) malloc(sizeof(FilterKey) * count);
   2762 
   2763     /*
   2764      * Extract all entries.
   2765      */
   2766     tmpOffset = 0;
   2767     for (i = 0; i < count; i++) {
   2768         next = findNextChar(data, dataEnd - data, '\n');
   2769 	//        assert(next > 0); // TODO: revise... (skip if next == 0 ?)
   2770         data[next] = '\0';
   2771 	tmpKey = data;
   2772 
   2773         if (*data == FILTER_FLAG_THREAD) {
   2774             filter->filterKeys[i].flags = 1;
   2775             tmpKey++;
   2776 	} else {
   2777             filter->filterKeys[i].flags = 0;
   2778 	}
   2779 
   2780 	tmpOffset = findNextChar(tmpKey, next, ',');
   2781 
   2782         if (tmpOffset < 0) {
   2783             // No comma, so only 1 key
   2784             key1 = tmpKey;
   2785 	    key2 = tmpKey;
   2786 
   2787 	    // Get type for key1
   2788             filter->filterKeys[i].type[0] = FILTER_TYPE_CLASS; // default
   2789             tmpOffset = findNextChar(key1, next, '(');
   2790 	    if (tmpOffset > 0) {
   2791 	        if (findNextChar(key1, next, ')') == tmpOffset + 1) {
   2792 		    filter->filterKeys[i].type[0] = FILTER_TYPE_METHOD;
   2793 		    filter->filterKeys[i].type[1] = FILTER_TYPE_METHOD;
   2794 		}
   2795 		key1[tmpOffset] = '\0';
   2796 	    }
   2797 	} else {
   2798 	    // Pair of keys
   2799 	    tmpKey[tmpOffset] = '\0';
   2800 	    key1 = tmpKey;
   2801 	    key2 = tmpKey + tmpOffset + 1;
   2802 
   2803 	    // Get type for key1
   2804 	    filter->filterKeys[i].type[0] = FILTER_TYPE_CLASS;
   2805 	    tmpKeyLen = tmpOffset;
   2806             tmpOffset = findNextChar(key1, tmpKeyLen, '(');
   2807 	    if (tmpOffset > 0) {
   2808 	        if (findNextChar(key1, tmpKeyLen, ')') == tmpOffset + 1) {
   2809 		    filter->filterKeys[i].type[0] = FILTER_TYPE_METHOD;
   2810 		}
   2811 		key1[tmpOffset] = '\0';
   2812 	    }
   2813 
   2814 	    // Get type for key2
   2815 	    filter->filterKeys[i].type[1] = FILTER_TYPE_CLASS;
   2816             tmpOffset = findNextChar(key2, next - tmpKeyLen, '(');
   2817 	    if (tmpOffset > 0) {
   2818 	        if (findNextChar(key2, next - tmpKeyLen, ')') == tmpOffset + 1) {
   2819 		    filter->filterKeys[i].type[1] = FILTER_TYPE_METHOD;
   2820 		}
   2821 		key2[tmpOffset] = '\0';
   2822 	    }
   2823 	}
   2824 
   2825 	filter->filterKeys[i].keys[0] = key1;
   2826 	filter->filterKeys[i].keys[1] = key2;
   2827         data += next+1;
   2828     }
   2829 
   2830     filter->numKeys = count;
   2831     filters[num] = filter;
   2832 
   2833     return data;
   2834 }
   2835 
   2836 /*
   2837  * Parses filters from given file. The file must follow the following format:
   2838  *
   2839  * *FilterName    <- creates a new filter with keys to follow
   2840  * A.method()     <- key that triggers whenever A.method() enters/exit
   2841  * Class          <- key that triggers whenever any method from Class enters/exits
   2842  * +CrossThread   <- same as above, but keeps track of execution times accross threads
   2843  * B.m(),C.m()    <- key that triggers filter on when B.m() enters and off when C.m() exits
   2844  *
   2845  * TODO: add concrete example to make things clear
   2846  */
   2847 Filter** parseFilters(const char* filterFileName) {
   2848 
   2849     Filter** filters = NULL;
   2850     FILE* fp = NULL;
   2851     long len;
   2852     char* data;
   2853     char* dataEnd;
   2854     char* dataStart;
   2855     int i, next, count;
   2856 
   2857     fp = fopen(filterFileName, "r");
   2858     if (fp == NULL)
   2859         goto bail;
   2860 
   2861     if (fseek(fp, 0L, SEEK_END) != 0) {
   2862         perror("fseek");
   2863         goto bail;
   2864     }
   2865 
   2866     len = ftell(fp);
   2867     if (len == 0) {
   2868         fprintf(stderr, "WARNING: Filter file is empty.\n");
   2869         goto bail;
   2870     }
   2871     rewind(fp);
   2872 
   2873     data = (char*) malloc(len);
   2874     if (data == NULL) {
   2875         fprintf(stderr, "ERROR: unable to alloc %ld bytes for filter file\n", len);
   2876         goto bail;
   2877     }
   2878 
   2879     // Read file into memory
   2880     if (fread(data, 1, len, fp) != (size_t) len) {
   2881         fprintf(stderr, "ERROR: unable to read %ld bytes from filter file\n", len);
   2882         goto bail;
   2883     }
   2884 
   2885     dataStart = data;
   2886     dataEnd = data + len;
   2887 
   2888     // Figure out how many filters there are
   2889     numFilters = 0;
   2890     next = -1;
   2891 
   2892     while (1) {
   2893         if (*data == FILTER_TAG)
   2894 	    numFilters++;
   2895         next = findNextChar(data, len, '\n');
   2896         if (next < 0)
   2897             break;
   2898         data += next+1;
   2899         len -= next+1;
   2900     }
   2901 
   2902     if (numFilters == 0) {
   2903         fprintf(stderr, "WARNING: no filters found. Continuing without filters\n");
   2904         goto bail;
   2905     }
   2906 
   2907     filters = (Filter**) calloc(numFilters, sizeof(Filter *));
   2908     if (filters == NULL) {
   2909         fprintf(stderr, "ERROR: unable to alloc memory for filters");
   2910         goto bail;
   2911     }
   2912 
   2913     data = dataStart;
   2914     for (i = 0; i < numFilters; i++) {
   2915         data = parseFilter(data, dataEnd, filters, i);
   2916     }
   2917 
   2918     return filters;
   2919 
   2920 bail:
   2921     if (fp != NULL)
   2922         fclose(fp);
   2923 
   2924     return NULL;
   2925 
   2926 }
   2927 
   2928 
   2929 /*
   2930  * Read the key and data files and return the MethodEntries for those files
   2931  */
   2932 DataKeys* parseDataKeys(TraceData* traceData, const char* traceFileName,
   2933 			uint64_t* threadTime, Filter** filters)
   2934 {
   2935     DataKeys* dataKeys = NULL;
   2936     MethodEntry **pMethods = NULL;
   2937     MethodEntry* method;
   2938     FILE* dataFp = NULL;
   2939     DataHeader dataHeader;
   2940     int ii, jj, numThreads;
   2941     uint64_t currentTime;
   2942     MethodEntry* caller;
   2943 
   2944     dataFp = fopen(traceFileName, "r");
   2945     if (dataFp == NULL)
   2946         goto bail;
   2947 
   2948     if ((dataKeys = parseKeys(dataFp, 0)) == NULL)
   2949        goto bail;
   2950 
   2951     if (parseDataHeader(dataFp, &dataHeader) < 0)
   2952         goto bail;
   2953 
   2954     numThreads = dataKeys->numThreads;
   2955 
   2956 #if 0
   2957     FILE *dumpStream = fopen("debug", "w");
   2958 #endif
   2959     while (1) {
   2960         int threadId;
   2961         unsigned int methodVal;
   2962         int action;
   2963         unsigned int methodId;
   2964         CallStack *pStack;
   2965 
   2966         /*
   2967          * Extract values from file.
   2968          */
   2969         if (readDataRecord(dataFp, &threadId, &methodVal, &currentTime))
   2970             break;
   2971 
   2972         action = METHOD_ACTION(methodVal);
   2973         methodId = METHOD_ID(methodVal);
   2974 
   2975         /* Get the call stack for this thread */
   2976         pStack = traceData->stacks[threadId];
   2977 
   2978         /* If there is no call stack yet for this thread, then allocate one */
   2979         if (pStack == NULL) {
   2980             pStack = malloc(sizeof(CallStack));
   2981             pStack->top = 0;
   2982             pStack->lastEventTime = currentTime;
   2983             pStack->threadStartTime = currentTime;
   2984 	    pStack->remTimes = (uint64_t*) calloc(numFilters, sizeof(uint64_t));
   2985             traceData->stacks[threadId] = pStack;
   2986         }
   2987 
   2988         /* Lookup the current method */
   2989         method = lookupMethod(dataKeys, methodId);
   2990         if (method == NULL)
   2991             method = &dataKeys->methods[UNKNOWN_INDEX];
   2992 
   2993 #if 0
   2994         if (method->methodName) {
   2995 	    fprintf(dumpStream, "%2d %-8llu %d %8llu r %d c %d %s.%s %s\n",
   2996 	           threadId, currentTime, action, pStack->threadStartTime,
   2997 	           method->recursiveEntries,
   2998 	           pStack->top, method->className, method->methodName,
   2999 	           method->signature);
   3000         } else {
   3001 	    printf(dumpStream, "%2d %-8llu %d %8llu r %d c %d %s\n",
   3002 	           threadId, currentTime, action, pStack->threadStartTime,
   3003 	           method->recursiveEntries,
   3004 	           pStack->top, method->className);
   3005         }
   3006 #endif
   3007 
   3008         if (action == METHOD_TRACE_ENTER) {
   3009             /* This is a method entry */
   3010             if (pStack->top >= MAX_STACK_DEPTH) {
   3011                 fprintf(stderr, "Stack overflow (exceeded %d frames)\n",
   3012                         MAX_STACK_DEPTH);
   3013                 exit(1);
   3014             }
   3015 
   3016             /* Get the caller method */
   3017             if (pStack->top >= 1)
   3018                 caller = pStack->calls[pStack->top - 1].method;
   3019             else
   3020                 caller = &dataKeys->methods[TOPLEVEL_INDEX];
   3021             countRecursiveEntries(pStack, pStack->top, caller);
   3022             caller->elapsedExclusive += currentTime - pStack->lastEventTime;
   3023 #if 0
   3024             if (caller->elapsedExclusive > 10000000)
   3025                 fprintf(dumpStream, "%llu current %llu last %llu diff %llu\n",
   3026                         caller->elapsedExclusive, currentTime,
   3027                         pStack->lastEventTime,
   3028                         currentTime - pStack->lastEventTime);
   3029 #endif
   3030             if (caller->recursiveEntries <= 1) {
   3031                 caller->topExclusive += currentTime - pStack->lastEventTime;
   3032             }
   3033 
   3034             /* Push the method on the stack for this thread */
   3035             pStack->calls[pStack->top].method = method;
   3036             pStack->calls[pStack->top++].entryTime = currentTime;
   3037 
   3038 	    // For each filter
   3039 	    int result = 0;
   3040 	    for (ii = 0; ii < numFilters; ii++) {
   3041 	        result = filterMethod(method, filters[ii], 1, threadId, numThreads,
   3042 				       currentTime - pStack->lastEventTime, pStack->remTimes[ii]);
   3043 
   3044 		// TODO: make remTimes work properly
   3045 		// Consider moving remTimes handling together with the rest
   3046 		// of time handling and clean up the return codes
   3047 		/*
   3048 		if (result == 0) { // no time added, no remTime added
   3049 		    pStack->remTimes[ii] += currentTime - pStack->lastEventTime;
   3050 		} else if (result == 3 || result == 4) { // remTime added
   3051 		    // Reset remTime, since it's been added
   3052 		    pStack->remTimes[ii] = 0;
   3053 		}
   3054 		*/
   3055 	    }
   3056 
   3057         } else {
   3058             /* This is a method exit */
   3059             uint64_t entryTime = 0;
   3060 
   3061             /* Pop the method off the stack for this thread */
   3062             if (pStack->top > 0) {
   3063                 pStack->top -= 1;
   3064                 entryTime = pStack->calls[pStack->top].entryTime;
   3065                 if (method != pStack->calls[pStack->top].method) {
   3066                     if (method->methodName) {
   3067                         fprintf(stderr,
   3068                             "Exit from method %s.%s %s does not match stack:\n",
   3069                             method->className, method->methodName,
   3070                             method->signature);
   3071                     } else {
   3072                         fprintf(stderr,
   3073                             "Exit from method %s does not match stack:\n",
   3074                             method->className);
   3075                     }
   3076                     stackDump(pStack, pStack->top + 1);
   3077                     exit(1);
   3078                 }
   3079             }
   3080 
   3081             /* Get the caller method */
   3082             if (pStack->top >= 1)
   3083                 caller = pStack->calls[pStack->top - 1].method;
   3084             else
   3085                 caller = &dataKeys->methods[TOPLEVEL_INDEX];
   3086             countRecursiveEntries(pStack, pStack->top, caller);
   3087             countRecursiveEntries(pStack, pStack->top, method);
   3088             uint64_t elapsed = currentTime - entryTime;
   3089             addInclusiveTime(caller, method, elapsed);
   3090             method->elapsedExclusive += currentTime - pStack->lastEventTime;
   3091             if (method->recursiveEntries == 0) {
   3092                 method->topExclusive += currentTime - pStack->lastEventTime;
   3093             }
   3094 
   3095 	    // For each filter
   3096 	    int result = 0;
   3097 	    for (ii = 0; ii < numFilters; ii++) {
   3098 	        result = filterMethod(method, filters[ii], 0, threadId, numThreads,
   3099 				       currentTime - pStack->lastEventTime, pStack->remTimes[ii]);
   3100 
   3101 		// TODO: make remTimes work properly
   3102 		/*
   3103 		if (result == 0) { // no time added, no remTime added
   3104 		    pStack->remTimes[ii] += currentTime - pStack->lastEventTime;
   3105 		} else if (result == 3 || result == 4) { // remTime added
   3106 		    // Reset remTime, since it's been added
   3107 		    pStack->remTimes[ii] = 0;
   3108 		}
   3109 		*/
   3110 	    }
   3111 
   3112         }
   3113         /* Remember the time of the last entry or exit event */
   3114         pStack->lastEventTime = currentTime;
   3115     }
   3116 
   3117     /* If we have calls on the stack when the trace ends, then clean
   3118      * up the stack and add time to the callers by pretending that we
   3119      * are exiting from their methods now.
   3120      */
   3121     CallStack *pStack;
   3122     int threadId;
   3123     uint64_t elapsedTime = 0;
   3124     uint64_t sumThreadTime = 0;
   3125     for (threadId = 0; threadId < MAX_THREADS; ++threadId) {
   3126 
   3127         pStack = traceData->stacks[threadId];
   3128 
   3129         /* If this thread never existed, then continue with next thread */
   3130         if (pStack == NULL)
   3131             continue;
   3132 
   3133         /* Calculate times spent in thread, and add it to total time */
   3134         elapsedTime = pStack->lastEventTime - pStack->threadStartTime;
   3135         sumThreadTime += elapsedTime;
   3136 
   3137         for (ii = 0; ii < pStack->top; ++ii) {
   3138 	  //printf("in loop\n");
   3139 
   3140             if (ii == 0)
   3141                 caller = &dataKeys->methods[TOPLEVEL_INDEX];
   3142             else
   3143                 caller = pStack->calls[ii - 1].method;
   3144             method = pStack->calls[ii].method;
   3145             countRecursiveEntries(pStack, ii, caller);
   3146             countRecursiveEntries(pStack, ii, method);
   3147 
   3148             uint64_t entryTime = pStack->calls[ii].entryTime;
   3149             uint64_t elapsed = pStack->lastEventTime - entryTime;
   3150             addInclusiveTime(caller, method, elapsed);
   3151 
   3152 	    // For each filter
   3153 	    int result = 0;
   3154 	    for (ii = 0; ii < numFilters; ii++) {
   3155 	        result = filterMethod(method, filters[ii], 0, threadId, numThreads,
   3156 				       currentTime - pStack->lastEventTime, pStack->remTimes[ii]);
   3157 
   3158 		// TODO: make remTimes work properly
   3159 		/*
   3160 		if (result == 0) { // no time added, no remTime added
   3161 		    pStack->remTimes[ii] += currentTime - pStack->lastEventTime;
   3162 		} else if (result == 3 || result == 4) { // remTime added
   3163 		    // Reset remTime, since it's been added
   3164 		    pStack->remTimes[ii] = 0;
   3165 		}
   3166 		*/
   3167 	    }
   3168         }
   3169 
   3170 	/* Save the per-thread elapsed time in the DataKeys struct */
   3171 	for (ii = 0; ii < dataKeys->numThreads; ++ii) {
   3172 	    if (dataKeys->threads[ii].threadId == threadId) {
   3173                 dataKeys->threads[ii].elapsedTime = elapsedTime;
   3174 	    }
   3175 	}
   3176 
   3177 
   3178     }
   3179     caller = &dataKeys->methods[TOPLEVEL_INDEX];
   3180     caller->elapsedInclusive = sumThreadTime;
   3181 
   3182 #if 0
   3183     fclose(dumpStream);
   3184 #endif
   3185 
   3186     if (threadTime != NULL) {
   3187         *threadTime = sumThreadTime;
   3188     }
   3189 
   3190 bail:
   3191     if (dataFp != NULL)
   3192         fclose(dataFp);
   3193 
   3194     return dataKeys;
   3195 }
   3196 
   3197 MethodEntry** parseMethodEntries(DataKeys* dataKeys)
   3198 {
   3199     int ii;
   3200     /* Create a new array of pointers to the methods and sort the pointers
   3201      * instead of the actual MethodEntry structs.  We need to do this
   3202      * because there are other lists that contain pointers to the
   3203      * MethodEntry structs.
   3204      */
   3205     MethodEntry** pMethods = (MethodEntry**) malloc(sizeof(MethodEntry*) * dataKeys->numMethods);
   3206     for (ii = 0; ii < dataKeys->numMethods; ++ii) {
   3207         MethodEntry* entry = &dataKeys->methods[ii];
   3208         pMethods[ii] = entry;
   3209     }
   3210 
   3211     return pMethods;
   3212 }
   3213 
   3214 
   3215 /*
   3216  * Produce a function profile from the following methods
   3217  */
   3218 void profileTrace(TraceData* traceData, MethodEntry **pMethods, int numMethods, uint64_t sumThreadTime,
   3219                   ThreadEntry *pThreads, int numThreads, Filter** filters)
   3220 {
   3221    /* Print the html header, if necessary */
   3222     if (gOptions.outputHtml) {
   3223         printf(htmlHeader, gOptions.sortableUrl);
   3224         outputTableOfContents();
   3225     }
   3226 
   3227     printExclusiveProfile(pMethods, numMethods, sumThreadTime);
   3228     printInclusiveProfile(pMethods, numMethods, sumThreadTime);
   3229 
   3230     printThreadProfile(pThreads, numThreads, sumThreadTime, filters);
   3231 
   3232     createClassList(traceData, pMethods, numMethods);
   3233     printClassProfiles(traceData, sumThreadTime);
   3234 
   3235     createUniqueMethodList(traceData, pMethods, numMethods);
   3236     printMethodProfiles(traceData, sumThreadTime);
   3237 
   3238     if (gOptions.outputHtml) {
   3239         printf("%s", htmlFooter);
   3240     }
   3241 }
   3242 
   3243 int compareMethodNamesForDiff(const void *a, const void *b)
   3244 {
   3245     int result;
   3246 
   3247     const MethodEntry *methodA = *(const MethodEntry**)a;
   3248     const MethodEntry *methodB = *(const MethodEntry**)b;
   3249     if (methodA->methodName == NULL || methodB->methodName == NULL) {
   3250         return compareClassNames(a, b);
   3251     }
   3252     result = strcmp(methodA->methodName, methodB->methodName);
   3253     if (result == 0) {
   3254         result = strcmp(methodA->signature, methodB->signature);
   3255         if (result == 0) {
   3256            return strcmp(methodA->className, methodB->className);
   3257         }
   3258     }
   3259     return result;
   3260 }
   3261 
   3262 int findMatch(MethodEntry** methods, int size, MethodEntry* matchThis)
   3263 {
   3264     int i;
   3265 
   3266     for (i = 0 ; i < size ; i++) {
   3267         MethodEntry* method = methods[i];
   3268 
   3269         if (method != NULL && !compareMethodNamesForDiff(&method, &matchThis)) {
   3270 //            printf("%s.%s == %s.%s<br>\n", matchThis->className, matchThis->methodName,
   3271   //              method->className, method->methodName);
   3272 
   3273             return i;
   3274 /*            if (!compareMethodNames(&method, &matchThis)) {
   3275                 return i;
   3276             }
   3277 */        }
   3278     }
   3279 
   3280     return -1;
   3281 }
   3282 
   3283 int compareDiffEntriesExculsive(const void *a, const void *b)
   3284 {
   3285     int result;
   3286 
   3287     const DiffEntry* entryA = (const DiffEntry*)a;
   3288     const DiffEntry* entryB = (const DiffEntry*)b;
   3289 
   3290     if (entryA->differenceExclusive < entryB->differenceExclusive) {
   3291         return 1;
   3292     } else if (entryA->differenceExclusive > entryB->differenceExclusive) {
   3293         return -1;
   3294     }
   3295 
   3296     return 0;
   3297 }
   3298 
   3299 int compareDiffEntriesInculsive(const void *a, const void *b)
   3300 {
   3301     int result;
   3302 
   3303     const DiffEntry* entryA = (const DiffEntry*)a;
   3304     const DiffEntry* entryB = (const DiffEntry*)b;
   3305 
   3306     if (entryA->differenceInclusive < entryB->differenceInclusive) {
   3307         return 1;
   3308     } else if (entryA->differenceInclusive > entryB->differenceInclusive) {
   3309         return -1;
   3310     }
   3311 
   3312     return 0;
   3313 }
   3314 
   3315 void printMissingMethod(MethodEntry* method)
   3316 {
   3317     char classBuf[HTML_BUFSIZE];
   3318     char methodBuf[HTML_BUFSIZE];
   3319     char* className;
   3320     char* methodName;
   3321 
   3322     className = htmlEscape(method->className, classBuf, HTML_BUFSIZE);
   3323     methodName = htmlEscape(method->methodName, methodBuf, HTML_BUFSIZE);
   3324 
   3325     if (gOptions.outputHtml) printf("<tr><td>\n");
   3326 
   3327     printf("%s.%s ", className, methodName);
   3328     if (gOptions.outputHtml) printf("</td><td>");
   3329 
   3330     printf("%lld ", method->elapsedExclusive);
   3331     if (gOptions.outputHtml) printf("</td><td>");
   3332 
   3333     printf("%lld ", method->elapsedInclusive);
   3334     if (gOptions.outputHtml) printf("</td><td>");
   3335 
   3336     printf("%d\n", method->numCalls[0]);
   3337     if (gOptions.outputHtml) printf("</td><td>\n");
   3338 }
   3339 
   3340 
   3341 void createDiff(DataKeys* d1, uint64_t sum1, DataKeys* d2, uint64_t sum2)
   3342 {
   3343     MethodEntry** methods1 = parseMethodEntries(d1);
   3344     MethodEntry** methods2 = parseMethodEntries(d2);
   3345 
   3346     // sort and assign the indicies
   3347     int i;
   3348     qsort(methods1, d1->numMethods, sizeof(MethodEntry*), compareElapsedInclusive);
   3349     for (i = 0; i < d1->numMethods; ++i) {
   3350         methods1[i]->index = i;
   3351     }
   3352 
   3353     qsort(methods2, d2->numMethods, sizeof(MethodEntry*), compareElapsedInclusive);
   3354     for (i = 0; i < d2->numMethods; ++i) {
   3355         methods2[i]->index = i;
   3356     }
   3357 
   3358     int max = (d1->numMethods < d2->numMethods) ? d2->numMethods : d1->numMethods;
   3359     max++;
   3360     DiffEntry* diffs = (DiffEntry*)malloc(max * sizeof(DiffEntry));
   3361     memset(diffs, 0, max * sizeof(DiffEntry));
   3362     DiffEntry* ptr = diffs;
   3363 
   3364 //    printf("<br>d1->numMethods: %d d1->numMethods: %d<br>\n", d1->numMethods, d2->numMethods);
   3365 
   3366     int matches = 0;
   3367 
   3368     for (i = 0 ; i < d1->numMethods ; i++) {
   3369         int match = findMatch(methods2, d2->numMethods, methods1[i]);
   3370         if (match >= 0) {
   3371             ptr->method1 = methods1[i];
   3372             ptr->method2 = methods2[match];
   3373 
   3374             uint64_t e1 = ptr->method1->elapsedExclusive;
   3375             uint64_t e2 = ptr->method2->elapsedExclusive;
   3376             if (e1 > 0) {
   3377                 ptr->differenceExclusive = e2 - e1;
   3378                 ptr->differenceExclusivePercentage = ((double)e2 / (double)e1) * 100.0;
   3379             }
   3380 
   3381             uint64_t i1 = ptr->method1->elapsedInclusive;
   3382             uint64_t i2 = ptr->method2->elapsedInclusive;
   3383             if (i1 > 0) {
   3384                 ptr->differenceInclusive = i2 - i1;
   3385                 ptr->differenceInclusivePercentage = ((double)i2 / (double)i1) * 100.0;
   3386             }
   3387 
   3388             // clear these out so we don't find them again and we know which ones
   3389             // we have left over
   3390             methods1[i] = NULL;
   3391             methods2[match] = NULL;
   3392             ptr++;
   3393 
   3394             matches++;
   3395         }
   3396     }
   3397     ptr->method1 = NULL;
   3398     ptr->method2 = NULL;
   3399 
   3400     qsort(diffs, matches, sizeof(DiffEntry), compareDiffEntriesExculsive);
   3401     ptr = diffs;
   3402 
   3403     if (gOptions.outputHtml) {
   3404         printf(htmlHeader, gOptions.sortableUrl);
   3405         printf("<h3>Table of Contents</h3>\n");
   3406         printf("<ul>\n");
   3407         printf("<li><a href='#exclusive'>Exclusive</a>\n");
   3408         printf("<li><a href='#inclusive'>Inclusive</a>\n");
   3409         printf("</ul>\n");
   3410         printf("Run 1: %s<br>\n", gOptions.diffFileName);
   3411         printf("Run 2: %s<br>\n", gOptions.traceFileName);
   3412         printf("<a name=\"exclusive\"></a><h3 id=\"exclusive\">Exclusive</h3>\n");
   3413         printf(tableHeader, "exclusive_table");
   3414     }
   3415 
   3416     char classBuf[HTML_BUFSIZE];
   3417     char methodBuf[HTML_BUFSIZE];
   3418     char* className;
   3419     char* methodName;
   3420 
   3421     while (ptr->method1 != NULL && ptr->method2 != NULL) {
   3422         if (gOptions.outputHtml) printf("<tr><td>\n");
   3423 
   3424         className = htmlEscape(ptr->method1->className, classBuf, HTML_BUFSIZE);
   3425         methodName = htmlEscape(ptr->method1->methodName, methodBuf, HTML_BUFSIZE);
   3426 
   3427         printf("%s.%s ", className, methodName);
   3428         if (gOptions.outputHtml) printf("</td><td>");
   3429 
   3430         printf("%lld ", ptr->method1->elapsedExclusive);
   3431         if (gOptions.outputHtml) printf("</td><td>");
   3432 
   3433         printf("%llu ", ptr->method2->elapsedExclusive);
   3434         if (gOptions.outputHtml) printf("</td><td>");
   3435 
   3436         printf("%lld ", ptr->differenceExclusive);
   3437         if (gOptions.outputHtml) printf("</td><td>");
   3438 
   3439         printf("%.2f\n", ptr->differenceExclusivePercentage);
   3440         if (gOptions.outputHtml) printf("</td><td>\n");
   3441 
   3442         printf("%d\n", ptr->method1->numCalls[0]);
   3443         if (gOptions.outputHtml) printf("</td><td>\n");
   3444 
   3445         printf("%d\n", ptr->method2->numCalls[0]);
   3446         if (gOptions.outputHtml) printf("</td></tr>\n");
   3447 
   3448         ptr++;
   3449     }
   3450 
   3451     if (gOptions.outputHtml) printf("</table>\n");
   3452 
   3453     if (gOptions.outputHtml) {
   3454         printf(htmlHeader, gOptions.sortableUrl);
   3455         printf("Run 1: %s<br>\n", gOptions.diffFileName);
   3456         printf("Run 2: %s<br>\n", gOptions.traceFileName);
   3457         printf("<a name=\"inclusive\"></a><h3 id=\"inculisve\">Inclusive</h3>\n");
   3458         printf(tableHeader, "inclusive_table");
   3459     }
   3460 
   3461     qsort(diffs, matches, sizeof(DiffEntry), compareDiffEntriesInculsive);
   3462     ptr = diffs;
   3463 
   3464     while (ptr->method1 != NULL && ptr->method2 != NULL) {
   3465         if (gOptions.outputHtml) printf("<tr><td>\n");
   3466 
   3467         className = htmlEscape(ptr->method1->className, classBuf, HTML_BUFSIZE);
   3468         methodName = htmlEscape(ptr->method1->methodName, methodBuf, HTML_BUFSIZE);
   3469 
   3470         printf("%s.%s ", className, methodName);
   3471         if (gOptions.outputHtml) printf("</td><td>");
   3472 
   3473         printf("%lld ", ptr->method1->elapsedInclusive);
   3474         if (gOptions.outputHtml) printf("</td><td>");
   3475 
   3476         printf("%llu ", ptr->method2->elapsedInclusive);
   3477         if (gOptions.outputHtml) printf("</td><td>");
   3478 
   3479         printf("%lld ", ptr->differenceInclusive);
   3480         if (gOptions.outputHtml) printf("</td><td>");
   3481 
   3482         printf("%.2f\n", ptr->differenceInclusivePercentage);
   3483         if (gOptions.outputHtml) printf("</td><td>\n");
   3484 
   3485         printf("%d\n", ptr->method1->numCalls[0]);
   3486         if (gOptions.outputHtml) printf("</td><td>\n");
   3487 
   3488         printf("%d\n", ptr->method2->numCalls[0]);
   3489         if (gOptions.outputHtml) printf("</td></tr>\n");
   3490 
   3491         ptr++;
   3492     }
   3493 
   3494     if (gOptions.outputHtml) {
   3495         printf("</table>\n");
   3496         printf("<h3>Run 1 methods not found in Run 2</h3>");
   3497         printf(tableHeaderMissing);
   3498     }
   3499 
   3500     for (i = 0; i < d1->numMethods; ++i) {
   3501         if (methods1[i] != NULL) {
   3502            printMissingMethod(methods1[i]);
   3503         }
   3504     }
   3505 
   3506     if (gOptions.outputHtml) {
   3507         printf("</table>\n");
   3508         printf("<h3>Run 2 methods not found in Run 1</h3>");
   3509         printf(tableHeaderMissing);
   3510     }
   3511 
   3512     for (i = 0; i < d2->numMethods; ++i) {
   3513         if (methods2[i] != NULL) {
   3514             printMissingMethod(methods2[i]);
   3515         }
   3516     }
   3517 
   3518     if (gOptions.outputHtml) printf("</body></html\n");
   3519 }
   3520 
   3521 int usage(const char *program)
   3522 {
   3523     fprintf(stderr, "usage: %s [-ho] [-s sortable] [-d trace-file-name] [-g outfile] [-f filter-file] trace-file-name\n", program);
   3524     fprintf(stderr, "  -d trace-file-name  - Diff with this trace\n");
   3525     fprintf(stderr, "  -g outfile          - Write graph to 'outfile'\n");
   3526     fprintf(stderr, "  -f filter-file      - Filter functions as specified in file\n");
   3527     fprintf(stderr, "  -k                  - When writing a graph, keep the intermediate DOT file\n");
   3528     fprintf(stderr, "  -h                  - Turn on HTML output\n");
   3529     fprintf(stderr, "  -o                  - Dump the dmtrace file instead of profiling\n");
   3530     fprintf(stderr, "  -s                  - URL base to where the sortable javascript file\n");
   3531     fprintf(stderr, "  -t threshold        - Threshold percentage for including nodes in the graph\n");
   3532     return 2;
   3533 }
   3534 
   3535 // Returns true if there was an error
   3536 int parseOptions(int argc, char **argv)
   3537 {
   3538     while (1) {
   3539         int opt = getopt(argc, argv, "d:hg:kos:t:f:");
   3540         if (opt == -1)
   3541             break;
   3542         switch (opt) {
   3543             case 'd':
   3544                 gOptions.diffFileName = optarg;
   3545                 break;
   3546             case 'g':
   3547                 gOptions.graphFileName = optarg;
   3548                 break;
   3549             case 'f':
   3550 	        gOptions.filterFileName = optarg;
   3551                 break;
   3552             case 'k':
   3553                 gOptions.keepDotFile = 1;
   3554                 break;
   3555             case 'h':
   3556                 gOptions.outputHtml = 1;
   3557                 break;
   3558             case 'o':
   3559                 gOptions.dump = 1;
   3560                 break;
   3561             case 's':
   3562                 gOptions.sortableUrl = optarg;
   3563                 break;
   3564             case 't':
   3565                 gOptions.threshold = atoi(optarg);
   3566                 break;
   3567             default:
   3568                 return 1;
   3569         }
   3570     }
   3571     return 0;
   3572 }
   3573 
   3574 /*
   3575  * Parse args.
   3576  */
   3577 int main(int argc, char** argv)
   3578 {
   3579 
   3580     gOptions.threshold = -1;
   3581 
   3582     // Parse the options
   3583     if (parseOptions(argc, argv) || argc - optind != 1)
   3584         return usage(argv[0]);
   3585 
   3586     gOptions.traceFileName = argv[optind];
   3587 
   3588     if (gOptions.threshold < 0 || 100 <= gOptions.threshold) {
   3589         gOptions.threshold = 20;
   3590     }
   3591 
   3592     if (gOptions.dump) {
   3593         dumpTrace();
   3594         return 0;
   3595     }
   3596 
   3597     uint64_t sumThreadTime = 0;
   3598 
   3599     Filter** filters = NULL;
   3600     if (gOptions.filterFileName != NULL) {
   3601         filters = parseFilters(gOptions.filterFileName);
   3602     }
   3603 
   3604     TraceData data1;
   3605     DataKeys* dataKeys = parseDataKeys(&data1, gOptions.traceFileName,
   3606                                        &sumThreadTime, filters);
   3607     if (dataKeys == NULL) {
   3608         fprintf(stderr, "Cannot read trace.\n");
   3609         exit(1);
   3610     }
   3611 
   3612     if (gOptions.diffFileName != NULL) {
   3613         uint64_t sum2;
   3614         TraceData data2;
   3615         DataKeys* d2 = parseDataKeys(&data2, gOptions.diffFileName, &sum2, filters);
   3616 
   3617         createDiff(d2, sum2, dataKeys, sumThreadTime);
   3618 
   3619         freeDataKeys(d2);
   3620     } else {
   3621         MethodEntry** methods = parseMethodEntries(dataKeys);
   3622         profileTrace(&data1, methods, dataKeys->numMethods, sumThreadTime,
   3623                      dataKeys->threads, dataKeys->numThreads, filters);
   3624         if (gOptions.graphFileName != NULL) {
   3625             createInclusiveProfileGraphNew(dataKeys);
   3626         }
   3627         free(methods);
   3628     }
   3629 
   3630     freeDataKeys(dataKeys);
   3631 
   3632     return 0;
   3633 }
   3634