Merge pull request #73 from DataDog/matt/reqs

requests: first pass at instrumenting requests

Author: clutchski

ddtrace/compat.py

@@ -19,6 +19,10 @@
     import http.client as httplib
     from io import StringIO
 
+try:
+    import urlparse
+except ImportError:
+    from urllib import parse as urlparse
 
 try:
     import simplejson as json
@@ -45,12 +49,13 @@ def to_unicode(s):
 
 
 __all__ = [
-    'PY2',
-    'urlencode',
     'httplib',
-    'stringify',
+    'iteritems',
+    'json',
+    'PY2',
     'Queue',
+    'stringify',
     'StringIO',
-    'json',
-    'iteritems'
+    'urlencode',
+    'urlparse',
 ]

ddtrace/contrib/autopatch.py

@@ -0,0 +1,43 @@
+"""
+the autopatch module will attempt to automatically monkeypatch
+all available contrib modules.
+
+It is currently experimental and incomplete.
+"""
+
+
+import logging
+import importlib
+
+
+log = logging.getLogger()
+
+
+# modules which are monkeypatch'able
+autopatch_modules = [
+    'requests',
+]
+
+
+def autopatch():
+    """ autopatch will attempt to patch all available contrib modules. """
+    for module in autopatch_modules:
+        path = 'ddtrace.contrib.%s' % module
+        patch_module(path)
+
+def patch_module(path):
+    """ patch_module will attempt to autopatch the module with the given
+        import path.
+    """
+    log.debug("attempting to patch %s", path)
+    imp = importlib.import_module(path)
+
+    func = getattr(imp, 'patch', None)
+    if func is None:
+        log.debug('no patch function in %s. skipping', path)
+        return False
+
+    log.debug("calling patch func %s in %s", func, path)
+    func()
+    log.debug("patched")
+    return True

ddtrace/contrib/requests/__init__.py

@@ -0,0 +1,28 @@
+"""
+To trace all HTTP calls from the requests library, patch the library like so::
+
+    # Patch the requests library.
+    from ddtrace.contrib.requests import patch
+    patch()
+
+    import requests
+    requests.get("http://www.datadog.com")
+
+If you would prefer finer grained control without monkeypatching the requests'
+code, use a TracedSession object as you would a requests.Session::
+
+    from ddtrace.contrib.requests import TracedSession
+
+    session = TracedSession()
+    session.get("http://www.datadog.com")
+"""
+
+
+from ..util import require_modules
+
+required_modules = ['requests']
+
+with require_modules(required_modules) as missing_modules:
+    if not missing_modules:
+        from .patch import TracedSession, patch
+        __all__ = ['TracedSession', 'patch']

ddtrace/contrib/requests/patch.py

@@ -0,0 +1,81 @@
+"""
+Tracing for the requests library.
+
+https://github.com/kennethreitz/requests
+"""
+
+# stdlib
+import logging
+
+# 3p
+import requests
+import wrapt
+
+# project
+import ddtrace
+from ddtrace.compat import urlparse
+from ddtrace.ext import http
+
+
+log = logging.getLogger(__name__)
+
+
+def patch():
+    """ Monkeypatch the requests library to trace http calls. """
+    wrapt.wrap_function_wrapper('requests', 'Session.request', _traced_request_func)
+
+
+def _traced_request_func(func, instance, args, kwargs):
+    """ traced_request is a tracing wrapper for requests' Session.request
+        instance method.
+    """
+
+    # perhaps a global tracer isn't what we want, so permit individual requests
+    # sessions to have their own (with the standard global fallback)
+    tracer = getattr(instance, 'datadog_tracer', ddtrace.tracer)
+
+    # bail on the tracing if not enabled.
+    if not tracer.enabled:
+        return func(*args, **kwargs)
+
+    method = kwargs.get('method') or args[0]
+    url = kwargs.get('url') or args[1]
+
+    with tracer.trace("requests.request", span_type=http.TYPE) as span:
+        resp = None
+        try:
+            resp = func(*args, **kwargs)
+            return resp
+        finally:
+            try:
+                _apply_tags(span, method, url, resp)
+            except Exception:
+                log.warn("error patching tags", exc_info=True)
+
+
+def _apply_tags(span, method, url, response):
+    """ apply_tags will patch the given span with tags about the given request. """
+    try:
+        parsed = urlparse.urlparse(url)
+        span.service = parsed.netloc
+        # FIXME[matt] how do we decide how do we normalize arbitrary urls???
+        path = parsed.path or "/"
+        span.resource = "%s %s" % (method.upper(), path)
+    except Exception:
+        pass
+
+    span.set_tag(http.METHOD, method)
+    span.set_tag(http.URL, url)
+    if response is not None:
+        span.set_tag(http.STATUS_CODE, response.status_code)
+        span.error = 500 <= response.status_code
+
+
+class TracedSession(requests.Session):
+    """ TracedSession is a requests' Session that is already patched.
+    """
+    pass
+
+# Always patch our traced session with the traced method (cheesy way of sharing
+# code)
+wrapt.wrap_function_wrapper(TracedSession, 'request', _traced_request_func)

ddtrace/ext/errors.py

@@ -9,6 +9,11 @@
 ERROR_TYPE = "error.type"   # a string representing the type of the error
 ERROR_STACK = "error.stack" # a human readable version of the stack. beta.
 
+# shorthand for -----^
+MSG = ERROR_MSG
+TYPE = ERROR_TYPE
+STACK = ERROR_STACK
+
 def get_traceback(tb=None, error=None):
     t = None
     if error:

tests/autopatch.py

@@ -0,0 +1,8 @@
+
+# manual test for autopatching
+import logging
+logging.basicConfig(level=logging.DEBUG)
+
+from ddtrace.contrib.autopatch import autopatch
+
+autopatch()

tests/contrib/requests/__init__.py

@@ -0,0 +1,145 @@
+
+# 3p
+from nose.tools import eq_, assert_raises
+from requests import Session
+
+# project
+from ddtrace.contrib.requests import TracedSession
+from ddtrace.ext import http, errors
+from tests.test_tracer import get_test_tracer
+
+
+class TestRequests(object):
+
+    @staticmethod
+    def test_resource_path():
+        tracer, session = get_traced_session()
+        out = session.get('http://httpstat.us/200')
+        eq_(out.status_code, 200)
+        spans = tracer.writer.pop()
+        eq_(len(spans), 1)
+        s = spans[0]
+        eq_(s.resource, 'GET /200')
+
+    @staticmethod
+    def test_resource_empty_path():
+        tracer, session = get_traced_session()
+        out = session.get('http://httpstat.us')
+        eq_(out.status_code, 200)
+        spans = tracer.writer.pop()
+        eq_(len(spans), 1)
+        s = spans[0]
+        eq_(s.resource, 'GET /')
+
+        out = session.get('http://httpstat.us/')
+        eq_(out.status_code, 200)
+        spans = tracer.writer.pop()
+        eq_(len(spans), 1)
+        s = spans[0]
+        eq_(s.resource, 'GET /')
+
+    @staticmethod
+    def test_tracer_disabled():
+        # ensure all valid combinations of args / kwargs work
+        tracer, session = get_traced_session()
+        tracer.enabled = False
+        out = session.get('http://httpstat.us/200')
+        eq_(out.status_code, 200)
+        spans = tracer.writer.pop()
+        eq_(len(spans), 0)
+
+    @staticmethod
+    def test_args_kwargs():
+        # ensure all valid combinations of args / kwargs work
+        tracer, session = get_traced_session()
+        url = 'http://httpstat.us/200'
+        method = 'GET'
+        inputs = [
+                ([], {'method': method, 'url': url}),
+                ([method], {'url': url}),
+                ([method, url], {}),
+        ]
+        untraced = Session()
+        for args, kwargs in inputs:
+            # ensure an untraced request works with these args
+            out = untraced.request(*args, **kwargs)
+            eq_(out.status_code, 200)
+            out = session.request(*args, **kwargs)
+            eq_(out.status_code, 200)
+            # validation
+            spans = tracer.writer.pop()
+            eq_(len(spans), 1)
+            s = spans[0]
+            eq_(s.get_tag(http.METHOD), 'GET')
+            eq_(s.get_tag(http.STATUS_CODE), '200')
+
+
+    @staticmethod
+    def test_200():
+        tracer, session = get_traced_session()
+        out = session.get('http://httpstat.us/200')
+        eq_(out.status_code, 200)
+        # validation
+        spans = tracer.writer.pop()
+        eq_(len(spans), 1)
+        s = spans[0]
+        eq_(s.get_tag(http.METHOD), 'GET')
+        eq_(s.get_tag(http.STATUS_CODE), '200')
+        eq_(s.error, 0)
+        eq_(s.service, 'httpstat.us')
+        eq_(s.span_type, http.TYPE)
+
+    @staticmethod
+    def test_post_500():
+        tracer, session = get_traced_session()
+        out = session.post('http://httpstat.us/500')
+        # validation
+        eq_(out.status_code, 500)
+        spans = tracer.writer.pop()
+        eq_(len(spans), 1)
+        s = spans[0]
+        eq_(s.get_tag(http.METHOD), 'POST')
+        eq_(s.get_tag(http.STATUS_CODE), '500')
+        eq_(s.error, 1)
+
+    @staticmethod
+    def test_non_existant_url():
+        tracer, session = get_traced_session()
+
+        try:
+            session.get('http://doesnotexist.google.com')
+        except Exception:
+            pass
+        else:
+            assert 0, "expected error"
+
+        spans = tracer.writer.pop()
+        eq_(len(spans), 1)
+        s = spans[0]
+        eq_(s.get_tag(http.METHOD), 'GET')
+        eq_(s.error, 1)
+        assert "Name or service not known" in s.get_tag(errors.MSG)
+        assert "Name or service not known" in s.get_tag(errors.STACK)
+        assert "Traceback (most recent call last)" in s.get_tag(errors.STACK)
+        assert "requests.exception" in s.get_tag(errors.TYPE)
+
+
+    @staticmethod
+    def test_500():
+        tracer, session = get_traced_session()
+        out = session.get('http://httpstat.us/500')
+        eq_(out.status_code, 500)
+
+        spans = tracer.writer.pop()
+        eq_(len(spans), 1)
+        s = spans[0]
+        eq_(s.get_tag(http.METHOD), 'GET')
+        eq_(s.get_tag(http.STATUS_CODE), '500')
+        eq_(s.error, 1)
+
+
+def get_traced_session():
+    tracer = get_test_tracer()
+    session = TracedSession()
+    setattr(session, 'datadog_tracer', tracer)
+    return tracer, session

tests/contrib/requests/test_requests.py

@@ -295,3 +295,7 @@ def pop_services(self):
         self.services = {}
         return s
 
+def get_test_tracer():
+    tracer = Tracer()
+    tracer.writer = DummyWriter()
+    return tracer

tests/test_tracer.py

@@ -18,6 +18,7 @@ envlist =
     {py27,py34}-mysqlconnector{21}
     {py27,py34}-pylibmc{140,150}
     {py27,py34}-pymongo{30,31,32,33}-mongoengine
+    {py27,py34}-requests{208,209,210,211}
     {py27,py34}-sqlalchemy{10,11}-psycopg2
     {py27,py34}-all
 
@@ -44,6 +45,7 @@ deps =
     all: pymongo
     all: python-memcached
     all: redis
+    all: requests
     all: sqlalchemy
     blinker: blinker
     elasticsearch23: elasticsearch>=2.3,<2.4
@@ -69,6 +71,11 @@ deps =
     pymongo33: pymongo>=3.3
     psycopg2: psycopg2
     redis: redis
+    requests200: requests>=2.0,<2.1
+    requests208: requests>=2.8,<2.9
+    requests209: requests>=2.9,<2.10
+    requests210: requests>=2.10,<2.11
+    requests211: requests>=2.11,<2.12
     sqlalchemy10: sqlalchemy>=1.0,<1.1
     sqlalchemy11: sqlalchemy==1.1.0b3
 
@@ -93,6 +100,7 @@ commands =
     {py27,py34}-pymongo{30,31,32,33}: nosetests {posargs} tests/contrib/pymongo/
     {py27,py34}-mongoengine: nosetests {posargs} tests/contrib/mongoengine
     {py27,py34}-psycopg2: nosetests {posargs} tests/contrib/psycopg
+    {py27,py34}-requests{200,208,209,210,211}: nosetests {posargs} tests/contrib/requests
     {py27,py34}-sqlalchemy{10,11}: nosetests {posargs} tests/contrib/sqlalchemy
 
 [testenv:wait]