ASGI server leaves stale DB connections

[James Thorniley]

This seems to be a regression from 4.2 to 5.0.

We are using Django ASGI server via uvicorn, with a mariadb database. When updating our app servers from Django 4.2.8 to 5.0, we experienced a spike in the number of database connections, eventually going over the limit set for the DB and causing 500 errors due to

django.db.utils.OperationalError: (1040, 'Too many connections')

I've created a minimal project to reproduce what I think is the phenomenon here using local docker container for the DB:

​https://github.com/jthorniley/django-asgi

I've put complete reproduction steps in that github link, but I will summarise here:

• When running a Django 5.0 ASGI server, some connections are not closed when requests complete, leaving stale connections in the DB. This can be confirmed by running curl against a local server and then show processlist in the mysql CLI when the requests are complete.
• As a result, if you send a moderate number of parallel requests to the server, it will go past the limit of DB connections (I think the out-of-the-box limit for the mariadb docker container is around 150, but it is configurable). Then new connections will fail with the Too many connections error. Obviously its theoretically possible to go over this limit anyway but it happens sooner due to server processes not cleaning up connections after requests complete.
• You can downgrade to 4.2.8 and run the same reproduction project and see that there is no issue there. The DB connections are closed after every individual request and hence provided there aren't more parallel requests than allowed connections to the DB you are safe.

[Bryce Durham]

I also experienced this with Postgres. Downgraded to Django 4.2.8

[Aryan Gholizadeh Mojaveri]

I also could reproduce this bug using James's repo.

[Mariusz Felisiak]

I don't see it as a regression. As for me it behaves exactly the same on Django 4.2. If you can ​bisect to determine the commit where the behavior changed, that would be useful.

This may be a duplicate of #33297 or #33497.

[James Thorniley]

git bisect found commit 7cd187a5ba58d7769039f487faeb9a5a2ff05540 however I think this is a red herring, not sure why it came to that.

Reverting the changes from 64cea1e48f285ea2162c669208d95188b32bbc82 on top of 5.0 fix the problems, so I think that is actually the problematic commit.

This commit moved the send_response function into a task which can be cancelled if and when http.disconnect is received. However the send_response function was also responsible for calling response.close() which is a sync function called asynchronously using sync_to_async. This introduced a race condition as if the http.disconnect is received during the call to the sync_to_async wrapped code then the response.close() can effectively be cancelled and the associated clean up (triggered by the request_finished signal from inside response.close() never gets called.

If created a PR here for review, it seems to solve the issue for me: ​https://github.com/django/django/pull/17675

[Carlton Gibson]

With the test cases, I think we can accept this as a bug in 64cea1e48f285ea2162c669208d95188b32bbc82. Thanks for the investigation James.

The request_finished signal should be dispatched in the disconnect case.

I left a few initial comments on the PR. Happy to take another look later on.

[Natalia Bidart]

Assigning to James following the proposed PR.

[Natalia Bidart]

Setting patch needs improvements following the latest batch of review comments made by Carlton.

[Natalia Bidart]

Setting as patch needs improvement while I wait for the author to reply to my comments.

[Josh Orr]

I have this same problem, it caused a massive spike in database connections. I had to revert back to Django 4.2 for now until this is fixed. I came here to report but found your all already on top of it, thank you! Can't wait until this is fixed in 5.0.

[Mariusz Felisiak]

Replying to Josh Orr:

I have this same problem, it caused a massive spike in database connections. I had to revert back to Django 4.2 for now until this is fixed. I came here to report but found your all already on top of it, thank you! Can't wait until this is fixed in 5.0.

Hi Josh, Does that the proposed patch work for you? Testing would be a huge help.

[Natalia Bidart]

#35148 was a duplicate.

[Natalia Bidart]

This is pretty much ready for checkin pending two question and one optional test change. I will wait for feedback from either the author or Carlton to merge ASAP (release is planned for Feb 6th). Thanks everyone who helped so far, by either building the fix, reviewing, debugging and/or testing the patch!

[Natalia <124304+nessita@…>]

In a43d75e:

Refs #35059 -- Made asgi tests' SignalHandler helper class re-usable by other tests.

[Natalia <124304+nessita@…>]

In 11393ab:

Fixed #35059 -- Ensured that ASGIHandler always sends the request_finished signal.

Prior to this work, when async tasks that process the request are cancelled due
to receiving an early "http.disconnect" ASGI message, the request_finished
signal was not being sent, potentially leading to resource leaks (such as
database connections).

This branch ensures that the request_finished signal is sent even in the case
of early termination of the response.

Regression in 64cea1e48f285ea2162c669208d95188b32bbc82.

Co-authored-by: Natalia <124304+nessita@…>
Co-authored-by: Carlton Gibson <carlton.gibson@…>

[Natalia <124304+nessita@…>]

In bbb9ef3:

[5.0.x] Refs #35059 -- Made asgi tests' SignalHandler helper class re-usable by other tests.

Backport of a43d75e81da783fda08bf8d3493252e3676d11ea from main

[Natalia <124304+nessita@…>]

In f1fbd061:

[5.0.x] Fixed #35059 -- Ensured that ASGIHandler always sends the request_finished signal.

Prior to this work, when async tasks that process the request are cancelled due
to receiving an early "http.disconnect" ASGI message, the request_finished
signal was not being sent, potentially leading to resource leaks (such as
database connections).

This branch ensures that the request_finished signal is sent even in the case
of early termination of the response.

Regression in 64cea1e48f285ea2162c669208d95188b32bbc82.

Co-authored-by: Natalia <124304+nessita@…>
Co-authored-by: Carlton Gibson <carlton.gibson@…>

Backport of 11393ab1316f973c5fbb534305750740d909b4e4 from main

[GitHub <noreply@…>]

In f4a08b6d:

Refs #35059 -- Used asyncio.Event in ASGITest.test_asyncio_cancel_error to enforce specific interleaving.

Sleep call leads to a hard to trace error in CI. Using an Event is
more deterministic, and should be less prone to environment
variations.

Bug in 11393ab1316f973c5fbb534305750740d909b4e4.

[Natalia <124304+nessita@…>]

In 3824858:

[5.1.x] Refs #35059 -- Used asyncio.Event in ASGITest.test_asyncio_cancel_error to enforce specific interleaving.

Sleep call leads to a hard to trace error in CI. Using an Event is
more deterministic, and should be less prone to environment
variations.

Bug in 11393ab1316f973c5fbb534305750740d909b4e4.

Backport of f4a08b6ddfcacadfe9ff8364bf1c6c54f5dd370f from main.

[Natalia <124304+nessita@…>]

In dd3d0483:

[5.0.x] Refs #35059 -- Used asyncio.Event in ASGITest.test_asyncio_cancel_error to enforce specific interleaving.

Sleep call leads to a hard to trace error in CI. Using an Event is
more deterministic, and should be less prone to environment
variations.

Bug in 11393ab1316f973c5fbb534305750740d909b4e4.

Backport of f4a08b6ddfcacadfe9ff8364bf1c6c54f5dd370f from main.