1 /* -----------------------------------------------------------------------------
2 * $Id: Stats.c,v 1.9 1999/02/23 15:45:08 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 double ElapsedTimeStart = 0.0;
82 static double TicksPerSecond = 0.0;
84 static double InitUserTime = 0.0;
85 static double InitElapsedTime = 0.0;
87 static ullong GC_tot_alloc = 0;
88 static ullong GC_tot_copied = 0;
90 static double GC_start_time, GC_tot_time = 0; /* User GC Time */
91 static double GCe_start_time, GCe_tot_time = 0; /* Elapsed GC time */
93 lnat MaxResidency = 0; /* in words; for stats only */
94 lnat ResidencySamples = 0; /* for stats only */
96 static lnat GC_start_faults = 0, GC_end_faults = 0;
98 static double *GC_coll_times;
100 /* ToDo: convert this to use integers? --SDM */
102 /* elapsedtime() -- The current elapsed time in seconds */
107 #if ! (defined(HAVE_TIMES) || defined(HAVE_FTIME))
108 /* We will #ifdef around the fprintf for machines
109 we *know* are unsupported. (WDP 94/05)
111 fprintf(stderr, "NOTE: `elapsedtime' does nothing!\n");
114 #else /* not stumped */
116 /* "ftime" may be nicer, but "times" is more standard;
117 but, on a Sun, if you do not get the SysV one, you are *hosed*...
120 # if defined(HAVE_TIMES) && ! sunos4_TARGET_OS
122 clock_t r = times(&t);
124 return (((double)r)/TicksPerSecond - ElapsedTimeStart);
126 # else /* HAVE_FTIME */
130 return (fabs(t.time + 1e-3*t.millitm - ElapsedTimeStart));
132 # endif /* HAVE_FTIME */
133 #endif /* not stumped */
139 # if !defined(HAVE_GETRUSAGE) || irix_TARGET_OS
144 getrusage(RUSAGE_SELF, &t);
149 /* ToDo: use gettimeofday on systems that support it (u-sec accuracy) */
155 /* Determine TicksPerSecond ... */
157 ticks = sysconf(_SC_CLK_TCK);
159 fprintf(stderr, "stat_init: bad call to 'sysconf'!\n");
160 stg_exit(EXIT_FAILURE);
162 TicksPerSecond = (double) ticks;
164 #else /* no "sysconf"; had better guess */
166 TicksPerSecond = (double) (HZ);
168 # else /* had better guess wildly */
169 /* We will #ifdef around the fprintf for machines
170 we *know* are unsupported. (WDP 94/05)
172 fprintf(stderr, "NOTE: Guessing `TicksPerSecond = 60'!\n");
173 TicksPerSecond = 60.0;
177 ElapsedTimeStart = elapsedtime();
185 FILE *sf = RtsFlags.GcFlags.statsFile;
187 if (RtsFlags.GcFlags.giveStats) {
188 fprintf(sf, " Alloc Collect Live GC GC TOT TOT Page Flts\n");
189 fprintf(sf, " bytes bytes bytes user elap user elap\n");
193 (double *)stgMallocBytes(sizeof(double) * RtsFlags.GcFlags.generations,
195 for (i = 0; i < RtsFlags.GcFlags.generations; i++) {
196 GC_coll_times[i] = 0.0;
204 #if ! (defined(HAVE_GETRUSAGE) || defined(HAVE_TIMES))
205 /* We will #ifdef around the fprintf for machines
206 we *know* are unsupported. (WDP 94/05)
208 fprintf(stderr, "NOTE: `usertime' does nothing!\n");
211 #else /* not stumped */
213 # if defined(HAVE_TIMES)
217 return(((double)(t.tms_utime))/TicksPerSecond);
219 #else /* HAVE_GETRUSAGE */
222 getrusage(RUSAGE_SELF, &t);
223 return(t.ru_utime.tv_sec + 1e-6*t.ru_utime.tv_usec);
225 # endif /* HAVE_GETRUSAGE */
226 #endif /* not stumped */
232 InitUserTime = usertime();
233 InitElapsedTime = elapsedtime();
234 if (InitElapsedTime < 0.0) {
235 InitElapsedTime = 0.0;
239 /* -----------------------------------------------------------------------------
240 Called at the beginning of each GC
241 -------------------------------------------------------------------------- */
243 static nat rub_bell = 0;
248 FILE *sf = RtsFlags.GcFlags.statsFile;
250 nat bell = RtsFlags.GcFlags.ringBell;
254 fprintf(stderr, " GC ");
257 fprintf(stderr, "\007");
262 GC_start_time = usertime();
263 GCe_start_time = elapsedtime();
264 if (RtsFlags.GcFlags.giveStats) {
265 GC_start_faults = pagefaults();
270 /* -----------------------------------------------------------------------------
271 Called at the end of each GC
272 -------------------------------------------------------------------------- */
275 stat_endGC(lnat alloc, lnat collect, lnat live, lnat copied, lnat gen)
277 FILE *sf = RtsFlags.GcFlags.statsFile;
280 double time = usertime();
281 double etime = elapsedtime();
283 if (RtsFlags.GcFlags.giveStats) {
284 nat faults = pagefaults();
286 fprintf(sf, "%9ld %9ld %9ld",
287 alloc*sizeof(W_), collect*sizeof(W_), live*sizeof(W_));
288 fprintf(sf, " %5.2f %5.2f %7.2f %7.2f %4ld %4ld (Gen: %2ld)\n",
289 (time-GC_start_time),
290 (etime-GCe_start_time),
293 faults - GC_start_faults,
294 GC_start_faults - GC_end_faults,
297 GC_end_faults = faults;
301 GC_coll_times[gen] += time-GC_start_time;
303 GC_tot_copied += (ullong) copied;
304 GC_tot_alloc += (ullong) alloc;
305 GC_tot_time += time-GC_start_time;
306 GCe_tot_time += etime-GCe_start_time;
308 if (gen == RtsFlags.GcFlags.generations-1) { /* major GC? */
309 if (live > MaxResidency) {
317 fprintf(stderr, "\b\b\b \b\b\b");
322 /* -----------------------------------------------------------------------------
323 Called at the end of execution
325 NOTE: number of allocations is not entirely accurate: it doesn't
326 take into account the few bytes at the end of the heap that
327 were left unused when the heap-check failed.
328 -------------------------------------------------------------------------- */
333 FILE *sf = RtsFlags.GcFlags.statsFile;
336 char temp[BIG_STRING_LEN];
337 double time = usertime();
338 double etime = elapsedtime();
339 double MutTime, MutElapsedTime;
341 /* avoid divide by zero if time is measured as 0.00 seconds -- SDM */
342 if (time == 0.0) time = 0.0001;
343 if (etime == 0.0) etime = 0.0001;
346 fprintf(sf, "%9ld %9.9s %9.9s",
347 (lnat)alloc*sizeof(W_), "", "");
348 fprintf(sf, " %5.2f %5.2f\n\n", 0.0, 0.0);
350 GC_tot_alloc += alloc;
352 ullong_format_string(GC_tot_alloc*sizeof(W_), temp, rtsTrue/*commas*/);
353 fprintf(sf, "%11s bytes allocated in the heap\n", temp);
355 ullong_format_string(GC_tot_copied*sizeof(W_), temp, rtsTrue/*commas*/);
356 fprintf(sf, "%11s bytes copied during GC\n", temp);
358 if ( ResidencySamples > 0 ) {
359 ullong_format_string(MaxResidency*sizeof(W_), temp, rtsTrue/*commas*/);
360 fprintf(sf, "%11s bytes maximum residency (%ld sample(s))\n",
366 { /* Count garbage collections */
368 for (g = 0; g < RtsFlags.GcFlags.generations; g++) {
369 fprintf(sf, "%11d collections in generation %d (%6.2fs)\n",
370 generations[g].collections, g, GC_coll_times[g]);
373 fprintf(sf,"\n%11ld Mb total memory in use\n\n",
374 mblocks_allocated * MBLOCK_SIZE / (1024 * 1024));
376 MutTime = time - GC_tot_time - InitUserTime;
377 if (MutTime < 0) { MutTime = 0; }
378 MutElapsedTime = etime - GCe_tot_time - InitElapsedTime;
379 if (MutElapsedTime < 0) { MutElapsedTime = 0; } /* sometimes -0.00 */
381 fprintf(sf, " INIT time %6.2fs (%6.2fs elapsed)\n",
382 InitUserTime, InitElapsedTime);
383 fprintf(sf, " MUT time %6.2fs (%6.2fs elapsed)\n",
384 MutTime, MutElapsedTime);
385 fprintf(sf, " GC time %6.2fs (%6.2fs elapsed)\n",
386 GC_tot_time, GCe_tot_time);
387 fprintf(sf, " Total time %6.2fs (%6.2fs elapsed)\n\n",
390 fprintf(sf, " %%GC time %5.1f%% (%.1f%% elapsed)\n\n",
391 GC_tot_time*100./time, GCe_tot_time*100./etime);
393 if (time - GC_tot_time == 0.0)
394 ullong_format_string(0, temp, rtsTrue/*commas*/);
396 ullong_format_string((ullong)(GC_tot_alloc*sizeof(W_)/
397 (time - GC_tot_time)),
398 temp, rtsTrue/*commas*/);
400 fprintf(sf, " Alloc rate %s bytes per MUT second\n\n", temp);
402 fprintf(sf, " Productivity %5.1f%% of total user, %.1f%% of total elapsed\n\n",
403 (time - GC_tot_time - InitUserTime) * 100. / time,
404 (time - GC_tot_time - InitUserTime) * 100. / etime);
410 /* -----------------------------------------------------------------------------
413 Produce some detailed info on the state of the generational GC.
414 -------------------------------------------------------------------------- */
416 stat_describe_gens(void)
418 nat g, s, mut, mut_once, lge, live;
423 fprintf(stderr, " Gen Steps Max Mutable Mut-Once Step Blocks Live Large\n Blocks Closures Closures Objects\n");
425 for (g = 0; g < RtsFlags.GcFlags.generations; g++) {
426 for (m = generations[g].mut_list, mut = 0; m != END_MUT_LIST;
429 for (m = generations[g].mut_once_list, mut_once = 0; m != END_MUT_LIST;
432 fprintf(stderr, "%8d %8d %8d %9d %9d", g, generations[g].n_steps,
433 generations[g].max_blocks, mut, mut_once);
435 for (s = 0; s < generations[g].n_steps; s++) {
436 step = &generations[g].steps[s];
437 for (bd = step->large_objects, lge = 0; bd; bd = bd->link)
440 if (RtsFlags.GcFlags.generations == 1) {
445 for (; bd; bd = bd->link) {
446 live += (bd->free - bd->start) * sizeof(W_);
449 fprintf(stderr,"%46s","");
451 fprintf(stderr,"%6d %8d %8d %8d\n", s, step->n_blocks,
455 fprintf(stderr,"\n");