rts/Stats.c

   1 /* -----------------------------------------------------------------------------
   2  *
   3  * (c) The GHC Team, 1998-2005
   4  *
   5  * Statistics and timing-related functions.
   6  *
   7  * ---------------------------------------------------------------------------*/
   8
   9 #include "Rts.h"
  10 #include "RtsFlags.h"
  11 #include "RtsUtils.h"
  12 #include "MBlock.h"
  13 #include "Schedule.h"
  14 #include "Stats.h"
  15 #include "ParTicky.h"                       /* ToDo: move into Rts.h */
  16 #include "Profiling.h"
  17 #include "Storage.h"
  18 #include "GetTime.h"
  19
  20 /* huh? */
  21 #define BIG_STRING_LEN              512
  22
  23 #define TICK_TO_DBL(t) ((double)(t) / TICKS_PER_SECOND)
  24
  25 static Ticks ElapsedTimeStart = 0;
  26
  27 static Ticks InitUserTime     = 0;
  28 static Ticks InitElapsedTime  = 0;
  29 static Ticks InitElapsedStamp = 0;
  30
  31 static Ticks MutUserTime      = 0;
  32 static Ticks MutElapsedTime   = 0;
  33 static Ticks MutElapsedStamp  = 0;
  34
  35 static Ticks ExitUserTime     = 0;
  36 static Ticks ExitElapsedTime  = 0;
  37
  38 static ullong GC_tot_alloc        = 0;
  39 static ullong GC_tot_copied       = 0;
  40 static ullong GC_tot_scavd_copied = 0;
  41
  42 static Ticks GC_start_time = 0,  GC_tot_time  = 0;  /* User GC Time */
  43 static Ticks GCe_start_time = 0, GCe_tot_time = 0;  /* Elapsed GC time */
  44
  45 #ifdef PROFILING
  46 static Ticks RP_start_time  = 0, RP_tot_time  = 0;  /* retainer prof user time */
  47 static Ticks RPe_start_time = 0, RPe_tot_time = 0;  /* retainer prof elap time */
  48
  49 static Ticks HC_start_time, HC_tot_time = 0;     // heap census prof user time
  50 static Ticks HCe_start_time, HCe_tot_time = 0;   // heap census prof elap time
  51 #endif
  52
  53 #ifdef PROFILING
  54 #define PROF_VAL(x)   (x)
  55 #else
  56 #define PROF_VAL(x)   0
  57 #endif
  58
  59 static lnat MaxResidency = 0;     // in words; for stats only
  60 static lnat AvgResidency = 0;
  61 static lnat ResidencySamples = 0; // for stats only
  62
  63 static lnat GC_start_faults = 0, GC_end_faults = 0;
  64
  65 static Ticks *GC_coll_times;
  66
  67 static void statsPrintf( char *s, ... )
  68     GNUC3_ATTRIBUTE(format (printf, 1, 2));
  69
  70 static void statsFlush( void );
  71 static void statsClose( void );
  72
  73 Ticks stat_getElapsedGCTime(void)
  74 {
  75     return GCe_tot_time;
  76 }
  77
  78 Ticks stat_getElapsedTime(void)
  79 {
  80     return getProcessElapsedTime() - ElapsedTimeStart;
  81 }
  82
  83 /* mut_user_time_during_GC() and mut_user_time()
  84  *
  85  * The former function can be used to get the current mutator time
  86  * *during* a GC, i.e. between stat_startGC and stat_endGC.  This is
  87  * used in the heap profiler for accurately time stamping the heap
  88  * sample.
  89  *
  90  * ATTENTION: mut_user_time_during_GC() relies on GC_start_time being
  91  *            defined in stat_startGC() - to minimise system calls,
  92  *            GC_start_time is, however, only defined when really needed (check
  93  *            stat_startGC() for details)
  94  */
  95 double
  96 mut_user_time_during_GC( void )
  97 {
  98   return TICK_TO_DBL(GC_start_time - GC_tot_time - PROF_VAL(RP_tot_time + HC_tot_time));
  99 }
 100
 101 double
 102 mut_user_time( void )
 103 {
 104     Ticks user;
 105     user = getProcessCPUTime();
 106     return TICK_TO_DBL(user - GC_tot_time - PROF_VAL(RP_tot_time + HC_tot_time));
 107 }
 108
 109 #ifdef PROFILING
 110 /*
 111   mut_user_time_during_RP() is similar to mut_user_time_during_GC();
 112   it returns the MUT time during retainer profiling.
 113   The same is for mut_user_time_during_HC();
 114  */
 115 double
 116 mut_user_time_during_RP( void )
 117 {
 118   return TICK_TO_DBL(RP_start_time - GC_tot_time - RP_tot_time - HC_tot_time);
 119 }
 120
 121 double
 122 mut_user_time_during_heap_census( void )
 123 {
 124   return TICK_TO_DBL(HC_start_time - GC_tot_time - RP_tot_time - HC_tot_time);
 125 }
 126 #endif /* PROFILING */
 127
 128 void
 129 initStats(void)
 130 {
 131     nat i;
 132
 133     if (RtsFlags.GcFlags.giveStats >= VERBOSE_GC_STATS) {
 134         statsPrintf("    Alloc    Copied     Live    GC    GC     TOT     TOT  Page Flts\n");
 135         statsPrintf("    bytes     bytes     bytes  user  elap    user    elap\n");
 136     }
 137     GC_coll_times =
 138         (Ticks *)stgMallocBytes(
 139             sizeof(Ticks)*RtsFlags.GcFlags.generations,
 140             "initStats");
 141     for (i = 0; i < RtsFlags.GcFlags.generations; i++) {
 142         GC_coll_times[i] = 0;
 143     }
 144 }
 145
 146 /* -----------------------------------------------------------------------------
 147    Initialisation time...
 148    -------------------------------------------------------------------------- */
 149
 150 void
 151 stat_startInit(void)
 152 {
 153     Ticks elapsed;
 154
 155     elapsed = getProcessElapsedTime();
 156     ElapsedTimeStart = elapsed;
 157 }
 158
 159 void
 160 stat_endInit(void)
 161 {
 162     Ticks user, elapsed;
 163
 164     getProcessTimes(&user, &elapsed);
 165
 166     InitUserTime = user;
 167     InitElapsedStamp = elapsed;
 168     if (ElapsedTimeStart > elapsed) {
 169         InitElapsedTime = 0;
 170     } else {
 171         InitElapsedTime = elapsed - ElapsedTimeStart;
 172     }
 173 }
 174
 175 /* -----------------------------------------------------------------------------
 176    stat_startExit and stat_endExit
 177
 178    These two measure the time taken in shutdownHaskell().
 179    -------------------------------------------------------------------------- */
 180
 181 void
 182 stat_startExit(void)
 183 {
 184     Ticks user, elapsed;
 185
 186     getProcessTimes(&user, &elapsed);
 187
 188     MutElapsedStamp = elapsed;
 189     MutElapsedTime = elapsed - GCe_tot_time -
 190         PROF_VAL(RPe_tot_time + HCe_tot_time) - InitElapsedStamp;
 191     if (MutElapsedTime < 0) { MutElapsedTime = 0; }     /* sometimes -0.00 */
 192
 193     MutUserTime = user - GC_tot_time - PROF_VAL(RP_tot_time + HC_tot_time) - InitUserTime;
 194     if (MutUserTime < 0) { MutUserTime = 0; }
 195 }
 196
 197 void
 198 stat_endExit(void)
 199 {
 200     Ticks user, elapsed;
 201
 202     getProcessTimes(&user, &elapsed);
 203
 204     ExitUserTime = user - MutUserTime - GC_tot_time - PROF_VAL(RP_tot_time + HC_tot_time) - InitUserTime;
 205     ExitElapsedTime = elapsed - MutElapsedStamp;
 206     if (ExitUserTime < 0) {
 207         ExitUserTime = 0;
 208     }
 209     if (ExitElapsedTime < 0) {
 210         ExitElapsedTime = 0;
 211     }
 212 }
 213
 214 /* -----------------------------------------------------------------------------
 215    Called at the beginning of each GC
 216    -------------------------------------------------------------------------- */
 217
 218 static nat rub_bell = 0;
 219
 220 /*  initialise global variables needed during GC
 221  *
 222  *  * GC_start_time is read in mut_user_time_during_GC(), which in turn is
 223  *    needed if either PROFILING or DEBUGing is enabled
 224  */
 225 void
 226 stat_startGC(void)
 227 {
 228     nat bell = RtsFlags.GcFlags.ringBell;
 229
 230     if (bell) {
 231         if (bell > 1) {
 232             debugBelch(" GC ");
 233             rub_bell = 1;
 234         } else {
 235             debugBelch("\007");
 236         }
 237     }
 238
 239 #if defined(PROFILING) || defined(DEBUG)
 240     GC_start_time = getProcessCPUTime();  // needed in mut_user_time_during_GC()
 241 #endif
 242
 243     if (RtsFlags.GcFlags.giveStats != NO_GC_STATS) {
 244 #if !defined(PROFILING) && !defined(DEBUG)
 245         GC_start_time = getProcessCPUTime();
 246 #endif
 247         GCe_start_time = getProcessElapsedTime();
 248         if (RtsFlags.GcFlags.giveStats) {
 249             GC_start_faults = getPageFaults();
 250         }
 251     }
 252 }
 253
 254 /* -----------------------------------------------------------------------------
 255    Called at the end of each GC
 256    -------------------------------------------------------------------------- */
 257
 258 void
 259 stat_endGC (lnat alloc, lnat live, lnat copied,
 260             lnat scavd_copied, lnat gen)
 261 {
 262     if (RtsFlags.GcFlags.giveStats != NO_GC_STATS) {
 263         Ticks time, etime, gc_time, gc_etime;
 264
 265         getProcessTimes(&time, &etime);
 266         gc_time  = time - GC_start_time;
 267         gc_etime = etime - GCe_start_time;
 268
 269         if (RtsFlags.GcFlags.giveStats == VERBOSE_GC_STATS) {
 270             nat faults = getPageFaults();
 271
 272             statsPrintf("%9ld %9ld %9ld",
 273                     alloc*sizeof(W_), (copied+scavd_copied)*sizeof(W_),
 274                         live*sizeof(W_));
 275             statsPrintf(" %5.2f %5.2f %7.2f %7.2f %4ld %4ld  (Gen: %2ld)\n",
 276                     TICK_TO_DBL(gc_time),
 277                     TICK_TO_DBL(gc_etime),
 278                     TICK_TO_DBL(time),
 279                     TICK_TO_DBL(etime - ElapsedTimeStart),
 280                     faults - GC_start_faults,
 281                     GC_start_faults - GC_end_faults,
 282                     gen);
 283
 284             GC_end_faults = faults;
 285             statsFlush();
 286         }
 287
 288         GC_coll_times[gen] += gc_time;
 289
 290         GC_tot_copied += (ullong) copied;
 291         GC_tot_scavd_copied += (ullong) scavd_copied;
 292         GC_tot_alloc  += (ullong) alloc;
 293         GC_tot_time   += gc_time;
 294         GCe_tot_time  += gc_etime;
 295
 296 #if defined(THREADED_RTS)
 297         {
 298             Task *task;
 299             if ((task = myTask()) != NULL) {
 300                 task->gc_time += gc_time;
 301                 task->gc_etime += gc_etime;
 302             }
 303         }
 304 #endif
 305
 306         if (gen == RtsFlags.GcFlags.generations-1) { /* major GC? */
 307             if (live > MaxResidency) {
 308                 MaxResidency = live;
 309             }
 310             ResidencySamples++;
 311             AvgResidency += live;
 312         }
 313     }
 314
 315     if (rub_bell) {
 316         debugBelch("\b\b\b  \b\b\b");
 317         rub_bell = 0;
 318     }
 319 }
 320
 321 /* -----------------------------------------------------------------------------
 322    Called at the beginning of each Retainer Profiliing
 323    -------------------------------------------------------------------------- */
 324 #ifdef PROFILING
 325 void
 326 stat_startRP(void)
 327 {
 328     Ticks user, elapsed;
 329     getProcessTimes( &user, &elapsed );
 330
 331     RP_start_time = user;
 332     RPe_start_time = elapsed;
 333 }
 334 #endif /* PROFILING */
 335
 336 /* -----------------------------------------------------------------------------
 337    Called at the end of each Retainer Profiliing
 338    -------------------------------------------------------------------------- */
 339
 340 #ifdef PROFILING
 341 void
 342 stat_endRP(
 343   nat retainerGeneration,
 344 #ifdef DEBUG_RETAINER
 345   nat maxCStackSize,
 346   int maxStackSize,
 347 #endif
 348   double averageNumVisit)
 349 {
 350     Ticks user, elapsed;
 351     getProcessTimes( &user, &elapsed );
 352
 353     RP_tot_time += user - RP_start_time;
 354     RPe_tot_time += elapsed - RPe_start_time;
 355
 356   fprintf(prof_file, "Retainer Profiling: %d, at %f seconds\n",
 357     retainerGeneration, mut_user_time_during_RP());
 358 #ifdef DEBUG_RETAINER
 359   fprintf(prof_file, "\tMax C stack size = %u\n", maxCStackSize);
 360   fprintf(prof_file, "\tMax auxiliary stack size = %u\n", maxStackSize);
 361 #endif
 362   fprintf(prof_file, "\tAverage number of visits per object = %f\n", averageNumVisit);
 363 }
 364 #endif /* PROFILING */
 365
 366 /* -----------------------------------------------------------------------------
 367    Called at the beginning of each heap census
 368    -------------------------------------------------------------------------- */
 369 #ifdef PROFILING
 370 void
 371 stat_startHeapCensus(void)
 372 {
 373     Ticks user, elapsed;
 374     getProcessTimes( &user, &elapsed );
 375
 376     HC_start_time = user;
 377     HCe_start_time = elapsed;
 378 }
 379 #endif /* PROFILING */
 380
 381 /* -----------------------------------------------------------------------------
 382    Called at the end of each heap census
 383    -------------------------------------------------------------------------- */
 384 #ifdef PROFILING
 385 void
 386 stat_endHeapCensus(void)
 387 {
 388     Ticks user, elapsed;
 389     getProcessTimes( &user, &elapsed );
 390
 391     HC_tot_time += user - HC_start_time;
 392     HCe_tot_time += elapsed - HCe_start_time;
 393 }
 394 #endif /* PROFILING */
 395
 396 /* -----------------------------------------------------------------------------
 397    Called at the end of execution
 398
 399    NOTE: number of allocations is not entirely accurate: it doesn't
 400    take into account the few bytes at the end of the heap that
 401    were left unused when the heap-check failed.
 402    -------------------------------------------------------------------------- */
 403
 404 void
 405 stat_exit(int alloc)
 406 {
 407     if (RtsFlags.GcFlags.giveStats != NO_GC_STATS) {
 408
 409         char temp[BIG_STRING_LEN];
 410         Ticks time;
 411         Ticks etime;
 412         nat g, total_collections = 0;
 413
 414         getProcessTimes( &time, &etime );
 415         etime -= ElapsedTimeStart;
 416
 417         GC_tot_alloc += alloc;
 418
 419         /* Count total garbage collections */
 420         for (g = 0; g < RtsFlags.GcFlags.generations; g++)
 421             total_collections += generations[g].collections;
 422
 423         /* avoid divide by zero if time is measured as 0.00 seconds -- SDM */
 424         if (time  == 0.0)  time = 1;
 425         if (etime == 0.0) etime = 1;
 426
 427         if (RtsFlags.GcFlags.giveStats >= VERBOSE_GC_STATS) {
 428             statsPrintf("%9ld %9.9s %9.9s", (lnat)alloc*sizeof(W_), "", "");
 429             statsPrintf(" %5.2f %5.2f\n\n", 0.0, 0.0);
 430         }
 431
 432         if (RtsFlags.GcFlags.giveStats >= SUMMARY_GC_STATS) {
 433             ullong_format_string(GC_tot_alloc*sizeof(W_),
 434                                  temp, rtsTrue/*commas*/);
 435             statsPrintf("%11s bytes allocated in the heap\n", temp);
 436
 437             ullong_format_string(GC_tot_copied*sizeof(W_),
 438                                  temp, rtsTrue/*commas*/);
 439             statsPrintf("%11s bytes copied during GC (scavenged)\n", temp);
 440
 441             ullong_format_string(GC_tot_scavd_copied*sizeof(W_),
 442                                  temp, rtsTrue/*commas*/);
 443             statsPrintf("%11s bytes copied during GC (not scavenged)\n", temp);
 444
 445             if ( ResidencySamples > 0 ) {
 446                 ullong_format_string(MaxResidency*sizeof(W_),
 447                                      temp, rtsTrue/*commas*/);
 448                 statsPrintf("%11s bytes maximum residency (%ld sample(s))\n",
 449                         temp, ResidencySamples);
 450             }
 451             statsPrintf("\n");
 452
 453             /* Print garbage collections in each gen */
 454             for (g = 0; g < RtsFlags.GcFlags.generations; g++) {
 455                 statsPrintf("%11d collections in generation %d (%6.2fs)\n",
 456                         generations[g].collections, g,
 457                         TICK_TO_DBL(GC_coll_times[g]));
 458             }
 459
 460             statsPrintf("\n%11ld Mb total memory in use\n\n",
 461                     mblocks_allocated * MBLOCK_SIZE / (1024 * 1024));
 462
 463 #if defined(THREADED_RTS)
 464             {
 465                 nat i;
 466                 Task *task;
 467                 for (i = 0, task = all_tasks;
 468                      task != NULL;
 469                      i++, task = task->all_link) {
 470                     statsPrintf("  Task %2d %-8s :  MUT time: %6.2fs  (%6.2fs elapsed)\n"
 471                             "                      GC  time: %6.2fs  (%6.2fs elapsed)\n\n",
 472                                 i,
 473                                 (task->tso == NULL) ? "(worker)" : "(bound)",
 474                                 TICK_TO_DBL(task->mut_time),
 475                                 TICK_TO_DBL(task->mut_etime),
 476                                 TICK_TO_DBL(task->gc_time),
 477                                 TICK_TO_DBL(task->gc_etime));
 478                 }
 479             }
 480 #endif
 481
 482             statsPrintf("  INIT  time  %6.2fs  (%6.2fs elapsed)\n",
 483                     TICK_TO_DBL(InitUserTime), TICK_TO_DBL(InitElapsedTime));
 484             statsPrintf("  MUT   time  %6.2fs  (%6.2fs elapsed)\n",
 485                     TICK_TO_DBL(MutUserTime), TICK_TO_DBL(MutElapsedTime));
 486             statsPrintf("  GC    time  %6.2fs  (%6.2fs elapsed)\n",
 487                     TICK_TO_DBL(GC_tot_time), TICK_TO_DBL(GCe_tot_time));
 488 #ifdef PROFILING
 489             statsPrintf("  RP    time  %6.2fs  (%6.2fs elapsed)\n",
 490                     TICK_TO_DBL(RP_tot_time), TICK_TO_DBL(RPe_tot_time));
 491             statsPrintf("  PROF  time  %6.2fs  (%6.2fs elapsed)\n",
 492                     TICK_TO_DBL(HC_tot_time), TICK_TO_DBL(HCe_tot_time));
 493 #endif
 494             statsPrintf("  EXIT  time  %6.2fs  (%6.2fs elapsed)\n",
 495                     TICK_TO_DBL(ExitUserTime), TICK_TO_DBL(ExitElapsedTime));
 496             statsPrintf("  Total time  %6.2fs  (%6.2fs elapsed)\n\n",
 497                     TICK_TO_DBL(time), TICK_TO_DBL(etime));
 498             statsPrintf("  %%GC time     %5.1f%%  (%.1f%% elapsed)\n\n",
 499                     TICK_TO_DBL(GC_tot_time)*100/TICK_TO_DBL(time),
 500                     TICK_TO_DBL(GCe_tot_time)*100/TICK_TO_DBL(etime));
 501
 502             if (time - GC_tot_time - PROF_VAL(RP_tot_time + HC_tot_time) == 0)
 503                 ullong_format_string(0, temp, rtsTrue/*commas*/);
 504             else
 505                 ullong_format_string(
 506                     (ullong)((GC_tot_alloc*sizeof(W_))/
 507                              TICK_TO_DBL(time - GC_tot_time -
 508                                          PROF_VAL(RP_tot_time + HC_tot_time))),
 509                     temp, rtsTrue/*commas*/);
 510
 511             statsPrintf("  Alloc rate    %s bytes per MUT second\n\n", temp);
 512
 513             statsPrintf("  Productivity %5.1f%% of total user, %.1f%% of total elapsed\n\n",
 514                     TICK_TO_DBL(time - GC_tot_time -
 515                                 PROF_VAL(RP_tot_time + HC_tot_time) - InitUserTime) * 100
 516                     / TICK_TO_DBL(time),
 517                     TICK_TO_DBL(time - GC_tot_time -
 518                                 PROF_VAL(RP_tot_time + HC_tot_time) - InitUserTime) * 100
 519                     / TICK_TO_DBL(etime));
 520         }
 521
 522         if (RtsFlags.GcFlags.giveStats == ONELINE_GC_STATS) {
 523           /* print the long long separately to avoid bugginess on mingwin (2001-07-02, mingw-0.5) */
 524           statsPrintf("<<ghc: %llu bytes, ", GC_tot_alloc*(ullong)sizeof(W_));
 525           statsPrintf("%d GCs, %ld/%ld avg/max bytes residency (%ld samples), %luM in use, %.2f INIT (%.2f elapsed), %.2f MUT (%.2f elapsed), %.2f GC (%.2f elapsed) :ghc>>\n",
 526                     total_collections,
 527                     ResidencySamples == 0 ? 0 :
 528                         AvgResidency*sizeof(W_)/ResidencySamples,
 529                     MaxResidency*sizeof(W_),
 530                     ResidencySamples,
 531                     (unsigned long)(mblocks_allocated * MBLOCK_SIZE / (1024L * 1024L)),
 532                     TICK_TO_DBL(InitUserTime), TICK_TO_DBL(InitElapsedTime),
 533                     TICK_TO_DBL(MutUserTime), TICK_TO_DBL(MutElapsedTime),
 534                     TICK_TO_DBL(GC_tot_time), TICK_TO_DBL(GCe_tot_time));
 535         }
 536
 537         statsFlush();
 538         statsClose();
 539     }
 540     if (GC_coll_times)
 541       stgFree(GC_coll_times);
 542     GC_coll_times = NULL;
 543 }
 544
 545 /* -----------------------------------------------------------------------------
 546    stat_describe_gens
 547
 548    Produce some detailed info on the state of the generational GC.
 549    -------------------------------------------------------------------------- */
 550 #ifdef DEBUG
 551 void
 552 statDescribeGens(void)
 553 {
 554   nat g, s, mut, lge;
 555   lnat live;
 556   bdescr *bd;
 557   step *step;
 558
 559   debugBelch(
 560 "     Gen    Steps      Max   Mutable  Step   Blocks     Live    Large\n"
 561 "                     Blocks Closures                          Objects\n");
 562
 563   mut = 0;
 564   for (g = 0; g < RtsFlags.GcFlags.generations; g++) {
 565       for (bd = generations[g].mut_list; bd != NULL; bd = bd->link) {
 566           mut += bd->free - bd->start;
 567       }
 568
 569     debugBelch("%8d %8d %8d %9d", g, generations[g].n_steps,
 570             generations[g].max_blocks, mut);
 571
 572     for (s = 0; s < generations[g].n_steps; s++) {
 573       step = &generations[g].steps[s];
 574       live = 0;
 575       for (bd = step->large_objects, lge = 0; bd; bd = bd->link) {
 576         lge++;
 577       }
 578       live = step->n_large_blocks * BLOCK_SIZE;
 579       bd = step->blocks;
 580       // This live figure will be slightly less that the "live" figure
 581       // given by +RTS -Sstderr, because we take don't count the
 582       // slop at the end of each block.
 583       for (; bd; bd = bd->link) {
 584         live += (bd->free - bd->start) * sizeof(W_);
 585       }
 586       if (s != 0) {
 587         debugBelch("%36s","");
 588       }
 589       debugBelch("%6d %8d %8ld %8d\n", s, step->n_blocks,
 590               live, lge);
 591     }
 592   }
 593   debugBelch("\n");
 594 }
 595 #endif
 596
 597 /* -----------------------------------------------------------------------------
 598    Stats available via a programmatic interface, so eg. GHCi can time
 599    each compilation and expression evaluation.
 600    -------------------------------------------------------------------------- */
 601
 602 extern HsInt64 getAllocations( void )
 603 { return (HsInt64)total_allocated * sizeof(W_); }
 604
 605 /* -----------------------------------------------------------------------------
 606    Dumping stuff in the stats file, or via the debug message interface
 607    -------------------------------------------------------------------------- */
 608
 609 static void
 610 statsPrintf( char *s, ... )
 611 {
 612     FILE *sf = RtsFlags.GcFlags.statsFile;
 613     va_list ap;
 614
 615     va_start(ap,s);
 616     if (sf == NULL) {
 617         vdebugBelch(s,ap);
 618     } else {
 619         vfprintf(sf, s, ap);
 620     }
 621     va_end(ap);
 622 }
 623
 624 static void
 625 statsFlush( void )
 626 {
 627     FILE *sf = RtsFlags.GcFlags.statsFile;
 628     if (sf != NULL) {
 629         fflush(sf);
 630     }
 631 }
 632
 633 static void
 634 statsClose( void )
 635 {
 636     FILE *sf = RtsFlags.GcFlags.statsFile;
 637     if (sf != NULL) {
 638         fclose(sf);
 639     }
 640 }