def test_v1_span(self, kind, annotations):
endpoint = create_endpoint(port=8080, service_name="foo", host="80")
span = Span(
trace_id=generate_random_64bit_string(),
name="test span",
parent_id=generate_random_64bit_string(),
span_id=generate_random_64bit_string(),
kind=kind,
timestamp=26.0,
duration=4.0,
local_endpoint=endpoint,
)
v1_span = span.build_v1_span()
assert v1_span.annotations == annotations
def _emit_spans_with_span_sender(self, span_sender):
with span_sender:
end_timestamp = time.time()
# Collect, annotate, and log client spans from the logging handler
for span in self._get_tracer()._span_storage:
span.local_endpoint = copy_endpoint_with_new_service_name(
self.endpoint,
span.local_endpoint.service_name,
)
span_sender.add_span(span)
annotations = {}
if self.add_logging_annotation:
annotations[LOGGING_END_KEY] = time.time()
span_sender.add_span(Span(
trace_id=self.zipkin_attrs.trace_id,
name=self.span_name,
parent_id=self.zipkin_attrs.parent_span_id,
span_id=self.zipkin_attrs.span_id,
kind=Kind.CLIENT if self.client_context else Kind.SERVER,
timestamp=self.start_timestamp,
duration=end_timestamp - self.start_timestamp,
local_endpoint=self.endpoint,
remote_endpoint=self.remote_endpoint,
shared=not self.report_root_timestamp,
annotations=annotations,
tags=self.tags,
))
def test_stop_non_root_ts_duration_overridden(self):
tracer = MockTracer()
tracer.set_transport_configured(configured=True)
tracer.get_context().push(zipkin.create_attrs_for_span())
ts = time.time()
context = tracer.zipkin_span(
service_name='test_service',
span_name='test_span',
timestamp=ts,
duration=25,
)
context.start()
context.stop()
assert len(tracer.get_spans()) == 1
endpoint = create_endpoint(service_name='test_service')
assert tracer.get_spans()[0] == Span(
trace_id=context.zipkin_attrs.trace_id,
name='test_span',
parent_id=context.zipkin_attrs.parent_span_id,
span_id=context.zipkin_attrs.span_id,
kind=Kind.LOCAL,
timestamp=ts,
duration=25,
annotations={},
local_endpoint=endpoint,
remote_endpoint=None,
tags={},
)
assert tracer.is_transport_configured() is True
def test_batch_sender_add_span_many_times(fake_endpoint):
# We create MAX_PORTION_SIZE * 2 + 1 spans, so we should trigger flush 3
# times, once every MAX_PORTION_SIZE spans.
encoder = MockEncoder()
sender = logging_helper.ZipkinBatchSender(
transport_handler=MockTransportHandler(),
max_portion_size=None,
encoder=encoder,
)
max_portion_size = logging_helper.ZipkinBatchSender.MAX_PORTION_SIZE
with sender:
for _ in range(max_portion_size * 2 + 1):
sender.add_span(
Span(
trace_id="000000000000000f",
name="span",
parent_id="0000000000000001",
span_id="0000000000000002",
kind=Kind.CLIENT,
timestamp=26.0,
duration=4.0,
local_endpoint=fake_endpoint,
annotations={},
tags={},
)
)
assert encoder.encode_queue.call_count == 3
assert len(encoder.encode_queue.call_args_list[0][0][0]) == max_portion_size
assert len(encoder.encode_queue.call_args_list[1][0][0]) == max_portion_size
assert len(encoder.encode_queue.call_args_list[2][0][0]) == 1
def test_batch_sender_defensive_about_transport_handler(fake_endpoint):
"""Make sure log_span doesn't try to call the transport handler if it's
None."""
encoder = MockEncoder()
sender = logging_helper.ZipkinBatchSender(
transport_handler=None,
max_portion_size=None,
encoder=encoder,
)
with sender:
sender.add_span(
Span(
trace_id='000000000000000f',
name='span',
parent_id='0000000000000001',
span_id='0000000000000002',
kind=Kind.CLIENT,
timestamp=26.0,
duration=4.0,
local_endpoint=fake_endpoint,
annotations={},
tags={},
))
assert encoder.encode_span.call_count == 1
assert encoder.encode_queue.call_count == 0
def test_create_protobuf_span():
span = Span(
trace_id="1",
name="name",
parent_id="2",
span_id="3",
kind=Kind.CLIENT,
timestamp=10,
duration=10,
local_endpoint=create_endpoint(service_name="service1", use_defaults=False),
remote_endpoint=create_endpoint(service_name="service2", use_defaults=False),
debug=True,
shared=True,
annotations={"foo": 1},
tags={"key": "value"},
)
pb_span = protobuf.create_protobuf_span(span)
assert pb_span == zipkin_pb2.Span(
trace_id=b"\000\000\000\000\000\000\000\001",
parent_id=b"\000\000\000\000\000\000\000\002",
id=b"\000\000\000\000\000\000\000\003",
kind=zipkin_pb2.Span.CLIENT,
name="name",
timestamp=10000000,
duration=10000000,
local_endpoint=zipkin_pb2.Endpoint(service_name="service1"),
remote_endpoint=zipkin_pb2.Endpoint(service_name="service2"),
debug=True,
shared=True,
annotations=[zipkin_pb2.Annotation(timestamp=1000000, value="foo")],
tags={"key": "value"},
)
def test_batch_sender_add_span_too_big(fake_endpoint):
# This time we set max_payload_bytes to 1000, so we have to send more batches.
# Each encoded span is 175 bytes, so we can fit 5 of those in 1000 bytes.
mock_transport_handler = mock.Mock(spec=MockTransportHandler)
mock_transport_handler.get_max_payload_bytes = lambda: 1000
sender = logging_helper.ZipkinBatchSender(
mock_transport_handler, 100, get_encoder(Encoding.V1_THRIFT),
)
with sender:
for _ in range(201):
sender.add_span(
Span(
trace_id="000000000000000f",
name="span",
parent_id="0000000000000001",
span_id="0000000000000002",
kind=Kind.CLIENT,
timestamp=26.0,
duration=4.0,
local_endpoint=fake_endpoint,
annotations={},
tags={},
)
)
# 5 spans per batch, means we need 201 / 4 = 41 batches to send them all.
assert mock_transport_handler.call_count == 41
for i in range(40):
# The first 40 batches have 5 spans of 197 bytes + 5 bytes of
# list headers = 990 bytes
assert len(mock_transport_handler.call_args_list[i][0][0]) == 990
# The last batch has a single remaining span of 197 bytes + 5 bytes of
# list headers = 202 bytes
assert len(mock_transport_handler.call_args_list[40][0][0]) == 202
def test_batch_sender_flush_calls_transport_handler_with_correct_params(fake_endpoint):
# Tests that the transport handler is called with the value returned
# by encoder.encode_queue.
transport_handler = mock.Mock()
transport_handler.get_max_payload_bytes = lambda: None
encoder = MockEncoder(encoded_queue="foobar")
sender = logging_helper.ZipkinBatchSender(
transport_handler=transport_handler, max_portion_size=None, encoder=encoder,
)
with sender:
sender.add_span(
Span(
trace_id="000000000000000f",
name="span",
parent_id="0000000000000001",
span_id="0000000000000002",
kind=Kind.CLIENT,
timestamp=26.0,
duration=4.0,
local_endpoint=fake_endpoint,
annotations={},
tags={},
)
)
transport_handler.assert_called_once_with("foobar")
def test_stop_non_root(self, mock_time):
tracer = MockTracer()
tracer.set_transport_configured(configured=True)
tracer.get_context().push(zipkin.create_attrs_for_span())
context = tracer.zipkin_span(
service_name="test_service", span_name="test_span",
)
context.start()
context.stop()
assert len(tracer.get_spans()) == 1
endpoint = create_endpoint(service_name="test_service")
assert tracer.get_spans()[0] == Span(
trace_id=context.zipkin_attrs.trace_id,
name="test_span",
parent_id=context.zipkin_attrs.parent_span_id,
span_id=context.zipkin_attrs.span_id,
kind=Kind.LOCAL,
timestamp=123,
duration=0,
annotations={},
local_endpoint=endpoint,
remote_endpoint=None,
tags={},
)
assert tracer.is_transport_configured() is True
def test_batch_sender_add_span(fake_endpoint):
# This test verifies it's possible to add 1 span without throwing errors.
# It also checks that exiting the ZipkinBatchSender context manager
# triggers a flush of all the already added spans.
encoder = MockEncoder(encoded_queue="foobar")
sender = logging_helper.ZipkinBatchSender(
transport_handler=MockTransportHandler(),
max_portion_size=None,
encoder=encoder,
)
with sender:
sender.add_span(
Span(
trace_id="000000000000000f",
name="span",
parent_id="0000000000000001",
span_id="0000000000000002",
kind=Kind.CLIENT,
timestamp=26.0,
duration=4.0,
local_endpoint=fake_endpoint,
annotations={},
tags={},
)
)
assert encoder.encode_queue.call_count == 1
def test_fits(self, encoder):
span = Span("1", "name", "2", "3", Kind.CLIENT, 10, 10)
pb_span = encoder.encode_span(span)
span_len = len(pb_span)
assert encoder.fits(None, 0, span_len * 2, pb_span) is True
assert encoder.fits(None, span_len, span_len * 2, pb_span) is True
assert encoder.fits(None, span_len + 1, span_len * 2, pb_span) is False
def test_fits(self, encoder):
span = Span('1', 'name', '2', '3', Kind.CLIENT, 10, 10)
pb_span = encoder.encode_span(span)
span_len = len(pb_span)
assert encoder.fits(None, 0, span_len * 2, pb_span) is True
assert encoder.fits(None, span_len, span_len * 2, pb_span) is True
assert encoder.fits(None, span_len + 1, span_len * 2, pb_span) is False
def stop(self, _exc_type=None, _exc_value=None, _exc_traceback=None):
"""Exit the span context. Zipkin attrs are pushed onto the
threadlocal stack regardless of sampling, so they always need to be
popped off. The actual logging of spans depends on sampling and that
the logging was correctly set up.
"""
if self.do_pop_attrs:
self.get_tracer().pop_zipkin_attrs()
# If no transport is configured, there's no reason to create a new Span.
# This also helps avoiding memory leaks since without a transport nothing
# would pull spans out of get_tracer().
if not self.get_tracer().is_transport_configured():
return
# Add the error annotation if an exception occurred
if any((_exc_type, _exc_value, _exc_traceback)):
error_msg = u'{0}: {1}'.format(_exc_type.__name__, _exc_value)
self.update_binary_annotations({
ERROR_KEY: error_msg,
})
# Logging context is only initialized for "root" spans of the local
# process (i.e. this zipkin_span not inside of any other local
# zipkin_spans)
if self.logging_context:
self.logging_context.stop()
self.logging_context = None
self.get_tracer().set_transport_configured(configured=False)
return
# If we've gotten here, that means that this span is a child span of
# this context's root span (i.e. it's a zipkin_span inside another
# zipkin_span).
end_timestamp = time.time()
# If self.duration is set, it means the user wants to override it
if self.duration:
duration = self.duration
else:
duration = end_timestamp - self.start_timestamp
endpoint = create_endpoint(self.port, self.service_name, self.host)
self.get_tracer().add_span(
Span(
trace_id=self.zipkin_attrs.trace_id,
name=self.span_name,
parent_id=self.zipkin_attrs.parent_span_id,
span_id=self.zipkin_attrs.span_id,
kind=self.kind,
timestamp=self.timestamp
if self.timestamp else self.start_timestamp,
duration=duration,
annotations=self.annotations,
local_endpoint=endpoint,
remote_endpoint=self.remote_endpoint,
tags=self.binary_annotations,
))
def _decode_thrift_span(self, thrift_span):
"""Decodes a thrift span.
:param thrift_span: thrift span
:type thrift_span: thrift Span object
:returns: span builder representing this span
:rtype: Span
"""
parent_id = None
local_endpoint = None
annotations = {}
tags = {}
kind = Kind.LOCAL
remote_endpoint = None
timestamp = None
duration = None
if thrift_span.parent_id:
parent_id = self._convert_unsigned_long_to_lower_hex(thrift_span.parent_id)
if thrift_span.annotations:
(
annotations,
local_endpoint,
kind,
timestamp,
duration,
) = self._decode_thrift_annotations(thrift_span.annotations)
if thrift_span.binary_annotations:
(
tags,
local_endpoint,
remote_endpoint,
) = self._convert_from_thrift_binary_annotations(
thrift_span.binary_annotations,
)
trace_id = self._convert_trace_id_to_string(
thrift_span.trace_id, thrift_span.trace_id_high,
)
return Span(
trace_id=trace_id,
name=thrift_span.name,
parent_id=parent_id,
span_id=self._convert_unsigned_long_to_lower_hex(thrift_span.id),
kind=kind,
timestamp=self.seconds(timestamp or thrift_span.timestamp),
duration=self.seconds(duration or thrift_span.duration),
local_endpoint=local_endpoint,
remote_endpoint=remote_endpoint,
shared=(kind == Kind.SERVER and thrift_span.timestamp is None),
annotations=annotations,
tags=tags,
)
def test_encode_span(self, mock_installed, encoder):
span = Span('1', 'name', '2', '3', Kind.CLIENT, 10, 10)
mock_installed.return_value = False
with pytest.raises(ZipkinError):
encoder.encode_span(span)
mock_installed.return_value = True
pb_span = encoder.encode_span(span)
assert isinstance(pb_span, bytes)
def test_zipkin_logging_client_context_emit_spans(add_span_mock, flush_mock,
time_mock, fake_endpoint):
# This lengthy function tests that the logging context properly
# logs root client span
trace_id = '000000000000000f'
client_span_id = '0000000000000003'
attr = ZipkinAttrs(
trace_id=trace_id,
span_id=client_span_id,
parent_span_id=None,
flags=None,
is_sampled=True,
)
tracer = MockTracer()
transport_handler = mock.Mock()
context = logging_helper.ZipkinLoggingContext(
zipkin_attrs=attr,
endpoint=fake_endpoint,
span_name='GET /foo',
transport_handler=transport_handler,
report_root_timestamp=True,
get_tracer=lambda: tracer,
client_context=True,
service_name='test_server',
encoding=Encoding.V1_JSON,
)
context.start_timestamp = 24
context.response_status_code = 200
context.tags = {'k': 'v'}
time_mock.return_value = 42
context.emit_spans()
log_call = add_span_mock.call_args_list[0]
assert log_call[0][1].build_v1_span() == Span(
trace_id=trace_id,
name='GET /foo',
parent_id=None,
span_id=client_span_id,
kind=Kind.CLIENT,
timestamp=24.0,
duration=18.0,
local_endpoint=fake_endpoint,
annotations={
'cs': 24,
'cr': 42
},
tags={
'k': 'v'
},
).build_v1_span()
assert flush_mock.call_count == 1
def test_create_span_with_bad_kind():
with pytest.raises(ZipkinError) as e:
Span(
trace_id=generate_random_64bit_string(),
name="test span",
parent_id=generate_random_64bit_string(),
span_id=generate_random_64bit_string(),
kind="client",
timestamp=26.0,
duration=4.0,
)
assert "Invalid kind value client. Must be of type Kind." in str(e.value)
def test_create_span_with_bad_remote_endpoint():
with pytest.raises(ZipkinError) as e:
Span(
trace_id=generate_random_64bit_string(),
name='test span',
parent_id=generate_random_64bit_string(),
span_id=generate_random_64bit_string(),
kind=Kind.CLIENT,
timestamp=26.0,
duration=4.0,
remote_endpoint='my_service',
)
assert 'Invalid remote_endpoint value. Must be of type Endpoint.' in str(e)
def test_create_span_with_bad_local_endpoint():
with pytest.raises(ZipkinError) as e:
Span(
trace_id=generate_random_64bit_string(),
name="test span",
parent_id=generate_random_64bit_string(),
span_id=generate_random_64bit_string(),
kind=Kind.CLIENT,
timestamp=26.0,
duration=4.0,
local_endpoint="my_service",
)
assert "Invalid local_endpoint value. Must be of type Endpoint." in str(
e.value)
def test_encode_queue(self, encoder):
span = Span('1', 'name', '2', '3', Kind.CLIENT, 10, 10)
pb_span = encoder.encode_span(span)
pb_list = encoder.encode_queue([pb_span])
assert isinstance(pb_list, bytes)
def test_zipkin_logging_server_context_emit_spans(
add_span_mock, flush_mock, time_mock, fake_endpoint
):
# This lengthy function tests that the logging context properly
# logs both client and server spans.
trace_id = "000000000000000f"
parent_span_id = "0000000000000001"
server_span_id = "0000000000000002"
client_span_id = "0000000000000003"
client_span_name = "breadcrumbs"
attr = ZipkinAttrs(
trace_id=trace_id,
span_id=server_span_id,
parent_span_id=parent_span_id,
flags=None,
is_sampled=True,
)
tracer = MockTracer()
client_span = Span(
trace_id=trace_id,
name=client_span_name,
parent_id=server_span_id,
span_id=client_span_id,
kind=Kind.CLIENT,
timestamp=26.0,
duration=4.0,
local_endpoint=create_endpoint(service_name="test_server"),
annotations={"ann2": 2, "cs": 26, "cr": 30},
tags={"bann2": "yiss"},
)
tracer.get_spans().append(client_span)
transport_handler = mock.Mock()
context = logging_helper.ZipkinLoggingContext(
zipkin_attrs=attr,
endpoint=fake_endpoint,
span_name="GET /foo",
transport_handler=transport_handler,
report_root_timestamp=True,
get_tracer=lambda: tracer,
service_name="test_server",
encoding=Encoding.V1_JSON,
)
context.start_timestamp = 24
context.response_status_code = 200
context.tags = {"k": "v"}
time_mock.return_value = 42
context.emit_spans()
client_log_call, server_log_call = add_span_mock.call_args_list
assert (
server_log_call[0][1].build_v1_span()
== Span(
trace_id=trace_id,
name="GET /foo",
parent_id=parent_span_id,
span_id=server_span_id,
kind=Kind.SERVER,
timestamp=24.0,
duration=18.0,
local_endpoint=fake_endpoint,
annotations={"sr": 24, "ss": 42},
tags={"k": "v"},
).build_v1_span()
)
assert client_log_call[0][1] == client_span
assert flush_mock.call_count == 1
def test_zipkin_logging_server_context_emit_spans_with_firehose(
add_span_mock, flush_mock, time_mock, fake_endpoint):
# This lengthy function tests that the logging context properly
# logs both client and server spans.
trace_id = '000000000000000f'
parent_span_id = '0000000000000001'
server_span_id = '0000000000000002'
client_span_id = '0000000000000003'
client_span_name = 'breadcrumbs'
client_svc_name = 'svc'
attr = ZipkinAttrs(
trace_id=trace_id,
span_id=server_span_id,
parent_span_id=parent_span_id,
flags=None,
is_sampled=True,
)
tracer = MockTracer()
client_span = Span(
trace_id=trace_id,
name=client_span_name,
parent_id=server_span_id,
span_id=client_span_id,
kind=Kind.CLIENT,
timestamp=26.0,
duration=4.0,
local_endpoint=create_endpoint(service_name=client_svc_name),
annotations={
'ann2': 2,
'cs': 26,
'cr': 30
},
tags={'bann2': 'yiss'},
)
tracer.get_spans().append(client_span)
transport_handler = mock.Mock()
firehose_handler = mock.Mock()
context = logging_helper.ZipkinLoggingContext(
zipkin_attrs=attr,
endpoint=fake_endpoint,
span_name='GET /foo',
transport_handler=transport_handler,
report_root_timestamp=True,
get_tracer=lambda: tracer,
firehose_handler=firehose_handler,
service_name='test_server',
encoding=Encoding.V1_JSON,
)
context.start_timestamp = 24
context.response_status_code = 200
context.tags = {'k': 'v'}
time_mock.return_value = 42
context.emit_spans()
call_args = add_span_mock.call_args_list
firehose_client_log_call, client_log_call = call_args[0], call_args[2]
firehose_server_log_call, server_log_call = call_args[1], call_args[3]
assert server_log_call[0][1].build_v1_span() == \
firehose_server_log_call[0][1].build_v1_span()
assert server_log_call[0][1].build_v1_span() == Span(
trace_id=trace_id,
name='GET /foo',
parent_id=parent_span_id,
span_id=server_span_id,
kind=Kind.SERVER,
timestamp=24.0,
duration=18.0,
local_endpoint=fake_endpoint,
annotations={
'sr': 24,
'ss': 42
},
tags={
'k': 'v'
},
).build_v1_span()
assert client_log_call[0][1] == firehose_client_log_call[0][
1] == client_span
assert flush_mock.call_count == 2
def test_encode_queue(self, encoder):
span = Span("1", "name", "2", "3", Kind.CLIENT, 10, 10)
pb_span = encoder.encode_span(span)
pb_list = encoder.encode_queue([pb_span])
assert isinstance(pb_list, bytes)
