sanic-org / sanic-ext

Extended Sanic functionality
https://sanic.dev/en/plugins/sanic-ext/getting-started.html
MIT License
50 stars 36 forks source link

[Bug] Dependency injection not working for requests received during server is initializing #218

Closed xmcp closed 3 months ago

xmcp commented 1 year ago

Describe the bug On Linux, dependency injection does not work for requests received during the @app.before_server_start code is executing, causing an HTTP 500 error.

Screenshots Not related to swagger.

To Reproduce Run this code on a Linux machine:

from sanic import Sanic
from sanic.response import text
import time
import requests
import threading

app = Sanic('app')

class Foo:
    pass
app.ext.add_dependency(Foo)

@app.before_server_start
async def setup(cur_app: Sanic, _loop):
    print('setup BEGIN')
    time.sleep(2)
    print('setup END')

@app.route("/test")
async def handler(request, foo: Foo):
    return text('hi')

def test_client():
    time.sleep(1)
    print('test-a BEGIN')
    res = requests.get('http://127.0.0.1:4321/test')
    print('test-a END WITH HTTP', res.status_code)

    time.sleep(2)
    print('test-b BEGIN')
    res = requests.get('http://127.0.0.1:4321/test')
    print('test-b END WITH HTTP', res.status_code)

if __name__=='__main__':
    threading.Thread(target=test_client).start()
    app.run(port=4321)

It emulates a web application where the setup process (@app.before_server_start) takes 2s. During this time, test_client requests the /test endpoint with injected dependencies, which will result in HTTP 500.

The console output looks like this:

[2023-07-23 16:02:33 +0800] [2628145] [WARNING] Sanic is running in PRODUCTION mode. Consider using '--debug' or '--dev' while actively developing your application.
[2023-07-23 16:02:34 +0800] [2628155] [INFO] Sanic Extensions:
[2023-07-23 16:02:34 +0800] [2628155] [INFO]   > injection [1 dependencies; 0 constants]
[2023-07-23 16:02:34 +0800] [2628155] [INFO]   > openapi [http://127.0.0.1:4321/docs]
[2023-07-23 16:02:34 +0800] [2628155] [INFO]   > http 
[2023-07-23 16:02:34 +0800] [2628155] [INFO]   > templating [jinja2==3.1.2]
setup BEGIN
test-a BEGIN
setup END
[2023-07-23 16:02:36 +0800] [2628155] [ERROR] Exception occurred while handling uri: 'http://127.0.0.1:4321/test'
Traceback (most recent call last):
  File "handle_request", line 94, in handle_request
    from sanic.worker.manager import WorkerManager
TypeError: handler() missing 1 required positional argument: 'foo'
[2023-07-23 16:02:36 +0800] [2628155] [INFO] Starting worker [2628155]
test-a END WITH HTTP 500
test-b BEGIN
test-b END WITH HTTP 200

Expected behavior

The above code works fine on Windows. Here is the console output on Windows:

[2023-07-23 16:02:17 +0800] [24032] [WARNING] Sanic is running in PRODUCTION mode. Consider using '--debug' or '--dev' while actively developing your application.
[2023-07-23 16:02:18 +0800] [29864] [INFO] Sanic Extensions:
[2023-07-23 16:02:18 +0800] [29864] [INFO]   > injection [1 dependencies; 0 constants]
[2023-07-23 16:02:18 +0800] [29864] [INFO]   > openapi [http://127.0.0.1:4321/docs]
[2023-07-23 16:02:18 +0800] [29864] [INFO]   > http
[2023-07-23 16:02:18 +0800] [29864] [INFO]   > templating [jinja2==3.1.2]
setup BEGIN
test-a BEGIN
setup END
[2023-07-23 16:02:20 +0800] [29864] [INFO] Starting worker [29864]
test-a END WITH HTTP 200
test-b BEGIN
test-b END WITH HTTP 200

Environment (please complete the following information):

Additional context I come across this bug when I restart a Sanic server behind an nginx. All queued requests when the backend is restarting get HTTP 500 responses.

sjsadowski commented 1 year ago

I believe this is a bug, but not for the reasons stated above - sanic should not be accepting requests at all before the server starts, and therefore clients should get a connection refused on the listening port until the before_server_start lifecycle event completes. Further, if it's running behind a proxy, this would necessitate the proxy returning a 502 because there was no open upstream connection during a sanic restart, which would allow a proxy that was doing health checks to mark the target as unhealthy and redirect to healthy targets (if there are any in the target group).

xmcp commented 3 months ago

Closing this because unable to reproduce this on sanic 23.12. Not sure which commit fixed it though.