Repository: scoutapp/scout_apm_python
Pull request #294 (2019-10-23 13:11:33)

Remove overly cautious header fetching behaviour
Both the Bottle and Pyramid integrations have this overly cautious behaviour around reading headers from the upstream framework. They both assume that basic framework operations such as fetching a header can fail, and guard around it.

Some of this came from my refactoring for Bottle in #192 and Pyramid in #195, where I narrowed large `try/except` blocks down, but didn't rethink this paranoia.

I think this is too cautious and can be removed. It required a lot of extra lines for the two frameworks when adding Amazon request queue timing in #279, to really no extra effect. If fetching headers (with safe defaults) is broken, users' applications are pretty much guaranteed to be broken too.


Patch:
diff --git a/CHANGELOG.md b/CHANGELOG.md
index c277c34..5ea5780 100644
--- a/CHANGELOG.md
+++ b/CHANGELOG.md
@@ -8,6 +8,8 @@
   ([PR #283](https://github.com/scoutapp/scout_apm_python/pull/283)).
 - Improve warning message for deprecated `log_level` configuration option
   ([PR #288](https://github.com/scoutapp/scout_apm_python/pull/288)).
+- Track errors on Pyramid
+  ([PR #298](https://github.com/scoutapp/scout_apm_python/pull/298)).
 
 ## [2.6.0] 2019-10-22
 
diff --git a/LICENSE b/LICENSE
index b25384b..44ba22b 100644
--- a/LICENSE
+++ b/LICENSE
@@ -1,6 +1,6 @@
 The MIT License (MIT)
 
-Copyright (c) 2018 Zimuth, Inc.
+Copyright (c) 2018-2019 Zimuth, Inc.
 
 Permission is hereby granted, free of charge, to any person obtaining a copy
 of this software and associated documentation files (the "Software"), to deal
diff --git a/src/scout_apm/bottle.py b/src/scout_apm/bottle.py
index bc248fa..beb8ddb 100644
--- a/src/scout_apm/bottle.py
+++ b/src/scout_apm/bottle.py
@@ -60,38 +60,24 @@ class ScoutPlugin(object):
                 controller_name = "/" + controller_name
             tracked_request.start_span(operation="Controller{}".format(controller_name))
 
-            try:
-                # Determine a remote IP to associate with the request. The
-                # value is spoofable by the requester so this is not suitable
-                # to use in any security sensitive context.
-                user_ip = (
-                    request.headers.get("x-forwarded-for", "").split(",")[0]
-                    or request.headers.get("client-ip", "").split(",")[0]
-                    or request.environ.get("REMOTE_ADDR")
-                )
-            except Exception:
-                pass
-            else:
-                tracked_request.tag("user_ip", user_ip)
+            # Determine a remote IP to associate with the request. The
+            # value is spoofable by the requester so this is not suitable
+            # to use in any security sensitive context.
+            user_ip = (
+                request.headers.get("x-forwarded-for", "").split(",")[0]
+                or request.headers.get("client-ip", "").split(",")[0]
+                or request.environ.get("REMOTE_ADDR")
+            )
+            tracked_request.tag("user_ip", user_ip)
 
             tracked_queue_time = False
-            try:
-                queue_time = request.headers.get(
-                    "x-queue-start", ""
-                ) or request.headers.get("x-request-start", "")
-            except Exception:
-                pass
-            else:
-                tracked_queue_time = track_request_queue_time(
-                    queue_time, tracked_request
-                )
+            queue_time = request.headers.get(
+                "x-queue-start", ""
+            ) or request.headers.get("x-request-start", "")
+            tracked_queue_time = track_request_queue_time(queue_time, tracked_request)
             if not tracked_queue_time:
-                try:
-                    amazon_queue_time = request.headers.get("x-amzn-trace-id", "")
-                except Exception:
-                    pass
-                else:
-                    track_amazon_request_queue_time(amazon_queue_time, tracked_request)
+                amazon_queue_time = request.headers.get("x-amzn-trace-id", "")
+                track_amazon_request_queue_time(amazon_queue_time, tracked_request)
 
             try:
                 return callback(*args, **kwargs)
diff --git a/src/scout_apm/core/__init__.py b/src/scout_apm/core/__init__.py
index 58c1323..0de41b9 100644
--- a/src/scout_apm/core/__init__.py
+++ b/src/scout_apm/core/__init__.py
@@ -2,6 +2,7 @@
 from __future__ import absolute_import, division, print_function, unicode_literals
 
 import logging
+import sys
 from os import getpid
 
 from scout_apm.core.config import ScoutConfig
@@ -23,6 +24,10 @@ def install(*args, **kwargs):
         ScoutConfig().set(**kwargs["config"])
     context = AgentContext.build(config=ScoutConfig())
 
+    if sys.platform == "win32":
+        logger.info("APM Not Launching on PID: %s - Windows is not supported", getpid())
+        return False
+
     if not context.config.value("monitor"):
         logger.info(
             "APM Not Launching on PID: %s - Configuration 'monitor' is not true",
diff --git a/src/scout_apm/pyramid.py b/src/scout_apm/pyramid.py
index 73ade4e..6d814bf 100644
--- a/src/scout_apm/pyramid.py
+++ b/src/scout_apm/pyramid.py
@@ -41,53 +41,38 @@ def instruments(handler, registry):
             if ignore_path(path):
                 tracked_request.tag("ignore_transaction", True)
 
-            try:
-                # Determine a remote IP to associate with the request. The value is
-                # spoofable by the requester so this is not suitable to use in any
-                # security sensitive context.
-                user_ip = (
-                    request.headers.get("x-forwarded-for", default="").split(",")[0]
-                    or request.headers.get("client-ip", default="").split(",")[0]
-                    or request.remote_addr
-                )
-            except Exception:
-                pass
-            else:
-                tracked_request.tag("user_ip", user_ip)
+            # Determine a remote IP to associate with the request. The value is
+            # spoofable by the requester so this is not suitable to use in any
+            # security sensitive context.
+            user_ip = (
+                request.headers.get("x-forwarded-for", default="").split(",")[0]
+                or request.headers.get("client-ip", default="").split(",")[0]
+                or request.remote_addr
+            )
+            tracked_request.tag("user_ip", user_ip)
 
             tracked_queue_time = False
-            try:
-                queue_time = request.headers.get(
-                    "x-queue-start", default=""
-                ) or request.headers.get("x-request-start", default="")
-            except Exception:
-                pass
-            else:
-                tracked_queue_time = track_request_queue_time(
-                    queue_time, tracked_request
-                )
+            queue_time = request.headers.get(
+                "x-queue-start", default=""
+            ) or request.headers.get("x-request-start", default="")
+            tracked_queue_time = track_request_queue_time(queue_time, tracked_request)
             if not tracked_queue_time:
-                try:
-                    amazon_queue_time = request.headers.get(
-                        "x-amzn-trace-id", default=""
-                    )
-                except Exception:
-                    pass
-                else:
-                    track_amazon_request_queue_time(amazon_queue_time, tracked_request)
+                amazon_queue_time = request.headers.get("x-amzn-trace-id", default="")
+                track_amazon_request_queue_time(amazon_queue_time, tracked_request)
 
             try:
-                response = handler(request)
+                try:
+                    response = handler(request)
+                finally:
+                    # Routing further down the call chain. So time it starting
+                    # above, but only name it if it gets a name
+                    if request.matched_route is not None:
+                        tracked_request.mark_real_request()
+                        span.operation = "Controller/" + request.matched_route.name
             except Exception:
                 tracked_request.tag("error", "true")
                 raise
 
-            # This happens further down the call chain. So time it starting
-            # above, but only name it if it gets to here.
-            if request.matched_route is not None:
-                tracked_request.mark_real_request()
-                span.operation = "Controller/" + request.matched_route.name
-
         finally:
             tracked_request.stop_span()
 


Test patch:
diff --git a/tests/integration/test_bottle.py b/tests/integration/test_bottle.py
index ad7afb2..f395ca4 100644
--- a/tests/integration/test_bottle.py
+++ b/tests/integration/test_bottle.py
@@ -5,13 +5,12 @@ import datetime as dt
 import sys
 from contextlib import contextmanager
 
-from bottle import Bottle, WSGIHeaderDict
+from bottle import Bottle
 from webtest import TestApp
 
 from scout_apm.api import Config
 from scout_apm.bottle import ScoutPlugin
 from scout_apm.compat import datetime_to_timestamp
-from tests.compat import mock
 from tests.integration.util import (
     parametrize_filtered_params,
     parametrize_queue_time_header_name,
@@ -100,23 +99,6 @@ def test_user_ip(headers, extra_environ, expected, tracked_requests):
     assert tracked_request.tags["user_ip"] == expected
 
 
-def test_user_ip_error(tracked_requests):
-    orig_headers_get = WSGIHeaderDict.get
-
-    def crashy_get(self, key, *args, **kwargs):
-        if key == "x-forwarded-for":
-            raise ValueError("Don't try get *that* header!")
-        return orig_headers_get(key, *args, **kwargs)
-
-    with mock.patch.object(
-        WSGIHeaderDict, "get", new=crashy_get
-    ), app_with_scout() as app:
-        TestApp(app).get("/")
-
-    tracked_request = tracked_requests[0]
-    assert "user_ip" not in tracked_request.tags
-
-
 @parametrize_queue_time_header_name
 def test_queue_time(header_name, tracked_requests):
     # Not testing floats due to Python 2/3 rounding differences
@@ -133,28 +115,6 @@ def test_queue_time(header_name, tracked_requests):
     assert queue_time_ns >= 2000000000 and queue_time_ns < 4000000000
 
 
-def test_queue_time_error(tracked_requests):
-    """
-    Scout doesn't crash if bottle's Request.headers.get raises an exception.
-
-    This cannot be tested without mocking because it should never happen.
-    """
-    orig_headers_get = WSGIHeaderDict.get
-
-    def crashy_get(self, key, *args, **kwargs):
-        if key == "x-queue-start":
-            raise ValueError("Don't try get *that* header!")
-        return orig_headers_get(key, *args, **kwargs)
-
-    with mock.patch.object(
-        WSGIHeaderDict, "get", new=crashy_get
-    ), app_with_scout() as app:
-        TestApp(app).get("/")
-
-    tracked_request = tracked_requests[0]
-    assert "scout.queue_time_ns" not in tracked_request.tags
-
-
 def test_amazon_queue_time(tracked_requests):
     queue_start = int(datetime_to_timestamp(dt.datetime.utcnow()) - 2)
     with app_with_scout() as app:
diff --git a/tests/integration/test_pyramid.py b/tests/integration/test_pyramid.py
index fb4df40..819d6dd 100644
--- a/tests/integration/test_pyramid.py
+++ b/tests/integration/test_pyramid.py
@@ -8,12 +8,10 @@ from contextlib import contextmanager
 import pytest
 from pyramid.config import Configurator
 from pyramid.response import Response
-from webob.headers import EnvironHeaders
 from webtest import TestApp
 
 from scout_apm.api import Config
 from scout_apm.compat import datetime_to_timestamp
-from tests.compat import mock
 from tests.integration.util import (
     parametrize_filtered_params,
     parametrize_queue_time_header_name,
@@ -100,27 +98,6 @@ def test_user_ip(headers, extra_environ, expected, tracked_requests):
     assert tracked_request.tags["user_ip"] == expected
 
 
-def test_user_ip_error(tracked_requests):
-    """
-    Scout doesn't crash if pyramid.request.Request.remote_addr raises an exception.
-
-    This cannot be tested without mocking because it should never happen.
-
-    It's implemented in webob.request.Request and it's just a lookup in environ.
-    """
-    remote_addr_patcher = mock.patch(
-        "pyramid.request.Request.remote_addr",
-        new_callable=mock.PropertyMock,
-        side_effect=ValueError,
-    )
-
-    with app_with_scout() as app, remote_addr_patcher:
-        response = TestApp(app).get("/hello/")
-
-    assert response.status_int == 200
-    assert "user_ip" not in tracked_requests[0].tags
-
-
 @parametrize_queue_time_header_name
 def test_queue_time(header_name, tracked_requests):
     # Not testing floats due to Python 2/3 rounding differences
@@ -137,31 +114,6 @@ def test_queue_time(header_name, tracked_requests):
     assert queue_time_ns >= 2000000000 and queue_time_ns < 4000000000
 
 
-def test_queue_time_error(tracked_requests):
-    """
-    Scout doesn't crash if pyramid.request.Request.headers.get raises an
-    exception.
-
-    This cannot be tested without mocking because it should never happen.
-    It's implemented in webob.headers.EnvironHeaders as a simple lookup in
-    environ: https://github.com/Pylons/webob/blob/master/src/webob/headers.py
-    """
-    orig_headers_get = EnvironHeaders.get
-
-    def crashy_get(self, key, *args, **kwargs):
-        if key == "x-queue-start":
-            raise ValueError("Don't try get *that* header!")
-        return orig_headers_get(key, *args, **kwargs)
-
-    get_patcher = mock.patch.object(EnvironHeaders, "get", new=crashy_get)
-
-    with app_with_scout() as app, get_patcher:
-        response = TestApp(app).get("/hello/")
-
-    assert response.status_int == 200
-    assert "user_ip" not in tracked_requests[0].tags
-
-
 def test_amazon_queue_time(tracked_requests):
     queue_start = int(datetime_to_timestamp(dt.datetime.utcnow()) - 2)
     with app_with_scout() as app:
@@ -217,7 +169,13 @@ def test_server_error(tracked_requests):
     with app_with_scout() as app, pytest.raises(ValueError):
         TestApp(app).get("/crash/", expect_errors=True)
 
-    assert tracked_requests == []
+    assert len(tracked_requests) == 1
+    tracked_request = tracked_requests[0]
+    assert tracked_request.tags["path"] == "/crash/"
+    assert tracked_request.tags["error"] == "true"
+    assert len(tracked_request.complete_spans) == 1
+    span = tracked_request.complete_spans[0]
+    assert span.operation == "Controller/crash"
 
 
 def test_no_monitor(tracked_requests):
diff --git a/tests/unit/test_core.py b/tests/unit/test_core.py
new file mode 100644
index 0000000..bcfe54b
--- /dev/null
+++ b/tests/unit/test_core.py
@@ -0,0 +1,55 @@
+# coding=utf-8
+from __future__ import absolute_import, division, print_function, unicode_literals
+
+import logging
+import os
+import sys
+
+from scout_apm.api import Config
+from scout_apm.core import install
+from scout_apm.core.core_agent_manager import CoreAgentManager
+from tests.compat import mock
+
+
+def test_install_fail_windows(caplog):
+    with mock.patch.object(sys, "platform", new="win32"):
+        installed = install()
+
+    assert installed is False
+    assert (
+        "scout_apm.core",
+        logging.INFO,
+        "APM Not Launching on PID: %s - Windows is not supported" % os.getpid(),
+    ) in caplog.record_tuples
+
+
+def test_install_fail_monitor_false(caplog):
+    try:
+        installed = install(config={"monitor": False})
+    finally:
+        Config.reset_all()
+
+    assert installed is False
+    assert (
+        "scout_apm.core",
+        logging.INFO,
+        (
+            "APM Not Launching on PID: %s - Configuration 'monitor' is not true"
+            % os.getpid()
+        ),
+    ) in caplog.record_tuples
+
+
+def test_install_success(caplog):
+    with mock.patch.object(CoreAgentManager, "launch"):
+        try:
+            installed = install(config={"monitor": True})
+        finally:
+            Config.reset_all()
+
+    assert installed is True
+    assert (
+        "scout_apm.core",
+        logging.DEBUG,
+        "APM Launching on PID: %s" % os.getpid(),
+    ) in caplog.record_tuples