Skip to content
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
3 changes: 2 additions & 1 deletion appmap/_implementation/__init__.py
Original file line number Diff line number Diff line change
@@ -1,6 +1,6 @@
from . import configuration
from . import env as appmapenv
from . import event, importer, metadata, recorder
from . import event, importer, metadata, recorder, web_framework
from .py_version_check import check_py_version


Expand All @@ -12,6 +12,7 @@ def initialize(**kwargs):
recorder.initialize()
configuration.initialize() # needs to be initialized after recorder
metadata.initialize()
web_framework.initialize()


initialize()
2 changes: 1 addition & 1 deletion appmap/_implementation/configuration.py
Original file line number Diff line number Diff line change
Expand Up @@ -218,7 +218,7 @@ def _load_config(self):
Env.current.enabled = should_enable
except ParserError:
pass
logger.info("config: %s", self._config)
logger.debug("config: %s", self._config)
return

if not Env.current.enabled:
Expand Down
34 changes: 34 additions & 0 deletions appmap/_implementation/django.py
Original file line number Diff line number Diff line change
@@ -0,0 +1,34 @@
"""
This file contains Django middleware that can be inserted into an app's stack to expose the remote
recording endpoint.

It expects the importer to have verified that Django is available.
"""

from http import HTTPStatus

from django.http import HttpRequest, HttpResponse

from . import remote_recording


class RemoteRecording: # pylint: disable=missing-class-docstring
def __init__(self, get_response):
super().__init__()
self.get_response = get_response

def __call__(self, request: HttpRequest):
if request.path != "/_appmap/record":
return self.get_response(request)

handlers = {
"GET": remote_recording.status,
"POST": remote_recording.start,
"DELETE": remote_recording.stop,
}

def not_allowed():
return "", HTTPStatus.METHOD_NOT_ALLOWED

body, status = handlers.get(request.method, not_allowed)()
return HttpResponse(body, status=status, content_type="application/json")
2 changes: 1 addition & 1 deletion appmap/_implementation/env.py
Original file line number Diff line number Diff line change
Expand Up @@ -80,7 +80,7 @@ def display_params(self):
return self.get("APPMAP_DISPLAY_PARAMS", "true").lower() == "true"

def _configure_logging(self):
log_level = self.get("APPMAP_LOG_LEVEL", "warning").upper()
log_level = self.get("APPMAP_LOG_LEVEL", "info").upper()

log_config = self.get("APPMAP_LOG_CONFIG")
log_stream = self.get("APPMAP_LOG_STREAM", "stderr")
Expand Down
3 changes: 2 additions & 1 deletion appmap/_implementation/event.py
Original file line number Diff line number Diff line change
@@ -1,3 +1,4 @@
# pylint: disable=missing-module-docstring,missing-class-docstring,missing-function-docstring
import inspect
import logging
import threading
Expand Down Expand Up @@ -90,7 +91,7 @@ class Event:
__slots__ = ["id", "event", "thread_id"]

def __init__(self, event):
self.id = Recorder.get_current().next_event_id()
self.id = Recorder.next_event_id()
self.event = event
self.thread_id = _EventIds.get_thread_id()

Expand Down
45 changes: 18 additions & 27 deletions appmap/_implementation/flask.py
Original file line number Diff line number Diff line change
@@ -1,39 +1,30 @@
""" remote_recording is a Flask app that can be mounted to expose the remote-recording endpoint. """
import json
"""
This file contains a Flask app that is mounted on /_appmap to expose the remote-recording endpoint
in a user's app.

from flask import Flask
It should only be imported if other code has already verified that Flask is available.
"""

from . import generation
from .recorder import Recorder
from .web_framework import AppmapMiddleware
from flask import Flask, Response

remote_recording = Flask(__name__)
from . import remote_recording

app = Flask(__name__)

@remote_recording.route("/record", methods=["GET"])
def status():
if not AppmapMiddleware.should_record():
return "Appmap is disabled.", 404

return {"enabled": Recorder.get_current().get_enabled()}
@app.route("/record", methods=["GET"])
def status():
body, rrstatus = remote_recording.status()
return Response(body, status=rrstatus, mimetype="application/json")


@remote_recording.route("/record", methods=["POST"])
@app.route("/record", methods=["POST"])
def start():
r = Recorder.get_current()
if r.get_enabled():
return "Recording is already in progress", 409

r.start_recording()
return "", 200
body, rrstatus = remote_recording.start()
return Response(body, status=rrstatus, mimetype="application/json")


@remote_recording.route("/record", methods=["DELETE"])
@app.route("/record", methods=["DELETE"])
def stop():
r = Recorder.get_current()
if not r.get_enabled():
return "No recording is in progress", 404

r.stop_recording()

return json.loads(generation.dump(r))
body, rrstatus = remote_recording.stop()
return Response(body, status=rrstatus, mimetype="application/json")
2 changes: 1 addition & 1 deletion appmap/_implementation/importer.py
Original file line number Diff line number Diff line change
Expand Up @@ -187,7 +187,7 @@ def instrument_functions(filterable):
if not cls.filter_chain.filter(filterable):
return

logger.info(" looking for members of %s", filterable.obj)
logger.debug(" looking for members of %s", filterable.obj)
functions = get_members(filterable.obj)
logger.debug(" functions %s", functions)

Expand Down
2 changes: 1 addition & 1 deletion appmap/_implementation/instrument.py
Original file line number Diff line number Diff line change
Expand Up @@ -109,7 +109,7 @@ def call_instrumented(f, instance, args, kwargs):

def instrument(filterable):
"""return an instrumented function"""
logger.info("hooking %s", filterable.fqname)
logger.debug("hooking %s", filterable.fqname)
fn = filterable.obj

make_call_event = event.CallEvent.make(fn, filterable.fntype)
Expand Down
70 changes: 46 additions & 24 deletions appmap/_implementation/recorder.py
Original file line number Diff line number Diff line change
Expand Up @@ -7,6 +7,7 @@

logger = logging.getLogger(__name__)

# pylint: disable=global-statement
_default_recorder = None


Expand All @@ -22,10 +23,14 @@ class Recorder(ABC):
def events(self):
return self._events

@abstractmethod
def next_event_id(self):
self._next_event_id += 1
return self._next_event_id
_next_event_id = 0
_next_event_id_lock = threading.Lock()

@classmethod
def next_event_id(cls):
with cls._next_event_id_lock:
cls._next_event_id += 1
return cls._next_event_id
Comment on lines +26 to +33
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

What was the interference of remote requests with remote recording?

Was part of it a race condition over event ids? If event ids are unique per thread then why put them behind a lock?

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

There were three two aspects to the interference:

  • remote recording and per-request recording were both trying to use Recorder.get_current().enabled to manage the state of remote recording
  • new event ids weren't getting issued properly

I fixed the first by tracking the state of remote recording with a ContextVar with a boolean value. I also simplified the code somewhat by separating it from the middleware that captures http_server events.

I fixed the second by having the next event id be global (it's a class variable of Recorder, which is why there's locking around updating it). Careful management of resetting it meant that no tests need to change. That management probably also means it's a bit fragile, but perhaps that an issue for another time.

One thing that might be surprising about this PR: there aren't any updates for the expected AppMaps. This is actually because of the problem identified with AppMap correctness: the only route in the test Flask app is implemented as a function in module , so it doesn't show up in the recordings.

WDYT, does it seem worth adding a test that show enabling both kinds of recording results in a proper AppMap?

Copy link
Contributor

@symwell symwell Nov 7, 2022

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I think

  • this pr is worth shipping as is. It fixes an observed problem.
  • it's worth adding a low priority issue to revisit event ids. If event ids are unique per thread then it appears possible to not need a global lock for event ids. At this point this looks like an optimization, so it doesn't appear like a priority.

I think test_record_request_appmap_enabled_requests_enabled_and_remote collects both kinds of recording results. I wonder if at least one of the many threads there contains data collected for remote recording. Maybe all it needs is an assert or two in record_request_thread.

Edit: after trying locally (by not deleting requests appmaps) I only see "name":"record_requests". I don't see "name":"record_remote". This test may be hard to write. It's strange there's no appmap on my local disk for remote.

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Event ids are not unique per-thread. They're global, so the lock is required.

I'll push a fixup commit with the other changes shortly.

Copy link
Contributor

@symwell symwell Nov 7, 2022

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

This doesn't work for Django for me:

APPMAP=true APPMAP_RECORD_REQUESTS=true APPMAP_OUTPUT_DIR=/tmp python3 manage.py runserver 0.0.0.0:8000

curl -s localhost:8000/_appmap/record

The _appmap/record doesn't exist.

It doesn't work for Flask either:

APPMAP=true APPMAP_RECORD_REQUESTS=true APPMAP_OUTPUT_DIR=/tmp  FLASK_DEBUG=1 FLASK_APP=app.py flask run -p 8000

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Try running it like this:

PYTHONPATH=init APPMAP=true APPMAP_RECORD_REQUESTS=true APPMAP_OUTPUT_DIR=/tmp  FLASK_DEBUG=1 FLASK_APP=app.py flask run -p 8000

Setting PYTHONPATH here simulates what happens when the package is really installed.


# It might be nice to put @property on the getters here. The python maintainers have gone back
# and forth on whether you should be able to combine @classmethod and @property. In 3.11,
Expand All @@ -44,24 +49,40 @@ def set_current(cls, r):
"""
Set the recorder for the current thread.
"""
appmap_tls()[cls._RECORDER_KEY] = r
tls = appmap_tls()
if r:
tls[cls._RECORDER_KEY] = r
else:
del tls[cls._RECORDER_KEY]

return r

@classmethod
def get_global(cls):
_, shared = cls._get_current()
return shared

@classmethod
def new_global(cls):
global _default_recorder
_default_recorder = SharedRecorder()
return _default_recorder

@classmethod
def get_enabled(cls):
return cls.get_current()._enabled
return cls.get_current()._enabled # pylint: disable=protected-access

@classmethod
def set_enabled(cls, e):
cls.get_current()._enabled = e
cls.get_current()._enabled = e # pylint: disable=protected-access

@classmethod
def start_recording(cls):
cls.get_current()._start_recording()
cls.get_current()._start_recording() # pylint: disable=protected-access

@classmethod
def stop_recording(cls):
return cls.get_current()._stop_recording()
return cls.get_current()._stop_recording() # pylint: disable=protected-access

@classmethod
def add_event(cls, event):
Expand All @@ -70,28 +91,25 @@ def add_event(cls, event):
one).
"""
perthread, shared = cls._get_current()
shared._add_event(event)
shared._add_event(event) # pylint: disable=protected-access
if perthread:
perthread._add_event(event)
perthread._add_event(event) # pylint: disable=protected-access

_RECORDER_KEY = "appmap_recorder"

@classmethod
def _get_current(cls):
global _default_recorder
perthread = appmap_tls().get(cls._RECORDER_KEY, None)

return [perthread, _default_recorder]

def clear(self):
self._events = []
self._next_event_id = 0

def __init__(self, enabled=False):
self._events = []
self._enabled = enabled
self.start_tb = None
self._next_event_id = 0

@abstractmethod
def _start_recording(self):
Expand Down Expand Up @@ -122,8 +140,7 @@ def _initialize():
threads initializing the default recorder. If you find yourself wanting to do that, you
should probably be using per-thread recording.
"""
global _default_recorder
_default_recorder = SharedRecorder()
Recorder.new_global()


class ThreadRecorder(Recorder):
Expand All @@ -135,9 +152,8 @@ class ThreadRecorder(Recorder):
def events(self):
return super().events

def next_event_id(self):
return super().next_event_id()

# They're not useless, because they're abtract with a default implementation
# pragma pylint: disable=useless-super-delegation
def _start_recording(self):
super()._start_recording()

Expand All @@ -147,6 +163,8 @@ def _stop_recording(self):
def _add_event(self, event):
super()._add_event(event)

# pragma pylint: enable=useless-super-delegation


class SharedRecorder(Recorder):
"""
Expand All @@ -155,6 +173,14 @@ class SharedRecorder(Recorder):

_lock = threading.Lock()

def __init__(self):
super().__init__()
Recorder._next_event_id = 0

def clear(self):
super().clear()
Recorder._next_event_id = 0

@property
def events(self):
with self._lock:
Expand All @@ -168,14 +194,10 @@ def _stop_recording(self):
with self._lock:
return super()._stop_recording()

def next_event_id(self):
with self._lock:
return super().next_event_id()

def _add_event(self, event):
with self._lock:
super()._add_event(event)


def initialize():
Recorder._initialize()
Recorder._initialize() # pylint: disable=protected-access
46 changes: 46 additions & 0 deletions appmap/_implementation/remote_recording.py
Original file line number Diff line number Diff line change
@@ -0,0 +1,46 @@
""" remote_recording is a Flask app that can be mounted to expose the remote-recording endpoint. """
import json
from threading import Lock

from . import generation
from .detect_enabled import DetectEnabled
from .recorder import Recorder

# pylint: disable=global-statement
_enabled_lock = Lock()
_enabled = False


def status():
if not DetectEnabled.should_enable("remote"):
return "Appmap is disabled.", 404

with _enabled_lock:
return json.dumps({"enabled": _enabled}), 200


def start():
global _enabled
with _enabled_lock:
if _enabled:
return "Recording is already in progress", 409

Recorder.new_global().start_recording()
_enabled = True
return "", 200


def stop():
global _enabled
with _enabled_lock:
if not _enabled:
return "No recording is in progress", 404
r = Recorder.get_global()
r.stop_recording()
_enabled = False
return generation.dump(r), 200


def initialize():
global _enabled
_enabled = False
Loading