Opened 4 years ago
Closed 4 years ago
#31717 closed Uncategorized (needsinfo)
WSGI calling close causes premature close_if_unusable_or_obsolete calls during transaction?
Reported by: | Yu Li | Owned by: | nobody |
---|---|---|---|
Component: | Uncategorized | Version: | 3.0 |
Severity: | Normal | Keywords: | |
Cc: | rm_ | Triage Stage: | Unreviewed |
Has patch: | no | Needs documentation: | no |
Needs tests: | no | Patch needs improvement: | no |
Easy pickings: | no | UI/UX: | no |
Description
I'm having an issue with uwsgi+postgresql+django combo. This issue does not exist when I use the manage runserver development server.
The issue is, I'm constantly receiving this error from django
prod_1 | Traceback (most recent call last): prod_1 | File "/usr/local/lib/python3.8/dist-packages/django/db/backends/base/base.py", line 253, in _cursor prod_1 | return self._prepare_cursor(self.create_cursor(name)) prod_1 | File "/usr/local/lib/python3.8/dist-packages/django/utils/asyncio.py", line 26, in inner prod_1 | return func(*args, **kwargs) prod_1 | File "/usr/local/lib/python3.8/dist-packages/django/db/backends/postgresql/base.py", line 231, in create_cursor prod_1 | cursor = self.connection.cursor() prod_1 | psycopg2.InterfaceError: connection already closed
Possibly related:
https://code.djangoproject.com/ticket/25362
https://code.djangoproject.com/ticket/15802
However, I backtraced the stack of this error and found out Django is calling BaseDatabaseWrapper.close()
right before this error.
Specifically, this line:
def close_if_unusable_or_obsolete(self): """ Close the current connection if unrecoverable errors have occurred or if it outlived its maximum age. """ if self.connection is not None: # If the application didn't restore the original autocommit setting, # don't take chances, drop the connection. if self.get_autocommit() != self.settings_dict["AUTOCOMMIT"]: self.close() return
And when the error happens, we have self.get_autocommit()
returning False
, and self.settings_dict["AUTOCOMMIT"]
returning True
.
Then I backtraced where self.set_autocommit(False)
was called and found out that this happened in Atomic.__enter__()
def __enter__(self): connection = get_connection(self.using) if not connection.in_atomic_block: # Reset state when entering an outermost atomic block. connection.commit_on_exit = True connection.needs_rollback = False if not connection.get_autocommit(): # Pretend we're already in an atomic block to bypass the code # that disables autocommit to enter a transaction, and make a # note to deal with this case in __exit__. connection.in_atomic_block = True connection.commit_on_exit = False if connection.in_atomic_block: # We're already in a transaction; create a savepoint, unless we # were told not to or we're already waiting for a rollback. The # second condition avoids creating useless savepoints and prevents # overwriting needs_rollback until the rollback is performed. if self.savepoint and not connection.needs_rollback: sid = connection.savepoint() connection.savepoint_ids.append(sid) else: connection.savepoint_ids.append(None) else: connection.set_autocommit(False, force_begin_transaction_with_broken_autocommit=True) connection.in_atomic_block = True
I think something bad is happening when wsgi calls HttpResponseBase.close()
during a transaction, because
def close_old_connections(**kwargs): for conn in connections.all(): conn.close_if_unusable_or_obsolete() signals.request_started.connect(close_old_connections) signals.request_finished.connect(close_old_connections)
and
# The WSGI server must call this method upon completion of the request. # See http://blog.dscpl.com.au/2012/10/obligations-for-calling-close-on.html def close(self): for closer in self._resource_closers: try: closer() except Exception: pass # Free resources that were still referenced. self._resource_closers.clear() self.closed = True signals.request_finished.send(sender=self._handler_class)
causes close_if_unusable_or_obsolete()
to be called during this transaction, so self.get_autocommit() != self.settings_dict["AUTOCOMMIT"]
closed the connection.
Change History (4)
comment:2 by , 4 years ago
Cc: | added |
---|
@ylilarry which uwsgi version? Can you share your uwsgi config?
I've tried multiple configurations with uwsgi.
This is the one I felt it would be the safest and still failed
[uwsgi] strict = true wsgi-file = project/wsgi.py threads = 1 stats = 0.0.0.0:9191 master = true log-master = true workers = 1 enable-threads = false single-interpreter = true die-on-term = true need-app = true
Name: uWSGI Version: 2.0.19.1 Summary: The uWSGI server Home-page: https://uwsgi-docs.readthedocs.io/en/latest/ Author: Unbit Author-email: info@unbit.it License: GPLv2+ Location: /usr/local/lib/python3.8/dist-packages
This issue on my server is sporadic. Although I still haven't found a consistent way of triggering it, I found it happens most of time when a user aborts the request early, for example, by repeatedly refreshing the webpage before the content loads, eventually end up with a 500 error.
comment:3 by , 4 years ago
@ylilarry please add a new comment next time please :) Could you reproduce with enable-threads = true ?
comment:4 by , 4 years ago
Resolution: | → needsinfo |
---|---|
Status: | new → closed |
There's not enough to go on here. If you could upload a minimal reproduce project so we can investigate that would be awesome. Thanks.
I commented out
signals.request_finished.connect(close_old_connections)
and the problem immediately goes away.Also manage runserver does not seem to call
HttpResponseBase.close()
, which could explain why the issue doesn't happen there.This gives me more confidence that where the issue lays. I think the problem is uwsgi is calling
.close()
from a different thread whereas a transaction is on-going somewhere else.