Improper error handling for lifespan protocol

[sm-Fifteen]

Describe the bug
FastAPI makes use of the Lifespan protocol internally while starting up. According to the ASGI spec, if the application throws while handling a lifespan message, the server must understand it as the application not supporting that protocol, and errors should instead be signalled using lifespan.startup.error (I don't have the spec open, it might actually be called something else). FastAPI fails to do this, which results in strange error messages and potentially incorrect initialisation based on how the server is configured to react.

To Reproduce
Steps to reproduce the behavior:

1. Create a file with the FastAPI hello world example
2. Launch the server on a port that is already being used by another process (or launch the server twice on the same port) using uvicorn hello:app --host=0.0.0.0 --port=8000
3. Port collision should cause socket binding to throw, see error

The uvicorn server will log that "The lifespan protocol appears unsupported". Depending on the error, and the server configuration, the application may be left running but the server will stop sending lifespan events as a result, so the shutdown event handlers(and possibly any user-defined startup handlers) will not be triggered either.

Expected behavior
FastAPI should correctly notify the server that an error was encountered while handling the lifespan event, and the server should exit after logging a lifespan error.

Environment:

• OS: Windows
• FastAPI Version: 0.38.1
• Python version: 3.6

Additional context
I know Uvicorn will sometimes leave applications running even if the lifespan handler raised an exception (which has happenned to me before and the ASGI spec says servers should allow) but I can't find a way to trigger this right now.

[sm-Fifteen]

I might actually be mixing up Kludex/starlette#488, which was recently fixed and caused a similar error to occur, with an unrelated uvicorn issue that causes it to report the same error in case of port collision regardless of the application.

[euri10]

just to be sure I get it right, here's what I tried with running uvicorn hello:app --host=0.0.0.0 --port=8000 in 2 terminals

1. running command in terminal1:

(celeryasgimon) ➜  celeryasgimon git:(master) ✗ uvicorn hello:app --host=0.0.0.0 --port=8000
email-validator not installed, email fields will be treated as str.
To install, run: pip install email-validator
INFO: Started server process [3411]
INFO: Waiting for application startup.
DEBUG: starting app
INFO: Uvicorn running on http://0.0.0.0:8000 (Press CTRL+C to quit)

2. run same command in terminal 2, it throws the socket error

(celeryasgimon) ➜  celeryasgimon git:(master) ✗ uvicorn hello:app --host=0.0.0.0 --port=8000
email-validator not installed, email fields will be treated as str.
To install, run: pip install email-validator
INFO: Started server process [6762]
INFO: Waiting for application startup.
DEBUG: starting app
Traceback (most recent call last):
  File "/home/lotso/.local/share/virtualenvs/celeryasgimon-mKbgSCbw/bin/uvicorn", line 10, in <module>
    sys.exit(main())
  File "/home/lotso/.local/share/virtualenvs/celeryasgimon-mKbgSCbw/lib/python3.7/site-packages/click/core.py", line 764, in __call__
    return self.main(*args, **kwargs)
  File "/home/lotso/.local/share/virtualenvs/celeryasgimon-mKbgSCbw/lib/python3.7/site-packages/click/core.py", line 717, in main
    rv = self.invoke(ctx)
  File "/home/lotso/.local/share/virtualenvs/celeryasgimon-mKbgSCbw/lib/python3.7/site-packages/click/core.py", line 956, in invoke
    return ctx.invoke(self.callback, **ctx.params)
  File "/home/lotso/.local/share/virtualenvs/celeryasgimon-mKbgSCbw/lib/python3.7/site-packages/click/core.py", line 555, in invoke
    return callback(*args, **kwargs)
  File "/home/lotso/.local/share/virtualenvs/celeryasgimon-mKbgSCbw/lib/python3.7/site-packages/uvicorn/main.py", line 258, in main
    run(**kwargs)
  File "/home/lotso/.local/share/virtualenvs/celeryasgimon-mKbgSCbw/lib/python3.7/site-packages/uvicorn/main.py", line 279, in run
    server.run()
  File "/home/lotso/.local/share/virtualenvs/celeryasgimon-mKbgSCbw/lib/python3.7/site-packages/uvicorn/main.py", line 307, in run
    loop.run_until_complete(self.serve(sockets=sockets))
  File "uvloop/loop.pyx", line 1417, in uvloop.loop.Loop.run_until_complete
  File "/home/lotso/.local/share/virtualenvs/celeryasgimon-mKbgSCbw/lib/python3.7/site-packages/uvicorn/main.py", line 322, in serve
    await self.startup(sockets=sockets)
  File "/home/lotso/.local/share/virtualenvs/celeryasgimon-mKbgSCbw/lib/python3.7/site-packages/uvicorn/main.py", line 377, in startup
    create_protocol, host=config.host, port=config.port, ssl=config.ssl
  File "uvloop/loop.pyx", line 1686, in create_server
OSError: [Errno 98] error while attempting to bind on address ('0.0.0.0', 8000): address already in use

3. back at terminal 1, I hit Ctrl+C, below is the full log, I see well the shutdown event, which you said wasnt triggered, is there anything in your description I misread ? :

(celeryasgimon) ➜  celeryasgimon git:(master) ✗ uvicorn hello:app --host=0.0.0.0 --port=8000
email-validator not installed, email fields will be treated as str.
To install, run: pip install email-validator
INFO: Started server process [3411]
INFO: Waiting for application startup.
DEBUG: starting app
INFO: Uvicorn running on http://0.0.0.0:8000 (Press CTRL+C to quit)
^CINFO: Shutting down
INFO: Waiting for application shutdown.
DEBUG: shutdown app
INFO: Finished server process [3411]

[sm-Fifteen]

Yes, in my case (on the Windows machine I'm currently using), Uvicorn in terminal 2 exits immediately with the following output.

$ uvicorn hello:app --host=0.0.0.0 --port=8000

email-validator not installed, email fields will be treated as str.
To install, run: pip install email-validator
INFO: Started server process [15384]
INFO: Waiting for application startup.
Traceback (most recent call last):
  File "C:\Python36\lib\asyncio\base_events.py", line 1045, in create_server
    sock.bind(sa)
OSError: [WinError 10048] Une seule utilisation de chaque adresse de socket (protocole/adresse r▒seau/port) est habituellement autoris▒e

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "c:\users\Th▒odore\Documents\prog\fastapi-test\.pyenv\Scripts\uvicorn-script.py", line 11, in <module>
    load_entry_point('uvicorn==0.8.6', 'console_scripts', 'uvicorn')()
  File "c:\users\Th▒odore\documents\prog\fastapi-test\.pyenv\lib\site-packages\click\core.py", line 764, in __call__
    return self.main(*args, **kwargs)
  File "c:\users\Th▒odore\documents\prog\fastapi-test\.pyenv\lib\site-packages\click\core.py", line 717, in main
    rv = self.invoke(ctx)
  File "c:\users\Th▒odore\documents\prog\fastapi-test\.pyenv\lib\site-packages\click\core.py", line 956, in invoke
    return ctx.invoke(self.callback, **ctx.params)
  File "c:\users\Th▒odore\documents\prog\fastapi-test\.pyenv\lib\site-packages\click\core.py", line 555, in invoke
    return callback(*args, **kwargs)
  File "c:\users\Th▒odore\documents\prog\fastapi-test\.pyenv\lib\site-packages\uvicorn\main.py", line 258, in main
    run(**kwargs)
  File "c:\users\Th▒odore\documents\prog\fastapi-test\.pyenv\lib\site-packages\uvicorn\main.py", line 279, in run
    server.run()
  File "c:\users\Th▒odore\documents\prog\fastapi-test\.pyenv\lib\site-packages\uvicorn\main.py", line 307, in run
    loop.run_until_complete(self.serve(sockets=sockets))
  File "C:\Python36\lib\asyncio\base_events.py", line 468, in run_until_complete
    return future.result()
  File "c:\users\Th▒odore\documents\prog\fastapi-test\.pyenv\lib\site-packages\uvicorn\main.py", line 322, in serve
    await self.startup(sockets=sockets)
  File "c:\users\Th▒odore\documents\prog\fastapi-test\.pyenv\lib\site-packages\uvicorn\main.py", line 377, in startup
    create_protocol, host=config.host, port=config.port, ssl=config.ssl
  File "C:\Python36\lib\asyncio\base_events.py", line 1049, in create_server
    % (sa, err.strerror.lower()))
OSError: [Errno 10048] error while attempting to bind on address ('0.0.0.0', 8000): une seule utilisation de chaque adresse de socket (protocole/adresse r▒seau/port) est habituellement autoris▒e
ERROR: Task was destroyed but it is pending!
task: <Task pending coro=<LifespanOn.main() running at c:\users\Th▒odore\documents\prog\fastapi-test\.pyenv\lib\site-packages\uvicorn\lifespan\on.py:44> wait_for=<Future pending cb=[<TaskWakeupMethWrapper object at 0x0000019248B3EF78>()]>>
INFO: ASGI 'lifespan' protocol appears unsupported.

I've done some further testing and uvicorn throws the same error with a simple ASGI lifespan handler, so this issue might actually not be related to FastAPI at all, my bad.

async def app(scope, receive, send):
    if scope['type'] == 'lifespan':
        while True:
            message = await receive()
            if message['type'] == 'lifespan.startup':
                # Do some startup here!
                await send({'type': 'lifespan.startup.complete'})
            elif message['type'] == 'lifespan.shutdown':
                # Do some shutdown here!
                await send({'type': 'lifespan.shutdown.complete'})
                return
    else:
        pass # Handle other types

[euri10]

interesting, I've seen but can't remember right now some issues related to windows and uvicor.
will post if I find it again, bonne chance

[sm-Fifteen]

Closing, since this is a Uvicorn bug, not a FastAPI bug (see Kludex/uvicorn#435).

[github-actions[bot]]

Assuming the original need was handled, this will be automatically closed now. But feel free to add more comments or create new issues or PRs.