1 /* -----------------------------------------------------------------------------
2 * $Id: Stats.c,v 1.3 1999/01/13 17:25:46 simonm Exp $
4 * Statistics and timing-related functions.
6 * ---------------------------------------------------------------------------*/
8 #define NON_POSIX_SOURCE
13 #include "StoragePriv.h"
17 * Ian: For the moment we just want to ignore
21 #ifdef HAVE_SYS_TIMES_H
22 #undef HAVE_SYS_TIMES_H /* <sys/times.h> */
24 #ifdef HAVE_SYS_RESOURCE_H /* <sys/resource.h> */
25 #undef HAVE_SYS_RESOURCE_H
27 #ifdef HAVE_SYS_TIME_H /* <sys/time.h> */
28 #undef HAVE_SYS_TIME_H
30 #ifdef HAVE_SYS_TIMEB_H
31 #undef HAVE_SYS_TIMEB_H /* <sys/timeb.h> */
34 #undef HAVE_UNISTD_H /* <unistd.h> */
48 #endif /* _NEMESIS_OS_ */
56 #ifdef HAVE_SYS_TIMES_H
57 #include <sys/times.h>
60 #ifdef HAVE_SYS_TIME_H
64 #if defined(HAVE_SYS_RESOURCE_H) && ! irix_TARGET_OS
65 #include <sys/resource.h>
68 #ifdef HAVE_SYS_TIMEB_H
69 #include <sys/timeb.h>
77 #define BIG_STRING_LEN 512
79 static StgDouble ElapsedTimeStart = 0.0;
80 static StgDouble TicksPerSecond = 0.0;
82 static StgDouble InitUserTime = 0.0;
83 static StgDouble InitElapsedTime = 0.0;
85 static ullong GC_tot_alloc = 0;
87 static StgDouble GC_start_time, GC_tot_time = 0; /* User GC Time */
88 static StgDouble GCe_start_time, GCe_tot_time = 0; /* Elapsed GC time */
90 lnat MaxResidency = 0; /* in words; for stats only */
91 lnat ResidencySamples = 0; /* for stats only */
93 static lnat GC_start_faults = 0, GC_end_faults = 0;
95 /* ToDo: convert this to use integers? --SDM */
97 /* elapsedtime() -- The current elapsed time in seconds */
102 #if ! (defined(HAVE_TIMES) || defined(HAVE_FTIME))
103 /* We will #ifdef around the fprintf for machines
104 we *know* are unsupported. (WDP 94/05)
106 fprintf(stderr, "NOTE: `elapsedtime' does nothing!\n");
109 #else /* not stumped */
111 /* "ftime" may be nicer, but "times" is more standard;
112 but, on a Sun, if you do not get the SysV one, you are *hosed*...
115 # if defined(HAVE_TIMES) && ! sunos4_TARGET_OS
117 clock_t r = times(&t);
119 return (((StgDouble)r)/TicksPerSecond - ElapsedTimeStart);
121 # else /* HAVE_FTIME */
125 return (fabs(t.time + 1e-3*t.millitm - ElapsedTimeStart));
127 # endif /* HAVE_FTIME */
128 #endif /* not stumped */
134 # if !defined(HAVE_GETRUSAGE) || irix_TARGET_OS
139 getrusage(RUSAGE_SELF, &t);
144 /* ToDo: use gettimeofday on systems that support it (u-sec accuracy) */
150 /* Determine TicksPerSecond ... */
152 ticks = sysconf(_SC_CLK_TCK);
154 fprintf(stderr, "stat_init: bad call to 'sysconf'!\n");
155 stg_exit(EXIT_FAILURE);
157 TicksPerSecond = (StgDouble) ticks;
159 #else /* no "sysconf"; had better guess */
161 TicksPerSecond = (StgDouble) (HZ);
163 # else /* had better guess wildly */
164 /* We will #ifdef around the fprintf for machines
165 we *know* are unsupported. (WDP 94/05)
167 fprintf(stderr, "NOTE: Guessing `TicksPerSecond = 60'!\n");
168 TicksPerSecond = 60.0;
172 ElapsedTimeStart = elapsedtime();
179 FILE *sf = RtsFlags.GcFlags.statsFile;
181 if (RtsFlags.GcFlags.giveStats) {
182 fprintf(sf, " Alloc Collect Live GC GC TOT TOT Page Flts\n");
183 fprintf(sf, " bytes bytes bytes user elap user elap\n");
191 #if ! (defined(HAVE_GETRUSAGE) || defined(HAVE_TIMES))
192 /* We will #ifdef around the fprintf for machines
193 we *know* are unsupported. (WDP 94/05)
195 fprintf(stderr, "NOTE: `usertime' does nothing!\n");
198 #else /* not stumped */
200 # if defined(HAVE_TIMES)
204 return(((StgDouble)(t.tms_utime))/TicksPerSecond);
206 #else /* HAVE_GETRUSAGE */
209 getrusage(RUSAGE_SELF, &t);
210 return(t.ru_utime.tv_sec + 1e-6*t.ru_utime.tv_usec);
212 # endif /* HAVE_GETRUSAGE */
213 #endif /* not stumped */
219 InitUserTime = usertime();
220 InitElapsedTime = elapsedtime();
221 if (InitElapsedTime < 0.0) {
222 InitElapsedTime = 0.0;
226 /* -----------------------------------------------------------------------------
227 Called at the beginning of each GC
228 -------------------------------------------------------------------------- */
230 static nat rub_bell = 0;
235 FILE *sf = RtsFlags.GcFlags.statsFile;
237 nat bell = RtsFlags.GcFlags.ringBell;
241 fprintf(stderr, " GC ");
244 fprintf(stderr, "\007");
249 GC_start_time = usertime();
250 GCe_start_time = elapsedtime();
251 if (RtsFlags.GcFlags.giveStats) {
252 GC_start_faults = pagefaults();
257 /* -----------------------------------------------------------------------------
258 Called at the end of each GC
259 -------------------------------------------------------------------------- */
262 stat_endGC(lnat alloc, lnat collect, lnat live, lnat gen)
264 FILE *sf = RtsFlags.GcFlags.statsFile;
267 StgDouble time = usertime();
268 StgDouble etime = elapsedtime();
270 if (RtsFlags.GcFlags.giveStats) {
271 nat faults = pagefaults();
273 fprintf(sf, "%9ld %9ld %9ld",
274 alloc*sizeof(W_), collect*sizeof(W_), live*sizeof(W_));
275 fprintf(sf, " %5.2f %5.2f %7.2f %7.2f %4ld %4ld (Gen: %2ld)\n",
276 (time-GC_start_time),
277 (etime-GCe_start_time),
280 faults - GC_start_faults,
281 GC_start_faults - GC_end_faults,
284 GC_end_faults = faults;
288 GC_tot_alloc += (ullong) alloc;
289 GC_tot_time += time-GC_start_time;
290 GCe_tot_time += etime-GCe_start_time;
292 if (gen == RtsFlags.GcFlags.generations-1) { /* major GC? */
293 if (live > MaxResidency) {
301 fprintf(stderr, "\b\b\b \b\b\b");
306 /* -----------------------------------------------------------------------------
307 Called at the end of execution
309 NOTE: number of allocations is not entirely accurate: it doesn't
310 take into account the few bytes at the end of the heap that
311 were left unused when the heap-check failed.
312 -------------------------------------------------------------------------- */
317 FILE *sf = RtsFlags.GcFlags.statsFile;
320 char temp[BIG_STRING_LEN];
321 StgDouble time = usertime();
322 StgDouble etime = elapsedtime();
323 StgDouble MutTime, MutElapsedTime;
325 /* avoid divide by zero if time is measured as 0.00 seconds -- SDM */
326 if (time == 0.0) time = 0.0001;
327 if (etime == 0.0) etime = 0.0001;
330 fprintf(sf, "%9ld %9.9s %9.9s",
331 (lnat)alloc*sizeof(W_), "", "");
332 fprintf(sf, " %5.2f %5.2f\n\n", 0.0, 0.0);
334 GC_tot_alloc += alloc;
336 ullong_format_string(GC_tot_alloc*sizeof(W_), temp, rtsTrue/*commas*/);
337 fprintf(sf, "%11s bytes allocated in the heap\n", temp);
339 if ( ResidencySamples > 0 ) {
340 ullong_format_string(MaxResidency*sizeof(W_), temp, rtsTrue/*commas*/);
341 fprintf(sf, "%11s bytes maximum residency (%ld sample(s))\n",
347 { /* Count garbage collections */
349 for (g = 0; g < RtsFlags.GcFlags.generations; g++) {
350 fprintf(sf, "%11d collections in generation %d\n",
351 generations[g].collections, g);
354 fprintf(sf,"\n%11ld Mb total memory in use\n\n",
355 mblocks_allocated * MBLOCK_SIZE / (1024 * 1024));
357 MutTime = time - GC_tot_time - InitUserTime;
358 if (MutTime < 0) { MutTime = 0; }
359 MutElapsedTime = etime - GCe_tot_time - InitElapsedTime;
360 if (MutElapsedTime < 0) { MutElapsedTime = 0; } /* sometimes -0.00 */
362 fprintf(sf, " INIT time %6.2fs (%6.2fs elapsed)\n",
363 InitUserTime, InitElapsedTime);
364 fprintf(sf, " MUT time %6.2fs (%6.2fs elapsed)\n",
365 MutTime, MutElapsedTime);
366 fprintf(sf, " GC time %6.2fs (%6.2fs elapsed)\n",
367 GC_tot_time, GCe_tot_time);
368 fprintf(sf, " Total time %6.2fs (%6.2fs elapsed)\n\n",
371 fprintf(sf, " %%GC time %5.1f%% (%.1f%% elapsed)\n\n",
372 GC_tot_time*100./time, GCe_tot_time*100./etime);
374 if (time - GC_tot_time == 0.0)
375 ullong_format_string(0, temp, rtsTrue/*commas*/);
377 ullong_format_string((ullong)(GC_tot_alloc*sizeof(W_)/
378 (time - GC_tot_time)),
379 temp, rtsTrue/*commas*/);
381 fprintf(sf, " Alloc rate %s bytes per MUT second\n\n", temp);
383 fprintf(sf, " Productivity %5.1f%% of total user, %.1f%% of total elapsed\n\n",
384 (time - GC_tot_time - InitUserTime) * 100. / time,
385 (time - GC_tot_time - InitUserTime) * 100. / etime);
391 /* -----------------------------------------------------------------------------
394 Produce some detailed info on the state of the generational GC.
395 -------------------------------------------------------------------------- */
397 stat_describe_gens(void)
399 nat g, s, mut, lge, live;
404 fprintf(stderr, " Gen Steps Max Mutable Step Blocks Live Large\n" " Blocks Closures Objects\n");
406 for (g = 0; g < RtsFlags.GcFlags.generations; g++) {
407 for (m = generations[g].mut_list, mut = 0; m != END_MUT_LIST;
410 fprintf(stderr, "%8d %8d %8d %9d", g, generations[g].n_steps,
411 generations[g].max_blocks, mut);
413 for (s = 0; s < generations[g].n_steps; s++) {
414 step = &generations[g].steps[s];
415 for (bd = step->large_objects, lge = 0; bd; bd = bd->link)
418 for (bd = step->blocks; bd; bd = bd->link) {
419 live += (bd->free - bd->start) * sizeof(W_);
422 fprintf(stderr,"%36s","");
424 fprintf(stderr,"%6d %8d %8d %8d\n", s, step->n_blocks,
428 fprintf(stderr,"\n");