runtime/gc/profiling.c

   1 /* Copyright (C) 2011-2012 Matthew Fluet.
   2  * Copyright (C) 1999-2007 Henry Cejtin, Matthew Fluet, Suresh
   3  *    Jagannathan, and Stephen Weeks.
   4  * Copyright (C) 1997-2000 NEC Research Institute.
   5  *
   6  * MLton is released under a BSD-style license.
   7  * See the file MLton-LICENSE for details.
   8  */
   9
  10 GC_profileMasterIndex sourceIndexToProfileMasterIndex (GC_state s,
  11                                                        GC_sourceIndex i)
  12  {
  13   GC_profileMasterIndex pmi;
  14   pmi = s->sourceMaps.sources[i].sourceNameIndex + s->sourceMaps.sourcesLength;
  15   if (DEBUG_PROFILE)
  16     fprintf (stderr, "%"PRIu32" = sourceIndexToProfileMasterIndex ("FMTSI")\n", pmi, i);
  17   return pmi;
  18 }
  19
  20 GC_sourceNameIndex profileMasterIndexToSourceNameIndex (GC_state s,
  21                                                         GC_profileMasterIndex i) {
  22   assert (i >= s->sourceMaps.sourcesLength);
  23   return i - s->sourceMaps.sourcesLength;
  24 }
  25
  26 char* profileIndexSourceName (GC_state s, GC_sourceIndex i) {
  27   char* res;
  28
  29   if (i < s->sourceMaps.sourcesLength)
  30     res = getSourceName (s, i);
  31   else
  32     res = s->sourceMaps.sourceNames[profileMasterIndexToSourceNameIndex (s, i)];
  33   return res;
  34 }
  35
  36 GC_profileStack getProfileStackInfo (GC_state s, GC_profileMasterIndex i) {
  37   assert (s->profiling.data != NULL);
  38   return &(s->profiling.data->stack[i]);
  39 }
  40
  41 static int profileDepth = 0;
  42
  43 static void profileIndent (void) {
  44   int i;
  45
  46   for (i = 0; i < profileDepth; ++i)
  47     fprintf (stderr, " ");
  48 }
  49
  50 void addToStackForProfiling (GC_state s, GC_profileMasterIndex i) {
  51   GC_profileData p;
  52   GC_profileStack ps;
  53
  54   p = s->profiling.data;
  55   ps = getProfileStackInfo (s, i);
  56   if (DEBUG_PROFILE)
  57     fprintf (stderr, "adding %s to stack  lastTotal = %"PRIuMAX"  lastTotalGC = %"PRIuMAX"\n",
  58              getSourceName (s, i),
  59              (uintmax_t)p->total,
  60              (uintmax_t)p->totalGC);
  61   ps->lastTotal = p->total;
  62   ps->lastTotalGC = p->totalGC;
  63 }
  64
  65 void enterSourceForProfiling (GC_state s, GC_profileMasterIndex i) {
  66   GC_profileStack ps;
  67
  68   ps = getProfileStackInfo (s, i);
  69   // assert (ps->numOccurrences >= 0);
  70   ps->numOccurrences++;
  71   if (1 == ps->numOccurrences) {
  72     addToStackForProfiling (s, i);
  73   }
  74 }
  75
  76 void enterForProfiling (GC_state s, GC_sourceSeqIndex sourceSeqIndex) {
  77   uint32_t i;
  78   GC_sourceIndex sourceIndex;
  79   uint32_t *sourceSeq;
  80
  81   if (DEBUG_PROFILE)
  82     fprintf (stderr, "enterForProfiling ("FMTSSI")\n", sourceSeqIndex);
  83   assert (s->profiling.stack);
  84   assert (sourceSeqIndex < s->sourceMaps.sourceSeqsLength);
  85   sourceSeq = s->sourceMaps.sourceSeqs[sourceSeqIndex];
  86   for (i = 1; i <= sourceSeq[0]; i++) {
  87     sourceIndex = sourceSeq[i];
  88     if (DEBUG_ENTER_LEAVE or DEBUG_PROFILE) {
  89       profileIndent ();
  90       fprintf (stderr, "(entering %s\n",
  91                getSourceName (s, sourceIndex));
  92       profileDepth++;
  93     }
  94     enterSourceForProfiling (s, (GC_profileMasterIndex)sourceIndex);
  95     enterSourceForProfiling (s, sourceIndexToProfileMasterIndex (s, sourceIndex));
  96   }
  97 }
  98
  99 void enterFrameForProfiling (GC_state s, GC_frameIndex i) {
 100   enterForProfiling (s, s->sourceMaps.frameSources[i]);
 101 }
 102
 103 void GC_profileEnter (GC_state s) {
 104   enterForProfiling (s, getCachedStackTopFrameSourceSeqIndex (s));
 105 }
 106
 107 void removeFromStackForProfiling (GC_state s, GC_profileMasterIndex i) {
 108   GC_profileData p;
 109   GC_profileStack ps;
 110
 111   p = s->profiling.data;
 112   ps = getProfileStackInfo (s, i);
 113   if (DEBUG_PROFILE)
 114     fprintf (stderr, "removing %s from stack  ticksInc = %"PRIuMAX"  ticksGCInc = %"PRIuMAX"\n",
 115              profileIndexSourceName (s, i),
 116              (uintmax_t)(p->total - ps->lastTotal),
 117              (uintmax_t)(p->totalGC - ps->lastTotalGC));
 118   ps->ticks += p->total - ps->lastTotal;
 119   ps->ticksGC += p->totalGC - ps->lastTotalGC;
 120 }
 121
 122 void leaveSourceForProfiling (GC_state s, GC_profileMasterIndex i) {
 123   GC_profileStack ps;
 124
 125   ps = getProfileStackInfo (s, i);
 126   assert (ps->numOccurrences > 0);
 127   ps->numOccurrences--;
 128   if (0 == ps->numOccurrences)
 129     removeFromStackForProfiling (s, i);
 130 }
 131
 132 void leaveForProfiling (GC_state s, GC_sourceSeqIndex sourceSeqIndex) {
 133   uint32_t i;
 134   GC_sourceIndex sourceIndex;
 135   uint32_t *sourceSeq;
 136
 137   if (DEBUG_PROFILE)
 138     fprintf (stderr, "leaveForProfiling ("FMTSSI")\n", sourceSeqIndex);
 139   assert (s->profiling.stack);
 140   assert (sourceSeqIndex < s->sourceMaps.sourceSeqsLength);
 141   sourceSeq = s->sourceMaps.sourceSeqs[sourceSeqIndex];
 142   for (i = sourceSeq[0]; i > 0; i--) {
 143     sourceIndex = sourceSeq[i];
 144     if (DEBUG_ENTER_LEAVE or DEBUG_PROFILE) {
 145       profileDepth--;
 146       profileIndent ();
 147       fprintf (stderr, "leaving %s)\n",
 148                getSourceName (s, sourceIndex));
 149     }
 150     leaveSourceForProfiling (s, (GC_profileMasterIndex)sourceIndex);
 151     leaveSourceForProfiling (s, sourceIndexToProfileMasterIndex (s, sourceIndex));
 152   }
 153 }
 154
 155 void GC_profileLeave (GC_state s) {
 156   leaveForProfiling (s, getCachedStackTopFrameSourceSeqIndex (s));
 157 }
 158
 159
 160 void incForProfiling (GC_state s, size_t amount, GC_sourceSeqIndex sourceSeqIndex) {
 161   uint32_t *sourceSeq;
 162   GC_sourceIndex topSourceIndex;
 163
 164   if (DEBUG_PROFILE)
 165     fprintf (stderr, "incForProfiling (%"PRIuMAX", "FMTSSI")\n",
 166              (uintmax_t)amount, sourceSeqIndex);
 167   assert (sourceSeqIndex < s->sourceMaps.sourceSeqsLength);
 168   sourceSeq = s->sourceMaps.sourceSeqs[sourceSeqIndex];
 169   topSourceIndex =
 170     sourceSeq[0] > 0
 171     ? sourceSeq[sourceSeq[0]]
 172     : SOURCES_INDEX_UNKNOWN;
 173   if (DEBUG_PROFILE) {
 174     profileIndent ();
 175     fprintf (stderr, "bumping %s by %"PRIuMAX"\n",
 176              getSourceName (s, topSourceIndex), (uintmax_t)amount);
 177   }
 178   s->profiling.data->countTop[topSourceIndex] += amount;
 179   s->profiling.data->countTop[sourceIndexToProfileMasterIndex (s, topSourceIndex)] += amount;
 180   if (s->profiling.stack)
 181     enterForProfiling (s, sourceSeqIndex);
 182   if (SOURCES_INDEX_GC == topSourceIndex)
 183     s->profiling.data->totalGC += amount;
 184   else
 185     s->profiling.data->total += amount;
 186   if (s->profiling.stack)
 187     leaveForProfiling (s, sourceSeqIndex);
 188 }
 189
 190 void GC_profileInc (GC_state s, size_t amount) {
 191   if (DEBUG_PROFILE)
 192     fprintf (stderr, "GC_profileInc (%"PRIuMAX")\n", (uintmax_t)amount);
 193   incForProfiling (s, amount,
 194                    s->amInGC
 195                    ? SOURCE_SEQ_GC
 196                    : getCachedStackTopFrameSourceSeqIndex (s));
 197 }
 198
 199 void GC_profileAllocInc (GC_state s, size_t amount) {
 200   if (s->profiling.isOn and (PROFILE_ALLOC == s->profiling.kind)) {
 201     if (DEBUG_PROFILE)
 202       fprintf (stderr, "GC_profileAllocInc (%"PRIuMAX")\n", (uintmax_t)amount);
 203     GC_profileInc (s, amount);
 204   }
 205 }
 206
 207 GC_profileData profileMalloc (GC_state s) {
 208   GC_profileData p;
 209   uint32_t profileMasterLength;
 210
 211   p = (GC_profileData)(malloc_safe (sizeof(*p)));
 212   p->total = 0;
 213   p->totalGC = 0;
 214   profileMasterLength = s->sourceMaps.sourcesLength + s->sourceMaps.sourceNamesLength;
 215   p->countTop = (uintmax_t*)(calloc_safe(profileMasterLength, sizeof(*(p->countTop))));
 216   if (s->profiling.stack)
 217     p->stack =
 218       (struct GC_profileStack *)
 219       (calloc_safe(profileMasterLength, sizeof(*(p->stack))));
 220   if (DEBUG_PROFILE)
 221     fprintf (stderr, FMTPTR" = profileMalloc ()\n", (uintptr_t)p);
 222   return p;
 223 }
 224
 225 GC_profileData GC_profileMalloc (GC_state s) {
 226   return profileMalloc (s);
 227 }
 228
 229 void profileFree (GC_state s, GC_profileData p) {
 230   if (DEBUG_PROFILE)
 231     fprintf (stderr, "profileFree ("FMTPTR")\n", (uintptr_t)p);
 232   free (p->countTop);
 233   if (s->profiling.stack)
 234     free (p->stack);
 235   free (p);
 236 }
 237
 238 void GC_profileFree (GC_state s, GC_profileData p) {
 239   profileFree (s, p);
 240 }
 241
 242 void writeProfileCount (GC_state s, FILE *f,
 243                         GC_profileData p, GC_profileMasterIndex i) {
 244   writeUintmaxU (f, p->countTop[i]);
 245   if (s->profiling.stack) {
 246     GC_profileStack ps;
 247
 248     ps = &(p->stack[i]);
 249     writeString (f, " ");
 250     writeUintmaxU (f, ps->ticks);
 251     writeString (f, " ");
 252     writeUintmaxU (f, ps->ticksGC);
 253   }
 254   writeNewline (f);
 255 }
 256
 257 void profileWrite (GC_state s, GC_profileData p, const char *fileName) {
 258   FILE *f;
 259   const char* kind;
 260
 261   if (DEBUG_PROFILE)
 262     fprintf (stderr, "profileWrite("FMTPTR",%s)\n", (uintptr_t)p, fileName);
 263   f = fopen_safe (fileName, "wb");
 264   writeString (f, "MLton prof\n");
 265   switch (s->profiling.kind) {
 266   case PROFILE_ALLOC:
 267     kind = "alloc\n";
 268     break;
 269   case PROFILE_COUNT:
 270     kind = "count\n";
 271     break;
 272   case PROFILE_NONE:
 273     die ("impossible PROFILE_NONE");
 274     // break;
 275   case PROFILE_TIME_FIELD:
 276     kind = "time\n";
 277     break;
 278   case PROFILE_TIME_LABEL:
 279     kind = "time\n";
 280     break;
 281   default:
 282     kind = "";
 283     assert (FALSE);
 284   }
 285   writeString (f, kind);
 286   writeString (f, s->profiling.stack ? "stack\n" : "current\n");
 287   writeUint32X (f, s->magic);
 288   writeNewline (f);
 289   writeUintmaxU (f, p->total);
 290   writeString (f, " ");
 291   writeUintmaxU (f, p->totalGC);
 292   writeNewline (f);
 293   writeUint32U (f, s->sourceMaps.sourcesLength);
 294   writeNewline (f);
 295   for (GC_sourceIndex i = 0; i < s->sourceMaps.sourcesLength; i++)
 296     writeProfileCount (s, f, p,
 297                        (GC_profileMasterIndex)i);
 298   writeUint32U (f, s->sourceMaps.sourceNamesLength);
 299   writeNewline (f);
 300   for (GC_sourceNameIndex i = 0; i < s->sourceMaps.sourceNamesLength; i++)
 301     writeProfileCount (s, f, p,
 302                        (GC_profileMasterIndex)(i + s->sourceMaps.sourcesLength));
 303   fclose_safe (f);
 304 }
 305
 306 void GC_profileWrite (GC_state s, GC_profileData p, NullString8_t fileName) {
 307   profileWrite (s, p, (const char*)fileName);
 308 }
 309
 310 void setProfTimer (suseconds_t usec) {
 311   struct itimerval iv;
 312
 313   iv.it_interval.tv_sec = 0;
 314   iv.it_interval.tv_usec = usec;
 315   iv.it_value.tv_sec = 0;
 316   iv.it_value.tv_usec = usec;
 317   unless (0 == setitimer (ITIMER_PROF, &iv, NULL))
 318     die ("setProfTimer: setitimer failed");
 319 }
 320
 321 #if not HAS_TIME_PROFILING
 322
 323 /* No time profiling on this platform.  There is a check in
 324  * mlton/main/main.fun to make sure that time profiling is never
 325  * turned on.
 326  */
 327 __attribute__ ((noreturn))
 328 void initProfilingTime (__attribute__ ((unused)) GC_state s) {
 329   die ("no time profiling");
 330 }
 331
 332 #else
 333
 334 static GC_state handleSigProfState;
 335
 336 void GC_handleSigProf (code_pointer pc) {
 337   GC_frameIndex frameIndex;
 338   GC_state s;
 339   GC_sourceSeqIndex sourceSeqsIndex;
 340
 341   s = handleSigProfState;
 342   if (DEBUG_PROFILE)
 343     fprintf (stderr, "GC_handleSigProf ("FMTPTR")\n", (uintptr_t)pc);
 344   if (s->amInGC)
 345     sourceSeqsIndex = SOURCE_SEQ_GC;
 346   else {
 347     frameIndex = getCachedStackTopFrameIndex (s);
 348     if (C_FRAME == s->frameLayouts[frameIndex].kind)
 349       sourceSeqsIndex = s->sourceMaps.frameSources[frameIndex];
 350     else {
 351       if (PROFILE_TIME_LABEL == s->profiling.kind) {
 352         uint32_t start, end, i;
 353
 354         /* Binary search labels to find which method contains PC */
 355         start = 0;
 356         end = s->sourceMaps.sourceLabelsLength;
 357         while (end - start > 1) {
 358           i = (start+end)/2;
 359           if ((uintptr_t)s->sourceMaps.sourceLabels[i].label <= (uintptr_t)pc)
 360             start = i;
 361           else
 362             end = i;
 363         }
 364         i = start;
 365
 366         /* The last label is dead code. Any address past it is thus unknown.
 367          * The first label is before all SML code. Before it is also unknown.
 368          */
 369         if (i-1 == s->sourceMaps.sourceLabelsLength ||
 370             (i == 0 &&
 371              (uintptr_t)pc < (uintptr_t)s->sourceMaps.sourceLabels[i].label)) {
 372           if (DEBUG_PROFILE)
 373             fprintf (stderr, "pc out of bounds\n");
 374           sourceSeqsIndex = SOURCE_SEQ_UNKNOWN;
 375         } else {
 376           sourceSeqsIndex = s->sourceMaps.sourceLabels[start].sourceSeqIndex;
 377         }
 378       } else {
 379         sourceSeqsIndex = s->sourceMaps.curSourceSeqsIndex;
 380       }
 381     }
 382   }
 383   incForProfiling (s, 1, sourceSeqsIndex);
 384 }
 385
 386 static void initProfilingTime (GC_state s) {
 387   struct sigaction sa;
 388
 389   s->profiling.data = profileMalloc (s);
 390   if (PROFILE_TIME_LABEL == s->profiling.kind) {
 391     initSourceLabels (s);
 392   } else {
 393     s->sourceMaps.curSourceSeqsIndex = SOURCE_SEQ_UNKNOWN;
 394   }
 395   /*
 396    * Install catcher, which handles SIGPROF and calls MLton_Profile_inc.
 397    *
 398    * One thing I should point out that I discovered the hard way: If
 399    * the call to sigaction does NOT specify the SA_ONSTACK flag, then
 400    * even if you have called sigaltstack(), it will NOT switch stacks,
 401    * so you will probably die.  Worse, if the call to sigaction DOES
 402    * have SA_ONSTACK and you have NOT called sigaltstack(), it still
 403    * switches stacks (to location 0) and you die of a SEGV.  Thus the
 404    * sigaction() call MUST occur after the call to sigaltstack(), and
 405    * in order to have profiling cover as much as possible, you want it
 406    * to occur right after the sigaltstack() call.
 407    */
 408   handleSigProfState = s;
 409   sigemptyset (&sa.sa_mask);
 410   GC_setSigProfHandler (&sa);
 411   unless (sigaction (SIGPROF, &sa, NULL) == 0)
 412     diee ("initProfilingTime: sigaction failed");
 413   /* Start the SIGPROF timer. */
 414   setProfTimer (10000);
 415 }
 416
 417 #endif
 418
 419 /* atexitForProfiling is for writing out an mlmon.out file even if the C code
 420  * terminates abnormally, e.g. due to running out of memory.  It will
 421  * only run if the usual SML profile atExit cleanup code did not
 422  * manage to run.
 423  */
 424 static GC_state atexitForProfilingState;
 425
 426 void atexitForProfiling (void) {
 427   GC_state s;
 428
 429   if (DEBUG_PROFILE)
 430     fprintf (stderr, "atexitForProfiling ()\n");
 431   s = atexitForProfilingState;
 432   if (s->profiling.isOn) {
 433     fprintf (stderr, "profiling is on\n");
 434     profileWrite (s, s->profiling.data, "mlmon.out");
 435   }
 436 }
 437
 438 void initProfiling (GC_state s) {
 439   if (PROFILE_NONE == s->profiling.kind)
 440     s->profiling.isOn = FALSE;
 441   else {
 442     s->profiling.isOn = TRUE;
 443     assert (s->sourceMaps.frameSourcesLength == s->frameLayoutsLength);
 444     switch (s->profiling.kind) {
 445     case PROFILE_ALLOC:
 446     case PROFILE_COUNT:
 447       s->profiling.data = profileMalloc (s);
 448       break;
 449     case PROFILE_NONE:
 450       die ("impossible PROFILE_NONE");
 451       // break;
 452     case PROFILE_TIME_FIELD:
 453     case PROFILE_TIME_LABEL:
 454       initProfilingTime (s);
 455       break;
 456     default:
 457       assert (FALSE);
 458     }
 459     atexitForProfilingState = s;
 460     atexit (atexitForProfiling);
 461   }
 462 }
 463
 464 void GC_profileDone (GC_state s) {
 465   GC_profileData p;
 466   GC_profileMasterIndex profileMasterIndex;
 467
 468   if (DEBUG_PROFILE)
 469     fprintf (stderr, "GC_profileDone ()\n");
 470   assert (s->profiling.isOn);
 471   if (PROFILE_TIME_FIELD == s->profiling.kind
 472       or PROFILE_TIME_LABEL == s->profiling.kind)
 473     setProfTimer (0);
 474   s->profiling.isOn = FALSE;
 475   p = s->profiling.data;
 476   if (s->profiling.stack) {
 477     uint32_t profileMasterLength =
 478       s->sourceMaps.sourcesLength + s->sourceMaps.sourceNamesLength;
 479     for (profileMasterIndex = 0;
 480          profileMasterIndex < profileMasterLength;
 481          profileMasterIndex++) {
 482       if (p->stack[profileMasterIndex].numOccurrences > 0) {
 483         if (DEBUG_PROFILE)
 484           fprintf (stderr, "done leaving %s\n",
 485                    profileIndexSourceName (s, profileMasterIndex));
 486         removeFromStackForProfiling (s, profileMasterIndex);
 487       }
 488     }
 489   }
 490 }
 491
 492
 493 GC_profileData GC_getProfileCurrent (GC_state s) {
 494   return s->profiling.data;
 495 }
 496 void GC_setProfileCurrent (GC_state s, GC_profileData p) {
 497   s->profiling.data = p;
 498 }