/* -----------------------------------------------------------------------------
- * $Id: Stats.c,v 1.10 1999/03/02 20:00:50 sof Exp $
+ * $Id: Stats.c,v 1.20 2000/01/12 15:15:18 simonmar Exp $
*
* (c) The GHC Team, 1998-1999
*
#include "RtsUtils.h"
#include "StoragePriv.h"
#include "MBlock.h"
-
-/**
- * Ian: For the moment we just want to ignore
- * these on Nemesis
- **/
-#ifdef _NEMESIS_OS_
-#ifdef HAVE_SYS_TIMES_H
-#undef HAVE_SYS_TIMES_H /* <sys/times.h> */
-#endif
-#ifdef HAVE_SYS_RESOURCE_H /* <sys/resource.h> */
-#undef HAVE_SYS_RESOURCE_H
-#endif
-#ifdef HAVE_SYS_TIME_H /* <sys/time.h> */
-#undef HAVE_SYS_TIME_H
-#endif
-#ifdef HAVE_SYS_TIMEB_H
-#undef HAVE_SYS_TIMEB_H /* <sys/timeb.h> */
-#endif
-#ifdef HAVE_UNISTD_H
-#undef HAVE_UNISTD_H /* <unistd.h> */
-#endif
-#ifdef HAVE_TIMES
-#undef HAVE_TIMES
-#endif
-#ifdef HAVE_FTIME
-#undef HAVE_FTIME
-#endif
-#ifdef HAVE_GETRUSAGE
-#undef HAVE_GETRUSAGE
-#endif
-#ifdef HAVE_SYSCONF
-#undef HAVE_SYSCONF
-#endif
-#endif /* _NEMESIS_OS_ */
-
+#include "Schedule.h"
#include "Stats.h"
#ifdef HAVE_UNISTD_H
#include <unistd.h>
#endif
-#ifndef _WIN32
+#ifndef __MINGW32__
# ifdef HAVE_SYS_TIMES_H
# include <sys/times.h>
# endif
#include <sys/time.h>
#endif
-#if ! irix_TARGET_OS && ! defined(_WIN32)
+#ifdef __CYGWIN32__
+# ifdef HAVE_TIME_H
+# include <time.h>
+# endif
+#endif
+
+#if ! irix_TARGET_OS && ! defined(__MINGW32__)
# if defined(HAVE_SYS_RESOURCE_H)
# include <sys/resource.h>
# endif
static double InitUserTime = 0.0;
static double InitElapsedTime = 0.0;
+static double InitElapsedStamp = 0.0;
+
+static double MutUserTime = 0.0;
+static double MutElapsedTime = 0.0;
+static double MutElapsedStamp = 0.0;
+
+static double ExitUserTime = 0.0;
+static double ExitElapsedTime = 0.0;
static ullong GC_tot_alloc = 0;
static ullong GC_tot_copied = 0;
FT2longlong(kT,kernelTime);
FT2longlong(uT,userTime);
- return (((StgDouble)(uT + kT))/TicksPerSecond - ElapsedTimeStart);
+ return (((StgDouble)(uT + kT))/TicksPerSecond);
}
#else
double
elapsedtime(void)
{
+
# if ! (defined(HAVE_TIMES) || defined(HAVE_FTIME))
/* We will #ifdef around the fprintf for machines
we *know* are unsupported. (WDP 94/05)
struct tms t;
clock_t r = times(&t);
- return (((double)r)/TicksPerSecond - ElapsedTimeStart);
+ return (((double)r)/TicksPerSecond);
# else /* HAVE_FTIME */
struct timeb t;
ftime(&t);
- return (fabs(t.time + 1e-3*t.millitm - ElapsedTimeStart));
+ return (fabs(t.time + 1e-3*t.millitm));
# endif /* HAVE_FTIME */
# endif /* not stumped */
}
#endif /* !_WIN32 */
+/* mut_user_time_during_GC() and mut_user_time()
+ *
+ * The former function can be used to get the current mutator time
+ * *during* a GC, i.e. between stat_startGC and stat_endGC. This is
+ * used in the heap profiler for accurately time stamping the heap
+ * sample.
+ *
+ * ATTENTION: mut_user_time_during_GC() relies on GC_start_time being
+ * defined in stat_startGC() - to minimise system calls,
+ * GC_start_time is, however, only defined when really needed (check
+ * stat_startGC() for details)
+ */
+double
+mut_user_time_during_GC(void)
+{
+ return (GC_start_time - GC_tot_time);
+}
+
+double
+mut_user_time(void)
+{
+ return (usertime() - GC_tot_time);
+}
+
static nat
pagefaults(void)
nat i;
FILE *sf = RtsFlags.GcFlags.statsFile;
- if (RtsFlags.GcFlags.giveStats) {
+ if (RtsFlags.GcFlags.giveStats >= VERBOSE_GC_STATS) {
fprintf(sf, " Alloc Collect Live GC GC TOT TOT Page Flts\n");
fprintf(sf, " bytes bytes bytes user elap user elap\n");
}
end_init(void)
{
InitUserTime = usertime();
- InitElapsedTime = elapsedtime();
+ InitElapsedStamp = elapsedtime();
+ InitElapsedTime = InitElapsedStamp - ElapsedTimeStart;
if (InitElapsedTime < 0.0) {
InitElapsedTime = 0.0;
}
}
/* -----------------------------------------------------------------------------
+ stat_startExit and stat_endExit
+
+ These two measure the time taken in shutdownHaskell().
+ -------------------------------------------------------------------------- */
+
+void
+stat_startExit(void)
+{
+ MutElapsedStamp = elapsedtime();
+ MutElapsedTime = MutElapsedStamp - GCe_tot_time - InitElapsedStamp;
+ if (MutElapsedTime < 0) { MutElapsedTime = 0; } /* sometimes -0.00 */
+
+ /* for SMP, we don't know the mutator time yet, we have to inspect
+ * all the running threads to find out, and they haven't stopped
+ * yet. So we just timestamp MutUserTime at this point so we can
+ * calculate the EXIT time. The real MutUserTime is calculated
+ * in stat_exit below.
+ */
+#ifdef SMP
+ MutUserTime = usertime();
+#else
+ MutUserTime = usertime() - GC_tot_time - InitUserTime;
+ if (MutUserTime < 0) { MutUserTime = 0; }
+#endif
+}
+
+void
+stat_endExit(void)
+{
+#ifdef SMP
+ ExitUserTime = usertime() - MutUserTime;
+#else
+ ExitUserTime = usertime() - MutUserTime - GC_tot_time - InitUserTime;
+#endif
+ ExitElapsedTime = elapsedtime() - MutElapsedStamp;
+ if (ExitUserTime < 0.0) {
+ ExitUserTime = 0.0;
+ }
+ if (ExitElapsedTime < 0.0) {
+ ExitElapsedTime = 0.0;
+ }
+}
+
+/* -----------------------------------------------------------------------------
Called at the beginning of each GC
-------------------------------------------------------------------------- */
static nat rub_bell = 0;
+/* initialise global variables needed during GC
+ *
+ * * GC_start_time is read in mut_user_time_during_GC(), which in turn is
+ * needed if either PROFILING or DEBUGing is enabled
+ */
void
stat_startGC(void)
{
}
}
+#if defined(PROFILING) || defined(DEBUG)
+ GC_start_time = usertime(); /* needed in mut_user_time_during_GC() */
+#endif
+
if (sf != NULL) {
- GC_start_time = usertime();
+#if !defined(PROFILING) && !defined(DEBUG)
+ GC_start_time = usertime();
+#endif
GCe_start_time = elapsedtime();
if (RtsFlags.GcFlags.giveStats) {
GC_start_faults = pagefaults();
FILE *sf = RtsFlags.GcFlags.statsFile;
if (sf != NULL) {
- double time = usertime();
- double etime = elapsedtime();
+ double time = usertime();
+ double etime = elapsedtime();
+ double gc_time = time - GC_start_time;
+ double gc_etime = etime - GCe_start_time;
- if (RtsFlags.GcFlags.giveStats) {
+ if (RtsFlags.GcFlags.giveStats >= VERBOSE_GC_STATS) {
nat faults = pagefaults();
fprintf(sf, "%9ld %9ld %9ld",
alloc*sizeof(W_), collect*sizeof(W_), live*sizeof(W_));
fprintf(sf, " %5.2f %5.2f %7.2f %7.2f %4ld %4ld (Gen: %2ld)\n",
- (time-GC_start_time),
- (etime-GCe_start_time),
+ gc_time,
+ gc_etime,
time,
- etime,
+ etime - ElapsedTimeStart,
faults - GC_start_faults,
GC_start_faults - GC_end_faults,
gen);
fflush(sf);
}
- GC_coll_times[gen] += time-GC_start_time;
+ GC_coll_times[gen] += gc_time;
GC_tot_copied += (ullong) copied;
GC_tot_alloc += (ullong) alloc;
- GC_tot_time += time-GC_start_time;
- GCe_tot_time += etime-GCe_start_time;
+ GC_tot_time += gc_time;
+ GCe_tot_time += gc_etime;
+
+#ifdef SMP
+ {
+ nat i;
+ pthread_t me = pthread_self();
+
+ for (i = 0; i < RtsFlags.ParFlags.nNodes; i++) {
+ if (me == task_ids[i].id) {
+ task_ids[i].gc_time += gc_time;
+ task_ids[i].gc_etime += gc_etime;
+ break;
+ }
+ }
+ }
+#endif
if (gen == RtsFlags.GcFlags.generations-1) { /* major GC? */
if (live > MaxResidency) {
}
/* -----------------------------------------------------------------------------
+ stat_workerStop
+
+ Called under SMP when a worker thread finishes. We drop the timing
+ stats for this thread into the task_ids struct for that thread.
+ -------------------------------------------------------------------------- */
+
+#ifdef SMP
+void
+stat_workerStop(void)
+{
+ nat i;
+ pthread_t me = pthread_self();
+
+ for (i = 0; i < RtsFlags.ParFlags.nNodes; i++) {
+ if (task_ids[i].id == me) {
+ task_ids[i].mut_time = usertime() - task_ids[i].gc_time;
+ task_ids[i].mut_etime = elapsedtime()
+ - GCe_tot_time
+ - task_ids[i].elapsedtimestart;
+ if (task_ids[i].mut_time < 0.0) { task_ids[i].mut_time = 0.0; }
+ if (task_ids[i].mut_etime < 0.0) { task_ids[i].mut_etime = 0.0; }
+ }
+ }
+}
+#endif
+
+/* -----------------------------------------------------------------------------
Called at the end of execution
NOTE: number of allocations is not entirely accurate: it doesn't
if (sf != NULL){
char temp[BIG_STRING_LEN];
double time = usertime();
- double etime = elapsedtime();
- double MutTime, MutElapsedTime;
+ double etime = elapsedtime() - ElapsedTimeStart;
/* avoid divide by zero if time is measured as 0.00 seconds -- SDM */
if (time == 0.0) time = 0.0001;
if (etime == 0.0) etime = 0.0001;
-
- fprintf(sf, "%9ld %9.9s %9.9s",
- (lnat)alloc*sizeof(W_), "", "");
- fprintf(sf, " %5.2f %5.2f\n\n", 0.0, 0.0);
+ if (RtsFlags.GcFlags.giveStats >= VERBOSE_GC_STATS) {
+ fprintf(sf, "%9ld %9.9s %9.9s", (lnat)alloc*sizeof(W_), "", "");
+ fprintf(sf, " %5.2f %5.2f\n\n", 0.0, 0.0);
+ }
GC_tot_alloc += alloc;
fprintf(sf,"\n%11ld Mb total memory in use\n\n",
mblocks_allocated * MBLOCK_SIZE / (1024 * 1024));
- MutTime = time - GC_tot_time - InitUserTime;
- if (MutTime < 0) { MutTime = 0; }
- MutElapsedTime = etime - GCe_tot_time - InitElapsedTime;
- if (MutElapsedTime < 0) { MutElapsedTime = 0; } /* sometimes -0.00 */
+ /* For SMP, we have to get the user time from each thread
+ * and try to work out the total time.
+ */
+#ifdef SMP
+ {
+ nat i;
+ MutUserTime = 0.0;
+ for (i = 0; i < RtsFlags.ParFlags.nNodes; i++) {
+ MutUserTime += task_ids[i].mut_time;
+ fprintf(sf, " Task %2d: MUT time: %6.2fs (%6.2fs elapsed)\n"
+ " GC time: %6.2fs (%6.2fs elapsed)\n\n",
+ i,
+ task_ids[i].mut_time, task_ids[i].mut_etime,
+ task_ids[i].gc_time, task_ids[i].gc_etime);
+ }
+ }
+ time = MutUserTime + GC_tot_time + InitUserTime + ExitUserTime;
+ if (MutUserTime < 0) { MutUserTime = 0; }
+#endif
fprintf(sf, " INIT time %6.2fs (%6.2fs elapsed)\n",
InitUserTime, InitElapsedTime);
fprintf(sf, " MUT time %6.2fs (%6.2fs elapsed)\n",
- MutTime, MutElapsedTime);
+ MutUserTime, MutElapsedTime);
fprintf(sf, " GC time %6.2fs (%6.2fs elapsed)\n",
GC_tot_time, GCe_tot_time);
+ fprintf(sf, " EXIT time %6.2fs (%6.2fs elapsed)\n",
+ ExitUserTime, ExitElapsedTime);
fprintf(sf, " Total time %6.2fs (%6.2fs elapsed)\n\n",
time, etime);
projects / ghc-hetmet.git / blobdiff