WSGI calling close causes premature close_if_unusable_or_obsolete calls during transaction?

[Yu Li]

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.

[Yu Li]

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().

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.

[rm_]

@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.

[rm_]

@ylilarry please add a new comment next time please :) Could you reproduce with enable-threads = true ?

[Carlton Gibson]

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.