#! /usr/bin/awk -f

# Note:  /bin/nawk on Solaris 9 seems to have a bug; the RSTART and RLENGTH
# vars are not set correctly during the last call to match() in
# recordGCPauseEVM.

# PrintGCStats - summarize statistics about garbage collection, in particular gc
# pause time totals, averages, maximum and standard deviations.
# 
# Attribution:  written by John Coomes, based on earlier work by Peter Kessler,
# Ross Knippel and Jon Masamitsu.
#
# The input to this script should be the output from the HotSpot(TM)
# Virtual Machine when run with one or more of the following flags:
#
# -verbose:gc			# produces minimal output so statistics are
#				# limited, but available in all VMs
#
# -XX:+PrintGCTimeStamps	# enables time-based statistics (e.g.,
#				# allocation rates, intervals), but only
#				# available in JDK 1.4.0 and later.
#
# -XX:+PrintGCDetails		# enables more detailed statistics gathering,
#				# but only available in JDK 1.4.1 and later.
#
# -XX:-TraceClassUnloading	# [1.5.0 and later] disable messages about class
#				# unloading, which are enabled as a side-effect
#				# by -XX:+PrintGCDetails.  The class unloading
#				# messages confuse this script and will cause
#				# some GC information in the log to be ignored.
#				# 
#				# Note:  This option only has an effect in 1.5.0
#				# and later.  Prior to 1.5.0, the option is
#				# accepted, but is overridden by
#				# -XX:+PrintGCDetails. In 1.4.2 and earlier
#				# releases, use -XX:-ClassUnloading instead (see
#				# below).
#
# -XX:-ClassUnloading		# disable class unloading, since PrintGCDetails
#				# turns on TraceClassUnloading, which cannot be
#				# overridden from the command line until 1.5.0.
#
# Recommended command-line with JDK 1.5.0 and later:
#
#	java -verbose:gc -XX:+PrintGCTimeStamps -XX:+PrintGCDetails \
#		-XX:-TraceClassUnloading ...
#
# Recommended command-line with JDK 1.4.1 and 1.4.2:
#
#	java -verbose:gc -XX:+PrintGCTimeStamps -XX:+PrintGCDetails \
#		-XX:-ClassUnloading ...
#
# ------------------------------------------------------------------------------
# 
# Usage:
#
# PrintGCStats -v cpus=<n> [-v interval=<seconds>] [-v verbose=1] [file ...]
# PrintGCStats -v plot=name[,name2,name3,...] [-v plotcolumns=<n>] [-v verbose=1] [-v splitfiles=1] [-v datestamps=1] [-v ts_start] [-v ts_end] [file ...]
# 
# cpus		- number of cpus on the machine where java was run, used to
#		  compute cpu time available and gc 'load' factors.  No default;
#		  must be specified on the command line (defaulting to 1 is too
#		  error prone).
#
# ncpu		- synonym for cpus, accepted for backward compatibility
#
# interval	- print statistics at the end of each interval; requires
#		  output from -XX:+PrintGCTimeStamps.  Default is 0 (disabled).
#
# plot		- generate data points useful for plotting one of the collected
#		  statistics instead of the normal statistics summary.  The name
#		  argument is the name of one (or multiple comma separated names) 
#     of the output statistics, e.g.,
#		  gen0t or cmsRM, or commit0", etc. (single plot)
#     gen0t,cmsRM,GCPause  (multiple plots)
# 
# 		  The default output format for time-based statistics such as
# 		  "gen0t(s)" includes four columns, described below.  The
# 		  default output format for size-based statistics such as
# 		  "commit0(MB)" includes just the first two columns.  The
# 		  number of columns in the output can be set on the command
# 		  line with -v plotcolumns=<N>.
# 
# 		  The output columns are:
#
#		  1) the starting timestamp if timestamps are present, or a
#		     simple counter if not
#
#		  2) the value of the desired statistic (e.g., the length of a
#		     cms remark pause).
#
#		  3) the ending timestamp (or counter)
#
#		  4) the value of the desired statistic (again)
#
#		  The last column is to make plotting start & stop events
#		  easier.
#
# plotcolumns	- the number of columns to include in the plot data.
#
# verbose	- if non-zero, print each item on a separate line in addition
#		  to the summary statistics
#
# splitfiles - When multiple plots are specified, enabling this flag (by setting
#              it to 1) will cause each gc metric to be written to its own file.
#              The output files are named <splitfileprefix>.plot.csv
#
# splitfileprefix - Prefix used for naming output files when using splitfiles. If
#                   no prefix is specified then "GC" will be used as the prefix
#
# datestamps - if datestamps is set to 1, use the timestamp as output by the
#              PrintDateStamps flag instead of the timestamps relative to JVM
#              start.
#
# ts_start - Start time for analysis of the gc log. Any entries before this
#            time will be ignored. Specify ts_start in the format below
#            "YYYY-MM-DD HH:MM:SS.sss"
#
# ts_end -  End time for analysis of the gc log. Once the end time is reached
#           the program will quit. Specify ts_end in the format below
#           "YYYY-MM-DD HH:MM:SS.sss"
#
# Typical usage:
#
# PrintGCStats -v cpus=4 gc.log > gc.stats
# 
# ------------------------------------------------------------------------------
#
# Basic Output statistics:
#
# gen0(s)     - young gen collection time, excluding gc_prologue & gc_epilogue.
# gen0t(s)    - young gen collection time, including gc_prologue & gc_epilogue
# gen0usr(s)  - young gen collection time in cpu user secs
# gen0sys(s)  - young gen collection time in cpu sys secs
# gen0real(s) - young gen collection time in elapsed time secs
# gen1i(s)    - train generation incremental collection
# gen1t(s)    - old generation collection/full GC
# cmsIM(s)    - CMS initial mark pause
# cmsRM(s)    - CMS remark pause
# cmsRS(s)    - CMS resize pause
# GCPause(s)       - all stop-the-world GC pauses
# cmsCM(s)    - CMS concurrent mark phase
# cmsCP(s)    - CMS concurrent preclean phase
# cmsCS(s)    - CMS concurrent sweep phase
# cmsCR(s)    - CMS concurrent reset phase
# alloc(MB)   - object allocation in MB (approximate***)
# promo(MB)   - object promotion in MB (approximate***)
# used0(MB)   - young gen used memory size (before gc)
# used1(MB)   - old gen used memory size (before gc)
# used(MB)    - heap space used memory size (before gc) (excludes perm gen)
# used0AfterGC(MB)   - young gen used memory size (after gc)
# used1AfterGC(MB)   - old gen used memory size (after gc)
# usedAfterGC(MB)    - heap space used memory size (after gc) (excludes perm gen)
# commit0(MB) - young gen committed memory size (after gc)
# commit1(MB) - old gen committed memory size (after gc)
# commit(MB)  - heap committed memory size (after gc) (excludes perm gen)
# apptime(s)  - amount of time application threads were running
# safept(s)   - amount of time the VM spent at safepoints (app threads stopped)
#
# *** - these values are approximate because there is no way to track
#       allocations that occur directly into older generations.
# 
# Some definitions:
# 
# 'mutator' or 'mutator thread':  a gc-centric term referring to a non-GC
# thread that modifies or 'mutates' the heap by allocating memory and/or
# updating object fields.
# 
# promotion:  when an object that was allocated in the young generation has
# survived long enough, it is copied, or promoted, into the old generation.
#
# Time-based Output Statistics (require -XX:+PrintGCTimeStamps):
# 
# alloc/elapsed_time - allocation rate, based on elapsed time
# alloc/tot_cpu_time - allocation rate, based on total cpu time
# alloc/mut_cpu_time - allocation rate, based on cpu time available to mutators
# promo/elapsed_time - promotion rate, based on elapsed time
# promo/gc0_time     - promotion rate, based on young gen gc time
# gc_seq_load        - the percentage of cpu cycles used by gc 'serially'
#		       (i.e., while java application threads are stopped)
# gc_conc_load       - the percentage of cpu cycles used by gc 'concurrently'
# 		       (i.e., while java application threads are also running)
# gc_tot_load        - the percentage of cpu cycles spent in gc

BEGIN {
  usage_msg = "PrintGCStats -v cpus=<n> [-v interval=<seconds>] " \
	      "[-v verbose=1] [file ...]\n" \
              "PrintGCStats -v plot=name[,name2,name3,...] [-v plotcolumns=<n>] "\
	      "[-v verbose=1] [-v splitfiles=1] [-v splitfileprefix=prefix] [-v datestamps=1] "\
        "[-v ts_start=start-timestamp] [-v ts_end=end-timestamp] [file ...]";

  # Seconds between printing per-interval statistics; a negative value disables
  # intervals (the default).  Allow command line to override.
  timeStampDelta = interval == 0 ? -1 : interval;
  # Number of cpus.  Require this on the command line since defaulting to 1 is
  # too error prone.  Older versions used ncpu as the var name; accept it for
  # compatibility.
  if (cpus == 0) cpus = ncpu;
  if (cpus == 0 && plot == "") {
    print usage_msg;
    exit(1);
  }

  # A note on time stamps:  the firstTimeStamp is not always assumed to be 0 so
  # that we can get accurate elapsed time measurement for a partial log (e.g.,
  # from the steady-state portion of a log from a long running server).  This
  # means that the elapsed time measurement can be wrong if a program runs for a
  # significant amount of time before the first gc time stamp is reported.  The
  # best way to fix this is to have the VM emit a time stamp when heap
  # initialization is complete.
  firstTimeStamp = -1.0;	# sentinel
  prevTimeStamp = lastTimeStamp = firstTimeStamp;
  lastFileName = "";	# Used to detect when the input file has changed.

  # This value is added to time stamps so that input from multiple files appears
  # to have monotonically increasing timestamps.
  timeStampOffset = 0.0;

  # Support time range filtering
  if(ts_start == "") ts_start = "2000-01-01 00:00:00.000";
  if(ts_end == "") ts_end = "3000-01-01 00:00:00.000";

  i = -1;
  gen0c_idx = ++i;	# With PrintGCDetails, DefNew collection time only.
  gen0t_idx = ++i;	# Includes gc_prologue() & gc_epilogue().
  gen1i_idx = ++i;	# Train incremental collection time. 
  gen1t_idx = ++i;	# Full GCs or Tenured GCs
  g1_young_idx = ++i; # G1 GC Young
  g1_mixed_idx = ++i; # G1 GC Mixed
  g1_remark_idx = ++i; # G1 Remark Pause
  g1_cleanup_idx = ++i; # G1 Cleanup Pause 
  cmsIM_idx = ++i;	# CMS Initial Mark
  cmsRM_idx = ++i;	# CMS Remark
  cmsRS_idx = ++i;	# CMS Resize (evm only)
  totgc_idx = ++i;	# Total gc pause time
  # These must be greater than the totgc_idx.
  g1_remark_refproc_idx = ++i; 
  g1_young_parallel_idx = ++i;
  g1_young_parallel_gc_workers_idx = ++i;
  g1_young_parallel_gc_worker_start_avg_idx = ++i;
  g1_young_parallel_gc_worker_start_max_idx = ++i;
  g1_young_parallel_ext_root_scanning_avg_idx = ++i;
  g1_young_parallel_ext_root_scanning_max_idx = ++i;
  g1_young_parallel_update_rs_avg_idx = ++i;
  g1_young_parallel_update_rs_max_idx = ++i;
  g1_young_parallel_update_rs_processed_buffer_avg_idx = ++i;
  g1_young_parallel_update_rs_processed_buffer_max_idx = ++i;
  g1_young_parallel_scan_rs_avg_idx = ++i;
  g1_young_parallel_scan_rs_max_idx = ++i;
  g1_young_parallel_object_copy_rs_avg_idx = ++i;
  g1_young_parallel_object_copy_rs_max_idx = ++i;
  g1_young_parallel_termination_avg_idx = ++i;
  g1_young_parallel_termination_max_idx = ++i;
  g1_young_parallel_gc_worker_other_avg_idx = ++i;
  g1_young_parallel_gc_worker_other_max_idx = ++i;
  g1_young_parallel_gc_worker_total_avg_idx = ++i;
  g1_young_parallel_gc_worker_total_max_idx = ++i;
  g1_young_parallel_gc_worker_end_avg_idx = ++i;
  g1_young_parallel_gc_worker_end_max_idx = ++i;
  g1_young_code_root_fixup_idx = ++i;
  g1_young_clear_ct_idx = ++i;
  g1_young_other_idx = ++i;
  g1_young_other_choose_cset_idx = ++i;
  g1_young_other_ref_proc_idx = ++i;
  g1_young_other_ref_enq_idx = ++i;
  g1_young_other_free_cset_idx = ++i;
  g1_young_cpu_sys_idx = ++i;
  g1_young_cpu_usr_idx = ++i;
  g1_young_cpu_real_idx = ++i;
  g1_mixed_parallel_idx = ++i;
  g1_mixed_parallel_gc_workers_idx = ++i;
  g1_mixed_parallel_gc_worker_start_avg_idx = ++i;
  g1_mixed_parallel_gc_worker_start_max_idx = ++i;
  g1_mixed_parallel_ext_root_scanning_avg_idx = ++i;
  g1_mixed_parallel_ext_root_scanning_max_idx = ++i;
  g1_mixed_parallel_update_rs_avg_idx = ++i;
  g1_mixed_parallel_update_rs_max_idx = ++i;
  g1_mixed_parallel_update_rs_processed_buffer_avg_idx = ++i;
  g1_mixed_parallel_update_rs_processed_buffer_max_idx = ++i;
  g1_mixed_parallel_scan_rs_avg_idx = ++i;
  g1_mixed_parallel_scan_rs_max_idx = ++i;
  g1_mixed_parallel_object_copy_rs_avg_idx = ++i;
  g1_mixed_parallel_object_copy_rs_max_idx = ++i;
  g1_mixed_parallel_termination_avg_idx = ++i;
  g1_mixed_parallel_termination_max_idx = ++i;
  g1_mixed_parallel_gc_worker_other_avg_idx = ++i;
  g1_mixed_parallel_gc_worker_other_max_idx = ++i;
  g1_mixed_parallel_gc_worker_total_avg_idx = ++i;
  g1_mixed_parallel_gc_worker_total_max_idx = ++i;
  g1_mixed_parallel_gc_worker_end_avg_idx = ++i;
  g1_mixed_parallel_gc_worker_end_max_idx = ++i;
  g1_mixed_code_root_fixup_idx = ++i;
  g1_mixed_clear_ct_idx = ++i;
  g1_mixed_other_idx = ++i;
  g1_mixed_other_choose_cset_idx = ++i;
  g1_mixed_other_ref_proc_idx = ++i;
  g1_mixed_other_ref_enq_idx = ++i;
  g1_mixed_other_free_cset_idx = ++i;
  g1_mixed_cpu_sys_idx = ++i;
  g1_mixed_cpu_usr_idx = ++i;
  g1_mixed_cpu_real_idx = ++i;
  g1_eden_occupancy_before_gc_idx = ++i;
  g1_eden_capacity_before_gc_idx = ++i;
  g1_eden_occupancy_after_gc_idx = ++i;
  g1_eden_capacity_after_gc_idx = ++i;
  g1_survivor_before_gc_idx = ++i;
  g1_survivor_after_gc_idx = ++i;
  g1_heap_occupancy_before_gc_idx = ++i;
  g1_heap_capacity_before_gc_idx = ++i;
  g1_heap_occupancy_after_gc_idx = ++i;
  g1_heap_capacity_after_gc_idx = ++i;

  gen0usr_idx = ++i;    # CPU user time in gen0
  gen0sys_idx = ++i;    # CPU sys time in gen0
  gen0real_idx = ++i;    # CPU sys time in gen0
  cmsCM_idx = ++i;	# CMS Concurrent Mark
  cmsCP_idx = ++i;	# CMS Concurrent Preclean
  cmsCS_idx = ++i;	# CMS Concurrent Sweep
  cmsCR_idx = ++i;	# CMS Concurrent Reset
  MB_a_idx = ++i;	# MB allocated
  MB_p_idx = ++i;	# MB promoted
  MB_used0_idx = ++i;	# MB used in young gen
  MB_used1_idx = ++i;	# MB used in old gen
  MB_usedh_idx = ++i;	# MB used in heap (occupancy)
  MB_c0_idx = ++i;	# MB committed for gen0
  MB_c1_idx = ++i;	# MB committed for gen1
  MB_ch_idx = ++i;	# MB committed for entire heap
  MB_used0AfterGC_idx = ++i;	# MB used in young gen
  MB_used1AfterGC_idx = ++i;	# MB used in old gen
  MB_usedhAfterGC_idx = ++i;	# MB used in heap (occupancy)

  safept_idx = ++i;	# Time application threads were stopped at a safepoint,
  			# from -XX:+TraceGCApplicationStoppedTime

  apptime_idx =	++i;	# Time application threads were running, from
  			# -XX:+PrintGCApplicationConcurrentTime

  # Parallel old phases from PrintParallelOldGCPhaseTimes.
  PO_precomp_idx	= ++i;
  PO_marking_idx	= ++i;
  PO_parmark_idx	= ++i;
  PO_mark_flush_idx	= ++i;
  PO_summary_idx 	= ++i;
  PO_adjroots_idx	= ++i;
  PO_permgen_idx	= ++i;
  PO_compact_idx 	= ++i;
  PO_drain_ts_idx 	= ++i;
  PO_dpre_ts_idx 	= ++i;
  PO_steal_ts_idx 	= ++i;
  PO_parcomp_idx 	= ++i;
  PO_deferred_idx	= ++i;
  PO_postcomp_idx	= ++i;

  last_idx = ++i;	# This is just the last *named* index; a corresponding
			# delta_* array item exists for each of the above items
			# starting at this point in the array.

  plot_cnt = -1;	# Used to identify plot lines if timestamps are not
  			# available.

  # Init arrays.
  name_v[gen0c_idx]	= "gen0";
  name_v[gen0t_idx]	= "gen0t";
  name_v[gen0usr_idx]	= "gen0usr";
  name_v[gen0sys_idx]	= "gen0sys";
  name_v[gen0real_idx]	= "gen0real";
  name_v[gen1i_idx]	= "gen1i";
  name_v[gen1t_idx]	= "gen1t";
  name_v[g1_young_idx] = "g1-pause-young";
  name_v[g1_mixed_idx] = "g1-pause-mixed";
  name_v[g1_remark_idx] = "g1-pause-remark";
  name_v[g1_remark_refproc_idx] = "g1-pause-remark.ref-proc";
  name_v[g1_cleanup_idx] = "g1-pause-cleanup";
  name_v[g1_young_parallel_idx] = "g1-pause-young.parallel";
  name_v[g1_young_parallel_gc_workers_idx] = "g1-pause-young.parallel.gcworkers";
  name_v[g1_young_parallel_gc_worker_start_avg_idx] = "g1-pause-young.parallel.gc-worker-start.avg";
  name_v[g1_young_parallel_gc_worker_start_max_idx] = "g1-pause-young.parallel.gc-worker-start.max";
  name_v[g1_young_parallel_ext_root_scanning_avg_idx] = "g1-pause-young.parallel.ext-root-scanning.avg";
  name_v[g1_young_parallel_ext_root_scanning_max_idx] = "g1-pause-young.parallel.ext-root-scanning.max";
  name_v[g1_young_parallel_update_rs_avg_idx] = "g1-pause-young.parallel.update-rs.avg";
  name_v[g1_young_parallel_update_rs_max_idx] = "g1-pause-young.parallel.update-rs.max";
  name_v[g1_young_parallel_update_rs_processed_buffer_avg_idx] = "g1-pause-young.parallel.update-rs.processed-buffers.avg";
  name_v[g1_young_parallel_update_rs_processed_buffer_max_idx] = "g1-pause-young.parallel.update-rs.processed-buffers.max";
  name_v[g1_young_parallel_scan_rs_avg_idx] = "g1-pause-young.parallel.scan-rs.avg";
  name_v[g1_young_parallel_scan_rs_max_idx] = "g1-pause-young.parallel.scan-rs.max";
  name_v[g1_young_parallel_object_copy_rs_avg_idx] = "g1-pause-young.parallel.object-copy-rs.avg";
  name_v[g1_young_parallel_object_copy_rs_max_idx] = "g1-pause-young.parallel.object-copy-rs.max";
  name_v[g1_young_parallel_termination_avg_idx] = "g1-pause-young.parallel.termination.avg";
  name_v[g1_young_parallel_termination_max_idx] = "g1-pause-young.parallel.termination.max";
  name_v[g1_young_parallel_gc_worker_other_avg_idx] = "g1-pause-young.parallel.gc-worker-other.avg";
  name_v[g1_young_parallel_gc_worker_other_max_idx] = "g1-pause-young.parallel.gc-worker-other.max";
  name_v[g1_young_parallel_gc_worker_total_avg_idx] = "g1-pause-young.parallel.gc-worker-total.avg";
  name_v[g1_young_parallel_gc_worker_total_max_idx] = "g1-pause-young.parallel.gc-worker-total.max";
  name_v[g1_young_parallel_gc_worker_end_avg_idx] = "g1-pause-young.parallel.gc-worker-end.avg";
  name_v[g1_young_parallel_gc_worker_end_max_idx] = "g1-pause-young.parallel.gc-worker-end.max";
  name_v[g1_young_code_root_fixup_idx] = "g1-pause-young.code-root-fixup";
  name_v[g1_young_clear_ct_idx] = "g1-pause-young.clear-ct";
  name_v[g1_young_other_idx] = "g1-pause-young.other";
  name_v[g1_young_other_choose_cset_idx] = "g1-pause-young.other.choose-cset";
  name_v[g1_young_other_ref_proc_idx] = "g1-pause-young.other.ref-proc";
  name_v[g1_young_other_ref_enq_idx] = "g1-pause-young.other.reg-enq";
  name_v[g1_young_other_free_cset_idx] = "g1-pause-young.other.free-cset";
  name_v[g1_young_cpu_sys_idx] = "g1-young-cpu.sys";
  name_v[g1_young_cpu_usr_idx] = "g1-young-cpu.usr";
  name_v[g1_young_cpu_real_idx] = "g1-young-cpu.real";
  name_v[g1_mixed_parallel_idx] = "g1-pause-mixed.parallel";
  name_v[g1_mixed_parallel_gc_workers_idx] = "g1-pause-mixed.parallel.gcworkers";
  name_v[g1_mixed_parallel_gc_worker_start_avg_idx] = "g1-pause-mixed.parallel.gc-worker-start.avg";
  name_v[g1_mixed_parallel_gc_worker_start_max_idx] = "g1-pause-mixed.parallel.gc-worker-start.max"
  name_v[g1_mixed_parallel_ext_root_scanning_avg_idx] = "g1-pause-mixed.parallel.ext-root-scanning.avg";
  name_v[g1_mixed_parallel_ext_root_scanning_max_idx] = "g1-pause-mixed.parallel.ext-root-scanning.max";
  name_v[g1_mixed_parallel_update_rs_avg_idx] = "g1-pause-mixed.parallel.update-rs.avg";
  name_v[g1_mixed_parallel_update_rs_max_idx] = "g1-pause-mixed.parallel.update-rs.max";
  name_v[g1_mixed_parallel_update_rs_processed_buffer_avg_idx] = "g1-pause-mixed.parallel.update-rs.processed-buffers.avg";
  name_v[g1_mixed_parallel_update_rs_processed_buffer_max_idx] = "g1-pause-mixed.parallel.update-rs.processed-buffers.max";
  name_v[g1_mixed_parallel_scan_rs_avg_idx] = "g1-pause-mixed.parallel.scan-rs.avg";
  name_v[g1_mixed_parallel_scan_rs_max_idx] = "g1-pause-mixed.parallel.scan-rs.max";
  name_v[g1_mixed_parallel_object_copy_rs_avg_idx] = "g1-pause-mixed.parallel.object-copy-rs.avg";
  name_v[g1_mixed_parallel_object_copy_rs_max_idx] = "g1-pause-mixed.parallel.object-copy-rs.max";
  name_v[g1_mixed_parallel_termination_avg_idx] = "g1-pause-mixed.parallel.termination.avg";
  name_v[g1_mixed_parallel_termination_max_idx] = "g1-pause-mixed.parallel.termination.max";
  name_v[g1_mixed_parallel_gc_worker_other_avg_idx] = "g1-pause-mixed.parallel.gc-worker-other.avg";
  name_v[g1_mixed_parallel_gc_worker_other_max_idx] = "g1-pause-mixed.parallel.gc-worker-other.max";
  name_v[g1_mixed_parallel_gc_worker_total_avg_idx] = "g1-pause-mixed.parallel.gc-worker-total.avg";
  name_v[g1_mixed_parallel_gc_worker_total_max_idx] = "g1-pause-mixed.parallel.gc-worker-total.max";
  name_v[g1_mixed_parallel_gc_worker_end_avg_idx] = "g1-pause-mixed.parallel.gc-worker-end.avg";
  name_v[g1_mixed_parallel_gc_worker_end_max_idx] = "g1-pause-mixed.parallel.gc-worker-end.max";
  name_v[g1_mixed_code_root_fixup_idx] = "g1-pause-mixed.code-root-fixup";
  name_v[g1_mixed_clear_ct_idx] = "g1-pause-mixed.clear-ct";
  name_v[g1_mixed_other_idx] = "g1-pause-mixed.other";
  name_v[g1_mixed_other_choose_cset_idx] = "g1-pause-mixed.other.choose-cset";
  name_v[g1_mixed_other_ref_proc_idx] = "g1-pause-mixed.other.ref-proc";
  name_v[g1_mixed_other_ref_enq_idx] = "g1-pause-mixed.other.reg-enq";
  name_v[g1_mixed_other_free_cset_idx] = "g1-pause-mixed.other.free-cset";
  name_v[g1_mixed_cpu_sys_idx] = "g1-mixed-cpu.sys";
  name_v[g1_mixed_cpu_usr_idx] = "g1-mixed-cpu.usr";
  name_v[g1_mixed_cpu_real_idx] = "g1-mixed-cpu.real";
  name_v[g1_eden_occupancy_before_gc_idx] = "g1-eden-occupancy-before-gc";
  name_v[g1_eden_capacity_before_gc_idx] = "g1-eden-capacity-before-gc";
  name_v[g1_eden_occupancy_after_gc_idx] = "g1-eden-occupancy-after-gc";
  name_v[g1_eden_capacity_after_gc_idx] = "g1-eden-capacity-after-gc";
  name_v[g1_survivor_before_gc_idx] = "g1-survivor-before-gc";
  name_v[g1_survivor_after_gc_idx] = "g1-survivor-after-gc";
  name_v[g1_heap_occupancy_before_gc_idx] = "g1-heap-occupancy-before-gc";
  name_v[g1_heap_capacity_before_gc_idx] = "g1-heap-capacity-before-gc";
  name_v[g1_heap_occupancy_after_gc_idx] = "g1-heap-occupancy-after-gc";
  name_v[g1_heap_capacity_after_gc_idx] = "g1-heap-capacity-after-gc";

  name_v[cmsIM_idx]	= "cmsIM";
  name_v[cmsRM_idx]	= "cmsRM";
  name_v[cmsRS_idx]	= "cmsRS";
  name_v[totgc_idx]	= "GCPause";
  name_v[cmsCM_idx]	= "cmsCM";
  name_v[cmsCP_idx]	= "cmsCP";
  name_v[cmsCS_idx]	= "cmsCS";
  name_v[cmsCR_idx]	= "cmsCR";
  name_v[MB_a_idx]	= "alloc";
  name_v[MB_p_idx]	= "promo";
  name_v[MB_used0_idx]	= "used0";
  name_v[MB_used1_idx]	= "used1";
  name_v[MB_usedh_idx]	= "used";
  name_v[MB_used0AfterGC_idx]	= "used0AfterGC";
  name_v[MB_used1AfterGC_idx]	= "used1AfterGC";
  name_v[MB_usedhAfterGC_idx]	= "usedAfterGC";
  name_v[MB_c0_idx]	= "commit0";
  name_v[MB_c1_idx]	= "commit1";
  name_v[MB_ch_idx]	= "commit";
  name_v[safept_idx]	= "safept";
  name_v[apptime_idx]	= "apptime";

  name_v[PO_precomp_idx]	= "precomp";
  name_v[PO_marking_idx]	= "marking";
  name_v[PO_parmark_idx]	= "parmark";
  name_v[PO_mark_flush_idx]	= "mark-f";
  name_v[PO_summary_idx]	= "summary";
  name_v[PO_adjroots_idx]	= "adjroots";
  name_v[PO_permgen_idx]	= "permgen";
  name_v[PO_compact_idx]	= "compact";
  name_v[PO_drain_ts_idx]	= "drain_ts";
  name_v[PO_dpre_ts_idx]	= "dpre_ts";
  name_v[PO_steal_ts_idx]	= "steal_ts";
  name_v[PO_parcomp_idx]	= "parcomp";
  name_v[PO_deferred_idx]	= "deferred";
  name_v[PO_postcomp_idx]	= "postcomp";

  for (i = 0; i < last_idx; ++i) {
    count_v[i] = 0;
    sum_v[i] = 0.0;
    max_v[i] = 0.0;
    sum_of_sq_v[i] = 0.0;
    name_v[last_idx + i] = name_v[i];	# Copy names.
  }

#  plot_idx = -1;
  requested_plot_count = 0;
  available_plot_count = 0;
  if (plot != "") {
      requested_plot_count = split(plot,plots,",");
    }
    # Convert the plot=name value to a plot_idx.  The default is no plotting,
    # which occurs when plot_idx < 0.
    for (i = 1; i <= requested_plot_count; i++) {
      for (j = 0; j < last_idx ; ++j) {
        if(plots[i] == name_v[j]) {
         available_plot_count += 1; 
         plot_idx[j] = "True" ;
        }
      }
    } 

    if (available_plot_count == 0) {
      print "PrintGCStats:  unrecognized plot name plot=" plot ".";
      print usage_msg;
      exit(1);
    }

  # If plotting, set plot_columns based on the statistic being plotted (unless
  # plotcolumns was set on the command line).
  if (available_plot_count > 0) {
    for (i = 0; i < last_idx; ++i) {
      if (plotcolumns > 0) {
        plot_columns[i] = plotcolumns;
      } else {
        if (i >= MB_a_idx && i <= MB_ch_idx) {
          # Use 2 columns for size-based statistics.
          plot_columns[i] = 2;
        } else {
          # Use 4 columns for time-based statistics.
          plot_columns[i] = 4;
        }
      }
    }
  }

  # Heap sizes at the start & end of the last gen0 collection.
  gen0_sizes[0] = 0.0;
  gen0_sizes[1] = 0.0;
  gen0_sizes[2] = 0.0;

  initIntervalVars();

  last_cmsRcount = 0;
  printFirstHeader = 1;

  # Six columns:  name, count, total, mean, max, standard deviation
  headfmt = "%-11s" "  %7s" "  %13s"   "  %12s"   "  %12s"   "  %9s"   "\n";
  datafmt = "%-11s" "  %7d" "  %13.3f" "  %12.5f" "  %12.3f" "  %9.4f" "\n";

  # Frequently-used regular expressions.
  # These are replicated in PrintGCFixup; keep them in sync.
  full_gc_re		= "\\[Full GC (\\(System\\) )?";
  heap_size_re		= "[0-9]+[KMG]";				# 8K
  heap_size_paren_re	= "\\(" heap_size_re "\\)";		# (8K)
  heap_size_change_re	= heap_size_re "->" heap_size_re;	# 8K->4K
  # 8K->4K(96K), or 8K->4K (96K)
  heap_size_status_re	= heap_size_change_re " ?" heap_size_paren_re;

  gc_time_re		= "[0-9]+\\.[0-9]+";
  gc_time_secs_re	= gc_time_re " secs";
  gc_time_ms_re		= gc_time_re " ms";
  timestamp_re		= "(" gc_time_re ": *)?";
  timestamp_range_re	= "(" gc_time_re "-" gc_time_re ": *)?";

  # Heap size status plus elapsed time:  8K->4K(96K), 0.0517089 secs
  heap_report_re	= heap_size_status_re ", " gc_time_secs_re;

  # Size printed at CMS initial mark and #remark.
  cms_heap_size_re	= heap_size_re heap_size_paren_re;	# 6K(9K)
  cms_heap_report_re	= cms_heap_size_re ", " gc_time_secs_re;
  cms_concurrent_phase_re = "(AS)?CMS-concurrent-(mark|(abortable-)?preclean|sweep|reset)";

  # Generations which print optional messages.
  promo_failed_re	= "( \\(promotion failed\\))?"
  cms_gen_re		= "(AS)?CMS( \\(concurrent mode failure\\))?";
  parnew_gen_re		= "(AS)?ParNew";
  # 'Framework' GCs:  DefNew, ParNew, Tenured, CMS
  fw_yng_gen_re		= "(DefNew|" parnew_gen_re ")" promo_failed_re;
  fw_old_gen_re		= "(Tenured|" cms_gen_re ")";

  # Garbage First (G1) pauses:
  #    [GC pause (young), 0.0082 secs]
  # or [GC pause (partial), 0.082 secs]
  # or [GC pause (young) (initial mark), 0.082 secs]
  # or [GC remark, 0.082 secs]
  # or [GC cleanup 11M->11M(25M), 0.126 secs]
  g1_gc_ms_re = "[0-9]+\\.[0-9]+ ms";
  g1_gc_stats_re =  "Min: [0-9]+[.0-9]+, Avg: [0-9]+[.0-9]+, Max: [0-9]+[.0-9]+, Diff: [0-9]+[.0-9]+, Sum: [0-9]+[.0-9]+";
  g1_gc_stats_alt_re =  "Min: [0-9]+[\\.0-9]+, Avg: [0-9]+[\\.0-9]+, Max: [0-9]+[\\.0-9]+, Diff: [0-9]+[\\.0-9]+";
  g1_stats_value_re = "[0-9]+[.0-9]+";
  g1_cpu_times_re = "\\[Times: user=" g1_stats_value_re " sys=" g1_stats_value_re ", real=" g1_stats_value_re " secs\\]";
  g1_avg_stats_re = "Avg: [0-9]+[.0-9]+";
  g1_max_stats_re = "Max: [0-9]+[.0-9]+";

  g1_parallel_re = "\\[Parallel Time: " gc_ms_re ", GC Workers: [0-9]+\\]";
  g1_parallel_gc_worker_start_re = "\\[GC Worker Start \\(ms\\): " g1_gc_stats_alt_re "\\]";
  g1_parallel_ext_root_scanning_re = "\\[Ext Root Scanning \\(ms\\): " g1_gc_stats_re "\\]";
  g1_parallel_update_rs_re = "\\[Update RS \\(ms\\): " g1_gc_stats_re "\\]";
  g1_parallel_update_rs_processed_buffer_re = "\\[Processed Buffers: " g1_gc_stats_re "\\]";
  g1_parallel_scan_rs_re = "\\[Scan RS \\(ms\\): " g1_gc_stats_re "\\]";
  g1_parallel_object_copy_rs_re = "\\[Object Copy \\(ms\\): " g1_gc_stats_re "\\]";
  g1_parallel_termination_re = "\\[Termination \\(ms\\): " g1_gc_stats_re "\\]";
  g1_parallel_gc_worker_other_re = "\\[GC Worker Other \\(ms\\): " g1_gc_stats_re "\\]";
  g1_parallel_gc_worker_total_re = "\\[GC Worker Total (ms): " g1_gc_stats_re "\\]";
  g1_parallel_gc_worker_end_re = "\\[GC Worker End \\(ms\\): " g1_gc_stats_alt_re "\\]";
  g1_code_root_fixup_re = "\\[Code Root Fixup: " g1_gc_ms_re "\\]";
  g1_clear_ct_re = "\\[Clear CT: " g1_gc_ms_re "\\]";
  g1_other_re = "\\[Other: " g1_gc_ms_re "\\]";
  g1_other_choose_cset_re = "\\[Choose CSet: " g1_gc_ms_re "\\]";
  g1_other_ref_proc_re = "\\[Ref Proc: " g1_gc_ms_re "\\]";
  g1_other_ref_enq_re = "\\[Ref Enq: " g1_gc_ms_re "\\]";
  g1_other_free_cset_re = "\\[Free CSet: " g1_gc_ms_re "\\]";
  g1_cleanup_re		= "cleanup " heap_size_status_re;
  g1_young_pause_re		= "pause \\(young\\)";
  g1_young_pause_re		= g1_young_pause_re "( \\((initial-mark|evacuation failed)\\))?";
  g1_mixed_pause_re = "pause \\(mixed\\)";
  g1_remark_re = "remark ";
  g1_remark_refproc_re = "\\[GC ref-proc, " gc_time_secs_re "\\]";
  g1_young_stw_re	= "\\[GC " g1_young_pause_re ", " gc_time_secs_re "\\]";
  g1_mixed_stw_re = "\\[GC " g1_mixed_pause_re ", " gc_time_secs_re "\\]";
  g1_cleanup_stw_re = "\\[GC " g1_cleanup_re ", " gc_time_secs_re "\\]";
  g1_remark_stw_re = "\\[GC " g1_remark_re ".*" g1_remark_refproc_re ", " gc_time_secs_re "\\]";
  g1_heap_size_re = "[0-9]+[.0-9]+[BKMG]";
  g1_eden_size_re =  "\\[Eden: " g1_heap_size_re "\\(" g1_heap_size_re "\\)->" g1_heap_size_re "\\(" g1_heap_size_re "\\)";
  g1_survivors_size_re = "Survivors: " g1_heap_size_re "->" g1_heap_size_re;
  g1_total_heap_size_re = "Heap: " g1_heap_size_re "\\(" g1_heap_size_re "\\)->" g1_heap_size_re "\\(" g1_heap_size_re "\\)";
  g1_heap_size_summary_re = "\\[Eden: " g1_heap_size_re "\\(" g1_heap_size_re "\\)->" g1_heap_size_re "\\(" g1_heap_size_re "\\) Survivors: " g1_heap_size_re "->" g1_heap_size_re " Heap: " g1_heap_size_re "\\(" g1_heap_size_re "\\)->" g1_heap_size_re "\\(" g1_heap_size_re "\\)\\]";
}

function initIntervalVars() {
  for (i = 0; i < last_idx; ++i) {
    count_v[last_idx + i] = 0;
    sum_v[last_idx + i] = 0.0;
    max_v[last_idx + i] = 0.0;
    sum_of_sq_v[last_idx + i] = 0.0;
  }
}

function ratio(dividend, divisor) {
  result = 0.0;
  if (divisor != 0.0) {
    result = dividend / divisor;
  }
  return result;
}

function stddev(count, sum, sum_of_squares) {
  if (count < 2) return 0.0;
  sum_squared_over_count = (sum * sum) / count;
  # This has happened on occasion--not sure why--but only for total gc time,
  # which includes samples from different populations.
  if (sum_of_squares < sum_squared_over_count) return -1.0;
#  print "stddev", count, sum, sum_of_squares, sum_squared_over_count;
  return sqrt((sum_of_squares - sum_squared_over_count) / (count - 1));
}

function printHeader() {
  printf(headfmt, "what", "count", "total", "mean", "max", "stddev");
}

function printData(idx) {
  cnt = count_v[idx];
  sec = sum_v[idx];
  sd = stddev(cnt, sec, sum_of_sq_v[idx]);
  printf(datafmt, name_v[idx], cnt, sec, ratio(sec, cnt), max_v[idx], sd);
}

function printRate(name, tot, tot_units, period, period_units) {
  printf("%-21s = %10.3f %-2s / %10.3f %-2s = %7.3f %s/%s\n",
    name, tot, tot_units, period, period_units, ratio(tot, period),
    tot_units, period_units);
}

function printPercent(name, tot, tot_units, period, period_units) {
  printf("%-21s = %10.3f %-2s / %10.3f %-2s = %7.3f%%\n",
    name, tot, tot_units, period, period_units, ratio(tot * 100.0, period));
}

function getDateTimeStamp() {
#2012-02-23T22:17:02.495
  gts_tmp_str = $0;
  if (!match(gts_tmp_str,"^[0-9][0-9][0-9][0-9]-[0-9][0-9]-[0-9][0-9]T[0-9][0-9]:[0-9][0-9]:[0-9][0-9].[0-9]+")) return -1.0;
  gts_tmp = substr(gts_tmp_str, RSTART, RLENGTH);
  sub(/T/, " ", gts_tmp);
  return gts_tmp;
}

function getTimeStamp() {
  gts_tmp_str = $0;
  # Note:  want to match the time stamp just before the '[GC' or '[Full GC' or
  # '[CMS-' string on the line, and there may be time stamps that appear
  # earlier.  Thus there is no beginning-of-line anchor ('^') in the regexp used
  # with match().
  if (sub(/:? ? ?\[((Full )?GC|(AS)?CMS-).*/, "", gts_tmp_str) != 1) return -1.0;
  if (! match(gts_tmp_str, "[0-9]+\\.[0-9]+(e[+-][0-9]+)?$")) return -1.0;

  gts_tmp = substr(gts_tmp_str, RSTART, RLENGTH) + 0.0;
  return gts_tmp;
}

function getNestedValue(inputString, regexOuter, regexInner) {
  match(inputString, regexOuter);
  extractedOuterString = substr(inputString, RSTART, RLENGTH);
  #print extractedOuterString;
  if (regexOuter == regexInner) {
  	return extractedOuterString;
  }
  match(extractedOuterString, regexInner);
  extractedInnerString = substr(extractedOuterString, RSTART, RLENGTH);
  #print extractedInnerString;
  return extractedInnerString;
}

function recordStatsInternal(idx, seconds) {
  count_v[idx] += 1;
  sum_v[idx] += seconds;
  sum_of_sq_v[idx] += seconds * seconds;
  if (seconds > max_v[idx]) max_v[idx] = seconds;
}

function writePlotData(tstamp, value, widx) {
  if (splitfileprefix == "") {
    splitfileprefix = "GC";
  }
  if (plot_columns[widx] == 4) {
    # Column 1 = start time, 2 = duration, 3 = end time, 4 = duration.
    #printf("%9.7f %9.7f %9.7f %9.7f\n", tstamp, value, tstamp + value, value);
    if (splitfiles == 1) {
      if (datestamps == 1) {
        printf("%s,%9.7f,%s,%9.7f\n", tstamp, value, tstamp, value) >> (splitfileprefix "." name_v[widx] ".csv");
        close((splitfileprefix "." name_v[widx] ".csv"));
      } else {
        printf("%9.3f,%9.7f,%9.3f,%9.7f\n", tstamp, value, tstamp + value, value) >> (splitfileprefix "." name_v[widx] ".csv");
        close((splitfileprefix "." name_v[widx] ".csv"));
      }
    } else {
      if (datestamps == 1) {
        printf("%s,%9.7f,%s,%9.7f,%s\n", tstamp, value, tstamp, value, name_v[widx]);
      } else {
        printf("%9.3f,%9.7f,%9.3f,%9.7f,%s\n", tstamp, value, tstamp + value, value, name_v[widx]);
      }
    }
    return;
  }
  if (plot_columns[widx] == 2) {
    # Column 1 = start time, 2 = value.
    # printf("%9.7f %9.7f\n", tstamp, value);
    if (splitfiles == 1) {
      if (datestamps == 1) {
        printf("%s,%9.7f\n", tstamp, value) >> (splitfileprefix "." name_v[widx] ".csv");
        close((splitfileprefix "." name_v[widx] ".csv"));
      } else {
        printf("%9.3f,%9.7f\n", tstamp, value) >> (splitfileprefix "." name_v[widx] ".csv");
        close((splitfileprefix "." name_v[widx] ".csv"));
      }
    } else {
      if (datestamps == 1) {
        printf("%s,%9.7f,%s\n", tstamp, value, name_v[widx]);
      } else {
        printf("%9.3f,%9.7f,%s\n", tstamp, value, name_v[widx]);
      }
    }
    return;
  }
  if (plot_columns[widx] == 1) {
    # Column 1 = start time.
    # printf("%9.7f\n", tstamp);
    if (splitfiles == 1) {
      if (datestamps == 1) {
        printf("%s\n", tstamp) >> (splitfileprefix "." name_v[widx] ".csv");
        close((splitfileprefix "." name_v[widx] ".csv"));
      } else {
        printf("%9.3f\n", tstamp) >> (splitfileprefix "." name_v[widx] ".csv");
        close((splitfileprefix "." name_v[widx] ".csv"));
      }
    } else {
      if (datestamps == 1) {
        printf("%s,%s\n", tstamp, name_v[widx]);
      } else {
        printf("%9.3f,%s\n", tstamp, name_v[widx]);
      }
    }
    return;
  }
  if (plot_columns[widx] == 3) {
    # Column 1 = start time, 2 = duration, 3 = end time.
    # printf("%9.7f %9.7f %9.7f\n", tstamp, value, tstamp + value);
    if (splitfiles == 1) {
      if (datestamps == 1) {
        printf("%s,%9.7f,%s\n", tstamp, value, tstamp) >> (splitfileprefix "." name_v[widx] ".csv");
        close((splitfileprefix "." name_v[widx] ".csv"));
      } else {
        printf("%9.3f,%9.7f,%9.3f\n", tstamp, value, tstamp + value) >> (splitfileprefix "." name_v[widx] ".csv");
        close((splitfileprefix "." name_v[widx] ".csv"));
      }
    } else {
      if (datestamps == 1) {
        printf("%s,%9.7f,%s,%s\n", tstamp, value, tstamp, name_v[widx]);
      } else {
        printf("%9.3f,%9.7f,%9.3f,%s\n", tstamp, value, tstamp+value, name_v[widx]);
      }
    }
    return;
  }
}

function recordStats(idx, value) {
  if (verbose) print name_v[idx] ":" NR ":" value;
  if (available_plot_count == 0) {
    # Plotting disabled; record statistics.
    recordStatsInternal(idx, value);
    recordStatsInternal(idx + last_idx, value);
    if (idx < totgc_idx) recordStatsInternal(totgc_idx, value);
  } else if (idx in plot_idx || (totgc_idx in plot_idx && idx < totgc_idx)) {
    # Plotting enabled; skip statistics and just print a plot line.
    if (datestamps == 1) {
      rs_tstamp = getDateTimeStamp();
    } else {
      rs_tstamp = getTimeStamp();
    }
    if (rs_tstamp != -1) {
      writePlotData(rs_tstamp, value, idx);
      if (totgc_idx in plot_idx && idx < totgc_idx && idx != gen0c_idx) {
        writePlotData(rs_tstamp, value, totgc_idx);
      }
    }
  }
}

function parseHeapSizes(sizes, str) {
  sizes[0] = sizes[1] = 0.0;

  if (!match(str, heap_size_re "->")) return -1;
  sizes[0] = substr(str, RSTART, RLENGTH - 3) + 0.0;
  if (substr(str, RSTART + RLENGTH - 3, 1) == "K") {
	  sizes[0] = sizes[0] / 1024.0;
  }

  if (!match(str, "[KM]->" heap_size_re)) return -1;
  sizes[1] = substr(str, RSTART + 3, RLENGTH - 4) + 0.0;
  if (substr(str, RSTART, 1) == "K") {
	  sizes[1] = sizes[1] / 1024.0;
  }

  if (!match(str, heap_size_paren_re)) return -1;
  sizes[2] = substr(str, RSTART + 1, RLENGTH - 3) + 0.0;
  if (substr(str, RSTART + RLENGTH - 2, 1) == "K") {
	  sizes[2] = sizes[2] / 1024.0;
  }

  return 0;
}

function recordHeapKb(str) {
  if (parseHeapSizes(tmp_mb, str) < 0) return;
  recordStats(MB_a_idx, tmp_mb[0] - gen0_sizes[1]);
  # Occupancy (the before gc value is used).
  recordStats(MB_usedh_idx, tmp_mb[0]);
  # Total heap committed size.
  recordStats(MB_ch_idx, tmp_mb[2]);

  gen0_sizes[0] = tmp_mb[0];
  gen0_sizes[1] = tmp_mb[1];
  gen0_sizes[2] = tmp_mb[2];
}

function recordGen0Kb(str, allow_3_sizes) {
  # Allocation info.
  if (parseHeapSizes(tmp_mb, str) < 0) { return; }
  str = substr(str, RSTART + RLENGTH);
#  print $0;
#  print tmp_mb[0],tmp_mb[1],gen0_sizes[0],gen0_sizes[1];
  recordStats(MB_used0_idx, tmp_mb[0]);
  recordStats(MB_used0AfterGC_idx, tmp_mb[1]);
  recordStats(MB_a_idx, tmp_mb[0] - gen0_sizes[1]);
  # Gen0 committed size.
  recordStats(MB_c0_idx, tmp_mb[2]);

  gen0_sizes[0] = tmp_mb[0];
  gen0_sizes[1] = tmp_mb[1];
  gen0_sizes[2] = tmp_mb[2];

  # If there isn't a second heap size figure (4096K->1024K) on the line,
  # promotion and occupancy info aren't available.
  if (parseHeapSizes(tmp_mb, str) < 0) return;

  # Promotion info.  Amount promoted is inferred from the last nnnK->nnnK
  # on the line, taking into account the amount collected:
  # 
  # promoted = change-in-overall-heap-occupancy - change-in-gen0-occupancy -
  #   change-in-gen1-occupancy
  #
  str = substr(str, RSTART + RLENGTH);
  if (match(str, heap_size_change_re) && allow_3_sizes) {
    # There is a 3rd heap size on the line; the 2nd one just parsed is assumed
    # to be from the old gen.  Get the 3rd one and use that for the overall
    # heap.
    gen1_sizes[0] = tmp_mb[0];
    gen1_sizes[1] = tmp_mb[1];
    gen1_sizes[2] = tmp_mb[2];
    parseHeapSizes(tmp_mb, str);
    mb_promo = tmp_mb[1] - tmp_mb[0] - (gen0_sizes[1] - gen0_sizes[0]);
    mb_promo -= (gen1_sizes[1] - gen1_sizes[0]);
  } else {
    # Only gen0 was collected.
    mb_promo = tmp_mb[1] - tmp_mb[0] - (gen0_sizes[1] - gen0_sizes[0]);
  }
  recordStats(MB_p_idx, mb_promo);
  # Occupancy (the before gc value is used).
  recordStats(MB_usedh_idx, tmp_mb[0]);
  recordStats(MB_usedhAfterGC_idx, tmp_mb[1]);
  # Total heap committed size.
  recordStats(MB_ch_idx, tmp_mb[2]);
  # Gen1 committed size.
  recordStats(MB_c1_idx, tmp_mb[2] - gen0_sizes[2]);
}

function recordParOldPhaseTime(str, phase_label, idx) {
	sub(".*" phase_label " *[,:] *", "", str);
	sub(" secs\\].*", "", str);
	recordStats(idx, str + 0.0);
}

function printInterval() {
  # No intervals if plotting.
  if (available_plot_count > 0) return;

  # Check for a time stamp.
  pi_tmp = getTimeStamp();
  if (pi_tmp < 0.0) return;

  # Update the global time stamp vars.
  if (lastFileName == FILENAME) {
    lastTimeStamp = timeStampOffset + pi_tmp;
  } else {
    if (firstTimeStamp < 0) {
      # First call of the run; initialize.
      lastTimeStamp = pi_tmp;
      firstTimeStamp = prevTimeStamp = lastTimeStamp;
    } else {
      # First call after the input file changed.
      timeStampOffset = lastTimeStamp;
      lastTimeStamp = timeStampOffset + pi_tmp;
    }
    lastFileName = FILENAME;
#     printf("%10.3f %10.6f %s %s\n", timeStampOffset, pi_tmp,
#       pi_tmp_str, FILENAME);
  }

  # Print out the statistics every timeStampDelta seconds.
  if (timeStampDelta < 0) return;
  if ((lastTimeStamp - prevTimeStamp) > timeStampDelta) {
    prevTimeStamp = lastTimeStamp;
    if ((printFirstHeader == 1) ||
    ((last_cmsRcount == 0) && (count_v[cmsRM_idx] != 0))) {
      printf("Incremental statistics at %d second intervals\n", timeStampDelta);
      printHeader();
      last_cmsRcount = count_v[cmsRM_idx];
      printFirstHeader = 0;
    }

    printf("interval=%d, time=%5.3f secs, line=%d\n",
      int((lastTimeStamp - firstTimeStamp) / timeStampDelta),
      lastTimeStamp, NR);
    for (i = 0; i < last_idx; ++i) {
      if (count_v[last_idx + i] > 0) {
	printData(last_idx + i);
      }
    }

    initIntervalVars();
  }
}

$0 ~ ".*\\[GC[^ ]+ .*" {
  sub(/GC[^ ]+/, "GC", $0);
}

$0 ~ ".* age .*" {
  next;
};

$0 ~ "Desired.*" {
  next;
};


$0 ~ ".*ParNew$" {
  parnew_prefix = $0;
  updateLog = 1;
  next;
};

updateLog == 1 {
  $0 = parnew_prefix$0;
  updateLog = 0;
  parnew_prefix = "";
}

$0 ~ "GC pause" {
  g1_prefix = $0;
  updateG1Log = 1;
  next;  
}

$0 ~ ".*real=.*" {
  if(updateG1Log == 1) {
    $0 = g1_prefix$0;
    updateG1Log = 0;
    g1_prefix = "";
  }
}

updateG1Log == 1 {
  g1_prefix = g1_prefix$0;
  next;
}

getDateTimeStamp() < ts_start {
   next;
}

getDateTimeStamp() > ts_end {
   exit;
}

$0 ~ ".*\\[GC remark [^\\[]+" {
  sub(/GC remark [^\[]+/, "GC remark ", $0);
  secs = $(NF-1);
  recordStats(g1_remark_idx, secs);
  match($0, g1_remark_refproc_re);
  split(substr($0, RSTART , RLENGTH),recprof," ");
  secs = recprof[3]; 
  recordStats(g1_remark_refproc_idx, secs);
  printInterval();
  next;
}


# Match CMS initial mark output from PrintGCDetails.
# 
#    [GC [1 CMS-initial-mark: 14136K(23568K)] 14216K(25680K), 0.0062443 secs]
#
#/\[GC \[1 (AS)?CMS-initial-mark: [0-9]+K\([0-9]+K\)\] [0-9]+K\([0-9]+K\), [0-9][0-9.]* secs\]/ {
# /\[1 (AS)?CMS-initial-mark: [0-9]+K\([0-9]+K\)\] [0-9]+K\([0-9]+K\), [0-9][0-9.]* secs\]/ {
#
match($0, "\\[1 (AS)?CMS-initial-mark: " cms_heap_size_re "\\] " cms_heap_report_re "\\]") {
# print "	>> cht 1. line ", FNR, $0;
  tString = substr($0, RSTART, RLENGTH);
  match(tString, gc_time_secs_re);
  secs = substr(tString, RSTART, RLENGTH - 5) + 0;
  recordStats(cmsIM_idx, secs);
  next;
}

# Match cms remark output from PrintGCDetails.
#[GC[dirty card accumulation, 0.0006214 secs][dirty card rescan, 0.1919700 secs] [1 CMS-remark: 10044K(16744K)] 10412K(18856K), 0.2095526 secs]
#
# /\[GC.*CMS-remark.*, [0-9][0-9.]*\ secs\]/ {
# /\[1 CMS-remark.*, [0-9][0-9.]*\ secs\]/ {
# /\[1 (AS)?CMS-remark: [0-9]+K\([0-9]+K\)\] [0-9]+K\([0-9]+K\), [0-9][0-9.]* secs\]/ {
match($0, "\\[1 (AS)?CMS-remark: " cms_heap_size_re "\\] " cms_heap_report_re "\\]") {
# print "	>> cht 2. line ", FNR, $0;
  tString = substr($0, RSTART, RLENGTH);
  match(tString, gc_time_secs_re);
  secs = substr(tString, RSTART, RLENGTH - 5) + 0;
  recordStats(cmsRM_idx, secs);
  # recordStats incremented the total gc count; undo that.
  count_v[totgc_idx] -= 1;
  next;
}

# Match CMS initial mark or remark output from -verbose:gc.
#
# [GC 43466K(68920K), 0.0002577 secs]
match($0, "\\[GC " cms_heap_report_re "\\]") {
# print "	>> cht 3. line ", FNR, $0;
  match($0, gc_time_secs_re);
  secs = substr($0, RSTART, RLENGTH - 5) + 0;
  recordStats(gen1t_idx, secs);
  # XXX - this updates the count of gen1 collections for both initial mark and
  # remark.  Would like to update it only once per cms cycle (i.e., for initial
  # mark only).  Doing the increment every other time would be more accurate,
  # but still subject to error because of aborted CMS cycles.
  next;
}

# Match cms concurrent phase output
# [CMS-concurrent-mark: 6.422/9.360 secs]
# 10820.4: [CMS-concurrent-mark: 6.422/9.360 secs]
# /\[(AS)?CMS-concurrent-(mark|preclean|sweep|reset): [0-9.]+\/[0-9.]+ secs\]/ {
$0 ~ "\\[" cms_concurrent_phase_re ": " gc_time_re "/" gc_time_secs_re "\\]" {
# print "	>> cht 4. line ", FNR, $0;
  match($0, cms_concurrent_phase_re ": ");	
  t_time_idx = RSTART + RLENGTH;
  tString = substr($0, RSTART, RLENGTH);
  if (match(tString, "-mark:")) {
    tIdx = cmsCM_idx;
  } else if (match(tString, "-sweep:")) {
    tIdx = cmsCS_idx;
  } else if (match(tString, "-preclean:")) {
    tIdx = cmsCP_idx;
  } else {
    tIdx = cmsCR_idx;
  }
  tString = substr($0, t_time_idx);
  match(tString, "/" gc_time_secs_re);
  secs = substr(tString, 1, RSTART - 1) + 0.0;
  recordStats(tIdx, secs);
  printInterval(); # Must do this before the getline below.

  if (match($0, "\\[(AS)?CMS" timestamp_re "\\[" cms_concurrent_phase_re)) {
    # If CMS is in the middle of a concurrent phase when System.gc() is called
    # or concurrent mode failure causes a bail out to mark-sweep,
    # the output is split across 2 lines, e.g.:
    #
    # 164.092: [Full GC 164.093: [CMS164.341: [CMS-concurrent-mark: 0.302/0.304 secs]
    # : 26221K->24397K(43704K), 0.8347158 secs] 26285K->24397K(64952K), [CMS Perm : 2794K->2794K(16384K)], 0.8350998 secs]
    #
    getline;
    tString = $0;
    tInt = sub(".*" heap_size_status_re "\\]?, ", "", tString);
    tInt += sub(" secs.*", "", tString);
    if (tInt == 2) {
      secs = tString + 0.0;
      recordStats(gen1t_idx, secs);
    }
  }
  next;
}

# Match PrintGCDetails output for Tenured or CMS full GC
# [GC [DefNew: 2048K->64K(2112K), 0.1517089 secs][Tenured: 1859K->1912K(1920K), 0.1184458 secs] 2048K->1923K(4032K), 0.2710333 secs]
#	or with time stamps
# 0.177656: [GC 0.177728: [DefNew: 2112K->0K(2176K), 0.1006331 secs]0.278442: [Tenured: 4092K->4092K(4208K), 0.1372500 secs] 4096K->4092K(6384K), 0.2385750 secs]
# 549.281: [GC 549.281: [ParNew: 14783K->14783K(14784K), 0.0000680 secs]549.281: [CMS: 275188K->136280K(290816K), 3.7791360 secs] 289972K->136280K(305600K), 3.7795440 secs]
# 25.980: [GC 25.980: [DefNew: 18526K->1418K(19392K), 0.0044480 secs]25.984: [Tenured: 42903K->13507K(43008K), 0.0665290 secs] 61060K->13507K(62400K), [Perm : 16268K->16268K(16384K)], 0.0710530 secs] [Times: user=0.07 sys=0.00, real=0.07 secs] 
# 
# /\[GC.*\[(DefNew|(AS)?ParNew): [0-9]+K->[0-9]+K\([0-9]+K\),.*secs\].*\[((AS)?CMS|Tenured): [0-9]+K->[0-9]+K\([0-9]+K\),.*secs\]/ {
#
# [GC [ParNew: 7812K->7812K(8128K), 0.0000310 secs][CMS (concurrent mode failure): 382515K->384858K(385024K), 0.0657172 secs] 390327K->390327K(393152K), 0.0658860 secs]
#
$0 ~ "\\[GC.*\\[" fw_yng_gen_re ": " heap_report_re "\\].*\\[" fw_old_gen_re ": " heap_report_re "\\]" {
# print "	>> cht 5. line ", FNR, $0;
  tString = $0;
  tInt = sub(".*\\[" fw_old_gen_re ": " heap_size_status_re ", ", "", tString);
  tInt = sub(" secs.*", "", tString);
  secs = tString + 0.0;
  recordStats(gen1t_idx, secs);

  # Old gen occupancy before GC.
  tString = $0;
  tInt = sub(".*\\[" fw_old_gen_re ": ", "", tString);
  parseHeapSizes(tmp_mb, tString);
  recordStats(MB_used1_idx, tmp_mb[0]);
  recordStats(MB_used1AfterGC_idx, tmp_mb[1]);

  # Heap occupancy before GC.
  tInt = sub(heap_report_re "\\] ", "", tString);
  parseHeapSizes(tmp_mb, tString);
  recordStats(MB_usedh_idx, tmp_mb[0]);
  recordStats(MB_usedhAfterGC_idx, tmp_mb[1]);

  printInterval();
  next;
}

# [Full GC [Tenured: 43464K->43462K(43712K), 0.0614658 secs] 63777K->63775K(64896K), [Perm : 1460K->1459K(16384K)], 0.0615839 secs]
# 
# 0.502: [Full GC 0.502: [Tenured: 43464K->43462K(43712K), 0.0724391 secs] 63777K->63775K(64896K), [Perm : 1460K->1459K(16384K)], 0.0725792 secs]

$0 ~ full_gc_re timestamp_re ".*\\[" fw_old_gen_re ": " heap_report_re "\\] " heap_size_status_re ", \\[((AS)?CMS )?Perm *: " heap_size_status_re "\\], " gc_time_secs_re "\\]" {
# print "	>> cht 6. line ", FNR, $0;
  tString = $0;
  tInt = sub(".*" heap_size_status_re "\\], ", "", tString);
  tInt = sub(" secs.*", "", tString);
  secs = tString + 0.0;
  recordStats(gen1t_idx, secs);

  # Old gen occupancy before GC.
  tString = $0;
  tInt = sub(".*\\[" fw_old_gen_re ": ", "", tString);
  parseHeapSizes(tmp_mb, tString);
  recordStats(MB_used1_idx, tmp_mb[0]);
  recordStats(MB_used1AfterGC_idx, tmp_mb[1]);

  # Heap occupancy before GC.
  tInt = sub(heap_report_re "\\] ", "", tString);
  parseHeapSizes(tmp_mb, tString);
  recordStats(MB_usedh_idx, tmp_mb[0]);
  recordStats(MB_usedhAfterGC_idx, tmp_mb[1]);

  printInterval();
  next;
}

# Full GC (System.gc()) w/CMS when the perm gen is *not* being collected.
# 
#    [Full GC [ParNew: 161K->238K(12288K), 0.0014651 secs] 161K->238K(61440K), 0.0015972 secs]
#    0.178: [Full GC 0.178: [ParNew: 161K->238K(12288K), 0.0014651 secs] 161K->238K(61440K), 0.0015972 secs]
$0 ~ full_gc_re timestamp_re ".*\\[" fw_yng_gen_re ": " heap_report_re "\\] " heap_report_re "\\]" {
# print "	>> cht 7. line ", FNR, $0;
  match($0, ".*" heap_size_status_re ", ");
  tString = substr($0, RSTART + RLENGTH);
  tInt = sub(" secs.*", "", tString);
  secs = tString + 0.0;
  recordStats(gen1t_idx, secs);
  printInterval();
  next;
}

# Match PrintGCDetails output for Train incremental GCs.
/\[GC.*\[(Def|Par)New: [0-9]+K->[0-9]+K\([0-9]+K\),.*secs\].*\[Train: [0-9]+K->[0-9]+K\([0-9]+K\),.*secs\]/ {
# print "	>> cht 8. line ", FNR, $0;
  # Young gen part.
  tString = $0;
  tInt = sub(/ secs.*/, "", tString);
  tInt = sub(".*" heap_size_status_re "\\], ", "", tString);
  secs = tString + 0.0;
  recordStats(gen0t_idx, secs);

  # Train incremental part.
  tString = $0;
  tInt = sub(".*Train: [^,]+, ", "", tString);
  tInt = sub(" secs.*", "", tString);
  secs = tString + 0.0;
  if (available_plot_count == 0) {
    # Skip the update of the totgc numbers, that was handled above.
    recordStatsInternal(gen1i_idx, secs);
    recordStatsInternal(gen1i_idx + last_idx, secs);
  } else if (gen1i_idx in plot_idx) {
    recordStats(gen1i_idx, secs);
  }
  recordGen0Kb($0, 1);
  printInterval();
  next;
}

# Match PrintGCDetails output for Train Full GC.
/.*\[Train MSC: [0-9]+K->[0-9]+K\([0-9]+K\),.*secs\]/ {
# print "	>> cht 9. line ", FNR, $0;
  # Get the last number of seconds on the line.
  tString = $0;
  tInt = sub(".*" heap_size_status_re ", ", "", tString);
  tInt = sub(" secs.*", "", tString);
  secs = tString + 0.0;
  recordStats(gen1t_idx, secs);

  printInterval();
  next;
}

# Match PrintGCDetails output for DefNew or ParNew
#[GC [DefNew: 2880K->63K(2944K), 0.4626167 secs] 16999K->16999K(26480K), 0.4627703 secs]
#	or with time stamps
# 0.431984: [GC 0.432051: [DefNew: 2112K->0K(2176K), 0.0911555 secs] 6204K->6201K(9000K), 0.0912899 secs]
# /\[GC.*\[(DefNew|(AS)?ParNew): [0-9]+K->[0-9]+K\([0-9]+K\),.*secs\] [0-9]+K->[0-9]+K\([0-9]+K\),.*secs\]/ {
$0 ~ "\\[GC " timestamp_re "\\[" fw_yng_gen_re ": " heap_report_re "\\] " heap_report_re "\\]" {

# this matches ParNew of concurrent young gen
# print "	>> cht 10. line ", FNR, $0;
  # The first time on the line is for DefNew/ParNew gc work only.
  match($0, gc_time_secs_re);
  secs = substr($0, RSTART, RLENGTH - 5) + 0;
  tString = substr($0, RSTART + RLENGTH);

  if (available_plot_count == 0) {
    # Skip the update of the totgc numbers, that will be handled below.
    recordStatsInternal(gen0c_idx, secs);
    recordStatsInternal(gen0c_idx + last_idx, secs);
  } else if (gen0c_idx in plot_idx) {
    recordStats(gen0c_idx, secs);
  }

  # The second time is the total time, which includes prologue, epilogue and
  # safepoint time.
  match(tString, gc_time_secs_re);
  secs = substr(tString, RSTART, RLENGTH - 5) + 0;
  recordStats(gen0t_idx, secs);

  recordGen0Kb($0, 0);

  # The last 3 time are user, system, and wall clock time
  match($0, "Times: user=");
  if (RSTART > 0) {
    tString = substr($0, RSTART + RLENGTH);
    match(tString, gc_time_re);
    secs = substr(tString, RSTART, RLENGTH) + 0;
    recordStats(gen0usr_idx, secs);
    match(tString, "sys=");
    if (RSTART > 0) {
      tString = substr(tString, RSTART + RLENGTH);
      match(tString, gc_time_re);
      secs = substr(tString, RSTART, RLENGTH) + 0;
      recordStats(gen0sys_idx, secs);
    }
    match(tString, "real=");
    if (RSTART > 0) {
      tString = substr(tString, RSTART + RLENGTH);
      match(tString, gc_time_re);
      secs = substr(tString, RSTART, RLENGTH) + 0;
      recordStats(gen0real_idx, secs);
    }
  }
  printInterval();
  next;
}

# 17.438: [Full GC [PSYoungGen: 48K->0K(9536K)] [PSOldGen: 173K->179K(87424K)] 221K->179K(96960K) [PSPermGen: 1928K->1928K(16384K)], 0.0824100 secs]
# 17.438: [Full GC [PSYoungGen: 48K->0K(9536K)] [ParOldGen: 173K->179K(87424K)] 221K->179K(96960K) [PSPermGen: 1928K->1928K(16384K)], 0.0824100 secs]
$0 ~ full_gc_re "\\[PSYoungGen: +" heap_size_status_re "\\] \\[(PS|Par)OldGen: +" heap_size_status_re "\\] " heap_size_status_re " \\[PSPermGen: +" heap_size_status_re "\\], " gc_time_secs_re "\\]" {
# print "	>> cht 11. line ", FNR, $0;
  match($0, gc_time_secs_re);
  secs = substr($0, RSTART, RLENGTH - 5) + 0;
  recordStats(gen1t_idx, secs);

  # Old gen occupancy before GC.
  tString = $0;
  tInt = sub(".*\\[(PS|Par)OldGen: +", "", tString);
  parseHeapSizes(tmp_mb, tString);
  recordStats(MB_used1_idx, tmp_mb[0]);
  recordStats(MB_used1AfterGC_idx, tmp_mb[1]);

  # Heap occupancy before GC.
  tInt = sub(heap_size_status_re "\\] ", "", tString);
  parseHeapSizes(tmp_mb, tString);
  recordStats(MB_usedh_idx, tmp_mb[0]);
  recordStats(MB_usedhAfterGC_idx, tmp_mb[1]);

  printInterval();
  next;
}

# [GC [PSYoungGen: 1070K->78K(1091K)] 3513K->2521K(4612K), 0.2177698 secs]
$0 ~ "\\[GC(--)? \\[PSYoungGen: +" heap_size_status_re "\\] " heap_report_re "\\]" {
# print "	>> cht 12. line ", FNR, $0;
  match($0, gc_time_secs_re);
  secs = substr($0, RSTART, RLENGTH - 5) + 0;
  recordStats(gen0t_idx, secs);

  recordGen0Kb($0, 0);
  printInterval();
  next;
}

#	[GC[0: 511K->228K(1984K)], 0.0087278 secs]
# or	[GC[1: 308K->230K(1984K)], 0.0212333 secs]
# or 	[GC[0: 8313K->8313K(8944K)][1: 8313K->8313K(8944K)], 0.2044176 secs]
# but this only handles generations 0 and 1.
#/\[GC\[.*\], [0-9][0-9.]* secs\]/ {
/\[GC.*\[.*\], [0-9][0-9.]* secs\]/ {
# print "	>> cht 13. line ", FNR, $0;
  tString = $0;
  tInt = sub(".*, ", "", tString);
  tInt = sub(" secs.*", "", tString);
  secs = tString + 0.0;
  # If a line is for generation 1, we give it all the time.
  # If it is just for generation 0, we give that generation the time.
  if ($0 ~ /\[1: /) {
    recordStats(gen1t_idx, secs);
  } else if ($0 ~ /\[0: /) {
    recordStats(gen0c_idx, secs);
    recordGen0Kb($0, 0);
  }
  printInterval();
  next;
}

# Match Garbage-First output:
#    [GC pause (young), 0.0082 secs]
# or [GC pause (partial), 0.082 secs]
# or [GC pause (young) (initial mark), 0.082 secs]
# or [GC remark, 0.082 secs]
# or [GC cleanup 11M->11M(25M), 0.126 secs]
# /\[GC.*, [0-9][0-9.]* secs\]/ {
# $0 ~ g1_stw_re {
$0 ~ g1_young_stw_re {
# print "	>> cht 14. line ", FNR, $0;
  match($0, gc_time_secs_re);
  secs = substr($0, RSTART, RLENGTH - 5);
  recordStats(g1_young_idx, secs);
  recordStats(g1_young_parallel_idx, getNestedValue($0,("Parallel Time: " g1_gc_ms_re),"[0-9]+\\.[0-9]+"));  
  recordStats(g1_young_parallel_gc_workers_idx, getNestedValue($0,"GC Workers: [0-9]+","[0-9]+"));
  recordStats(g1_young_parallel_gc_worker_end_avg_idx, getNestedValue(getNestedValue($0, g1_parallel_gc_worker_start_re, g1_avg_stats_re), g1_stats_value_re, g1_stats_value_re));
  recordStats(g1_young_parallel_gc_worker_end_max_idx, getNestedValue(getNestedValue($0, g1_parallel_gc_worker_start_re, g1_max_stats_re), g1_stats_value_re, g1_stats_value_re)); 
  recordStats(g1_young_parallel_ext_root_scanning_avg_idx, getNestedValue(getNestedValue($0, g1_parallel_ext_root_scanning_re, g1_avg_stats_re), g1_stats_value_re, g1_stats_value_re));
  recordStats(g1_young_parallel_ext_root_scanning_max_idx, getNestedValue(getNestedValue($0, g1_parallel_ext_root_scanning_re, g1_max_stats_re), g1_stats_value_re, g1_stats_value_re));
  recordStats(g1_young_parallel_update_rs_avg_idx, getNestedValue(getNestedValue($0, g1_parallel_update_rs_re, g1_avg_stats_re), g1_stats_value_re, g1_stats_value_re)); 
  recordStats(g1_young_parallel_update_rs_max_idx, getNestedValue(getNestedValue($0, g1_parallel_update_rs_re, g1_max_stats_re), g1_stats_value_re, g1_stats_value_re));
  recordStats(g1_young_parallel_update_rs_processed_buffer_avg_idx, getNestedValue(getNestedValue($0, g1_parallel_update_rs_processed_buffer_re, g1_avg_stats_re), g1_stats_value_re, g1_stats_value_re)); 
  recordStats(g1_young_parallel_update_rs_processed_buffer_max_idx, getNestedValue(getNestedValue($0, g1_parallel_update_rs_processed_buffer_re, g1_max_stats_re), g1_stats_value_re, g1_stats_value_re));
  recordStats(g1_young_parallel_scan_rs_avg_idx, getNestedValue(getNestedValue($0, g1_parallel_scan_rs_re, g1_avg_stats_re), g1_stats_value_re, g1_stats_value_re));
  recordStats(g1_young_parallel_scan_rs_max_idx, getNestedValue(getNestedValue($0, g1_parallel_scan_rs_re, g1_max_stats_re), g1_stats_value_re, g1_stats_value_re));
  recordStats(g1_young_parallel_object_copy_rs_avg_idx, getNestedValue(getNestedValue($0, g1_parallel_object_copy_rs_re, g1_avg_stats_re), g1_stats_value_re, g1_stats_value_re));
  recordStats(g1_young_parallel_object_copy_rs_max_idx, getNestedValue(getNestedValue($0, g1_parallel_object_copy_rs_re, g1_max_stats_re), g1_stats_value_re, g1_stats_value_re));
  recordStats(g1_young_parallel_termination_avg_idx, getNestedValue(getNestedValue($0, g1_parallel_termination_re, g1_avg_stats_re), g1_stats_value_re, g1_stats_value_re));
  recordStats(g1_young_parallel_termination_max_idx, getNestedValue(getNestedValue($0, g1_parallel_termination_re, g1_max_stats_re), g1_stats_value_re, g1_stats_value_re));
  recordStats(g1_young_parallel_gc_worker_other_avg_idx, getNestedValue(getNestedValue($0, g1_parallel_gc_worker_other_re, g1_avg_stats_re), g1_stats_value_re, g1_stats_value_re));
  recordStats(g1_young_parallel_gc_worker_other_max_idx, getNestedValue(getNestedValue($0, g1_parallel_gc_worker_other_re, g1_max_stats_re), g1_stats_value_re, g1_stats_value_re));
  recordStats(g1_young_parallel_gc_worker_total_avg_idx, getNestedValue(getNestedValue($0, g1_parallel_gc_worker_total_re, g1_avg_stats_re), g1_stats_value_re, g1_stats_value_re));
  recordStats(g1_young_parallel_gc_worker_total_max_idx, getNestedValue(getNestedValue($0, g1_parallel_gc_worker_total_re, g1_max_stats_re), g1_stats_value_re, g1_stats_value_re));
  recordStats(g1_young_parallel_gc_worker_end_avg_idx, getNestedValue(getNestedValue($0, g1_parallel_gc_worker_end_re, g1_avg_stats_re), g1_stats_value_re, g1_stats_value_re));
  recordStats(g1_young_parallel_gc_worker_end_max_idx, getNestedValue(getNestedValue($0, g1_parallel_gc_worker_end_re, g1_max_stats_re), g1_stats_value_re, g1_stats_value_re));
  recordStats(g1_young_code_root_fixup_idx, getNestedValue($0, g1_code_root_fixup_re, "[0-9]+[.0-9]+"));
  recordStats(g1_young_clear_ct_idx, getNestedValue($0, g1_clear_ct_re, "[0-9]+[.0-9]+"));
  recordStats(g1_young_other_idx, getNestedValue($0, g1_other_re, "[0-9]+[.0-9]+"));
  recordStats(g1_young_other_choose_cset_idx, getNestedValue($0, g1_other_choose_cset_re, "[0-9]+[.0-9]+"));
  recordStats(g1_young_other_ref_proc_idx, getNestedValue($0, g1_other_ref_proc_re, "[0-9]+[.0-9]+"));
  recordStats(g1_young_other_ref_enq_idx, getNestedValue($0, g1_other_ref_enq_re, "[0-9]+[.0-9]+"));
  recordStats(g1_young_other_free_cset_idx, getNestedValue($0, g1_other_free_cset_re, "[0-9]+[.0-9]+"));
  recordStats(g1_eden_occupancy_before_gc_idx, getNestedValue(getNestedValue($0, g1_eden_size_re, g1_heap_size_re "\\(" g1_heap_size_re "\\)->"),g1_heap_size_re "\\(", g1_heap_size_re));
  recordStats(g1_eden_capacity_before_gc_idx, getNestedValue(getNestedValue($0, g1_eden_size_re, g1_heap_size_re "\\(" g1_heap_size_re "\\)->"), "\\(" g1_heap_size_re "\\)", g1_heap_size_re));
  recordStats(g1_eden_occupancy_after_gc_idx, getNestedValue(getNestedValue($0, g1_eden_size_re, "->" g1_heap_size_re "\\("), g1_heap_size_re, g1_heap_size_re));
  recordStats(g1_eden_capacity_after_gc_idx, getNestedValue(getNestedValue($0, g1_eden_size_re, "->" g1_heap_size_re "\\(" g1_heap_size_re "\\)"), "\\(" g1_heap_size_re, g1_heap_size_re));
  recordStats(g1_survivor_before_gc_idx, getNestedValue($0, g1_survivors_size_re, g1_heap_size_re));
  recordStats(g1_survivor_after_gc_idx, getNestedValue(getNestedValue($0, g1_survivors_size_re, "->" g1_heap_size_re), g1_heap_size_re, g1_heap_size_re));
  recordStats(g1_heap_occupancy_before_gc_idx, getNestedValue(getNestedValue($0, g1_total_heap_size_re, g1_heap_size_re "\\(" g1_heap_size_re "\\)->"),g1_heap_size_re "\\(", g1_heap_size_re));
  recordStats(g1_heap_capacity_before_gc_idx, getNestedValue(getNestedValue($0, g1_total_heap_size_re, g1_heap_size_re "\\(" g1_heap_size_re "\\)->"), "\\(" g1_heap_size_re "\\)", g1_heap_size_re));
  recordStats(g1_heap_occupancy_after_gc_idx, getNestedValue(getNestedValue($0, g1_total_heap_size_re, "->" g1_heap_size_re "\\("), g1_heap_size_re, g1_heap_size_re));
  recordStats(g1_heap_capacity_after_gc_idx, getNestedValue(getNestedValue($0, g1_total_heap_size_re, "->" g1_heap_size_re "\\(" g1_heap_size_re "\\)"), "\\(" g1_heap_size_re, g1_heap_size_re));
  recordStats(g1_young_cpu_sys_idx, getNestedValue(getNestedValue($0, g1_cpu_times_re, "sys=" g1_stats_value_re), g1_stats_value_re, g1_stats_value_re));
  recordStats(g1_young_cpu_usr_idx, getNestedValue(getNestedValue($0, g1_cpu_times_re, "user=" g1_stats_value_re), g1_stats_value_re, g1_stats_value_re));
  recordStats(g1_young_cpu_real_idx, getNestedValue(getNestedValue($0, g1_cpu_times_re, "real=" g1_stats_value_re), g1_stats_value_re, g1_stats_value_re));
  printInterval();
  next;
}

$0 ~ g1_mixed_stw_re {
  match($0, gc_time_secs_re);
  secs = substr($0, RSTART, RLENGTH - 5);
  recordStats(g1_mixed_idx, secs);
  recordStats(g1_mixed_parallel_idx, getNestedValue($0,("Parallel Time: " g1_gc_ms_re),"[0-9]+\\.[0-9]+"));  
  recordStats(g1_mixed_parallel_gc_workers_idx, getNestedValue($0,"GC Workers: [0-9]+","[0-9]+"));
  recordStats(g1_mixed_parallel_gc_worker_start_avg_idx, getNestedValue(getNestedValue($0, g1_parallel_gc_worker_start_re, g1_avg_stats_re), g1_stats_value_re, g1_stats_value_re)); 
  recordStats(g1_mixed_parallel_gc_worker_start_max_idx, getNestedValue(getNestedValue($0, g1_parallel_gc_worker_start_re, g1_max_stats_re), g1_stats_value_re, g1_stats_value_re)); 
  recordStats(g1_mixed_parallel_ext_root_scanning_avg_idx, getNestedValue(getNestedValue($0, g1_parallel_ext_root_scanning_re, g1_avg_stats_re), g1_stats_value_re, g1_stats_value_re));
  recordStats(g1_mixed_parallel_ext_root_scanning_max_idx, getNestedValue(getNestedValue($0, g1_parallel_ext_root_scanning_re, g1_max_stats_re), g1_stats_value_re, g1_stats_value_re));
  recordStats(g1_mixed_parallel_update_rs_avg_idx, getNestedValue(getNestedValue($0, g1_parallel_update_rs_re, g1_avg_stats_re), g1_stats_value_re, g1_stats_value_re));
  recordStats(g1_mixed_parallel_update_rs_max_idx, getNestedValue(getNestedValue($0, g1_parallel_update_rs_re, g1_max_stats_re), g1_stats_value_re, g1_stats_value_re));
  recordStats(g1_mixed_parallel_update_rs_processed_buffer_avg_idx, getNestedValue(getNestedValue($0, g1_parallel_update_rs_processed_buffer_re, g1_avg_stats_re), g1_stats_value_re, g1_stats_value_re));
  recordStats(g1_mixed_parallel_update_rs_processed_buffer_max_idx, getNestedValue(getNestedValue($0, g1_parallel_update_rs_processed_buffer_re, g1_max_stats_re), g1_stats_value_re, g1_stats_value_re));
  recordStats(g1_mixed_parallel_scan_rs_avg_idx, getNestedValue(getNestedValue($0, g1_parallel_scan_rs_re, g1_avg_stats_re), g1_stats_value_re, g1_stats_value_re));
  recordStats(g1_mixed_parallel_scan_rs_max_idx, getNestedValue(getNestedValue($0, g1_parallel_scan_rs_re, g1_max_stats_re), g1_stats_value_re, g1_stats_value_re));
  recordStats(g1_mixed_parallel_object_copy_rs_avg_idx, getNestedValue(getNestedValue($0, g1_parallel_object_copy_rs_re, g1_avg_stats_re), g1_stats_value_re, g1_stats_value_re));
  recordStats(g1_mixed_parallel_object_copy_rs_max_idx, getNestedValue(getNestedValue($0, g1_parallel_object_copy_rs_re, g1_max_stats_re), g1_stats_value_re, g1_stats_value_re));
  recordStats(g1_mixed_parallel_termination_avg_idx, getNestedValue(getNestedValue($0, g1_parallel_termination_re, g1_avg_stats_re), g1_stats_value_re, g1_stats_value_re));
  recordStats(g1_mixed_parallel_termination_max_idx, getNestedValue(getNestedValue($0, g1_parallel_termination_re, g1_max_stats_re), g1_stats_value_re, g1_stats_value_re));
  recordStats(g1_mixed_parallel_gc_worker_other_avg_idx, getNestedValue(getNestedValue($0, g1_parallel_gc_worker_other_re, g1_avg_stats_re), g1_stats_value_re, g1_stats_value_re));
  recordStats(g1_mixed_parallel_gc_worker_other_max_idx, getNestedValue(getNestedValue($0, g1_parallel_gc_worker_other_re, g1_max_stats_re), g1_stats_value_re, g1_stats_value_re));
  recordStats(g1_mixed_parallel_gc_worker_total_avg_idx, getNestedValue(getNestedValue($0, g1_parallel_gc_worker_total_re, g1_avg_stats_re), g1_stats_value_re, g1_stats_value_re));
  recordStats(g1_mixed_parallel_gc_worker_total_max_idx, getNestedValue(getNestedValue($0, g1_parallel_gc_worker_total_re, g1_max_stats_re), g1_stats_value_re, g1_stats_value_re));
  recordStats(g1_mixed_parallel_gc_worker_end_avg_idx, getNestedValue(getNestedValue($0, g1_parallel_gc_worker_end_re, g1_avg_stats_re), g1_stats_value_re, g1_stats_value_re));
  recordStats(g1_mixed_parallel_gc_worker_end_max_idx, getNestedValue(getNestedValue($0, g1_parallel_gc_worker_end_re, g1_max_stats_re), g1_stats_value_re, g1_stats_value_re));
  recordStats(g1_mixed_code_root_fixup_idx, getNestedValue($0, g1_code_root_fixup_re, "[0-9]+[.0-9]+"));
  recordStats(g1_mixed_clear_ct_idx, getNestedValue($0, g1_clear_ct_re, "[0-9]+[.0-9]+"));
  recordStats(g1_mixed_other_idx, getNestedValue($0, g1_other_re, "[0-9]+[.0-9]+"));
  recordStats(g1_mixed_other_choose_cset_idx, getNestedValue($0, g1_other_choose_cset_re, "[0-9]+[.0-9]+"));
  recordStats(g1_mixed_other_ref_proc_idx, getNestedValue($0, g1_other_ref_proc_re, "[0-9]+[.0-9]+"));
  recordStats(g1_mixed_other_ref_enq_idx, getNestedValue($0, g1_other_ref_enq_re, "[0-9]+[.0-9]+"));
  recordStats(g1_mixed_other_free_cset_idx, getNestedValue($0, g1_other_free_cset_re, "[0-9]+[.0-9]+"));
  recordStats(g1_eden_occupancy_before_gc_idx, getNestedValue(getNestedValue($0, g1_eden_size_re, g1_heap_size_re "\\(" g1_heap_size_re "\\)->"),g1_heap_size_re "\\(", g1_heap_size_re));
  recordStats(g1_eden_capacity_before_gc_idx, getNestedValue(getNestedValue($0, g1_eden_size_re, g1_heap_size_re "\\(" g1_heap_size_re "\\)->"), "\\(" g1_heap_size_re "\\)", g1_heap_size_re));
  recordStats(g1_eden_occupancy_after_gc_idx, getNestedValue(getNestedValue($0, g1_eden_size_re, "->" g1_heap_size_re "\\("), g1_heap_size_re, g1_heap_size_re));
  recordStats(g1_eden_capacity_after_gc_idx, getNestedValue(getNestedValue($0, g1_eden_size_re, "->" g1_heap_size_re "\\(" g1_heap_size_re "\\)"), "\\(" g1_heap_size_re, g1_heap_size_re));
  recordStats(g1_survivor_before_gc_idx, getNestedValue($0, g1_survivors_size_re, g1_heap_size_re));
  recordStats(g1_survivor_after_gc_idx, getNestedValue(getNestedValue($0, g1_survivors_size_re, "->" g1_heap_size_re), g1_heap_size_re, g1_heap_size_re));
  recordStats(g1_heap_occupancy_before_gc_idx, getNestedValue(getNestedValue($0, g1_total_heap_size_re, g1_heap_size_re "\\(" g1_heap_size_re "\\)->"),g1_heap_size_re "\\(", g1_heap_size_re));
  recordStats(g1_heap_capacity_before_gc_idx, getNestedValue(getNestedValue($0, g1_total_heap_size_re, g1_heap_size_re "\\(" g1_heap_size_re "\\)->"), "\\(" g1_heap_size_re "\\)", g1_heap_size_re));
  recordStats(g1_heap_occupancy_after_gc_idx, getNestedValue(getNestedValue($0, g1_total_heap_size_re, "->" g1_heap_size_re "\\("), g1_heap_size_re, g1_heap_size_re));
  recordStats(g1_heap_capacity_after_gc_idx, getNestedValue(getNestedValue($0, g1_total_heap_size_re, "->" g1_heap_size_re "\\(" g1_heap_size_re "\\)"), "\\(" g1_heap_size_re, g1_heap_size_re));
  recordStats(g1_mixed_cpu_sys_idx, getNestedValue(getNestedValue($0, g1_cpu_times_re, "sys=" g1_stats_value_re), g1_stats_value_re, g1_stats_value_re));
  recordStats(g1_mixed_cpu_usr_idx, getNestedValue(getNestedValue($0, g1_cpu_times_re, "user=" g1_stats_value_re), g1_stats_value_re, g1_stats_value_re));
  recordStats(g1_mixed_cpu_real_idx, getNestedValue(getNestedValue($0, g1_cpu_times_re, "real=" g1_stats_value_re), g1_stats_value_re, g1_stats_value_re));
  printInterval();
  next;
}

$0 ~ g1_cleanup_stw_re {
  match($0, gc_time_secs_re);
  secs = substr($0, RSTART, RLENGTH - 5);
  recordStats(g1_cleanup_idx, secs);
  printInterval();
  next;
}


# Match -verbose:gc and pre-GC-interface output
#    [GC 17648K->12496K(31744K), 0.0800696 secs]
#    [GC-- 17648K->12496K(31744K), 0.0800696 secs]
#    [ParNew 17648K->12496K(31744K), 0.0800696 secs]
# /\[(GC(--)?|(AS)?ParNew) [0-9]+K->[0-9]+K\([0-9]+K\), [0-9][0-9.]* secs\]/ {
$0 ~ "\\[(GC(--)?|" parnew_gen_re ") " heap_report_re "\\]" {
# print "	>> cht 15. line ", FNR, $0;
  match($0, gc_time_secs_re);
  secs = substr($0, RSTART, RLENGTH - 5) + 0;
  recordStats(gen0c_idx, secs);
  recordHeapKb($0);
  printInterval();
  next;
}

# Match -verbose:gc and pre-GC-interface output
#    [Full GC 14538K->535K(31744K), 0.1335093 secs]
$0 ~ full_gc_re heap_report_re "\\]" {
# print "	>> cht 16. line ", FNR, $0;
  match($0, gc_time_secs_re);
  secs = substr($0, RSTART, RLENGTH - 5) + 0;
  recordStats(gen1t_idx, secs);
  recordHeapKb($0);
  printInterval();
  next;
}

# Parallel Old Gen phases.
# 0.547: [par marking phase, 0.0400133 secs]
# 0.547: [par marking main, 0.0400133 secs]
# 0.547: [par marking flush, 0.0400133 secs]
# 0.587: [summary phase, 0.0022902 secs]
# 0.590: [adjust roots, 0.0056697 secs]
# 0.596: [compact perm gen, 0.1242983 secs]
# 0.720: [draining task setup , 0.0031352 secs]
# -or-
# 0.720: [drain task setup, 0.0031352 secs]
# 0.724: [dense prefix task setup , 0.0000029 secs]
# 0.724: [steal task setup , 0.0000227 secs]
# 0.724: [par compact, 0.0154057 secs]
# 0.739: [post compact, 0.0009566 secs]
/\[pre compact *[,:] *[0-9][0-9.]* secs\]/ {
# print "	>> cht 17. line ", FNR, $0;
	recordParOldPhaseTime($0, "pre compact", PO_precomp_idx)
    next;
}
/\[(par )?marking phase *[,:] *[0-9][0-9.]* secs\]/ {
# print "	>> cht 18. line ", FNR, $0;
	recordParOldPhaseTime($0, "(par )?marking phase", PO_marking_idx)
    next;
}
/\[par mark *[,:] *[0-9][0-9.]* secs\]/ {
# print "	>> cht 19. line ", FNR, $0;
	recordParOldPhaseTime($0, "par mark", PO_parmark_idx)
    next;
}
/\[marking flush *[,:] *[0-9][0-9.]* secs\]/ {
# print "	>> cht 20. line ", FNR, $0;
	recordParOldPhaseTime($0, "marking flush", PO_mark_flush_idx)
    next;
}
/\[summary phase *[,:] *[0-9][0-9.]* secs\]/ {
	recordParOldPhaseTime($0, "summary phase", PO_summary_idx)
    next;
}
/\[adjust roots *[,:] *[0-9][0-9.]* secs\]/ {
	recordParOldPhaseTime($0, "adjust roots", PO_adjroots_idx)
    next;
}
/\[compact perm gen *[,:] *[0-9][0-9.]* secs\]/ {
	recordParOldPhaseTime($0, "compact perm gen", PO_permgen_idx)
    next;
}
/\[compaction phase *[,:] *[0-9][0-9.]* secs\]/ {
	recordParOldPhaseTime($0, "compaction phase", PO_compact_idx)
    next;
}
/\[drain(ing)? task setup *[,:] *[0-9][0-9.]* secs\]/ {
	recordParOldPhaseTime($0, "drain(ing)? task setup", PO_drain_ts_idx)
    next;
}
/\[dense prefix task setup *[,:] *[0-9][0-9.]* secs\]/ {
	recordParOldPhaseTime($0, "dense prefix task setup", PO_dpre_ts_idx)
    next;
}
/\[steal task setup *[,:] *[0-9][0-9.]* secs\]/ {
	recordParOldPhaseTime($0, "steal task setup", PO_steal_ts_idx)
    next;
}
/\[par compact *[,:] *[0-9][0-9.]* secs\]/ {
	recordParOldPhaseTime($0, "par compact", PO_parcomp_idx)
    next;
}
/\[deferred updates *[,:] *[0-9][0-9.]* secs\]/ {
	recordParOldPhaseTime($0, "deferred updates", PO_deferred_idx)
    next;
}
/\[post compact *[,:] *[0-9][0-9.]* secs\]/ {
	recordParOldPhaseTime($0, "post compact", PO_postcomp_idx)
    next;
}

# Match output from -XX:+TraceGCApplicationStoppedTime.
/Total time for which application threads were stopped: [0-9][0-9.]* seconds/ {
# print "	>> cht 40. line ", FNR, $0;
	match($0, "were stopped: [0-9][0-9.]* seconds");
	secs = substr($0, RSTART + 14, RLENGTH - 14 - 8) + 0;
	recordStats(safept_idx, secs);
	next;
}

# Match output from -XX:+TraceGCApplicationConcurrentTime.
/Application time:[	 ]+[0-9][0-9.]* seconds/ {
# print "	>> cht 41. line ", FNR, $0;
	match($0, "Application time:[	 ]+[0-9][0-9.]* seconds");
	secs = substr($0, RSTART + 18, RLENGTH - 18 - 8) + 0;
	recordStats(apptime_idx, secs);
	next;
}

# Match +TraceGen*Time output
# $1           $2 $3         $4     $5   $6      $7
/\[Accumulated GC generation [0-9]+ time [0-9.]+ secs\]/ {
# print "	>> cht 42. line ", FNR, $0;
  if ($4 == 0) {
    gc0caccum = $6 + 0;
  } else if ($4 == 1) {
    gc1taccum = $6 + 0;
  } else {
    printf("Accumulated GC generation out of bounds\n");
  }
  next;
}

# BEA JRockit GC times (very basic).
# Java(TM) 2 Runtime Environment, Standard Edition (build 1.5.0_04-b05)
# BEA JRockit(R) (build R26.1.0-22-54592-1.5.0_04-20051213-1629-solaris-sparcv9, )
# 
# [memory ] <s>-<end>: GC <before>K-><after>K (<heap>K), <pause> ms
# [memory ] <s/start> - start time of collection (seconds since jvm start)
# [memory ] <end>     - end time of collection (seconds since jvm start)
# [memory ] <before>  - memory used by objects before collection (KB)
# [memory ] <after>   - memory used by objects after collection (KB)
# [memory ] <heap>    - size of heap after collection (KB)
# [memory ] <pause>   - total pause time during collection (milliseconds)
#
# [memory ] 14.229-16.647: GC 1572864K->718K (10485760K), 2418.000 ms
# [memory ] 133.299-133.568: GC 10485760K->762425K (10485760K), 269.000 ms

match($0, "\\[memory ?\\] " timestamp_range_re "GC " heap_size_status_re ", " gc_time_ms_re) {
  match($0, gc_time_ms_re);
  secs = substr($0, RSTART, RLENGTH - 3) / 1000.0;
  recordStats(gen1t_idx, secs);
  recordHeapKb($0);
  # printInterval();
  next;
}

# EVM allocation info.
#
# Starting GC at Tue Nov 12 10:44:23 2002; suspending threads.
# Gen[0](semi-spaces): size=12Mb(50% overhead), free=0kb, maxAlloc=0kb.
/Starting GC at .*; suspending threads/ {
  evm_last_was_starting_gc = 1;
  next;
}

evm_last_was_starting_gc && \
$0 ~ /Gen\[0\]\([a-z-]+\): size=[0-9]+Mb.*, free=[0-9]+kb,/ {
  evm_last_was_starting_gc = 0;
  match($0, "size=[0-9]+Mb");
  tString = substr($0, RSTART + 5, RLENGTH - 7);
  tmp_size = tString * 512;	# * 1024 / 2:  the size includes both semispaces
  match($0, "free=[0-9]+kb");
  tString = substr($0, RSTART + 5, RLENGTH - 7);
  tmp_free = tString + 0;
  recordStats(MB_a_idx, (tmp_size - tmp_free) / 1024);
  next;
}

# EVM promotion info
# 
# Gen0(semi-spaces)-GC #2030 tenure-thresh=0 42ms 0%->100% free, promoted 46712 obj's/1978kb
# /Gen0\([a-z-]+\)-GC.* promoted / {
/% free, promoted [0-9]+ obj.s\/[0-9]+kb/ {
  tString = $0;
  match($0, "obj.s/[0-9]+kb");
  tString = substr($0, RSTART + 6, RLENGTH - 8);
  kb_promo = tString + 0;
  recordStats(MB_p_idx, kb_promo / 1024.0);
  next;
}

function recordGCPauseEVM(idx) {
  evm_last_was_starting_gc = 0;
  match($0, "in [0-9]+ ms:");
  tString = substr($0, RSTART + 3, RLENGTH - 7);
  recordStats(idx, tString / 1000.0);

  # Record committed and used stats for young gen collections.
  if (idx == gen0t_idx && match($0, "ms: \\([0-9]+[MmKk][Bb],")) {
    tString = substr($0, RSTART + 5, RLENGTH - 8);
    evm_units = tolower(substr($0, RSTART + RLENGTH - 3, 2));
    evm_factor = evm_units == "kb" ? 1024 : 1;
    evm_val = tString + 0;
    recordStats(MB_ch_idx, tString / evm_factor);
    if (match($0, ", [0-9]+% free\\)")) {
      tString = substr($0, RSTART + 2, RLENGTH - 7);
      evm_val = evm_val * (100 - tString) / 100;
      recordStats(MB_usedh_idx, evm_val / evm_factor);
    }
  }

  # Application time.
  if (match($0, "\\[application [0-9]+ ms")) {
    tString = substr($0, RSTART + 13, RLENGTH - 16);
    recordStats(apptime_idx, tString / 1000.0);
  }
}

# EVM output with -verbose:gc -verbose:gc
# 
# GC[0] in 50 ms: (656Mb, 80% free) -> (656Mb, 80% free) [application 353 ms  requested 6 words]
# GC[1] in 3963 ms: (656Mb, 0% free) -> (656Mb, 81% free) [application 380 ms  requested 28 words]
# GC[1: initial mark] in 84 ms: (656Mb, 97% free) -> (656Mb, 97% free) [application 65 ms  requested 0 words]
# GC[1: remark] in 36 ms: (656Mb, 93% free) -> (656Mb, 93% free) [application 241 ms  requested 0 words]
# GC[1: resize heap] in 0 ms: (656Mb, 97% free) -> (656Mb, 97% free) [application 213 ms  requested 0 words]
/GC\[0\] in [0-9]+ ms: / {
  recordGCPauseEVM(gen0t_idx);
  printInterval();
  next;
}

/GC\[1\] in [0-9]+ ms: / {
  recordGCPauseEVM(gen1t_idx);
  next;
}

/GC\[1: initial mark\] in [0-9]+ ms: / {
  recordGCPauseEVM(cmsIM_idx);
  next;
}

/GC\[1: remark\] in [0-9]+ ms: / {
  recordGCPauseEVM(cmsRM_idx);
  next;
}

/GC\[1: resize heap\] in [0-9]+ ms: / {
  recordGCPauseEVM(cmsRS_idx);
  next;
}

#{
#print "not matched ", $0;
#}

END {
  # No summary stats if plotting.
  if (available_plot_count > 0) exit(0);

  if (interval >= 0) print "";

  printHeader();
  for (i = 0; i < last_idx; ++i) {
    if (count_v[i] > 0) {
      printData(i);
    }
  }

  if (lastTimeStamp != firstTimeStamp) {
    # Elapsed time.
    tot_time = lastTimeStamp - firstTimeStamp;
    # Elapsed time scaled by cpus.
    tot_cpu_time = tot_time * cpus;
    # Sequential gc time scaled by cpus.
    seq_gc_cpu_time = sum_v[totgc_idx] * cpus;
    # Concurrent gc time (scaling not necessary).
    cms_gc_cpu_time = sum_v[cmsCM_idx] + sum_v[cmsCP_idx] + \
      sum_v[cmsCS_idx] + sum_v[cmsCR_idx];
    # Cpu time available to mutators.
    mut_cpu_time = tot_cpu_time - seq_gc_cpu_time - cms_gc_cpu_time;

    print "";
    printRate("alloc/elapsed_time",
      sum_v[MB_a_idx], "MB", tot_time, "s");
    printRate("alloc/tot_cpu_time",
      sum_v[MB_a_idx], "MB", tot_cpu_time, "s");
    printRate("alloc/mut_cpu_time",
      sum_v[MB_a_idx], "MB", mut_cpu_time, "s");
    printRate("promo/elapsed_time",
      sum_v[MB_p_idx], "MB", tot_time, "s");
    printRate("promo/gc0_time",
      sum_v[MB_p_idx], "MB", sum_v[gen0t_idx], "s");
    printPercent("gc_seq_load",
      seq_gc_cpu_time, "s", tot_cpu_time, "s");
    printPercent("gc_conc_load",
      cms_gc_cpu_time, "s", tot_cpu_time, "s");
    printPercent("gc_tot_load",
      seq_gc_cpu_time + cms_gc_cpu_time, "s", tot_cpu_time, "s");
  }

  if (gc0caccum != 0 || gc1taccum != 0) {
    genAccum = gc0caccum + gc1taccum;
    printf("Accum\t%7.3f\t\t\t%7.3f\t\t\t%7.3f\n",
	   gc0caccum, gc1taccum, genAccum);
    gc0cdelta = gc0cseconds - gc0caccum;
    gc1tdelta = gc1tseconds - gc1taccum;
    gcDelta = gcSeconds - genAccum;
    printf("Delta\t%7.3f\t\t\t%7.3f\t\t\t%7.3f\n",
	   gc0cdelta, gc1tdelta, gcDelta);
  }
}
