From de4f5a27e5c4cb4b4e62fe98842c7a95ba68bfb3 Mon Sep 17 00:00:00 2001 From: Owais Lone Date: Wed, 26 Feb 2020 13:34:08 +0530 Subject: [PATCH] Add support for Tornado 6 This PR adds support for Tornado 6 by conditionally using different scope manager, context manager and tracing implementation depending on the version of Tornado and Python being used. It does not require existing users to change anything other than upgrade to the latest version of this package. This package used to use the TornadoScopeManager shipped by opentracing-python. The scope manager used `tornado.stack_context` which was deprecated in Tornado 5 and removed in Tornado 6. Tornado now recommends using contextvars package introduced in Python3.7. opentracing-python already provides a ContextVarsScopeManager that builds on top of the contextvars package. It also implements AsyncioScopeManager which builds on top of asyncio and falls back on thread local storage to implement context propagation. We fallback on this for Python 3.6 and older when using Tornado 6 and newer. The package also had seen some decay and some tests were not passing. This PR updates the test suite and unit tests to get them working again. Changes this PR introduces: - Default to ContextVarsScopeManager instead of TornadoScopeManager. Fallback on TornadoScopeManager or AsyncioScopeManager based on the Tornado and Python version. - Added tox support to enable easier testing across Python and Tornado versions. - Updated travis config to work with tox environments. Now each travis build will run tests on every supported python version in parallel. Each parallel test will run all tests for all versions of tornado serially. - The PR add some code that uses the new async/await syntax. Such code is invalid for older versions of python. To make it works for all versions, we conditionally import modules depending on the Python interpreter version. - To preserve backward compatibility and to keep using common code for all tornado versions, we've added some noop implementations that are not to be used with newer versions of tornado. - `tornado.gen.coroutine` was deprecated in favour of async/await but we still support it where we can. There is a bug in Tornado 6 that prevents us from support the deprecated feature on Python3.7 with ContextVarsScopeManager. (https://github.com/tornadoweb/tornado/pull/2716) - Python3.4 also does not pass the tests for `tornado.gen.coroutine` but it is not a regression caused by this PR. Testing on master results in the same behavior. For now, I've added skip markers to these tests on Python3.4. If needed, we can look into supporting these in future in a separate PR. --- .gitignore | 6 + .travis.yml | 8 +- Makefile | 5 +- README.rst | 2 +- setup.py | 8 +- tests/helpers/__init__.py | 14 ++ tests/helpers/_test_case.py | 8 ++ tests/helpers/_test_case_gen.py | 31 ++++ tests/helpers/handlers.py | 22 +++ tests/helpers/handlers_async_await.py | 60 ++++++++ tests/helpers/markers.py | 28 ++++ tests/test_client.py | 65 ++++----- tests/test_decorated.py | 108 ++++++++++++-- tests/test_tracing.py | 124 ++++++++++++---- tornado_opentracing/_tracing.py | 176 +++++++++++++++++++++++ tornado_opentracing/_tracing_async.py | 64 +++++++++ tornado_opentracing/context_managers.py | 25 ++++ tornado_opentracing/handlers.py | 29 ++-- tornado_opentracing/httpclient.py | 1 - tornado_opentracing/initialization.py | 29 +++- tornado_opentracing/scope_managers.py | 18 +++ tornado_opentracing/tracing.py | 180 ++---------------------- tox.ini | 31 ++++ 23 files changed, 780 insertions(+), 262 deletions(-) create mode 100644 tests/helpers/__init__.py create mode 100644 tests/helpers/_test_case.py create mode 100644 tests/helpers/_test_case_gen.py create mode 100644 tests/helpers/handlers.py create mode 100644 tests/helpers/handlers_async_await.py create mode 100644 tests/helpers/markers.py create mode 100644 tornado_opentracing/_tracing.py create mode 100644 tornado_opentracing/_tracing_async.py create mode 100644 tornado_opentracing/context_managers.py create mode 100644 tornado_opentracing/scope_managers.py create mode 100644 tox.ini diff --git a/.gitignore b/.gitignore index 81615c4..6cd277f 100644 --- a/.gitignore +++ b/.gitignore @@ -1,4 +1,8 @@ +.coverage +.python-version +.tox *.pyc +.vscode dist bin eggs @@ -6,3 +10,5 @@ lib *.egg-info build env/ +venv/ +.pytest_cache/* diff --git a/.travis.yml b/.travis.yml index 06887e2..52172dc 100644 --- a/.travis.yml +++ b/.travis.yml @@ -1,11 +1,17 @@ language: python python: - "2.7" + - "3.4" + - "3.5" + - "3.6" + - "3.7" + - "3.8" sudo: required install: + - pip install tox tox-travis - make bootstrap script: - - make test lint + - make test diff --git a/Makefile b/Makefile index 7c73df8..1ec5a5a 100644 --- a/Makefile +++ b/Makefile @@ -38,9 +38,12 @@ clean-test: lint: flake8 $(project) tests -test: +test-local: py.test -s --cov-report term-missing:skip-covered --cov=$(project) +test: + tox + build: python setup.py build diff --git a/README.rst b/README.rst index 74bea2a..98011d2 100644 --- a/README.rst +++ b/README.rst @@ -25,7 +25,7 @@ In order to implement tracing in your system (for all the requests), add the fol .. code-block:: python - from opentracing.scope_managers.tornado import TornadoScopeManager + from opentracing_tornado.scope_managers import TornadoScopeManager import tornado_opentracing # Create your opentracing tracer using TornadoScopeManager for active Span handling. diff --git a/setup.py b/setup.py index cc630af..43ed068 100644 --- a/setup.py +++ b/setup.py @@ -15,15 +15,17 @@ platforms='any', install_requires=[ 'tornado', - 'opentracing>=2.0,<2.1', + 'opentracing>=2.0,<2.4', 'wrapt', ], extras_require={ 'tests': [ - 'flake8<3', # see https://github.com/zheller/flake8-quotes/issues/29 + 'flake8<4', 'flake8-quotes', - 'pytest>=2.7,<3', + 'pytest>=4.6.9', 'pytest-cov', + 'mock', + 'tox', ], }, classifiers=[ diff --git a/tests/helpers/__init__.py b/tests/helpers/__init__.py new file mode 100644 index 0000000..95c1868 --- /dev/null +++ b/tests/helpers/__init__.py @@ -0,0 +1,14 @@ +import sys + +import tornado_opentracing +from opentracing.mocktracer import MockTracer +from tornado_opentracing.scope_managers import ScopeManager + + +if sys.version_info >= (3, 3): + from ._test_case_gen import AsyncHTTPTestCase # noqa +else: + from ._test_case import AsyncHTTPTestCase # noqa + + +tracing = tornado_opentracing.TornadoTracing(MockTracer(ScopeManager())) diff --git a/tests/helpers/_test_case.py b/tests/helpers/_test_case.py new file mode 100644 index 0000000..55852be --- /dev/null +++ b/tests/helpers/_test_case.py @@ -0,0 +1,8 @@ +import tornado.testing + + +class AsyncHTTPTestCase(tornado.testing.AsyncHTTPTestCase): + + def http_fetch(self, url, *args, **kwargs): + self.http_client.fetch(url, self.stop, *args, **kwargs) + return self.wait() diff --git a/tests/helpers/_test_case_gen.py b/tests/helpers/_test_case_gen.py new file mode 100644 index 0000000..d172582 --- /dev/null +++ b/tests/helpers/_test_case_gen.py @@ -0,0 +1,31 @@ +import tornado.testing +from tornado.httpclient import HTTPError +from tornado import version_info as tornado_version + +from ._test_case import AsyncHTTPTestCase as BaseTestCase + + +use_wait_stop = tornado_version < (5, 0, 0) + +if use_wait_stop: + def gen_test(func): + return func +else: + gen_test = tornado.testing.gen_test + + +class AsyncHTTPTestCase(BaseTestCase): + + @gen_test + def _http_fetch_gen(self, url, *args, **kwargs): + try: + response = yield self.http_client.fetch(url, *args, **kwargs) + except HTTPError as exc: + response = exc.response + return response + + def http_fetch(self, url, *args, **kwargs): + fetch = self._http_fetch_gen + if use_wait_stop: + fetch = super().http_fetch + return fetch(url, *args, **kwargs) diff --git a/tests/helpers/handlers.py b/tests/helpers/handlers.py new file mode 100644 index 0000000..469601d --- /dev/null +++ b/tests/helpers/handlers.py @@ -0,0 +1,22 @@ +import sys + +import tornado.web + + +class noopHandler(tornado.web.RequestHandler): + def get(self): + pass + + +if sys.version_info > (3, 5): + from .handlers_async_await import ( + AsyncScopeHandler, + DecoratedAsyncHandler, + DecoratedAsyncScopeHandler, + DecoratedAsyncErrorHandler + ) +else: + AsyncScopeHandler = noopHandler + DecoratedAsyncHandler = noopHandler + DecoratedAsyncScopeHandler = noopHandler + DecoratedAsyncErrorHandler = noopHandler diff --git a/tests/helpers/handlers_async_await.py b/tests/helpers/handlers_async_await.py new file mode 100644 index 0000000..d523863 --- /dev/null +++ b/tests/helpers/handlers_async_await.py @@ -0,0 +1,60 @@ +import asyncio + +import tornado.web + +from . import tracing + + +class AsyncScopeHandler(tornado.web.RequestHandler): + async def do_something(self): + tracing = self.settings.get('opentracing_tracing') + with tracing.tracer.start_active_span('Child'): + tracing.tracer.active_span.set_tag('start', 0) + await asyncio.sleep(0) + tracing.tracer.active_span.set_tag('end', 1) + + async def get(self): + tracing = self.settings.get('opentracing_tracing') + span = tracing.get_span(self.request) + assert span is not None + assert tracing.tracer.active_span is span + + await self.do_something() + + assert tracing.tracer.active_span is span + self.write('{}') + + +class DecoratedAsyncHandler(tornado.web.RequestHandler): + @tracing.trace('protocol', 'doesntexist') + async def get(self): + await asyncio.sleep(0) + self.set_status(201) + self.write('{}') + + +class DecoratedAsyncErrorHandler(tornado.web.RequestHandler): + @tracing.trace() + async def get(self): + await asyncio.sleep(0) + raise ValueError('invalid value') + + +class DecoratedAsyncScopeHandler(tornado.web.RequestHandler): + async def do_something(self): + with tracing.tracer.start_active_span('Child'): + tracing.tracer.active_span.set_tag('start', 0) + await asyncio.sleep(0) + tracing.tracer.active_span.set_tag('end', 1) + + @tracing.trace() + async def get(self): + span = tracing.get_span(self.request) + assert span is not None + assert tracing.tracer.active_span is span + + await self.do_something() + + assert tracing.tracer.active_span is span + self.set_status(201) + self.write('{}') diff --git a/tests/helpers/markers.py b/tests/helpers/markers.py new file mode 100644 index 0000000..fa2229a --- /dev/null +++ b/tests/helpers/markers.py @@ -0,0 +1,28 @@ +import sys + +import pytest +from tornado import version_info as tornado_version + + +skip_generator_contextvars_on_tornado6 = pytest.mark.skipif( + tornado_version >= (6, 0, 0), + reason=( + 'tornado6 has a bug (#2716) that ' + 'prevents contextvars from working.' + ) +) + + +skip_generator_contextvars_on_py34 = pytest.mark.skipif( + sys.version_info.major == 3 and sys.version_info.minor == 4, + reason=('does not work on 3.4 with tornado context stack currently.') +) + + +skip_no_async_await = pytest.mark.skipif( + sys.version_info < (3, 5) or tornado_version < (5, 0), + reason=( + 'async/await is not supported on python older than 3.5 ' + 'and tornado older than 5.0.' + ) +) diff --git a/tests/test_client.py b/tests/test_client.py index e895e6a..7d36144 100644 --- a/tests/test_client.py +++ b/tests/test_client.py @@ -15,13 +15,15 @@ import mock from opentracing.mocktracer import MockTracer -from opentracing.scope_managers.tornado import TornadoScopeManager -from opentracing.scope_managers.tornado import tracer_stack_context import tornado.gen from tornado.httpclient import HTTPRequest import tornado.web import tornado.testing import tornado_opentracing +from tornado_opentracing.scope_managers import ScopeManager +from tornado_opentracing.context_managers import tornado_context + +from .helpers import AsyncHTTPTestCase class MainHandler(tornado.web.RequestHandler): @@ -47,9 +49,9 @@ def make_app(): return app -class TestClient(tornado.testing.AsyncHTTPTestCase): +class TestClient(AsyncHTTPTestCase): def setUp(self): - self.tracer = MockTracer(TornadoScopeManager()) + self.tracer = MockTracer(ScopeManager()) super(TestClient, self).setUp() def tearDown(self): @@ -63,10 +65,9 @@ def test_no_tracer(self): tornado_opentracing.init_client_tracing() with mock.patch('opentracing.tracer', new=self.tracer): - with tracer_stack_context(): - self.http_client.fetch(self.get_url('/'), self.stop) + with tornado_context(): + response = self.http_fetch(self.get_url('/')) - response = self.wait() self.assertEqual(response.code, 200) spans = self.tracer.finished_spans() @@ -84,10 +85,9 @@ def test_no_tracer(self): def test_simple(self): tornado_opentracing.init_client_tracing(self.tracer) - with tracer_stack_context(): - self.http_client.fetch(self.get_url('/'), self.stop) + with tornado_context(): + response = self.http_fetch(self.get_url('/')) - response = self.wait() self.assertEqual(response.code, 200) spans = self.tracer.finished_spans() @@ -110,10 +110,9 @@ def test_cb(span, request): 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) + with tornado_context(): + response = self.http_fetch(self.get_url('/')) - response = self.wait() self.assertEqual(response.code, 200) spans = self.tracer.finished_spans() @@ -135,10 +134,9 @@ def test_cb(span, request): 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) + with tornado_context(): + response = self.http_fetch(self.get_url('/')) - response = self.wait() self.assertEqual(response.code, 200) spans = self.tracer.finished_spans() @@ -148,15 +146,14 @@ def test_cb(span, request): 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) + with tornado_context(): + response = self.http_fetch( + self.get_url('/error'), + raise_error=False, + method='POST', + body='') + self.assertEqual(response.code, 500) spans = self.tracer.finished_spans() self.assertEqual(len(spans), 1) self.assertTrue(spans[0].finished) @@ -172,10 +169,8 @@ def test_explicit_parameters(self): def test_request_obj(self): tornado_opentracing.init_client_tracing(self.tracer) - with tracer_stack_context(): - self.http_client.fetch(HTTPRequest(self.get_url('/')), self.stop) - - response = self.wait() + with tornado_context(): + response = self.http_fetch(HTTPRequest(self.get_url('/'))) self.assertEqual(response.code, 200) @@ -194,12 +189,10 @@ def test_request_obj(self): 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) + with tornado_context(): + response = self.http_fetch(self.get_url('/error')) - response = self.wait() self.assertEqual(response.code, 500) - spans = self.tracer.finished_spans() self.assertEqual(len(spans), 1) self.assertTrue(spans[0].finished) @@ -220,10 +213,12 @@ def test_server_error(self): 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) + with tornado_context(): + response = self.http_fetch( + self.get_url('/doesnotexist'), + raise_error=False + ) - response = self.wait() self.assertEqual(response.code, 404) spans = self.tracer.finished_spans() diff --git a/tests/test_decorated.py b/tests/test_decorated.py index 6e5af36..4bbf2a5 100644 --- a/tests/test_decorated.py +++ b/tests/test_decorated.py @@ -12,16 +12,24 @@ # See the License for the specific language governing permissions and # limitations under the License. -from opentracing.mocktracer import MockTracer -from opentracing.scope_managers.tornado import TornadoScopeManager -from opentracing.scope_managers.tornado import tracer_stack_context import tornado.gen import tornado.web import tornado.testing import tornado_opentracing - - -tracing = tornado_opentracing.TornadoTracing(MockTracer(TornadoScopeManager())) +from tornado_opentracing.context_managers import tornado_context + +from .helpers import tracing +from .helpers import AsyncHTTPTestCase +from .helpers.handlers import ( + DecoratedAsyncHandler, + DecoratedAsyncScopeHandler, + DecoratedAsyncErrorHandler +) +from .helpers.markers import ( + skip_generator_contextvars_on_tornado6, + skip_generator_contextvars_on_py34, + skip_no_async_await, +) class MainHandler(tornado.web.RequestHandler): @@ -98,6 +106,9 @@ def make_app(with_tracing_obj=False): ('/decorated_coroutine', DecoratedCoroutineHandler), ('/decorated_coroutine_error', DecoratedCoroutineErrorHandler), ('/decorated_coroutine_scope', DecoratedCoroutineScopeHandler), + ('/decorated_async', DecoratedAsyncHandler), + ('/decorated_async_error', DecoratedAsyncErrorHandler), + ('/decorated_async_scope', DecoratedAsyncScopeHandler), ], **settings ) @@ -154,6 +165,8 @@ def test_error(self): logs[0].key_values.get('error.object', None), ValueError )) + @skip_generator_contextvars_on_tornado6 + @skip_generator_contextvars_on_py34 def test_coroutine(self): response = self.fetch('/decorated_coroutine') self.assertEqual(response.code, 201) @@ -171,6 +184,8 @@ def test_coroutine(self): 'protocol': 'http', }) + @skip_generator_contextvars_on_tornado6 + @skip_generator_contextvars_on_py34 def test_coroutine_error(self): response = self.fetch('/decorated_coroutine_error') self.assertEqual(response.code, 500) @@ -192,6 +207,8 @@ def test_coroutine_error(self): logs[0].key_values.get('error.object', None), ValueError )) + @skip_generator_contextvars_on_tornado6 + @skip_generator_contextvars_on_py34 def test_coroutine_scope(self): response = self.fetch('/decorated_coroutine_scope') self.assertEqual(response.code, 201) @@ -223,6 +240,78 @@ def test_coroutine_scope(self): self.assertEqual(child.context.trace_id, parent.context.trace_id) self.assertEqual(child.parent_id, parent.context.span_id) + @skip_no_async_await + def test_async(self): + response = self.fetch('/decorated_async') + self.assertEqual(response.code, 201) + + spans = tracing.tracer.finished_spans() + self.assertEqual(len(spans), 1) + self.assertTrue(spans[0].finished) + self.assertEqual(spans[0].operation_name, 'DecoratedAsyncHandler') + self.assertEqual(spans[0].tags, { + 'component': 'tornado', + 'span.kind': 'server', + 'http.url': '/decorated_async', + 'http.method': 'GET', + 'http.status_code': 201, + 'protocol': 'http', + }) + + @skip_no_async_await + def test_async_error(self): + response = self.fetch('/decorated_async_error') + self.assertEqual(response.code, 500) + + spans = tracing.tracer.finished_spans() + self.assertEqual(len(spans), 1) + self.assertTrue(spans[0].finished) + self.assertEqual(spans[0].operation_name, + 'DecoratedAsyncErrorHandler') + + tags = spans[0].tags + 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), ValueError + )) + + @skip_no_async_await + def test_async_scope(self): + response = self.fetch('/decorated_async_scope') + self.assertEqual(response.code, 201) + + spans = tracing.tracer.finished_spans() + self.assertEqual(len(spans), 2) + + child = spans[0] + self.assertTrue(child.finished) + self.assertEqual(child.operation_name, 'Child') + self.assertEqual(child.tags, { + 'start': 0, + 'end': 1, + }) + + parent = spans[1] + self.assertTrue(parent.finished) + self.assertEqual(parent.operation_name, + 'DecoratedAsyncScopeHandler') + self.assertEqual(parent.tags, { + 'component': 'tornado', + 'span.kind': 'server', + 'http.url': '/decorated_async_scope', + 'http.method': 'GET', + 'http.status_code': 201, + }) + + # Same trace. + self.assertEqual(child.context.trace_id, parent.context.trace_id) + self.assertEqual(child.parent_id, parent.context.span_id) + class TestDecoratedAndTraceAll(tornado.testing.AsyncHTTPTestCase): def setUp(self): @@ -251,7 +340,7 @@ def test_only_one_span(self): self.assertTrue(spans[0].finished) -class TestClientIntegration(tornado.testing.AsyncHTTPTestCase): +class TestClientIntegration(AsyncHTTPTestCase): def tearDown(self): tornado_opentracing.initialization._unpatch_tornado_client() tracing.tracer.reset() @@ -263,10 +352,9 @@ def get_app(self): def test_simple(self): tornado_opentracing.init_client_tracing(tracing) - with tracer_stack_context(): - self.http_client.fetch(self.get_url('/decorated'), self.stop) + with tornado_context(): + response = self.http_fetch(self.get_url('/decorated')) - response = self.wait() self.assertEqual(response.code, 200) spans = tracing.tracer.finished_spans() diff --git a/tests/test_tracing.py b/tests/test_tracing.py index 2152d7f..254cebc 100644 --- a/tests/test_tracing.py +++ b/tests/test_tracing.py @@ -12,31 +12,52 @@ # See the License for the specific language governing permissions and # limitations under the License. +import sys import mock import unittest import opentracing from opentracing.mocktracer import MockTracer -from opentracing.scope_managers.tornado import TornadoScopeManager -from opentracing.scope_managers.tornado import tracer_stack_context import tornado.gen import tornado.web import tornado.testing import tornado_opentracing +from tornado import version_info as tornado_version from tornado_opentracing import TornadoTracing +from tornado_opentracing.scope_managers import ScopeManager +from tornado_opentracing.context_managers import tornado_context + +from .helpers import AsyncHTTPTestCase +from .helpers.handlers import AsyncScopeHandler +from .helpers.markers import ( + skip_generator_contextvars_on_tornado6, + skip_no_async_await, +) + + +async_await_not_supported = ( + sys.version_info < (3, 5) or tornado_version < (5, 0) +) class MainHandler(tornado.web.RequestHandler): + SUPPORTED_METHODS = ( + tornado.web.RequestHandler.SUPPORTED_METHODS + ('CUSTOM_METHOD',) + ) + def get(self): self.write('{}') + def custom_method(self): + self.write('{}') + class ErrorHandler(tornado.web.RequestHandler): def get(self): raise ValueError('invalid input') -class ScopeHandler(tornado.web.RequestHandler): +class CoroutineScopeHandler(tornado.web.RequestHandler): @tornado.gen.coroutine def do_something(self): tracing = self.settings.get('opentracing_tracing') @@ -82,7 +103,8 @@ def make_app(tracer=None, tracer_callable=None, tracer_parameters={}, [ ('/', MainHandler), ('/error', ErrorHandler), - ('/coroutine_scope', ScopeHandler), + ('/coroutine_scope', CoroutineScopeHandler), + ('/async_scope', AsyncScopeHandler), ], **settings ) @@ -108,7 +130,7 @@ def test_start_span_cb_invalid(self): tornado_opentracing.TornadoTracing(start_span_cb=[]) -class TestTornadoTracingBase(tornado.testing.AsyncHTTPTestCase): +class TestTornadoTracingBase(AsyncHTTPTestCase): def setUp(self): tornado_opentracing.init_tracing() super(TestTornadoTracingBase, self).setUp() @@ -121,7 +143,7 @@ def tearDown(self): class TestInitWithoutTracingObj(TestTornadoTracingBase): def get_app(self): - self.tracer = MockTracer(TornadoScopeManager()) + self.tracer = MockTracer(ScopeManager()) return make_app(start_span_cb=self.start_span_cb) def start_span_cb(self, span, request): @@ -154,7 +176,7 @@ def tracer_callable(tracer): class TestInitWithTracerCallable(TestTornadoTracingBase): def get_app(self): - self.tracer = MockTracer(TornadoScopeManager()) + self.tracer = MockTracer(ScopeManager()) return make_app(tracer_callable=tracer_callable, tracer_parameters={ 'tracer': self.tracer, }) @@ -172,7 +194,7 @@ def test_case(self): class TestInitWithTracerCallableStr(TestTornadoTracingBase): def get_app(self): - self.tracer = MockTracer(TornadoScopeManager()) + self.tracer = MockTracer(ScopeManager()) return make_app(tracer_callable='tests.test_tracing.tracer_callable', tracer_parameters={ 'tracer': self.tracer @@ -191,7 +213,7 @@ def test_case(self): class TestTracing(TestTornadoTracingBase): def get_app(self): - self.tracer = MockTracer(TornadoScopeManager()) + self.tracer = MockTracer(ScopeManager()) return make_app(self.tracer, trace_client=False) def test_simple(self): @@ -210,8 +232,28 @@ def test_simple(self): 'http.status_code': 200, }) + def test_custom_method(self): + response = self.fetch( + '/', + method='CUSTOM_METHOD', + allow_nonstandard_methods=True + ) + 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, 'MainHandler') + self.assertEqual(spans[0].tags, { + 'component': 'tornado', + 'span.kind': 'server', + 'http.url': '/', + 'http.method': 'CUSTOM_METHOD', + 'http.status_code': 200, + }) + def test_error(self): - response = self.fetch('/error') + response = self.http_fetch(self.get_url('/error')) self.assertEqual(response.code, 500) spans = self.tracer.finished_spans() @@ -230,8 +272,9 @@ def test_error(self): logs[0].key_values.get('error.object', None), ValueError )) - def test_scope(self): - response = self.fetch('/coroutine_scope') + @skip_generator_contextvars_on_tornado6 + def test_scope_coroutine(self): + response = self.http_fetch(self.get_url('/coroutine_scope')) self.assertEqual(response.code, 200) spans = self.tracer.finished_spans() @@ -247,7 +290,7 @@ def test_scope(self): parent = spans[1] self.assertTrue(parent.finished) - self.assertEqual(parent.operation_name, 'ScopeHandler') + self.assertEqual(parent.operation_name, 'CoroutineScopeHandler') self.assertEqual(parent.tags, { 'component': 'tornado', 'span.kind': 'server', @@ -260,14 +303,45 @@ def test_scope(self): self.assertEqual(child.context.trace_id, parent.context.trace_id) self.assertEqual(child.parent_id, parent.context.span_id) + @skip_no_async_await + def test_scope_async(self): + response = self.http_fetch(self.get_url('/async_scope')) + self.assertEqual(response.code, 200) + + spans = self.tracer.finished_spans() + self.assertEqual(len(spans), 2) + + child = spans[0] + self.assertTrue(child.finished) + self.assertEqual(child.operation_name, 'Child') + self.assertEqual(child.tags, { + 'start': 0, + 'end': 1, + }) + + parent = spans[1] + self.assertTrue(parent.finished) + self.assertEqual(parent.operation_name, 'AsyncScopeHandler') + self.assertEqual(parent.tags, { + 'component': 'tornado', + 'span.kind': 'server', + 'http.url': '/async_scope', + 'http.method': 'GET', + 'http.status_code': 200, + }) + + # Same trace. + self.assertEqual(child.context.trace_id, parent.context.trace_id) + self.assertEqual(child.parent_id, parent.context.span_id) + class TestNoTraceAll(TestTornadoTracingBase): def get_app(self): - self.tracer = MockTracer(TornadoScopeManager()) + self.tracer = MockTracer(ScopeManager()) return make_app(self.tracer, trace_all=False, trace_client=False) def test_simple(self): - response = self.fetch('/') + response = self.http_fetch(self.get_url('/')) self.assertEqual(response.code, 200) spans = self.tracer.finished_spans() @@ -276,7 +350,7 @@ def test_simple(self): class TestTracedAttributes(TestTornadoTracingBase): def get_app(self): - self.tracer = MockTracer(TornadoScopeManager()) + self.tracer = MockTracer(ScopeManager()) return make_app(self.tracer, trace_client=False, traced_attributes=[ @@ -311,7 +385,7 @@ def start_span_cb(self, span, request): span.set_tag('custom-tag', 'custom-value') def get_app(self): - self.tracer = MockTracer(TornadoScopeManager()) + self.tracer = MockTracer(ScopeManager()) return make_app(self.tracer, trace_client=False, start_span_cb=self.start_span_cb) @@ -339,7 +413,7 @@ def start_span_cb(self, span, request): raise RuntimeError('This should not happen') def get_app(self): - self.tracer = MockTracer(TornadoScopeManager()) + self.tracer = MockTracer(ScopeManager()) return make_app(self.tracer, trace_client=False, start_span_cb=self.start_span_cb) @@ -355,15 +429,14 @@ def test_start_span_cb(self): class TestClient(TestTornadoTracingBase): def get_app(self): - self.tracer = MockTracer(TornadoScopeManager()) + self.tracer = MockTracer(ScopeManager()) return make_app(self.tracer, trace_all=False) def test_simple(self): - with tracer_stack_context(): - self.http_client.fetch(self.get_url('/'), self.stop) + with tornado_context(): + response = self.http_fetch(self.get_url('/'), self.stop) - response = self.wait() self.assertEqual(response.code, 200) spans = self.tracer.finished_spans() @@ -381,7 +454,7 @@ def test_simple(self): class TestClientCallback(TestTornadoTracingBase): def get_app(self): - self.tracer = MockTracer(TornadoScopeManager()) + self.tracer = MockTracer(ScopeManager()) return make_app(self.tracer, trace_all=False, start_span_cb=self.start_span_cb) @@ -392,10 +465,9 @@ def start_span_cb(self, span, request): span.set_tag('custom-tag', 'custom-value') def test_simple(self): - with tracer_stack_context(): - self.http_client.fetch(self.get_url('/'), self.stop) + with tornado_context(): + response = self.http_fetch(self.get_url('/'), self.stop) - response = self.wait() self.assertEqual(response.code, 200) spans = self.tracer.finished_spans() diff --git a/tornado_opentracing/_tracing.py b/tornado_opentracing/_tracing.py new file mode 100644 index 0000000..a06f16b --- /dev/null +++ b/tornado_opentracing/_tracing.py @@ -0,0 +1,176 @@ +# Copyright The OpenTracing Authors +# +# Licensed under the Apache License, Version 2.0 (the "License"); +# you may not use this file except in compliance with the License. +# You may obtain a copy of the License at +# +# http://www.apache.org/licenses/LICENSE-2.0 +# +# Unless required by applicable law or agreed to in writing, software +# distributed under the License is distributed on an "AS IS" BASIS, +# WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. +# See the License for the specific language governing permissions and +# limitations under the License. + +import functools +import wrapt + +import opentracing +from opentracing.ext import tags + +from .context_managers import tornado_context +from ._constants import SCOPE_ATTR + + +class BaseTornadoTracing(object): + """ + @param tracer the OpenTracing tracer to be used + to trace requests using this TornadoTracing + """ + def __init__(self, tracer=None, start_span_cb=None): + if start_span_cb is not None and not callable(start_span_cb): + raise ValueError('start_span_cb is not callable') + + self._tracer_obj = tracer + self._start_span_cb = start_span_cb + self._trace_all = False + self._trace_client = False + + @property + def _tracer(self): + """ + DEPRECATED + """ + return self.tracer + + @property + def tracer(self): + if self._tracer_obj is None: + return opentracing.tracer + + return self._tracer_obj + + def get_span(self, request): + """ + @param request + Returns the span tracing this request + """ + scope = getattr(request, SCOPE_ATTR, None) + return None if scope is None else scope.span + + def _handle_wrapped_result(self, handler, result): + # 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) + + def trace(self, *attributes): + """ + Function decorator that traces functions + NOTE: Must be placed before the Tornado decorators + @param attributes any number of request attributes + (strings) to be set as tags on the created span + """ + + @wrapt.decorator + def wrapper(wrapped, instance, args, kwargs): + if self._trace_all: + return wrapped(*args, **kwargs) + + handler = instance + + with tornado_context(): + try: + self._apply_tracing(handler, list(attributes)) + + # Run the actual function. + result = wrapped(*args, **kwargs) + self._handle_wrapped_result(handler, result) + except Exception as exc: + self._finish_tracing(handler, error=exc) + raise + + return result + + return wrapper + + def _get_operation_name(self, handler): + full_class_name = type(handler).__name__ + return full_class_name.rsplit('.')[-1] # package-less name. + + def _finish_tracing_callback(self, future, handler): + error = future.exception() + self._finish_tracing(handler, error=error) + + def _apply_tracing(self, handler, attributes): + """ + Helper function to avoid rewriting for middleware and decorator. + Returns a new span from the request with logged attributes and + correct operation name from the func. + """ + operation_name = self._get_operation_name(handler) + headers = handler.request.headers + request = handler.request + + # start new span from trace info + try: + span_ctx = self._tracer.extract(opentracing.Format.HTTP_HEADERS, + headers) + scope = self._tracer.start_active_span(operation_name, + child_of=span_ctx) + except (opentracing.InvalidCarrierException, + opentracing.SpanContextCorruptedException): + scope = self._tracer.start_active_span(operation_name) + + # add span to current spans + setattr(request, SCOPE_ATTR, scope) + + # log any traced attributes + scope.span.set_tag(tags.COMPONENT, 'tornado') + scope.span.set_tag(tags.SPAN_KIND, tags.SPAN_KIND_RPC_SERVER) + scope.span.set_tag(tags.HTTP_METHOD, request.method) + scope.span.set_tag(tags.HTTP_URL, request.uri) + + for attr in attributes: + if hasattr(request, attr): + payload = str(getattr(request, attr)) + if payload: + scope.span.set_tag(attr, payload) + + # invoke the start span callback, if any + self._call_start_span_cb(scope.span, request) + + return scope + + def _finish_tracing(self, handler, error=None): + scope = getattr(handler.request, SCOPE_ATTR, None) + if scope is None: + return + + delattr(handler.request, SCOPE_ATTR) + + if error is not None: + scope.span.set_tag(tags.ERROR, True) + scope.span.log_kv({ + 'event': tags.ERROR, + 'error.object': error, + }) + else: + scope.span.set_tag(tags.HTTP_STATUS_CODE, handler.get_status()) + + scope.close() + + def _call_start_span_cb(self, span, request): + if self._start_span_cb is None: + return + + try: + self._start_span_cb(span, request) + except Exception: + # TODO - log the error to the Span? + pass diff --git a/tornado_opentracing/_tracing_async.py b/tornado_opentracing/_tracing_async.py new file mode 100644 index 0000000..d1e35a2 --- /dev/null +++ b/tornado_opentracing/_tracing_async.py @@ -0,0 +1,64 @@ +""" +This module implements AsyncTornadoTracing for Python3.5 and above. +The module must be only imported when running on Python3.5 and newer. +Importing it on older version of Python will result in SyntaxError +exception. +The module is suffixed with "_py35" to indicate to python tooling +such as linters that it should be only be taken into account +for Python3.5 and above. +""" + +import inspect +import functools + +from ._tracing import BaseTornadoTracing + + +class AsyncTornadoTracing(BaseTornadoTracing): + + def trace(self, *attributes): + """ + Function decorator that traces functions + NOTE: Must be placed before the Tornado decorators + @param attributes any number of request attributes + (strings) to be set as tags on the created span. + + This decorator support async functions in addition to regular ones. + This is needed for tornado to work correctly with async handlers. + + We use a descriptor here as we need reference to the instance of the + method being decorated which is not possible to do with a simple + decorator. + + We don't use wrapt.decorator as it does not work uniformly with + both async and regular functions, and we cannot selectively export + an async or a regular decorator using wrapt as it's not possible + to determine if the function being wrapped is async or not before + the decorator is applied. + """ + tracing = self + + class Descriptor(object): + def __init__(self, wrapped): + self.wrapped = wrapped + + async def __call__(self, handler, *args, **kwargs): + if tracing._trace_all: + return self.wrapped(handler, *args, **kwargs) + + try: + tracing._apply_tracing(handler, list(attributes)) + + result = self.wrapped(handler, *args, **kwargs) + if result is not None and inspect.isawaitable(result): + result = await result + tracing._handle_wrapped_result(handler, result) + + except Exception as exc: + tracing._finish_tracing(handler, error=exc) + raise + + def __get__(self, instance, owner): + return functools.partial(self.__call__, instance) + + return Descriptor diff --git a/tornado_opentracing/context_managers.py b/tornado_opentracing/context_managers.py new file mode 100644 index 0000000..59fe77d --- /dev/null +++ b/tornado_opentracing/context_managers.py @@ -0,0 +1,25 @@ +from tornado import version_info as tornado_version + +if tornado_version < (6, 0): + from opentracing.scope_managers.tornado import ( + tracer_stack_context as tornado_context + ) +else: + def tornado_context(): + return _NoopContextManager() + + +class _NoopContextManager(object): + """ + With Tornado 6 and newer, we use ContextVarsScopeManager + or AsyncIOScopeManager depending on the Python interpreter version. + Neither of the two really need the tracer_stack_context context manager + but to keep the code uniform and not break APIs, we use a + noop context manager for Tornado 6. + """ + + def __enter__(self): + pass + + def __exit__(self, *_): + pass diff --git a/tornado_opentracing/handlers.py b/tornado_opentracing/handlers.py index 4c55516..35b6e81 100644 --- a/tornado_opentracing/handlers.py +++ b/tornado_opentracing/handlers.py @@ -12,24 +12,31 @@ # See the License for the specific language governing permissions and # limitations under the License. -from tornado.web import HTTPError +from functools import wraps -from opentracing.scope_managers.tornado import tracer_stack_context +from tornado.web import HTTPError -def execute(func, handler, args, kwargs): +def wrap_method(handler, method_name): """ - Wrap the handler ``_execute`` method to trace incoming requests, - extracting the context from the headers, if available. + wrap_method takes a request handler instance and a method name (string) + and decorates the method to add automatic tracing. It starts a span + on every HTTP request (method call) and then calls the original method. """ - tracing = handler.settings.get('opentracing_tracing') + original = getattr(handler, method_name, None) + if original is None: + return - with tracer_stack_context(): - if tracing._trace_all: - attrs = handler.settings.get('opentracing_traced_attributes', []) - tracing._apply_tracing(handler, attrs) + @wraps(original) + def wrapper(self, *args, **kwargs): + tracing = self.settings.get('opentracing_tracing') + if tracing: + attrs = self.settings.get('opentracing_traced_attributes', []) + tracing._apply_tracing(self, attrs) + return original(*args, **kwargs) - return func(*args, **kwargs) + bound_wrapper = wrapper.__get__(handler, handler.__class__) + setattr(handler, method_name, bound_wrapper) def on_finish(func, handler, args, kwargs): diff --git a/tornado_opentracing/httpclient.py b/tornado_opentracing/httpclient.py index 3555837..de9c31b 100644 --- a/tornado_opentracing/httpclient.py +++ b/tornado_opentracing/httpclient.py @@ -100,7 +100,6 @@ def fetch_async(func, handler, args, kwargs): def _finish_tracing_callback(future, span): - status_code = None exc = future.exception() if exc: diff --git a/tornado_opentracing/initialization.py b/tornado_opentracing/initialization.py index a64d746..d2e1fb5 100644 --- a/tornado_opentracing/initialization.py +++ b/tornado_opentracing/initialization.py @@ -33,6 +33,29 @@ def init_client_tracing(tracer=None, start_span_cb=None): _patch_tornado_client(tracer, start_span_cb) +def _patch_handler_init(init, handler, args, kwargs): + """ + This function patches tornado request handlers init method + and then patches method that handle HTTP requests inside. + This happens dynamically every time a request handler instace + is created. This is needed as HTTP handler method do not exists + on request handlers by default and are supposed to be added + by users. + + TODO: check if patching __new__ would be better in any way. + """ + init(*args, **kwargs) + + tracing = handler.settings.get('opentracing_tracing') + if not tracing: + return + if not tracing._trace_all: + return + + for method in handler.SUPPORTED_METHODS: + handlers.wrap_method(handler, method.lower()) + + def _patch_tornado(): # patch only once if getattr(tornado, '__opentracing_patch', False) is True: @@ -43,8 +66,8 @@ def _patch_tornado(): wrap_function('tornado.web', 'Application.__init__', application.tracer_config) - wrap_function('tornado.web', 'RequestHandler._execute', - handlers.execute) + wrap_function('tornado.web', 'RequestHandler.__init__', + _patch_handler_init) wrap_function('tornado.web', 'RequestHandler.on_finish', handlers.on_finish) wrap_function('tornado.web', 'RequestHandler.log_exception', @@ -77,7 +100,7 @@ def _unpatch_tornado(): _unpatch(tornado.web.Application, '__init__') - _unpatch(tornado.web.RequestHandler, '_execute') + _unpatch(tornado.web.RequestHandler, '__init__') _unpatch(tornado.web.RequestHandler, 'on_finish') _unpatch(tornado.web.RequestHandler, 'log_exception') diff --git a/tornado_opentracing/scope_managers.py b/tornado_opentracing/scope_managers.py new file mode 100644 index 0000000..e073dc6 --- /dev/null +++ b/tornado_opentracing/scope_managers.py @@ -0,0 +1,18 @@ +import sys +from tornado import version_info as tornado_version + +# - For Tornado 5 and older, we continue to use the old TornadoScopeManager +# based on tornado.stack_context which was removed in Tornado6. +# - For Tornado 6 and newer, we use the ContextVarsScopeManager based on +# the new contextvars module introduced in Python3.7. +# - For Tornado 6 and newer running on Python 3.6 and older, we use the +# AsyncIOScopeManager which implements context propagation using a custom +# mechanism built on top of the asyncio module. + +if tornado_version >= (6, 0): + if sys.version_info >= (3, 7): + from opentracing.scope_managers.contextvars import ContextVarsScopeManager as ScopeManager # noqa + else: + from opentracing.scope_managers.asyncio import AsyncioScopeManager as ScopeManager # noqa +else: + from opentracing.scope_managers.tornado import TornadoScopeManager as ScopeManager # noqa diff --git a/tornado_opentracing/tracing.py b/tornado_opentracing/tracing.py index 95a597a..e09ce18 100644 --- a/tornado_opentracing/tracing.py +++ b/tornado_opentracing/tracing.py @@ -1,175 +1,15 @@ -# Copyright The OpenTracing Authors -# -# Licensed under the Apache License, Version 2.0 (the "License"); -# you may not use this file except in compliance with the License. -# You may obtain a copy of the License at -# -# http://www.apache.org/licenses/LICENSE-2.0 -# -# Unless required by applicable law or agreed to in writing, software -# distributed under the License is distributed on an "AS IS" BASIS, -# WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. -# See the License for the specific language governing permissions and -# limitations under the License. +import sys -import functools -import wrapt +from tornado import version_info as tornado_version -import opentracing -from opentracing.ext import tags -from opentracing.scope_managers.tornado import tracer_stack_context -from ._constants import SCOPE_ATTR +# Use asyncio compatible tracing when running tornado 5 or above +# on Python3.5 or above. Older version continue to use the +# old tornado tracing based on tornado.stack_context. +use_async_tracing = sys.version_info >= (3, 5) and tornado_version >= (5, 0) -class TornadoTracing(object): - """ - @param tracer the OpenTracing tracer to be used - to trace requests using this TornadoTracing - """ - def __init__(self, tracer=None, start_span_cb=None): - if start_span_cb is not None and not callable(start_span_cb): - raise ValueError('start_span_cb is not callable') - - self._tracer_obj = tracer - self._start_span_cb = start_span_cb - self._trace_all = False - self._trace_client = False - - @property - def _tracer(self): - """ - DEPRECATED - """ - return self.tracer - - @property - def tracer(self): - if self._tracer_obj is None: - return opentracing.tracer - - return self._tracer_obj - - def get_span(self, request): - """ - @param request - Returns the span tracing this request - """ - scope = getattr(request, SCOPE_ATTR, None) - return None if scope is None else scope.span - - def trace(self, *attributes): - """ - Function decorator that traces functions - NOTE: Must be placed before the Tornado decorators - @param attributes any number of request attributes - (strings) to be set as tags on the created span - """ - - @wrapt.decorator - 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 - - return wrapper - - def _get_operation_name(self, handler): - full_class_name = type(handler).__name__ - return full_class_name.rsplit('.')[-1] # package-less name. - - def _finish_tracing_callback(self, future, handler): - error = future.exception() - self._finish_tracing(handler, error=error) - - def _apply_tracing(self, handler, attributes): - """ - Helper function to avoid rewriting for middleware and decorator. - Returns a new span from the request with logged attributes and - correct operation name from the func. - """ - operation_name = self._get_operation_name(handler) - headers = handler.request.headers - request = handler.request - - # start new span from trace info - try: - span_ctx = self._tracer.extract(opentracing.Format.HTTP_HEADERS, - headers) - scope = self._tracer.start_active_span(operation_name, - child_of=span_ctx) - except (opentracing.InvalidCarrierException, - opentracing.SpanContextCorruptedException): - scope = self._tracer.start_active_span(operation_name) - - # add span to current spans - setattr(request, SCOPE_ATTR, scope) - - # log any traced attributes - scope.span.set_tag(tags.COMPONENT, 'tornado') - scope.span.set_tag(tags.SPAN_KIND, tags.SPAN_KIND_RPC_SERVER) - scope.span.set_tag(tags.HTTP_METHOD, request.method) - scope.span.set_tag(tags.HTTP_URL, request.uri) - - for attr in attributes: - if hasattr(request, attr): - payload = str(getattr(request, attr)) - if payload: - scope.span.set_tag(attr, payload) - - # invoke the start span callback, if any - self._call_start_span_cb(scope.span, request) - - return scope - - def _finish_tracing(self, handler, error=None): - scope = getattr(handler.request, SCOPE_ATTR, None) - if scope is None: - return - - delattr(handler.request, SCOPE_ATTR) - - if error is not None: - scope.span.set_tag(tags.ERROR, True) - scope.span.log_kv({ - 'event': tags.ERROR, - 'error.object': error, - }) - else: - scope.span.set_tag(tags.HTTP_STATUS_CODE, handler.get_status()) - - scope.close() - - def _call_start_span_cb(self, span, request): - if self._start_span_cb is None: - return - - try: - self._start_span_cb(span, request) - except Exception: - # TODO - log the error to the Span? - pass +if use_async_tracing: + from ._tracing_async import AsyncTornadoTracing as TornadoTracing # noqa +else: + from ._tracing import BaseTornadoTracing as TornadoTracing # noqa diff --git a/tox.ini b/tox.ini new file mode 100644 index 0000000..82f9b05 --- /dev/null +++ b/tox.ini @@ -0,0 +1,31 @@ +[tox] +envlist = + py{27,34}-tornado{4,5} + py{35,36,37,38}-tornado{4,5,6} + +[base] +basepython = + py27: python2.7 + py34: python3.4 + py35: python3.5 + py36: python3.6 + py37: python3.7 + py38: python3.8 +deps = + py: -rrequirements-test.txt + tornado4: tornado>=4.1,<5.0 + tornado5: tornado>=5.0,<6.0 + tornado6: tornado>=6.0,<7.0 + +[testenv] +whitelist_externals = pytest +commands = pytest --cov-append --cov-report term-missing:skip-covered --cov=tornado_opentracing + +# Run linter in py37 only +[testenv:py37] +whitelist_externals = + pytest + flake8 +commands_pre = flake8 tornado_opentracing tests +commands = pytest --cov-append --cov-report term-missing:skip-covered --cov=tornado_opentracing + \ No newline at end of file