Commit f0b258bc authored by duog's avatar duog Committed by Ben Gamari

rts, base: Refactor stats.c to improve --machine-readable report

There should be no change in the output of the '+RTS -s' (summary)
report, or
the 'RTS -t' (one-line) report.

All data shown in the summary report is now shown in the machine
readable
report.

All data in RTSStats is now shown in the machine readable report.

init times are added to RTSStats and added to GHC.Stats.

Example of the new output:
```
 [("bytes allocated", "375016384")
 ,("num_GCs", "113")
 ,("average_bytes_used", "148348")
 ,("max_bytes_used", "206552")
 ,("num_byte_usage_samples", "2")
 ,("peak_megabytes_allocated", "6")
 ,("init_cpu_seconds", "0.001642")
 ,("init_wall_seconds", "0.001027")
 ,("mut_cpu_seconds", "3.020166")
 ,("mut_wall_seconds", "0.757244")
 ,("GC_cpu_seconds", "0.037750")
 ,("GC_wall_seconds", "0.009569")
 ,("exit_cpu_seconds", "0.000890")
 ,("exit_wall_seconds", "0.002551")
 ,("total_cpu_seconds", "3.060452")
 ,("total_wall_seconds", "0.770395")
 ,("major_gcs", "2")
 ,("allocated_bytes", "375016384")
 ,("max_live_bytes", "206552")
 ,("max_large_objects_bytes", "159344")
 ,("max_compact_bytes", "0")
 ,("max_slop_bytes", "59688")
 ,("max_mem_in_use_bytes", "6291456")
 ,("cumulative_live_bytes", "296696")
 ,("copied_bytes", "541024")
 ,("par_copied_bytes", "493976")
 ,("cumulative_par_max_copied_bytes", "104104")
 ,("cumulative_par_balanced_copied_bytes", "274456")
 ,("fragmentation_bytes", "2112")
 ,("alloc_rate", "124170795")
 ,("productivity_cpu_percent", "0.986838")
 ,("productivity_wall_percent", "0.982935")
 ,("bound_task_count", "1")
 ,("sparks_count", "5836258")
 ,("sparks_converted", "237")
 ,("sparks_overflowed", "1990408")
 ,("sparks_dud ", "0")
 ,("sparks_gcd", "3455553")
 ,("sparks_fizzled", "390060")
 ,("work_balance", "0.555606")
 ,("n_capabilities", "4")
 ,("task_count", "10")
 ,("peak_worker_count", "9")
 ,("worker_count", "9")
 ,("gc_alloc_block_sync_spin", "162")
 ,("gc_alloc_block_sync_yield", "0")
 ,("gc_alloc_block_sync_spin", "162")
 ,("gc_spin_spin", "18840855")
 ,("gc_spin_yield", "10355")
 ,("mut_spin_spin", "70331392")
 ,("mut_spin_yield", "61700")
 ,("waitForGcThreads_spin", "241")
 ,("waitForGcThreads_yield", "2797")
 ,("whitehole_gc_spin", "0")
 ,("whitehole_lockClosure_spin", "0")
 ,("whitehole_lockClosure_yield", "0")
 ,("whitehole_executeMessage_spin", "0")
 ,("whitehole_threadPaused_spin", "0")
 ,("any_work", "1667")
 ,("no_work", "1662")
 ,("scav_find_work", "1026")
 ,("gen_0_collections", "111")
 ,("gen_0_par_collections", "111")
 ,("gen_0_cpu_seconds", "0.036126")
 ,("gen_0_wall_seconds", "0.036126")
 ,("gen_0_max_pause_seconds", "0.036126")
 ,("gen_0_avg_pause_seconds", "0.000081")
 ,("gen_0_sync_spin", "21")
 ,("gen_0_sync_yield", "0")
 ,("gen_1_collections", "2")
 ,("gen_1_par_collections", "1")
 ,("gen_1_cpu_seconds", "0.001624")
 ,("gen_1_wall_seconds", "0.001624")
 ,("gen_1_max_pause_seconds", "0.001624")
 ,("gen_1_avg_pause_seconds", "0.000272")
 ,("gen_1_sync_spin", "3")
 ,("gen_1_sync_yield", "0")
 ]
```

Test Plan: Ensure that one-line and summary reports are unchanged.

Reviewers: erikd, simonmar, hvr

Subscribers: duog, carter, thomie, rwbarton

GHC Trac Issues: #14660

Differential Revision: https://phabricator.haskell.org/D4529
parent 60e29dc2
......@@ -184,7 +184,7 @@ typedef struct _RTSStats {
uint64_t par_copied_bytes;
// Sum of par_max_copied_bytes across all parallel GCs
uint64_t cumulative_par_max_copied_bytes;
// Sum of par_balanced_copied_byes across all parallel GCs.
// Sum of par_balanced_copied_byes across all parallel GCs.
uint64_t cumulative_par_balanced_copied_bytes;
// -----------------------------------
......@@ -192,6 +192,10 @@ typedef struct _RTSStats {
// (we use signed values here because due to inaccuracies in timers
// the values can occasionally go slightly negative)
// Total CPU time used by the init phase
Time init_cpu_ns;
// Total elapsed time used by the init phase
Time init_elapsed_ns;
// Total CPU time used by the mutator
Time mutator_cpu_ns;
// Total elapsed time used by the mutator
......@@ -213,26 +217,26 @@ typedef struct _RTSStats {
// -----------------------------------
// Internal Counters
// The number of times a GC thread spun on its 'gc_spin' lock.
// Will be zero if the rts was not built with PROF_SPIN
// The number of times a GC thread spun on its 'gc_spin' lock.
// Will be zero if the rts was not built with PROF_SPIN
uint64_t gc_spin_spin;
// The number of times a GC thread yielded on its 'gc_spin' lock.
// Will be zero if the rts was not built with PROF_SPIN
// The number of times a GC thread yielded on its 'gc_spin' lock.
// Will be zero if the rts was not built with PROF_SPIN
uint64_t gc_spin_yield;
// The number of times a GC thread spun on its 'mut_spin' lock.
// Will be zero if the rts was not built with PROF_SPIN
// The number of times a GC thread spun on its 'mut_spin' lock.
// Will be zero if the rts was not built with PROF_SPIN
uint64_t mut_spin_spin;
// The number of times a GC thread yielded on its 'mut_spin' lock.
// Will be zero if the rts was not built with PROF_SPIN
// The number of times a GC thread yielded on its 'mut_spin' lock.
// Will be zero if the rts was not built with PROF_SPIN
uint64_t mut_spin_yield;
// The number of times a GC thread has checked for work across all parallel
// GCs
// The number of times a GC thread has checked for work across all parallel
// GCs
uint64_t any_work;
// The number of times a GC thread has checked for work and found none across
// all parallel GCs
// The number of times a GC thread has checked for work and found none
// across all parallel GCs
uint64_t no_work;
// The number of times a GC thread has iterated it's outer loop across all
// parallel GCs
// The number of times a GC thread has iterated it's outer loop across all
// parallel GCs
uint64_t scav_find_work;
} RTSStats;
......
......@@ -83,6 +83,12 @@ data RTSStats = RTSStats {
-- (we use signed values here because due to inaccuracies in timers
-- the values can occasionally go slightly negative)
-- | Total CPU time used by the init phase
-- @since 4.12.0.0
, init_cpu_ns :: RtsTime
-- | Total elapsed time used by the init phase
-- @since 4.12.0.0
, init_elapsed_ns :: RtsTime
-- | Total CPU time used by the mutator
, mutator_cpu_ns :: RtsTime
-- | Total elapsed time used by the mutator
......@@ -175,6 +181,8 @@ getRTSStats = do
(# peek RTSStats, cumulative_par_max_copied_bytes) p
cumulative_par_balanced_copied_bytes <-
(# peek RTSStats, cumulative_par_balanced_copied_bytes) p
init_cpu_ns <- (# peek RTSStats, init_cpu_ns) p
init_elapsed_ns <- (# peek RTSStats, init_elapsed_ns) p
mutator_cpu_ns <- (# peek RTSStats, mutator_cpu_ns) p
mutator_elapsed_ns <- (# peek RTSStats, mutator_elapsed_ns) p
gc_cpu_ns <- (# peek RTSStats, gc_cpu_ns) p
......
This diff is collapsed.
......@@ -66,4 +66,49 @@ void statDescribeGens( void );
Time stat_getElapsedGCTime(void);
Time stat_getElapsedTime(void);
typedef struct GenerationSummaryStats_ {
uint32_t collections;
uint32_t par_collections;
Time cpu_ns;
Time elapsed_ns;
Time max_pause_ns;
Time avg_pause_ns;
#if defined(THREADED_RTS) && defined(PROF_SPIN)
uint64_t sync_spin;
uint64_t sync_yield;
#endif
} GenerationSummaryStats;
typedef struct RTSSummaryStats_ {
// These profiling times could potentially be in RTSStats. However, I'm not
// confident enough to do this now, since there is some logic depending on
// global state that I do not understand. (Or if I do understand it, it's
// wrong)
Time rp_cpu_ns;
Time rp_elapsed_ns;
Time hc_cpu_ns;
Time hc_elapsed_ns;
Time exit_cpu_ns;
Time exit_elapsed_ns;
#if defined(THREADED_RTS)
uint32_t bound_task_count;
uint64_t sparks_count;
SparkCounters sparks;
double work_balance;
#else // THREADED_RTS
double gc_cpu_percent;
double gc_elapsed_percent;
#endif
uint64_t fragmentation_bytes;
uint64_t average_bytes_used; // This is not shown in the '+RTS -s' report
uint64_t alloc_rate;
double productivity_cpu_percent;
double productivity_elapsed_percent;
// one for each generation, 0 first
GenerationSummaryStats* gc_summary_stats;
} RTSSummaryStats;
#include "EndPrivate.h"
Markdown is supported
0%
or
You are about to add 0 people to the discussion. Proceed with caution.
Finish editing this message first!
Please register or to comment