Remote and requests 20221026 #190
Conversation
Change the default log level to INFO. Downgrade some messages from INFO to DEBUG. This change means the user will now see the initial record-by-default message, but it will be labeled INFO instead of (the scary looking WARNING.
apotterri
requested review from
dividedmind and
symwell
and removed request for
symwell
symwell
left a comment
symwell
left a comment
There was a problem hiding this comment.
Lots of good stuff for appmap-python! A couple of questions to understand the design better.
appmap/_implementation/recorder.py
Outdated
| """ | ||
|
|
||
| _lock = threading.Lock() | ||
| _lock = threading.RLock() |
There was a problem hiding this comment.
It may be worth explaining in a comment how the non re-entrancy lead to what this suggests to have been a deadlock. How did a thread, after acquiring this lock, called code that tried to acquire the lock again?
There was a problem hiding this comment.
Good catch. Using an RLock here was a holdover from a previous attempt to fix this problem. It's no longer necessary, so I've switched back to Lock.
| _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 |
There was a problem hiding this comment.
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?
There was a problem hiding this comment.
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?
There was a problem hiding this comment.
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.
There was a problem hiding this comment.
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.
There was a problem hiding this comment.
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
There was a problem hiding this comment.
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.
symwell
left a comment
symwell
left a comment
There was a problem hiding this comment.
Django/Flask _appmap/record endpoints don't work for me.
With these changes, remote recording and per-request recording no longer interfere with one another.
apotterri
force-pushed
the
remote-and-requests_20221026
branch
from
c2400e0 to
521a910
Compare
With these changes, remote recording and per-request recording no longer
interfere with one another.
Fixes getappmap/board#203.