pgjones / hypercorn

Hypercorn is an ASGI and WSGI Server based on Hyper libraries and inspired by Gunicorn.
MIT License
1.16k stars 105 forks source link

SSL shutdown timed out #202

Open adam-pawluczuk opened 8 months ago

adam-pawluczuk commented 8 months ago

Hello.

When I use httpx along hypercorn served app, I'm getting "SSL shutdown timed out" traceback.

Hypercorn: 0.16.0 Python: 3.11.5 and 3.12.0

The simplest server-side script to demonstrate:

# server.py
import asyncio

from hypercorn.asyncio import serve
from hypercorn.config import Config
from fastapi import FastAPI

app = FastAPI()

@app.get("/ping")
async def ping():
    return "pong"

config = Config.from_mapping({
    "bind": ["[::]:8080"],
    "certfile": "cert.pem",
    "keyfile": "key.pem",
})

shutdown_event = asyncio.Event()
asyncio.run(serve(app, config, shutdown_trigger=shutdown_event.wait))

I generated a self-signed certificate as follows (this is rather not related to the issue - just an information):

openssl req -x509 -newkey rsa:4096 -keyout key.pem -out cert.pem -sha256 -days 3650 -nodes -subj "/C=XX/ST=StateName/L=CityName/O=CompanyName/OU=CompanySectionName/CN=CommonNameOrHostname"

The client side example:

# client.py
import httpx
import asyncio
from ssl import create_default_context, Purpose

ssl_context = create_default_context(
    purpose=Purpose.SERVER_AUTH, cafile="cert.pem"
)
# Disable hostname checking
ssl_context.check_hostname = False

async def run():
    async with httpx.AsyncClient(verify=ssl_context) as client:
        await client.get("https://localhost:8080/ping")
        # Wait so the connection doesn't get closed by the client before 30s passes
        await asyncio.sleep(35)

asyncio.run(run())

To repro:

  1. Run the server.py.
  2. Run client.py and wait until it finishes (~35s).
  3. Press Ctrl+C and the traceback is visible.
KeyboardInterrupt
Task exception was never retrieved
future: <Task finished name='Task-6' coro=<worker_serve.<locals>._server_callback() done, defined at /Users/apawlucz/opt/anaconda3/envs/rd_312/lib/python3.12/site-packages/hypercorn/asyncio/run.py:112> exception=TimeoutError('SSL shutdown timed out')>
Traceback (most recent call last):
  File "/Users/apawlucz/opt/anaconda3/envs/rd_312/lib/python3.12/site-packages/hypercorn/asyncio/run.py", line 120, in _server_callback
    await TCPServer(app, loop, config, context, reader, writer)
  File "/Users/apawlucz/opt/anaconda3/envs/rd_312/lib/python3.12/site-packages/hypercorn/asyncio/tcp_server.py", line 80, in run
    await self._close()
  File "/Users/apawlucz/opt/anaconda3/envs/rd_312/lib/python3.12/site-packages/hypercorn/asyncio/tcp_server.py", line 127, in _close
    await self.writer.wait_closed()
  File "/Users/apawlucz/opt/anaconda3/envs/rd_312/lib/python3.12/asyncio/streams.py", line 349, in wait_closed
    await self._protocol._get_close_waiter(self)
TimeoutError: SSL shutdown timed out

Alternative is to do steps 1 and 2 and just wait until garbage collection occurs and this traceback occurs.

Another alternative is to use gc.collect() manually so the traceback pops up much faster (no need for Ctrl+C):

import asyncio
import gc
from anyio import create_task_group

from hypercorn.asyncio import serve
from hypercorn.config import Config
from fastapi import FastAPI

app = FastAPI()

@app.get("/ping")
async def ping():
    return "pong"

config = Config.from_mapping({
    "bind": ["[::]:8080"],
    "certfile": "cert.pem",
    "keyfile": "key.pem",
})

async def run():
    shutdown_event = asyncio.Event()
    async def hypercorn_serve():
        await serve(app, config, shutdown_trigger=shutdown_event.wait)

    async with create_task_group() as tg:
        tg.start_soon(hypercorn_serve)
        while True:
            gc.collect()
            await asyncio.sleep(5)

asyncio.run(run())

I'm not quite sure where the 30s timeout comes from - most probably somewhere in asyncio.

This issue does not happen on Python 3.8, 3.9 and 3.10

Only Python 3.11 & 3.12 are affected.

I think this might be related to custom TaskGroup implementation in hypercorn, which is being used for 3.8-3.10, but not for >=3.11.

pgjones commented 5 months ago

SSL Shutdown timeouts was only added in 3.11, I don't know why it would timeout though. Does it also timeout with other http clients e.g. aiohttp?

WillPiledriver commented 2 months ago

SSL Shutdown timeouts was only added in 3.11, I don't know why it would timeout though. Does it also timeout with other http clients e.g. aiohttp?

Just tested it with aiohttp, same issue. Python 3.12.5

transport: <asyncio.sslproto._SSLProtocolTransport object at 0x7f7914be0dd0>
Traceback (most recent call last):
  File "/usr/local/lib/python3.12/site-packages/hypercorn/asyncio/run.py", line 110, in _server_callback
    await TCPServer(app, loop, config, context, lifespan_state, reader, writer)
  File "/usr/local/lib/python3.12/site-packages/hypercorn/asyncio/tcp_server.py", line 76, in run
    await self._close()
  File "/usr/local/lib/python3.12/site-packages/hypercorn/asyncio/tcp_server.py", line 119, in _close
    await self.writer.wait_closed()
  File "/usr/lib64/python3.12/asyncio/streams.py", line 364, in wait_closed
    await self._protocol._get_close_waiter(self)
TimeoutError: SSL shutdown timed out

I just added TimeoutError to the except on line 125 of tcp_server.py to suppress the error