From c6ff5639cde8f7ffd005b5d89449adcfa90a5c01 Mon Sep 17 00:00:00 2001 From: simonmar Date: Tue, 2 Nov 1999 17:19:17 +0000 Subject: [PATCH] [project @ 1999-11-02 17:19:15 by simonmar] Time the shutdown code as well as the initialisation code. This figure is sometimes significant for SMP, because the tasks are all killed by a signal (at the moment) and it might take a while for the signal to be delivered. --- ghc/rts/RtsStartup.c | 16 +++++++++---- ghc/rts/Schedule.c | 8 ++++++- ghc/rts/Stats.c | 65 +++++++++++++++++++++++++++++++++++++++----------- ghc/rts/Stats.h | 7 +++++- 4 files changed, 76 insertions(+), 20 deletions(-) diff --git a/ghc/rts/RtsStartup.c b/ghc/rts/RtsStartup.c index 9d3c99c..8673986 100644 --- a/ghc/rts/RtsStartup.c +++ b/ghc/rts/RtsStartup.c @@ -1,5 +1,5 @@ /* ----------------------------------------------------------------------------- - * $Id: RtsStartup.c,v 1.22 1999/11/02 15:06:01 simonmar Exp $ + * $Id: RtsStartup.c,v 1.23 1999/11/02 17:19:15 simonmar Exp $ * * (c) The GHC Team, 1998-1999 * @@ -174,6 +174,9 @@ shutdownHaskell(void) if (!rts_has_started_up) return; + /* start timing the shutdown */ + stat_startExit(); + /* Finalize any remaining weak pointers */ finalizeWeakPointersNow(); @@ -186,12 +189,17 @@ shutdownHaskell(void) /* stop all running tasks */ exitScheduler(); - /* clean up things from the storage manager's point of view */ - exitStorage(); - /* stop the ticker */ initialize_virtual_timer(0); + /* stop timing the shutdown, we're about to print stats */ + stat_endExit(); + + /* clean up things from the storage manager's point of view. + * also outputs the stats (+RTS -s) info. + */ + exitStorage(); + #if defined(PROFILING) || defined(DEBUG) endProfiling(); #endif diff --git a/ghc/rts/Schedule.c b/ghc/rts/Schedule.c index 720386d..fb6749a 100644 --- a/ghc/rts/Schedule.c +++ b/ghc/rts/Schedule.c @@ -1,5 +1,5 @@ /* ----------------------------------------------------------------------------- - * $Id: Schedule.c,v 1.28 1999/11/02 15:06:01 simonmar Exp $ + * $Id: Schedule.c,v 1.29 1999/11/02 17:19:16 simonmar Exp $ * * (c) The GHC Team, 1998-1999 * @@ -256,6 +256,12 @@ schedule( void ) RELEASE_LOCK(&sched_mutex); +#ifdef SMP + IF_DEBUG(scheduler,fprintf(stderr,"schedule (task %ld): running thread %d\n", pthread_self(),t->id)); +#else + IF_DEBUG(scheduler,fprintf(stderr,"schedule: running thread %d\n",t->id)); +#endif + /* Run the current thread */ switch (cap->rCurrentTSO->whatNext) { diff --git a/ghc/rts/Stats.c b/ghc/rts/Stats.c index c82827d..097b5b9 100644 --- a/ghc/rts/Stats.c +++ b/ghc/rts/Stats.c @@ -1,5 +1,5 @@ /* ----------------------------------------------------------------------------- - * $Id: Stats.c,v 1.15 1999/11/02 15:06:03 simonmar Exp $ + * $Id: Stats.c,v 1.16 1999/11/02 17:19:16 simonmar Exp $ * * (c) The GHC Team, 1998-1999 * @@ -64,6 +64,12 @@ static double TicksPerSecond = 0.0; static double InitUserTime = 0.0; static double InitElapsedTime = 0.0; +static double MutUserTime = 0.0; +static double MutElapsedTime = 0.0; + +static double ExitUserTime = 0.0; +static double ExitElapsedTime = 0.0; + static ullong GC_tot_alloc = 0; static ullong GC_tot_copied = 0; @@ -294,6 +300,42 @@ end_init(void) } } +void +stat_startExit(void) +{ + MutElapsedTime = elapsedtime() - GCe_tot_time - InitElapsedTime; + 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; +#endif +} + +void +stat_endExit(void) +{ +#ifdef SMP + ExitUserTime = usertime() - MutUserTime; +#else + ExitUserTime = usertime() - MutUserTime - GC_tot_time - InitUserTime; +#endif + ExitElapsedTime = elapsedtime() - MutElapsedTime; + if (ExitUserTime < 0.0) { + ExitUserTime = 0.0; + } + if (ExitElapsedTime < 0.0) { + ExitElapsedTime = 0.0; + } +} + /* ----------------------------------------------------------------------------- Called at the beginning of each GC -------------------------------------------------------------------------- */ @@ -411,7 +453,6 @@ stat_exit(int alloc) char temp[BIG_STRING_LEN]; double time = usertime(); double etime = elapsedtime(); - double MutTime, MutElapsedTime; /* avoid divide by zero if time is measured as 0.00 seconds -- SDM */ if (time == 0.0) time = 0.0001; @@ -448,36 +489,32 @@ stat_exit(int alloc) fprintf(sf,"\n%11ld Mb total memory in use\n\n", mblocks_allocated * MBLOCK_SIZE / (1024 * 1024)); - MutElapsedTime = etime - GCe_tot_time - InitElapsedTime; - if (MutElapsedTime < 0) { MutElapsedTime = 0; } /* sometimes -0.00 */ - -#ifndef SMP - MutTime = time - GC_tot_time - InitUserTime; - if (MutTime < 0) { MutTime = 0; } - -#else /* SMP */ /* For SMP, we have to get the user time from each thread * and try to work out the total time. */ +#ifdef SMP { nat i; - MutTime = 0.0; + MutUserTime = 0.0; for (i = 0; i < RtsFlags.ConcFlags.nNodes; i++) { + MutUserTime += task_ids[i].mut_time; fprintf(sf, " Task %2d: MUT time: %6.2fs, GC time: %6.2fs\n", i, task_ids[i].mut_time, task_ids[i].gc_time); - MutTime += task_ids[i].mut_time; } } - time = MutTime + GC_tot_time + InitUserTime; + time = MutUserTime + GC_tot_time + InitUserTime + ExitUserTime; + if (MutUserTime < 0) { MutUserTime = 0; } fprintf(sf,"\n"); #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); diff --git a/ghc/rts/Stats.h b/ghc/rts/Stats.h index ec2f2b8..0bf0886 100644 --- a/ghc/rts/Stats.h +++ b/ghc/rts/Stats.h @@ -1,5 +1,5 @@ /* ----------------------------------------------------------------------------- - * $Id: Stats.h,v 1.6 1999/09/15 13:45:20 simonmar Exp $ + * $Id: Stats.h,v 1.7 1999/11/02 17:19:17 simonmar Exp $ * * (c) The GHC Team, 1998-1999 * @@ -12,9 +12,14 @@ extern void start_time(void); extern StgDouble usertime(void); extern void end_init(void); extern void stat_exit(int alloc); + extern void stat_startGC(void); extern void stat_endGC(lnat alloc, lnat collect, lnat live, lnat copied, lnat gen); + +extern void stat_startExit(void); +extern void stat_endExit(void); + extern void initStats(void); extern void stat_describe_gens(void); extern double mut_user_time_during_GC(void); -- 1.7.10.4