diff options
| -rw-r--r-- | rts/RtsStartup.c | 4 | ||||
| -rw-r--r-- | rts/Stats.c | 79 | ||||
| -rw-r--r-- | rts/Stats.h | 4 | ||||
| -rw-r--r-- | rts/sm/Storage.c | 2 |
4 files changed, 62 insertions, 27 deletions
diff --git a/rts/RtsStartup.c b/rts/RtsStartup.c index 6dd8c555f1..5e2495844c 100644 --- a/rts/RtsStartup.c +++ b/rts/RtsStartup.c @@ -581,6 +581,10 @@ hs_exit_(bool wait_foreign) if (is_io_mng_native_p()) hs_restoreConsoleCP(); #endif + + /* tear down statistics subsystem */ + stat_exit(); + /* free hash table storage */ exitHashTable(); diff --git a/rts/Stats.c b/rts/Stats.c index fcf48c3720..71dcf8a9d0 100644 --- a/rts/Stats.c +++ b/rts/Stats.c @@ -26,6 +26,11 @@ #include <string.h> // for memset +#if defined(THREADED_RTS) +// Protects all statistics below +Mutex stats_mutex; +#endif + static Time start_init_cpu, start_init_elapsed, end_init_cpu, end_init_elapsed, @@ -81,25 +86,6 @@ Time stat_getElapsedTime(void) Measure the current MUT time, for profiling ------------------------------------------------------------------------ */ -double -mut_user_time_until( Time t ) -{ - return TimeToSecondsDbl(t - stats.gc_cpu_ns - stats.nonmoving_gc_cpu_ns); - // heapCensus() time is included in GC_tot_cpu, so we don't need - // to subtract it here. - - // TODO: This seems wrong to me. Surely we should be subtracting - // (at least) start_init_cpu? -} - -double -mut_user_time( void ) -{ - Time cpu; - cpu = getProcessCPUTime(); - return mut_user_time_until(cpu); -} - #if defined(PROFILING) /* mut_user_time_during_RP() returns the MUT time during retainer profiling. @@ -120,6 +106,10 @@ mut_user_time_during_RP( void ) void initStats0(void) { +#if defined(THREADED_RTS) + initMutex(&stats_mutex); +#endif + start_init_cpu = 0; start_init_elapsed = 0; end_init_cpu = 0; @@ -281,9 +271,11 @@ stat_endInit(void) void stat_startExit(void) { + ACQUIRE_LOCK(&stats_mutex); getProcessTimes(&start_exit_cpu, &start_exit_elapsed); start_exit_gc_elapsed = stats.gc_elapsed_ns; start_exit_gc_cpu = stats.gc_cpu_ns; + RELEASE_LOCK(&stats_mutex); } /* ----------------------------------------------------------------------------- @@ -294,7 +286,9 @@ stat_startExit(void) void stat_endExit(void) { + ACQUIRE_LOCK(&stats_mutex); getProcessTimes(&end_exit_cpu, &end_exit_elapsed); + RELEASE_LOCK(&stats_mutex); } void @@ -306,8 +300,10 @@ stat_startGCSync (gc_thread *gct) void stat_startNonmovingGc () { + ACQUIRE_LOCK(&stats_mutex); start_nonmoving_gc_cpu = getCurrentThreadCPUTime(); start_nonmoving_gc_elapsed = getProcessCPUTime(); + RELEASE_LOCK(&stats_mutex); } void @@ -315,6 +311,8 @@ stat_endNonmovingGc () { Time cpu = getCurrentThreadCPUTime(); Time elapsed = getProcessCPUTime(); + + ACQUIRE_LOCK(&stats_mutex); stats.gc.nonmoving_gc_elapsed_ns = elapsed - start_nonmoving_gc_elapsed; stats.nonmoving_gc_elapsed_ns += stats.gc.nonmoving_gc_elapsed_ns; @@ -324,12 +322,15 @@ stat_endNonmovingGc () stats.nonmoving_gc_max_elapsed_ns = stg_max(stats.gc.nonmoving_gc_elapsed_ns, stats.nonmoving_gc_max_elapsed_ns); + RELEASE_LOCK(&stats_mutex); } void stat_startNonmovingGcSync () { + ACQUIRE_LOCK(&stats_mutex); start_nonmoving_gc_sync_elapsed = getProcessElapsedTime(); + RELEASE_LOCK(&stats_mutex); traceConcSyncBegin(); } @@ -337,13 +338,17 @@ void stat_endNonmovingGcSync () { Time end_elapsed = getProcessElapsedTime(); + ACQUIRE_LOCK(&stats_mutex); stats.gc.nonmoving_gc_sync_elapsed_ns = end_elapsed - start_nonmoving_gc_sync_elapsed; stats.nonmoving_gc_sync_elapsed_ns += stats.gc.nonmoving_gc_sync_elapsed_ns; stats.nonmoving_gc_sync_max_elapsed_ns = stg_max(stats.gc.nonmoving_gc_sync_elapsed_ns, stats.nonmoving_gc_sync_max_elapsed_ns); + Time sync_elapsed = stats.gc.nonmoving_gc_sync_elapsed_ns; + RELEASE_LOCK(&stats_mutex); + if (RtsFlags.GcFlags.giveStats == VERBOSE_GC_STATS) { - statsPrintf("# sync %6.3f\n", TimeToSecondsDbl(stats.gc.nonmoving_gc_sync_elapsed_ns)); + statsPrintf("# sync %6.3f\n", TimeToSecondsDbl(sync_elapsed)); } traceConcSyncEnd(); } @@ -459,6 +464,8 @@ stat_endGC (Capability *cap, gc_thread *initiating_gct, W_ live, W_ copied, W_ s W_ mut_spin_spin, W_ mut_spin_yield, W_ any_work, W_ no_work, W_ scav_find_work) { + ACQUIRE_LOCK(&stats_mutex); + // ------------------------------------------------- // Collect all the stats about this GC in stats.gc. We always do this since // it's relatively cheap and we need allocated_bytes to catch heap @@ -628,6 +635,7 @@ stat_endGC (Capability *cap, gc_thread *initiating_gct, W_ live, W_ copied, W_ s CAPSET_HEAP_DEFAULT, mblocks_allocated * MBLOCK_SIZE); } + RELEASE_LOCK(&stats_mutex); } /* ----------------------------------------------------------------------------- @@ -640,8 +648,10 @@ stat_startRP(void) Time user, elapsed; getProcessTimes( &user, &elapsed ); + ACQUIRE_LOCK(&stats_mutex); RP_start_time = user; RPe_start_time = elapsed; + RELEASE_LOCK(&stats_mutex); } #endif /* PROFILING */ @@ -659,11 +669,14 @@ stat_endRP( Time user, elapsed; getProcessTimes( &user, &elapsed ); + ACQUIRE_LOCK(&stats_mutex); RP_tot_time += user - RP_start_time; RPe_tot_time += elapsed - RPe_start_time; + double mut_time_during_RP = mut_user_time_during_RP(); + RELEASE_LOCK(&stats_mutex); fprintf(prof_file, "Retainer Profiling: %d, at %f seconds\n", - retainerGeneration, mut_user_time_during_RP()); + retainerGeneration, mut_time_during_RP); fprintf(prof_file, "\tMax auxiliary stack size = %u\n", maxStackSize); fprintf(prof_file, "\tAverage number of visits per object = %f\n", averageNumVisit); @@ -680,8 +693,10 @@ stat_startHeapCensus(void) Time user, elapsed; getProcessTimes( &user, &elapsed ); + ACQUIRE_LOCK(&stats_mutex); HC_start_time = user; HCe_start_time = elapsed; + RELEASE_LOCK(&stats_mutex); } #endif /* PROFILING */ @@ -695,8 +710,10 @@ stat_endHeapCensus(void) Time user, elapsed; getProcessTimes( &user, &elapsed ); + ACQUIRE_LOCK(&stats_mutex); HC_tot_time += user - HC_start_time; HCe_tot_time += elapsed - HCe_start_time; + RELEASE_LOCK(&stats_mutex); } #endif /* PROFILING */ @@ -793,6 +810,7 @@ static void free_RTSSummaryStats(RTSSummaryStats * sum) sum->gc_summary_stats = NULL; } +// Must hold stats_mutex. static void report_summary(const RTSSummaryStats* sum) { // We should do no calculation, other than unit changes and formatting, and @@ -1195,6 +1213,7 @@ static void report_machine_readable (const RTSSummaryStats * sum) statsPrintf(" ]\n"); } +// Must hold stats_mutex. static void report_one_line(const RTSSummaryStats * sum) { // We should do no calculation, other than unit changes and formatting, and @@ -1226,7 +1245,7 @@ static void report_one_line(const RTSSummaryStats * sum) } void -stat_exit (void) +stat_exitReport (void) { RTSSummaryStats sum; init_RTSSummaryStats(&sum); @@ -1241,6 +1260,7 @@ stat_exit (void) Time now_cpu_ns, now_elapsed_ns; getProcessTimes(&now_cpu_ns, &now_elapsed_ns); + ACQUIRE_LOCK(&stats_mutex); stats.cpu_ns = now_cpu_ns - start_init_cpu; stats.elapsed_ns = now_elapsed_ns - start_init_elapsed; /* avoid divide by zero if stats.total_cpu_ns is measured as 0.00 @@ -1429,6 +1449,7 @@ stat_exit (void) report_one_line(&sum); } } + RELEASE_LOCK(&stats_mutex); statsFlush(); statsClose(); @@ -1452,6 +1473,13 @@ stat_exit (void) RELEASE_LOCK(&all_tasks_mutex); } +void stat_exit() +{ +#if defined(THREADED_RTS) + closeMutex(&stats_mutex); +#endif +} + /* Note [Work Balance] ---------------------- Work balance is a measure of how evenly the work done during parallel garbage @@ -1669,7 +1697,10 @@ statDescribeGens(void) uint64_t getAllocations( void ) { - return stats.allocated_bytes; + ACQUIRE_LOCK(&stats_mutex); + StgWord64 n = stats.allocated_bytes; + RELEASE_LOCK(&stats_mutex); + return n; } int getRTSStatsEnabled( void ) @@ -1682,7 +1713,9 @@ void getRTSStats( RTSStats *s ) Time current_elapsed = 0; Time current_cpu = 0; + ACQUIRE_LOCK(&stats_mutex); *s = stats; + RELEASE_LOCK(&stats_mutex); getProcessTimes(¤t_cpu, ¤t_elapsed); s->cpu_ns = current_cpu - end_init_cpu; diff --git a/rts/Stats.h b/rts/Stats.h index f5b8ce9991..9d62acef37 100644 --- a/rts/Stats.h +++ b/rts/Stats.h @@ -58,6 +58,7 @@ void stat_endHeapCensus(void); void stat_startExit(void); void stat_endExit(void); +void stat_exitReport(void); void stat_exit(void); void stat_workerStop(void); @@ -65,9 +66,6 @@ void initStats0(void); void initStats1(void); void resetChildProcessStats(void); -double mut_user_time_until(Time t); -double mut_user_time(void); - void statDescribeGens( void ); Time stat_getElapsedGCTime(void); diff --git a/rts/sm/Storage.c b/rts/sm/Storage.c index 251353de6d..98aefa9a4b 100644 --- a/rts/sm/Storage.c +++ b/rts/sm/Storage.c @@ -302,7 +302,7 @@ exitStorage (void) { nonmovingExit(); updateNurseriesStats(); - stat_exit(); + stat_exitReport(); } void |