def __init__(self, latency_list=None):
"""Create a latency instance.
latency_list: aggregate all latency values from list if not None
"""
self.min_usec = sys.maxsize
self.max_usec = 0
self.avg_usec = 0
self.hdrh = None
if latency_list:
hdrh_list = []
for lat in latency_list:
if lat.available():
self.min_usec = min(self.min_usec, lat.min_usec)
self.max_usec = max(self.max_usec, lat.max_usec)
self.avg_usec += lat.avg_usec
if lat.hdrh_available():
hdrh_list.append(HdrHistogram.decode(lat.hdrh))
# aggregate histograms if any
if hdrh_list:
def add_hdrh(x, y):
x.add(y)
return x
decoded_hdrh = reduce(add_hdrh, hdrh_list)
self.hdrh = HdrHistogram.encode(decoded_hdrh).decode('utf-8')
# round to nearest usec
self.avg_usec = int(round(float(self.avg_usec) / len(latency_list)))
def __call__(
self,
*,
started_workunits: tuple[Workunit, ...],
completed_workunits: tuple[Workunit, ...],
finished: bool,
context: StreamingWorkunitContext,
) -> None:
if not self.enabled:
return
# Aggregate counters on completed workunits.
for workunit in completed_workunits:
if "counters" in workunit:
for name, value in workunit["counters"].items():
self.counters[name] += value
if not finished:
return
# Add any counters with a count of 0.
for counter in context.run_tracker.counter_names:
if counter not in self.counters:
self.counters[counter] = 0
# Log aggregated counters.
counter_lines = "\n".join(
f" {name}: {count}"
for name, count in sorted(self.counters.items()))
logger.info(f"Counters:\n{counter_lines}")
if not self.has_histogram_module:
return
from hdrh.histogram import HdrHistogram
histograms = context.get_observation_histograms()["histograms"]
if not histograms:
logger.info("No observation histogram were recorded.")
return
logger.info("Observation histogram summaries:")
for name, encoded_histogram in histograms.items():
# Note: The Python library for HDR Histogram will only decode compressed histograms
# that are further encoded with base64. See
# https://github.com/HdrHistogram/HdrHistogram_py/issues/29.
histogram = HdrHistogram.decode(
base64.b64encode(encoded_histogram))
percentile_to_vals = "\n".join(
f" p{percentile}: {value}" for percentile, value in histogram.
get_percentile_to_value_dict([25, 50, 75, 90, 95, 99]).items())
logger.info(f"Summary of `{name}` observation histogram:\n"
f" min: {histogram.get_min_value()}\n"
f" max: {histogram.get_max_value()}\n"
f" mean: {histogram.get_mean_value():.3f}\n"
f" std dev: {histogram.get_stddev():.3f}\n"
f" total observations: {histogram.total_count}\n"
f"{percentile_to_vals}")
def from_row(cls, row, prefix=""):
if row is None:
return None
else:
raw_histo = row[prefix + "jitterHistogram"]
return cls(
row[prefix + "measurementID"], row[prefix + "serviceSetID"],
row[prefix + "minJitter"], row[prefix + "maxJitter"],
row[prefix + "avgJitter"], row[prefix + "stdDevJitter"],
HdrHistogram.decode(raw_histo, b64_wrap=False)
if raw_histo else None, row[prefix + "jitterHistogramOffset"],
row[prefix + "interval"],
cls._json_loads(row[prefix + "extraJSONData"]))
def _decode_next_interval_histogram(self,
dest_histogram,
range_start_time_sec=0.0,
range_end_time_sec=sys.maxsize,
absolute=False):
'''Read the next interval histogram from the log, if interval falls
within an absolute or relative time range.
Timestamps are assumed to appear in order in the log file, and as such
this method will return a null upon encountering a timestamp larger than
range_end_time_sec.
Relative time range:
the range is assumed to be in seconds relative to
the actual timestamp value found in each interval line in the log
Absolute time range:
Absolute timestamps are calculated by adding the timestamp found
with the recorded interval to the [latest, optional] start time
found in the log. The start time is indicated in the log with
a "#[StartTime: " followed by the start time in seconds.
Params:
dest_histogram if None, created a new histogram, else adds
the new interval histogram to it
range_start_time_sec The absolute or relative start of the expected
time range, in seconds.
range_start_time_sec The absolute or relative end of the expected
time range, in seconds.
absolute Defines if the passed range is absolute or relative
Return:
Returns an histogram object if an interval line was found with an
associated start timestamp value that falls between start_time_sec and
end_time_sec,
or null if no such interval line is found.
Upon encountering any unexpected format errors in reading the next
interval from the file, this method will return None.
The histogram returned will have it's timestamp set to the absolute
timestamp calculated from adding the interval's indicated timestamp
value to the latest [optional] start time found in the log.
Exceptions:
ValueError if there is a syntax error in one of the float fields
'''
while 1:
line = self.input_file.readline()
if not line:
return None
if line[0] == '#':
match_res = re_start_time.match(line)
if match_res:
self.start_time_sec = float(match_res.group(1))
self.observed_start_time = True
continue
match_res = re_base_time.match(line)
if match_res:
self.base_time_sec = float(match_res.group(1))
self.observed_base_time = True
continue
match_res = re_histogram_interval.match(line)
if not match_res:
# probably a legend line that starts with "\"StartTimestamp"
continue
# Decode: startTimestamp, intervalLength, maxTime, histogramPayload
# Timestamp is expected to be in seconds
log_time_stamp_in_sec = float(match_res.group(1))
interval_length_sec = float(match_res.group(2))
cpayload = match_res.group(4)
if not self.observed_start_time:
# No explicit start time noted. Use 1st observed time:
self.start_time_sec = log_time_stamp_in_sec
self.observed_start_time = True
if not self.observed_base_time:
# No explicit base time noted.
# Deduce from 1st observed time (compared to start time):
if log_time_stamp_in_sec < self.start_time_sec - (365 * 24 *
3600.0):
# Criteria Note: if log timestamp is more than a year in
# the past (compared to StartTime),
# we assume that timestamps in the log are not absolute
self.base_time_sec = self.start_time_sec
else:
# Timestamps are absolute
self.base_time_sec = 0.0
self.observed_base_time = True
absolute_start_time_stamp_sec = \
log_time_stamp_in_sec + self.base_time_sec
offset_start_time_stamp_sec = \
absolute_start_time_stamp_sec - self.start_time_sec
# Timestamp length is expect to be in seconds
absolute_end_time_stamp_sec = \
absolute_start_time_stamp_sec + interval_length_sec
if absolute:
start_time_stamp_to_check_range_on = absolute_start_time_stamp_sec
else:
start_time_stamp_to_check_range_on = offset_start_time_stamp_sec
if start_time_stamp_to_check_range_on < range_start_time_sec:
continue
if start_time_stamp_to_check_range_on > range_end_time_sec:
return None
if dest_histogram:
# add the interval histogram to the destination histogram
histogram = dest_histogram
histogram.decode_and_add(cpayload)
else:
histogram = HdrHistogram.decode(cpayload)
histogram.set_start_time_stamp(absolute_start_time_stamp_sec *
1000.0)
histogram.set_end_time_stamp(absolute_end_time_stamp_sec *
1000.0)
return histogram
def _decode_next_interval_histogram(self,
dest_histogram,
range_start_time_sec=0.0,
range_end_time_sec=sys.maxint,
absolute=False):
'''Read the next interval histogram from the log, if interval falls
within an absolute or relative time range.
Timestamps are assumed to appear in order in the log file, and as such
this method will return a null upon encountering a timestamp larger than
range_end_time_sec.
Relative time range:
the range is assumed to be in seconds relative to
the actual timestamp value found in each interval line in the log
Absolute time range:
Absolute timestamps are calculated by adding the timestamp found
with the recorded interval to the [latest, optional] start time
found in the log. The start time is indicated in the log with
a "#[StartTime: " followed by the start time in seconds.
Params:
dest_histogram if None, created a new histogram, else adds
the new interval histogram to it
range_start_time_sec The absolute or relative start of the expected
time range, in seconds.
range_start_time_sec The absolute or relative end of the expected
time range, in seconds.
absolute Defines if the passed range is absolute or relative
Return:
Returns an histogram object if an interval line was found with an
associated start timestamp value that falls between start_time_sec and
end_time_sec,
or null if no such interval line is found.
Upon encountering any unexpected format errors in reading the next
interval from the file, this method will return None.
The histogram returned will have it's timestamp set to the absolute
timestamp calculated from adding the interval's indicated timestamp
value to the latest [optional] start time found in the log.
Exceptions:
ValueError if there is a syntax error in one of the float fields
'''
while 1:
line = self.input_file.readline()
if not line:
return None
if line[0] == '#':
match_res = re_start_time.match(line)
if match_res:
self.start_time_sec = float(match_res.group(1))
self.observed_start_time = True
continue
match_res = re_base_time.match(line)
if match_res:
self.base_time = float(match_res.group(1))
self.observed_base_time = True
continue
match_res = re_histogram_interval.match(line)
if not match_res:
# probably a legend line that starts with "\"StartTimestamp"
continue
# Decode: startTimestamp, intervalLength, maxTime, histogramPayload
# Timestamp is expected to be in seconds
log_time_stamp_in_sec = float(match_res.group(1))
interval_length_sec = float(match_res.group(2))
cpayload = match_res.group(4)
if not self.observed_start_time:
# No explicit start time noted. Use 1st observed time:
self.start_time_sec = log_time_stamp_in_sec
self.observed_start_time = True
if not self.observed_base_time:
# No explicit base time noted.
# Deduce from 1st observed time (compared to start time):
if log_time_stamp_in_sec < self.start_time_sec - (365 * 24 * 3600.0):
# Criteria Note: if log timestamp is more than a year in
# the past (compared to StartTime),
# we assume that timestamps in the log are not absolute
self.base_time_sec = self.start_time_sec
else:
# Timestamps are absolute
self.base_time_sec = 0.0
self.observed_base_time = True
absolute_start_time_stamp_sec = \
log_time_stamp_in_sec + self.base_time_sec
offset_start_time_stamp_sec = \
absolute_start_time_stamp_sec - self.start_time_sec
# Timestamp length is expect to be in seconds
absolute_end_time_stamp_sec = \
absolute_start_time_stamp_sec + interval_length_sec
if absolute:
start_time_stamp_to_check_range_on = absolute_start_time_stamp_sec
else:
start_time_stamp_to_check_range_on = offset_start_time_stamp_sec
if start_time_stamp_to_check_range_on < range_start_time_sec:
continue
if start_time_stamp_to_check_range_on > range_end_time_sec:
return None
if dest_histogram:
# add the interval histogram to the destination histogram
histogram = dest_histogram
histogram.decode_and_add(cpayload)
else:
histogram = HdrHistogram.decode(cpayload)
histogram.set_start_time_stamp(absolute_start_time_stamp_sec * 1000.0)
histogram.set_end_time_stamp(absolute_end_time_stamp_sec * 1000.0)
return histogram
def __call__(
self,
*,
started_workunits: tuple[Workunit, ...],
completed_workunits: tuple[Workunit, ...],
finished: bool,
context: StreamingWorkunitContext,
) -> None:
if not finished:
return
if self.log:
# Capture global counters.
counters = Counter(context.get_metrics())
# Add any counters with a count of 0.
for counter in context.run_tracker.counter_names:
if counter not in counters:
counters[counter] = 0
# Log aggregated counters.
counter_lines = "\n".join(
f" {name}: {count}"
for name, count in sorted(counters.items()))
logger.info(f"Counters:\n{counter_lines}")
if self.memory:
ids: set[int] = set()
count_by_type: Counter[type] = Counter()
sizes_by_type: Counter[type] = Counter()
items, rust_sizes = context._scheduler.live_items()
for item in items:
count_by_type[type(item)] += 1
sizes_by_type[type(item)] += deep_getsizeof(item, ids)
entries = [(size, count_by_type[typ],
f"{typ.__module__}.{typ.__qualname__}")
for typ, size in sizes_by_type.items()]
entries.extend((size, count, f"(native) {name}")
for name, (count, size) in rust_sizes.items())
memory_lines = "\n".join(f" {size}\t\t{count}\t\t{name}"
for size, count, name in sorted(entries))
logger.info(
f"Memory summary (total size in bytes, count, name):\n{memory_lines}"
)
if not (self.log and self.has_histogram_module):
return
from hdrh.histogram import HdrHistogram # pants: no-infer-dep
histograms = context.get_observation_histograms()["histograms"]
if not histograms:
logger.info("No observation histogram were recorded.")
return
logger.info("Observation histogram summaries:")
for name, encoded_histogram in histograms.items():
# Note: The Python library for HDR Histogram will only decode compressed histograms
# that are further encoded with base64. See
# https://github.com/HdrHistogram/HdrHistogram_py/issues/29.
histogram = HdrHistogram.decode(
base64.b64encode(encoded_histogram))
percentile_to_vals = "\n".join(
f" p{percentile}: {value}" for percentile, value in histogram.
get_percentile_to_value_dict([25, 50, 75, 90, 95, 99]).items())
logger.info(f"Summary of `{name}` observation histogram:\n"
f" min: {histogram.get_min_value()}\n"
f" max: {histogram.get_max_value()}\n"
f" mean: {histogram.get_mean_value():.3f}\n"
f" std dev: {histogram.get_stddev():.3f}\n"
f" total observations: {histogram.total_count}\n"
f"{percentile_to_vals}")
