def test_stopwatch_full_cancel(self):
"""Test that an entire span - from root to children, can be cancelled."""
sw = StopWatch()
sw.start('root')
sw.start('child')
sw.start('grand')
sw.cancel('grand')
sw.cancel('child')
sw.cancel('root')
assert not sw.get_last_aggregated_report()
assert not sw._cancelled_spans
sw = StopWatch()
with sw.timer('root'):
with sw.timer('child'):
with sw.timer('grandchild'):
sw.cancel('grandchild')
sw.cancel('child')
sw.cancel('root')
assert not sw.get_last_aggregated_report()
assert not sw._cancelled_spans
def test_stopwatch_cancel_context_manager(self):
"""Test that spans can be cancelled while inside a span context."""
sw = StopWatch()
with sw.timer('root'):
with sw.timer('child'):
sw.cancel('child')
with sw.timer('grand'):
pass
agg_values = sw.get_last_aggregated_report().aggregated_values
assert len(agg_values) == 2
assert all([span in agg_values for span in ('root', 'root#grand')])
def test_scope_in_loop(self):
sw = StopWatch()
with sw.timer('root', start_time=20, end_time=120):
for t in range(30, 100, 10):
with sw.timer('child', start_time=t, end_time=t + 5):
pass
agg_report = sw.get_last_aggregated_report()
assert agg_report.aggregated_values == {
'root': [100000.0, 1, None],
'root#child': [35000.0, 7, None],
}
assert agg_report.root_timer_data.start_time == 20.0
assert agg_report.root_timer_data.end_time == 120.0
assert agg_report.root_timer_data.name == 'root'
def test_scope_in_loop(self):
sw = StopWatch()
with sw.timer('root', start_time=20, end_time=120):
for t in range(30, 100, 10):
with sw.timer('child', start_time=t, end_time=t + 5):
pass
agg_report = sw.get_last_aggregated_report()
assert agg_report.aggregated_values == {
'root': [100000.0, 1, None],
'root#child': [35000.0, 7, None],
}
assert agg_report.root_timer_data.start_time == 20.0
assert agg_report.root_timer_data.end_time == 120.0
assert agg_report.root_timer_data.name == 'root'
def test_time_func_default(self):
"""Make sure that the default time_func=None"""
sw = StopWatch(time_func=None)
with sw.timer('root'):
pass
agg_report = sw.get_last_aggregated_report()
tr_data = agg_report.root_timer_data
assert tr_data.name == 'root'
assert tr_data.end_time >= tr_data.start_time
def test_time_func_default(self):
"""Make sure that the default time_func=None"""
sw = StopWatch(time_func=None)
with sw.timer('root'):
pass
agg_report = sw.get_last_aggregated_report()
tr_data = agg_report.root_timer_data
assert tr_data.name == 'root'
assert tr_data.end_time >= tr_data.start_time
def test_sampling_timer(self):
for i in range(100):
sw = StopWatch()
with sw.timer('root', start_time=20, end_time=120):
with sw.sampling_timer('child', p=0.5, start_time=40, end_time=100):
pass
agg_report = sw.get_last_aggregated_report()
assert len(agg_report.aggregated_values) in (1, 2)
if len(agg_report.aggregated_values) == 2:
assert agg_report.aggregated_values['root#child'] == [60000.0, 1, None]
def test_multiple_root_spans(self):
"""Test multiple root spans timed in one instance of the StopWatch object."""
sw = StopWatch()
with sw.timer('root'):
with sw.timer('child'):
pass
agg_values = sw.get_last_aggregated_report().aggregated_values
assert len(agg_values) == 2
assert all([span in agg_values for span in ('root', 'root#child')])
with sw.timer('root'):
with sw.timer('different_child'):
pass
agg_values = sw.get_last_aggregated_report().aggregated_values
assert len(agg_values) == 2
assert all([span in agg_values for span in ('root', 'root#different_child')])
def test_scope_in_loop(self):
export_timers = Mock()
sw = StopWatch(
export_aggregated_timers_func=export_timers,
)
with sw.timer('root', start_time=20, end_time=120):
for t in range(30, 100, 10):
with sw.timer('child', start_time=t, end_time=t + 5):
pass
export_timers.assert_called_once_with(
reported_values={
'root': [100000.0, 1, None],
'root#child': [35000.0, 7, None],
},
tags=set(),
total_time_ms=100000.0,
root_span_name="root",
)
def test_trace_annotations(self):
sw = StopWatch()
sw.add_annotation('key0', 'value0', event_time=0)
with sw.timer('root', start_time=10, end_time=1000):
with sw.timer('child', start_time=20, end_time=900):
sw.add_span_annotation('key1', 'value1', event_time=101)
sw.add_span_annotation('key2', 'value2', event_time=104)
sw.add_annotation('key3', 'value3', event_time=107)
trace_report = sw.get_last_trace_report()
assert len(trace_report) == 2
assert trace_report[0].name == 'child'
assert trace_report[0].trace_annotations == [
TraceAnnotation('key1', 'value1', 101),
TraceAnnotation('key2', 'value2', 104),
]
assert trace_report[1].name == 'root'
assert trace_report[1].trace_annotations == [
TraceAnnotation('key0', 'value0', 0),
TraceAnnotation('key3', 'value3', 107),
]
def test_trace_annotations(self):
sw = StopWatch()
sw.add_annotation('key0', 'value0', event_time=0)
with sw.timer('root', start_time=10, end_time=1000):
with sw.timer('child', start_time=20, end_time=900):
sw.add_span_annotation('key1', 'value1', event_time=101)
sw.add_span_annotation('key2', 'value2', event_time=104)
sw.add_annotation('key3', 'value3', event_time=107)
trace_report = sw.get_last_trace_report()
assert len(trace_report) == 2
assert trace_report[0].name == 'child'
assert trace_report[0].trace_annotations == [
TraceAnnotation('key1', 'value1', 101),
TraceAnnotation('key2', 'value2', 104),
]
assert trace_report[1].name == 'root'
assert trace_report[1].trace_annotations == [
TraceAnnotation('key0', 'value0', 0),
TraceAnnotation('key3', 'value3', 107),
]
def test_stopwatch_cancel_multiple_root_spans(self):
"""Test that spans can be cancelled inside a span context, with multiple
of the same root span created. Ensure that they behave in an expected way.
"""
sw = StopWatch()
with sw.timer('root'):
with sw.timer('child'):
sw.cancel('child')
pass
with sw.timer('root'):
with sw.timer('child'):
pass
agg_values = sw.get_last_aggregated_report().aggregated_values
assert len(agg_values) == 2
assert all([span in agg_values for span in ('root', 'root#child')])
# Ensure that we are not leaking cancelled span data
assert not sw._cancelled_spans
def test_exception_annotation(self):
class SpecialError(Exception):
pass
sw = StopWatch()
with pytest.raises(SpecialError):
with sw.timer('root', start_time=10, end_time=1000):
raise SpecialError("Ahhh")
trace_report = sw.get_last_trace_report()
assert trace_report[0].trace_annotations == [
TraceAnnotation('Exception', 'SpecialError', 1000),
]
def test_exception_annotation(self):
class SpecialError(Exception):
pass
sw = StopWatch()
with pytest.raises(SpecialError):
with sw.timer('root', start_time=10, end_time=1000):
raise SpecialError("Ahhh")
trace_report = sw.get_last_trace_report()
assert trace_report[0].trace_annotations == [
TraceAnnotation('Exception', 'SpecialError', 1000),
]
def test_time_func(self):
"""Test override of the time_func"""
time_mock = Mock(side_effect=[50, 70])
sw = StopWatch(time_func=time_mock)
# Should call our timer func once on entry and once on exit
with sw.timer('root'):
pass
agg_report = sw.get_last_aggregated_report()
assert agg_report.aggregated_values == {
'root': [20000.0, 1, None],
}
assert agg_report.root_timer_data.start_time == 50.0
assert agg_report.root_timer_data.end_time == 70.0
assert agg_report.root_timer_data.name == 'root'
def test_time_func(self):
"""Test override of the time_func"""
time_mock = Mock(side_effect=[50, 70])
sw = StopWatch(time_func=time_mock)
# Should call our timer func once on entry and once on exit
with sw.timer('root'):
pass
agg_report = sw.get_last_aggregated_report()
assert agg_report.aggregated_values == {
'root': [20000.0, 1, None],
}
assert agg_report.root_timer_data.start_time == 50.0
assert agg_report.root_timer_data.end_time == 70.0
assert agg_report.root_timer_data.name == 'root'
def test_time_func(self):
export_mock = Mock()
time_mock = Mock(side_effect=[50, 70])
sw = StopWatch(export_aggregated_timers_func=export_mock, time_func=time_mock)
# Should call our timer func once on entry and once on exit
with sw.timer('root'):
pass
export_mock.assert_called_once_with(
reported_values={
'root': [20000.0, 1, None],
},
tags=set(),
total_time_ms=20000.0,
root_span_name="root",
)
def test_export_default(self):
"""Make sure that passing None in explicitly works"""
sw = StopWatch(export_aggregated_timers_func=None,
export_tracing_func=None)
with sw.timer('root'):
pass
def test_export_default(self):
"""Make sure that passing None in explicitly works"""
sw = StopWatch(export_aggregated_timers_func=None, export_tracing_func=None)
with sw.timer('root'):
pass
