When on_shutdown function raises error, starlette doesn't catch it and uvicorn thinks that lifespan is not supported

[mvolfik]

Checklist

• The bug is reproducible against the latest release and/or master.
• There are no similar issues or pull requests to fix it yet.

Describe the bug

When one of the on_shutdown functions raises an error

To reproduce

from starlette.applications import Starlette

async def fail():
    raise Exception()

app = Starlette(on_shutdown=[fail])

(Doesn't matter if the function is async or not)

uvicorn app:app --log-level trace

Expected behavior

The exception is caught, reported, and Starlette shuts down properly

Actual behavior

Logs:

INFO:     Started server process [22310]
INFO:     Waiting for application startup.
TRACE:    ASGI [1] Started scope={'type': 'lifespan', 'asgi': {'version': '3.0', 'spec_version': '2.0'}}
TRACE:    ASGI [1] Receive {'type': 'lifespan.startup'}
TRACE:    ASGI [1] Send {'type': 'lifespan.startup.complete'}
INFO:     Application startup complete.
INFO:     Uvicorn running on http://127.0.0.1:8000 (Press CTRL+C to quit)
^C
INFO:     Shutting down
INFO:     Waiting for application shutdown.
TRACE:    ASGI [1] Receive {'type': 'lifespan.shutdown'}
TRACE:    ASGI [1] Raised exception
INFO:     ASGI 'lifespan' protocol appears unsupported.
INFO:     Application shutdown complete.
INFO:     Finished server process [22310]

Note that the TRACE messages are hidden, and all that is printed is "ASGI 'lifespan' protocol appears unsupported."

Debugging material

When I run uvicorn with --lifespan on, these logs appear:

INFO:     Started server process [22568]
INFO:     Waiting for application startup.
TRACE:    ASGI [1] Started scope={'type': 'lifespan', 'asgi': {'version': '3.0', 'spec_version': '2.0'}}
TRACE:    ASGI [1] Receive {'type': 'lifespan.startup'}
TRACE:    ASGI [1] Send {'type': 'lifespan.startup.complete'}
INFO:     Application startup complete.
INFO:     Uvicorn running on http://127.0.0.1:8000 (Press CTRL+C to quit)
^C
INFO:     Shutting down
INFO:     Waiting for application shutdown.
TRACE:    ASGI [1] Receive {'type': 'lifespan.shutdown'}
TRACE:    ASGI [1] Raised exception
ERROR:    Exception in 'lifespan' protocol
Traceback (most recent call last):
  File "/tmp/issue/env/lib/python3.8/site-packages/uvicorn/lifespan/on.py", line 55, in main
    await app(scope, self.receive, self.send)
  File "/tmp/issue/env/lib/python3.8/site-packages/uvicorn/middleware/proxy_headers.py", line 45, in __call__
    return await self.app(scope, receive, send)
  File "/tmp/issue/env/lib/python3.8/site-packages/uvicorn/middleware/message_logger.py", line 65, in __call__
    raise exc from None
  File "/tmp/issue/env/lib/python3.8/site-packages/uvicorn/middleware/message_logger.py", line 61, in __call__
    await self.app(scope, inner_receive, inner_send)
  File "/tmp/issue/env/lib/python3.8/site-packages/starlette/applications.py", line 112, in __call__
    await self.middleware_stack(scope, receive, send)
  File "/tmp/issue/env/lib/python3.8/site-packages/starlette/middleware/errors.py", line 146, in __call__
    await self.app(scope, receive, send)
  File "/tmp/issue/env/lib/python3.8/site-packages/starlette/exceptions.py", line 58, in __call__
    await self.app(scope, receive, send)
  File "/tmp/issue/env/lib/python3.8/site-packages/starlette/routing.py", line 569, in __call__
    await self.lifespan(scope, receive, send)
  File "/tmp/issue/env/lib/python3.8/site-packages/starlette/routing.py", line 540, in lifespan
    async for item in self.lifespan_context(app):
  File "/tmp/issue/env/lib/python3.8/site-packages/starlette/routing.py", line 483, in default_lifespan
    await self.shutdown()
  File "/tmp/issue/env/lib/python3.8/site-packages/starlette/routing.py", line 528, in shutdown
    handler()
  File "./app.py", line 5, in fail
    raise Exception()
Exception
INFO:     Application shutdown complete.
INFO:     Finished server process [22568]

Environment

• OS: Ubuntu 20.04.1 LTS
• Python version: 3.8.5

click==7.1.2
h11==0.12.0
starlette==0.14.2
uvicorn==0.13.3

Additional context

Somebody likely ran into this here: https://stackoverflow.com/q/64512286/7292139

[euri10]

Note also that shutdown.failed is not implemented in uvicorn , PR exists though

encode/uvicorn#752

Not sure that would help anyway since starlette doesn't make use of it.

[Kludex]

A quick update: actually is encode/uvicorn#755. Which is already merged.

But as @euri10 said, it doesn't help as starlette doesn't make use of it.

[koffie]

A workaround that I use in the mean time is just adding the middleware to correctly deal with lifespan events yourself.
I was first going to say that ASGI was designed to make such things relatively simple, but coming up with the following workaround wasn't that straight forward.

from starlette.applications import Starlette
from starlette.requests import Request
from starlette.responses import JSONResponse, Response
from starlette.routing import Route

class ReceiveWrapper:
    def __init__(self, receive):
        self.receive = receive
        self.message_queue = []
        self.last_message = None

    async def __call__(self):
        if self.message_queue:
            message = self.message_queue.pop()
        else:
            message = await self.receive()
        self.last_message = message
        return message

    def add_message(self, message):
        self.message_queue.append(message)


async def app(scope, receive, send):
    if scope['type'] == 'lifespan':
        new_receive = ReceiveWrapper(receive)
        while True:
            message = await receive()
            new_receive.add_message(message)
            type = message['type']
            try:
                await star_app(scope, new_receive, send)
            except RuntimeError as err:

                if new_receive.last_message:
                    type = new_receive.last_message["type"]
                if type == 'lifespan.startup':
                    await send({'type': 'lifespan.startup.failed',
                                'message': f'The following error was raised during startup:\n {repr(err)}'})
                elif type == 'lifespan.shutdown':
                    await send({'type': 'lifespan.shutdown.failed',
                                'message': f'The following error was raised during shutdown:\n {repr(err)}'})
                return

    else:
        return await star_app(scope, receive, send)


async def lifespan(_app):
    yield
    raise RuntimeError


async def health(_request: Request) -> JSONResponse:
    json_body = {"running": True}
    return JSONResponse(json_body, status_code=200)


routes = [
    Route("/", health)
]

star_app = Starlette(routes=routes, lifespan=lifespan)

People with a better understanding of ASGI then me could probably make this more elegant. But using uvicorn where encode/uvicorn#755 is merged I now get using the above:

INFO:     Uvicorn running on http://0.0.0.0:8000 (Press CTRL+C to quit)
INFO:     Started reloader process [19604] using watchgod
INFO:     Started server process [19606]
INFO:     Waiting for application startup.
INFO:     Application startup complete.
^CINFO:     Shutting down
INFO:     Waiting for application shutdown.
ERROR:    The following error was raised during shutdown:
 RuntimeError()
ERROR:    Application shutdown failed. Exiting.
INFO:     Finished server process [19606]
INFO:     Stopping reloader process [19604]