Histogram

The raw latency histogram is used to record periodic latency data in a raw format that can be easily converted to other formats and combined with separate runs of the benchmark.

Configuration

To enable raw latency tracing, pass the --outputFile flag followed by the name of the file to write the raw latency information to. For example

target/benchmark --outputFile raw_output.txt

Note that this file is opened in append mode.

The structure of the raw latency histogram is printed first in the file, in the format

write_hist:
    Total num buckets: <n>
    Range min: <lower bound of smallest bucket>
    Range max: <upper bound of largest bucket>
    Bucket range 0:
        Range min: <lower bound of smallest bucket>
        Range max: <upper bound of largest bucket>
        Num buckets: <number of buckets this range is divided into (each bucket will have the same width)>
    Bucket range 1:
        ...
    ...
    Bucket range <n>:
        ...
read_hist:
    ...

This is followed by the raw latency data recorded during the run. This is in the format

<histogram name> <UTC_time> <elapsed time in seconds since last record> <total number of records> <bucket 1 lower bound>:<bucket count> <bucket 2 lower bound>:<bucket count> ...

The stage numbers and descriptions are also printed at the appropriate places between recordings.

Note that only non-zero buckets are printed, i.e. buckets with at least one record. Also, the lower bound of the bucket in milliseconds is used to identify the buckets.

Example run

Here is an example output from a run:

write_hist:
	Total num buckets: 115
	Range min: 100us
	Range max: 128000us
	Bucket range 0:
		Range min: 100us
		Range max: 4000us
		Bucket width: 100us
		Num buckets: 39
	Bucket range 1:
		Range min: 4000us
		Range max: 64000us
		Bucket width: 1000us
		Num buckets: 60
	Bucket range 2:
		Range min: 64000us
		Range max: 128000us
		Bucket width: 4000us
		Num buckets: 16
read_hist:
	Total num buckets: 115
	Range min: 100us
	Range max: 128000us
	Bucket range 0:
		Range min: 100us
		Range max: 4000us
		Bucket width: 100us
		Num buckets: 39
	Bucket range 1:
		Range min: 4000us
		Range max: 64000us
		Bucket width: 1000us
		Num buckets: 60
	Bucket range 2:
		Range min: 64000us
		Range max: 128000us
		Bucket width: 4000us
		Num buckets: 16
Stage 0: initialization stage
write_hist 2021-02-11T20:49:45Z, 0.123402s, 10000, 0:4571, 100:4191, 200:853, 300:174, 400:96, 500:31, 600:19, 700:2, 800:13, 900:13, 1000:4, 1100:7, 1200:3, 1300:2, 1400:2, 1500:1, 1800:1, 1900:1, 2000:3, 2100:1, 2200:2, 2300:1, 2500:1, 2700:1, 3300:3, 3400:2, 4000:1, 6000:1
read_hist 2021-02-11T20:49:45Z, 0.123402s, 0
Stage 1: random read/write stage
write_hist 2021-02-11T20:49:46Z, 1.00341s, 0
read_hist 2021-02-11T20:49:46Z, 1.00341s, 160, 0:16, 100:34, 200:39, 300:44, 400:12, 500:7, 600:4, 700:3, 800:1
write_hist 2021-02-11T20:49:47Z, 0.99933s, 0
read_hist 2021-02-11T20:49:47Z, 0.99933s, 144, 0:4, 100:18, 200:28, 300:45, 400:22, 500:12, 600:6, 700:1, 800:3, 900:1, 1000:2, 1200:1, 1300:1
write_hist 2021-02-11T20:49:48Z, 1.00001s, 0
read_hist 2021-02-11T20:49:48Z, 1.00001s, 160, 0:12, 100:55, 200:59, 300:20, 400:12, 500:1, 600:1
write_hist 2021-02-11T20:49:49Z, 0.998519s, 0
read_hist 2021-02-11T20:49:49Z, 0.998519s, 144, 0:4, 100:35, 200:36, 300:41, 400:18, 500:2, 600:5, 700:2, 1000:1
write_hist 2021-02-11T20:49:50Z, 0.998714s, 0
read_hist 2021-02-11T20:49:50Z, 0.998714s, 144, 0:12, 100:35, 200:45, 300:29, 400:11, 500:3, 600:7, 800:2
write_hist 2021-02-11T20:49:50Z, 0.002855s, 0
read_hist 2021-02-11T20:49:50Z, 0.002855s, 0
Stage 3: cleanup stage
write_hist 2021-02-11T20:49:50Z, 0.103364s, 10000, 0:4228, 100:4363, 200:953, 300:234, 400:95, 500:48, 600:28, 700:16, 800:9, 900:3, 1000:5, 1100:4, 1200:2, 1300:3, 1500:2, 1600:1, 1800:1, 2000:1, 2400:1, 2600:1, 4000:2
read_hist 2021-02-11T20:49:50Z, 0.103364s, 0