sumerc / yappi

Yet Another Python Profiler, but this time multithreading, asyncio and gevent aware.
MIT License
1.41k stars 73 forks source link

failing to capture FastAPI uvicorn threads, only seeing the _MainThread #133

Closed MorAlterya closed 7 months ago

MorAlterya commented 1 year ago

Overview

I tried using yappi (version 1.4.0) to profile my python (3.10) server. I am using FastAPI version 0.88.0 and uvicorn version 0.20.0 , And no matter how I try to run multithreaded-profiling I cannot get yappi to capture anything but the _MainThread thread :( .
All of my actual code runs and produces the logs and results I expect, but cannot find a single call to a function/module of my own code in the profiling results.

I have seen this lone thread (https://github.com/sumerc/yappi/issues/98) that does not relate to my problem, and looked over everything in the docs and saw nothing wrong with that I was doing.

As a module:

I tried using yappi as a module like so:

import yappi
import fastapi

app = FastAPI()
app.include_router(...)

...  # Send out a few requests, see logs of the requests being handled by my code

yappi.start()  # 'profile_threads=True' default value
uvicorn.run("main:app")
yappi.stop()

yappi.get_func_stats().print_all()
yappi.get_threads_stats().print_all()

And get only results about the _MainThread.

Using CLI

I also tried using the CLI usage, so I ran the following command: yappi server/main.py and got the same result.

I KNOW my code runs, but there is not a single mention of it in the profile results :(

Is this a known issue? I went over the issues in this project and saw no mention of my problem.

Using the timing_middleware is not an option, as I need the most indepth profiling results and I can afford to run it this way.
This is not to be used in production, if that changes anything

Thanks in advance! <3

kwuite commented 1 year ago

@MorAlterya

Have you tried returning results first and then executing yappi.stop()?

yappi.start()  # 'profile_threads=True' default value

uvicorn.run("main:app")

yappi.get_func_stats().print_all()
yappi.get_threads_stats().print_all()
yappi.stop()
sumerc commented 1 year ago

@kwuite , it should not make any difference if the profiler is stopped or not.

@MorAlterya , could you please provide an example application that reproduces the problem. In theory, the code you have provided should just work fine, and we have many unit tests confirming it should work. I need to understand what is different in your case. What version of FastAPI, how you run it..etc. A simple example demonstrating this error would be very useful.

MorAlterya commented 1 year ago

The exact configuration I provided produces results for the main thread only, tested it but calling endpoints and not even seeing the output.

FastAPI version: 0.88.0 yappi version: 1.4.0

Our project no longer runs on FastAPI, we moved to a task-based system, and now Yappi works great! We have excellent profiling from threads. Now none of them are created by uvicorn/FastAPI.

davidvoler commented 1 year ago
from fastapi import FastAPI
from uvicorn import Config, Server

import yappi
import sys
import asyncio
import random
from logging import getLogger

logger = getLogger(__name__)
current_module = sys.modules[__name__]
yappi.set_clock_type("WALL") 

app = FastAPI()

async def handle_messages():
    r = random.random()
    # r = 3
    await asyncio.sleep(r)
    logger.error(f"waited for {r} seconds")

async def listener():
    logger.error("listener started")
    while True:
        asyncio.create_task(handle_messages())
        await asyncio.sleep(1)

@app.on_event("startup")
async def startup():
    asyncio.create_task(listener())

@app.get("/")
async def root():
    return {"message": "Hello World"}

@app.get("/stats")
async def stats():
    stats = yappi.get_func_stats(
        filter_callback=lambda x: yappi.module_matches(x, [current_module])
    )
    stats.sort("totaltime", "desc").print_all()
    stats.strip_dirs()
    stats.print_all()
    yappi.clear_stats()
    ret = []
    for s in stats:
        ret.append((s[15],s[3], s[14], s[6]))
    return ret

if __name__ == "__main__":
    with yappi.run():
        config = Config(app)
        server = Server(config)
        server.run()

Save the the above code as main.py The follwing code is working when running : python main.py

But it will not work if you run: uvicorn main:app This make sense as when you run with uvicorn you skip the if name == "main": part

I am happy with this workaround. Will it work for you @MorAlterya ?