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

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