Uvicorn: Misleading logs during application startup

[RobertoPrevato]

Hi,
When running an application with Uvicorn, logs are a bit misleading, especially when running with "INFO" log level.

Because Waiting for application startup. is logged before lifespan.startup with INFO level, but no information is logged to signal the end of application startup, giving the idea that the application is stuck at startup event. 'lifespan.startup.complete' can be seen using DEBUG level.

No information is logged to signal when the underlying application is ready to handle requests.

For example:

$ uvicorn server:app --port 44777 --reload --log-level info

INFO: Uvicorn running on http://127.0.0.1:44777 (Press CTRL+C to quit)
INFO: Started reloader process [8402]
INFO: Started server process [8406]
INFO: Waiting for application startup.  # <-- nothing is logged after this point; the user might think the application is not ready, yet

Would you accept a PR to signal with info level when application startup completes? I ask because I already have a PR open and I don't want to look annoying.

[tomchristie]

Yes please!

Let's get the messaging tweaked to this:

INFO: Waiting for application startup...
INFO: ...application startup complete.

[RobertoPrevato]

Sorry, @tomchristie, for not contributing on this one. I really wanted to, but I had no time lately.

[tomchristie]

S'all good 😀👍