Teardown of a PG test database fails if it is an autogenerated test_MYDB database

[Cynthia Kiser]

When running tests using a Postgres instance where the user does not have access to the postgres database, the database teardown fails with the message: django.db.utils.OperationalError: cannot drop the currently open database

I do not see any problems on 1.8 release branch starting from the commit referenced in #24791. The commit that was made to the master branch at that time also works - until the commit to fix #25329. That commit was before the branch for 1.9 was cut, so this bug affects all releases in the 1.9 and 1.10 series as well as the current master branch.

I don't understand the issue well enough to resolve the apparent conflict between supporting MySQL and Postgres, but I do have a sample app (the polls tutorial) with a README that explains how to set up your database to reproduce the issue: ​https://github.com/cnk/d110example

[Tim Graham]

The report seems credible, although I did not attempt to reproduce myself.

[Cynthia Kiser]

I was wondering if the problem was that Django was trying to drop the wrong database (e.g. postgres) so I put a print statement in django.db.backends.base.creation.py and the error is coming from trying to drop the correct test_X database. I have a sneaking suspicion that despite the comment in that method, we are actually connecting to text_X before trying to drop test_X. (The commit that broke this behavior changed the decorator on _nodb_connection from @cached_property to just @property.)

    def _destroy_test_db(self, test_database_name, verbosity):
        """
        Internal implementation - remove the test db tables.
        """
        # Remove the test database to clean up after
        # ourselves. Connect to the previous database (not the test database)
        # to do so, because it's not allowed to delete a database while being
        # connected to it.
        with self.connection._nodb_connection.cursor() as cursor:
            # Wait to avoid "database is being accessed by other users" errors.
            time.sleep(1)
            print('************* dropping test db {} ********'.format(test_database_name))
            cursor.execute("DROP DATABASE %s"
                           % self.connection.ops.quote_name(test_database_name))

[Andrew Nester]

Hi Cynthia!

I was trying reproduce your issue with your test app and no luck, tests passed fine.
Maybe there's something about postgre configuration that it doesn't close connection properly?
Please provide more details if possible.
Thanks!

[Cynthia Kiser]

The postgres install is pretty standard - using the packages installed via apt on Ubuntu 16.04.

$ dpkg -l | grep postgres
ii  postgresql-9.5                     9.5.5-0ubuntu0.16.04            amd64        object-relational SQL database, version 9.5 server
ii  postgresql-client                  9.5+173                         all          front-end programs for PostgreSQL (supported version)
ii  postgresql-client-9.5              9.5.5-0ubuntu0.16.04            amd64        front-end programs for PostgreSQL 9.5
ii  postgresql-client-common           173                             all          manager for multiple PostgreSQL client versions
ii  postgresql-common                  173                             all          PostgreSQL database-cluster manager
ii  postgresql-contrib-9.5             9.5.5-0ubuntu0.16.04            amd64        additional facilities for PostgreSQL

The same VM + same database did not have trouble dropping the test database when I was running Django 1.8. The error started appearing as soon as I upgraded to 1.9.

The only thing I am doing that is non-standard is the django database user does not have access to the postgres database. My database / user set up is as follows (from the referenced demo project):

For this test, I set up the database and database user as follows:

postgres=# create user d110example password 'd110example' CREATEDB;

postgres=# create database d110example owner d110example;


postgres=# \l
List of databases
Name             |    Owner    | Encoding |   Collate   |    Ctype    |   Access privileges
------------------+-------------+----------+-------------+-------------+-----------------------
d110example      | d110example | UTF8     | en_US.UTF-8 | en_US.UTF-8 |
postgres         | postgres    | UTF8     | en_US.UTF-8 | en_US.UTF-8 |
template0        | postgres    | UTF8     | en_US.UTF-8 | en_US.UTF-8 | =c/postgres + postgres=CTc/postgres
template1        | postgres    | UTF8     | en_US.UTF-8 | en_US.UTF-8 | =c/postgres + postgres=CTc/postgres
(4 rows)

postgres=# \du
List of roles
Role name   |                         Attributes                         | Member of
-------------+------------------------------------------------------------+-----------
d110example | Create DB                                                  | {}
postgres    | Superuser, Create role, Create DB, Replication, Bypass RLS | {}


# And these lines in the pg_hba.conf (my VM answers on 10.1.99.100)

# local DATABASE            USER            METHOD  [OPTIONS]
local   d110example         d110example     md5
local   test_d110example    d110example     md5
# host  DATABASE            USER            ADDRESS         METHOD  [OPTIONS]
host    d110example         d110example     10.1.99.0/24    md5
host    test_d110example    d110example     10.1.99.0/24    md5

And the database settings from settings.py are as follows. I do not have any environment variables set but left them in my example to make it easier for other people to run the example on their machines.

DATABASES = {
    'default': {
        'ENGINE': 'django.db.backends.postgresql_psycopg2',
        'NAME': os.environ.get('DATABASE_NAME', 'd110example'),
        'USER': os.environ.get('DATABASE_USER', 'd110example'),
        'PASSWORD': os.environ.get('DATABASE_PASSWORD', 'd110example'),
        'HOST': os.environ.get('DATABASE_HOST', '10.1.99.100'),
        'PORT': os.environ.get('DATABASE_PORT', '5432'),
        'CHARSET': 'utf8',
    },
}

[Andrew Nester]

Thanks for great explanation!
Sorry, but I still can't reproduce it.

Could you please attach Postgre log file when tests failed?

[Cynthia Kiser]

$ tail -f /var/log/postgresql/postgresql-9.5-main.log

2017-01-27 09:44:28 PST [17850-1] d110example@postgres FATAL:  no pg_hba.conf entry for host "10.1.99.1", user "d110example", database "postgres", SSL on
2017-01-27 09:44:28 PST [17851-1] d110example@postgres FATAL:  no pg_hba.conf entry for host "10.1.99.1", user "d110example", database "postgres", SSL off
2017-01-27 09:44:28 PST [17856-1] d110example@postgres FATAL:  no pg_hba.conf entry for host "10.1.99.1", user "d110example", database "postgres", SSL on
2017-01-27 09:44:28 PST [17857-1] d110example@postgres FATAL:  no pg_hba.conf entry for host "10.1.99.1", user "d110example", database "postgres", SSL off
2017-01-27 09:44:29 PST [17858-1] d110example@test_d110example ERROR:  cannot drop the currently open database
2017-01-27 09:44:29 PST [17858-2] d110example@test_d110example STATEMENT:  DROP DATABASE "test_d110example"

Output from running tests:

$ python manage.py test
Creating test database for alias 'default'...
/Users/cnk/.pyenv/versions/d110example-3.5.2/lib/python3.5/site-packages/django/db/backends/postgresql/base.py:248: 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 default database instead.
  RuntimeWarning
..........
----------------------------------------------------------------------
Ran 10 tests in 0.125s

OK
Destroying test database for alias 'default'...
/Users/cnk/.pyenv/versions/d110example-3.5.2/lib/python3.5/site-packages/django/db/backends/postgresql/base.py:248: 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 default database instead.
  RuntimeWarning
Traceback (most recent call last):
  File "/Users/cnk/.pyenv/versions/d110example-3.5.2/lib/python3.5/site-packages/django/db/backends/utils.py", line 62, in execute
    return self.cursor.execute(sql)
psycopg2.OperationalError: cannot drop the currently open database


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

Traceback (most recent call last):
  File "manage.py", line 22, in <module>
    execute_from_command_line(sys.argv)
  File "/Users/cnk/.pyenv/versions/d110example-3.5.2/lib/python3.5/site-packages/django/core/management/__init__.py", line 367, in execute_from_command_line
    utility.execute()
  File "/Users/cnk/.pyenv/versions/d110example-3.5.2/lib/python3.5/site-packages/django/core/management/__init__.py", line 359, in execute
    self.fetch_command(subcommand).run_from_argv(self.argv)
  File "/Users/cnk/.pyenv/versions/d110example-3.5.2/lib/python3.5/site-packages/django/core/management/commands/test.py", line 29, in run_from_argv
    super(Command, self).run_from_argv(argv)
  File "/Users/cnk/.pyenv/versions/d110example-3.5.2/lib/python3.5/site-packages/django/core/management/base.py", line 294, in run_from_argv
    self.execute(*args, **cmd_options)
  File "/Users/cnk/.pyenv/versions/d110example-3.5.2/lib/python3.5/site-packages/django/core/management/base.py", line 345, in execute
    output = self.handle(*args, **options)
  File "/Users/cnk/.pyenv/versions/d110example-3.5.2/lib/python3.5/site-packages/django/core/management/commands/test.py", line 72, in handle
    failures = test_runner.run_tests(test_labels)
  File "/Users/cnk/.pyenv/versions/d110example-3.5.2/lib/python3.5/site-packages/django/test/runner.py", line 551, in run_tests
    self.teardown_databases(old_config)
  File "/Users/cnk/.pyenv/versions/d110example-3.5.2/lib/python3.5/site-packages/django/test/runner.py", line 526, in teardown_databases
    connection.creation.destroy_test_db(old_name, self.verbosity, self.keepdb)
  File "/Users/cnk/.pyenv/versions/d110example-3.5.2/lib/python3.5/site-packages/django/db/backends/base/creation.py", line 264, in destroy_test_db
    self._destroy_test_db(test_database_name, verbosity)
  File "/Users/cnk/.pyenv/versions/d110example-3.5.2/lib/python3.5/site-packages/django/db/backends/base/creation.py", line 283, in _destroy_test_db
    % self.connection.ops.quote_name(test_database_name))
  File "/Users/cnk/.pyenv/versions/d110example-3.5.2/lib/python3.5/site-packages/django/db/backends/utils.py", line 64, in execute
    return self.cursor.execute(sql, params)
  File "/Users/cnk/.pyenv/versions/d110example-3.5.2/lib/python3.5/site-packages/django/db/utils.py", line 94, in __exit__
    six.reraise(dj_exc_type, dj_exc_value, traceback)
  File "/Users/cnk/.pyenv/versions/d110example-3.5.2/lib/python3.5/site-packages/django/utils/six.py", line 685, in reraise
    raise value.with_traceback(tb)
  File "/Users/cnk/.pyenv/versions/d110example-3.5.2/lib/python3.5/site-packages/django/db/backends/utils.py", line 62, in execute
    return self.cursor.execute(sql)
django.db.utils.OperationalError: cannot drop the currently open database

---

Using django 1.8

2017-01-27 09:53:37 PST [18450-1] d110example@postgres FATAL:  no pg_hba.conf entry for host "10.1.99.1", user "d110example", database "postgres", SSL on
2017-01-27 09:53:37 PST [18451-1] d110example@postgres FATAL:  no pg_hba.conf entry for host "10.1.99.1", user "d110example", database "postgres", SSL off

(using-django1.8)$ python manage.py test
Creating test database for alias 'default'...
/Users/cnk/.pyenv/versions/d110example-3.5.2/lib/python3.5/site-packages/django/db/backends/postgresql_psycopg2/base.py:249: 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 default database instead.
  RuntimeWarning

..........
----------------------------------------------------------------------
Ran 10 tests in 0.059s

OK
Destroying test database for alias 'default'...

[Ian Clark]

This is happening because you are missing an entry in your pg_hba.conf file for your user to access the database 'postgres'. Ran into this problem myself today.

[Cynthia Kiser]

Replying to Ian Clark:

This is happening because you are missing an entry in your pg_hba.conf file for your user to access the database 'postgres'. Ran into this problem myself today.

I do not want my django user to write to the 'postgres' database. I consider the test framework trying to write to the postgres database a bug - one that was fixed in ticket #24791 - and then broken again in ticket #25329.

[Cynthia Kiser]

Replying to Andrew Nester:

Thanks for great explanation!
Sorry, but I still can't reproduce it.

I thought of one more thing - I didn't say explicitly that I am using python 3 (though the stack trace shows python3.5 in the path).

I am really puzzled you are having a hard time reproducing this. Can you think of anything else I can tell you that might identify the difference between our environments?

[Marek Onuszko]

I'm getting the same error.

Debian Linux 8.0 (Jessie)
Python 3.4.2 (python --version)
Django 1.10.5 (installed in virtualenv via pip)
psycopg2 2.7.1 (installed in virtualenv via pip)

dpkg -l | grep postgres
ii  postgresql                                                  9.4+165+deb8u2                       all          object-relational SQL database (supported version)
ii  postgresql-9.4                                              9.4.10-0+deb8u1                      amd64        object-relational SQL database, version 9.4 server
ii  postgresql-client-9.4                                       9.4.10-0+deb8u1                      amd64        front-end programs for PostgreSQL 9.4
ii  postgresql-client-common                                    165+deb8u2                           all          manager for multiple PostgreSQL client versions
ii  postgresql-common                                           165+deb8u2                           all          PostgreSQL database-cluster manager
ii  postgresql-server-dev-9.4                                   9.4.10-0+deb8u1                      amd64        development files for PostgreSQL 9.4 server-side programming

Setting up database was like this:

CREATE ROLE kartyuser LOGIN PASSWORD 'somepassword';
ALTER ROLE kartyuser CREATEDB;
CREATE DATABASE kartydb;
ALTER ROLE kartyuser SET client_encoding TO 'utf8';
ALTER ROLE kartyuser SET default_transaction_isolation TO 'read committed';
ALTER ROLE kartyuser SET timezone TO 'UTC';
GRANT ALL PRIVILEGES ON DATABASE kartydb TO kartyuser;

pg_hba.conf:

# "local" is for Unix domain socket connections only
local   all             all                                     peer
host    kartydb         kartyuser       10.7.90.5/24            md5
host    test_kartydb    kartyuser       10.7.90.5/24            md5
# IPv4 local connections:
host    all             all             127.0.0.1/32            md5
# IPv6 local connections:
host    all             all             ::1/128                 md5

settings.py:

DATABASES = {
    'default': {
        'ENGINE': 'django.db.backends.postgresql_psycopg2',
        'NAME': 'kartydb',
        'USER': 'kartyuser',
        'PASSWORD': 'somepassword',
        'HOST': '10.7.90.5',
        'PORT': '5432',
    }
}

runtests.sh:

coverage run manage.py test karty.tests
coverage report

Traceback:

/home/monuszko/warsztat/ENV/karty/lib/python3.4/site-packages/django/db/backends/postgresql/base.py:248: 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 default database instead.
  RuntimeWarning
Got an error creating the test database: database "test_kartydb" already exists

Type 'yes' if you would like to try deleting the test database 'test_kartydb', or 'no' to cancel: yes
Destroying old test database for alias 'default'...
..........................
----------------------------------------------------------------------
Ran 26 tests in 4.090s

OK
Destroying test database for alias 'default'...
/home/monuszko/warsztat/ENV/karty/lib/python3.4/site-packages/django/db/backends/postgresql/base.py:248: 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 default database instead.
  RuntimeWarning
Traceback (most recent call last):
  File "/home/monuszko/warsztat/ENV/karty/lib/python3.4/site-packages/django/db/backends/utils.py", line 62, in execute
    return self.cursor.execute(sql)
psycopg2.OperationalError: cannot drop the currently open database


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

Traceback (most recent call last):
  File "manage.py", line 22, in <module>
    execute_from_command_line(sys.argv)
  File "/home/monuszko/warsztat/ENV/karty/lib/python3.4/site-packages/django/core/management/__init__.py", line 367, in execute_from_command_line
    utility.execute()
  File "/home/monuszko/warsztat/ENV/karty/lib/python3.4/site-packages/django/core/management/__init__.py", line 359, in execute
    self.fetch_command(subcommand).run_from_argv(self.argv)
  File "/home/monuszko/warsztat/ENV/karty/lib/python3.4/site-packages/django/core/management/commands/test.py", line 29, in run_from_argv
    super(Command, self).run_from_argv(argv)
  File "/home/monuszko/warsztat/ENV/karty/lib/python3.4/site-packages/django/core/management/base.py", line 294, in run_from_argv
    self.execute(*args, **cmd_options)
  File "/home/monuszko/warsztat/ENV/karty/lib/python3.4/site-packages/django/core/management/base.py", line 345, in execute
    output = self.handle(*args, **options)
  File "/home/monuszko/warsztat/ENV/karty/lib/python3.4/site-packages/django/core/management/commands/test.py", line 72, in handle
    failures = test_runner.run_tests(test_labels)
  File "/home/monuszko/warsztat/ENV/karty/lib/python3.4/site-packages/django/test/runner.py", line 551, in run_tests
    self.teardown_databases(old_config)
  File "/home/monuszko/warsztat/ENV/karty/lib/python3.4/site-packages/django/test/runner.py", line 526, in teardown_databases
    connection.creation.destroy_test_db(old_name, self.verbosity, self.keepdb)
  File "/home/monuszko/warsztat/ENV/karty/lib/python3.4/site-packages/django/db/backends/base/creation.py", line 264, in destroy_test_db
    self._destroy_test_db(test_database_name, verbosity)
  File "/home/monuszko/warsztat/ENV/karty/lib/python3.4/site-packages/django/db/backends/base/creation.py", line 283, in _destroy_test_db
    % self.connection.ops.quote_name(test_database_name))
  File "/home/monuszko/warsztat/ENV/karty/lib/python3.4/site-packages/django/db/backends/utils.py", line 64, in execute
    return self.cursor.execute(sql, params)
  File "/home/monuszko/warsztat/ENV/karty/lib/python3.4/site-packages/django/db/utils.py", line 94, in __exit__
    six.reraise(dj_exc_type, dj_exc_value, traceback)
  File "/home/monuszko/warsztat/ENV/karty/lib/python3.4/site-packages/django/utils/six.py", line 685, in reraise
    raise value.with_traceback(tb)
  File "/home/monuszko/warsztat/ENV/karty/lib/python3.4/site-packages/django/db/backends/utils.py", line 62, in execute
    return self.cursor.execute(sql)
django.db.utils.OperationalError: cannot drop the currently open database

Name                                              Stmts   Miss Branch BrPart  Cover
-----------------------------------------------------------------------------------
karty/admin.py                                       10      0      0      0   100%
karty/apps.py                                         3      0      0      0   100%
karty/factories.py                                   35      0      4      0   100%
karty/management/commands/create_sample_data.py      18      0      4      0   100%
karty/management/commands/destroy_app_data.py         7      0      0      0   100%
karty/models.py                                      44      1      4      0    98%
karty/serializers.py                                 11      0      0      0   100%
karty/urls.py                                         4      0      0      0   100%
karty/views.py                                       53      2      8      1    95%
-----------------------------------------------------------------------------------
TOTAL                                               185      3     20      1    98%

[Marek Onuszko]

I used the workaround:

\c postgres
GRANT SELECT ON ALL TABLES IN SCHEMA public to kartyuser;

and added this line to pg_hba.conf:

host    postgres        kartyuser       10.7.90.5/24            md5