From 5b55af706cf3823494123da092a0a0319297a93e Mon Sep 17 00:00:00 2001 From: Rodrigo Ipince Date: Mon, 3 Aug 2009 21:34:47 -0700 Subject: [PATCH] Added thread profile to dmtracedump output The thread profile lists all the running threads, sorted by elapsed time. --- tools/dmtracedump/TraceDump.c | 123 +++++++++++++++++++++++++++++++++++++++--- 1 file changed, 115 insertions(+), 8 deletions(-) diff --git a/tools/dmtracedump/TraceDump.c b/tools/dmtracedump/TraceDump.c index ae56d4d8f..2308148cd 100644 --- a/tools/dmtracedump/TraceDump.c +++ b/tools/dmtracedump/TraceDump.c @@ -14,6 +14,7 @@ ** See the License for the specific language governing permissions and ** limitations under the License. */ + /* * Process dmtrace output. * @@ -127,6 +128,7 @@ typedef struct DataHeader { typedef struct ThreadEntry { int threadId; const char* threadName; + uint64_t elapsedTime; } ThreadEntry; struct MethodEntry; @@ -178,7 +180,7 @@ typedef struct MethodEntry { * The parsed contents of the key file. */ typedef struct DataKeys { - char* fileData; /* contents of the entire file */ + char* fileData; /* contents of the entire file */ long fileLen; int numThreads; ThreadEntry* threads; @@ -398,6 +400,37 @@ int compareElapsedInclusive(const void *a, const void *b) { /* * This comparison function is called from qsort() to sort + * threads into decreasing order of elapsed time. + */ +int compareElapsed(const void *a, const void *b) { + const ThreadEntry *threadA, *threadB; + uint64_t elapsed1, elapsed2; + int result = 0; + + threadA = (ThreadEntry const *)a; + threadB = (ThreadEntry const *)b; + elapsed1 = threadA->elapsedTime; + elapsed2 = threadB->elapsedTime; + if (elapsed1 < elapsed2) + return 1; + if (elapsed1 > elapsed2) + return -1; + + /* If the elapsed times of two threads are equal, then sort them + * by thread id. + */ + int idA = threadA->threadId; + int idB = threadB->threadId; + if (idA < idB) + result = -1; + if (idA > idB) + result = 1; + + return result; +} + +/* + * This comparison function is called from qsort() to sort * TimedMethods into decreasing order of inclusive elapsed time. */ int compareTimedMethod(const void *a, const void *b) { @@ -1078,7 +1111,7 @@ int parseDataHeader(FILE *fp, DataHeader* pHeader) } /* - * Look up a method by it's method ID. + * Look up a method by its method ID (using binary search). * * Returns NULL if no matching method was found. */ @@ -1096,7 +1129,7 @@ MethodEntry* lookupMethod(DataKeys* pKeys, unsigned int methodId) id = pKeys->methods[mid].methodId; if (id == methodId) /* match */ return &pKeys->methods[mid]; - else if (id < methodId) /* too low */ + else if (id < methodId) /* too low */ lo = mid + 1; else /* too high */ hi = mid - 1; @@ -1490,6 +1523,7 @@ void outputTableOfContents() printf("\n\n"); @@ -1500,6 +1534,7 @@ void outputNavigationBar() printf("[Top]\n"); printf("[Exclusive]\n"); printf("[Inclusive]\n"); + printf("[Thread]\n"); printf("[Class]\n"); printf("[Method]\n"); printf("

\n"); @@ -1765,6 +1800,65 @@ void printInclusiveProfile(MethodEntry **pMethods, int numMethods, } } +void printThreadProfile(ThreadEntry *pThreads, int numThreads, uint64_t sumThreadTime) +{ + int ii; + ThreadEntry thread; + double total, per, sum_per; + uint64_t sum; + char threadBuf[HTML_BUFSIZE]; + char anchor_buf[80]; + char *anchor_close = ""; + + total = sumThreadTime; + anchor_buf[0] = 0; + if (gOptions.outputHtml) { + anchor_close = ""; + printf("\n"); + printf("
\n"); + outputNavigationBar(); + } else { + printf("\n%s\n", profileSeparator); + } + + /* Sort the threads into decreasing order of elapsed time. */ + qsort(pThreads, numThreads, sizeof(ThreadEntry), compareElapsed); + + printf("\nElapsed times for each thread, sorted by elapsed time.\n\n"); + + if (gOptions.outputHtml) { + printf("

\n
\n");
+    }
+
+    printf("    Usecs   self %%  sum %% tid   ThreadName\n");
+    sum = 0;
+
+    for (ii = 0; ii < numThreads; ++ii) {
+        int threadId;
+        char *threadName;
+        uint64_t time;
+
+        thread = pThreads[ii];
+
+        threadId = thread.threadId;
+        threadName = (char*)(thread.threadName);
+        time = thread.elapsedTime;
+
+        sum += time;
+        per = 100.0 * time / total;
+        sum_per = 100.0 * sum / total;
+
+        if (gOptions.outputHtml) {
+	    threadName = htmlEscape(threadName, threadBuf, HTML_BUFSIZE);
+        }
+	printf("%9llu  %6.2f %6.2f  %3d   %s\n", time, per, sum_per, threadId, threadName);
+    }
+
+    if (gOptions.outputHtml)
+        printf("
\n"); + +} + void createClassList(TraceData* traceData, MethodEntry **pMethods, int numMethods) { int ii; @@ -2416,16 +2510,25 @@ DataKeys* parseDataKeys(TraceData* traceData, const char* traceFileName, uint64_ */ CallStack *pStack; int threadId; + uint64_t elapsedTime = 0; uint64_t sumThreadTime = 0; for (threadId = 0; threadId < MAX_THREADS; ++threadId) { + pStack = traceData->stacks[threadId]; /* If this thread never existed, then continue with next thread */ if (pStack == NULL) continue; - /* Also, add up the time taken by all of the threads */ - sumThreadTime += pStack->lastEventTime - pStack->threadStartTime; + /* Calculate time spent in thread, and add it to total time */ + elapsedTime = pStack->lastEventTime - pStack->threadStartTime; + sumThreadTime += elapsedTime; + + /* Save the per-thread elapsed time in the DataKeys struct */ + for (ii = 0; ii < dataKeys->numThreads; ++ii) { + if (dataKeys->threads[ii].threadId == threadId) + dataKeys->threads[ii].elapsedTime = elapsedTime; + } for (ii = 0; ii < pStack->top; ++ii) { if (ii == 0) @@ -2479,7 +2582,8 @@ MethodEntry** parseMethodEntries(DataKeys* dataKeys) /* * Produce a function profile from the following methods */ -void profileTrace(TraceData* traceData, MethodEntry **pMethods, int numMethods, uint64_t sumThreadTime) +void profileTrace(TraceData* traceData, MethodEntry **pMethods, int numMethods, uint64_t sumThreadTime, + ThreadEntry *pThreads, int numThreads) { /* Print the html header, if necessary */ if (gOptions.outputHtml) { @@ -2490,6 +2594,8 @@ void profileTrace(TraceData* traceData, MethodEntry **pMethods, int numMethods, printExclusiveProfile(pMethods, numMethods, sumThreadTime); printInclusiveProfile(pMethods, numMethods, sumThreadTime); + printThreadProfile(pThreads, numThreads, sumThreadTime); + createClassList(traceData, pMethods, numMethods); printClassProfiles(traceData, sumThreadTime); @@ -2844,7 +2950,7 @@ int main(int argc, char** argv) if (gOptions.threshold < 0 || 100 <= gOptions.threshold) { gOptions.threshold = 20; } - + if (gOptions.dump) { dumpTrace(); return 0; @@ -2870,7 +2976,8 @@ int main(int argc, char** argv) freeDataKeys(d2); } else { MethodEntry** methods = parseMethodEntries(dataKeys); - profileTrace(&data1, methods, dataKeys->numMethods, sumThreadTime); + profileTrace(&data1, methods, dataKeys->numMethods, sumThreadTime, + dataKeys->threads, dataKeys->numThreads); if (gOptions.graphFileName != NULL) { createInclusiveProfileGraphNew(dataKeys); } -- 2.11.0