def benchmark_tracer_wrap():
tracer = Tracer()
tracer.writer = DummyWriter()
# testcase
class Foo(object):
@staticmethod
@tracer.wrap()
def s():
return 0
@classmethod
@tracer.wrap()
def c(cls):
return 0
@tracer.wrap()
def m(self):
return 0
f = Foo()
# benchmark
print("## tracer.trace() wrapper benchmark: {} loops ##".format(NUMBER))
timer = timeit.Timer(f.s)
result = timer.repeat(repeat=REPEAT, number=NUMBER)
print("- staticmethod execution time: {:8.6f}".format(min(result)))
timer = timeit.Timer(f.c)
result = timer.repeat(repeat=REPEAT, number=NUMBER)
print("- classmethod execution time: {:8.6f}".format(min(result)))
timer = timeit.Timer(f.m)
result = timer.repeat(repeat=REPEAT, number=NUMBER)
print("- method execution time: {:8.6f}".format(min(result)))
def test_priority_sampling_response(encoding, monkeypatch):
monkeypatch.setenv("DD_TRACE_API_VERSION", encoding)
# Send the data once because the agent doesn't respond with them on the
# first payload.
t = Tracer()
s = t.trace("operation", service="my-svc")
s.set_tag("env", "my-env")
s.finish()
assert "service:my-svc,env:my-env" not in t.writer._priority_sampler._by_service_samplers
t.shutdown()
# For some reason the agent doesn't start returning the service information
# immediately
import time
time.sleep(5)
t = Tracer()
s = t.trace("operation", service="my-svc")
s.set_tag("env", "my-env")
s.finish()
assert "service:my-svc,env:my-env" not in t.writer._priority_sampler._by_service_samplers
t.shutdown()
assert "service:my-svc,env:my-env" in t.writer._priority_sampler._by_service_samplers
def test_metrics():
with override_global_config(dict(health_metrics_enabled=True)):
t = Tracer()
statsd_mock = mock.Mock()
t.writer.dogstatsd = statsd_mock
assert t.writer._report_metrics
with mock.patch("ddtrace.internal.writer.log") as log:
for _ in range(5):
spans = []
for i in range(3000):
spans.append(t.trace("op"))
for s in spans:
s.finish()
t.shutdown()
log.warning.assert_not_called()
log.error.assert_not_called()
statsd_mock.distribution.assert_has_calls(
[
mock.call("datadog.tracer.buffer.accepted.traces", 5, tags=[]),
mock.call(
"datadog.tracer.buffer.accepted.spans", 15000, tags=[]),
mock.call("datadog.tracer.http.requests", 1, tags=[]),
mock.call("datadog.tracer.http.sent.bytes", AnyInt()),
],
any_order=True,
)
def test_wrong_span_name_type_not_sent():
"""Span names should be a text type."""
tracer = Tracer()
with mock.patch("ddtrace.span.log") as log:
with tracer.trace(123):
pass
log.exception.assert_called_once_with("error closing trace")
def benchmark_tracer_wrap():
tracer = Tracer()
tracer.writer = DummyWriter()
# testcase
class Foo(object):
@staticmethod
@tracer.wrap()
def s():
return 0
@classmethod
@tracer.wrap()
def c(cls):
return 0
@tracer.wrap()
def m(self):
return 0
f = Foo()
# benchmark
print("## tracer.trace() wrapper benchmark: {} loops ##".format(NUMBER))
timer = timeit.Timer(f.s)
result = timer.repeat(repeat=REPEAT, number=NUMBER)
print("- staticmethod execution time: {:8.6f}".format(min(result)))
timer = timeit.Timer(f.c)
result = timer.repeat(repeat=REPEAT, number=NUMBER)
print("- classmethod execution time: {:8.6f}".format(min(result)))
timer = timeit.Timer(f.m)
result = timer.repeat(repeat=REPEAT, number=NUMBER)
print("- method execution time: {:8.6f}".format(min(result)))
def test_pylons_exception_with_code_method():
writer = DummyWriter()
tracer = Tracer()
tracer.writer = writer
app = FakeWSGIApp()
traced = PylonsTraceMiddleware(app, tracer, service="p")
app.code = '200 OK'
app.body = ['woo']
app.environ = {
'REQUEST_METHOD': 'GET',
'pylons.routes_dict': {
'controller': 'foo',
'action': 'bar',
}
}
try:
out = traced(app.environ, app.start_response_exception_code_method)
assert False
except ExceptionWithCodeMethod:
pass
spans = writer.pop()
ok_(spans, spans)
eq_(len(spans), 1)
s = spans[0]
eq_(s.error, 1)
eq_(s.get_tag('error.msg'), 'Exception with code method')
eq_(int(s.get_tag('http.status_code')), 500)
def test_pylons_string_code():
writer = DummyWriter()
tracer = Tracer()
tracer.writer = writer
app = FakeWSGIApp()
traced = PylonsTraceMiddleware(app, tracer, service="p")
# successful request
eq_(writer.pop(), [])
app.code = '200 OK'
app.body = ['woo']
app.environ = {
'REQUEST_METHOD': 'GET',
'pylons.routes_dict': {
'controller': 'foo',
'action': 'bar',
}
}
try:
out = traced(app.environ, app.start_response_string_code)
except Exception as e:
pass
eq_(tracer.current_span(), None)
spans = writer.pop()
ok_(spans, spans)
eq_(len(spans), 1)
s = spans[0]
eq_(s.error, 1)
eq_(s.get_tag("error.msg"), "Custom exception")
sc = int(s.get_tag("http.status_code"))
eq_(sc, 512)
ok_(s.get_tag("error.stack"))
def test_trace_with_wrong_metrics_types_not_sent(metrics):
tracer = Tracer()
with mock.patch("ddtrace.span.log") as log:
with tracer.trace("root") as root:
root._metrics = metrics
for _ in range(499):
with tracer.trace("child") as child:
child._metrics = metrics
log.exception.assert_called_once_with("error closing trace")
def test_wrong_span_name_type_refused_by_agent(self):
"""Span names should be a text type."""
tracer = Tracer()
with mock.patch("ddtrace.internal.writer.log") as log:
with tracer.trace(123):
pass
tracer.shutdown()
self._assert_bad_trace_refused_by_agent(log)
def test_int_service_integration(int_config):
pin = Pin()
tracer = Tracer()
assert trace_utils.int_service(pin, int_config.myint) is None
with override_global_config(dict(service="global-svc")):
assert trace_utils.int_service(pin, int_config.myint) is None
with tracer.trace("something", service=trace_utils.int_service(pin, int_config.myint)) as s:
assert s.service == "global-svc"
def test_bad_endpoint():
t = Tracer()
t.writer._endpoint = "/bad"
with mock.patch("ddtrace.internal.writer.log") as log:
s = t.trace("operation", service="my-svc")
s.set_tag("env", "my-env")
s.finish()
t.shutdown()
calls = [mock.call("unsupported endpoint '%s': received response %s from Datadog Agent", "/bad", 404)]
log.error.assert_has_calls(calls)
def test_downgrade():
t = Tracer()
t.writer._downgrade(None, None)
assert t.writer._endpoint == "/v0.3/traces"
with mock.patch("ddtrace.internal.writer.log") as log:
s = t.trace("operation", service="my-svc")
s.finish()
t.shutdown()
log.warning.assert_not_called()
log.error.assert_not_called()
def test_single_trace_too_large():
t = Tracer()
with mock.patch("ddtrace.internal.writer.log") as log:
with t.trace("huge"):
for i in range(100000):
with tracer.trace("operation") as s:
s.set_tag("a" * 10, "b" * 10)
t.shutdown()
calls = [mock.call("trace (%db) larger than payload limit (%db), dropping", AnyInt(), AnyInt())]
log.warning.assert_has_calls(calls)
log.error.assert_not_called()
def test_span_tags():
t = Tracer()
with mock.patch("ddtrace.internal.writer.log") as log:
s = t.trace("operation", service="my-svc")
s.set_tag("env", "my-env")
s.set_metric("number", 123)
s.set_metric("number", 12.0)
s.set_metric("number", "1")
s.finish()
t.shutdown()
log.warning.assert_not_called()
log.error.assert_not_called()
def test_child_spans():
t = Tracer()
with mock.patch("ddtrace.internal.writer.log") as log:
spans = []
for i in range(10000):
spans.append(t.trace("op"))
for s in spans:
s.finish()
t.shutdown()
log.warning.assert_not_called()
log.error.assert_not_called()
def test_large_payload():
t = Tracer()
# Traces are approx. 275 bytes.
# 10,000*275 ~ 3MB
with mock.patch("ddtrace.internal.writer.log") as log:
for i in range(10000):
with t.trace("operation"):
pass
t.shutdown()
log.warning.assert_not_called()
log.error.assert_not_called()
def test_get_log_correlation_context_disabled_tracer(self):
"""Ensure get_correlation_log_record returns None if tracer is disabled."""
tracer = Tracer()
tracer.enabled = False
with tracer.trace("test-span"):
dd_log_record = tracer.get_log_correlation_context()
assert dd_log_record == {
"span_id": "0",
"trace_id": "0",
"service": "",
"env": "",
"version": "",
}
def test_large_payload(encoding, monkeypatch):
monkeypatch.setenv("DD_TRACE_API_VERSION", encoding)
t = Tracer()
# Traces are approx. 275 bytes.
# 10,000*275 ~ 3MB
with mock.patch("ddtrace.internal.writer.log") as log:
for i in range(10000):
with t.trace("operation"):
pass
t.shutdown()
log.warning.assert_not_called()
log.error.assert_not_called()
def test_partial_flush_log(run_python_code_in_subprocess):
partial_flush_min_spans = 2
t = Tracer()
t.configure(
partial_flush_enabled=True,
partial_flush_min_spans=partial_flush_min_spans,
)
s1 = t.trace("1")
s2 = t.trace("2")
s3 = t.trace("3")
t_id = s3.trace_id
with mock.patch("ddtrace.internal.processor.trace.log") as log:
s3.finish()
s2.finish()
calls = [
mock.call("trace %d has %d spans, %d finished", t_id, 3, 1),
mock.call("Partially flushing %d spans for trace %d",
partial_flush_min_spans, t_id),
]
log.debug.assert_has_calls(calls)
s1.finish()
t.shutdown()
def test_child_spans(encoding, monkeypatch):
monkeypatch.setenv("DD_TRACE_API_VERSION", encoding)
t = Tracer()
with mock.patch("ddtrace.internal.writer.log") as log:
spans = []
for i in range(10000):
spans.append(t.trace("op"))
for s in spans:
s.finish()
t.shutdown()
log.warning.assert_not_called()
log.error.assert_not_called()
def test_span_tags(encoding, monkeypatch):
monkeypatch.setenv("DD_TRACE_API_VERSION", encoding)
t = Tracer()
with mock.patch("ddtrace.internal.writer.log") as log:
s = t.trace("operation", service="my-svc")
s.set_tag("env", "my-env")
s.set_metric("number", 123)
s.set_metric("number", 12.0)
s.set_metric("number", "1")
s.finish()
t.shutdown()
log.warning.assert_not_called()
log.error.assert_not_called()
def test_downgrade(encoding, monkeypatch):
monkeypatch.setenv("DD_TRACE_API_VERSION", encoding)
t = Tracer()
t.writer._downgrade(None, None)
assert t.writer._endpoint == {
"v0.5": "v0.4/traces",
"v0.4": "v0.3/traces"
}[encoding or "v0.4"]
with mock.patch("ddtrace.internal.writer.log") as log:
s = t.trace("operation", service="my-svc")
s.finish()
t.shutdown()
log.warning.assert_not_called()
log.error.assert_not_called()
def wrapper(wrapped, instance, args, kwargs):
if len(args) > 1:
self = args[0]
clsname = self.__class__.__name__
else:
clsname = ""
if include_tracer:
tracer = Tracer()
else:
tracer = ddtrace.tracer
module = inspect.getmodule(wrapped)
# Use the fully qualified function name as a unique test token to
# identify the snapshot.
token = "{}{}{}.{}".format(module.__name__, "." if clsname else "",
clsname, wrapped.__name__)
# Use variant that applies to update test token. One must apply. If none
# apply, the test should have been marked as skipped.
if variants:
applicable_variant_ids = [k for (k, v) in variants.items() if v]
assert len(applicable_variant_ids) == 1
variant_id = applicable_variant_ids[0]
token = "{}_{}".format(token, variant_id) if variant_id else token
with snapshot_context(token,
ignores=ignores,
tracer=tracer,
async_mode=async_mode):
# Run the test.
if include_tracer:
kwargs["tracer"] = tracer
return wrapped(*args, **kwargs)
def wrapper(wrapped, instance, args, kwargs):
if len(args) > 1:
self = args[0]
clsname = self.__class__.__name__
else:
clsname = ""
if include_tracer:
tracer = Tracer()
else:
tracer = ddtrace.tracer
module = inspect.getmodule(wrapped)
# Use the fully qualified function name as a unique test token to
# identify the snapshot.
token = (
"{}{}{}.{}".format(module.__name__, "." if clsname else "", clsname, wrapped.__name__)
if token_override is None
else token_override
)
with snapshot_context(token, ignores=ignores, tracer=tracer, async_mode=async_mode, variants=variants):
# Run the test.
if include_tracer:
kwargs["tracer"] = tracer
return wrapped(*args, **kwargs)
def test_activate_distributed_headers_no_headers(int_config):
tracer = Tracer()
int_config.myint["distributed_tracing_enabled"] = True
trace_utils.activate_distributed_headers(tracer,
int_config=int_config.myint,
request_headers=None)
assert tracer.context_provider.active() is None
def test_uds_wrong_socket_path():
t = Tracer()
t.configure(uds_path="/tmp/ddagent/nosockethere")
with mock.patch("ddtrace.internal.writer.log") as log:
t.trace("client.testing").finish()
t.shutdown()
calls = [
mock.call("failed to send traces to Datadog Agent at %s", "unix:///tmp/ddagent/nosockethere", exc_info=True)
]
log.error.assert_has_calls(calls)
def test_single_trace_uds():
t = Tracer()
sockdir = "/tmp/ddagent/trace.sock"
t.configure(uds_path=sockdir)
with mock.patch("ddtrace.internal.writer.log") as log:
t.trace("client.testing").finish()
t.shutdown()
log.warning.assert_not_called()
log.error.assert_not_called()
def test_payload_too_large(encoding, monkeypatch):
SIZE = 1 << 12 # 4KB
monkeypatch.setenv("DD_TRACE_API_VERSION", encoding)
monkeypatch.setenv("DD_TRACE_WRITER_BUFFER_SIZE_BYTES", str(SIZE))
monkeypatch.setenv("DD_TRACE_WRITER_MAX_PAYLOAD_SIZE_BYTES", str(SIZE))
t = Tracer()
assert t.writer._max_payload_size == SIZE
assert t.writer._buffer_size == SIZE
# Make sure a flush doesn't happen partway through.
t.configure(
writer=AgentWriter(agent.get_trace_url(), processing_interval=1000))
with mock.patch("ddtrace.internal.writer.log") as log:
for i in range(100000 if encoding == "v0.5" else 1000):
with t.trace("operation") as s:
s.set_tag(str(i), "b" * 190)
s.set_tag(str(i), "a" * 190)
t.shutdown()
calls = [
mock.call(
"trace buffer (%s traces %db/%db) cannot fit trace of size %db, dropping",
AnyInt(),
AnyInt(),
AnyInt(),
AnyInt(),
)
]
log.warning.assert_has_calls(calls)
log.error.assert_not_called()
def test_tracer_trace_across_fork():
"""
When a trace is started in a parent process and a child process is spawned
The trace should be continued in the child process
"""
tracer = Tracer()
def task(tracer):
with tracer.trace("child"):
pass
tracer.shutdown()
with tracer.trace("parent"):
p = multiprocessing.Process(target=task, args=(tracer, ))
p.start()
p.join()
tracer.shutdown()
def test_synchronous_writer():
tracer = Tracer()
writer = AgentWriter(tracer.writer.agent_url, sync_mode=True, priority_sampler=tracer.priority_sampler)
tracer.configure(writer=writer)
with tracer.trace("operation1", service="my-svc"):
with tracer.trace("child1"):
pass
with tracer.trace("operation2", service="my-svc"):
with tracer.trace("child2"):
pass
def test_single_trace_uds(encoding, monkeypatch):
monkeypatch.setenv("DD_TRACE_API_VERSION", encoding)
t = Tracer()
sockdir = "/tmp/ddagent/trace.sock"
t.configure(uds_path=sockdir)
with mock.patch("ddtrace.internal.writer.log") as log:
t.trace("client.testing").finish()
t.shutdown()
log.warning.assert_not_called()
log.error.assert_not_called()
def benchmark_tracer_trace():
tracer = Tracer()
tracer.writer = DummyWriter()
# testcase
def trace(tracer):
# explicit vars
with tracer.trace("a", service="s", resource="r", span_type="t") as s:
s.set_tag("a", "b")
s.set_tag("b", 1)
with tracer.trace("another.thing"):
pass
with tracer.trace("another.thing"):
pass
# benchmark
print("## tracer.trace() benchmark: {} loops ##".format(NUMBER))
timer = timeit.Timer(lambda: trace(tracer))
result = timer.repeat(repeat=REPEAT, number=NUMBER)
print("- trace execution time: {:8.6f}".format(min(result)))
from nose.tools import eq_
# project
from ddtrace import Tracer
from ddtrace.constants import SAMPLING_PRIORITY_KEY
from ddtrace.contrib.flask import TraceMiddleware
from ddtrace.ext import http, errors
from ...test_tracer import DummyWriter
log = logging.getLogger(__name__)
# global writer tracer for the tests.
writer = DummyWriter()
tracer = Tracer()
tracer.writer = writer
class TestError(Exception): pass
class HandleMe(Exception): pass
# define a toy flask app.
cur_dir = os.path.dirname(os.path.realpath(__file__))
tmpl_path = os.path.join(cur_dir, 'test_templates')
app = Flask(__name__, template_folder=tmpl_path)
@app.route('/')
