Prototype of response_status retrieval

howfast_apm/core.py

@@ -74,6 +74,7 @@ def save_point(
             method: str,
             uri: str,
             endpoint: str = None,  # function name handling the request
+            response_status: str = None,  # HTTP response status (200 OK, etc)
     ) -> None:
         """
         Save a request/response performance information.
@@ -88,9 +89,10 @@ def save_point(
             uri=uri,
             endpoint=endpoint,
             interactions=self.interactions,
+            response_status=response_status,
         )
         # Reset the list of interactions, since it's specific to a request/point
-        self.interactions = []
+        self.reset_interactions()
 
     @staticmethod
     def _save_point(**kwargs) -> None:

howfast_apm/flask.py

@@ -54,6 +54,7 @@ def __init__(
     def __call__(self, environ, start_response):
         if not self.app_id:
             # HF APM not configured, return early to save some time
+            # TODO: wouldn't it be better to just not replace the WSGI app?
             return self.wsgi_app(environ, start_response)
 
         uri = environ.get('PATH_INFO')
@@ -64,22 +65,46 @@ def __call__(self, environ, start_response):
 
         method = environ.get('REQUEST_METHOD')
 
+        response_status: str = None
+
+        def _start_response_wrapped(status, *args, **kwargs):
+            nonlocal response_status
+            # We wrap the start_response callback to access the response status line (eg "200 OK")
+            response_status = status
+            return start_response(status, *args, **kwargs)
+
         time_request_started = datetime.now(timezone.utc)
-        start = timer()
-        return_value = self.wsgi_app(environ, start_response)
-        end = timer()
-        elapsed = end - start
-
-        self.save_point(
-            time_request_started=time_request_started,
-            time_elapsed=elapsed,
-            method=method,
-            uri=uri,
-            endpoint=self.current_endpoint,
-        )
-        self.current_endpoint = None
-        # TODO: remove this once overhead has been measured in production
-        logger.info("overhead when saving the point: %.3fms", (timer() - end) * 1000)
+
+        try:
+            # Time the function execution
+            start = timer()
+            return_value = self.wsgi_app(environ, _start_response_wrapped)
+            # Stop the timer as soon as possible to get the best measure of the function's execution time
+            end = timer()
+        except Exception:
+            # The WSGI app raised an exception, let's still save the point before raising the
+            # exception again
+            # First, "stop" the timer now to get the good measure of the function's execution time
+            end = timer()
+            # The real response status will actually be set by the server that interacts with the
+            # WSGI app, but we cannot instrument it from here, so we just assume a common string.
+            response_status = "500 INTERNAL SERVER ERROR"
+            raise
+        finally:
+            elapsed = end - start
+
+            self.save_point(
+                time_request_started=time_request_started,
+                time_elapsed=elapsed,
+                method=method,
+                uri=uri,
+                endpoint=self.current_endpoint,
+                response_status=response_status,
+            )
+            self.current_endpoint = None
+            # TODO: remove this once overhead has been measured in production
+            logger.info("overhead when saving the point: %.3fms", (timer() - end) * 1000)
+
         return return_value
 
     def _request_started(self, sender, **kwargs):

howfast_apm/runner.py

@@ -73,16 +73,17 @@ def run_once(self):
             return
 
     @staticmethod
-    def serialize_point(point: dict) -> tuple:
+    def serialize_point(point: dict) -> dict:
         """ Prepare the point to be sent to the API """
-        return (
-            point['method'],
-            point['uri'],
-            point['time_request_started'].isoformat(),
-            point['time_elapsed'],
-            point['endpoint'],
-            point['interactions'],
-        )
+        return {
+            'method': point['method'],
+            'uri': point['uri'],
+            'time_request_started': point['time_request_started'].isoformat(),
+            'time_elapsed': point['time_elapsed'],
+            'endpoint': point['endpoint'],
+            'interactions': point['interactions'],
+            'response_status': point['response_status'],
+        }
 
     def _send_batch_robust(self, attempts=1, max_attempts=3) -> None:
         """ Retry sending the batch up to max_retry times """

tests/conftest.py

@@ -35,12 +35,14 @@ def generator():
                 'uri': f'/call/{request_id}',
                 'endpoint': 'controllers.endpoint_name',
                 'interactions': [Interaction('request', f'https://www.example.org/req{request_id}', 0.02)],
+                'response_status': '200 OK',
             }
             # Alternate between an endpoint or no endpoint
             yield {
                 'time_request_started': datetime.now(timezone.utc),
                 'time_elapsed': 0.04,
                 'method': 'GET',
+                'response_status': '200 OK',
                 'uri': f'/call/{request_id}',
                 'endpoint': None,
                 'interactions': [],

tests/test_middleware_flask.py

@@ -22,6 +22,10 @@ def external_call():
         requests.put('https://does-not-exist/')
         return 'ok'
 
+    @app.route('/error')
+    def error():
+        raise Exception("Unhandled exception, kaboom!")
+
     return app
 
 
@@ -61,16 +65,36 @@ def test_ok_with_dsn(HowFastFlaskMiddleware):
     assert point.get('time_elapsed') > 0
     assert point.get('time_request_started') < datetime.now(timezone.utc)
     assert point.get('method') == "GET"
+    assert point.get('response_status') == "200 OK"
     assert point.get('uri') == "/"
 
     response = tester.post('/does-not-exist')
     assert response.status_code == 404
     assert middleware._save_point.call_count == 2
     point = middleware._save_point.call_args[1]
     assert point.get('method') == "POST"
+    assert point.get('response_status') == "404 NOT FOUND"
     assert point.get('uri') == "/does-not-exist"
 
 
+def test_with_exception(HowFastFlaskMiddleware):
+    """ The middleware should gracefully handle routes that raise an Exception """
+    app = create_app()
+    middleware = HowFastFlaskMiddleware(app, app_id='some-dsn')
+
+    tester = app.test_client()
+    response = tester.get('/error')
+    assert response.status_code == 500
+    assert middleware._save_point.called is True
+    assert middleware._save_point.call_count == 1
+    point = middleware._save_point.call_args[1]
+    assert point.get('time_elapsed') > 0
+    assert point.get('time_request_started') < datetime.now(timezone.utc)
+    assert point.get('method') == "GET"
+    assert point.get('response_status') == "500 INTERNAL SERVER ERROR"
+    assert point.get('uri') == "/error"
+
+
 def test_with_path_parameter(HowFastFlaskMiddleware):
     """ Endpoints with a path parameter should be deduplicated """
     app = create_app()

tests/test_runner.py

@@ -95,16 +95,17 @@ def test_send_batch(mocked_post, queue_full):
     points = json_payload.get('perf')
     # queue_full has 10 elements
     assert len(points) == 10
-    assert isinstance(points[0], tuple)
-    assert len(points[0]) == 6
-    assert len(points[1]) == 6
+    assert isinstance(points[0], dict)
+    assert len(points[0].keys()) == 7
+    assert 'method' in points[0].keys()
+    assert len(points[1].keys()) == 7
+    assert 'method' in points[1].keys()
     # Make sure we have the correct point
-    (method, uri, time_request_started, elapsed, endpoint, interactions) = points[0]
-    assert method == 'PUT'
-    assert uri == '/call/1'
-    assert len(interactions) == 1
-    assert interactions[0].interaction_type == 'request'
-    assert interactions[0].name == 'https://www.example.org/req1'
+    assert points[0].get('method') == 'PUT'
+    assert points[0].get('uri') == '/call/1'
+    assert len(points[0].get('interactions')) == 1
+    assert points[0].get('interactions')[0].interaction_type == 'request'
+    assert points[0].get('interactions')[0].name == 'https://www.example.org/req1'
 
 
 @patch('requests.post')