lots of test failures with pysqlite file db backend in some Windows environment

[Christian Boos]

With Python 2.7.11 and sqlite3 2.6.0 (3.6.21), we get lots of errors like this one:

======================================================================
ERROR: test_author_full_name (trac.ticket.tests.notification.AttachmentNotificationTestCase)
----------------------------------------------------------------------
Traceback (most recent call last):
  File "C:\projects\trac\trac\ticket\tests\notification.py", line 1524, in tearDown
    shutil.rmtree(self.env.path)
  File "C:\Python27-x64\lib\shutil.py", line 252, in rmtree
    onerror(os.remove, fullname, sys.exc_info())
  File "C:\Python27-x64\lib\shutil.py", line 250, in rmtree
    os.remove(fullname)
WindowsError: [Error 32] The process cannot access the file because it is being used by another process: 'c:\\users\\appveyor\\appdata\\local\\temp\\1\\trac-tempenv-hjqqot\\test.db'

We see that using 32-bits or 64-bits Python 2.7.11.

However, the problem doesn't happen with Python 2.6.6 and sqlite3 2.4.1 (3.5.9) and it also never happens when the in-memory version of SQLite is used (obviously, as the problem is with test.db still opened at the time we do the rmtree).

Locally, I have these additional results:

• reproduced with Python 2.7.9sl x86 (that's a Stackless python)
• reproduced with Python 2.7.10 x64 and pysqlite 2.8.1 (3.7.5)
• no errors with Python 2.6.5

[Christian Boos]

one of the build logs showing the issue

[Jun Omae]

reset_db() doesn't close database connection. Instead, I think we should use shutdown() before rmtree(self.env.path).

trac/ticket/tests/notification.py

@@ -1273 +1273 @@
     def tearDown(self):
         """Signal the notification test suite that a test is over"""
         notifysuite.tear_down()
-        self.env.reset_db()
+        self.env.shutdown()  # really closes the db connections
         shutil.rmtree(self.env.path)
 
     def test_ticket_notify_attachment_enabled_attachment_added(self):

trac/web/tests/api.py

@@ -50 +50 @@
         self.req_handler = module_class(self.env)
 
     def tearDown(self):
-        self.env.reset_db()
+        self.env.shutdown()  # really closes the db connections
         shutil.rmtree(self.path)
 
     def create_request(self, authname='anonymous', **kwargs):

trac/web/tests/chrome.py

@@ -476 +476 @@
         self.chrome = Chrome(self.env)
 
     def tearDown(self):
+        self.env.shutdown()  # really closes the db connections
         shutil.rmtree(self.env.path)
 
     def test_malicious_filename_raises(self):

[Christian Boos]

Thanks!

Yes, this seems to be the logical thing to do, and the tests pass (locally). However, I've seen that elsewhere we sometimes have rmtree followed by reset_db. Like in trac/wiki/tests/model.py:

    def tearDown(self):
        shutil.rmtree(self.env.path)
        self.env.reset_db()

Strange.

[Christian Boos]

I reviewed our usage of rmtree and came up with r14432.

The idea is that tearDown should contain:

• a call to reset_db if the tests created some content in the database,
• a call to rmtree if the tests created something in the env; this must be preceded by a call to shutdown in order to free the resources, and in this case closing opened files (like db connections, but also version control related files)

[Christian Boos]

Replying to Christian Boos:

I reviewed our usage of rmtree and came up with r14432.

That broke 2.7 with SQLite :memory: db:

======================================================================
ERROR: test (trac.wiki.tests.formatter.WikiTestCase)
Test attachment: "foreign" links
----------------------------------------------------------------------
Traceback (most recent call last):
  File "/home/travis/build/edgewall/trac/trac/wiki/tests/formatter.py", line 191, in setUp
    wiki.save('joe', 'Entry page', '::1', datetime.now(utc))
  File "/home/travis/build/edgewall/trac/trac/wiki/model.py", line 148, in save
    self.readonly))
  File "/home/travis/build/edgewall/trac/trac/db/util.py", line 128, in execute
    cursor.execute(query, params if params is not None else [])
  File "/home/travis/build/edgewall/trac/trac/db/util.py", line 61, in execute
    r = self.cursor.execute(sql_escape_percent(sql), args)
  File "/home/travis/build/edgewall/trac/trac/db/sqlite_backend.py", line 82, in execute
    result = PyFormatCursor.execute(self, *args)
  File "/home/travis/build/edgewall/trac/trac/db/sqlite_backend.py", line 60, in execute
    args or [])
  File "/home/travis/build/edgewall/trac/trac/db/sqlite_backend.py", line 52, in _rollback_on_error
    return function(self, *args, **kwargs)
OperationalError: no such table: wiki

(and many more of the same)

But for 2.6 it's fine…

Same situation on both Windows and Linux.

[Christian Boos]

For example, on the test-wiki subset (422 tests failing out of 425), all pass again with:

trac/tests/wikisyntax.py

@@ -144 +144 @@
 
 def attachment_teardown(tc):
     tc.env.reset_db()
-    tc.env.shutdown()
+    # tc.env.shutdown()
     shutil.rmtree(tc.env.path)
 

Probably everything's gone when all connections to an in-memory DB are closed, with the more recent versions of SQLite.

… which brings me back to the idea of adding a few helper methods to be used in tearDown methods.

[Jun Omae]

Replying to Christian Boos:

That broke 2.7 with SQLite :memory: db: […]

But for 2.6 it's fine…

Same situation on both Windows and Linux.

I get the same errors with Python 2.5, 2.6 and 2.7 on Linux.

WikiTestCase in trac.wiki.tests.formatter creates a EnvironmentStub instance on __init__(), not setUp(). It means that the database is initialized before running all tests. I think we should create a EnvironmentStub instance in WikiTestCase.setUp() in order to create it on each test. See attachment:t12310-wikitestcase-setup.diff​, which is verified with all database backends.

[anonymous]

Replying to Jun Omae:

Replying to Christian Boos:

That broke 2.7 with SQLite :memory: db: […]

But for 2.6 it's fine…

Same situation on both Windows and Linux.

I get the same errors with Python 2.5, 2.6 and 2.7 on Linux.

Just out of curiosity, which sqlite3 or PySqlite versions are you using together with these different versions of Python?

[…] I think we should create a EnvironmentStub instance in WikiTestCase.setUp() in order to create it on each test.

I agree and applied your patch in r14438. Let's see how it behaves on AppVeyor…

[Jun Omae]

Replying to anonymous:

Just out of curiosity, which sqlite3 or PySqlite versions are you using together with these different versions of Python?

I'm using Ubuntu 12.04 LTS with older pythons on ​https://launchpad.net/~fkrull/+archive/ubuntu/deadsnakes.

Python	2.5.6	2.6.9	2.7.3
sqlite3	2.3.2 (3.7.9)	2.4.1 (3.7.9)	2.6.0 (3.7.9)
PySqlite	2.6.3 (3.7.9)	2.6.3 (3.7.9)	2.6.3 (3.7.9)

[Christian Boos]

Replying to Jun Omae:

Replying to anonymous (cboos):

Just out of curiosity, which sqlite3 or PySqlite versions are you using together with these different versions of Python?

I'm using Ubuntu 12.04 LTS with older pythons on ​https://launchpad.net/~fkrull/+archive/ubuntu/deadsnakes.

Python	2.5.6	2.6.9	2.7.3
sqlite3	2.3.2 (3.7.9)	2.4.1 (3.7.9)	2.6.0 (3.7.9)
PySqlite	2.6.3 (3.7.9)	2.6.3 (3.7.9)	2.6.3 (3.7.9)

Interesting, that's not consistent with the ​Travis results for Python 2.6.9, as there with sqlite3 2.4.1 (3.7.9) the tests passed.

[Christian Boos]

Actually if your table means that you tested only 3 combinations, with sqlite3 + PySqlite both installed, then as PySqlite takes precedence over sqlite3, this could explain the difference:

• Python 2.6.9 with sqlite3 2.4.1 (3.7.9) and PySqlite not installed ⇒ OK (Travis)
• Python 2.6.9 with sqlite3 2.4.1 (3.7.9) and PySqlite 2.6.3 (3.7.9) ⇒ FAIL (yours)

In that case, something must have changed in PySqlite between 2.4.1 and 2.6.3 w.r.t. in-memory databases.

[Christian Boos]

Following-up to comment:5:

… which brings me back to the idea of adding a few helper methods to be used in tearDown methods.

Ok with reset_db_and_disk() to automate the error prone sequence reset_db/shutdown/rmtree? (log:cboos.git@t12310-reset_db_and_disk)

[Ryan J Ollos]

The helper method looks like a good idea.

[Christian Boos]

Last refactoring committed in [14493], merged on trunk in [14494] with one additional fix, for trac\upgrades\tests\db41.py.