feat: when APPMAP_RECORD_REQUESTS is set record each request in a separate file

Author: symwell

appmap/_implementation/env.py

@@ -76,6 +76,10 @@ def enabled(self, value):
     def display_params(self):
         return self.get("APPMAP_DISPLAY_PARAMS", "true").lower() == "true"
 
+    @property
+    def record_all_requests(self):
+        return self.get("APPMAP_RECORD_REQUESTS", "false").lower() == "true"
+
     def _configure_logging(self):
         log_level = self.get("APPMAP_LOG_LEVEL", "warning").upper()
 

appmap/_implementation/testing_framework.py

@@ -1,6 +1,8 @@
 """Shared infrastructure for testing framework integration."""
 
+import datetime
 import os
+import os.path
 import re
 from contextlib import contextmanager
 from hashlib import sha256
@@ -9,7 +11,8 @@
 import inflection
 
 from appmap._implementation import configuration, env, generation, recording
-from appmap._implementation.utils import fqname
+from appmap._implementation.env import Env
+from appmap._implementation.utils import fqname, scenario_filename
 
 from .metadata import Metadata
 
@@ -120,6 +123,34 @@ def write_appmap(basedir, basename, contents):
         tmp.write(contents)
     os.replace(tmp.name, basedir / filename)
 
+def create_appmap_file(request_method, request_path_info, request_full_path, response, headers, rec):
+    start_time = datetime.datetime.now()
+    appmap_name = (
+        request_method
+        + " "
+        + request_path_info
+        + " ("
+        + str(response.status_code)
+        + ") - "
+        + start_time.strftime("%T.%f")[:-3]
+    )
+    output_dir = Env.current.output_dir
+    appmap_basename = scenario_filename(
+        "_".join([str(start_time.timestamp()), request_full_path])
+    )
+    appmap_file_path = os.path.join(output_dir, appmap_basename)
+    metadata = {
+        "name": appmap_name,
+        "timestamp": start_time.timestamp(),
+        "recorder": {"name": "record_requests"},
+    }
+    write_appmap(
+        output_dir, appmap_basename, generation.dump(rec, metadata)
+    )
+    headers["AppMap-Name"] = os.path.abspath(appmap_name)
+    headers["AppMap-File-Name"] = (
+        os.path.abspath(appmap_file_path) + APPMAP_SUFFIX
+    )
 
 class session:
     def __init__(self, name, recorder_type, version=None):

appmap/_implementation/utils.py

@@ -1,5 +1,6 @@
 import inspect
 import os
+import re
 import shlex
 import subprocess
 import threading
@@ -192,3 +193,10 @@ def _wrap_cls(patch):
         return patch
 
     return _wrap_cls
+
+
+# this is different than appmap-ruby: part of its logic is in write_appmap
+def scenario_filename(name, separator="-"):
+    pattern = r"[^a-z0-9\-_]+"
+    replacement = separator
+    return re.sub(pattern, replacement, name, flags=re.IGNORECASE)

appmap/django.py

@@ -22,14 +22,15 @@
 from django.urls.exceptions import Resolver404
 from django.urls.resolvers import _route_to_regex
 
-from appmap._implementation import generation
+from appmap._implementation import generation, recording, testing_framework
 from appmap._implementation.env import Env
 from appmap._implementation.event import (
     ExceptionEvent,
     HttpServerRequestEvent,
     HttpServerResponseEvent,
     ReturnEvent,
     SqlEvent,
+    _EventIds,
 )
 from appmap._implementation.instrument import is_instrumentation_disabled
 from appmap._implementation.recording import Recorder
@@ -218,51 +219,32 @@ def __call__(self, request):
 
         if request.path_info == "/_appmap/record":
             return self.recording(request)
-        if self.recorder.enabled:
-            add_metadata()
-            start = time.monotonic()
-            params = request_params(request)
-            try:
-                resolved = resolve(request.path_info)
-                params.update(resolved.kwargs)
-                normalized_path_info = normalize_path_info(request.path_info, resolved)
-            except Resolver404:
-                # If the request was for a bad path (e.g. when an app
-                # is testing 404 handling), resolving will fail.
-                normalized_path_info = None
-
-            call_event = HttpServerRequestEvent(
-                request_method=request.method,
-                path_info=request.path_info,
-                message_parameters=params,
-                normalized_path_info=normalized_path_info,
-                protocol=request.META["SERVER_PROTOCOL"],
-                headers=request.headers,
-            )
-            Recorder.add_event(call_event)
 
-        try:
-            response = self.get_response(request)
-        except:
-            if self.recorder.enabled:
-                duration = time.monotonic() - start
-                exception_event = ExceptionEvent(
-                    parent_id=call_event.id, elapsed=duration, exc_info=sys.exc_info()
-                )
-                Recorder.add_event(exception_event)
-            raise
-
-        if self.recorder.enabled:
-            duration = time.monotonic() - start
-            return_event = HttpServerResponseEvent(
-                parent_id=call_event.id,
-                elapsed=duration,
-                status_code=response.status_code,
-                headers=dict(response.items()),
-            )
-            Recorder.add_event(return_event)
-
-        return response
+        if Env.current.enabled or self.recorder.enabled:
+            # It should be recording or it's currently recording.  The
+            # recording is either
+            # a) remote, enabled by POST to /_appmap/record, which set
+            #    self.recorder.enabled, or
+            # b) requests, set by Env.current.record_all_requests, or
+            # c) both remote and requests; there are multiple active recorders.
+            if not Env.current.record_all_requests and self.recorder.enabled:
+                # a)
+                return self.record_request([self.recorder], request)
+            elif Env.current.record_all_requests:
+                # b) or c)
+                rec = Recorder(_EventIds.get_thread_id())
+                rec.start_recording()
+                recorders = [rec]
+                # Each time an event is added for a thread_id it's
+                # also added to the global Recorder().  So don't add
+                # the global Recorder() into recorders: that would
+                # have added the event in the global Recorder() twice.
+                try:
+                    response = self.record_request(recorders, request)
+                    testing_framework.create_appmap_file(request.method, request.path_info, request.get_full_path(), response, response, rec)
+                    return response
+                finally:
+                    rec.stop_recording()
 
     def recording(self, request):
         """Handle recording requests."""
@@ -286,6 +268,55 @@ def recording(self, request):
 
         return HttpResponseBadRequest()
 
+    def record_request(self, recorders, request):
+        for rec in recorders:
+            if rec.enabled:
+                add_metadata()
+                start = time.monotonic()
+                params = request_params(request)
+                try:
+                    resolved = resolve(request.path_info)
+                    params.update(resolved.kwargs)
+                    normalized_path_info = normalize_path_info(request.path_info, resolved)
+                except Resolver404:
+                    # If the request was for a bad path (e.g. when an app
+                    # is testing 404 handling), resolving will fail.
+                    normalized_path_info = None
+
+                call_event = HttpServerRequestEvent(
+                    request_method=request.method,
+                path_info=request.path_info,
+                    message_parameters=params,
+                    normalized_path_info=normalized_path_info,
+                    protocol=request.META["SERVER_PROTOCOL"],
+                    headers=request.headers,
+                )
+                rec.add_event(call_event)
+
+        try:
+            response = self.get_response(request)
+        except:
+            for rec in recorders:
+                if rec and rec.enabled:
+                    duration = time.monotonic() - start
+                    exception_event = ExceptionEvent(
+                        parent_id=call_event.id, elapsed=duration, exc_info=sys.exc_info()
+                    )
+                    rec.add_event(exception_event)
+                raise
+
+        for rec in recorders:
+            if rec and rec.enabled:
+                duration = time.monotonic() - start
+                return_event = HttpServerResponseEvent(
+                    parent_id=call_event.id,
+                    elapsed=duration,
+                    status_code=response.status_code,
+                    headers=dict(response.items()),
+                )
+                rec.add_event(return_event)
+
+        return response
 
 def inject_middleware():
     """Make sure AppMap middleware is added to the stack"""

appmap/flask.py

@@ -1,4 +1,6 @@
+import datetime
 import json
+import os.path
 import time
 from functools import wraps
 
@@ -9,9 +11,9 @@
 from werkzeug.exceptions import BadRequest
 from werkzeug.routing import parse_rule
 
-from appmap._implementation import generation
+from appmap._implementation import generation, testing_framework
 from appmap._implementation.env import Env
-from appmap._implementation.event import HttpServerRequestEvent, HttpServerResponseEvent
+from appmap._implementation.event import HttpServerRequestEvent, HttpServerResponseEvent, _EventIds
 from appmap._implementation.recording import Recorder, Recording
 from appmap._implementation.web_framework import TemplateHandler as BaseTemplateHandler
 
@@ -100,49 +102,108 @@ def record_delete(self):
         return json.loads(generation.dump(self.recording))
 
     def before_request(self):
-        if self.recording.is_running() and request.path != self.record_url:
-            Metadata.add_framework("flask", flask.__version__)
-            np = None
-            # See
-            # https://github.com/pallets/werkzeug/blob/2.0.0/src/werkzeug/routing.py#L213
-            # for a description of parse_rule.
-            if request.url_rule:
-                np = "".join(
-                    [
-                        f"{{{p}}}" if c else p
-                        for c, _, p in parse_rule(request.url_rule.rule)
-                    ]
+        if request.path == self.record_url:
+            return
+
+        if (Env.current.enabled or self.recording.is_running()):
+            # It should be recording or it's currently recording.  The
+            # recording is either
+            # a) remote, enabled by POST to /_appmap/record, which set
+            #    self.recording.is_running, or
+            # b) requests, set by Env.current.record_all_requests, or
+            # c) both remote and requests; there are multiple active recorders.
+            if not Env.current.record_all_requests and self.recording.is_running():
+                self.before_request_main([Recorder()])
+            else:
+                rec = Recorder(_EventIds.get_thread_id())
+                rec.start_recording()
+                recorders = [rec]
+                # Each time an event is added for a thread_id it's
+                # also added to the global Recorder().  So don't add
+                # the global Recorder() into recorders: that would
+                # have added the event in the global Recorder() twice.
+                self.before_request_main(recorders)
+
+    def before_request_main(self, recorders):
+        for rec in recorders:
+            if rec.enabled:
+                Metadata.add_framework("flask", flask.__version__)
+                np = None
+                # See
+                # https://github.com/pallets/werkzeug/blob/2.0.0/src/werkzeug/routing.py#L213
+                # for a description of parse_rule.
+                if request.url_rule:
+                    np = "".join(
+                        [
+                            f"{{{p}}}" if c else p
+                            for c, _, p in parse_rule(request.url_rule.rule)
+                        ]
+                    )
+                call_event = HttpServerRequestEvent(
+                    request_method=request.method,
+                    path_info=request.path,
+                    message_parameters=request_params(request),
+                    normalized_path_info=np,
+                    protocol=request.environ.get("SERVER_PROTOCOL"),
+                    headers=request.headers,
                 )
-            call_event = HttpServerRequestEvent(
-                request_method=request.method,
-                path_info=request.path,
-                message_parameters=request_params(request),
-                normalized_path_info=np,
-                protocol=request.environ.get("SERVER_PROTOCOL"),
-                headers=request.headers,
-            )
-            Recorder.add_event(call_event)
-
-            appctx = _app_ctx_stack.top
-            appctx.appmap_request_event = call_event
-            appctx.appmap_request_start = time.monotonic()
+                rec.add_event(call_event)
+
+                appctx = _app_ctx_stack.top
+                appctx.appmap_request_event = call_event
+                appctx.appmap_request_start = time.monotonic()
 
     def after_request(self, response):
-        if self.recording.is_running() and request.path != self.record_url:
-            appctx = _app_ctx_stack.top
-            parent_id = appctx.appmap_request_event.id
-            duration = time.monotonic() - appctx.appmap_request_start
-
-            return_event = HttpServerResponseEvent(
-                parent_id=parent_id,
-                elapsed=duration,
-                status_code=response.status_code,
-                headers=response.headers,
-            )
-            Recorder.add_event(return_event)
+        if request.path == self.record_url:
+            return response
+
+        if Env.current.enabled or self.recording.is_running():
+            # It should be recording or it's currently recording.  The
+            # recording is either
+            # a) remote, enabled by POST to /_appmap/record, which set
+            #    self.recording.is_running, or
+            # b) requests, set by Env.current.record_all_requests, or
+            # c) both remote and requests; there are multiple active recorders.
+            if not Env.current.record_all_requests and self.recording.is_running():
+                # a)
+                self.after_request_main([Recorder()], response)
+            else:
+                # b) or c)
+                rec = Recorder(_EventIds.get_thread_id())
+                recorders = [rec]
+                # Each time an event is added for a thread_id it's
+                # also added to the global Recorder().  So don't add
+                # the global Recorder() into recorders: that would
+                # have added the event in the global Recorder() twice.
+                try:
+                    self.after_request_main(recorders, response)
+                    web_framework.create_appmap_file(
+                        request.method,
+                        request.path,
+                        request.path,
+                        response,
+                        response.headers,
+                        rec,
+                    )
+                finally:
+                    rec.stop_recording()
 
         return response
 
+    def after_request_main(self, recorders, response):
+        for rec in recorders:
+            if rec.enabled:
+                appctx = _app_ctx_stack.top
+                parent_id = appctx.appmap_request_event.id
+                duration = time.monotonic() - appctx.appmap_request_start
+
+                return_event = HttpServerResponseEvent(
+                    parent_id=parent_id,
+                    elapsed=duration,
+                    status_code=response.status_code,
+                    headers=response.headers,
+                )
+                rec.add_event(return_event)
 
 @patch_class(jinja2.Template)
 class TemplateHandler(BaseTemplateHandler):