fix: Flask events are ordered correctly

Currently, if the config specifies that flask should be instrumented, an
http_server_response event gets recorded between the call and return
events for Flask.finalize_request. Also, a return event with an
exception will get recorded between the call and return events for
Flask.handle_user_exception.

These changes hook finalize_request and handle_user_exception, and
ensure that the events get ordered correctly.

_appmap/event.py

@@ -457,7 +457,7 @@ def normalized_path_info(self, npi):
 class ReturnEvent(Event):
     __slots__ = ["parent_id", "elapsed"]
 
-    def __init__(self, parent_id, elapsed):
+    def __init__(self, parent_id, elapsed, exception=None):
         super().__init__("return")
         self.parent_id = parent_id
         self.elapsed = elapsed
@@ -480,18 +480,19 @@ class HttpResponseEvent(ReturnEvent):
 
     def __init__(self, status_code, headers=None, **kwargs):
         super().__init__(**kwargs)
+        self.response = {}
+        self.update(status_code, headers)
 
-        response = {"status_code": status_code}
+    def update(self, status_code, headers):
+        if status_code is not None:
+            self.response.update({"status_code": status_code})
 
         if headers is not None:
-            response.update(
-                {
-                    "mime_type": headers.get("Content-Type"),
-                    "headers": none_if_empty(dict(headers)),
-                }
-            )
-
-        self.response = compact_dict(response)
+            if "Content-Type" in headers:
+                self.response.update({"mime_type": headers.get("Content-Type")})
+            updated_headers = dict(headers)
+            if len(updated_headers) > 0:
+                self.response.update({"headers": updated_headers})
 
 
 # pylint: disable=too-few-public-methods

_appmap/test/data/flask-instrumented/appmap.yml

@@ -1,4 +1,4 @@
 name: FlaskTest
 packages:
 - path: flaskapp
-- path: flask.app.Flask
+- path: flask.app.Flask

_appmap/test/data/flask-instrumented/flaskapp.py

@@ -3,9 +3,9 @@
 """
 # pylint: disable=missing-function-docstring
 
+import werkzeug
 from appmap.flask import AppmapFlask
-from flask import Flask, make_response
-from markupsafe import escape
+from flask import Flask, request
 
 app = Flask(__name__)
 AppmapFlask(app).init_app()
@@ -18,3 +18,13 @@ def hello_world():
 @app.route("/exception")
 def raise_exception():
     raise Exception("An exception")
+
+@app.post("/do_post")
+def do_post():
+    _ = request.get_json()
+    return "Got post request"
+
+
+@app.errorhandler(werkzeug.exceptions.BadRequest)
+def handle_bad_request(e):
+    return "That's a bad request!", 400

_appmap/test/data/flask-instrumented/test_app.py

@@ -17,3 +17,15 @@ def test_exception(client):
     response = client.get("/exception")
 
     assert response.status_code == 500
+
+def test_not_found(client):
+    response = client.get("/not_found")
+
+    assert response.status_code == 404
+
+
+def test_errorhandler(client):
+    response = client.post("/do_post", content_type="application/json")
+
+    assert response.status_code == 400
+    assert response.text == "That's a bad request!"

_appmap/test/data/flask/flaskapp.py

@@ -6,8 +6,9 @@
 """
 # pylint: disable=missing-function-docstring
 
-from flask import Flask, make_response
+from flask import Flask, make_response, request
 from markupsafe import escape
+import werkzeug
 
 app = Flask(__name__)
 
@@ -50,3 +51,13 @@ def show_org_user_posts(org, username):
 @app.route("/exception")
 def raise_exception():
     raise Exception("An exception")
+
+@app.post("/do_post")
+def do_post():
+    _ = request.get_json()
+    return "Got post request"
+
+
+@app.errorhandler(werkzeug.exceptions.BadRequest)
+def handle_bad_request(e):
+    return "That's a bad request!", 400

_appmap/test/data/flask/test_app.py

@@ -12,3 +12,15 @@ def test_request(client):
     response = client.get("/")
 
     assert response.status_code == 200
+
+def test_not_found(client):
+    response = client.get("/not_found")
+
+    assert response.status_code == 404
+
+
+def test_errorhandler(client):
+    response = client.post("/do_post", content_type="application/json")
+
+    assert response.status_code == 400
+    assert response.text == "That's a bad request!"

_appmap/test/test_django.py

@@ -171,9 +171,6 @@ def raise_on_call(*args):
 
     assert events[1].event == "return"
     assert events[1].parent_id == events[0].id
-    assert events[1].exceptions == [
-        DictIncluding({"class": "builtins.RuntimeError", "message": "An error"})
-    ]
 
 
 @pytest.mark.appmap_enabled(env={"APPMAP_RECORD_REQUESTS": "false"})

_appmap/test/test_flask.py

@@ -78,18 +78,59 @@ def test_framework_metadata(client, events):  # pylint: disable=unused-argument
 
 
 @pytest.mark.appmap_enabled(env={"APPMAP_RECORD_REQUESTS": "false"})
-def test_exception(client, events):  # pylint: disable=unused-argument
+def test_exception(client, events):
     with pytest.raises(Exception):
         client.get("/exception")
 
     assert events[0].http_server_request == DictIncluding(
         {"request_method": "GET", "path_info": "/exception", "protocol": "HTTP/1.1"}
     )
+
+    assert events[1].event == "return"
+    assert events[1].parent_id == events[0].id
+    assert events[1].http_server_response["status_code"] == 500
+
+
+@pytest.mark.appmap_enabled(env={"APPMAP_RECORD_REQUESTS": "false"})
+def test_not_found(client, events):
+    client.get("/not_found")
+
+    assert events[0].http_server_request == DictIncluding(
+        {"request_method": "GET", "path_info": "/not_found", "protocol": "HTTP/1.1"}
+    )
+
     assert events[1].event == "return"
     assert events[1].parent_id == events[0].id
-    assert events[1].exceptions == [
-        DictIncluding({"class": "builtins.Exception", "message": "An exception"})
-    ]
+    assert events[1].http_server_response["status_code"] == 404
+
+
+@pytest.mark.appmap_enabled(env={"APPMAP_RECORD_REQUESTS": "false"})
+def test_bad_request(client, events):
+    client.post("/test")
+
+    assert events[0].http_server_request == DictIncluding(
+        {"request_method": "POST", "path_info": "/test", "protocol": "HTTP/1.1"}
+    )
+
+    assert events[1].event == "return"
+    assert events[1].parent_id == events[0].id
+    assert events[1].http_server_response["status_code"] == 405
+
+
+@pytest.mark.appmap_enabled(env={"APPMAP_RECORD_REQUESTS": "false"})
+def test_errorhandler(client, events):
+    response = client.post("/do_post", content_type="application/json")
+
+    # Verify that the custom errorhandler was used
+    assert response.text == "That's a bad request!"
+
+    assert events[0].http_server_request == DictIncluding(
+        {"request_method": "POST", "path_info": "/do_post", "protocol": "HTTP/1.1"}
+    )
+
+    assert events[1].event == "return"
+    assert events[1].parent_id == events[0].id
+    assert events[1].http_server_response["status_code"] == 400
 
 
 @pytest.mark.appmap_enabled
@@ -141,7 +182,7 @@ def beforeEach(self, monkeypatch, pytester):
     def test_enabled(self, pytester):
         result = pytester.runpytest("-svv")
 
-        result.assert_outcomes(passed=1, failed=0, errors=0)
+        result.assert_outcomes(passed=3, failed=0, errors=0)
         appmap_file = (
             pytester.path / "tmp" / "appmap" / "pytest" / "test_request.appmap.json"
         )
@@ -157,71 +198,78 @@ def test_disabled(self, pytester, monkeypatch):
 
         result = pytester.runpytest("-svv")
 
-        result.assert_outcomes(passed=1, failed=0, errors=0)
+        result.assert_outcomes(passed=3, failed=0, errors=0)
         assert not (pytester.path / "tmp" / "appmap").exists()
 
     def test_disabled_for_process(self, pytester, monkeypatch):
         monkeypatch.setenv("APPMAP_RECORD_PROCESS", "true")
 
         result = pytester.runpytest("-svv")
 
-        result.assert_outcomes(passed=1, failed=0, errors=0)
+        result.assert_outcomes(passed=3, failed=0, errors=0)
 
         assert (pytester.path / "tmp" / "appmap" / "process").exists()
         assert not (pytester.path / "tmp" / "appmap" / "requests").exists()
         assert not (pytester.path / "tmp" / "appmap" / "pytest").exists()
 
-def call_stack_balanced(events):
-    """Ensure that the call stack in events has balanced call and return events"""
-    stack = []
-    for e in events:
-        if e.get("event") == "call":
-            stack.append(e)
-        elif e.get("event") == "return":
-            if len(stack) > 0:
-                call = stack.pop()
-                if call.get("id") != e.get("parent_id"):
-                    return False
-            else:
-                return False
-    if len(stack) == 0:
-        return True
-
-    return False
-
-
-@pytest.mark.example_dir("flask-instrumented")
-def test_flask_instrumented(testdir, monkeypatch):
-    result = testdir.runpytest("-svv", "-k", "test_request")
-    result.assert_outcomes(passed=1)
-
-    appmap_file = testdir.path / "tmp" / "appmap" / "pytest" / "test_request.appmap.json"
-    appmap = json.load(appmap_file.open())
-    events = appmap["events"]
-    assert len(events) == 32
-    request_event = events[10]
-    assert request_event.get("http_server_request") is not None
-    nested_events = events[11:17]
-    assert call_stack_balanced(nested_events), f"unbalanced call stack\n{events[11:17]}"
-    response_event = events[17]
-    assert response_event.get("http_server_response") is not None and response_event.get(
-        "parent_id"
-    ) == request_event.get("id")
 
 @pytest.mark.example_dir("flask-instrumented")
-def test_flask_instrumented_with_exception(testdir, monkeypatch):
-    result = testdir.runpytest("-svv", "-k", "test_exception")
-    result.assert_outcomes(passed=1)
-
-    appmap_file = testdir.path / "tmp" / "appmap" / "pytest" / "test_exception.appmap.json"
-    appmap = json.load(appmap_file.open())
-    events = appmap["events"]
-    assert len(events) == 41
-    request_event = events[10]
-    assert request_event.get("http_server_request") is not None
-    nested_events = events[11:21]
-    assert call_stack_balanced(nested_events), f"unbalanced call stack\n{events[11:17]}"
-    response_event = events[21]
-    assert len(response_event.get("exceptions")) == 1 and response_event.get(
-        "parent_id"
-    ) == request_event.get("id")
+class TestFlaskInstrumented:
+    def test_all(self, testdir):
+        result = testdir.runpytest("-svv")
+        result.assert_outcomes(passed=4)
+
+    def check_call_stack(self, events):
+        """Ensure that the call stack in events has balanced call and return events"""
+        stack = []
+        for e in events:
+            if e.get("event") == "call":
+                stack.append(e)
+            elif e.get("event") == "return":
+                assert len(stack) > 0, "return without call"
+                call = stack.pop()
+                assert call.get("id") == e.get("parent_id")
+        assert len(stack) == 0, "leftover events"
+
+    def verify_events(self, events, expected_len, request_idx, response_idx):
+        assert len(events) == expected_len
+        request_event = events[request_idx]
+        assert request_event.get("http_server_request") is not None
+        nested_events = events[request_idx + 1 : response_idx]
+        self.check_call_stack(nested_events)
+        response_event = events[response_idx]
+        assert response_event.get("http_server_response") is not None and response_event.get(
+            "parent_id"
+        ) == request_event.get("id")
+
+    def test_response(self, testdir):
+        result = testdir.runpytest("-svv", "-k", "test_request")
+        result.assert_outcomes(passed=1)
+
+        appmap_file = testdir.path / "tmp" / "appmap" / "pytest" / "test_request.appmap.json"
+        appmap = json.load(appmap_file.open())
+        self.verify_events(appmap["events"], 32, 10, 21)
+
+    def test_unhandled_exception(self, testdir):
+        result = testdir.runpytest("-svv", "-k", "test_exception")
+        result.assert_outcomes(passed=1)
+
+        appmap_file = testdir.path / "tmp" / "appmap" / "pytest" / "test_exception.appmap.json"
+        appmap = json.load(appmap_file.open())
+        self.verify_events(appmap["events"], 38, 10, 17)
+
+    def test_default_exception(self, testdir):
+        result = testdir.runpytest("-svv", "-k", "test_not_found")
+        result.assert_outcomes(passed=1)
+
+        appmap_file = testdir.path / "tmp" / "appmap" / "pytest" / "test_not_found.appmap.json"
+        appmap = json.load(appmap_file.open())
+        self.verify_events(appmap["events"], 34, 10, 23)
+
+    def test_errorhandler(self, testdir):
+        result = testdir.runpytest("-svv", "-k", "test_errorhandler")
+        result.assert_outcomes(passed=1)
+
+        appmap_file = testdir.path / "tmp" / "appmap" / "pytest" / "test_errorhandler.appmap.json"
+        appmap = json.load(appmap_file.open())
+        self.verify_events(appmap["events"], 36, 10, 25)