Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Using a lock inexplicably doesn't protect against multiple profilers #307

Open
datalogics-kam opened this issue Jun 4, 2024 · 0 comments

Comments

@datalogics-kam
Copy link

I'm profiling a FastAPI app, and when I'm doing that, I know that multiple profilers can't have sync enabled. So I figured, I'd protect the profiler with a lock. It'd serialize the calls the front end is doing in parallel, but for profiling, I don't care. So I did:

profiler_lock = asyncio.Lock()


# https://pyinstrument.readthedocs.io/en/latest/guide.html#profile-a-web-request-in-fastapi
@app.middleware("http")
async def profile_request(request: Request, call_next):
    if request.method == "OPTIONS":
        return await call_next(request)
    async with profiler_lock:
        profiler = Profiler(
            interval=0.001, async_mode="enabled"  # settings.profiling_interval,
        )
        with profiler:
            retval = await call_next(request)
        now = datetime.datetime.now().isoformat(timespec="microseconds")  # noqa: DTZ005
        with Path(f"{now}.prof.txt").open("w") as f:
            f.write(profiler.output_text())
        with Path(f"{now}.speedscope.json").open("w") as f:
            f.write(profiler.output(SpeedscopeRenderer()))
    return retval

But still, I get an exception:

  File "/Users/kam/src/dl/pdfassistant-chatbot-async/.venv/lib/python3.11/site-packages/starlette/middleware/base.py", line 191, in __call__
    response = await self.dispatch_func(request, call_next)
               ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/Users/kam/src/dl/pdfassistant-chatbot-async/pdfassistant_chatbot/app.py", line 149, in profile_request
    with profiler:
  File "/Users/kam/src/dl/pdfassistant-chatbot-async/.venv/lib/python3.11/site-packages/pyinstrument/profiler.py", line 207, in __enter__
    self.start(caller_frame=inspect.currentframe().f_back)  # type: ignore
    ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/Users/kam/src/dl/pdfassistant-chatbot-async/.venv/lib/python3.11/site-packages/pyinstrument/profiler.py", line 131, in start
    get_stack_sampler().subscribe(
  File "/Users/kam/src/dl/pdfassistant-chatbot-async/.venv/lib/python3.11/site-packages/pyinstrument/stack_sampler.py", line 62, in subscribe
    raise RuntimeError(
RuntimeError: There is already a profiler running. You cannot run multiple profilers in the same thread or async context, unless you disable async support.

I've tried everything; I've tried print statements, it doesn't appear the locked section is being entered twice.

Am I missing something really dumb, or did I find a subtle interaction between the locking and the profiing?

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

No branches or pull requests

1 participant