vm/Profile.c

   1 /*
   2  * Copyright (C) 2008 The Android Open Source Project
   3  *
   4  * Licensed under the Apache License, Version 2.0 (the "License");
   5  * you may not use this file except in compliance with the License.
   6  * You may obtain a copy of the License at
   7  *
   8  *      http://www.apache.org/licenses/LICENSE-2.0
   9  *
  10  * Unless required by applicable law or agreed to in writing, software
  11  * distributed under the License is distributed on an "AS IS" BASIS,
  12  * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
  13  * See the License for the specific language governing permissions and
  14  * limitations under the License.
  15  */
  16
  17 /*
  18  * Android's method call profiling goodies.
  19  */
  20 #include "Dalvik.h"
  21
  22 #ifdef WITH_PROFILER        // -- include rest of file
  23
  24 #include <stdlib.h>
  25 #include <stddef.h>
  26 #include <string.h>
  27 #include <sys/time.h>
  28 #include <time.h>
  29 #include <sys/mman.h>
  30 #include <sched.h>
  31 #include <errno.h>
  32
  33 #ifdef HAVE_ANDROID_OS
  34 # define UPDATE_MAGIC_PAGE      1
  35 # define MAGIC_PAGE_BASE_ADDR   0x08000000
  36 # ifndef PAGESIZE
  37 #  define PAGESIZE              4096
  38 # endif
  39 #endif
  40
  41 /*
  42  * File format:
  43  *  header
  44  *  record 0
  45  *  record 1
  46  *  ...
  47  *
  48  * Header format:
  49  *  u4  magic ('SLOW')
  50  *  u2  version
  51  *  u2  offset to data
  52  *  u8  start date/time in usec
  53  *
  54  * Record format:
  55  *  u1  thread ID
  56  *  u4  method ID | method action
  57  *  u4  time delta since start, in usec
  58  *
  59  * 32 bits of microseconds is 70 minutes.
  60  *
  61  * All values are stored in little-endian order.
  62  */
  63 #define TRACE_REC_SIZE      9
  64 #define TRACE_MAGIC         0x574f4c53
  65 #define TRACE_HEADER_LEN    32
  66
  67
  68 /*
  69  * Get the wall-clock date/time, in usec.
  70  */
  71 static inline u8 getTimeInUsec()
  72 {
  73     struct timeval tv;
  74
  75     gettimeofday(&tv, NULL);
  76     return tv.tv_sec * 1000000LL + tv.tv_usec;
  77 }
  78
  79 /*
  80  * Get the current time, in microseconds.
  81  *
  82  * This can mean one of two things.  In "global clock" mode, we get the
  83  * same time across all threads.  If we use CLOCK_THREAD_CPUTIME_ID, we
  84  * get a per-thread CPU usage timer.  The latter is better, but a bit
  85  * more complicated to implement.
  86  */
  87 static inline u8 getClock()
  88 {
  89 #if defined(HAVE_POSIX_CLOCKS)
  90     struct timespec tm;
  91
  92     clock_gettime(CLOCK_THREAD_CPUTIME_ID, &tm);
  93     //assert(tm.tv_nsec >= 0 && tm.tv_nsec < 1*1000*1000*1000);
  94     if (!(tm.tv_nsec >= 0 && tm.tv_nsec < 1*1000*1000*1000)) {
  95         LOGE("bad nsec: %ld\n", tm.tv_nsec);
  96         dvmAbort();
  97     }
  98
  99     return tm.tv_sec * 1000000LL + tm.tv_nsec / 1000;
 100 #else
 101     struct timeval tv;
 102
 103     gettimeofday(&tv, NULL);
 104     return tv.tv_sec * 1000000LL + tv.tv_usec;
 105 #endif
 106 }
 107
 108 /*
 109  * Write little-endian data.
 110  */
 111 static inline void storeShortLE(u1* buf, u2 val)
 112 {
 113     *buf++ = (u1) val;
 114     *buf++ = (u1) (val >> 8);
 115 }
 116 static inline void storeIntLE(u1* buf, u4 val)
 117 {
 118     *buf++ = (u1) val;
 119     *buf++ = (u1) (val >> 8);
 120     *buf++ = (u1) (val >> 16);
 121     *buf++ = (u1) (val >> 24);
 122 }
 123 static inline void storeLongLE(u1* buf, u8 val)
 124 {
 125     *buf++ = (u1) val;
 126     *buf++ = (u1) (val >> 8);
 127     *buf++ = (u1) (val >> 16);
 128     *buf++ = (u1) (val >> 24);
 129     *buf++ = (u1) (val >> 32);
 130     *buf++ = (u1) (val >> 40);
 131     *buf++ = (u1) (val >> 48);
 132     *buf++ = (u1) (val >> 56);
 133 }
 134
 135 /*
 136  * Boot-time init.
 137  */
 138 bool dvmProfilingStartup(void)
 139 {
 140     /*
 141      * Initialize "dmtrace" method profiling.
 142      */
 143     memset(&gDvm.methodTrace, 0, sizeof(gDvm.methodTrace));
 144     dvmInitMutex(&gDvm.methodTrace.startStopLock);
 145     pthread_cond_init(&gDvm.methodTrace.threadExitCond, NULL);
 146
 147     ClassObject* clazz =
 148         dvmFindClassNoInit("Ldalvik/system/VMDebug;", NULL);
 149     assert(clazz != NULL);
 150     gDvm.methodTrace.gcMethod =
 151         dvmFindDirectMethodByDescriptor(clazz, "startGC", "()V");
 152     gDvm.methodTrace.classPrepMethod =
 153         dvmFindDirectMethodByDescriptor(clazz, "startClassPrep", "()V");
 154     if (gDvm.methodTrace.gcMethod == NULL ||
 155         gDvm.methodTrace.classPrepMethod == NULL)
 156     {
 157         LOGE("Unable to find startGC or startClassPrep\n");
 158         return false;
 159     }
 160
 161     assert(!dvmCheckException(dvmThreadSelf()));
 162
 163     /*
 164      * Allocate storage for instruction counters.
 165      */
 166     gDvm.executedInstrCounts = (int*) malloc(kNumDalvikInstructions * sizeof(int));
 167     if (gDvm.executedInstrCounts == NULL)
 168         return false;
 169     memset(gDvm.executedInstrCounts, 0, kNumDalvikInstructions * sizeof(int));
 170
 171 #ifdef UPDATE_MAGIC_PAGE
 172     /*
 173      * If we're running on the emulator, there's a magic page into which
 174      * we can put interpreted method information.  This allows interpreted
 175      * methods to show up in the emulator's code traces.
 176      *
 177      * We could key this off of the "ro.kernel.qemu" property, but there's
 178      * no real harm in doing this on a real device.
 179      */
 180     gDvm.emulatorTracePage = mmap((void*) MAGIC_PAGE_BASE_ADDR,
 181         PAGESIZE, PROT_READ|PROT_WRITE, MAP_FIXED|MAP_SHARED|MAP_ANON, -1, 0);
 182     if (gDvm.emulatorTracePage == MAP_FAILED) {
 183         LOGE("Unable to mmap magic page (0x%08x)\n", MAGIC_PAGE_BASE_ADDR);
 184         return false;
 185     }
 186     *(u4*) gDvm.emulatorTracePage = 0;
 187 #else
 188     assert(gDvm.emulatorTracePage == NULL);
 189 #endif
 190
 191     return true;
 192 }
 193
 194 /*
 195  * Free up profiling resources.
 196  */
 197 void dvmProfilingShutdown(void)
 198 {
 199 #ifdef UPDATE_MAGIC_PAGE
 200     if (gDvm.emulatorTracePage != NULL)
 201         munmap(gDvm.emulatorTracePage, PAGESIZE);
 202 #endif
 203     free(gDvm.executedInstrCounts);
 204 }
 205
 206 /*
 207  * Update the "active profilers" count.
 208  *
 209  * "count" should be +1 or -1.
 210  */
 211 static void updateActiveProfilers(int count)
 212 {
 213     int oldValue, newValue;
 214
 215     do {
 216         oldValue = gDvm.activeProfilers;
 217         newValue = oldValue + count;
 218         if (newValue < 0) {
 219             LOGE("Can't have %d active profilers\n", newValue);
 220             dvmAbort();
 221         }
 222     } while (!ATOMIC_CMP_SWAP(&gDvm.activeProfilers, oldValue, newValue));
 223
 224     LOGD("+++ active profiler count now %d\n", newValue);
 225 }
 226
 227
 228 /*
 229  * Reset the "cpuClockBase" field in all threads.
 230  */
 231 static void resetCpuClockBase(void)
 232 {
 233     Thread* thread;
 234
 235     dvmLockThreadList(NULL);
 236     for (thread = gDvm.threadList; thread != NULL; thread = thread->next) {
 237         thread->cpuClockBaseSet = false;
 238         thread->cpuClockBase = 0;
 239     }
 240     dvmUnlockThreadList();
 241 }
 242
 243 /*
 244  * Dump the thread list to the specified file.
 245  */
 246 static void dumpThreadList(FILE* fp)
 247 {
 248     Thread* thread;
 249
 250     dvmLockThreadList(NULL);
 251     for (thread = gDvm.threadList; thread != NULL; thread = thread->next) {
 252         char* name = dvmGetThreadName(thread);
 253
 254         fprintf(fp, "%d\t%s\n", thread->threadId, name);
 255         free(name);
 256     }
 257     dvmUnlockThreadList();
 258 }
 259
 260 /*
 261  * This is a dvmHashForeach callback.
 262  */
 263 static int dumpMarkedMethods(void* vclazz, void* vfp)
 264 {
 265     DexStringCache stringCache;
 266     ClassObject* clazz = (ClassObject*) vclazz;
 267     FILE* fp = (FILE*) vfp;
 268     Method* meth;
 269     char* name;
 270     int i, lineNum;
 271
 272     dexStringCacheInit(&stringCache);
 273
 274     for (i = 0; i < clazz->virtualMethodCount; i++) {
 275         meth = &clazz->virtualMethods[i];
 276         if (meth->inProfile) {
 277             name = dvmDescriptorToName(meth->clazz->descriptor);
 278             fprintf(fp, "0x%08x\t%s\t%s\t%s\t%s\t%d\n", (int) meth,
 279                 name, meth->name,
 280                 dexProtoGetMethodDescriptor(&meth->prototype, &stringCache),
 281                 dvmGetMethodSourceFile(meth), dvmLineNumFromPC(meth, 0));
 282             meth->inProfile = false;
 283             free(name);
 284         }
 285     }
 286
 287     for (i = 0; i < clazz->directMethodCount; i++) {
 288         meth = &clazz->directMethods[i];
 289         if (meth->inProfile) {
 290             name = dvmDescriptorToName(meth->clazz->descriptor);
 291             fprintf(fp, "0x%08x\t%s\t%s\t%s\t%s\t%d\n", (int) meth,
 292                 name, meth->name,
 293                 dexProtoGetMethodDescriptor(&meth->prototype, &stringCache),
 294                 dvmGetMethodSourceFile(meth), dvmLineNumFromPC(meth, 0));
 295             meth->inProfile = false;
 296             free(name);
 297         }
 298     }
 299
 300     dexStringCacheRelease(&stringCache);
 301
 302     return 0;
 303 }
 304
 305 /*
 306  * Dump the list of "marked" methods to the specified file.
 307  */
 308 static void dumpMethodList(FILE* fp)
 309 {
 310     dvmHashTableLock(gDvm.loadedClasses);
 311     dvmHashForeach(gDvm.loadedClasses, dumpMarkedMethods, (void*) fp);
 312     dvmHashTableUnlock(gDvm.loadedClasses);
 313 }
 314
 315 /*
 316  * Start method tracing.  This opens the file and allocates the buffer.
 317  * If any of these fail, we throw an exception and return.
 318  *
 319  * Method tracing is global to the VM.
 320  */
 321 void dvmMethodTraceStart(const char* traceFileName, int bufferSize, int flags)
 322 {
 323     MethodTraceState* state = &gDvm.methodTrace;
 324
 325     assert(bufferSize > 0);
 326
 327     if (state->traceEnabled != 0) {
 328         LOGI("TRACE start requested, but already in progress; stopping\n");
 329         dvmMethodTraceStop();
 330     }
 331     updateActiveProfilers(1);
 332     LOGI("TRACE STARTED: '%s' %dKB\n",
 333         traceFileName, bufferSize / 1024);
 334     dvmLockMutex(&state->startStopLock);
 335
 336     /*
 337      * Allocate storage and open files.
 338      *
 339      * We don't need to initialize the buffer, but doing so might remove
 340      * some fault overhead if the pages aren't mapped until touched.
 341      */
 342     state->buf = (u1*) malloc(bufferSize);
 343     if (state->buf == NULL) {
 344         dvmThrowException("Ljava/lang/InternalError;", "buffer alloc failed");
 345         goto fail;
 346     }
 347     state->traceFile = fopen(traceFileName, "w");
 348     if (state->traceFile == NULL) {
 349         LOGE("Unable to open trace file '%s': %s\n",
 350             traceFileName, strerror(errno));
 351         dvmThrowException("Ljava/lang/RuntimeException;", "file open failed");
 352         goto fail;
 353     }
 354     memset(state->buf, 0xee, bufferSize);
 355
 356     state->bufferSize = bufferSize;
 357     state->overflow = false;
 358
 359     /*
 360      * Enable alloc counts if we've been requested to do so.
 361      */
 362     state->flags = flags;
 363     if ((flags & TRACE_ALLOC_COUNTS) != 0)
 364         dvmStartAllocCounting();
 365
 366     /* reset our notion of the start time for all CPU threads */
 367     resetCpuClockBase();
 368
 369     state->startWhen = getTimeInUsec();
 370
 371     /*
 372      * Output the header.
 373      */
 374     memset(state->buf, 0, TRACE_HEADER_LEN);
 375     storeIntLE(state->buf + 0, TRACE_MAGIC);
 376     storeShortLE(state->buf + 4, TRACE_VERSION);
 377     storeShortLE(state->buf + 6, TRACE_HEADER_LEN);
 378     storeLongLE(state->buf + 8, state->startWhen);
 379     state->curOffset = TRACE_HEADER_LEN;
 380
 381     MEM_BARRIER();
 382
 383     /*
 384      * Set the "enabled" flag.  Once we do this, threads will wait to be
 385      * signaled before exiting, so we have to make sure we wake them up.
 386      */
 387     state->traceEnabled = true;
 388     dvmUnlockMutex(&state->startStopLock);
 389     return;
 390
 391 fail:
 392     updateActiveProfilers(-1);
 393     if (state->traceFile != NULL) {
 394         fclose(state->traceFile);
 395         state->traceFile = NULL;
 396     }
 397     if (state->buf != NULL) {
 398         free(state->buf);
 399         state->buf = NULL;
 400     }
 401     dvmUnlockMutex(&state->startStopLock);
 402 }
 403
 404 /*
 405  * Run through the data buffer and pull out the methods that were visited.
 406  * Set a mark so that we know which ones to output.
 407  */
 408 static void markTouchedMethods(void)
 409 {
 410     u1* ptr = gDvm.methodTrace.buf + TRACE_HEADER_LEN;
 411     u1* end = gDvm.methodTrace.buf + gDvm.methodTrace.curOffset;
 412     unsigned int methodVal;
 413     Method* method;
 414
 415     while (ptr < end) {
 416         methodVal = *(ptr+1) | (*(ptr+2) << 8) | (*(ptr+3) << 16)
 417                     | (*(ptr+4) << 24);
 418         method = (Method*) METHOD_ID(methodVal);
 419
 420         method->inProfile = true;
 421         ptr += TRACE_REC_SIZE;
 422     }
 423 }
 424
 425 /*
 426  * Compute the amount of overhead in a clock call, in nsec.
 427  *
 428  * This value is going to vary depending on what else is going on in the
 429  * system.  When examined across several runs a pattern should emerge.
 430  */
 431 static u4 getClockOverhead(void)
 432 {
 433     u8 calStart, calElapsed;
 434     int i;
 435
 436     calStart = getClock();
 437     for (i = 1000 * 4; i > 0; i--) {
 438         getClock();
 439         getClock();
 440         getClock();
 441         getClock();
 442         getClock();
 443         getClock();
 444         getClock();
 445         getClock();
 446     }
 447
 448     calElapsed = getClock() - calStart;
 449     return (int) (calElapsed / (8*4));
 450 }
 451
 452 /*
 453  * Returns "true" if method tracing is currently active.
 454  */
 455 bool dvmIsMethodTraceActive(void)
 456 {
 457     const MethodTraceState* state = &gDvm.methodTrace;
 458     return state->traceEnabled;
 459 }
 460
 461 /*
 462  * Stop method tracing.  We write the buffer to disk and generate a key
 463  * file so we can interpret it.
 464  */
 465 void dvmMethodTraceStop(void)
 466 {
 467     MethodTraceState* state = &gDvm.methodTrace;
 468     u8 elapsed;
 469
 470     /*
 471      * We need this to prevent somebody from starting a new trace while
 472      * we're in the process of stopping the old.
 473      */
 474     dvmLockMutex(&state->startStopLock);
 475
 476     if (!state->traceEnabled) {
 477         /* somebody already stopped it, or it was never started */
 478         LOGD("TRACE stop requested, but not running\n");
 479         dvmUnlockMutex(&state->startStopLock);
 480         return;
 481     } else {
 482         updateActiveProfilers(-1);
 483     }
 484
 485     /* compute elapsed time */
 486     elapsed = getTimeInUsec() - state->startWhen;
 487
 488     /*
 489      * Globally disable it, and allow other threads to notice.  We want
 490      * to stall here for at least as long as dvmMethodTraceAdd needs
 491      * to finish.  There's no real risk though -- it will take a while to
 492      * write the data to disk, and we don't clear the buffer pointer until
 493      * after that completes.
 494      */
 495     state->traceEnabled = false;
 496     MEM_BARRIER();
 497     sched_yield();
 498
 499     if ((state->flags & TRACE_ALLOC_COUNTS) != 0)
 500         dvmStopAllocCounting();
 501
 502     LOGI("TRACE STOPPED%s: writing %d records\n",
 503         state->overflow ? " (NOTE: overflowed buffer)" : "",
 504         (state->curOffset - TRACE_HEADER_LEN) / TRACE_REC_SIZE);
 505     if (gDvm.debuggerActive) {
 506         LOGW("WARNING: a debugger is active; method-tracing results "
 507              "will be skewed\n");
 508     }
 509
 510     /*
 511      * Do a quick calibration test to see how expensive our clock call is.
 512      */
 513     u4 clockNsec = getClockOverhead();
 514
 515     markTouchedMethods();
 516
 517     fprintf(state->traceFile, "%cversion\n", TOKEN_CHAR);
 518     fprintf(state->traceFile, "%d\n", TRACE_VERSION);
 519     fprintf(state->traceFile, "data-file-overflow=%s\n",
 520         state->overflow ? "true" : "false");
 521 #if defined(HAVE_POSIX_CLOCKS)
 522     fprintf(state->traceFile, "clock=thread-cpu\n");
 523 #else
 524     fprintf(state->traceFile, "clock=global\n");
 525 #endif
 526     fprintf(state->traceFile, "elapsed-time-usec=%llu\n", elapsed);
 527     fprintf(state->traceFile, "num-method-calls=%d\n",
 528         (state->curOffset - TRACE_HEADER_LEN) / TRACE_REC_SIZE);
 529     fprintf(state->traceFile, "clock-call-overhead-nsec=%d\n", clockNsec);
 530     fprintf(state->traceFile, "vm=dalvik\n");
 531     if ((state->flags & TRACE_ALLOC_COUNTS) != 0) {
 532         fprintf(state->traceFile, "alloc-count=%d\n",
 533             gDvm.allocProf.allocCount);
 534         fprintf(state->traceFile, "alloc-size=%d\n",
 535             gDvm.allocProf.allocSize);
 536         fprintf(state->traceFile, "gc-count=%d\n",
 537             gDvm.allocProf.gcCount);
 538     }
 539     fprintf(state->traceFile, "%cthreads\n", TOKEN_CHAR);
 540     dumpThreadList(state->traceFile);
 541     fprintf(state->traceFile, "%cmethods\n", TOKEN_CHAR);
 542     dumpMethodList(state->traceFile);
 543     fprintf(state->traceFile, "%cend\n", TOKEN_CHAR);
 544
 545     if (fwrite(state->buf, state->curOffset, 1, state->traceFile) != 1) {
 546         LOGE("trace fwrite(%d) failed, errno=%d\n", state->curOffset, errno);
 547         dvmThrowException("Ljava/lang/RuntimeException;", "data write failed");
 548         goto bail;
 549     }
 550
 551 bail:
 552     free(state->buf);
 553     state->buf = NULL;
 554     fclose(state->traceFile);
 555     state->traceFile = NULL;
 556
 557     int cc = pthread_cond_broadcast(&state->threadExitCond);
 558     assert(cc == 0);
 559     dvmUnlockMutex(&state->startStopLock);
 560 }
 561
 562
 563 /*
 564  * We just did something with a method.  Emit a record.
 565  *
 566  * Multiple threads may be banging on this all at once.  We use atomic ops
 567  * rather than mutexes for speed.
 568  */
 569 void dvmMethodTraceAdd(Thread* self, const Method* method, int action)
 570 {
 571     MethodTraceState* state = &gDvm.methodTrace;
 572     u4 clockDiff, methodVal;
 573     int oldOffset, newOffset;
 574     u1* ptr;
 575
 576     /*
 577      * We can only access the per-thread CPU clock from within the
 578      * thread, so we have to initialize the base time on the first use.
 579      * (Looks like pthread_getcpuclockid(thread, &id) will do what we
 580      * want, but it doesn't appear to be defined on the device.)
 581      */
 582     if (!self->cpuClockBaseSet) {
 583         self->cpuClockBase = getClock();
 584         self->cpuClockBaseSet = true;
 585         //LOGI("thread base id=%d 0x%llx\n",
 586         //    self->threadId, self->cpuClockBase);
 587     }
 588
 589     /*
 590      * Advance "curOffset" atomically.
 591      */
 592     do {
 593         oldOffset = state->curOffset;
 594         newOffset = oldOffset + TRACE_REC_SIZE;
 595         if (newOffset > state->bufferSize) {
 596             state->overflow = true;
 597             return;
 598         }
 599     } while (!ATOMIC_CMP_SWAP(&state->curOffset, oldOffset, newOffset));
 600
 601     //assert(METHOD_ACTION((u4) method) == 0);
 602
 603     u8 now = getClock();
 604     clockDiff = (u4) (now - self->cpuClockBase);
 605
 606     methodVal = METHOD_COMBINE((u4) method, action);
 607
 608     /*
 609      * Write data into "oldOffset".
 610      */
 611     ptr = state->buf + oldOffset;
 612     *ptr++ = self->threadId;
 613     *ptr++ = (u1) methodVal;
 614     *ptr++ = (u1) (methodVal >> 8);
 615     *ptr++ = (u1) (methodVal >> 16);
 616     *ptr++ = (u1) (methodVal >> 24);
 617     *ptr++ = (u1) clockDiff;
 618     *ptr++ = (u1) (clockDiff >> 8);
 619     *ptr++ = (u1) (clockDiff >> 16);
 620     *ptr++ = (u1) (clockDiff >> 24);
 621 }
 622
 623 /*
 624  * We just did something with a method.  Emit a record by setting a value
 625  * in a magic memory location.
 626  */
 627 void dvmEmitEmulatorTrace(const Method* method, int action)
 628 {
 629 #ifdef UPDATE_MAGIC_PAGE
 630     /*
 631      * We want to store the address of the Dalvik bytecodes.  Native and
 632      * abstract methods don't have any, so we don't do this for those.
 633      * (Abstract methods are never called, but in Dalvik they can be
 634      * because we do a "late trap" to generate the abstract method
 635      * exception.  However, we trap to a native method, so we don't need
 636      * an explicit check for abstract here.)
 637      */
 638     if (dvmIsNativeMethod(method))
 639         return;
 640     assert(method->insns != NULL);
 641
 642     u4* pMagic = ((u4*) MAGIC_PAGE_BASE_ADDR) +1;
 643
 644     /*
 645      * The dexlist output shows the &DexCode.insns offset value, which
 646      * is offset from the start of the base DEX header. Method.insns
 647      * is the absolute address, effectively offset from the start of
 648      * the optimized DEX header. We either need to return the
 649      * optimized DEX base file address offset by the right amount, or
 650      * take the "real" address and subtract off the size of the
 651      * optimized DEX header.
 652      *
 653      * Would be nice to factor this out at dexlist time, but we can't count
 654      * on having access to the correct optimized DEX file.
 655      */
 656     u4 addr;
 657 #if 0
 658     DexFile* pDexFile = method->clazz->pDvmDex->pDexFile;
 659     addr = (u4)pDexFile->pOptHeader; /* file starts at "opt" header */
 660     addr += dvmGetMethodCode(method)->insnsOff;
 661 #else
 662     const DexOptHeader* pOptHdr = method->clazz->pDvmDex->pDexFile->pOptHeader;
 663     addr = (u4) method->insns - pOptHdr->dexOffset;
 664 #endif
 665     assert(METHOD_TRACE_ENTER == 0);
 666     assert(METHOD_TRACE_EXIT == 1);
 667     assert(METHOD_TRACE_UNROLL == 2);
 668     *(pMagic+action) = addr;
 669     LOGVV("Set %p = 0x%08x (%s.%s)\n",
 670         pMagic+action, addr, method->clazz->descriptor, method->name);
 671 #endif
 672 }
 673
 674 /*
 675  * The GC calls this when it's about to start.  We add a marker to the
 676  * trace output so the tool can exclude the GC cost from the results.
 677  */
 678 void dvmMethodTraceGCBegin(void)
 679 {
 680     TRACE_METHOD_ENTER(dvmThreadSelf(), gDvm.methodTrace.gcMethod);
 681 }
 682 void dvmMethodTraceGCEnd(void)
 683 {
 684     TRACE_METHOD_EXIT(dvmThreadSelf(), gDvm.methodTrace.gcMethod);
 685 }
 686
 687 /*
 688  * The class loader calls this when it's loading or initializing a class.
 689  */
 690 void dvmMethodTraceClassPrepBegin(void)
 691 {
 692     TRACE_METHOD_ENTER(dvmThreadSelf(), gDvm.methodTrace.classPrepMethod);
 693 }
 694 void dvmMethodTraceClassPrepEnd(void)
 695 {
 696     TRACE_METHOD_EXIT(dvmThreadSelf(), gDvm.methodTrace.classPrepMethod);
 697 }
 698
 699
 700 /*
 701  * Enable emulator trace info.
 702  */
 703 void dvmEmulatorTraceStart(void)
 704 {
 705     updateActiveProfilers(1);
 706
 707     /* in theory we should make this an atomic inc; in practice not important */
 708     gDvm.emulatorTraceEnableCount++;
 709     if (gDvm.emulatorTraceEnableCount == 1)
 710         LOGD("--- emulator method traces enabled\n");
 711 }
 712
 713 /*
 714  * Disable emulator trace info.
 715  */
 716 void dvmEmulatorTraceStop(void)
 717 {
 718     if (gDvm.emulatorTraceEnableCount == 0) {
 719         LOGE("ERROR: emulator tracing not enabled\n");
 720         dvmAbort();
 721     }
 722     updateActiveProfilers(-1);
 723     /* in theory we should make this an atomic inc; in practice not important */
 724     gDvm.emulatorTraceEnableCount--;
 725     if (gDvm.emulatorTraceEnableCount == 0)
 726         LOGD("--- emulator method traces disabled\n");
 727 }
 728
 729
 730 /*
 731  * Start instruction counting.
 732  */
 733 void dvmStartInstructionCounting()
 734 {
 735     updateActiveProfilers(1);
 736     /* in theory we should make this an atomic inc; in practice not important */
 737     gDvm.instructionCountEnableCount++;
 738 }
 739
 740 /*
 741  * Start instruction counting.
 742  */
 743 void dvmStopInstructionCounting()
 744 {
 745     if (gDvm.instructionCountEnableCount == 0) {
 746         LOGE("ERROR: instruction counting not enabled\n");
 747         dvmAbort();
 748     }
 749     updateActiveProfilers(-1);
 750     gDvm.instructionCountEnableCount--;
 751 }
 752
 753
 754 /*
 755  * Start alloc counting.  Note this doesn't affect the "active profilers"
 756  * count, since the interpreter loop is not involved.
 757  */
 758 void dvmStartAllocCounting(void)
 759 {
 760     gDvm.allocProf.enabled = true;
 761 }
 762
 763 /*
 764  * Stop alloc counting.
 765  */
 766 void dvmStopAllocCounting(void)
 767 {
 768     gDvm.allocProf.enabled = false;
 769 }
 770
 771 #endif /*WITH_PROFILER*/