Add option for specifying wall-clock in method profiling.

Normally you want to use the per-thread CPU clock rather than the wall
clock, because (a) it's more useful and (b) traceview goes a little nuts
if you don't.  However, it's useful for some performance testing.

The command-line option allows you to switch modes like this:

  % adb shell stop
  % adb shell setprop dalvik.vm.extra-opts -Xprofile:wallclock
  % adb shell start

This also changes the somewhat nebulous "clock=global" trace header line
to "clock=wall".  Nothing looks at this anyway so I'm not worried
about breaking compatibility.

While I was in here, I fixed a couple of problems caused by failure to
initialize data structures that made dmtracedump crash (yay valgrind).

Bug 2943229.

(cherry-pick from dalvik-dev)

Change-Id: I2f6657f7abe02f2a17784588d922b88397639a47

diff --git a/tools/dmtracedump/TraceDump.c b/tools/dmtracedump/TraceDump.c
index 02cdf98..3f80064 100644 (file)
--- a/tools/dmtracedump/TraceDump.c
+++ b/tools/dmtracedump/TraceDump.c
@@ -1060,9 +1060,6 @@ DataKeys* parseKeys(FILE *fp, int verbose)
     if (offset < 0)
         goto fail;
 
-    /* Reduce our allocation now that we know where the end of the key section is. */
-    pKeys->fileData = (char *)realloc(pKeys->fileData, offset);
-    pKeys->fileLen = offset;
     /* Leave fp pointing to the beginning of the data section. */
     fseek(fp, offset, SEEK_SET);
 
@@ -1174,7 +1171,7 @@ MethodEntry* lookupMethod(DataKeys* pKeys, unsigned int methodId)
 
     /* Create cache if it doesn't already exist */
     if (pKeys->methodCache == NULL) {
-        pKeys->methodCache = (int*) malloc(sizeof(int) * METHOD_CACHE_SIZE);
+        pKeys->methodCache = (int*) calloc(METHOD_CACHE_SIZE, sizeof(int));
     }
 
     // ids are multiples of 4, so shift
@@ -3602,6 +3599,7 @@ int main(int argc, char** argv)
     }
 
     TraceData data1;
+    memset(&data1, 0, sizeof(data1));
     DataKeys* dataKeys = parseDataKeys(&data1, gOptions.traceFileName,
                                        &sumThreadTime, filters);
     if (dataKeys == NULL) {

diff --git a/vm/Globals.h b/vm/Globals.h
index d0ad110..f6499ee 100644 (file)
--- a/vm/Globals.h
+++ b/vm/Globals.h
@@ -91,6 +91,9 @@ struct DvmGlobals {
     int         jdwpPort;
     bool        jdwpSuspend;
 
+    /* use wall clock as method profiler clock source? */
+    bool        profilerWallClock;
+
     /*
      * Lock profiling threshold value in milliseconds.  Acquires that
      * exceed threshold are logged.  Acquires within the threshold are

diff --git a/vm/Init.c b/vm/Init.c
index 84cd6c8..81a385a 100644 (file)
--- a/vm/Init.c
+++ b/vm/Init.c
@@ -995,6 +995,9 @@ static int dvmProcessOptions(int argc, const char* const argv[],
         } else if (strcmp(argv[i], "-Xcheckdexsum") == 0) {
             gDvm.verifyDexChecksum = true;
 
+        } else if (strcmp(argv[i], "-Xprofile:wallclock") == 0) {
+            gDvm.profilerWallClock = true;
+
         } else {
             if (!ignoreUnrecognized) {
                 dvmFprintf(stderr, "Unrecognized option '%s'\n", argv[i]);

diff --git a/vm/Profile.c b/vm/Profile.c
index ca3788a..d5dcc36 100644 (file)
--- a/vm/Profile.c
+++ b/vm/Profile.c
@@ -86,22 +86,24 @@ static inline u8 getTimeInUsec()
 static inline u8 getClock()
 {
 #if defined(HAVE_POSIX_CLOCKS)
-    struct timespec tm;
+    if (!gDvm.profilerWallClock) {
+        struct timespec tm;
 
-    clock_gettime(CLOCK_THREAD_CPUTIME_ID, &tm);
-    //assert(tm.tv_nsec >= 0 && tm.tv_nsec < 1*1000*1000*1000);
-    if (!(tm.tv_nsec >= 0 && tm.tv_nsec < 1*1000*1000*1000)) {
-        LOGE("bad nsec: %ld\n", tm.tv_nsec);
-        dvmAbort();
-    }
-
-    return tm.tv_sec * 1000000LL + tm.tv_nsec / 1000;
-#else
-    struct timeval tv;
+        clock_gettime(CLOCK_THREAD_CPUTIME_ID, &tm);
+        if (!(tm.tv_nsec >= 0 && tm.tv_nsec < 1*1000*1000*1000)) {
+            LOGE("bad nsec: %ld\n", tm.tv_nsec);
+            dvmAbort();
+        }
 
-    gettimeofday(&tv, NULL);
-    return tv.tv_sec * 1000000LL + tv.tv_usec;
+        return tm.tv_sec * 1000000LL + tm.tv_nsec / 1000;
+    } else
 #endif
+    {
+        struct timeval tv;
+
+        gettimeofday(&tv, NULL);
+        return tv.tv_sec * 1000000LL + tv.tv_usec;
+    }
 }
 
 /*
@@ -602,10 +604,13 @@ void dvmMethodTraceStop(void)
     fprintf(state->traceFile, "data-file-overflow=%s\n",
         state->overflow ? "true" : "false");
 #if defined(HAVE_POSIX_CLOCKS)
-    fprintf(state->traceFile, "clock=thread-cpu\n");
-#else
-    fprintf(state->traceFile, "clock=global\n");
+    if (!gDvm.profilerWallClock) {
+        fprintf(state->traceFile, "clock=thread-cpu\n");
+    } else
 #endif
+    {
+        fprintf(state->traceFile, "clock=wall\n");
+    }
     fprintf(state->traceFile, "elapsed-time-usec=%llu\n", elapsed);
     fprintf(state->traceFile, "num-method-calls=%d\n",
         (finalCurOffset - TRACE_HEADER_LEN) / TRACE_REC_SIZE);