Difference between revisions of "Heap Memory Profile Probe"

From OC Systems Wiki!
Jump to: navigation, search
m (Usage)
m (Usage)
 
Line 19: Line 19:
 
You can also track the lifetimes of objects by using the <code> -l</code> option.  This will report on the lifetime of objects by size, and produce additional tabular and histogram reports.
 
You can also track the lifetimes of objects by using the <code> -l</code> option.  This will report on the lifetime of objects by size, and produce additional tabular and histogram reports.
  
NOTE: As of Aprobe 4.5.1, <code>hmp.ual</code> is not delivered compiled on Linux 32-bit systems.  You will have to compile it yourself by copying the source, <code>hmp.apc</code>, from <code>$APROBE/probes</code> to a local directory to compile it with:
+
NOTE: Prior to Aprobe 4.5.4, <code>hmp.ual</code> was not delivered compiled on Linux 32-bit systems.  You will have to compile it yourself by copying the source, <code>hmp.apc</code>, from <code>$APROBE/probes</code> to a local directory to compile it with:
  
   apc -v -g hmp.apc -linker “-l pthreads”
+
   apc -v -g hmp.apc -linker “-lpthreads -lrt”
  
 
=== Profile UAL Parameters ===
 
=== Profile UAL Parameters ===

Latest revision as of 20:28, 27 April 2021

Heap Memory Profile Probe: hmp.ual

(Since 4.5.0).

The hmp.ual predefined probe profiles the use of heap memory within an application program. The probe records the number, size, and time taken for allocations and deallocations from and to the heap. The profiling information is reported periodically in snapshots and in a final snapshot at the program termination.

Heap profiling allows you to determine how the heap is being used in your application. The heap profile information can be used to locate "hot spots" of heap usage in your application on which to focus your attention when trying to improve your program's performance. This probe focuses on overall usage not on specific allocations and deallocations.

See memstat.ual, memleak.ual and memwatch.ual for other approaches to heap analysis.

Usage

This probe is applied at run time using aprobe as described under Profile UAL Parameters below. Heap profiling data will be collected for the standard memory functions: malloc, calloc, realloc, and free. You would need to modify this probe to collect information from custom allocation functions.

The heap profile information is collected in memory and periodically logged in snapshots logged to the APD file for later processing by apformat. At format time a report is generated for each snapshot and an overall summary for the whole program which details the number and duration of allocations and deallocation of objects of different sizes. The data is tabulated and displayed in histograms. The reports are designed to allow you to identify areas of heavy heap usage based on object sizes rather than specific objects. This analysis may be followed up by custom probes to discover where the application is allocating objects of a specific size, for example.

The default parameters provide good initial coverage of heap object sizes by defining bucket sizes that increase by powers of two. Object smaller than the smallest bucket size are tallied in the the smallest bucket and object larger than the largest bucket size are tallied in the largest bucket. You can focus on specific object size by specifying a starting bucket size and the number of buckets to use with linearly increasing sizes.

You can also track the lifetimes of objects by using the -l option. This will report on the lifetime of objects by size, and produce additional tabular and histogram reports.

NOTE: Prior to Aprobe 4.5.4, hmp.ual was not delivered compiled on Linux 32-bit systems. You will have to compile it yourself by copying the source, hmp.apc, from $APROBE/probes to a local directory to compile it with:

  apc -v -g hmp.apc -linker “-lpthreads -lrt”

Profile UAL Parameters

hmp.ual is specified on the aprobe command line or in an APO file as described in Command Line. The specific options are:

aprobe  -u hmp.ual    [-p "param-list"] your_program

where param_list may include:

-i InitTime
num secs before starting snapshots [SnapTime]
-w WaitTime
wait WaitTime secs before tracking allocations [0]
-s SnapTime
num secs between snapshots after InitTime [30]
-r
reset statistics after each snapshot
-x
collect CPU times in addtion to wall times
-y
Use MONOTONIC clock instead of CPU clock (implies -x)
-b NBuckets
number of buckets : default 16
-c BucketSize
size in bytes of each bucket : default 0 (= doubling)
-d BucketStart
first bucket size in bytes : default 32
-l
track object lifetimes : default off
-t NTimeBuckets
number of time buckets : default 10
-u TimeBucketSize
size in seconds of each time bucket : default 0 (= doubling)
-v TimeBucketStart
first time bucket time in seconds : default 1


Heap Memory Profile API

Users can control the behavior of the heap memory profile probe by calls from within their own probes. The API is defined by [../include/hmp.h $APROBE/include/hmp.h]. The functions exported by hmp.ual are:

ap_Hmp_DoSnapshot

Takes a snapshot of heap memory profile data.

See Snapshots for more information and an example.

Heap Memory Profile Demand Actions

You can control hmp.ual using demand.ual and apdemand.

Include demand.ual on the Aprobe command line:

 aprobe -u hmp -u demand myapp.exe
 

then use apdemand to send actions:

 apdemand hmp snapshot
 

hmp.ual responds to the following actions:

  • hmp snapshot

Note that all actions containing the action string will be triggered.

Heap Memory Profile Performance Issues

See Performance_Issues for a general discussion of factors that affect performance.

You can use the InitTime and WaitTime options to control when heap memory profiling is performed. This can reduce the overhead during application start-up when many tables and other data structures are populated by allocations from the heap.

While snapshots are reasonable quick, you can use the SnapTime option to control how often, if at all, periodic snapshots are taken.

Heap Memory Profile Report

The reports generated by running apformat vary considerably depending upon the options chosen as specified above. The default looks like the example below:

Heap Memory Profile Probe 4.5.0 (181025)
Copyright 1993-2018 OC Systems, Inc. All rights reserved.
For support/questions send mail to support@ocsystems.com.

PID: 17171 - Summary of options
   Program start: Thu Oct 25 14:47:02.828433 2018
Options:
   WaitTime:          0
   InitTime:          60
   SnapTime:          60
   Buckets:           16
   Bucket Size:       0
   Bucket Start:      32
   TimeBuckets:       10
   Time Bucket Size:  0
   Time Bucket Start: 1
   TrackLifetime:     0
   ResetStats:        0
   CPUTime:           0
   Monotonic:         0
   SnapshotSig:       0

Heap Memory Profile Probe 4.5.0 (181025)
Copyright 1993-2018 OC Systems, Inc. All rights reserved.
For support/questions send mail to support@ocsystems.com.

PID: 17171 - Summary of snapshot #1 ("Final Snapshot")
   Program start: Thu Oct 25 14:47:02.828433 2018
   Snapshot time: Thu Oct 25 14:48:32.830581 2018
   Buckets:           16
   Bucket Size:       0
   Bucket Start:      32
   TimeBuckets:       10
   Time Bucket Size:  0
   Time Bucket Start: 1
Overall:
	MaxOutstanding:	13
	BytesAllocated:	99,439
	BytesFreed:	82,710

	NumAllocs:	27
	AvgAllocSize:	3,682
	MaxAllocSize:	9,783
	TotalAllocTime:	        0.0001730000
	AvgAllocTime:	        0.0000064074
	MaxAllocTime:	        0.0000460000
	MaxAllocTimeSize:	5,038

	NumReallocs:	0
	MaxReallocSize:	0
	TotalReallocTime:	        0.0000000000
	AvgReallocTime:	        0.0000000000
	MaxReallocTime:	        0.0000000000
	MaxReallocTimeSize:	0

	NumFrees:	20
	AvgFreeSize:	4,135
	MaxFreeSize:	9,793
	TotalFreeTime:	        0.0001030000
	AvgFreeTime:	        0.0000051500
	MaxFreeTime:	        0.0000190000
	MaxFreeTimeSize:	0
Bucket:
	Size:	0 .. 32
	MaxOutstanding:	0
	BytesAllocated:	0
	BytesFreed:	0

	NumAllocs:	0
	AvgAllocSize:	0
	MaxAllocSize:	0
	TotalAllocTime:	        0.0000000000
	AvgAllocTime:	        0.0000000000
	MaxAllocTime:	        0.0000000000
	MaxAllocTimeSize:	0

	NumReallocs:	0
	MaxReallocSize:	0
	TotalReallocTime:	        0.0000000000
	AvgReallocTime:	        0.0000000000
	MaxReallocTime:	        0.0000000000
	MaxReallocTimeSize:	0

	NumFrees:	0
	AvgFreeSize:	0
	MaxFreeSize:	0
	TotalFreeTime:	        0.0000000000
	AvgFreeTime:	        0.0000000000
	MaxFreeTime:	        0.0000000000
	MaxFreeTimeSize:	0

Bucket:
	Size:	33 .. 64
	MaxOutstanding:	0
	BytesAllocated:	0
	BytesFreed:	0

	NumAllocs:	0
	AvgAllocSize:	0
	MaxAllocSize:	0
	TotalAllocTime:	        0.0000000000
	AvgAllocTime:	        0.0000000000
	MaxAllocTime:	        0.0000000000
	MaxAllocTimeSize:	0

	NumReallocs:	0
	MaxReallocSize:	0
	TotalReallocTime:	        0.0000000000
	AvgReallocTime:	        0.0000000000
	MaxReallocTime:	        0.0000000000
	MaxReallocTimeSize:	0

	NumFrees:	0
	AvgFreeSize:	0
	MaxFreeSize:	0
	TotalFreeTime:	        0.0000000000
	AvgFreeTime:	        0.0000000000
	MaxFreeTime:	        0.0000000000
	MaxFreeTimeSize:	0

Bucket:
	Size:	65 .. 128
	MaxOutstanding:	0
	BytesAllocated:	0
	BytesFreed:	0

	NumAllocs:	0
	AvgAllocSize:	0
	MaxAllocSize:	0
	TotalAllocTime:	        0.0000000000
	AvgAllocTime:	        0.0000000000
	MaxAllocTime:	        0.0000000000
	MaxAllocTimeSize:	0

	NumReallocs:	0
	MaxReallocSize:	0
	TotalReallocTime:	        0.0000000000
	AvgReallocTime:	        0.0000000000
	MaxReallocTime:	        0.0000000000
	MaxReallocTimeSize:	0

	NumFrees:	0
	AvgFreeSize:	0
	MaxFreeSize:	0
	TotalFreeTime:	        0.0000000000
	AvgFreeTime:	        0.0000000000
	MaxFreeTime:	        0.0000000000
	MaxFreeTimeSize:	0

Bucket:
	Size:	129 .. 256
	MaxOutstanding:	0
	BytesAllocated:	0
	BytesFreed:	0

	NumAllocs:	0
	AvgAllocSize:	0
	MaxAllocSize:	0
	TotalAllocTime:	        0.0000000000
	AvgAllocTime:	        0.0000000000
	MaxAllocTime:	        0.0000000000
	MaxAllocTimeSize:	0

	NumReallocs:	0
	MaxReallocSize:	0
	TotalReallocTime:	        0.0000000000
	AvgReallocTime:	        0.0000000000
	MaxReallocTime:	        0.0000000000
	MaxReallocTimeSize:	0

	NumFrees:	0
	AvgFreeSize:	0
	MaxFreeSize:	0
	TotalFreeTime:	        0.0000000000
	AvgFreeTime:	        0.0000000000
	MaxFreeTime:	        0.0000000000
	MaxFreeTimeSize:	0

Bucket:
	Size:	257 .. 512
	MaxOutstanding:	6
	BytesAllocated:	1,851
	BytesFreed:	714

	NumAllocs:	6
	AvgAllocSize:	308
	MaxAllocSize:	411
	TotalAllocTime:	        0.0000140000
	AvgAllocTime:	        0.0000023333
	MaxAllocTime:	        0.0000030000
	MaxAllocTimeSize:	288

	NumReallocs:	0
	MaxReallocSize:	0
	TotalReallocTime:	        0.0000000000
	AvgReallocTime:	        0.0000000000
	MaxReallocTime:	        0.0000000000
	MaxReallocTimeSize:	0

	NumFrees:	2
	AvgFreeSize:	357
	MaxFreeSize:	417
	TotalFreeTime:	        0.0000060000
	AvgFreeTime:	        0.0000030000
	MaxFreeTime:	        0.0000050000
	MaxFreeTimeSize:	0

Bucket:
	Size:	513 .. 1,024
	MaxOutstanding:	0
	BytesAllocated:	0
	BytesFreed:	0

	NumAllocs:	0
	AvgAllocSize:	0
	MaxAllocSize:	0
	TotalAllocTime:	        0.0000000000
	AvgAllocTime:	        0.0000000000
	MaxAllocTime:	        0.0000000000
	MaxAllocTimeSize:	0

	NumReallocs:	0
	MaxReallocSize:	0
	TotalReallocTime:	        0.0000000000
	AvgReallocTime:	        0.0000000000
	MaxReallocTime:	        0.0000000000
	MaxReallocTimeSize:	0

	NumFrees:	0
	AvgFreeSize:	0
	MaxFreeSize:	0
	TotalFreeTime:	        0.0000000000
	AvgFreeTime:	        0.0000000000
	MaxFreeTime:	        0.0000000000
	MaxFreeTimeSize:	0

Bucket:
	Size:	1,025 .. 2,048
	MaxOutstanding:	1
	BytesAllocated:	4,061
	BytesFreed:	4,090

	NumAllocs:	3
	AvgAllocSize:	1,353
	MaxAllocSize:	1,945
	TotalAllocTime:	        0.0000090000
	AvgAllocTime:	        0.0000030000
	MaxAllocTime:	        0.0000040000
	MaxAllocTimeSize:	1,031

	NumReallocs:	0
	MaxReallocSize:	0
	TotalReallocTime:	        0.0000000000
	AvgReallocTime:	        0.0000000000
	MaxReallocTime:	        0.0000000000
	MaxReallocTimeSize:	0

	NumFrees:	3
	AvgFreeSize:	1,363
	MaxFreeSize:	1,953
	TotalFreeTime:	        0.0000160000
	AvgFreeTime:	        0.0000053333
	MaxFreeTime:	        0.0000060000
	MaxFreeTimeSize:	0

Bucket:
	Size:	2,049 .. 4,096
	MaxOutstanding:	4
	BytesAllocated:	22,375
	BytesFreed:	16,396

	NumAllocs:	7
	AvgAllocSize:	3,196
	MaxAllocSize:	3,857
	TotalAllocTime:	        0.0000260000
	AvgAllocTime:	        0.0000037143
	MaxAllocTime:	        0.0000060000
	MaxAllocTimeSize:	3,555

	NumReallocs:	0
	MaxReallocSize:	0
	TotalReallocTime:	        0.0000000000
	AvgReallocTime:	        0.0000000000
	MaxReallocTime:	        0.0000000000
	MaxReallocTimeSize:	0

	NumFrees:	5
	AvgFreeSize:	3,279
	MaxFreeSize:	3,801
	TotalFreeTime:	        0.0000370000
	AvgFreeTime:	        0.0000074000
	MaxFreeTime:	        0.0000190000
	MaxFreeTimeSize:	0

Bucket:
	Size:	4,097 .. 8,192
	MaxOutstanding:	5
	BytesAllocated:	42,419
	BytesFreed:	42,492

	NumAllocs:	8
	AvgAllocSize:	5,302
	MaxAllocSize:	7,081
	TotalAllocTime:	        0.0001070000
	AvgAllocTime:	        0.0000133750
	MaxAllocTime:	        0.0000460000
	MaxAllocTimeSize:	5,038

	NumReallocs:	0
	MaxReallocSize:	0
	TotalReallocTime:	        0.0000000000
	AvgReallocTime:	        0.0000000000
	MaxReallocTime:	        0.0000000000
	MaxReallocTimeSize:	0

	NumFrees:	8
	AvgFreeSize:	5,311
	MaxFreeSize:	7,089
	TotalFreeTime:	        0.0000340000
	AvgFreeTime:	        0.0000042500
	MaxFreeTime:	        0.0000050000
	MaxFreeTimeSize:	0

Bucket:
	Size:	8,193 .. 16,384
	MaxOutstanding:	2
	BytesAllocated:	28,733
	BytesFreed:	19,018

	NumAllocs:	3
	AvgAllocSize:	9,577
	MaxAllocSize:	9,783
	TotalAllocTime:	        0.0000170000
	AvgAllocTime:	        0.0000056667
	MaxAllocTime:	        0.0000080000
	MaxAllocTimeSize:	9,783

	NumReallocs:	0
	MaxReallocSize:	0
	TotalReallocTime:	        0.0000000000
	AvgReallocTime:	        0.0000000000
	MaxReallocTime:	        0.0000000000
	MaxReallocTimeSize:	0

	NumFrees:	2
	AvgFreeSize:	9,509
	MaxFreeSize:	9,793
	TotalFreeTime:	        0.0000100000
	AvgFreeTime:	        0.0000050000
	MaxFreeTime:	        0.0000060000
	MaxFreeTimeSize:	0

Bucket:
	Size:	16,385 .. 32,768
	MaxOutstanding:	0
	BytesAllocated:	0
	BytesFreed:	0

	NumAllocs:	0
	AvgAllocSize:	0
	MaxAllocSize:	0
	TotalAllocTime:	        0.0000000000
	AvgAllocTime:	        0.0000000000
	MaxAllocTime:	        0.0000000000
	MaxAllocTimeSize:	0

	NumReallocs:	0
	MaxReallocSize:	0
	TotalReallocTime:	        0.0000000000
	AvgReallocTime:	        0.0000000000
	MaxReallocTime:	        0.0000000000
	MaxReallocTimeSize:	0

	NumFrees:	0
	AvgFreeSize:	0
	MaxFreeSize:	0
	TotalFreeTime:	        0.0000000000
	AvgFreeTime:	        0.0000000000
	MaxFreeTime:	        0.0000000000
	MaxFreeTimeSize:	0

Bucket:
	Size:	32,769 .. 65,536
	MaxOutstanding:	0
	BytesAllocated:	0
	BytesFreed:	0

	NumAllocs:	0
	AvgAllocSize:	0
	MaxAllocSize:	0
	TotalAllocTime:	        0.0000000000
	AvgAllocTime:	        0.0000000000
	MaxAllocTime:	        0.0000000000
	MaxAllocTimeSize:	0

	NumReallocs:	0
	MaxReallocSize:	0
	TotalReallocTime:	        0.0000000000
	AvgReallocTime:	        0.0000000000
	MaxReallocTime:	        0.0000000000
	MaxReallocTimeSize:	0

	NumFrees:	0
	AvgFreeSize:	0
	MaxFreeSize:	0
	TotalFreeTime:	        0.0000000000
	AvgFreeTime:	        0.0000000000
	MaxFreeTime:	        0.0000000000
	MaxFreeTimeSize:	0

Bucket:
	Size:	65,537 .. 131,072
	MaxOutstanding:	0
	BytesAllocated:	0
	BytesFreed:	0

	NumAllocs:	0
	AvgAllocSize:	0
	MaxAllocSize:	0
	TotalAllocTime:	        0.0000000000
	AvgAllocTime:	        0.0000000000
	MaxAllocTime:	        0.0000000000
	MaxAllocTimeSize:	0

	NumReallocs:	0
	MaxReallocSize:	0
	TotalReallocTime:	        0.0000000000
	AvgReallocTime:	        0.0000000000
	MaxReallocTime:	        0.0000000000
	MaxReallocTimeSize:	0

	NumFrees:	0
	AvgFreeSize:	0
	MaxFreeSize:	0
	TotalFreeTime:	        0.0000000000
	AvgFreeTime:	        0.0000000000
	MaxFreeTime:	        0.0000000000
	MaxFreeTimeSize:	0

Bucket:
	Size:	131,073 .. 262,144
	MaxOutstanding:	0
	BytesAllocated:	0
	BytesFreed:	0

	NumAllocs:	0
	AvgAllocSize:	0
	MaxAllocSize:	0
	TotalAllocTime:	        0.0000000000
	AvgAllocTime:	        0.0000000000
	MaxAllocTime:	        0.0000000000
	MaxAllocTimeSize:	0

	NumReallocs:	0
	MaxReallocSize:	0
	TotalReallocTime:	        0.0000000000
	AvgReallocTime:	        0.0000000000
	MaxReallocTime:	        0.0000000000
	MaxReallocTimeSize:	0

	NumFrees:	0
	AvgFreeSize:	0
	MaxFreeSize:	0
	TotalFreeTime:	        0.0000000000
	AvgFreeTime:	        0.0000000000
	MaxFreeTime:	        0.0000000000
	MaxFreeTimeSize:	0

Bucket:
	Size:	262,145 .. 524,288
	MaxOutstanding:	0
	BytesAllocated:	0
	BytesFreed:	0

	NumAllocs:	0
	AvgAllocSize:	0
	MaxAllocSize:	0
	TotalAllocTime:	        0.0000000000
	AvgAllocTime:	        0.0000000000
	MaxAllocTime:	        0.0000000000
	MaxAllocTimeSize:	0

	NumReallocs:	0
	MaxReallocSize:	0
	TotalReallocTime:	        0.0000000000
	AvgReallocTime:	        0.0000000000
	MaxReallocTime:	        0.0000000000
	MaxReallocTimeSize:	0

	NumFrees:	0
	AvgFreeSize:	0
	MaxFreeSize:	0
	TotalFreeTime:	        0.0000000000
	AvgFreeTime:	        0.0000000000
	MaxFreeTime:	        0.0000000000
	MaxFreeTimeSize:	0

Bucket:
	Size:	524,289 .. 2,147,483,647
	MaxOutstanding:	0
	BytesAllocated:	0
	BytesFreed:	0

	NumAllocs:	0
	AvgAllocSize:	0
	MaxAllocSize:	0
	TotalAllocTime:	        0.0000000000
	AvgAllocTime:	        0.0000000000
	MaxAllocTime:	        0.0000000000
	MaxAllocTimeSize:	0

	NumReallocs:	0
	MaxReallocSize:	0
	TotalReallocTime:	        0.0000000000
	AvgReallocTime:	        0.0000000000
	MaxReallocTime:	        0.0000000000
	MaxReallocTimeSize:	0

	NumFrees:	0
	AvgFreeSize:	0
	MaxFreeSize:	0
	TotalFreeTime:	        0.0000000000
	AvgFreeTime:	        0.0000000000
	MaxFreeTime:	        0.0000000000
	MaxFreeTimeSize:	0



Allocs Histogram:
       0 ..         32 : 
      33 ..         64 : 
      65 ..        128 : 
     129 ..        256 : 
     257 ..        512 : ******
     513 ..       1024 : 
    1025 ..       2048 : ***
    2049 ..       4096 : *******
    4097 ..       8192 : ********
    8193 ..      16384 : ***
   16385 ..      32768 : 
   32769 ..      65536 : 
   65537 ..     131072 : 
  131073 ..     262144 : 
  262145 ..     524288 : 
  524289 .. 2147483647 : 


Reallocs Histogram:
       0 ..         32 : 
      33 ..         64 : 
      65 ..        128 : 
     129 ..        256 : 
     257 ..        512 : 
     513 ..       1024 : 
    1025 ..       2048 : 
    2049 ..       4096 : 
    4097 ..       8192 : 
    8193 ..      16384 : 
   16385 ..      32768 : 
   32769 ..      65536 : 
   65537 ..     131072 : 
  131073 ..     262144 : 
  262145 ..     524288 : 
  524289 .. 2147483647 :  
 

The report starts with a summary of the options used for the run.

Next comes a snapshot, in this case the final snapshot on program termination. The snapshot reports some information about the buckets used to summarize the data, and overall information for all object sizes for the snapshot. Next are summaries for each object size bucket of the snapshot. Following the bucket summaries there are histograms displaying the spread of object sizes recorded for the snapshot.

Note that allocation and reallocation data are tracked separately, because it is not possible to separate the deallocation time forth allocation time in a realloc() call. In practice this should not be a significant problem.

This is a final snapshot so the statistics cover the entire run. If there were periodic snapshots taken, the statistics for each snapshot might reset depending on the -r option.

In this particular example there are no glaring hot spots, but further investigation of object sizes between 2KB and 8KB might be warranted. In that case you might run with:

aprobe -u hmp -p "-b 8 -c 1024 -d 2048"

to track objects in 8 buckets starting at 2048 bytes and incrementing by 1024 bytes.

Heap Memory Profile Lifetime Report

When lifetime data is selected each size bucket section includes additional lifetime information like:

Bucket:
	Size:	2,049 .. 4,096
	MaxOutstanding:	5
	BytesAllocated:	13,908
	BytesFreed:	9,866

	NumAllocs:	5
	AvgAllocSize:	2,781
	MaxAllocSize:	4,087
	TotalAllocTime:	        0.0000190000
	AvgAllocTime:	        0.0000038000
	MaxAllocTime:	        0.0000090000
	MaxAllocTimeSize:	4,087

	NumReallocs:	0
	MaxReallocSize:	0
	TotalReallocTime:	        0.0000000000
	AvgReallocTime:	        0.0000000000
	MaxReallocTime:	        0.0000000000
	MaxReallocTimeSize:	0

	NumFrees:	4
	AvgFreeSize:	2,466
	MaxFreeSize:	2,617
	TotalFreeTime:	        0.0000200000
	AvgFreeTime:	        0.0000050000
	MaxFreeTime:	        0.0000060000
	MaxFreeTimeSize:	0

	Time Bucket:
		Secs:	0 .. 1
		Count:	0
	Time Bucket:
		Secs:	2 .. 2
		Count:	0
	Time Bucket:
		Secs:	3 .. 4
		Count:	0
	Time Bucket:
		Secs:	5 .. 8
		Count:	0
	Time Bucket:
		Secs:	9 .. 16
		Count:	0
	Time Bucket:
		Secs:	17 .. 32
		Count:	1
	Time Bucket:
		Secs:	33 .. 64
		Count:	3
	Time Bucket:
		Secs:	65 .. 128
		Count:	0
	Time Bucket:
		Secs:	129 .. 256
		Count:	0
	Time Bucket:
		Secs:	257 .. 2,147,483,647
		Count:	0


	Time Histogram:
	       0 ..          1 : 
	       2 ..          2 : 
	       3 ..          4 : 
	       5 ..          8 : 
	       9 ..         16 : 
	      17 ..         32 : *
	      33 ..         64 : ***
	      65 ..        128 : 
	     129 ..        256 : 
	     257 .. 2147483647 : 
 

There are time buckets reported for seconds of duration, and a histogram of the spread of lifetime durations.