maxfischer2781 commented 2 months ago

Summary

This PR suppresses noise and dirt from signal propagation introduced in #1600.

Suppress tracebacks from worker/reload subprocesses on termination. These are triggered deep inside multiprocessing.process on any exception. Since the shutdown exception is expected, subprocesses spawned for workers/reload simply discard it.
- Fixes #2294.
Always run cleanup of unix domain sockets when the uvicorn.run exits. This would previously be skipped on forced shutdown.

Note: I was not able to reproduce #2281 / #2289 so I do not know if they are fixed by this. However, this fixes the various reports on those discussions/issues about tracebacks.

~~I do not have access to a Windows machine for testing so had to emulate it. It would be nice if someone can confirm that this works on Windows.~~ A minimal repro is the program

# test.py
async def dummy_app(scope, receive, send): pass

run via

python -m uvicorn test:dummy_app --reload

@johanboekhoven kindly tested this on Windows.

Checklist

[x] I understand that this PR may be closed in case there was no previous discussion. (This doesn't apply to typos!)
[x] I've added a test for each change that was introduced, and I tried as much as possible to make a single atomic change.
- This change has no effect on behaviour, merely output.
[x] I've updated the documentation accordingly.
- This change has no effect on documented behaviour.

Kludex commented 1 month ago

I can't reproduce it. How did you?

maxfischer2781 commented 1 month ago

@Kludex Sorry, I forgot to add one detail. To reproduce the Windows behaviour on UNIX, one must patch how the subprocesses are killed (SIGINT on Windows vs SIGTERM on UNIX).

In uvicorn/supervisors/basereload.py, one must change the use of terminate:

https://github.com/encode/uvicorn/blob/0efd3835da6dcc713f74aadf7b52779d0d1fa17d/uvicorn/supervisors/basereload.py#L92-L93

to sending SIGINT explicitly:

        else:  # pragma: py-win32
            self.process._popen._send_signal(signal.SIGINT)

Afterwards, run the example mentioned above. Saving any file should trigger a reload and finishing the subprocess triggers a traceback as below:

...
INFO:     Application startup complete.
WARNING:  WatchFiles detected changes in 'uvicorn/supervisors/basereload.py'. Reloading...
INFO:     Shutting down
INFO:     Waiting for application shutdown.
INFO:     Application shutdown complete.
INFO:     Finished server process [55538]
err
Process SpawnProcess-3:
Traceback (most recent call last):
  File "/opt/homebrew/Cellar/python@3.12/3.12.2_1/Frameworks/Python.framework/Versions/3.12/lib/python3.12/asyncio/runners.py", line 118, in run
    return self._loop.run_until_complete(task)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "uvloop/loop.pyx", line 1517, in uvloop.loop.Loop.run_until_complete
asyncio.exceptions.CancelledError

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/opt/homebrew/Cellar/python@3.12/3.12.2_1/Frameworks/Python.framework/Versions/3.12/lib/python3.12/multiprocessing/process.py", line 314, in _bootstrap
    self.run()
  File "/opt/homebrew/Cellar/python@3.12/3.12.2_1/Frameworks/Python.framework/Versions/3.12/lib/python3.12/multiprocessing/process.py", line 108, in run
    self._target(*self._args, **self._kwargs)
  File "/Users/maxfischer/code_projects/uvicorn/uvicorn/_subprocess.py", line 79, in subprocess_started
    target(sockets=sockets)
  File "/Users/maxfischer/code_projects/uvicorn/uvicorn/server.py", line 66, in run
    return asyncio.run(self.serve(sockets=sockets))
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/opt/homebrew/Cellar/python@3.12/3.12.2_1/Frameworks/Python.framework/Versions/3.12/lib/python3.12/asyncio/runners.py", line 194, in run
    return runner.run(main)
           ^^^^^^^^^^^^^^^^
  File "/opt/homebrew/Cellar/python@3.12/3.12.2_1/Frameworks/Python.framework/Versions/3.12/lib/python3.12/asyncio/runners.py", line 123, in run
    raise KeyboardInterrupt()
KeyboardInterrupt
INFO:     Started server process [55539]
INFO:     Waiting for application startup.
...

Note This patch is only for testing the Windows behaviour on UNIX and not part of the actual fix.

kenn commented 1 month ago

Not to distract your quality work, but I just wanted to add my experience.

I've had the following monkey patch in main.py to suppress tracebacks upon hitting ctrl+C on a dev machine (Mac), worked until 0.27.1:

if is_dev:
    get = asyncio.Queue.get

    async def new_get(self):
        try:
            return await get(self)
        except asyncio.exceptions.CancelledError:
            pass

    asyncio.Queue.get = new_get

But it stopped working after upgradeing to 0.29.0. If I'm not mistaken, this PR fixes this issue, correct?

INFO:     Shutting down
INFO:     Finished server process [98267]
ERROR:    Traceback (most recent call last):
  File ".pyenv/versions/3.10.10/lib/python3.10/asyncio/runners.py", line 44, in run
    return loop.run_until_complete(main)
  File "uvloop/loop.pyx", line 1511, in uvloop.loop.Loop.run_until_complete
  File "uvloop/loop.pyx", line 1504, in uvloop.loop.Loop.run_until_complete
  File "uvloop/loop.pyx", line 1377, in uvloop.loop.Loop.run_forever
  File "uvloop/loop.pyx", line 555, in uvloop.loop.Loop._run
  File "uvloop/loop.pyx", line 474, in uvloop.loop.Loop._on_idle
  File "uvloop/cbhandles.pyx", line 83, in uvloop.loop.Handle._run
  File "uvloop/cbhandles.pyx", line 63, in uvloop.loop.Handle._run
  File ".venv/lib/python3.10/site-packages/uvicorn/server.py", line 68, in serve
    with self.capture_signals():
  File ".pyenv/versions/3.10.10/lib/python3.10/contextlib.py", line 142, in __exit__
    next(self.gen)
  File ".venv/lib/python3.10/site-packages/uvicorn/server.py", line 328, in capture_signals
    signal.raise_signal(captured_signal)
KeyboardInterrupt

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File ".venv/lib/python3.10/site-packages/starlette/routing.py", line 741, in lifespan
    await receive()
  File ".venv/lib/python3.10/site-packages/uvicorn/lifespan/on.py", line 137, in receive
    return await self.receive_queue.get()
  File ".pyenv/versions/3.10.10/lib/python3.10/asyncio/queues.py", line 159, in get
    await getter
asyncio.exceptions.CancelledError

Process SpawnProcess-1:
Traceback (most recent call last):
  File ".pyenv/versions/3.10.10/lib/python3.10/multiprocessing/process.py", line 314, in _bootstrap
    self.run()
  File ".pyenv/versions/3.10.10/lib/python3.10/multiprocessing/process.py", line 108, in run
    self._target(*self._args, **self._kwargs)
  File ".venv/lib/python3.10/site-packages/uvicorn/_subprocess.py", line 78, in subprocess_started
    target(sockets=sockets)
  File ".venv/lib/python3.10/site-packages/uvicorn/server.py", line 65, in run
    return asyncio.run(self.serve(sockets=sockets))
  File ".pyenv/versions/3.10.10/lib/python3.10/asyncio/runners.py", line 44, in run
    return loop.run_until_complete(main)
  File "uvloop/loop.pyx", line 1511, in uvloop.loop.Loop.run_until_complete
  File "uvloop/loop.pyx", line 1504, in uvloop.loop.Loop.run_until_complete
  File "uvloop/loop.pyx", line 1377, in uvloop.loop.Loop.run_forever
  File "uvloop/loop.pyx", line 555, in uvloop.loop.Loop._run
  File "uvloop/loop.pyx", line 474, in uvloop.loop.Loop._on_idle
  File "uvloop/cbhandles.pyx", line 83, in uvloop.loop.Handle._run
  File "uvloop/cbhandles.pyx", line 63, in uvloop.loop.Handle._run
  File ".venv/lib/python3.10/site-packages/uvicorn/server.py", line 68, in serve
    with self.capture_signals():
  File ".pyenv/versions/3.10.10/lib/python3.10/contextlib.py", line 142, in __exit__
    next(self.gen)
  File ".venv/lib/python3.10/site-packages/uvicorn/server.py", line 328, in capture_signals
    signal.raise_signal(captured_signal)
KeyboardInterrupt
INFO:     Stopping reloader process [98264]

maxfischer2781 commented 1 month ago

@kenn This PR will remove the Process SpawnProcess-1 part. Your patch should play nicely with this.

However, the first traceback does not seem to include your new_get function at all. In fact, the trace going through File ".venv/lib/python3.10/site-packages/uvicorn/lifespan/on.py", line 137, in receive and then immediately through File ".pyenv/versions/3.10.10/lib/python3.10/asyncio/queues.py", line 159, in get indicates new_get wasn't installed (it should show up in between otherwise). Perhaps you might want to double-check whether the code path that installs the patch is still run.

kenn commented 1 month ago

@kenn This PR will remove the Process SpawnProcess-1 part. Your patch should play nicely with this.

However, the first traceback does not seem to include your new_get function at all.

Thanks! new_get is used to overwrite the original get method with asyncio.Queue.get = new_get, hence monkey-patching. Save (as backup) the original get, use it in new_get, and then use new_get to overwrite the original get.

I know this is a dirty hack, but it works for a single purpose as expected — suppress the verbose tracebacks upon ctrl-C while preserving its original functionality 100%.

Kludex commented 1 month ago

Thanks @maxfischer2781 :)

encode / uvicorn

Suppress side-effects of signal propagation #2317

Summary

Checklist