The lightning-fast ASGI server. ?

There seems to be some weird issue with pipelining and or connection reuse and nginx. I have nginx sitting in front of my uvicorn/starlette app, and on patch/post requests I occasionally get 502's from nginx (about 30-40% of the time). The nginx logs say:

upstream prematurely closed connection while reading response header from upstream

all over the place

and my app logs say:

WARNING: Invalid HTTP request received.
WARNING: Invalid HTTP request received.

with not much more information.

I forced connection reuse to not work by adding the default header Connection: close, which forces nginx to kill the connection. Performance drops significantly, but at least I don't get 502's.

uvicorn.run(app, host='0.0.0.0', port=8445, headers=[('Server', 'custom'), ('Connection', 'close')], proxy_headers=True)

potentially relevant: the 502 doesn't seem to ever happen on a GET

Checklist

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

Describe the bug

I'm developing a FastApi application deployed on a Kubernetes cluster using gunicorn as process manager.

I'm also using UvicornWorkers for sure, because of the async nature of fastapi.

After the application deployment I can see the memory growing up at rest, until OOM.

This happen just when I use UvicornWorker.

Tests made by me:

• Comment all my code to ensure is not a my application mem leak (leak present);
• Start the application using uvicorn instead of gunicorn (no leak present);
• Start application using gunicorn sync workers (no leak present);
• Start application using gunicorn + UvicornWorker (leak present);
• Start application using gunicorn + UvicornWorker + max_requests (leak present);

Plus, this happens just on the Kubernetes cluster, when I run my application locally (MacBook pro 16) (is the same docker image used on k8s) the leak is not present.

Anyone else had a similar problem?

Describe the bug Uvicorn doesn't seem to be able to start with multiple workers.

Code snippet Starlette Hello World

import uvicorn as uvicorn
from starlette.applications import Starlette
from starlette.responses import JSONResponse

app = Starlette(debug=True)


@app.route('/')
async def homepage(request):
    return JSONResponse({'hello': 'world'})


if __name__ == '__main__':
    uvicorn.run(app, host='127.0.0.1', port=8000, workers=2)

Expected behavior

Uvicorn starts and is ready to serve with multiple workers.

Environment

Windows 10 Uvicorn: 0.6.1 Python: 3.7.2 Starlette: 0.11.4

Additional context

(venv) C:\Users\marodev\source\repos\StarletteHelloWorldVirtualEnvPy37>python main.py

INFO: Uvicorn running on http://127.0.0.1:8000 (Press CTRL+C to quit)
INFO: Started parent process [35788]

Traceback (most recent call last):

  File "main.py", line 14, in <module>
    uvicorn.run(app, host='127.0.0.1', port=8000, workers=2)
	
  File "C:\Users\marodev\source\repos\StarletteHelloWorldVirtualEnvPy37\venv\lib\site-packages\uvicorn\main.py", line 274, in run
    supervisor.run(server.run, sockets=[socket])
	
  File "C:\Users\marodev\source\repos\StarletteHelloWorldVirtualEnvPy37\venv\lib\site-packages\uvicorn\supervisors\multiprocess.py", line 33, in run
    process.start()
	
  File "C:\Users\marodev\AppData\Local\Programs\Python\Python37\lib\multiprocessing\process.py", line 112, in start
    self._popen = self._Popen(self)
	
  File "C:\Users\marodev\AppData\Local\Programs\Python\Python37\lib\multiprocessing\context.py", line 223, in _Popen
    return _default_context.get_context().Process._Popen(process_obj)
	
  File "C:\Users\marodev\AppData\Local\Programs\Python\Python37\lib\multiprocessing\context.py", line 322, in _Popen
    return Popen(process_obj)
	
  File "C:\Users\marodev\AppData\Local\Programs\Python\Python37\lib\multiprocessing\popen_spawn_win32.py", line 65, in __init__
    reduction.dump(process_obj, to_child)
	
  File "C:\Users\marodev\AppData\Local\Programs\Python\Python37\lib\multiprocessing\reduction.py", line 60, in dump
    ForkingPickler(file, protocol).dump(obj)
	
AttributeError: Can't pickle local object 'request_response.<locals>.app'

(venv) C:\Users\marodev\source\repos\StarletteHelloWorldVirtualEnvPy37>Traceback (most recent call last):
  File "<string>", line 1, in <module>
  
  File "C:\Users\marodev\AppData\Local\Programs\Python\Python37\lib\multiprocessing\spawn.py", line 99, in spawn_main
    new_handle = reduction.steal_handle(parent_pid, pipe_handle)
	
  File "C:\Users\marodev\AppData\Local\Programs\Python\Python37\lib\multiprocessing\reduction.py", line 82, in steal_handle
    _winapi.PROCESS_DUP_HANDLE, False, source_pid)
	
OSError: [WinError 87] The parameter is incorrect

This is #224 rebased to master. Closes #219.

I also pinned wsproto because uvicorn does not work for wsproto 0.13. Would probably be good to fix that (in another PR).

Suggestion: what about also adding [dev]. We could use that in the CI script, so we'd have all dependencies defined in a single place.

Instead of the platform detection I’d like uvicorn to use optional installs.

• pip install uvicorn - Just the package itself.
• pip install uvicorn[standard] - uvloop/httptools/websockets
• pip install uvicorn[pure] - asyncio/h11/wsproto
• pip install uvicorn[full] - Everything

See https://watchfiles.helpmanual.io/migrating/.

TL;DR; I've renamed watchgod to watchfiles and rewritten it to use the rust "notify" crate for all the heavy lifting. This PR is a WIP to see if you're willing to move ahead with a change like this.

Still TODO/to answer:

• I've changed the logic of BaseReload to try and make StatReload and watchfiles share an interface, are you happy with this?
• tests are a fair bit more complicated, are you happy with how I'm implemented/changed them?
• ~~I don't see an obvious way to deal with --reload-include and --reload-exclude being paths rather than extensions. Are you happy to drop this functionality? It's much less important now there's little overhead to scanning big directories, if not, we can implement something but it'll be complicated.~~ I think I've dealt with this a287d5c

Using the example code

async def app(scope, receive, send):
    assert scope['type'] == 'http'

    await send({
        'type': 'http.response.start',
        'status': 200,
        'headers': [
            [b'content-type', b'text/plain'],
        ],
    })
    await send({
        'type': 'http.response.body',
        'body': b'Hello, world!',
    })

and running uvicorn main:app, CPU usage is unnoticeable (less than 1% of 1 core). But when running with uvicorn main:app --reload, CPU usage jumps to 54% of 1 core.

Environment: python -V: Python 3.7.2 uvicorn: 0.6.1 uname -a: Linux architect 5.0.4-arch1-1-ARCH #1 SMP PREEMPT Sat Mar 23 21:00:33 UTC 2019 x86_64 GNU/Linux

I'm trying to run uvicorn --reload in a docker-compose setup with a mounted directory of my code. When using "ctrl+c" and other ways to end the process it ends up just haning for the graceful shutdown periode and then it gets the SIGKILL because nothings happens. When looking at the strace it seems to be hanging indeed:

wait4(7, 0x7ffcf1409d84, WNOHANG, NULL) = 0
getpid()                                = 1
write(2, "INFO: Stopping reloader process "..., 36) = 36
getsockname(3, {sa_family=AF_INET, sin_port=htons(8000), sin_addr=inet_addr("0.0.0.0")}, [16]) = 0
getpeername(3, 0x7ffcf1409f70, [16])    = -1 ENOTCONN (Transport endpoint is not connected)
close(3)                                = 0
wait4(7, 0x7ffcf140afe4, WNOHANG, NULL) = 0
wait4(7, 0x7ffcf140afe4, WNOHANG, NULL) = 0
getpid()                                = 1
wait4(7,  <unfinished ...>)             = ?
+++ killed by SIGKILL +++

If I disable the reloader it shutdowns down fine. I've uploaded a minimal sample here: https://gist.github.com/sbv-trueenergy/a9a6971778a01d1acd3c466719e690b8

Am I doing something wrong?

uvicorn==0.2.5 is throwing errors for some requests.

ERROR: Exception in ASGI application
Traceback (most recent call last):
  File "/home/chillar/.virtualenvs/library/lib/python3.6/site-packages/uvicorn/protocols/http/httptools.py", line 196, in run_asgi
    result = await asgi(self.receive, self.send)
  File "/home/chillar/.virtualenvs/library/lib/python3.6/site-packages/channels/http.py", line 190, in __call__
    await self.handle(body)
  File "/home/chillar/.virtualenvs/library/lib/python3.6/site-packages/asgiref/sync.py", line 110, in __call__
    return await asyncio.wait_for(future, timeout=None)
  File "/usr/lib/python3.6/asyncio/tasks.py", line 339, in wait_for
    return (yield from fut)
  File "/usr/lib/python3.6/concurrent/futures/thread.py", line 56, in run
    result = self.fn(*self.args, **self.kwargs)
  File "/home/chillar/.virtualenvs/library/lib/python3.6/site-packages/asgiref/sync.py", line 125, in thread_handler
    return self.func(*args, **kwargs)
  File "/home/chillar/.virtualenvs/library/lib/python3.6/site-packages/channels/http.py", line 229, in handle
    self.send(response_message)
  File "/home/chillar/.virtualenvs/library/lib/python3.6/site-packages/asgiref/sync.py", line 64, in __call__
    return call_result.result()
  File "/usr/lib/python3.6/concurrent/futures/_base.py", line 432, in result
    return self.__get_result()
  File "/usr/lib/python3.6/concurrent/futures/_base.py", line 384, in __get_result
    raise self._exception
  File "/home/chillar/.virtualenvs/library/lib/python3.6/site-packages/asgiref/sync.py", line 78, in main_wrap
    result = await self.awaitable(*args, **kwargs)
  File "/home/chillar/.virtualenvs/library/lib/python3.6/site-packages/uvicorn/protocols/http/httptools.py", line 308, in send
    protocol.transport.write(body)
  File "uvloop/handles/stream.pyx", line 636, in uvloop.loop.UVStream.write
  File "uvloop/handles/handle.pyx", line 165, in uvloop.loop.UVHandle._ensure_alive
RuntimeError: unable to perform operation on <TCPTransport closed=True reading=False 0x1a48ad8>; the handler is closed

Checklist

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

Describe the bug

My FastAPI ASGI server cannot shutdown properly with uvicorn==0.15 while it can with 0.14

To reproduce

Setup minimal FastAPI app and add some functions with logs(prints) to shutdown event

Expected behavior

You see all logs(prints) from functions on shutdown

Actual behavior

Get ASGI 'lifespan' protocol appears unsupported. without --lifespan on Get error trace with --lifespan on

Debugging material

uvicorn scheduler.main:app --host=0.0.0.0 --port ${WEB_PORT:-8000} --reload --lifespan on INFO: Will watch for changes in these directories: ['/home/dmytro/storage/chimplie/projects/raok-main/raok-scheduler'] INFO: Uvicorn running on http://0.0.0.0:8004 (Press CTRL+C to quit) INFO: Started reloader process [177653] using statreload INFO: Started server process [177655] INFO: Waiting for application startup. INFO: Tortoise-ORM started, {'default': <tortoise.backends.asyncpg.client.AsyncpgDBClient object at 0x7f63d4a10e50>}, {'models': {'Task': <class 'scheduler.models.task.Task'>, 'Aerich': <class 'aerich.models.Aerich'>}} INFO: Application startup complete. ^CINFO: Shutting down INFO: Finished server process [177655] ERROR: Exception in 'lifespan' protocol Traceback (most recent call last): File "/home/dmytro/.local/share/virtualenvs/raok-scheduler-hpGGYNLi/lib/python3.8/site-packages/uvicorn/lifespan/on.py", line 84, in main await app(scope, self.receive, self.send) File "/home/dmytro/.local/share/virtualenvs/raok-scheduler-hpGGYNLi/lib/python3.8/site-packages/uvicorn/middleware/proxy_headers.py", line 75, in call return await self.app(scope, receive, send) File "/home/dmytro/.local/share/virtualenvs/raok-scheduler-hpGGYNLi/lib/python3.8/site-packages/fastapi/applications.py", line 199, in call await super().call(scope, receive, send) File "/home/dmytro/.local/share/virtualenvs/raok-scheduler-hpGGYNLi/lib/python3.8/site-packages/starlette/applications.py", line 112, in call await self.middleware_stack(scope, receive, send) File "/home/dmytro/.local/share/virtualenvs/raok-scheduler-hpGGYNLi/lib/python3.8/site-packages/starlette/middleware/errors.py", line 146, in call await self.app(scope, receive, send) File "/home/dmytro/.local/share/virtualenvs/raok-scheduler-hpGGYNLi/lib/python3.8/site-packages/starlette/middleware/cors.py", line 70, in call await self.app(scope, receive, send) File "/home/dmytro/.local/share/virtualenvs/raok-scheduler-hpGGYNLi/lib/python3.8/site-packages/starlette/exceptions.py", line 58, in call await self.app(scope, receive, send) File "/home/dmytro/.local/share/virtualenvs/raok-scheduler-hpGGYNLi/lib/python3.8/site-packages/starlette/routing.py", line 569, in call await self.lifespan(scope, receive, send) File "/home/dmytro/.local/share/virtualenvs/raok-scheduler-hpGGYNLi/lib/python3.8/site-packages/starlette/routing.py", line 544, in lifespan await receive() File "/home/dmytro/.local/share/virtualenvs/raok-scheduler-hpGGYNLi/lib/python3.8/site-packages/uvicorn/lifespan/on.py", line 135, in receive return await self.receive_queue.get() File "/usr/lib64/python3.8/asyncio/queues.py", line 163, in get await getter asyncio.exceptions.CancelledError INFO: Stopping reloader process [177653]

Environment

• Fedora 34 / Python 3.8 / Uvicorn version: 0.15 - bug, 0.14 - ok
• command to run: uvicorn main:app --host=0.0.0.0 --port 8000 --reload

Bumps httpx from 0.23.0 to 0.23.1.

Dependabot will resolve any conflicts with this PR as long as you don't alter it yourself. You can also trigger a rebase manually by commenting @dependabot rebase.

Bumps asgiref from 3.5.2 to 3.6.0.

Dependabot will resolve any conflicts with this PR as long as you don't alter it yourself. You can also trigger a rebase manually by commenting @dependabot rebase.

• Closes https://github.com/encode/uvicorn/issues/451
• Closes https://github.com/encode/uvicorn/issues/675

Description

This PR adds the --timeout-graceful-shutdown parameter, which sets a timeout on tasks that the server is waiting to perform the shutdown lifespan event.

This timeout doesn't act on the shutdown lifespan event i.e. the shutdown event is supposed to run even in the scenario the tasks are timed out.

I need to think of a nice test for this. Ideas?

Notes

1. The --graceful-timeout from gunicorn is conceptually different from --timeout-graceful-shutdown. The first forcefully kills the worker, and the latter cancels the tasks that are running after uvicorn said "I'm not receiving more requests, I'm just going to finish some tasks".

2. An alternative name for this parameter could be --timeout-tasks-shutdown, or similar.

3. The logs are horrible when a task is cancelled. Should it be fine tho? :shrug:

Missing

• [ ] Add an entry on the documentation.
• [ ] Add a test case.

• Closes #1344

Changes

• Send 500 or 1012 to the client on server shutdown, instead of the previous 1006.
• Improve test suite to check what the client receives, instead of only the ASGI application.
• Increase coverage from 98.5% to 98.8%.