Corner case failures when running the functional tests with alternate db backend

[Christian Boos]

While testing #8502, I've noticed that when running the functional tests for the first time against a non-existing schema, some tests would fail, due to a bootstrap problem.

The errors were:

$ PYTHONPATH=. python trac/db/tests/functional.py
...
Traceback (most recent call last):
  File "trac/db/tests/functional.py", line 27, in <module>
    unittest.main(defaultTest='functionalSuite')
  File "C:\Dev\Python261\lib\unittest.py", line 817, in __init__
    self.runTests()
  File "C:\Dev\Python261\lib\unittest.py", line 861, in runTests
    result = testRunner.run(self.test)
  File "C:\Dev\Python261\lib\unittest.py", line 753, in run
    test(result)
  File "C:\Dev\Python261\lib\unittest.py", line 464, in __call__
    return self.run(*args, **kwds)
  File "C:\Dev\Python261\lib\unittest.py", line 460, in run
    test(result)
  File "C:\Workspace\src\trac\repos\0.11-stable\trac\test.py", line 137, in __call__
    return self.run(*args, **kwds)
  File "C:\Workspace\src\trac\repos\0.11-stable\trac\test.py", line 124, in run
    self.setUp()
  File "C:\Workspace\src\trac\repos\0.11-stable\trac\tests\functional\__init__.py", line 126, in setUp
    self._testenv = self.env_class(dirname, port, baseurl)
  File "C:\Workspace\src\trac\repos\0.11-stable\trac\tests\functional\testenv.py", line 57, in __init__
    self.destroy()
  File "C:\Workspace\src\trac\repos\0.11-stable\trac\tests\functional\testenv.py", line 67, in destroy
    env.destroy_db()
  File "C:\Workspace\src\trac\repos\0.11-stable\trac\test.py", line 350, in destroy_db
    db = self.get_db_cnx()
  File "C:\Workspace\src\trac\repos\0.11-stable\trac\test.py", line 292, in get_db_cnx
    self.reset_db() # make sure we get rid of garbage from previous run
  File "C:\Workspace\src\trac\repos\0.11-stable\trac\test.py", line 343, in reset_db
    ('database_version', str(db_default.db_version)))
  File "C:\Workspace\src\trac\repos\0.11-stable\trac\db\util.py", line 59, in execute
    return self.cursor.execute(sql_escape_percent(sql), args)
  File "C:\Workspace\src\trac\repos\0.11-stable\trac\db\util.py", line 59, in execute
    return self.cursor.execute(sql_escape_percent(sql), args)
psycopg2.ProgrammingError: relation "system" does not exist

The following fixed it for me:

trac/test.py

@@ -276 +276 @@
                 return True
         return False
 
-    def get_db_cnx(self):
+    def get_db_cnx(self, destroying=False):
         if self.db:
             return self.db # in-memory SQLite
 
@@ -289 +289 @@
         if not dbenv:
             dbenv = EnvironmentStub.dbenv = EnvironmentStub()
             dbenv.config.set('trac', 'database', self.dburi)
-            self.reset_db() # make sure we get rid of garbage from previous run
+            if not destroying:
+                self.reset_db() # make sure we get rid of previous garbage
         return DatabaseManager(dbenv).get_connection()
 
     def reset_db(self, default_data=None):
@@ -347 +348 @@
         if not (scheme and db_prop):
             scheme, db_prop = _parse_db_str(self.dburi)
 
-        db = self.get_db_cnx()
+        db = self.get_db_cnx(destroying=True)
         cursor = db.cursor()
         try:
             if scheme == 'postgres' and db.schema:

Remy also had (similar?) problems which were not fixed by the above patch, so we still need to investigate further.

For him, the first errors were:

======================================================================
ERROR: test_delete (trac.tests.attachment.AttachmentTestCase)
----------------------------------------------------------------------
Traceback (most recent call last):
  File "/home/joe/src/trac/0.11-stable/trac/tests/attachment.py", line 101, in test_delete
    attachment1.insert('foo.txt', tempfile.TemporaryFile(), 0)
  File "/home/joe/src/trac/0.11-stable/trac/attachment.py", line 202, in insert
    db = self.env.get_db_cnx()
  File "/home/joe/src/trac/0.11-stable/trac/test.py", line 293, in get_db_cnx
    self.reset_db() # make sure we get rid of previous garbage
  File "/home/joe/src/trac/0.11-stable/trac/test.py", line 344, in reset_db
    ('database_version', str(db_default.db_version)))
  File "/home/joe/src/trac/0.11-stable/trac/db/util.py", line 59, in execute
    return self.cursor.execute(sql_escape_percent(sql), args)
  File "/home/joe/src/trac/0.11-stable/trac/db/util.py", line 59, in execute
    return self.cursor.execute(sql_escape_percent(sql), args)
ProgrammingError: relation "system" does not exist


======================================================================
ERROR: test_delete (trac.tests.attachment.AttachmentTestCase)
----------------------------------------------------------------------
Traceback (most recent call last):
  File "/home/joe/src/trac/0.11-stable/trac/tests/attachment.py", line 43, in tearDown
    self.env.reset_db()
  File "/home/joe/src/trac/0.11-stable/trac/test.py", line 331, in reset_db
    DatabaseManager(EnvironmentStub.dbenv).init_db()
  File "/home/joe/src/trac/0.11-stable/trac/db/api.py", line 81, in init_db
    connector.init_db(**args)
  File "/home/joe/src/trac/0.11-stable/trac/db/postgres_backend.py", line 76, in init_db
    cursor.execute('CREATE SCHEMA "%s"' % cnx.schema)
  File "/home/joe/src/trac/0.11-stable/trac/db/util.py", line 60, in execute
    return self.cursor.execute(sql)
ProgrammingError: schema "tractest-pat-011" already exists


======================================================================
ERROR: test_delete_file_gone (trac.tests.attachment.AttachmentTestCase)
----------------------------------------------------------------------
Traceback (most recent call last):
  File "/home/joe/src/trac/0.11-stable/trac/tests/attachment.py", line 123, in test_delete_file_gone
    attachment.insert('foo.txt', tempfile.TemporaryFile(), 0)
  File "/home/joe/src/trac/0.11-stable/trac/attachment.py", line 234, in insert
    self.author, self.ipnr))
  File "/home/joe/src/trac/0.11-stable/trac/db/util.py", line 59, in execute
    return self.cursor.execute(sql_escape_percent(sql), args)
  File "/home/joe/src/trac/0.11-stable/trac/db/util.py", line 59, in execute
    return self.cursor.execute(sql_escape_percent(sql), args)
ProgrammingError: relation "attachment" does not exist

… whether the above patch was applied or not.

This was obtained while running the unit tests.

[Christian Boos]

I've applied the above patch in r8381 as it fixes the issue for me. Remy could you please try again at that revision?

[Remy Blank]

Replying to cboos:

Remy could you please try again at that revision?

No, still no luck. Just in case, here's the script I use to run the tests (the DB is on another machine):

#!/bin/bash

rm -rf testenv
export TRAC_TEST_DB_URI=postgres://trac:password@mac.vathome:5432/trac?schema=tractest-pat-011
PYTHONPATH=. python trac/test.py

[Christian Boos]

Ah yes, forgot to remove testenv ;-)

I have the error as well now.

[Christian Boos]

Well, removing testenv or not was not the problem, I was just wrong and r8381 doesn't fix the unit-tests for me either. What it fixes arethe functional tests only.

Description updated accordingly.

[Christian Boos]

Hm, I have a fix now, but I don't understand it ;-)

trac/test.py

@@ -328 +328 @@
 
             if not tables:
                 del db
-                DatabaseManager(EnvironmentStub.dbenv).init_db()
+                dm = DatabaseManager(EnvironmentStub.dbenv)
+                dm.init_db()
+                # we need to make sure the next get_db_cnx() will re-create
+                # a new connection aware of the new data model - see #8518.
+                dm.shutdown()
 
         db = self.get_db_cnx()
         cursor = db.cursor()

The idea I had here was that in reset_db(), we should make sure that after init_db(), the get_db_cnx() call that follows doesn't give us back a connection from the pool that existed before the tables were created, as it appears that for PosgreSQL at least, this old connection wouldn't see the newly created tables. So we force a flush of the pool using shutdown().

The problem is, I don't see any reference to that behavior in the PostgreSQL manual or elsewhere on the web, and interactive testing with psql show that this shouldn't be a problem (well, unless psql do some tricks that psycopg2 doesn't).

[Remy Blank]

The patch works fine here. Maybe this is again an issue due to not rolling back connections before releasing them to the pool?

[Christian Boos]

We normally do a rollback before putting connections back into the _pool LRU list.

I've just verified and that rollback is indeed called on the connection, just after the del db before init_db(). So it must be something else.

[Christian Boos]

Ok, for now I've applied the fix from comment:5, in r8416.

One might revisit this issue one day in order to understand it better, but enough for now ;-)