1 /* -----------------------------------------------------------------------------
2 * $Id: Stats.c,v 1.6 1999/02/05 16:02:56 simonm Exp $
4 * (c) The GHC Team, 1998-1999
6 * Statistics and timing-related functions.
8 * ---------------------------------------------------------------------------*/
10 #define NON_POSIX_SOURCE
15 #include "StoragePriv.h"
19 * Ian: For the moment we just want to ignore
23 #ifdef HAVE_SYS_TIMES_H
24 #undef HAVE_SYS_TIMES_H /* <sys/times.h> */
26 #ifdef HAVE_SYS_RESOURCE_H /* <sys/resource.h> */
27 #undef HAVE_SYS_RESOURCE_H
29 #ifdef HAVE_SYS_TIME_H /* <sys/time.h> */
30 #undef HAVE_SYS_TIME_H
32 #ifdef HAVE_SYS_TIMEB_H
33 #undef HAVE_SYS_TIMEB_H /* <sys/timeb.h> */
36 #undef HAVE_UNISTD_H /* <unistd.h> */
50 #endif /* _NEMESIS_OS_ */
58 #ifdef HAVE_SYS_TIMES_H
59 #include <sys/times.h>
62 #ifdef HAVE_SYS_TIME_H
66 #if defined(HAVE_SYS_RESOURCE_H) && ! irix_TARGET_OS
67 #include <sys/resource.h>
70 #ifdef HAVE_SYS_TIMEB_H
71 #include <sys/timeb.h>
79 #define BIG_STRING_LEN 512
81 static StgDouble ElapsedTimeStart = 0.0;
82 static StgDouble TicksPerSecond = 0.0;
84 static StgDouble InitUserTime = 0.0;
85 static StgDouble InitElapsedTime = 0.0;
87 static ullong GC_tot_alloc = 0;
89 static StgDouble GC_start_time, GC_tot_time = 0; /* User GC Time */
90 static StgDouble GCe_start_time, GCe_tot_time = 0; /* Elapsed GC time */
92 lnat MaxResidency = 0; /* in words; for stats only */
93 lnat ResidencySamples = 0; /* for stats only */
95 static lnat GC_start_faults = 0, GC_end_faults = 0;
97 /* ToDo: convert this to use integers? --SDM */
99 /* elapsedtime() -- The current elapsed time in seconds */
104 #if ! (defined(HAVE_TIMES) || defined(HAVE_FTIME))
105 /* We will #ifdef around the fprintf for machines
106 we *know* are unsupported. (WDP 94/05)
108 fprintf(stderr, "NOTE: `elapsedtime' does nothing!\n");
111 #else /* not stumped */
113 /* "ftime" may be nicer, but "times" is more standard;
114 but, on a Sun, if you do not get the SysV one, you are *hosed*...
117 # if defined(HAVE_TIMES) && ! sunos4_TARGET_OS
119 clock_t r = times(&t);
121 return (((StgDouble)r)/TicksPerSecond - ElapsedTimeStart);
123 # else /* HAVE_FTIME */
127 return (fabs(t.time + 1e-3*t.millitm - ElapsedTimeStart));
129 # endif /* HAVE_FTIME */
130 #endif /* not stumped */
136 # if !defined(HAVE_GETRUSAGE) || irix_TARGET_OS
141 getrusage(RUSAGE_SELF, &t);
146 /* ToDo: use gettimeofday on systems that support it (u-sec accuracy) */
152 /* Determine TicksPerSecond ... */
154 ticks = sysconf(_SC_CLK_TCK);
156 fprintf(stderr, "stat_init: bad call to 'sysconf'!\n");
157 stg_exit(EXIT_FAILURE);
159 TicksPerSecond = (StgDouble) ticks;
161 #else /* no "sysconf"; had better guess */
163 TicksPerSecond = (StgDouble) (HZ);
165 # else /* had better guess wildly */
166 /* We will #ifdef around the fprintf for machines
167 we *know* are unsupported. (WDP 94/05)
169 fprintf(stderr, "NOTE: Guessing `TicksPerSecond = 60'!\n");
170 TicksPerSecond = 60.0;
174 ElapsedTimeStart = elapsedtime();
181 FILE *sf = RtsFlags.GcFlags.statsFile;
183 if (RtsFlags.GcFlags.giveStats) {
184 fprintf(sf, " Alloc Collect Live GC GC TOT TOT Page Flts\n");
185 fprintf(sf, " bytes bytes bytes user elap user elap\n");
193 #if ! (defined(HAVE_GETRUSAGE) || defined(HAVE_TIMES))
194 /* We will #ifdef around the fprintf for machines
195 we *know* are unsupported. (WDP 94/05)
197 fprintf(stderr, "NOTE: `usertime' does nothing!\n");
200 #else /* not stumped */
202 # if defined(HAVE_TIMES)
206 return(((StgDouble)(t.tms_utime))/TicksPerSecond);
208 #else /* HAVE_GETRUSAGE */
211 getrusage(RUSAGE_SELF, &t);
212 return(t.ru_utime.tv_sec + 1e-6*t.ru_utime.tv_usec);
214 # endif /* HAVE_GETRUSAGE */
215 #endif /* not stumped */
221 InitUserTime = usertime();
222 InitElapsedTime = elapsedtime();
223 if (InitElapsedTime < 0.0) {
224 InitElapsedTime = 0.0;
228 /* -----------------------------------------------------------------------------
229 Called at the beginning of each GC
230 -------------------------------------------------------------------------- */
232 static nat rub_bell = 0;
237 FILE *sf = RtsFlags.GcFlags.statsFile;
239 nat bell = RtsFlags.GcFlags.ringBell;
243 fprintf(stderr, " GC ");
246 fprintf(stderr, "\007");
251 GC_start_time = usertime();
252 GCe_start_time = elapsedtime();
253 if (RtsFlags.GcFlags.giveStats) {
254 GC_start_faults = pagefaults();
259 /* -----------------------------------------------------------------------------
260 Called at the end of each GC
261 -------------------------------------------------------------------------- */
264 stat_endGC(lnat alloc, lnat collect, lnat live, lnat gen)
266 FILE *sf = RtsFlags.GcFlags.statsFile;
269 StgDouble time = usertime();
270 StgDouble etime = elapsedtime();
272 if (RtsFlags.GcFlags.giveStats) {
273 nat faults = pagefaults();
275 fprintf(sf, "%9ld %9ld %9ld",
276 alloc*sizeof(W_), collect*sizeof(W_), live*sizeof(W_));
277 fprintf(sf, " %5.2f %5.2f %7.2f %7.2f %4ld %4ld (Gen: %2ld)\n",
278 (time-GC_start_time),
279 (etime-GCe_start_time),
282 faults - GC_start_faults,
283 GC_start_faults - GC_end_faults,
286 GC_end_faults = faults;
290 GC_tot_alloc += (ullong) alloc;
291 GC_tot_time += time-GC_start_time;
292 GCe_tot_time += etime-GCe_start_time;
294 if (gen == RtsFlags.GcFlags.generations-1) { /* major GC? */
295 if (live > MaxResidency) {
303 fprintf(stderr, "\b\b\b \b\b\b");
308 /* -----------------------------------------------------------------------------
309 Called at the end of execution
311 NOTE: number of allocations is not entirely accurate: it doesn't
312 take into account the few bytes at the end of the heap that
313 were left unused when the heap-check failed.
314 -------------------------------------------------------------------------- */
319 FILE *sf = RtsFlags.GcFlags.statsFile;
322 char temp[BIG_STRING_LEN];
323 StgDouble time = usertime();
324 StgDouble etime = elapsedtime();
325 StgDouble MutTime, MutElapsedTime;
327 /* avoid divide by zero if time is measured as 0.00 seconds -- SDM */
328 if (time == 0.0) time = 0.0001;
329 if (etime == 0.0) etime = 0.0001;
332 fprintf(sf, "%9ld %9.9s %9.9s",
333 (lnat)alloc*sizeof(W_), "", "");
334 fprintf(sf, " %5.2f %5.2f\n\n", 0.0, 0.0);
336 GC_tot_alloc += alloc;
338 ullong_format_string(GC_tot_alloc*sizeof(W_), temp, rtsTrue/*commas*/);
339 fprintf(sf, "%11s bytes allocated in the heap\n", temp);
341 if ( ResidencySamples > 0 ) {
342 ullong_format_string(MaxResidency*sizeof(W_), temp, rtsTrue/*commas*/);
343 fprintf(sf, "%11s bytes maximum residency (%ld sample(s))\n",
349 { /* Count garbage collections */
351 for (g = 0; g < RtsFlags.GcFlags.generations; g++) {
352 fprintf(sf, "%11d collections in generation %d\n",
353 generations[g].collections, g);
356 fprintf(sf,"\n%11ld Mb total memory in use\n\n",
357 mblocks_allocated * MBLOCK_SIZE / (1024 * 1024));
359 MutTime = time - GC_tot_time - InitUserTime;
360 if (MutTime < 0) { MutTime = 0; }
361 MutElapsedTime = etime - GCe_tot_time - InitElapsedTime;
362 if (MutElapsedTime < 0) { MutElapsedTime = 0; } /* sometimes -0.00 */
364 fprintf(sf, " INIT time %6.2fs (%6.2fs elapsed)\n",
365 InitUserTime, InitElapsedTime);
366 fprintf(sf, " MUT time %6.2fs (%6.2fs elapsed)\n",
367 MutTime, MutElapsedTime);
368 fprintf(sf, " GC time %6.2fs (%6.2fs elapsed)\n",
369 GC_tot_time, GCe_tot_time);
370 fprintf(sf, " Total time %6.2fs (%6.2fs elapsed)\n\n",
373 fprintf(sf, " %%GC time %5.1f%% (%.1f%% elapsed)\n\n",
374 GC_tot_time*100./time, GCe_tot_time*100./etime);
376 if (time - GC_tot_time == 0.0)
377 ullong_format_string(0, temp, rtsTrue/*commas*/);
379 ullong_format_string((ullong)(GC_tot_alloc*sizeof(W_)/
380 (time - GC_tot_time)),
381 temp, rtsTrue/*commas*/);
383 fprintf(sf, " Alloc rate %s bytes per MUT second\n\n", temp);
385 fprintf(sf, " Productivity %5.1f%% of total user, %.1f%% of total elapsed\n\n",
386 (time - GC_tot_time - InitUserTime) * 100. / time,
387 (time - GC_tot_time - InitUserTime) * 100. / etime);
393 /* -----------------------------------------------------------------------------
396 Produce some detailed info on the state of the generational GC.
397 -------------------------------------------------------------------------- */
399 stat_describe_gens(void)
401 nat g, s, mut, mut_once, lge, live;
406 fprintf(stderr, " Gen Steps Max Mutable Mut-Once Step Blocks Live Large\n Blocks Closures Closures Objects\n");
408 for (g = 0; g < RtsFlags.GcFlags.generations; g++) {
409 for (m = generations[g].mut_list, mut = 0; m != END_MUT_LIST;
412 for (m = generations[g].mut_once_list, mut_once = 0; m != END_MUT_LIST;
415 fprintf(stderr, "%8d %8d %8d %9d %9d", g, generations[g].n_steps,
416 generations[g].max_blocks, mut, mut_once);
418 for (s = 0; s < generations[g].n_steps; s++) {
419 step = &generations[g].steps[s];
420 for (bd = step->large_objects, lge = 0; bd; bd = bd->link)
423 for (bd = step->blocks; bd; bd = bd->link) {
424 live += (bd->free - bd->start) * sizeof(W_);
427 fprintf(stderr,"%46s","");
429 fprintf(stderr,"%6d %8d %8d %8d\n", s, step->n_blocks,
433 fprintf(stderr,"\n");