1# -*- coding: utf-8 -*-
2import re
3import sys
4import time
5from unittest.case import SkipTest
6
7import mock
8import pytest
9import six
10
11from ddtrace.constants import ANALYTICS_SAMPLE_RATE_KEY
12from ddtrace.constants import ENV_KEY
13from ddtrace.constants import ERROR_MSG
14from ddtrace.constants import ERROR_STACK
15from ddtrace.constants import ERROR_TYPE
16from ddtrace.constants import SERVICE_VERSION_KEY
17from ddtrace.constants import SPAN_MEASURED_KEY
18from ddtrace.constants import VERSION_KEY
19from ddtrace.ext import SpanTypes
20from ddtrace.span import Span
21from tests.utils import TracerTestCase
22from tests.utils import assert_is_measured
23from tests.utils import assert_is_not_measured
24from tests.utils import override_global_config
25
26
27class SpanTestCase(TracerTestCase):
28    def test_ids(self):
29        s = Span(tracer=None, name="span.test")
30        assert s.trace_id
31        assert s.span_id
32        assert not s.parent_id
33
34        s2 = Span(tracer=None, name="t", trace_id=1, span_id=2, parent_id=1)
35        assert s2.trace_id == 1
36        assert s2.span_id == 2
37        assert s2.parent_id == 1
38
39    def test_tags(self):
40        s = Span(tracer=None, name="test.span")
41        s.set_tag("a", "a")
42        s.set_tag("b", 1)
43        s.set_tag("c", "1")
44        d = s.to_dict()
45        assert d["meta"] == dict(a="a", c="1")
46        assert d["metrics"] == dict(b=1)
47
48    def test_numeric_tags(self):
49        s = Span(tracer=None, name="test.span")
50        s.set_tag("negative", -1)
51        s.set_tag("zero", 0)
52        s.set_tag("positive", 1)
53        s.set_tag("large_int", 2 ** 53)
54        s.set_tag("really_large_int", (2 ** 53) + 1)
55        s.set_tag("large_negative_int", -(2 ** 53))
56        s.set_tag("really_large_negative_int", -((2 ** 53) + 1))
57        s.set_tag("float", 12.3456789)
58        s.set_tag("negative_float", -12.3456789)
59        s.set_tag("large_float", 2.0 ** 53)
60        s.set_tag("really_large_float", (2.0 ** 53) + 1)
61
62        d = s.to_dict()
63        assert d["meta"] == dict(
64            really_large_int=str(((2 ** 53) + 1)),
65            really_large_negative_int=str(-((2 ** 53) + 1)),
66        )
67        assert d["metrics"] == {
68            "negative": -1,
69            "zero": 0,
70            "positive": 1,
71            "large_int": 2 ** 53,
72            "large_negative_int": -(2 ** 53),
73            "float": 12.3456789,
74            "negative_float": -12.3456789,
75            "large_float": 2.0 ** 53,
76            "really_large_float": (2.0 ** 53) + 1,
77        }
78
79    def test_set_tag_bool(self):
80        s = Span(tracer=None, name="test.span")
81        s.set_tag("true", True)
82        s.set_tag("false", False)
83
84        d = s.to_dict()
85        assert d["meta"] == dict(true="True", false="False")
86        assert "metrics" not in d
87
88    def test_set_tag_metric(self):
89        s = Span(tracer=None, name="test.span")
90
91        s.set_tag("test", "value")
92        assert s.meta == dict(test="value")
93        assert s.metrics == dict()
94
95        s.set_tag("test", 1)
96        assert s.meta == dict()
97        assert s.metrics == dict(test=1)
98
99    def test_set_valid_metrics(self):
100        s = Span(tracer=None, name="test.span")
101        s.set_metric("a", 0)
102        s.set_metric("b", -12)
103        s.set_metric("c", 12.134)
104        s.set_metric("d", 1231543543265475686787869123)
105        s.set_metric("e", "12.34")
106        d = s.to_dict()
107        expected = {
108            "a": 0,
109            "b": -12,
110            "c": 12.134,
111            "d": 1231543543265475686787869123,
112            "e": 12.34,
113        }
114        assert d["metrics"] == expected
115
116    def test_set_invalid_metric(self):
117        s = Span(tracer=None, name="test.span")
118
119        invalid_metrics = [None, {}, [], s, "quarante-douze", float("nan"), float("inf"), 1j]
120
121        for i, m in enumerate(invalid_metrics):
122            k = str(i)
123            s.set_metric(k, m)
124            assert s.get_metric(k) is None
125
126    def test_set_numpy_metric(self):
127        try:
128            import numpy as np
129        except ImportError:
130            raise SkipTest("numpy not installed")
131        s = Span(tracer=None, name="test.span")
132        s.set_metric("a", np.int64(1))
133        assert s.get_metric("a") == 1
134        assert type(s.get_metric("a")) == float
135
136    def test_tags_not_string(self):
137        # ensure we can cast as strings
138        class Foo(object):
139            def __repr__(self):
140                1 / 0
141
142        s = Span(tracer=None, name="test.span")
143        s.set_tag("a", Foo())
144
145    def test_finish(self):
146        # ensure span.finish() marks the end time of the span
147        s = Span(None, "test.span")
148        sleep = 0.05
149        time.sleep(sleep)
150        s.finish()
151        assert s.duration >= sleep, "%s < %s" % (s.duration, sleep)
152
153    def test_finish_no_tracer(self):
154        # ensure finish works with no tracer without raising exceptions
155        s = Span(tracer=None, name="test.span")
156        s.finish()
157
158    def test_finish_called_multiple_times(self):
159        # we should only record a span the first time finish is called on it
160        s = Span(self.tracer, "bar")
161        s.finish()
162        s.finish()
163
164    def test_finish_set_span_duration(self):
165        # If set the duration on a span, the span should be recorded with this
166        # duration
167        s = Span(tracer=None, name="test.span")
168        s.duration = 1337.0
169        s.finish()
170        assert s.duration == 1337.0
171
172    def test_setter_casts_duration_ns_as_int(self):
173        s = Span(tracer=None, name="test.span")
174        s.duration = 3.2
175        s.finish()
176        assert s.duration == 3.2
177        assert s.duration_ns == 3200000000
178        assert isinstance(s.duration_ns, int)
179
180    def test_get_span_returns_none_by_default(self):
181        s = Span(tracer=None, name="test.span")
182        assert s.duration is None
183
184    def test_traceback_with_error(self):
185        s = Span(None, "test.span")
186        try:
187            1 / 0
188        except ZeroDivisionError:
189            s.set_traceback()
190        else:
191            assert 0, "should have failed"
192
193        assert s.error
194        assert "by zero" in s.get_tag(ERROR_MSG)
195        assert "ZeroDivisionError" in s.get_tag(ERROR_TYPE)
196
197    def test_traceback_without_error(self):
198        s = Span(None, "test.span")
199        s.set_traceback()
200        assert not s.error
201        assert not s.get_tag(ERROR_MSG)
202        assert not s.get_tag(ERROR_TYPE)
203        assert "in test_traceback_without_error" in s.get_tag(ERROR_STACK)
204
205    def test_ctx_mgr(self):
206        s = Span(self.tracer, "bar")
207        assert not s.duration
208        assert not s.error
209
210        e = Exception("boo")
211        try:
212            with s:
213                time.sleep(0.01)
214                raise e
215        except Exception as out:
216            assert out == e
217            assert s.duration > 0, s.duration
218            assert s.error
219            assert s.get_tag(ERROR_MSG) == "boo"
220            assert "Exception" in s.get_tag(ERROR_TYPE)
221            assert s.get_tag(ERROR_STACK)
222
223        else:
224            assert 0, "should have failed"
225
226    def test_span_type(self):
227        s = Span(tracer=None, name="test.span", service="s", resource="r", span_type=SpanTypes.WEB)
228        s.set_tag("a", "1")
229        s.set_meta("b", "2")
230        s.finish()
231
232        d = s.to_dict()
233        assert d
234        assert d["span_id"] == s.span_id
235        assert d["trace_id"] == s.trace_id
236        assert d["parent_id"] == s.parent_id
237        assert d["meta"] == {"a": "1", "b": "2"}
238        assert d["type"] == "web"
239        assert d["error"] == 0
240        assert type(d["error"]) == int
241
242    def test_span_to_dict(self):
243        s = Span(tracer=None, name="test.span", service="s", resource="r")
244        s.span_type = "foo"
245        s.set_tag("a", "1")
246        s.set_meta("b", "2")
247        s.finish()
248
249        d = s.to_dict()
250        assert d
251        assert d["span_id"] == s.span_id
252        assert d["trace_id"] == s.trace_id
253        assert d["parent_id"] == s.parent_id
254        assert d["meta"] == {"a": "1", "b": "2"}
255        assert d["type"] == "foo"
256        assert d["error"] == 0
257        assert type(d["error"]) == int
258
259    def test_span_to_dict_sub(self):
260        parent = Span(tracer=None, name="test.span", service="s", resource="r")
261        s = Span(tracer=None, name="test.span", service="s", resource="r")
262        s._parent = parent
263        s.span_type = "foo"
264        s.set_tag("a", "1")
265        s.set_meta("b", "2")
266        s.finish()
267
268        d = s.to_dict()
269        assert d
270        assert d["span_id"] == s.span_id
271        assert d["trace_id"] == s.trace_id
272        assert d["parent_id"] == s.parent_id
273        assert d["meta"] == {"a": "1", "b": "2"}
274        assert d["type"] == "foo"
275        assert d["error"] == 0
276        assert type(d["error"]) == int
277
278    def test_span_boolean_err(self):
279        s = Span(tracer=None, name="foo.bar", service="s", resource="r")
280        s.error = True
281        s.finish()
282
283        d = s.to_dict()
284        assert d
285        assert d["error"] == 1
286        assert type(d["error"]) == int
287
288    @mock.patch("ddtrace.span.log")
289    def test_numeric_tags_none(self, span_log):
290        s = Span(tracer=None, name="test.span")
291        s.set_tag(ANALYTICS_SAMPLE_RATE_KEY, None)
292        d = s.to_dict()
293        assert d
294        assert "metrics" not in d
295
296        # Ensure we log a debug message
297        span_log.debug.assert_called_once_with(
298            "ignoring not number metric %s:%s",
299            ANALYTICS_SAMPLE_RATE_KEY,
300            None,
301        )
302
303    def test_numeric_tags_true(self):
304        s = Span(tracer=None, name="test.span")
305        s.set_tag(ANALYTICS_SAMPLE_RATE_KEY, True)
306        d = s.to_dict()
307        assert d
308        expected = {ANALYTICS_SAMPLE_RATE_KEY: 1.0}
309        assert d["metrics"] == expected
310
311    def test_numeric_tags_value(self):
312        s = Span(tracer=None, name="test.span")
313        s.set_tag(ANALYTICS_SAMPLE_RATE_KEY, 0.5)
314        d = s.to_dict()
315        assert d
316        expected = {ANALYTICS_SAMPLE_RATE_KEY: 0.5}
317        assert d["metrics"] == expected
318
319    def test_numeric_tags_bad_value(self):
320        s = Span(tracer=None, name="test.span")
321        s.set_tag(ANALYTICS_SAMPLE_RATE_KEY, "Hello")
322        d = s.to_dict()
323        assert d
324        assert "metrics" not in d
325
326    def test_set_tag_none(self):
327        s = Span(tracer=None, name="root.span", service="s", resource="r")
328        assert s.meta == dict()
329
330        s.set_tag("custom.key", "100")
331
332        assert s.meta == {"custom.key": "100"}
333
334        s.set_tag("custom.key", None)
335
336        assert s.meta == {"custom.key": "None"}
337
338    def test_duration_zero(self):
339        s = Span(tracer=None, name="foo.bar", service="s", resource="r", start=123)
340        s.finish(finish_time=123)
341        assert s.duration_ns == 0
342        assert s.duration == 0
343
344    def test_start_int(self):
345        s = Span(tracer=None, name="foo.bar", service="s", resource="r", start=123)
346        assert s.start == 123
347        assert s.start_ns == 123000000000
348
349        s = Span(tracer=None, name="foo.bar", service="s", resource="r", start=123.123)
350        assert s.start == 123.123
351        assert s.start_ns == 123123000000
352
353        s = Span(tracer=None, name="foo.bar", service="s", resource="r", start=123.123)
354        s.start = 234567890.0
355        assert s.start == 234567890
356        assert s.start_ns == 234567890000000000
357
358    def test_duration_int(self):
359        s = Span(tracer=None, name="foo.bar", service="s", resource="r")
360        s.finish()
361        assert isinstance(s.duration_ns, int)
362        assert isinstance(s.duration, float)
363
364        s = Span(tracer=None, name="foo.bar", service="s", resource="r", start=123)
365        s.finish(finish_time=123.2)
366        assert s.duration_ns == 200000000
367        assert s.duration == 0.2
368
369        s = Span(tracer=None, name="foo.bar", service="s", resource="r", start=123.1)
370        s.finish(finish_time=123.2)
371        assert s.duration_ns == 100000000
372        assert s.duration == 0.1
373
374        s = Span(tracer=None, name="foo.bar", service="s", resource="r", start=122)
375        s.finish(finish_time=123)
376        assert s.duration_ns == 1000000000
377        assert s.duration == 1
378
379    def test_set_tag_version(self):
380        s = Span(tracer=None, name="test.span")
381        s.set_tag(VERSION_KEY, "1.2.3")
382        assert s.get_tag(VERSION_KEY) == "1.2.3"
383        assert s.get_tag(SERVICE_VERSION_KEY) is None
384
385        s.set_tag(SERVICE_VERSION_KEY, "service.version")
386        assert s.get_tag(VERSION_KEY) == "service.version"
387        assert s.get_tag(SERVICE_VERSION_KEY) == "service.version"
388
389    def test_set_tag_env(self):
390        s = Span(tracer=None, name="test.span")
391        s.set_tag(ENV_KEY, "prod")
392        assert s.get_tag(ENV_KEY) == "prod"
393
394
395@pytest.mark.parametrize(
396    "value,assertion",
397    [
398        (None, assert_is_measured),
399        (1, assert_is_measured),
400        (1.0, assert_is_measured),
401        (-1, assert_is_measured),
402        (True, assert_is_measured),
403        ("true", assert_is_measured),
404        # DEV: Ends up being measured because we do `bool("false")` which is `True`
405        ("false", assert_is_measured),
406        (0, assert_is_not_measured),
407        (0.0, assert_is_not_measured),
408        (False, assert_is_not_measured),
409    ],
410)
411def test_set_tag_measured(value, assertion):
412    s = Span(tracer=None, name="test.span")
413    s.set_tag(SPAN_MEASURED_KEY, value)
414    assertion(s)
415
416
417def test_set_tag_measured_not_set():
418    # Span is not measured by default
419    s = Span(tracer=None, name="test.span")
420    assert_is_not_measured(s)
421
422
423def test_set_tag_measured_no_value():
424    s = Span(tracer=None, name="test.span")
425    s.set_tag(SPAN_MEASURED_KEY)
426    assert_is_measured(s)
427
428
429def test_set_tag_measured_change_value():
430    s = Span(tracer=None, name="test.span")
431    s.set_tag(SPAN_MEASURED_KEY, True)
432    assert_is_measured(s)
433
434    s.set_tag(SPAN_MEASURED_KEY, False)
435    assert_is_not_measured(s)
436
437    s.set_tag(SPAN_MEASURED_KEY)
438    assert_is_measured(s)
439
440
441@mock.patch("ddtrace.span.log")
442def test_span_key(span_log):
443    # Span tag keys must be strings
444    s = Span(tracer=None, name="test.span")
445
446    s.set_tag(123, True)
447    span_log.warning.assert_called_once_with("Ignoring tag pair %s:%s. Key must be a string.", 123, True)
448    assert s.get_tag(123) is None
449    assert s.get_tag("123") is None
450
451    span_log.reset_mock()
452
453    s.set_tag(None, "val")
454    span_log.warning.assert_called_once_with("Ignoring tag pair %s:%s. Key must be a string.", None, "val")
455    assert s.get_tag(123.32) is None
456
457
458def test_span_finished():
459    span = Span(None, None)
460    assert span.finished is False
461    assert span.duration_ns is None
462
463    span.finished = True
464    assert span.finished is True
465    assert span.duration_ns is not None
466    duration = span.duration_ns
467
468    span.finished = True
469    assert span.finished is True
470    assert span.duration_ns == duration
471
472    span.finished = False
473    assert span.finished is False
474
475    span.finished = True
476    assert span.finished is True
477    assert span.duration_ns != duration
478
479
480def test_span_unicode_set_tag():
481    span = Span(None, None)
482    span.set_tag("key", u"��")
483    span.set_tag("��", u"��")
484    span._set_str_tag("key", u"��")
485    span._set_str_tag(u"��", u"��")
486
487
488@pytest.mark.skipif(sys.version_info.major != 2, reason="This test only applies Python 2")
489@mock.patch("ddtrace.span.log")
490def test_span_binary_unicode_set_tag(span_log):
491    span = Span(None, None)
492    span.set_tag("key", "��")
493    span._set_str_tag("key_str", "��")
494    # only span.set_tag() will fail
495    span_log.warning.assert_called_once_with("error setting tag %s, ignoring it", "key", exc_info=True)
496    assert "key" not in span.meta
497    assert span.meta["key_str"] == u"��"
498
499
500@pytest.mark.skipif(sys.version_info.major == 2, reason="This test does not apply to Python 2")
501@mock.patch("ddtrace.span.log")
502def test_span_bytes_string_set_tag(span_log):
503    span = Span(None, None)
504    span.set_tag("key", b"\xf0\x9f\xa4\x94")
505    span._set_str_tag("key_str", b"\xf0\x9f\xa4\x94")
506    assert span.meta["key"] == "b'\\xf0\\x9f\\xa4\\x94'"
507    assert span.meta["key_str"] == "��"
508    span_log.warning.assert_not_called()
509
510
511@mock.patch("ddtrace.span.log")
512def test_span_encoding_set_str_tag(span_log):
513    span = Span(None, None)
514    span._set_str_tag("foo", u"/?foo=bar&baz=정상처리".encode("euc-kr"))
515    span_log.warning.assert_not_called()
516    assert span.meta["foo"] == u"/?foo=bar&baz=����ó��"
517
518
519def test_span_nonstring_set_str_tag_exc():
520    span = Span(None, None)
521    with pytest.raises(TypeError):
522        span._set_str_tag("foo", dict(a=1))
523    assert "foo" not in span.meta
524
525
526@mock.patch("ddtrace.span.log")
527def test_span_nonstring_set_str_tag_warning(span_log):
528    with override_global_config(dict(_raise=False)):
529        span = Span(None, None)
530        span._set_str_tag("foo", dict(a=1))
531        span_log.warning.assert_called_once_with(
532            "Failed to set text tag '%s'",
533            "foo",
534            exc_info=True,
535        )
536
537
538def test_span_ignored_exceptions():
539    s = Span(None, None)
540    s._ignore_exception(ValueError)
541
542    with pytest.raises(ValueError):
543        with s:
544            raise ValueError()
545
546    assert s.error == 0
547    assert s.get_tag(ERROR_MSG) is None
548    assert s.get_tag(ERROR_TYPE) is None
549    assert s.get_tag(ERROR_STACK) is None
550
551    s = Span(None, None)
552    s._ignore_exception(ValueError)
553
554    with pytest.raises(ValueError):
555        with s:
556            raise ValueError()
557
558    with pytest.raises(RuntimeError):
559        with s:
560            raise RuntimeError()
561
562    assert s.error == 1
563    assert s.get_tag(ERROR_MSG) is not None
564    assert "RuntimeError" in s.get_tag(ERROR_TYPE)
565    assert s.get_tag(ERROR_STACK) is not None
566
567
568def test_span_ignored_exception_multi():
569    s = Span(None, None)
570    s._ignore_exception(ValueError)
571    s._ignore_exception(RuntimeError)
572
573    with pytest.raises(ValueError):
574        with s:
575            raise ValueError()
576
577    with pytest.raises(RuntimeError):
578        with s:
579            raise RuntimeError()
580
581    assert s.error == 0
582    assert s.get_tag(ERROR_MSG) is None
583    assert s.get_tag(ERROR_TYPE) is None
584    assert s.get_tag(ERROR_STACK) is None
585
586
587def test_span_ignored_exception_subclass():
588    s = Span(None, None)
589    s._ignore_exception(Exception)
590
591    with pytest.raises(ValueError):
592        with s:
593            raise ValueError()
594
595    with pytest.raises(RuntimeError):
596        with s:
597            raise RuntimeError()
598
599    assert s.error == 0
600    assert s.get_tag(ERROR_MSG) is None
601    assert s.get_tag(ERROR_TYPE) is None
602    assert s.get_tag(ERROR_STACK) is None
603
604
605def test_on_finish_single_callback():
606    m = mock.Mock()
607    s = Span(None, "test", on_finish=[m])
608    m.assert_not_called()
609    s.finish()
610    m.assert_called_once_with(s)
611
612
613def test_on_finish_multi_callback():
614    m1 = mock.Mock()
615    m2 = mock.Mock()
616    s = Span(None, "test", on_finish=[m1, m2])
617    s.finish()
618    m1.assert_called_once_with(s)
619    m2.assert_called_once_with(s)
620
621
622@pytest.mark.parametrize("arg", ["span_id", "trace_id", "parent_id"])
623def test_span_preconditions(arg):
624    Span(None, "test", **{arg: None})
625    with pytest.raises(TypeError):
626        Span(None, "test", **{arg: "foo"})
627
628
629def test_span_pprint():
630    root = Span(None, "test.span", service="s", resource="r", span_type=SpanTypes.WEB)
631    root.set_tag("t", "v")
632    root.set_metric("m", 1.0)
633    root.finish()
634    actual = root.pprint()
635    assert "name='test.span'" in actual
636    assert "service='s'" in actual
637    assert "resource='r'" in actual
638    assert "type='web'" in actual
639    assert "error=0" in actual
640    assert ("tags={'t': 'v'}" if six.PY3 else "tags={'t': u'v'}") in actual
641    assert "metrics={'m': 1.0}" in actual
642    assert re.search("id=[0-9]+", actual) is not None
643    assert re.search("trace_id=[0-9]+", actual) is not None
644    assert "parent_id=None" in actual
645    assert re.search("duration=[0-9.]+", actual) is not None
646    assert re.search("start=[0-9.]+", actual) is not None
647    assert re.search("end=[0-9.]+", actual) is not None
648
649    root = Span(None, "test.span", service="s", resource="r", span_type=SpanTypes.WEB)
650    actual = root.pprint()
651    assert "duration=None" in actual
652    assert "end=None" in actual
653
654    root = Span(None, "test.span", service="s", resource="r", span_type=SpanTypes.WEB)
655    root.error = 1
656    actual = root.pprint()
657    assert "error=1" in actual
658
659    root = Span(None, "test.span", service="s", resource="r", span_type=SpanTypes.WEB)
660    root.set_tag(u"��", u"��")
661    actual = root.pprint()
662    assert (u"tags={'��': '��'}" if six.PY3 else "tags={u'\\U0001f60c': u'\\U0001f60c'}") in actual
663
664    root = Span(None, "test.span", service=object())
665    actual = root.pprint()
666    assert "service=<object object at" in actual
667
668
669def test_manual_context_usage():
670    span1 = Span(None, "span1")
671    span2 = Span(None, "span2", context=span1.context)
672
673    span2.context.sampling_priority = 2
674    assert span1.context.sampling_priority == 2
675
676    span1.context.sampling_priority = 1
677    assert span2.context.sampling_priority == 1
678    assert span1.context.sampling_priority == 1
679