def execute_with_instana(wrapped, instance, argv, kwargs):
try:
with tracer_stack_context():
ctx = None
if hasattr(instance.request.headers, '__dict__') and '_dict' in instance.request.headers.__dict__:
ctx = tornado_tracer.extract(opentracing.Format.HTTP_HEADERS, instance.request.headers.__dict__['_dict'])
scope = tornado_tracer.start_active_span('tornado-server', child_of=ctx)
# Query param scrubbing
if instance.request.query is not None and len(instance.request.query) > 0:
cleaned_qp = strip_secrets_from_query(instance.request.query, agent.options.secrets_matcher, agent.options.secrets_list)
scope.span.set_tag("http.params", cleaned_qp)
url = "%s://%s%s" % (instance.request.protocol, instance.request.host, instance.request.path)
scope.span.set_tag("http.url", url)
scope.span.set_tag("http.method", instance.request.method)
scope.span.set_tag("handler", instance.__class__.__name__)
# Custom header tracking support
if agent.options.extra_http_headers is not None:
for custom_header in agent.options.extra_http_headers:
if custom_header in instance.request.headers:
scope.span.set_tag("http.header.%s" % custom_header, instance.request.headers[custom_header])
setattr(instance.request, "_instana", scope)
# Set the context response headers now because tornado doesn't give us a better option to do so
# later for this request.
tornado_tracer.inject(scope.span.context, opentracing.Format.HTTP_HEADERS, instance._headers)
instance.set_header(name='Server-Timing', value="intid;desc=%s" % scope.span.context.trace_id)
return wrapped(*argv, **kwargs)
except Exception:
logger.debug("tornado execute", exc_info=True)
def test_start_span_cb(self):
def test_cb(span, request):
span.operation_name = 'foo/' + request.method
span.set_tag('component', 'tornado-client')
tornado_opentracing.init_client_tracing(self.tracer,
start_span_cb=test_cb)
with tracer_stack_context():
self.http_client.fetch(self.get_url('/'), self.stop)
response = self.wait()
self.assertEqual(response.code, 200)
spans = self.tracer.finished_spans()
self.assertEqual(len(spans), 1)
self.assertTrue(spans[0].finished)
self.assertEqual(spans[0].operation_name, 'foo/GET')
self.assertEqual(
spans[0].tags, {
'component': 'tornado-client',
'span.kind': 'client',
'http.url': self.get_url('/'),
'http.method': 'GET',
'http.status_code': 200,
})
def test_good_solution_to_set_parent(self):
"""Solution is good because, though the RequestHandler being shared,
the context will be properly detected."""
with tracer_stack_context():
with self.tracer.start_active_span('parent'):
req_handler = RequestHandler(self.tracer,
ignore_active_span=False)
client = Client(req_handler, self.loop)
response = client.send_sync('correct_parent')
self.assertEquals('correct_parent::response', response)
# Should NOT be a child of the previously activated Span
response = client.send_sync('wrong_parent')
self.assertEquals('wrong_parent::response', response)
spans = self.tracer.finished_spans()
self.assertEquals(len(spans), 3)
spans = sorted(spans, key=lambda x: x.start_time)
parent_span = get_one_by_operation_name(spans, 'parent')
self.assertIsNotNone(parent_span)
self.assertIsChildOf(spans[1], parent_span)
self.assertIsNotChildOf(spans[2], parent_span) # Proper parent (none).
def wrapper(wrapped, instance, args, kwargs):
if self._trace_all:
return wrapped(*args, **kwargs)
handler = instance
with tracer_stack_context():
try:
self._apply_tracing(handler, list(attributes))
# Run the actual function.
result = wrapped(*args, **kwargs)
# if it has `add_done_callback` it's a Future,
# else, a normal method/function.
if callable(getattr(result, 'add_done_callback', None)):
callback = functools.partial(
self._finish_tracing_callback, handler=handler)
result.add_done_callback(callback)
else:
self._finish_tracing(handler)
except Exception as exc:
self._finish_tracing(handler, error=exc)
raise
return result
def test_main(self):
parent_task = functools.partial(self.parent_task, 'message')
with tracer_stack_context():
res = self.loop.run_sync(parent_task)
self.assertEqual(res, 'message::response')
spans = self.tracer.finished_spans()
self.assertEqual(len(spans), 2)
self.assertNamesEqual(spans, ['child', 'parent'])
self.assertIsChildOf(spans[0], spans[1])
def span_in_stack_context(span):
"""
Create Tornado's (4.x, 5.x) StackContext that stores the given span in the
thread-local request context. This function is intended for use
in Tornado applications based on IOLoop, although will work fine
in single-threaded apps like Flask, albeit with more overhead.
StackContext has been deprecated in Tornado 6 and higher.
Because of asyncio nature of Tornado 6.x, consider using
`span_in_context` with opentracing scope manager `ContextVarScopeManager`
## Usage example in Tornado application
Suppose you have a method `handle_request(request)` in the http server.
Instead of calling it directly, use a wrapper:
.. code-block:: python
from opentracing_instrumentation import request_context
@tornado.gen.coroutine
def handle_request_wrapper(request, actual_handler, *args, **kwargs)
request_wrapper = TornadoRequestWrapper(request=request)
span = http_server.before_request(request=request_wrapper)
with request_context.span_in_stack_context(span):
return actual_handler(*args, **kwargs)
:param span:
:return:
Return StackContext that wraps the request context.
"""
if not _tornado_supported:
raise RuntimeError('span_in_stack_context requires Tornado')
if not is_stack_context_supported():
raise RuntimeError('tornado.stack_context is not supported in '
'Tornado >= 6.x')
if not isinstance(opentracing.tracer.scope_manager, TornadoScopeManager):
raise RuntimeError('scope_manager is not TornadoScopeManager')
# Enter the newly created stack context so we have
# storage available for Span activation.
context = tracer_stack_context()
entered_context = _TracerEnteredStackContext(context)
if span is None:
return entered_context
opentracing.tracer.scope_manager.activate(span, False)
assert opentracing.tracer.active_span is not None
assert opentracing.tracer.active_span is span
return entered_context
def execute(func, handler, args, kwargs):
"""
Wrap the handler ``_execute`` method to trace incoming requests,
extracting the context from the headers, if available.
"""
tracing = handler.settings.get('opentracing_tracing')
with tracer_stack_context():
if tracing._trace_all:
attrs = handler.settings.get('opentracing_traced_attributes', [])
tracing._apply_tracing(handler, attrs)
return func(*args, **kwargs)
def test(self):
client = Client(self.tracer, self.queue)
with tracer_stack_context():
self.loop.add_callback(self.server.run)
self.loop.add_callback(client.send)
stop_loop_when(self.loop,
lambda: len(self.tracer.finished_spans()) >= 2)
self.loop.start()
spans = self.tracer.finished_spans()
self.assertIsNotNone(
get_one_by_tag(spans, tags.SPAN_KIND, tags.SPAN_KIND_RPC_SERVER))
self.assertIsNotNone(
get_one_by_tag(spans, tags.SPAN_KIND, tags.SPAN_KIND_RPC_CLIENT))
def test_start_span_cb_exception(self):
def test_cb(span, request):
raise RuntimeError('This should not happen')
tornado_opentracing.init_client_tracing(self.tracer,
start_span_cb=test_cb)
with tracer_stack_context():
self.http_client.fetch(self.get_url('/'), self.stop)
response = self.wait()
self.assertEqual(response.code, 200)
spans = self.tracer.finished_spans()
self.assertEqual(len(spans), 1)
self.assertFalse(spans[0].tags.get('error', False))
def test_main(self):
# Start a Span and let the callback-chain
# finish it when the task is done
with tracer_stack_context():
with self.tracer.start_active_span('one', finish_on_close=False):
self.submit()
stop_loop_when(self.loop,
lambda: len(self.tracer.finished_spans()) == 1)
self.loop.start()
spans = self.tracer.finished_spans()
self.assertEqual(len(spans), 1)
self.assertEqual(spans[0].operation_name, 'one')
for i in range(1, 4):
self.assertEqual(spans[0].tags.get('key%s' % i, None), str(i))
def test_server_not_found(self):
tornado_opentracing.init_client_tracing(self.tracer)
with tracer_stack_context():
self.http_client.fetch(self.get_url('/doesnotexist'), self.stop)
response = self.wait()
self.assertEqual(response.code, 404)
spans = self.tracer.finished_spans()
self.assertEqual(len(spans), 1)
self.assertEqual(spans[0].operation_name, 'GET')
tags = spans[0].tags
self.assertEqual(tags.get('http.status_code', None), 404)
self.assertEqual(tags.get('error', None), None) # no error.
self.assertEqual(len(spans[0].logs), 0)
def test_simple(self):
with tracer_stack_context():
self.http_client.fetch(self.get_url('/'), self.stop)
response = self.wait()
self.assertEqual(response.code, 200)
spans = self.tracer.finished_spans()
self.assertEqual(len(spans), 1)
self.assertTrue(spans[0].finished)
self.assertEqual(spans[0].operation_name, 'GET')
self.assertEqual(
spans[0].tags, {
'component': 'tornado',
'span.kind': 'client',
'http.url': self.get_url('/'),
'http.method': 'GET',
'http.status_code': 200,
})
def test_simple(self):
tornado_opentracing.init_client_tracing(tracing)
with tracer_stack_context():
self.http_client.fetch(self.get_url('/decorated'), self.stop)
response = self.wait()
self.assertEqual(response.code, 200)
spans = tracing.tracer.finished_spans()
self.assertEqual(len(spans), 2)
# Client
span = spans[1]
self.assertTrue(span.finished)
self.assertEqual(span.operation_name, 'GET')
self.assertEqual(
span.tags, {
'component': 'tornado',
'span.kind': 'client',
'http.url': self.get_url('/decorated'),
'http.method': 'GET',
'http.status_code': 200,
})
# Server
span2 = spans[0]
self.assertTrue(span2.finished)
self.assertEqual(span2.operation_name, 'DecoratedHandler')
self.assertEqual(
span2.tags, {
'component': 'tornado',
'span.kind': 'server',
'http.url': '/decorated',
'http.method': 'GET',
'http.status_code': 200,
'protocol': 'http',
})
# Make sure the context was propagated,
# and the client/server have the proper child_of relationship.
self.assertEqual(span.context.trace_id, span2.context.trace_id)
self.assertEqual(span.context.span_id, span2.parent_id)
def test_parent_not_picked(self):
"""Active parent should not be picked up by child
as we pass ignore_active_span=True to the RequestHandler"""
with tracer_stack_context():
with self.tracer.start_active_span('parent'):
response = self.client.send_sync('no_parent')
self.assertEquals('no_parent::response', response)
spans = self.tracer.finished_spans()
self.assertEquals(len(spans), 2)
child_span = get_one_by_operation_name(spans, 'send')
self.assertIsNotNone(child_span)
parent_span = get_one_by_operation_name(spans, 'parent')
self.assertIsNotNone(parent_span)
# Here check that there is no parent-child relation.
self.assertIsNotChildOf(child_span, parent_span)
def test_main(self):
@gen.coroutine
def main_task():
with self.tracer.start_active_span('parent'):
tasks = self.submit_callbacks()
yield tasks
with tracer_stack_context():
self.loop.add_callback(main_task)
stop_loop_when(self.loop,
lambda: len(self.tracer.finished_spans()) == 4)
self.loop.start()
spans = self.tracer.finished_spans()
self.assertEquals(len(spans), 4)
self.assertNamesEqual(spans, ['task', 'task', 'task', 'parent'])
for i in range(3):
self.assertSameTrace(spans[i], spans[-1])
self.assertIsChildOf(spans[i], spans[-1])
def test_main(self):
# Create a Span and use it as (explicit) parent of a pair of subtasks.
with tracer_stack_context():
parent_span = self.tracer.start_span('parent')
self.submit_subtasks(parent_span)
stop_loop_when(self.loop,
lambda: len(self.tracer.finished_spans()) >= 2)
self.loop.start()
# Late-finish the parent Span now.
parent_span.finish()
spans = self.tracer.finished_spans()
self.assertEqual(len(spans), 3)
self.assertNamesEqual(spans, ['task1', 'task2', 'parent'])
for i in range(2):
self.assertSameTrace(spans[i], spans[-1])
self.assertIsChildOf(spans[i], spans[-1])
self.assertTrue(spans[i].finish_time <= spans[-1].finish_time)
def test_main(self):
# Start an isolated task and query for its result -and finish it-
# in another task/thread
span = self.tracer.start_span('initial')
with tracer_stack_context():
self.submit_another_task(span)
stop_loop_when(self.loop,
lambda: len(self.tracer.finished_spans()) >= 3)
self.loop.start()
spans = self.tracer.finished_spans()
self.assertEqual(len(spans), 3)
self.assertNamesEqual(spans, ['initial', 'subtask', 'task'])
# task/subtask are part of the same trace,
# and subtask is a child of task
self.assertSameTrace(spans[1], spans[2])
self.assertIsChildOf(spans[1], spans[2])
# initial task is not related in any way to those two tasks
self.assertNotSameTrace(spans[0], spans[1])
self.assertEqual(spans[0].parent_id, None)
def test_server_error(self):
tornado_opentracing.init_client_tracing(self.tracer)
with tracer_stack_context():
self.http_client.fetch(self.get_url('/error'), self.stop)
response = self.wait()
self.assertEqual(response.code, 500)
spans = self.tracer.finished_spans()
self.assertEqual(len(spans), 1)
self.assertTrue(spans[0].finished)
self.assertEqual(spans[0].operation_name, 'GET')
tags = spans[0].tags
self.assertEqual(tags.get('http.status_code', None), 500)
self.assertEqual(tags.get('error', None), True)
logs = spans[0].logs
self.assertEqual(len(logs), 1)
self.assertEqual(logs[0].key_values.get('event', None), 'error')
self.assertTrue(
isinstance(logs[0].key_values.get('error.object', None),
Exception))
def test_explicit_parameters(self):
tornado_opentracing.init_client_tracing(self.tracer)
with tracer_stack_context():
self.http_client.fetch(self.get_url('/error'),
self.stop,
raise_error=False,
method='POST',
body='')
response = self.wait()
self.assertEqual(response.code, 500)
spans = self.tracer.finished_spans()
self.assertEqual(len(spans), 1)
self.assertTrue(spans[0].finished)
self.assertEqual(spans[0].operation_name, 'POST')
self.assertEqual(
spans[0].tags, {
'component': 'tornado',
'span.kind': 'client',
'http.url': self.get_url('/error'),
'http.method': 'POST',
'http.status_code': 500,
})
def run_test(self, test_fn):
with tracer_stack_context():
ioloop.IOLoop.current().run_sync(test_fn)
