1 /* -----------------------------------------------------------------------------
2 * $Id: ProfHeap.c,v 1.48 2003/09/23 15:38:36 simonmar Exp $
4 * (c) The GHC Team, 1998-2003
6 * Support for heap profiling
8 * ---------------------------------------------------------------------------*/
10 #if defined(DEBUG) && !defined(PROFILING)
11 #define DEBUG_HEAP_PROF
13 #undef DEBUG_HEAP_PROF
16 #if defined(PROFILING) || defined(DEBUG_HEAP_PROF)
18 #include "PosixSource.h"
22 #include "Profiling.h"
28 #include "RetainerProfile.h"
29 #include "LdvProfile.h"
36 /* -----------------------------------------------------------------------------
37 * era stores the current time period. It is the same as the
38 * number of censuses that have been performed.
41 * era must be no longer than LDV_SHIFT (15 or 30) bits.
43 * era is initialized to 1 in initHeapProfiling().
45 * max_era is initialized to 2^LDV_SHIFT in initHeapProfiling().
46 * When era reaches max_era, the profiling stops because a closure can
47 * store only up to (max_era - 1) as its creation or last use time.
48 * -------------------------------------------------------------------------- */
52 /* -----------------------------------------------------------------------------
55 * For most heap profiles each closure identity gets a simple count
56 * of live words in the heap at each census. However, if we're
57 * selecting by biography, then we have to keep the various
58 * lag/drag/void counters for each identity.
59 * -------------------------------------------------------------------------- */
60 typedef struct _counter {
65 int prim; // total size of 'inherently used' closures
66 int not_used; // total size of 'never used' closures
67 int used; // total size of 'used at least once' closures
68 int void_total; // current total size of 'destroyed without being used' closures
69 int drag_total; // current total size of 'used at least once and waiting to die'
72 struct _counter *next;
76 initLDVCtr( counter *ctr )
79 ctr->c.ldv.not_used = 0;
81 ctr->c.ldv.void_total = 0;
82 ctr->c.ldv.drag_total = 0;
86 double time; // the time in MUT time when the census is made
91 // for LDV profiling, when just displaying by LDV
99 static Census *censuses = NULL;
100 static nat n_censuses = 0;
103 static void aggregateCensusInfo( void );
106 static void dumpCensus( Census *census );
108 /* -----------------------------------------------------------------------------
109 Closure Type Profiling;
111 PROBABLY TOTALLY OUT OF DATE -- ToDo (SDM)
112 -------------------------------------------------------------------------- */
114 #ifdef DEBUG_HEAP_PROF
115 static char *type_names[] = {
121 , "CONSTR_NOCAF_STATIC"
159 , "MUT_ARR_PTRS_FROZEN"
173 #endif /* DEBUG_HEAP_PROF */
175 /* -----------------------------------------------------------------------------
176 * Find the "closure identity", which is a unique pointer reresenting
177 * the band to which this closure's heap space is attributed in the
179 * ------------------------------------------------------------------------- */
181 closureIdentity( StgClosure *p )
183 switch (RtsFlags.ProfFlags.doHeapProfile) {
187 return p->header.prof.ccs;
189 return p->header.prof.ccs->cc->module;
191 return get_itbl(p)->prof.closure_desc;
193 return get_itbl(p)->prof.closure_type;
194 case HEAP_BY_RETAINER:
195 // AFAIK, the only closures in the heap which might not have a
196 // valid retainer set are DEAD_WEAK closures.
197 if (isRetainerSetFieldValid(p))
198 return retainerSetOf(p);
203 case HEAP_BY_INFOPTR:
204 return (void *)((StgClosure *)p)->header.info;
205 case HEAP_BY_CLOSURE_TYPE:
206 return type_names[get_itbl(p)->type];
210 barf("closureIdentity");
214 /* --------------------------------------------------------------------------
215 * Profiling type predicates
216 * ----------------------------------------------------------------------- */
218 static inline rtsBool
219 doingLDVProfiling( void )
221 return (RtsFlags.ProfFlags.doHeapProfile == HEAP_BY_LDV
222 || RtsFlags.ProfFlags.bioSelector != NULL);
225 static inline rtsBool
226 doingRetainerProfiling( void )
228 return (RtsFlags.ProfFlags.doHeapProfile == HEAP_BY_RETAINER
229 || RtsFlags.ProfFlags.retainerSelector != NULL);
233 // Precesses a closure 'c' being destroyed whose size is 'size'.
234 // Make sure that LDV_recordDead() is not invoked on 'inherently used' closures
235 // such as TSO; they should not be involved in computing dragNew or voidNew.
237 // Even though era is checked in both LdvCensusForDead() and
238 // LdvCensusKillAll(), we still need to make sure that era is > 0 because
239 // LDV_recordDead() may be called from elsewhere in the runtime system. E.g.,
240 // when a thunk is replaced by an indirection object.
244 LDV_recordDead( StgClosure *c, nat size )
250 if (era > 0 && closureSatisfiesConstraints(c)) {
251 size -= sizeofW(StgProfHeader);
252 if ((LDVW((c)) & LDV_STATE_MASK) == LDV_STATE_CREATE) {
253 t = (LDVW((c)) & LDV_CREATE_MASK) >> LDV_SHIFT;
255 if (RtsFlags.ProfFlags.bioSelector == NULL) {
256 censuses[t].void_total += (int)size;
257 censuses[era].void_total -= (int)size;
259 id = closureIdentity(c);
260 ctr = lookupHashTable(censuses[t].hash, (StgWord)id);
261 ASSERT( ctr != NULL );
262 ctr->c.ldv.void_total += (int)size;
263 ctr = lookupHashTable(censuses[era].hash, (StgWord)id);
265 ctr = arenaAlloc(censuses[era].arena, sizeof(counter));
267 insertHashTable(censuses[era].hash, (StgWord)id, ctr);
269 ctr->next = censuses[era].ctrs;
270 censuses[era].ctrs = ctr;
272 ctr->c.ldv.void_total -= (int)size;
276 t = LDVW((c)) & LDV_LAST_MASK;
278 if (RtsFlags.ProfFlags.bioSelector == NULL) {
279 censuses[t+1].drag_total += size;
280 censuses[era].drag_total -= size;
283 id = closureIdentity(c);
284 ctr = lookupHashTable(censuses[t+1].hash, (StgWord)id);
285 ASSERT( ctr != NULL );
286 ctr->c.ldv.drag_total += (int)size;
287 ctr = lookupHashTable(censuses[era].hash, (StgWord)id);
289 ctr = arenaAlloc(censuses[era].arena, sizeof(counter));
291 insertHashTable(censuses[era].hash, (StgWord)id, ctr);
293 ctr->next = censuses[era].ctrs;
294 censuses[era].ctrs = ctr;
296 ctr->c.ldv.drag_total -= (int)size;
304 /* --------------------------------------------------------------------------
305 * Initialize censuses[era];
306 * ----------------------------------------------------------------------- */
308 initEra(Census *census)
310 census->hash = allocHashTable();
312 census->arena = newArena();
314 census->not_used = 0;
317 census->void_total = 0;
318 census->drag_total = 0;
321 /* --------------------------------------------------------------------------
322 * Increases era by 1 and initialize census[era].
323 * Reallocates gi[] and increases its size if needed.
324 * ----------------------------------------------------------------------- */
329 if (doingLDVProfiling()) {
332 if (era == max_era) {
333 prog_belch("maximum number of censuses reached; use +RTS -i to reduce");
334 stg_exit(EXIT_FAILURE);
337 if (era == n_censuses) {
339 censuses = stgReallocBytes(censuses, sizeof(Census) * n_censuses,
345 initEra( &censuses[era] );
348 /* -----------------------------------------------------------------------------
349 * DEBUG heap profiling, by info table
350 * -------------------------------------------------------------------------- */
352 #ifdef DEBUG_HEAP_PROF
355 void initProfiling1( void )
359 void initProfiling2( void )
364 void endProfiling( void )
368 #endif /* DEBUG_HEAP_PROF */
370 /* --------------------------------------------------------------------------
371 * Initialize the heap profilier
372 * ----------------------------------------------------------------------- */
374 initHeapProfiling(void)
376 if (! RtsFlags.ProfFlags.doHeapProfile) {
381 if (doingLDVProfiling() && doingRetainerProfiling()) {
382 prog_belch("cannot mix -hb and -hr");
387 // we only count eras if we're doing LDV profiling. Otherwise era
390 if (doingLDVProfiling()) {
398 { // max_era = 2^LDV_SHIFT
401 for (p = 0; p < LDV_SHIFT; p++)
406 censuses = stgMallocBytes(sizeof(Census) * n_censuses, "initHeapProfiling");
408 initEra( &censuses[era] );
410 fprintf(hp_file, "JOB \"%s", prog_name);
415 for(count = 1; count < prog_argc; count++)
416 fprintf(hp_file, " %s", prog_argv[count]);
417 fprintf(hp_file, " +RTS ");
418 for(count = 0; count < rts_argc; count++)
419 fprintf(hp_file, "%s ", rts_argv[count]);
420 fprintf(hp_file, "\n");
422 #endif /* PROFILING */
424 fprintf(hp_file, "\"\n" );
426 fprintf(hp_file, "DATE \"%s\"\n", time_str());
428 fprintf(hp_file, "SAMPLE_UNIT \"seconds\"\n");
429 fprintf(hp_file, "VALUE_UNIT \"bytes\"\n");
431 fprintf(hp_file, "BEGIN_SAMPLE 0.00\n");
432 fprintf(hp_file, "END_SAMPLE 0.00\n");
434 #ifdef DEBUG_HEAP_PROF
435 DEBUG_LoadSymbols(prog_name);
439 if (doingRetainerProfiling()) {
440 initRetainerProfiling();
448 endHeapProfiling(void)
452 if (! RtsFlags.ProfFlags.doHeapProfile) {
457 if (doingRetainerProfiling()) {
458 endRetainerProfiling();
463 if (doingLDVProfiling()) {
466 aggregateCensusInfo();
467 for (t = 1; t < era; t++) {
468 dumpCensus( &censuses[t] );
473 seconds = mut_user_time();
474 fprintf(hp_file, "BEGIN_SAMPLE %0.2f\n", seconds);
475 fprintf(hp_file, "END_SAMPLE %0.2f\n", seconds);
483 buf_append(char *p, const char *q, char *end)
487 for (m = 0; p < end; p++, q++, m++) {
489 if (*q == '\0') { break; }
495 fprint_ccs(FILE *fp, CostCentreStack *ccs, nat max_length)
497 char buf[max_length+1], *p, *buf_end;
501 // MAIN on its own gets printed as "MAIN", otherwise we ignore MAIN.
502 if (ccs == CCS_MAIN) {
507 fprintf(fp, "(%d)", ccs->ccsID);
510 buf_end = buf + max_length + 1;
512 // keep printing components of the stack until we run out of space
513 // in the buffer. If we run out of space, end with "...".
514 for (; ccs != NULL && ccs != CCS_MAIN; ccs = ccs->prevStack) {
516 // CAF cost centres print as M.CAF, but we leave the module
517 // name out of all the others to save space.
518 if (!strcmp(ccs->cc->label,"CAF")) {
519 p += buf_append(p, ccs->cc->module, buf_end);
520 p += buf_append(p, ".CAF", buf_end);
522 if (ccs->prevStack != NULL && ccs->prevStack != CCS_MAIN) {
523 p += buf_append(p, "/", buf_end);
525 p += buf_append(p, ccs->cc->label, buf_end);
529 sprintf(buf+max_length-4, "...");
532 next_offset += written;
535 fprintf(fp, "%s", buf);
540 strMatchesSelector( char* str, char* sel )
543 // fprintf(stderr, "str_matches_selector %s %s\n", str, sel);
545 // Compare str against wherever we've got to in sel.
547 while (*p != '\0' && *sel != ',' && *sel != '\0' && *p == *sel) {
550 // Match if all of str used and have reached the end of a sel fragment.
551 if (*p == '\0' && (*sel == ',' || *sel == '\0'))
554 // No match. Advance sel to the start of the next elem.
555 while (*sel != ',' && *sel != '\0') sel++;
556 if (*sel == ',') sel++;
558 /* Run out of sel ?? */
559 if (*sel == '\0') return rtsFalse;
563 /* -----------------------------------------------------------------------------
564 * Figure out whether a closure should be counted in this census, by
565 * testing against all the specified constraints.
566 * -------------------------------------------------------------------------- */
568 closureSatisfiesConstraints( StgClosure* p )
570 #ifdef DEBUG_HEAP_PROF
575 // The CCS has a selected field to indicate whether this closure is
576 // deselected by not being mentioned in the module, CC, or CCS
578 if (!p->header.prof.ccs->selected) {
582 if (RtsFlags.ProfFlags.descrSelector) {
583 b = strMatchesSelector( (get_itbl((StgClosure *)p))->prof.closure_desc,
584 RtsFlags.ProfFlags.descrSelector );
585 if (!b) return rtsFalse;
587 if (RtsFlags.ProfFlags.typeSelector) {
588 b = strMatchesSelector( (get_itbl((StgClosure *)p))->prof.closure_type,
589 RtsFlags.ProfFlags.typeSelector );
590 if (!b) return rtsFalse;
592 if (RtsFlags.ProfFlags.retainerSelector) {
595 // We must check that the retainer set is valid here. One
596 // reason it might not be valid is if this closure is a
597 // a newly deceased weak pointer (i.e. a DEAD_WEAK), since
598 // these aren't reached by the retainer profiler's traversal.
599 if (isRetainerSetFieldValid((StgClosure *)p)) {
600 rs = retainerSetOf((StgClosure *)p);
602 for (i = 0; i < rs->num; i++) {
603 b = strMatchesSelector( rs->element[i]->cc->label,
604 RtsFlags.ProfFlags.retainerSelector );
605 if (b) return rtsTrue;
612 #endif /* PROFILING */
615 /* -----------------------------------------------------------------------------
616 * Aggregate the heap census info for biographical profiling
617 * -------------------------------------------------------------------------- */
620 aggregateCensusInfo( void )
624 counter *c, *d, *ctrs;
627 if (!doingLDVProfiling()) return;
629 // Aggregate the LDV counters when displaying by biography.
630 if (RtsFlags.ProfFlags.doHeapProfile == HEAP_BY_LDV) {
631 int void_total, drag_total;
633 // Now we compute void_total and drag_total for each census
636 for (t = 1; t < era; t++) { // note: start at 1, not 0
637 void_total += censuses[t].void_total;
638 drag_total += censuses[t].drag_total;
639 censuses[t].void_total = void_total;
640 censuses[t].drag_total = drag_total;
641 ASSERT( censuses[t].void_total <= censuses[t].not_used );
642 ASSERT( censuses[t].drag_total <= censuses[t].used );
648 // otherwise... we're doing a heap profile that is restricted to
649 // some combination of lag, drag, void or use. We've kept all the
650 // census info for all censuses so far, but we still need to
651 // aggregate the counters forwards.
654 acc = allocHashTable();
657 for (t = 1; t < era; t++) {
659 // first look through all the counters we're aggregating
660 for (c = ctrs; c != NULL; c = c->next) {
661 // if one of the totals is non-zero, then this closure
662 // type must be present in the heap at this census time...
663 d = lookupHashTable(censuses[t].hash, (StgWord)c->identity);
666 // if this closure identity isn't present in the
667 // census for this time period, then our running
668 // totals *must* be zero.
669 ASSERT(c->c.ldv.void_total == 0 && c->c.ldv.drag_total == 0);
671 // fprintCCS(stderr,c->identity);
672 // fprintf(stderr," census=%d void_total=%d drag_total=%d\n",
673 // t, c->c.ldv.void_total, c->c.ldv.drag_total);
675 d->c.ldv.void_total += c->c.ldv.void_total;
676 d->c.ldv.drag_total += c->c.ldv.drag_total;
677 c->c.ldv.void_total = d->c.ldv.void_total;
678 c->c.ldv.drag_total = d->c.ldv.drag_total;
680 ASSERT( c->c.ldv.void_total >= 0 );
681 ASSERT( c->c.ldv.drag_total >= 0 );
685 // now look through the counters in this census to find new ones
686 for (c = censuses[t].ctrs; c != NULL; c = c->next) {
687 d = lookupHashTable(acc, (StgWord)c->identity);
689 d = arenaAlloc( arena, sizeof(counter) );
691 insertHashTable( acc, (StgWord)c->identity, d );
692 d->identity = c->identity;
695 d->c.ldv.void_total = c->c.ldv.void_total;
696 d->c.ldv.drag_total = c->c.ldv.drag_total;
698 ASSERT( c->c.ldv.void_total >= 0 );
699 ASSERT( c->c.ldv.drag_total >= 0 );
703 freeHashTable(acc, NULL);
708 /* -----------------------------------------------------------------------------
709 * Print out the results of a heap census.
710 * -------------------------------------------------------------------------- */
712 dumpCensus( Census *census )
717 fprintf(hp_file, "BEGIN_SAMPLE %0.2f\n", census->time);
720 if (RtsFlags.ProfFlags.doHeapProfile == HEAP_BY_LDV) {
721 fprintf(hp_file, "VOID\t%u\n", census->void_total * sizeof(W_));
722 fprintf(hp_file, "LAG\t%u\n",
723 (census->not_used - census->void_total) * sizeof(W_));
724 fprintf(hp_file, "USE\t%u\n",
725 (census->used - census->drag_total) * sizeof(W_));
726 fprintf(hp_file, "INHERENT_USE\t%u\n",
727 census->prim * sizeof(W_));
728 fprintf(hp_file, "DRAG\t%u\n", census->drag_total *
730 fprintf(hp_file, "END_SAMPLE %0.2f\n", census->time);
735 for (ctr = census->ctrs; ctr != NULL; ctr = ctr->next) {
738 if (RtsFlags.ProfFlags.bioSelector != NULL) {
740 if (strMatchesSelector("lag", RtsFlags.ProfFlags.bioSelector))
741 count += ctr->c.ldv.not_used - ctr->c.ldv.void_total;
742 if (strMatchesSelector("drag", RtsFlags.ProfFlags.bioSelector))
743 count += ctr->c.ldv.drag_total;
744 if (strMatchesSelector("void", RtsFlags.ProfFlags.bioSelector))
745 count += ctr->c.ldv.void_total;
746 if (strMatchesSelector("use", RtsFlags.ProfFlags.bioSelector))
747 count += ctr->c.ldv.used - ctr->c.ldv.drag_total;
751 count = ctr->c.resid;
754 ASSERT( count >= 0 );
756 if (count == 0) continue;
758 #ifdef DEBUG_HEAP_PROF
759 switch (RtsFlags.ProfFlags.doHeapProfile) {
760 case HEAP_BY_INFOPTR:
761 fprintf(hp_file, "%s", lookupGHCName(ctr->identity));
763 case HEAP_BY_CLOSURE_TYPE:
764 fprintf(hp_file, "%s", (char *)ctr->identity);
770 switch (RtsFlags.ProfFlags.doHeapProfile) {
772 fprint_ccs(hp_file, (CostCentreStack *)ctr->identity, 25);
777 fprintf(hp_file, "%s", (char *)ctr->identity);
779 case HEAP_BY_RETAINER:
781 RetainerSet *rs = (RetainerSet *)ctr->identity;
783 // it might be the distinguished retainer set rs_MANY:
784 if (rs == &rs_MANY) {
785 fprintf(hp_file, "MANY");
789 // Mark this retainer set by negating its id, because it
790 // has appeared in at least one census. We print the
791 // values of all such retainer sets into the log file at
792 // the end. A retainer set may exist but not feature in
793 // any censuses if it arose as the intermediate retainer
794 // set for some closure during retainer set calculation.
798 // report in the unit of bytes: * sizeof(StgWord)
799 printRetainerSetShort(hp_file, rs);
803 barf("dumpCensus; doHeapProfile");
807 fprintf(hp_file, "\t%d\n", count * sizeof(W_));
810 fprintf(hp_file, "END_SAMPLE %0.2f\n", census->time);
813 /* -----------------------------------------------------------------------------
814 * Code to perform a heap census.
815 * -------------------------------------------------------------------------- */
817 heapCensusChain( Census *census, bdescr *bd )
827 for (; bd != NULL; bd = bd->link) {
829 // HACK: ignore pinned blocks, because they contain gaps.
830 // It's not clear exactly what we'd like to do here, since we
831 // can't tell which objects in the block are actually alive.
832 // Perhaps the whole block should be counted as SYSTEM memory.
833 if (bd->flags & BF_PINNED) {
838 while (p < bd->free) {
839 info = get_itbl((StgClosure *)p);
842 switch (info->type) {
849 case IND_OLDGEN_PERM:
851 case SE_CAF_BLACKHOLE:
856 case CONSTR_CHARLIKE:
870 size = sizeW_fromITBL(info);
875 size = bco_sizeW((StgBCO *)p);
885 size = sizeW_fromITBL(info);
888 case THUNK_1_0: /* ToDo - shouldn't be here */
889 case THUNK_0_1: /* " ditto " */
891 size = sizeofW(StgHeader) + MIN_UPD_SIZE;
896 size = pap_sizeW((StgPAP *)p);
900 size = ap_stack_sizeW((StgAP_STACK *)p);
905 size = arr_words_sizeW(stgCast(StgArrWords*,p));
909 case MUT_ARR_PTRS_FROZEN:
911 size = mut_arr_ptrs_sizeW((StgMutArrPtrs *)p);
916 #ifdef DEBUG_HEAP_PROF
917 size = tso_sizeW((StgTSO *)p);
920 if (RtsFlags.ProfFlags.includeTSOs) {
921 size = tso_sizeW((StgTSO *)p);
924 // Skip this TSO and move on to the next object
925 p += tso_sizeW((StgTSO *)p);
936 #ifdef DEBUG_HEAP_PROF
939 // subtract the profiling overhead
940 real_size = size - sizeofW(StgProfHeader);
943 if (closureSatisfiesConstraints((StgClosure*)p)) {
945 if (RtsFlags.ProfFlags.doHeapProfile == HEAP_BY_LDV) {
947 census->prim += real_size;
948 else if ((LDVW(p) & LDV_STATE_MASK) == LDV_STATE_CREATE)
949 census->not_used += real_size;
951 census->used += real_size;
955 identity = closureIdentity((StgClosure *)p);
957 if (identity != NULL) {
958 ctr = lookupHashTable( census->hash, (StgWord)identity );
961 if (RtsFlags.ProfFlags.bioSelector != NULL) {
963 ctr->c.ldv.prim += real_size;
964 else if ((LDVW(p) & LDV_STATE_MASK) == LDV_STATE_CREATE)
965 ctr->c.ldv.not_used += real_size;
967 ctr->c.ldv.used += real_size;
971 ctr->c.resid += real_size;
974 ctr = arenaAlloc( census->arena, sizeof(counter) );
976 insertHashTable( census->hash, (StgWord)identity, ctr );
977 ctr->identity = identity;
978 ctr->next = census->ctrs;
982 if (RtsFlags.ProfFlags.bioSelector != NULL) {
984 ctr->c.ldv.prim = real_size;
985 else if ((LDVW(p) & LDV_STATE_MASK) == LDV_STATE_CREATE)
986 ctr->c.ldv.not_used = real_size;
988 ctr->c.ldv.used = real_size;
992 ctr->c.resid = real_size;
1010 census = &censuses[era];
1011 census->time = mut_user_time();
1013 // calculate retainer sets if necessary
1015 if (doingRetainerProfiling()) {
1021 stat_startHeapCensus();
1024 // Traverse the heap, collecting the census info
1026 // First the small_alloc_list: we have to fix the free pointer at
1027 // the end by calling tidyAllocatedLists() first.
1028 tidyAllocateLists();
1029 heapCensusChain( census, small_alloc_list );
1031 // Now traverse the heap in each generation/step.
1032 if (RtsFlags.GcFlags.generations == 1) {
1033 heapCensusChain( census, g0s0->to_blocks );
1035 for (g = 0; g < RtsFlags.GcFlags.generations; g++) {
1036 for (s = 0; s < generations[g].n_steps; s++) {
1037 heapCensusChain( census, generations[g].steps[s].blocks );
1038 // Are we interested in large objects? might be
1039 // confusing to include the stack in a heap profile.
1040 heapCensusChain( census, generations[g].steps[s].large_objects );
1045 // dump out the census info
1047 // We can't generate any info for LDV profiling until
1048 // the end of the run...
1049 if (!doingLDVProfiling())
1050 dumpCensus( census );
1052 dumpCensus( census );
1056 // free our storage, unless we're keeping all the census info for
1057 // future restriction by biography.
1059 if (RtsFlags.ProfFlags.bioSelector == NULL)
1062 freeHashTable( census->hash, NULL/* don't free the elements */ );
1063 arenaFree( census->arena );
1064 census->hash = NULL;
1065 census->arena = NULL;
1068 // we're into the next time period now
1072 stat_endHeapCensus();
1076 #endif /* PROFILING || DEBUG_HEAP_PROF */