You cannot select more than 25 topics Topics must start with a letter or number, can include dashes ('-') and can be up to 35 characters long.
mitogen/tests/ansible/lib/callback/fork_histogram.py

97 lines
3.1 KiB
Python

# Monkey-patch os.fork() to produce a latency histogram on run completion.
# Requires 'hdrhsitograms' PyPI module.
from __future__ import print_function
import os
import resource
import sys
import time
import ansible.plugins.callback
import hdrh.histogram
def get_fault_count(who=resource.RUSAGE_CHILDREN):
ru = resource.getrusage(who)
return ru.ru_minflt + ru.ru_majflt
class CallbackModule(ansible.plugins.callback.CallbackBase):
hist = None
def v2_playbook_on_start(self, playbook):
if self.hist is not None:
return
self.hist = hdrh.histogram.HdrHistogram(1, int(1e6*60), 3)
self.fork_latency_sum_usec = 0.0
if 'FORK_HISTOGRAM' in os.environ:
self.install()
def install(self):
self.faults_at_start = get_fault_count(resource.RUSAGE_SELF)
self.run_start_time = time.time()
self.real_fork = os.fork
os.fork = self.my_fork
self_fault_usec = 1.113664156753052
child_fault_usec = 4.734975610975617
dummy_heap_size = int(os.environ.get('FORK_STATS_FAKE_HEAP_MB', '0'))
dummy_heap = 'x' * (dummy_heap_size * 1048576)
def my_fork(self):
# doesnt count last child, oh well
now_faults = get_fault_count()
t0 = time.time()
try:
return self.real_fork()
finally:
latency_usec = (1e6 * (time.time() - t0))
self.fork_latency_sum_usec += latency_usec
self.hist.record_value(latency_usec)
def playbook_on_stats(self, stats):
if 'FORK_HISTOGRAM' not in os.environ:
return
self_faults = get_fault_count(resource.RUSAGE_SELF) - self.faults_at_start
child_faults = get_fault_count()
run_duration_sec = time.time() - self.run_start_time
fault_wastage_usec = (
((self.self_fault_usec * self_faults) +
(self.child_fault_usec * child_faults))
)
fork_wastage = self.hist.get_total_count()
all_wastage_usec = ((2*self.fork_latency_sum_usec) + fault_wastage_usec)
print('--- Fork statistics ---')
print('Post-boot run duration: %.02f ms, %d total forks' % (
1000 * run_duration_sec,
self.hist.get_total_count(),
))
print('Self faults during boot: %d, post-boot: %d, avg %d/child' % (
self.faults_at_start,
self_faults,
self_faults / self.hist.get_total_count(),
))
print('Total child faults: %d, avg %d/child' % (
child_faults,
child_faults / self.hist.get_total_count(),
))
print('Est. wastage on faults: %d ms, forks+faults+waits: %d ms (%.2f%%)' % (
fault_wastage_usec / 1000,
all_wastage_usec / 1000,
100 * (all_wastage_usec / (run_duration_sec * 1e6)),
))
print('99th%% fork latency: %.03f msec, max %d new tasks/sec' % (
self.hist.get_value_at_percentile(99) / 1000.0,
1e6 / self.hist.get_value_at_percentile(99),
))
self.hist.output_percentile_distribution(sys.stdout, 1000)
print('--- End fork statistics ---')
print()