Opened 15 months ago

Closed 13 months ago

Last modified 8 months ago

#22420 closed Bug (needsinfo)

Postgresql connections not being dropped between tests?

Reported by: bacongobbler Owned by: nobody
Component: Testing framework Version: 1.6
Severity: Normal Keywords:
Cc: 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 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.

Change History (18)

comment:1 Changed 15 months ago by bacongobbler

  • Needs documentation unset
  • Needs tests unset
  • Patch needs improvement unset
  • Type changed from Uncategorized to Bug

comment:2 Changed 15 months ago by claudep

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

comment:3 Changed 15 months ago by bacongobbler

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

comment:4 follow-up: Changed 14 months ago by 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.

comment:5 in reply to: ↑ 4 Changed 14 months ago by 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.

comment:6 follow-up: Changed 14 months ago by 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?

comment:7 in reply to: ↑ 6 ; follow-up: Changed 14 months ago by 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.

comment:8 in reply to: ↑ 7 Changed 14 months ago by 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.

comment:9 Changed 14 months ago by timo

  • Resolution set to invalid
  • Status changed from new to closed

All right thanks, please reopen if you determine otherwise.

comment:10 follow-ups: Changed 14 months ago by gabrtv

  • Resolution invalid deleted
  • Status changed from closed to new

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.

comment:11 in reply to: ↑ 10 Changed 14 months ago by 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.

comment:12 Changed 13 months ago by 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.

comment:13 Changed 13 months ago by 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?

comment:14 Changed 13 months ago by anonymous

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

comment:15 Changed 13 months ago by 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.

comment:16 Changed 13 months ago by timo

  • Resolution set to needsinfo
  • Status changed from new to closed

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

comment:17 in reply to: ↑ 10 Changed 9 months ago by trueqbit

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
Last edited 8 months ago by trueqbit (previous) (diff)

comment:18 Changed 8 months ago by pwmarcz

I'm running into 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.

Last edited 8 months ago by pwmarcz (previous) (diff)
Note: See TracTickets for help on using tickets.
Back to Top