Postgresql connections not being dropped between tests?

[Matthew Fisher]

I'm on Django 1.6.2, and ever since we switched to using psql for our database, we have been hitting an issue with running the test suite. I haven't been able to figure out why this occurs. Logs follow below.

$ make coverage
coverage run manage.py test --noinput api web
Creating test database for alias 'default'...
...............................................
----------------------------------------------------------------------
Ran 47 tests in 12.388s

OK
Destroying test database for alias 'default'...
Traceback (most recent call last):
  File "manage.py", line 13, in <module>
    execute_from_command_line(sys.argv)
  File "/Users/bacongobbler/venv/lib/python2.7/site-packages/django/core/management/__init__.py", line 399, in execute_from_command_line
    utility.execute()
  File "/Users/bacongobbler/venv/lib/python2.7/site-packages/django/core/management/__init__.py", line 392, in execute
    self.fetch_command(subcommand).run_from_argv(self.argv)
  File "/Users/bacongobbler/venv/lib/python2.7/site-packages/django/core/management/commands/test.py", line 50, in run_from_argv
    super(Command, self).run_from_argv(argv)
  File "/Users/bacongobbler/venv/lib/python2.7/site-packages/django/core/management/base.py", line 242, in run_from_argv
    self.execute(*args, **options.__dict__)
  File "/Users/bacongobbler/venv/lib/python2.7/site-packages/django/core/management/commands/test.py", line 71, in execute
    super(Command, self).execute(*args, **options)
  File "/Users/bacongobbler/venv/lib/python2.7/site-packages/django/core/management/base.py", line 285, in execute
    output = self.handle(*args, **options)
  File "/Users/bacongobbler/venv/lib/python2.7/site-packages/south/management/commands/test.py", line 8, in handle
    super(Command, self).handle(*args, **kwargs)
  File "/Users/bacongobbler/venv/lib/python2.7/site-packages/django/core/management/commands/test.py", line 88, in handle
    failures = test_runner.run_tests(test_labels)
  File "/Users/bacongobbler/git/github.com/opdemand/deis/controller/api/tests/__init__.py", line 41, in run_tests
    test_labels, extra_tests, **kwargs)
  File "/Users/bacongobbler/venv/lib/python2.7/site-packages/django/test/runner.py", line 147, in run_tests
    self.teardown_databases(old_config)
  File "/Users/bacongobbler/venv/lib/python2.7/site-packages/django/test/runner.py", line 122, in teardown_databases
    connection.creation.destroy_test_db(old_name, self.verbosity)
  File "/Users/bacongobbler/venv/lib/python2.7/site-packages/django/db/backends/creation.py", line 443, in destroy_test_db
    new_connection.creation._destroy_test_db(test_database_name, verbosity)
  File "/Users/bacongobbler/venv/lib/python2.7/site-packages/django/db/backends/creation.py", line 457, in _destroy_test_db
    % self.connection.ops.quote_name(test_database_name))
  File "/Users/bacongobbler/venv/lib/python2.7/site-packages/django/db/backends/util.py", line 53, in execute
    return self.cursor.execute(sql, params)
  File "/Users/bacongobbler/venv/lib/python2.7/site-packages/django/db/utils.py", line 99, in __exit__
    six.reraise(dj_exc_type, dj_exc_value, traceback)
  File "/Users/bacongobbler/venv/lib/python2.7/site-packages/django/db/backends/util.py", line 51, in execute
    return self.cursor.execute(sql)
OperationalError: database "test_deis" is being accessed by other users
DETAIL:  There is 1 other session using the database.

make: *** [coverage] Error 1

To me, it looks like Django is trying to destroy the temporary test database, but there are some connections still left over from the previous test suite run, which prevents the database from being dropped.

[Claude Paroz]

Can you check if the cause is the same as ticket #22414 (i.e. you have LiveServerTestCase and CONN_MAX_AGE = None)?

[Matthew Fisher]

We use TransactionTestCase and TestCase in our test suite. CONN_MAX_AGE is set to 180.

[anonymous]

I wonder if this issue is specific to a certain version of Postgres (or maybe surfaced with it) as I have had Django 1.6.2 for some time and only started hitting this issue after a Postgres package upgrade. I have upgraded postgresql from 9.1.12 to 9.1.13 and started getting the error after a reboot a couple of days later.

We don't use LiveServerTestCase and I wasn't using CONN_MAX_AGE in my settings. Setting CONN_MAX_AGE to 0 doesn't change anything for me.

[anonymous]

Replying to anonymous:

I wonder if this issue is specific to a certain version of Postgres (or maybe surfaced with it) as I have had Django 1.6.2 for some time and only started hitting this issue after a Postgres package upgrade. I have upgraded postgresql from 9.1.12 to 9.1.13 and started getting the error after a reboot a couple of days later.

We don't use LiveServerTestCase and I wasn't using CONN_MAX_AGE in my settings. Setting CONN_MAX_AGE to 0 doesn't change anything for me.

Hello, it's me again. I guess it also only occurs with a test run that produces failures. A successful test run or a test run that produces error results will not produce the issue.

[Tim Graham]

Any chance you could provide a minimal test project that reproduces the issue?

Also you said, "A successful test run or a test run that produces error results will not produce the issue." but the example in the description doesn't appear to have any failures?

[anonymous]

Replying to timo:

Any chance you could provide a minimal test project that reproduces the issue?

Also you said, "A successful test run or a test run that produces error results will not produce the issue." but the example in the description doesn't appear to have any failures?

Good points. I just tried again with a forced failure and an error. Now of course it appears to be reproducing in all 3 cases. (Fail, Error, Pass). Bah. I will try to get a GitHub project together and post back here.

[anonymous]

Replying to anonymous:

Replying to timo:

Any chance you could provide a minimal test project that reproduces the issue?

Also you said, "A successful test run or a test run that produces error results will not produce the issue." but the example in the description doesn't appear to have any failures?

Good points. I just tried again with a forced failure and an error. Now of course it appears to be reproducing in all 3 cases. (Fail, Error, Pass). Bah. I will try to get a GitHub project together and post back here.

I have been trying to narrow this down by reproducing with a minimal project and eliminating variables one by one in the project with the error. I still haven't been able to get it to reproduce in the minimal project (​https://github.com/WimpyAnalytics/djangobug22420). However I was able to determine that the problem only occurs on my larger project when all of the following circumstances are true:

1. I am using a custom test runner (I have tried Django Nose and Django Juno)
2. I am using Django Blog Zinnia
3. I am using a Custom User Model

Anyway, I think it's safe to say that my particular issue is not with Django itself.

[Tim Graham]

All right thanks, please reopen if you determine otherwise.

[gabrtv]

This is still an issue for us, but we were able to find a workaround I wanted to share:

1. The problem is related to using threads that access the database inside a TransactionTestCase
2. Explicitly closing database connections before the threads exit seems to resolve the issue

We are using the following decorator:

def close_db_connections(func, *args, **kwargs):
    """
    Decorator to close db connections during threaded execution

    Note this is necessary to work around:
    https://code.djangoproject.com/ticket/22420
    """
    def _inner(*args, **kwargs):
        func(*args, **kwargs)
        for conn in connections.all():
            conn.close()
    return _inner

At first blush, it seems like TransactionTestCase may not be threadsafe.

While I'd love to work on a minimal example of the broken behavior, I don't have time. :(

Hopefully this workaround is helpful to others who may run across this problem. Re-opening in case someone wants to take some action.

[EricBoersma]

Replying to gabrtv:

At first blush, it seems like TransactionTestCase may not be threadsafe.

That would appear to be a reasonable assumption. We're still seeing the issue in our main project and the workaround that you posted is intermittently successful, but I'm still seeing the error pop up from time to time, specifically when running tests that result in errors which are running through the .request() method. I will try to find a way to create a minimal test case this weekend.

[EricBoersma]

I attempted to create a short example which would reproduce this issue this weekend and was unsuccessful. I've done a bit more tinkering with gabrtv's solution, and it seems to work approximately 95% of the time. When it does fail, the error shows up on every test run until I restart the postgres service, at which point the fix works for a while again.

[IvanVenOsdel]

EricBoersma, gabrtv: We were able to narrow the hanging connections down to a few test methods that work with the ORM, signals, celery (w/Redis) and the Django cache (w/redis). The test uses the ORM and the cache. The code uses the ORM, cache and celery. We use the CELERY_ALWAYS_EAGER and CELERY_EAGER_PROPAGATES_EXCEPTIONS settings to make tasks synchronous when running the tests.

Does your setup overlap with that at all?

[anonymous]

IvanVanOsdel: yes, that sounds exactly like what we are using, however we do not use CELERY_EAGER_PROPAGATES_EXCEPTIONS.

[IvanVenOsdel]

Anonymous: Excellent, It would be nice to get confirmation from more people though. We still have the issue with CELERY_EAGER_PROPAGATES_EXCEPTIONS turned off so I don't think that difference matters.

[Tim Graham]

It's still not clear to me what, if any, action we should take. Please reopen if you have a proposal, thanks!

[klaus triendl]

Stable decorator that closes the connections in all cases:

def close_db_connections(func, *args, **kwargs):
    """
    Decorator to explicitly close db connections during threaded execution

    Note this is necessary to work around:
    https://code.djangoproject.com/ticket/22420
    """
    def _close_db_connections(*args, **kwargs):
        ret = None
        try:
            ret = func(*args, **kwargs)
        finally:
            for conn in connections.all():
                conn.close()
        return ret
    return _close_db_connections

[Paweł Marczewski]

I'm running about the same problem; it happens after a successful test run as well. More details: we're using Django 1.6 (though it happened in 1.5 as well) and Selenium tests with a TransactionTestCase and a LiveServerThread from Django. After every Selenium test run (in fixture_teardown) we're closing Selenium then joining the server thread,

From what I could determine, django.db.connections.all() doesn't show any other connections after closing the thread; however SELECT * from pg_stat_activity sometimes reveals a second connection (reported as having done COMMIT; just before the fixture teardown). The second connection often lingers for half a minute. We're not using the CONN_MAX_AGE setting.

I should also mention that we're sometimes closing the test while the server is processing a request, this is sometimes unavoidable because of Ajax requests in a page. Some of these requests get dropped when we close Selenium, disconnecting the client. I suspect that the LiveServerThread (or rather, StoppableWSGIServer) sometimes does not shut down the database correctly; maybe when it happens during a long-running request handler.

For now, we're ​forcibly closing all other Postgres connections to work around the issue, but it'd be great if someone could investigate this.

[Paul Bormans]

I'm seeing the same issue running a test suite that contains "TransactionTestCase" cases. Further more i'm running django 1.9.10 and postgres 9.3.

The odd thing is that the testcase causing the trouble ran fine before using default TestCase base class. But for reasons unknown to me (maybe upgrade some libs?) a worker thread part of the testcase started to yield no results from the orm that should be initialized using fixtures. It ran fine again after a switched to TransactionTestCase but that gave the mentioned issue:

django.db.utils.OperationalError: database "<name>" is being accessed by other users
DETAIL: There is 1 other session using the database.

I tried the cleanup decorator and it does close 1 connection but the error message remains.

I double checked that each of the Thread instances is properly closed (there is an explicit join() before the testcase ends).

Does each thread have its own session? Could i explicitly close it in a finally block?

Paul

[Will Plaehn]

I've created a project that replicates the issue using threading, a context processor, and a simple model. Hopefully this scenario helps!

​https://github.com/willplaehn/django-issue-22420

[Andrew Lindberg]

I also ran into this issue trying to build a Selenium test using LiveServerTestCase. Even with the above decorator, the postgres connections remain and prevent the test database from being destroyed.

I updated the repro from Will Plaehn with Django 3.0.5 and the issue persists.
My version of the repro also uses docker to simplify the setup process.

​https://github.com/hackedhead/django-issue-22420/tree/docker-repro

This is my first time engaging with a Django project issue, what needs to happen to reopen this to continue investigation?

[Andrew Lindberg]

Re-opened to invite further triage with new reproduction information. Updated version to 3.0 from 1.6.2 after testing reproduction on 3.0.5 and confirming bug still occurs.

[Carlton Gibson]

Hi Andrew.

Do you have a proposal here? (I can't see any new information really...)

Looking at the test project, I'm inclined to think the issue lies in the weird threading usage. (It's always the weird threading usage... 🙂)

The original Caktus article notes that the test code used inside the test_concurrently decorator must be thread safe. I'm guessing it's not — but I don't have a specific diagnosis there.
The article says that each thread must use it's own client instance, but the test code references self.factory... Maybe worth looking at? (In contrast to RequestFactory, Client actually processing the request, including calling close_old_connections — the example project's render call does not...)

This is my first time engaging with a Django project issue, what needs to happen to reopen this to continue investigation?

Welcome aboard. Investigation can continue, but it probably needs you to dig down and establish exactly what's going on. (Can you inspect connections inside each thread, for example...)

At this stage it's not clear that Django is at fault, or that the intended usage is supported or ... — as such it's needsinfo. That doesn't mean it can't be addressed if we can pin it down some more, just that it's not clear what, if anything, we can or should do. I hope that makes sense.

[Mike Lissner]

For others that land on this esoteric bug, I was able to produce a version of it today. I have been working on making tests faster, and one step of that is to enable the --parallel flag. When I did, I started getting this error after tests ran:

Ran 26 tests in 6.688s

OK
Destroying test database for alias 'default'...
Destroying test database for alias 'default'...
Destroying test database for alias 'default'...
Destroying test database for alias 'default'...
Destroying test database for alias 'default'...
/usr/local/lib/python3.8/site-packages/django/db/backends/postgresql/base.py:304: RuntimeWarning: Normally Django will use a connection to the 'postgres' database to avoid running initialization queries against the production database when it's not needed (for example, when running tests). Django was unable to create a connection to the 'postgres' database and will use the first PostgreSQL database instead.
  warnings.warn(
Traceback (most recent call last):
  File "/usr/local/lib/python3.8/site-packages/django/db/backends/utils.py", line 82, in _execute
    return self.cursor.execute(sql)
psycopg2.errors.ObjectInUse: database "test_courtlistener" is being accessed by other users
DETAIL:  There is 1 other session using the database.


The above exception was the direct cause of the following exception:

Traceback (most recent call last):
  File "/usr/local/lib/python3.8/site-packages/django/db/backends/postgresql/base.py", line 302, in _nodb_cursor
    yield cursor
  File "/usr/local/lib/python3.8/site-packages/django/db/backends/base/creation.py", line 293, in _destroy_test_db
    cursor.execute("DROP DATABASE %s"
  File "/usr/local/lib/python3.8/site-packages/sentry_sdk/integrations/django/__init__.py", line 499, in execute
    return real_execute(self, sql, params)
  File "/usr/local/lib/python3.8/site-packages/django/db/backends/utils.py", line 66, in execute
    return self._execute_with_wrappers(sql, params, many=False, executor=self._execute)
  File "/usr/local/lib/python3.8/site-packages/django/db/backends/utils.py", line 75, in _execute_with_wrappers
    return executor(sql, params, many, context)
  File "/usr/local/lib/python3.8/site-packages/django/db/backends/utils.py", line 84, in _execute
    return self.cursor.execute(sql, params)
  File "/usr/local/lib/python3.8/site-packages/django/db/utils.py", line 90, in __exit__
    raise dj_exc_value.with_traceback(traceback) from exc_value
  File "/usr/local/lib/python3.8/site-packages/django/db/backends/utils.py", line 82, in _execute
    return self.cursor.execute(sql)
django.db.utils.OperationalError: database "test_courtlistener" is being accessed by other users
DETAIL:  There is 1 other session using the database.


During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/opt/courtlistener/manage.py", line 15, in <module>
    main()
  File "/opt/courtlistener/manage.py", line 11, in main
    execute_from_command_line(sys.argv)
  File "/usr/local/lib/python3.8/site-packages/django/core/management/__init__.py", line 401, in execute_from_command_line
    utility.execute()
  File "/usr/local/lib/python3.8/site-packages/django/core/management/__init__.py", line 395, in execute
    self.fetch_command(subcommand).run_from_argv(self.argv)
  File "/usr/local/lib/python3.8/site-packages/django/core/management/commands/test.py", line 23, in run_from_argv
    super().run_from_argv(argv)
  File "/usr/local/lib/python3.8/site-packages/django/core/management/base.py", line 330, in run_from_argv
    self.execute(*args, **cmd_options)
  File "/usr/local/lib/python3.8/site-packages/django/core/management/base.py", line 371, in execute
    output = self.handle(*args, **options)
  File "/usr/local/lib/python3.8/site-packages/django/core/management/commands/test.py", line 53, in handle
    failures = test_runner.run_tests(test_labels)
  File "/usr/local/lib/python3.8/site-packages/django/test/runner.py", line 705, in run_tests
    self.teardown_databases(old_config)
  File "/usr/local/lib/python3.8/site-packages/django/test/runner.py", line 645, in teardown_databases
    _teardown_databases(
  File "/usr/local/lib/python3.8/site-packages/django/test/utils.py", line 298, in teardown_databases
    connection.creation.destroy_test_db(old_name, verbosity, keepdb)
  File "/usr/local/lib/python3.8/site-packages/django/db/backends/base/creation.py", line 277, in destroy_test_db
    self._destroy_test_db(test_database_name, verbosity)
  File "/usr/local/lib/python3.8/site-packages/django/db/backends/base/creation.py", line 293, in _destroy_test_db
    cursor.execute("DROP DATABASE %s"
  File "/usr/local/lib/python3.8/contextlib.py", line 162, in __exit__
    raise RuntimeError("generator didn't stop after throw()")
RuntimeError: generator didn't stop after throw()
Sentry is attempting to send 1 pending error messages
Waiting up to 2 seconds
Press Ctrl-C to quit

This was very irritating to track down, but by bisecting the tests, I was able to eventually figure out that one of my tests used __init__() instead of setUp. Eventually, I swapped out that, and everything worked. You can see the commit here: ​https://github.com/freelawproject/courtlistener/commit/57c51d124e0a5deae96016e6fb26da03ff3a09ca

[Peter Ashford]

I have the same issue. I am using a TransactionTestCase with multiple threads
Postgres 12.8 (Ubuntu 12.8-0ubuntu0.20.04.1)
Django 2.2.16.
Nosetests test runner v1.3.7
I'm not using init in my test classes (as per last post on this bug)

[Ryan Causey]

I found this code snippet in some old tests I was perusing recently. I hope it helps someone.

def close_db_connections(func, *args, **kwargs):
    """
    Decorator to explicitly close db connections during threaded execution

    Note this is necessary to work around:
    https://code.djangoproject.com/ticket/22420
    """

    def _close_db_connections(*args, **kwargs):
        ret = None
        try:
            ret = func(*args, **kwargs)
        finally:
            for conn in connections.all():
                conn.close()
        return ret

    return _close_db_connections

# This decorator is necessary to work around:
# https://code.djangoproject.com/ticket/22420
@close_db_connections
def create_account():
    """Create an account for the test_user."""
    account = Account(
        name="foo",
        jurisdiction=test_jurisdiction,
        alarm_system_address=test_address,
        alarm_system_user=test_user,
        effective_creation_date=timezone.now().date(),
    )
    account.full_clean()
    account.save()
    return account

futures = []
with ThreadPoolExecutor() as executor:
    # Try to run one thousand account creations concurrently.
    for _ in range(1000):
        futures.append(executor.submit(create_account))

[David Greaves]

In case this is useful to others I'll add this here:

I'm running my tests and using some asyncio code and the pytest_django plugin

I'm using a ThreadExecutor to run the django via the 'a' methods or sync_to_async
I've used a hacked version of django_db_setup to make this run.

All db operations are working but I get this problem.

My suspicion is that the initial django setup is occuring in the MainThread as there is a connection to the test db there.

Adding in a conn.close() loop into the django_db_setup() finalizer resolved the issue for me.