From 463a7ca6549fde8dba9f6beecc2adec5df2aa70e Mon Sep 17 00:00:00 2001 From: Matt Perpick Date: Tue, 28 Jun 2016 18:02:45 +0000 Subject: [PATCH 01/15] add tags to span pprint --- ddtrace/span.py | 2 ++ 1 file changed, 2 insertions(+) diff --git a/ddtrace/span.py b/ddtrace/span.py index 0da43e25341..81d1d38c8ac 100644 --- a/ddtrace/span.py +++ b/ddtrace/span.py @@ -162,8 +162,10 @@ def pprint(self): ("end", "" if not self.duration else self.start + self.duration), ("duration", self.duration), ("error", self.error), + ("tags", "") ] + lines.extend((" ", "%s:%s" % kv) for kv in self.meta.items()) return "\n".join("%10s %s" % l for l in lines) def __enter__(self): From c0638fdae6253db37f3333e49743131fe654f44f Mon Sep 17 00:00:00 2001 From: Matt Perpick Date: Tue, 28 Jun 2016 18:03:12 +0000 Subject: [PATCH 02/15] add dev install command --- Rakefile | 5 +++++ 1 file changed, 5 insertions(+) diff --git a/Rakefile b/Rakefile index 6abfbe6824c..b198360fe1b 100644 --- a/Rakefile +++ b/Rakefile @@ -24,6 +24,11 @@ task :upload do sh "s3cmd put ddtrace-*.whl s3://pypi.datadoghq.com/" end +task :dev do + sh "pip uninstall ddtrace" + sh "pip install -e ." +end + task :ci => [:clean, :test, :build] task :release => [:ci, :upload] From 41b50730459cc41f844f12ad0d197b7af9e639ff Mon Sep 17 00:00:00 2001 From: Matt Perpick Date: Tue, 28 Jun 2016 18:03:43 +0000 Subject: [PATCH 03/15] django: add initial app --- ddtrace/contrib/django/__init__.py | 68 ++++++++++++++++++++++++++++++ 1 file changed, 68 insertions(+) create mode 100644 ddtrace/contrib/django/__init__.py diff --git a/ddtrace/contrib/django/__init__.py b/ddtrace/contrib/django/__init__.py new file mode 100644 index 00000000000..e137cc8b5bc --- /dev/null +++ b/ddtrace/contrib/django/__init__.py @@ -0,0 +1,68 @@ + + +import logging + +# project +from ... import tracer +from ...ext import http, errors + + +log = logging.getLogger(__name__) + + +class TraceMiddleware(object): + + def __init__(self): + # override if necessary (can't initialize though) + self.tracer = tracer + + def process_request(self, request): + try: + service = "django" # FIXME: app name + + span = self.tracer.trace( + "django.request", + service=service, + resource="request", # will be filled by process view + span_type=http.TYPE) + + span.set_tag(http.METHOD, request.method) + span.set_tag(http.URL, request.path) + _set_req_span(request, span) + except Exception: + log.exception("error tracing request") + + def process_view(self, request, view_func, *args, **kwargs): + span = _get_req_span(request) + if span: + span.resource = _view_func_name(view_func) + + def process_response(self, request, response): + try: + span = _get_req_span(request) + if span: + span.set_tag(http.STATUS_CODE, response.status_code) + span.finish() + except Exception: + log.exception("error tracing request") + finally: + return response + + def process_exception(self, request, exception): + try: + span = _get_req_span(request) + if span: + span.set_tag(http.STATUS_CODE, '500') + span.set_traceback() # will set the exception info + except Exception: + log.exception("error processing exception") + +def _view_func_name(view_func): + return "%s.%s" % (view_func.__module__, view_func.__name__) + +def _get_req_span(request): + return getattr(request, '_datadog_request_span', None) + +def _set_req_span(request, span): + return setattr(request, '_datadog_request_span', span) + From c9fea94f9291bf5c28cc5b8d62f181498bb14c87 Mon Sep 17 00:00:00 2001 From: Matt Perpick Date: Tue, 28 Jun 2016 20:03:34 +0000 Subject: [PATCH 04/15] django: time templates --- ddtrace/contrib/django/__init__.py | 37 +++++++++++++++++++++++++++--- 1 file changed, 34 insertions(+), 3 deletions(-) diff --git a/ddtrace/contrib/django/__init__.py b/ddtrace/contrib/django/__init__.py index e137cc8b5bc..283779ccf47 100644 --- a/ddtrace/contrib/django/__init__.py +++ b/ddtrace/contrib/django/__init__.py @@ -1,11 +1,16 @@ import logging +from types import MethodType + # project from ... import tracer from ...ext import http, errors +# 3p +from django.template import Template + log = logging.getLogger(__name__) @@ -15,14 +20,15 @@ class TraceMiddleware(object): def __init__(self): # override if necessary (can't initialize though) self.tracer = tracer + self.service = "django" + + _patch_template(self.tracer) def process_request(self, request): try: - service = "django" # FIXME: app name - span = self.tracer.trace( "django.request", - service=service, + service=self.service, resource="request", # will be filled by process view span_type=http.TYPE) @@ -57,6 +63,31 @@ def process_exception(self, request, exception): except Exception: log.exception("error processing exception") + +def _patch_template(tracer): + + log.debug("patching") + + attr = '_datadog_original_render' + + if getattr(Template, attr, None): + log.info("already patched") + return + + setattr(Template, attr, Template.render) + + class TracedTemplate(object): + + def render(self, context): + with tracer.trace('django.template', span_type=http.TEMPLATE) as span: + try: + return Template._datadog_original_render(self, context) + finally: + span.set_tag('django.template_name', context.template_name or 'unknown') + + Template.render = TracedTemplate.render.__func__ + + def _view_func_name(view_func): return "%s.%s" % (view_func.__module__, view_func.__name__) From 215e14bad7baaca1e589e17af326d3f70c31a5bd Mon Sep 17 00:00:00 2001 From: Matt Perpick Date: Tue, 28 Jun 2016 20:24:03 +0000 Subject: [PATCH 05/15] django: template cleanups --- ddtrace/contrib/__init__.py | 5 +++++ ddtrace/contrib/django/__init__.py | 21 ++++++++++++--------- 2 files changed, 17 insertions(+), 9 deletions(-) diff --git a/ddtrace/contrib/__init__.py b/ddtrace/contrib/__init__.py index e69de29bb2d..ad455755aad 100644 --- a/ddtrace/contrib/__init__.py +++ b/ddtrace/contrib/__init__.py @@ -0,0 +1,5 @@ + + +def func_name(f): + """ Return a human readable version of the function's name. """ + return "%s.%s" % (f.__module__, f.__name__) diff --git a/ddtrace/contrib/django/__init__.py b/ddtrace/contrib/django/__init__.py index 283779ccf47..a7f62f02130 100644 --- a/ddtrace/contrib/django/__init__.py +++ b/ddtrace/contrib/django/__init__.py @@ -7,6 +7,7 @@ # project from ... import tracer from ...ext import http, errors +from ...contrib import func_name # 3p from django.template import Template @@ -22,7 +23,10 @@ def __init__(self): self.tracer = tracer self.service = "django" - _patch_template(self.tracer) + try: + _patch_template(self.tracer) + except Exception: + log.exception("error patching template class") def process_request(self, request): try: @@ -41,7 +45,7 @@ def process_request(self, request): def process_view(self, request, view_func, *args, **kwargs): span = _get_req_span(request) if span: - span.resource = _view_func_name(view_func) + span.resource = func_name(view_func) def process_response(self, request, response): try: @@ -65,13 +69,15 @@ def process_exception(self, request, exception): def _patch_template(tracer): + """ will patch the django template render function to include information. + """ - log.debug("patching") - + # FIXME[matt] we're patching the template class here. ideally we'd only + # patch so we can use multiple tracers at once, but i suspect this is fine + # in practice. attr = '_datadog_original_render' - if getattr(Template, attr, None): - log.info("already patched") + log.debug("already patched") return setattr(Template, attr, Template.render) @@ -88,9 +94,6 @@ def render(self, context): Template.render = TracedTemplate.render.__func__ -def _view_func_name(view_func): - return "%s.%s" % (view_func.__module__, view_func.__name__) - def _get_req_span(request): return getattr(request, '_datadog_request_span', None) From 644bc967cfafe1c68c9c89c8bb3dc66e08c8091d Mon Sep 17 00:00:00 2001 From: Matt Perpick Date: Tue, 28 Jun 2016 21:41:40 +0000 Subject: [PATCH 06/15] django tests --- setup.py | 1 + 1 file changed, 1 insertion(+) diff --git a/setup.py b/setup.py index fffe6e20aa1..164dceeed1d 100644 --- a/setup.py +++ b/setup.py @@ -6,6 +6,7 @@ 'blinker', 'elasticsearch', 'psycopg2', + 'django' ] setup( From 500bd8de38ff46bfac24f958c988f371f7a10e66 Mon Sep 17 00:00:00 2001 From: Matt Perpick Date: Wed, 29 Jun 2016 17:34:19 +0000 Subject: [PATCH 07/15] django: add user information --- ddtrace/contrib/django/__init__.py | 30 +++++++++++++++++++++++++++++- 1 file changed, 29 insertions(+), 1 deletion(-) diff --git a/ddtrace/contrib/django/__init__.py b/ddtrace/contrib/django/__init__.py index a7f62f02130..442f0e6a7c3 100644 --- a/ddtrace/contrib/django/__init__.py +++ b/ddtrace/contrib/django/__init__.py @@ -11,6 +11,7 @@ # 3p from django.template import Template +from django.apps import apps log = logging.getLogger(__name__) @@ -52,7 +53,12 @@ def process_response(self, request, response): span = _get_req_span(request) if span: span.set_tag(http.STATUS_CODE, response.status_code) + + if apps.is_installed("django.contrib.auth"): + span = _set_auth_tags(span, request) + span.finish() + except Exception: log.exception("error tracing request") finally: @@ -93,10 +99,32 @@ def render(self, context): Template.render = TracedTemplate.render.__func__ - def _get_req_span(request): + """ Return the datadog span from the given request. """ return getattr(request, '_datadog_request_span', None) def _set_req_span(request, span): + """ Set the datadog span on the given request. """ return setattr(request, '_datadog_request_span', span) + +def _set_auth_tags(span, request): + """ Patch any available auth tags from the request onto the span. """ + user = getattr(request, 'user', None) + if not user: + return + + if hasattr(user, 'is_authenticated'): + span.set_tag('django.user.is_authenticated', user.is_authenticated()) + + uid = getattr(user, 'pk', None) + if uid: + span.set_tag('django.user.id', uid) + + uname = getattr(user, 'username', None) + if uname: + span.set_tag('django.user.name', uname) + + return span + + From b1ba6afecac4f957d3cf4455df7e5ec020332218 Mon Sep 17 00:00:00 2001 From: Matt Perpick Date: Wed, 29 Jun 2016 18:18:17 +0000 Subject: [PATCH 08/15] django: split templates --- ddtrace/contrib/django/__init__.py | 28 ++------------------- ddtrace/contrib/django/templates.py | 39 +++++++++++++++++++++++++++++ 2 files changed, 41 insertions(+), 26 deletions(-) create mode 100644 ddtrace/contrib/django/templates.py diff --git a/ddtrace/contrib/django/__init__.py b/ddtrace/contrib/django/__init__.py index 442f0e6a7c3..58cc2888d61 100644 --- a/ddtrace/contrib/django/__init__.py +++ b/ddtrace/contrib/django/__init__.py @@ -8,9 +8,9 @@ from ... import tracer from ...ext import http, errors from ...contrib import func_name +from .templates import patch_template # 3p -from django.template import Template from django.apps import apps @@ -25,7 +25,7 @@ def __init__(self): self.service = "django" try: - _patch_template(self.tracer) + patch_template(self.tracer) except Exception: log.exception("error patching template class") @@ -74,30 +74,6 @@ def process_exception(self, request, exception): log.exception("error processing exception") -def _patch_template(tracer): - """ will patch the django template render function to include information. - """ - - # FIXME[matt] we're patching the template class here. ideally we'd only - # patch so we can use multiple tracers at once, but i suspect this is fine - # in practice. - attr = '_datadog_original_render' - if getattr(Template, attr, None): - log.debug("already patched") - return - - setattr(Template, attr, Template.render) - - class TracedTemplate(object): - - def render(self, context): - with tracer.trace('django.template', span_type=http.TEMPLATE) as span: - try: - return Template._datadog_original_render(self, context) - finally: - span.set_tag('django.template_name', context.template_name or 'unknown') - - Template.render = TracedTemplate.render.__func__ def _get_req_span(request): """ Return the datadog span from the given request. """ diff --git a/ddtrace/contrib/django/templates.py b/ddtrace/contrib/django/templates.py new file mode 100644 index 00000000000..6c00b3f117d --- /dev/null +++ b/ddtrace/contrib/django/templates.py @@ -0,0 +1,39 @@ + +# stdlib +import logging + +# project +from ...ext import http, errors + +# 3p +from django.template import Template + + +log = logging.getLogger(__name__) + + +def patch_template(tracer): + """ will patch the django template render function to include information. + """ + + # FIXME[matt] we're patching the template class here. ideally we'd only + # patch so we can use multiple tracers at once, but i suspect this is fine + # in practice. + attr = '_datadog_original_render' + if getattr(Template, attr, None): + log.debug("already patched") + return + + setattr(Template, attr, Template.render) + + class TracedTemplate(object): + + def render(self, context): + with tracer.trace('django.template', span_type=http.TEMPLATE) as span: + try: + return Template._datadog_original_render(self, context) + finally: + span.set_tag('django.template_name', context.template_name or 'unknown') + + Template.render = TracedTemplate.render.__func__ + From 2e7c66372420ebbcb59c056504377f9b7ea080b8 Mon Sep 17 00:00:00 2001 From: Matt Perpick Date: Wed, 29 Jun 2016 18:19:17 +0000 Subject: [PATCH 09/15] django: template comments --- ddtrace/contrib/django/templates.py | 7 ++++++- 1 file changed, 6 insertions(+), 1 deletion(-) diff --git a/ddtrace/contrib/django/templates.py b/ddtrace/contrib/django/templates.py index 6c00b3f117d..aeeea4eba56 100644 --- a/ddtrace/contrib/django/templates.py +++ b/ddtrace/contrib/django/templates.py @@ -1,3 +1,7 @@ +""" +code to measure django template rendering. +""" + # stdlib import logging @@ -13,7 +17,8 @@ def patch_template(tracer): - """ will patch the django template render function to include information. + """ will patch django's template rendering function to include timing + and trace information. """ # FIXME[matt] we're patching the template class here. ideally we'd only From 659adffb326f1e84f74f7c9186f294af05ee5f48 Mon Sep 17 00:00:00 2001 From: Matt Perpick Date: Wed, 29 Jun 2016 19:35:44 +0000 Subject: [PATCH 10/15] trace/django: wrap cursors --- ddtrace/contrib/django/__init__.py | 2 + ddtrace/contrib/django/db.py | 68 ++++++++++++++++++++++++++++++ 2 files changed, 70 insertions(+) create mode 100644 ddtrace/contrib/django/db.py diff --git a/ddtrace/contrib/django/__init__.py b/ddtrace/contrib/django/__init__.py index 58cc2888d61..7708fdcaa60 100644 --- a/ddtrace/contrib/django/__init__.py +++ b/ddtrace/contrib/django/__init__.py @@ -9,6 +9,7 @@ from ...ext import http, errors from ...contrib import func_name from .templates import patch_template +from .db import patch_db # 3p from django.apps import apps @@ -26,6 +27,7 @@ def __init__(self): try: patch_template(self.tracer) + patch_db(self.tracer) except Exception: log.exception("error patching template class") diff --git a/ddtrace/contrib/django/db.py b/ddtrace/contrib/django/db.py new file mode 100644 index 00000000000..2216ef3efa2 --- /dev/null +++ b/ddtrace/contrib/django/db.py @@ -0,0 +1,68 @@ + +import logging + +from django.db import connections + +# project +from ...ext import sql as sqlx + + +log = logging.getLogger(__name__) + + +def patch_db(tracer): + for c in connections.all(): + patch_conn(tracer, c) + +def patch_conn(tracer, conn): + attr = '_datadog_original_cursor' + + if hasattr(conn, attr): + log.debug("already patched") + return + + conn._datadog_original_cursor = conn.cursor + def cursor(): + return TracedCursor(tracer, conn, conn._datadog_original_cursor()) + conn.cursor = cursor + + +class TracedCursor(object): + + def __init__(self, tracer, conn, cursor): + self.tracer = tracer + self.conn = conn + self.cursor = cursor + + self._prefix = conn.vendor or "db" # e.g sqlite, postgres, etc. + self._name = "%s.%s" % (self._prefix, "query") # e.g sqlite.query + self._service = "%s%s" % (conn.alias or self._prefix, "db") # e.g. defaultdb or postgresdb + + def _trace(self, func, sql, params): + with self.tracer.trace(self._name, service=self._service, span_type=sqlx.TYPE) as span: + span.set_tag(sqlx.QUERY, sql) + return func(sql, params) + + def callproc(self, procname, params=None): + return self._trace(self.cursor.callproc, procname, params) + + def execute(self, sql, params=None): + return self._trace(self.cursor.execute, sql, params) + + def executemany(self, sql, param_list): + return self._trace(self.cursor.executemany, sql, param_list) + + def close(self): + return self.cursor.close() + + def __getattr__(self, attr): + return getattr(self.cursor, attr) + + def __iter__(self): + return iter(self.cursor) + + def __enter__(self): + return self + + def __exit__(self, type, value, traceback): + self.close() From 5b0763365bd87c225fbeb74edf41010e5276be4c Mon Sep 17 00:00:00 2001 From: Matt Perpick Date: Wed, 29 Jun 2016 19:52:44 +0000 Subject: [PATCH 11/15] more db work --- ddtrace/contrib/django/db.py | 21 ++++++++++++++++++--- 1 file changed, 18 insertions(+), 3 deletions(-) diff --git a/ddtrace/contrib/django/db.py b/ddtrace/contrib/django/db.py index 2216ef3efa2..f88f87b54bb 100644 --- a/ddtrace/contrib/django/db.py +++ b/ddtrace/contrib/django/db.py @@ -34,13 +34,19 @@ def __init__(self, tracer, conn, cursor): self.conn = conn self.cursor = cursor - self._prefix = conn.vendor or "db" # e.g sqlite, postgres, etc. - self._name = "%s.%s" % (self._prefix, "query") # e.g sqlite.query - self._service = "%s%s" % (conn.alias or self._prefix, "db") # e.g. defaultdb or postgresdb + self._vendor = getattr(conn, 'vendor', 'db') # e.g sqlite, postgres + self._alias = getattr(conn, 'alias', 'default') # e.g. default, users + + prefix = _vendor_to_prefix(self._vendor) + self._name = "%s.%s" % (prefix, "query") # e.g sqlite3.query + self._service = "%s%s" % (self._alias or prefix, "db") # e.g. defaultdb or postgresdb def _trace(self, func, sql, params): with self.tracer.trace(self._name, service=self._service, span_type=sqlx.TYPE) as span: span.set_tag(sqlx.QUERY, sql) + span.set_tag("django.db.vendor", self._vendor) + span.set_tag("django.db.alias", self._alias) + return func(sql, params) def callproc(self, procname, params=None): @@ -66,3 +72,12 @@ def __enter__(self): def __exit__(self, type, value, traceback): self.close() + + +def _vendor_to_prefix(vendor): + if not vendor: + return "db" # should this ever happen? + elif vendor == "sqlite": + return "sqlite3" # for consitency with the sqlite3 integration + else: + return vendor From 49c565f111e92fc2d08d573cad9b713bf35a6ac4 Mon Sep 17 00:00:00 2001 From: Matt Perpick Date: Wed, 29 Jun 2016 20:12:46 +0000 Subject: [PATCH 12/15] django: add row count --- ddtrace/contrib/django/db.py | 8 ++++++-- ddtrace/ext/sql.py | 3 ++- 2 files changed, 8 insertions(+), 3 deletions(-) diff --git a/ddtrace/contrib/django/db.py b/ddtrace/contrib/django/db.py index f88f87b54bb..73fc4dfeda9 100644 --- a/ddtrace/contrib/django/db.py +++ b/ddtrace/contrib/django/db.py @@ -46,8 +46,12 @@ def _trace(self, func, sql, params): span.set_tag(sqlx.QUERY, sql) span.set_tag("django.db.vendor", self._vendor) span.set_tag("django.db.alias", self._alias) - - return func(sql, params) + try: + return func(sql, params) + finally: + rows = self.cursor.cursor.rowcount + if rows and 0 <= rows: + span.set_tag(sqlx.ROWS, self.cursor.cursor.rowcount) def callproc(self, procname, params=None): return self._trace(self.cursor.callproc, procname, params) diff --git a/ddtrace/ext/sql.py b/ddtrace/ext/sql.py index e1e8adbcb70..36d2d07b08c 100644 --- a/ddtrace/ext/sql.py +++ b/ddtrace/ext/sql.py @@ -3,4 +3,5 @@ TYPE = "sql" # tags -QUERY = "sql.query" +QUERY = "sql.query" # the query text +ROWS = "sql.rows" # number of rows returned by a query From 34f3f8bd4f3af7d0362dcf2275f36a9ab7d031b8 Mon Sep 17 00:00:00 2001 From: Matt Perpick Date: Thu, 30 Jun 2016 19:20:41 +0000 Subject: [PATCH 13/15] django: set the sql resource --- ddtrace/contrib/django/db.py | 3 +-- 1 file changed, 1 insertion(+), 2 deletions(-) diff --git a/ddtrace/contrib/django/db.py b/ddtrace/contrib/django/db.py index 73fc4dfeda9..60f4880ac36 100644 --- a/ddtrace/contrib/django/db.py +++ b/ddtrace/contrib/django/db.py @@ -16,7 +16,6 @@ def patch_db(tracer): def patch_conn(tracer, conn): attr = '_datadog_original_cursor' - if hasattr(conn, attr): log.debug("already patched") return @@ -42,7 +41,7 @@ def __init__(self, tracer, conn, cursor): self._service = "%s%s" % (self._alias or prefix, "db") # e.g. defaultdb or postgresdb def _trace(self, func, sql, params): - with self.tracer.trace(self._name, service=self._service, span_type=sqlx.TYPE) as span: + with self.tracer.trace(self._name, resource=sql, service=self._service, span_type=sqlx.TYPE) as span: span.set_tag(sqlx.QUERY, sql) span.set_tag("django.db.vendor", self._vendor) span.set_tag("django.db.alias", self._alias) From b6e45c4ac9c5ad45e104828aa92792a7704186ef Mon Sep 17 00:00:00 2001 From: Matt Perpick Date: Thu, 30 Jun 2016 19:21:03 +0000 Subject: [PATCH 14/15] django: patch db's on every request postgres (at least) will reconnect on every request so this needs to be verified each time --- ddtrace/contrib/django/__init__.py | 3 ++- 1 file changed, 2 insertions(+), 1 deletion(-) diff --git a/ddtrace/contrib/django/__init__.py b/ddtrace/contrib/django/__init__.py index 7708fdcaa60..2e00b3ca883 100644 --- a/ddtrace/contrib/django/__init__.py +++ b/ddtrace/contrib/django/__init__.py @@ -27,12 +27,13 @@ def __init__(self): try: patch_template(self.tracer) - patch_db(self.tracer) except Exception: log.exception("error patching template class") def process_request(self, request): try: + patch_db(self.tracer) # ensure that connections are always patched. + span = self.tracer.trace( "django.request", service=self.service, From aab5f312bce2b6a0ad4f2ebeec4b916db298dcca Mon Sep 17 00:00:00 2001 From: Matt Perpick Date: Thu, 30 Jun 2016 19:21:40 +0000 Subject: [PATCH 15/15] django: url = unknown until we know it so that 404s look good. --- ddtrace/contrib/django/__init__.py | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/ddtrace/contrib/django/__init__.py b/ddtrace/contrib/django/__init__.py index 2e00b3ca883..2550bb8e40f 100644 --- a/ddtrace/contrib/django/__init__.py +++ b/ddtrace/contrib/django/__init__.py @@ -37,7 +37,7 @@ def process_request(self, request): span = self.tracer.trace( "django.request", service=self.service, - resource="request", # will be filled by process view + resource="unknown", # will be filled by process view span_type=http.TYPE) span.set_tag(http.METHOD, request.method)