def region_exited(self, profiler, region):
"""Log 'Exit region' event.
"""
ts = region.timer.last_event_time - profiler.root.timer.begin_ts()
elapsed = region.timer.last_event_time - region.timer.begin_ts()
print('RegionProfiler: Exited {} at {} after {}'.format(
region.name, pretty_print_time(ts), pretty_print_time(elapsed)),
file=sys.stderr)
def region_canceled(self, profiler, region):
"""Log 'Exit region' event.
"""
ts = region.timer.last_event_time - profiler.root.timer.begin_ts()
print('RegionProfiler: Canceled {} at {}'.format(
region.name, pretty_print_time(ts)),
file=sys.stderr)
def main(p):
reps = 30
loop_reps = 100
recursion_depth = 100
for _ in range(reps):
for _ in range(loop_reps):
with rp.region('a'):
x = fact(recursion_depth)
for _ in range(loop_reps):
with rp.region('b1'):
with rp.region('b2'):
x = fact(recursion_depth)
for _ in range(loop_reps):
with rp.region('c1'):
with rp.region('c2'):
with rp.region('c3'):
x = fact(recursion_depth)
for _ in range(loop_reps):
x = timed_fact(recursion_depth)
nodes = p.root.children
inner_a = nodes['a'].stats.total / reps # F + r * loop_reps
inner_b1 = nodes['b1'].stats.total / reps # F + r * loop_reps * 2
inner_b2 = nodes['b1'].children['b2'].stats.total / reps # F + r * loop_reps
inner_c1 = nodes['c1'].stats.total / reps # F + r * loop_reps * 3
inner_c2 = nodes['c1'].children['c2'].stats.total / reps # F + r * loop_reps * 2
inner_c3 = nodes['c1'].children['c2'].children['c3'].stats.total / reps # F + r * loop_reps
func = nodes['timed_fact()'].stats.total / reps # F + r * loop_reps * recursion
stats = SeqStats()
stats.add((inner_b1 - inner_b2) / loop_reps)
stats.add((inner_b1 - inner_a) / loop_reps)
stats.add((inner_c2 - inner_c3) / loop_reps)
stats.add((inner_c1 - inner_c2) / loop_reps)
stats.add((func - inner_a) / (loop_reps * (recursion_depth - 1)))
print('Region overhead:\n\t{} .. {} .. {}'.
format(pretty_print_time(stats.min),
pretty_print_time(stats.avg),
pretty_print_time(stats.max)))
def test_pretty_print_time():
assert pretty_print_time(666) == '666 s'
assert pretty_print_time(100.44) == '100.4 s'
assert pretty_print_time(10.044) == '10.04 s'
assert pretty_print_time(1.0044) == '1.004 s'
assert pretty_print_time(0.13244) == '132.4 ms'
assert pretty_print_time(0.013244) == '13.24 ms'
assert pretty_print_time(0.0013244) == '1.324 ms'
assert pretty_print_time(0.00013244) == '132.4 us'
assert pretty_print_time(0.000013244) == '13.24 us'
assert pretty_print_time(0.0000013244) == '1.324 us'
assert pretty_print_time(0.00000013244) == '132 ns'
def average(this_slice, all_slices):
return pretty_print_time(this_slice.avg_time)
def total_inner(this_slice, all_slices):
return pretty_print_time(this_slice.total_inner_time)
def max(this_slice, all_slices):
return pretty_print_time(this_slice.max_time)
def min(this_slice, all_slices):
return pretty_print_time(this_slice.min_time)