def test_log_unfinished_spans_disabled(self, log):
# the trace finished status logging is disabled
tracer = get_dummy_tracer()
ctx = Context()
# manually create a root-child trace
root = Span(tracer=tracer, name='root')
child_1 = Span(tracer=tracer,
name='child_1',
trace_id=root.trace_id,
parent_id=root.span_id)
child_2 = Span(tracer=tracer,
name='child_2',
trace_id=root.trace_id,
parent_id=root.span_id)
child_1._parent = root
child_2._parent = root
ctx.add_span(root)
ctx.add_span(child_1)
ctx.add_span(child_2)
# close only the parent
root.finish()
# the logger has never been invoked to print unfinished spans
for call, _ in log.call_args_list:
msg = call[0]
assert 'the trace has %d unfinished spans' not in msg
def test_partial_flush_too_few(self):
"""
When calling `Context.get`
When partial flushing is enabled
When we do not have enough finished spans to flush
We return no spans
"""
tracer = get_dummy_tracer()
ctx = Context()
# Create a root span with 5 children, all of the children are finished, the root is not
root = Span(tracer=tracer, name='root')
ctx.add_span(root)
for i in range(5):
child = Span(tracer=tracer,
name='child_{}'.format(i),
trace_id=root.trace_id,
parent_id=root.span_id)
child._parent = root
child.finished = True
ctx.add_span(child)
ctx.close_span(child)
# Test with having 1 too few spans for partial flush
with self.override_partial_flush(ctx, enabled=True, min_spans=6):
trace, sampled = ctx.get()
self.assertIsNone(trace)
self.assertIsNone(sampled)
self.assertEqual(len(ctx._trace), 6)
self.assertEqual(
set([
'root', 'child_0', 'child_1', 'child_2', 'child_3', 'child_4'
]), set([span.name for span in ctx._trace]))
def test_log_unfinished_spans(log, tracer_with_debug_logging):
# when the root parent is finished, notify if there are spans still pending
tracer = tracer_with_debug_logging
ctx = Context()
# manually create a root-child trace
root = Span(tracer=tracer, name='root')
child_1 = Span(tracer=tracer,
name='child_1',
trace_id=root.trace_id,
parent_id=root.span_id)
child_2 = Span(tracer=tracer,
name='child_2',
trace_id=root.trace_id,
parent_id=root.span_id)
child_1._parent = root
child_2._parent = root
ctx.add_span(root)
ctx.add_span(child_1)
ctx.add_span(child_2)
# close only the parent
root.finish()
unfinished_spans_log = log.call_args_list[-3][0][2]
child_1_log = log.call_args_list[-2][0][1]
child_2_log = log.call_args_list[-1][0][1]
assert 2 == unfinished_spans_log
assert 'name child_1' in child_1_log
assert 'name child_2' in child_2_log
assert 'duration 0.000000s' in child_1_log
assert 'duration 0.000000s' in child_2_log
def test_finish_set_span_duration(self):
# If set the duration on a span, the span should be recorded with this
# duration
s = Span(tracer=None, name='test.span')
s.duration = 1337.0
s.finish()
assert s.duration == 1337.0
def test_tags_not_string(self):
# ensure we can cast as strings
class Foo(object):
def __repr__(self):
1 / 0
s = Span(tracer=None, name='test.span')
s.set_tag('a', Foo())
def test_finish_called_multiple_times(self):
# we should only record a span the first time finish is called on it
ctx = Context()
s = Span(self.tracer, 'bar', context=ctx)
ctx.add_span(s)
s.finish()
s.finish()
self.assert_span_count(1)
def create_span(tracer=None, name='test.span', meta=None, *args, **kwargs):
tracer = tracer or get_dummy_tracer()
if 'context' not in kwargs:
kwargs['context'] = tracer.get_call_context()
span = Span(tracer=tracer, name=name, *args, **kwargs)
if meta:
span.set_tags(meta)
return span
def test_list_no_match(self):
span = Span(name='Name', tracer=None)
span.set_tag(URL, r'http://cooldomain.example.com')
filtr = FilterRequestsOnUrl([
r'http://domain\.example\.com',
r'http://anotherdomain\.example\.com'
])
trace = filtr.process_trace([span])
self.assertIsNotNone(trace)
def test_context_sampled(self):
# a context is sampled if the spans are sampled
ctx = Context()
span = Span(tracer=None, name='fake_span')
ctx.add_span(span)
span.finish()
trace, sampled = ctx.get()
assert sampled is True
assert ctx.sampling_priority is None
def test_numeric_tags_value(self):
s = Span(tracer=None, name='test.span')
s.set_tag(ANALYTICS_SAMPLE_RATE_KEY, 0.5)
d = s.to_dict()
assert d
expected = {
ANALYTICS_SAMPLE_RATE_KEY: 0.5
}
assert d['metrics'] == expected
def test_ids(self):
s = Span(tracer=None, name='span.test')
assert s.trace_id
assert s.span_id
assert not s.parent_id
s2 = Span(tracer=None, name='t', trace_id=1, span_id=2, parent_id=1)
assert s2.trace_id == 1
assert s2.span_id == 2
assert s2.parent_id == 1
def test_get_trace(self):
# it should return the internal trace structure
# if the context is finished
ctx = Context()
span = Span(tracer=None, name='fake_span')
ctx.add_span(span)
span.finish()
trace, sampled = ctx.get()
assert [span] == trace
assert sampled is True
# the context should be empty
assert 0 == len(ctx._trace)
assert ctx._current_span is None
def test_tags(self):
s = Span(tracer=None, name='test.span')
s.set_tag('a', 'a')
s.set_tag('b', 1)
s.set_tag('c', '1')
d = s.to_dict()
expected = {
'a': 'a',
'b': '1',
'c': '1',
}
assert d['meta'] == expected
def test_sampling_rule_sample_rate_1():
tracer = get_dummy_tracer()
rule = SamplingRule(sample_rate=1)
iterations = int(1e4)
assert all(
rule.sample(Span(tracer=tracer, name=i)) for i in range(iterations))
def test_span_to_dict(self):
s = Span(tracer=None, name='test.span', service='s', resource='r')
s.span_type = 'foo'
s.set_tag('a', '1')
s.set_meta('b', '2')
s.finish()
d = s.to_dict()
assert d
assert d['span_id'] == s.span_id
assert d['trace_id'] == s.trace_id
assert d['parent_id'] == s.parent_id
assert d['meta'] == {'a': '1', 'b': '2'}
assert d['type'] == 'foo'
assert d['error'] == 0
assert type(d['error']) == int
def test_add_span(self):
# it should add multiple spans
ctx = Context()
span = Span(tracer=None, name='fake_span')
ctx.add_span(span)
assert 1 == len(ctx._trace)
assert 'fake_span' == ctx._trace[0].name
assert ctx == span.context
def test_get_trace_empty(self):
# it should return None if the Context is not finished
ctx = Context()
span = Span(tracer=None, name='fake_span')
ctx.add_span(span)
trace, sampled = ctx.get()
assert trace is None
assert sampled is None
def test_close_span(self):
# it should keep track of closed spans, moving
# the current active to it's parent
ctx = Context()
span = Span(tracer=None, name='fake_span')
ctx.add_span(span)
ctx.close_span(span)
assert ctx.get_current_span() is None
def test_context_priority(self):
# a context is sampled if the spans are sampled
ctx = Context()
for priority in [
USER_REJECT, AUTO_REJECT, AUTO_KEEP, USER_KEEP, None, 999
]:
ctx.sampling_priority = priority
span = Span(tracer=None, name=('fake_span_%s' % repr(priority)))
ctx.add_span(span)
span.finish()
# It's "normal" to have sampled be true even when priority sampling is
# set to 0 or -1. It would stay false even even with priority set to 2.
# The only criteria to send (or not) the spans to the agent should be
# this "sampled" attribute, as it's tightly related to the trace weight.
assert priority == ctx.sampling_priority
trace, sampled = ctx.get()
assert sampled is True, 'priority has no impact on sampled status'
def test_traceback_without_error(self):
s = Span(None, 'test.span')
s.set_traceback()
assert not s.error
assert not s.get_tag(errors.ERROR_MSG)
assert not s.get_tag(errors.ERROR_TYPE)
assert 'in test_traceback_without_error' in s.get_tag(errors.ERROR_STACK)
def test_set_invalid_metric(self):
s = Span(tracer=None, name='test.span')
invalid_metrics = [
None,
{},
[],
s,
'quarante-douze',
float('nan'),
float('inf'),
1j
]
for i, m in enumerate(invalid_metrics):
k = str(i)
s.set_metric(k, m)
assert s.get_metric(k) is None
def test_partial_flush_remaining(self):
"""
When calling `Context.get`
When partial flushing is enabled
When we have some unfinished spans
We keep the unfinished spans around
"""
tracer = get_dummy_tracer()
ctx = Context()
# Create a root span with 5 children, all of the children are finished, the root is not
root = Span(tracer=tracer, name='root')
ctx.add_span(root)
for i in range(10):
child = Span(tracer=tracer,
name='child_{}'.format(i),
trace_id=root.trace_id,
parent_id=root.span_id)
child._parent = root
ctx.add_span(child)
# CLose the first 5 only
if i < 5:
child.finished = True
ctx.close_span(child)
with self.override_partial_flush(ctx, enabled=True, min_spans=5):
trace, sampled = ctx.get()
# Assert partially flushed spans
self.assertTrue(len(trace), 5)
self.assertIsNotNone(sampled)
self.assertEqual(
set(['child_0', 'child_1', 'child_2', 'child_3', 'child_4']),
set([span.name for span in trace]))
# Assert remaining unclosed spans
self.assertEqual(len(ctx._trace), 6)
self.assertEqual(
set([
'root', 'child_5', 'child_6', 'child_7', 'child_8', 'child_9'
]),
set([span.name for span in ctx._trace]),
)
def test_clone(self):
ctx = Context()
ctx.sampling_priority = 2
# manually create a root-child trace
root = Span(tracer=None, name='root')
child = Span(tracer=None,
name='child_1',
trace_id=root.trace_id,
parent_id=root.span_id)
child._parent = root
ctx.add_span(root)
ctx.add_span(child)
cloned_ctx = ctx.clone()
assert cloned_ctx._parent_trace_id == ctx._parent_trace_id
assert cloned_ctx._parent_span_id == ctx._parent_span_id
assert cloned_ctx._sampling_priority == ctx._sampling_priority
assert cloned_ctx._otel_origin == ctx._otel_origin
assert cloned_ctx._current_span == ctx._current_span
assert cloned_ctx._trace == []
def test_ctx_mgr(self):
s = Span(self.tracer, 'bar')
assert not s.duration
assert not s.error
e = Exception('boo')
try:
with s:
time.sleep(0.01)
raise e
except Exception as out:
assert out == e
assert s.duration > 0, s.duration
assert s.error
assert s.get_tag(errors.ERROR_MSG) == 'boo'
assert 'Exception' in s.get_tag(errors.ERROR_TYPE)
assert s.get_tag(errors.ERROR_STACK)
else:
assert 0, 'should have failed'
def test_partial_flush_too_many(self):
"""
When calling `Context.get`
When partial flushing is enabled
When we have more than the minimum number of spans needed to flush
We return the finished spans
"""
tracer = get_dummy_tracer()
ctx = Context()
# Create a root span with 5 children, all of the children are finished, the root is not
root = Span(tracer=tracer, name='root')
ctx.add_span(root)
for i in range(5):
child = Span(tracer=tracer,
name='child_{}'.format(i),
trace_id=root.trace_id,
parent_id=root.span_id)
child._parent = root
child.finished = True
ctx.add_span(child)
ctx.close_span(child)
with self.override_partial_flush(ctx, enabled=True, min_spans=1):
trace, sampled = ctx.get()
self.assertIsNotNone(trace)
self.assertIsNotNone(sampled)
self.assertEqual(len(trace), 5)
self.assertEqual(
set(['child_0', 'child_1', 'child_2', 'child_3', 'child_4']),
set([span.name for span in trace]))
# Ensure we clear/reset internal stats as expected
self.assertEqual(ctx._trace, [root])
with self.override_partial_flush(ctx, enabled=True, min_spans=5):
trace, sampled = ctx.get()
self.assertIsNone(trace)
self.assertIsNone(sampled)
def test_finish(self):
# ensure finish will record a span
ctx = Context()
s = Span(self.tracer, 'test.span', context=ctx)
ctx.add_span(s)
assert s.duration is None
sleep = 0.05
with s as s1:
assert s is s1
time.sleep(sleep)
assert s.duration >= sleep, '%s < %s' % (s.duration, sleep)
self.assert_span_count(1)
def test_sampling_rule_sample(sample_rate):
tracer = get_dummy_tracer()
rule = SamplingRule(sample_rate=sample_rate)
iterations = int(1e4 / sample_rate)
sampled = sum(
rule.sample(Span(tracer=tracer, name=i)) for i in range(iterations))
# Less than 5% deviation when 'enough' iterations (arbitrary, just check if it converges)
deviation = abs(sampled -
(iterations * sample_rate)) / (iterations * sample_rate)
assert deviation < 0.05, (
'Deviation {!r} too high with sample_rate {!r} for {} sampled'.format(
deviation, sample_rate, sampled))
def test_span_boolean_err(self):
s = Span(tracer=None, name='foo.bar', service='s', resource='r')
s.error = True
s.finish()
d = s.to_dict()
assert d
assert d['error'] == 1
assert type(d['error']) == int
def test_set_numpy_metric(self):
try:
import numpy as np
except ImportError:
raise SkipTest('numpy not installed')
s = Span(tracer=None, name='test.span')
s.set_metric('a', np.int64(1))
assert s.get_metric('a') == 1
assert type(s.get_metric('a')) == float
def test_log_unfinished_spans_when_ok(self, log):
# if the unfinished spans logging is enabled but the trace is finished, don't log anything
tracer = get_dummy_tracer()
ctx = Context()
# manually create a root-child trace
root = Span(tracer=tracer, name='root')
child = Span(tracer=tracer,
name='child_1',
trace_id=root.trace_id,
parent_id=root.span_id)
child._parent = root
ctx.add_span(root)
ctx.add_span(child)
# close the trace
child.finish()
root.finish()
# the logger has never been invoked to print unfinished spans
for call, _ in log.call_args_list:
msg = call[0]
assert 'the trace has %d unfinished spans' not in msg
