Repository: scoutapp/scout_apm_python
Pull request #171 (2019-05-03 08:29:48)

Test tracked requests and fix username tracking on Django < 1.10
Split from #167.

The `tracked_requests` fixture intercepts all the requests that would go into `RequestBuffer` so assertions can be made on them.

Adding these assertions has revealed a number of bugs, only some of which I'm fixing here:
* Repeated spans - the middleware seems is re-installed repeatedly in tests, but it doesn't uninstall itself, so the instruments were installed on top of each other a lot. I've fixed this for now by making the installs idempotent, like the middleware, but long term will be making the django app only get installed once during tests.
* Username tracking wasn't implemented in the old Django middleware
* The test to disable monitoring doesn't really disable it because Scout is fully installed by the time the test runs. Some refactoring is needed here.

adamchainz: Tests are failing because of Django 1.11 differences around what's getting tracked, needs some more investigation I think

Patch:
diff --git a/CHANGELOG.md b/CHANGELOG.md
index 921940d..ce539cf 100644
--- a/CHANGELOG.md
+++ b/CHANGELOG.md
@@ -6,6 +6,7 @@
 
 - Tested on Django 2.2
 - Added PyPI Trove classifiers for supported Django versions
+- Track usernames on Django < 1.10
 
 ### Fixed
 
diff --git a/src/scout_apm/django/instruments/sql.py b/src/scout_apm/django/instruments/sql.py
index 2048822..643b0ca 100644
--- a/src/scout_apm/django/instruments/sql.py
+++ b/src/scout_apm/django/instruments/sql.py
@@ -49,6 +49,8 @@ class _DetailedTracingCursorWrapper(CursorWrapper):
 
 
 class SQLInstrument(object):
+    installed = False
+
     @staticmethod
     def install():
         """
@@ -56,6 +58,9 @@ class SQLInstrument(object):
         method of BaseDatabaseWrapper, to return a wrapper that instruments any
         calls going through it.
         """
+        if SQLInstrument.installed:
+            return
+        SQLInstrument.installed = True
 
         @monkeypatch_method(BaseDatabaseWrapper)
         def cursor(original, self, *args, **kwargs):
diff --git a/src/scout_apm/django/instruments/template.py b/src/scout_apm/django/instruments/template.py
index b19dd0e..544c248 100644
--- a/src/scout_apm/django/instruments/template.py
+++ b/src/scout_apm/django/instruments/template.py
@@ -47,6 +47,8 @@ def load(parser, token):  # pragma: no cover
 
 
 class TemplateInstrument(object):
+    installed = False
+
     @staticmethod
     def install():
         # Our eventual aim is to patch the render() method on the Node objects
@@ -70,6 +72,9 @@ class TemplateInstrument(object):
 
         # XXX: Stopped working in Django 1.9
         #  add_to_builtins('apm.instruments.view')
+        if TemplateInstrument.installed:
+            return
+        TemplateInstrument.installed = True
 
         @trace_method(Template)
         def __init__(self, *args, **kwargs):
diff --git a/src/scout_apm/django/middleware.py b/src/scout_apm/django/middleware.py
index 3ec9871..bd9537b 100644
--- a/src/scout_apm/django/middleware.py
+++ b/src/scout_apm/django/middleware.py
@@ -133,6 +133,12 @@ class OldStyleViewMiddleware(object):
         # if we're matched up when stopping
         request.scout_view_span = span
 
+        try:
+            if getattr(request, "user", None) is not None:
+                Context.add("username", request.user.get_username())
+        except Exception:
+            pass
+
         return None
 
     # Process Response could be called without ever having called process_view.


Test patch:
diff --git a/tests/conftest.py b/tests/conftest.py
index c44846c..c162b11 100644
--- a/tests/conftest.py
+++ b/tests/conftest.py
@@ -4,8 +4,15 @@ import pytest
 
 from scout_apm.core import socket as scout_apm_core_socket
 from scout_apm.core.config import SCOUT_PYTHON_VALUES
+from scout_apm.core.request_manager import RequestBuffer
 from scout_apm.core.tracked_request import TrackedRequest
 
+try:
+    from unittest import mock
+except ImportError:
+    # Python 2
+    import mock
+
 # Env variables have precedence over Python configs in ScoutConfig.
 # Unset all Scout env variables to prevent interference with tests.
 
@@ -108,3 +115,21 @@ def short_timeouts():
         yield
     finally:
         scout_apm_core_socket.SECOND = 1
+
+
+@pytest.fixture
+def tracked_requests():
+    """
+    Gather all TrackedRequests that are buffered during a test into a list.
+    """
+    requests = []
+    orig_flush_request = RequestBuffer.flush_request
+
+    def wrapped_flush_request(self, request):
+        requests.append(request)
+        return orig_flush_request(self, request)
+
+    RequestBuffer.flush_request = wrapped_flush_request
+
+    with mock.patch.object(RequestBuffer, "flush_request", wrapped_flush_request):
+        yield requests
diff --git a/tests/integration/test_django.py b/tests/integration/test_django.py
index 99a3665..224024e 100644
--- a/tests/integration/test_django.py
+++ b/tests/integration/test_django.py
@@ -80,95 +80,175 @@ def finish_tracked_request_if_old_style_middlware():
             TrackedRequest.instance().finish()
 
 
-def test_home():
+def test_home(tracked_requests):
     with app_with_scout() as app:
         response = TestApp(app).get("/")
         assert response.status_int == 200
 
+    assert len(tracked_requests) == 1
+    spans = tracked_requests[0].complete_spans
+    assert [s.operation for s in spans] == [
+        "Controller/tests.integration.django_app.home",
+        "Middleware",
+    ]
+
 
 # During the transition between old-style and new-style middleware, Django
 # defaults to the old style. Also test with the new style in that case.
 @skip_unless_new_style_middleware
 @skip_unless_old_style_middleware
-def test_home_new_style():
+def test_home_new_style(tracked_requests):
     with override_settings(MIDDLEWARE=[]):
-        test_home()
+        test_home(tracked_requests)
 
 
-def test_hello():
+def test_hello(tracked_requests):
     with app_with_scout() as app:
         response = TestApp(app).get("/hello/")
         assert response.status_int == 200
 
+    assert len(tracked_requests) == 1
+    spans = tracked_requests[0].complete_spans
+    assert [s.operation for s in spans] == [
+        "Controller/tests.integration.django_app.hello",
+        "Middleware",
+    ]
+
 
 # During the transition between old-style and new-style middleware, Django
 # defaults to the old style. Also test with the new style in that case.
 @skip_unless_new_style_middleware
 @skip_unless_old_style_middleware
-def test_hello_new_style():
+def test_hello_new_style(tracked_requests):
     with override_settings(MIDDLEWARE=[]):
-        test_hello()
+        test_hello(tracked_requests)
 
 
-def test_not_found():
+def test_not_found(tracked_requests):
     with app_with_scout() as app:
         response = TestApp(app).get("/not-found/", expect_errors=True)
         assert response.status_int == 404
 
+    if django.VERSION < (1, 10) or settings.MIDDLEWARE is None:
+        # Old style middleware doesn't currently pick up 404's
+        assert len(tracked_requests) == 0
+    else:
+        assert len(tracked_requests) == 1
+        spans = tracked_requests[0].complete_spans
+        assert [s.operation for s in spans] == [
+            "Template/Compile/<Unknown Template>",
+            "Template/Render/<Unknown Template>",
+            "Unknown",
+            "Middleware",
+        ]
+
 
 # During the transition between old-style and new-style middleware, Django
 # defaults to the old style. Also test with the new style in that case.
 @skip_unless_new_style_middleware
 @skip_unless_old_style_middleware
-def test_not_found_new_style():
+def test_not_found_new_style(tracked_requests):
     with override_settings(MIDDLEWARE=[]):
-        test_not_found()
+        test_not_found(tracked_requests)
 
 
-def test_server_error():
+def test_server_error(tracked_requests):
     with app_with_scout() as app:
         response = TestApp(app).get("/crash/", expect_errors=True)
         assert response.status_int == 500
 
+    assert len(tracked_requests) == 1
+    spans = tracked_requests[0].complete_spans
+    # Different processing order on old-style middleware
+    if django.VERSION < (1, 10) or settings.MIDDLEWARE is None:
+        expected = [
+            "Controller/tests.integration.django_app.crash",
+            "Template/Compile/<Unknown Template>",
+            "Template/Render/<Unknown Template>",
+            "Middleware",
+        ]
+    else:
+        expected = [
+            "Template/Compile/<Unknown Template>",
+            "Template/Render/<Unknown Template>",
+            "Controller/tests.integration.django_app.crash",
+            "Middleware",
+        ]
+    assert [s.operation for s in spans] == expected
+
 
 # During the transition between old-style and new-style middleware, Django
 # defaults to the old style. Also test with the new style in that case.
 @skip_unless_new_style_middleware
 @skip_unless_old_style_middleware
-def test_server_error_new_style():
+def test_server_error_new_style(tracked_requests):
     with override_settings(MIDDLEWARE=[]):
-        test_server_error()
+        test_server_error(tracked_requests)
 
 
-def test_sql():
+def test_sql(tracked_requests):
     with app_with_scout() as app:
         response = TestApp(app).get("/sql/")
         assert response.status_int == 200
 
+    assert len(tracked_requests) == 1
+    spans = tracked_requests[0].complete_spans
+    assert [s.operation for s in spans] == [
+        "SQL/Query",
+        "SQL/Many",
+        "SQL/Query",
+        "Controller/tests.integration.django_app.sql",
+        "Middleware",
+    ]
+
 
 # Monkey patch should_capture_backtrace in order to keep the test fast.
 @patch(
     "scout_apm.core.n_plus_one_call_set.NPlusOneCallSetItem.should_capture_backtrace"
 )
-def test_sql_capture_backtrace(should_capture_backtrace):
+def test_sql_capture_backtrace(should_capture_backtrace, tracked_requests):
     should_capture_backtrace.return_value = True
     with app_with_scout() as app:
         response = TestApp(app).get("/sql/")
         assert response.status_int == 200
 
+    assert len(tracked_requests) == 1
+    spans = tracked_requests[0].complete_spans
+    assert [s.operation for s in spans] == [
+        "SQL/Query",
+        "SQL/Many",
+        "SQL/Query",
+        "Controller/tests.integration.django_app.sql",
+        "Middleware",
+    ]
+
 
-def test_template():
+def test_template(tracked_requests):
     with app_with_scout() as app:
         response = TestApp(app).get("/template/")
         assert response.status_int == 200
 
+    assert len(tracked_requests) == 1
+    spans = tracked_requests[0].complete_spans
+    print([s.operation for s in spans])
+    assert [s.operation for s in spans] == [
+        "Template/Compile/<Unknown Template>",
+        "Block/Render/name",
+        "Template/Render/<Unknown Template>",
+        "Controller/tests.integration.django_app.template",
+        "Middleware",
+    ]
 
-def test_no_monitor():
+
+@pytest.mark.xfail(reason="Test setup doesn't reset state fully at the moment.")
+def test_no_monitor(tracked_requests):
     # With an empty config, "scout.monitor" defaults to "false".
     with app_with_scout({}) as app:
         response = TestApp(app).get("/hello/")
         assert response.status_int == 200
 
+    assert len(tracked_requests) == 0
+
 
 def fake_authentication_middleware(get_response):
     def middleware(request):
@@ -181,12 +261,16 @@ def fake_authentication_middleware(get_response):
 
 
 @skip_unless_new_style_middleware
-def test_username():
+def test_username(tracked_requests):
     with override_settings(MIDDLEWARE=[__name__ + ".fake_authentication_middleware"]):
         with app_with_scout() as app:
             response = TestApp(app).get("/hello/")
             assert response.status_int == 200
 
+    assert len(tracked_requests) == 1
+    tr = tracked_requests[0]
+    assert tr.tags["username"] == "scout"
+
 
 def crashy_authentication_middleware(get_response):
     def middleware(request):
@@ -199,12 +283,16 @@ def crashy_authentication_middleware(get_response):
 
 
 @skip_unless_new_style_middleware
-def test_username_exception():
+def test_username_exception(tracked_requests):
     with override_settings(MIDDLEWARE=[__name__ + ".crashy_authentication_middleware"]):
         with app_with_scout() as app:
             response = TestApp(app).get("/hello/")
             assert response.status_int == 200
 
+    assert len(tracked_requests) == 1
+    tr = tracked_requests[0]
+    assert "username" not in tr.tags
+
 
 class FakeAuthenticationMiddleware(object):
     def process_request(self, request):
@@ -214,7 +302,7 @@ class FakeAuthenticationMiddleware(object):
 
 
 @skip_unless_old_style_middleware
-def test_old_style_username():
+def test_old_style_username(tracked_requests):
     with override_settings(
         MIDDLEWARE_CLASSES=[__name__ + ".FakeAuthenticationMiddleware"]
     ):
@@ -222,6 +310,11 @@ def test_old_style_username():
             response = TestApp(app).get("/hello/")
             assert response.status_int == 200
 
+    assert len(tracked_requests) == 1
+    tr = tracked_requests[0]
+    print(tr.tags)
+    assert tr.tags["username"] == "scout"
+
 
 class CrashyAuthenticationMiddleware(object):
     def process_request(self, request):
@@ -231,7 +324,7 @@ class CrashyAuthenticationMiddleware(object):
 
 
 @skip_unless_old_style_middleware
-def test_old_style_username_exception():
+def test_old_style_username_exception(tracked_requests):
     with override_settings(
         MIDDLEWARE_CLASSES=[__name__ + ".CrashyAuthenticationMiddleware"]
     ):
@@ -239,6 +332,10 @@ def test_old_style_username_exception():
             response = TestApp(app).get("/hello/")
             assert response.status_int == 200
 
+    assert len(tracked_requests) == 1
+    tr = tracked_requests[0]
+    assert "username" not in tr.tags
+
 
 @pytest.mark.parametrize("list_or_tuple", [list, tuple])
 @skip_unless_new_style_middleware