From 9cbc6343328d40a7b61c9a42ad28466d5f5051e5 Mon Sep 17 00:00:00 2001 From: Steven Lang Date: Thu, 21 Nov 2013 11:46:15 -0800 Subject: [PATCH] Fix DB locked error on commit This bug was introduced in ef7f9e27; while moving timeout for execute to the cursor wrapper, commit was moved as well; however commit is purely a connection method, only execute is passed on to a cursor. Added unit tests to check both methods for correct timeouts. This manifested in a test failure as: ERROR __call__ error with POST /sdb1/418/AUTH_d1c4b610b16a48de83219c696261009c/TestContainer-tempest-1572414684 : Traceback (most recent call last): File "/opt/stack/new/swift/swift/container/server.py", line 486, in __call__ res = method(req) File "/opt/stack/new/swift/swift/common/utils.py", line 1915, in wrapped return func(*a, **kw) File "/opt/stack/new/swift/swift/common/utils.py", line 687, in _timing_stats resp = func(ctrl, *args, **kwargs) File "/opt/stack/new/swift/swift/container/server.py", line 464, in POST broker.update_metadata(metadata) File "/opt/stack/new/swift/swift/common/db.py", line 677, in update_metadata conn.commit() OperationalError: database is locked (txn: tx5065394f288740e69fcec-00528e184e) Change-Id: I269b133fac53d4792d21b62f801cc0c0ccf337ea --- swift/common/db.py | 38 +++++++++++++++------------- test/unit/common/test_db.py | 49 +++++++++++++++++++++++++++++-------- 2 files changed, 60 insertions(+), 27 deletions(-) diff --git a/swift/common/db.py b/swift/common/db.py index e5b957e7da..6f921a70e9 100644 --- a/swift/common/db.py +++ b/swift/common/db.py @@ -57,6 +57,19 @@ def utf8encodekeys(metadata): metadata[k.encode('utf-8')] = sv +def _db_timeout(timeout, db_file, call): + with LockTimeout(timeout, db_file): + retry_wait = 0.001 + while True: + try: + return call() + except sqlite3.OperationalError as e: + if 'locked' not in str(e): + raise + sleep(retry_wait) + retry_wait = min(retry_wait * 2, 0.05) + + class DatabaseConnectionError(sqlite3.DatabaseError): """More friendly error messages for DB Errors.""" @@ -94,6 +107,11 @@ class GreenDBConnection(sqlite3.Connection): cls = GreenDBCursor return sqlite3.Connection.cursor(self, cls) + def commit(self): + return _db_timeout( + self.timeout, self.db_file, + lambda: sqlite3.Connection.commit(self)) + class GreenDBCursor(sqlite3.Cursor): """SQLite Cursor handler that plays well with eventlet.""" @@ -103,24 +121,10 @@ class GreenDBCursor(sqlite3.Cursor): self.db_file = args[0].db_file sqlite3.Cursor.__init__(self, *args, **kwargs) - def _timeout(self, call): - with LockTimeout(self.timeout, self.db_file): - retry_wait = 0.001 - while True: - try: - return call() - except sqlite3.OperationalError as e: - if 'locked' not in str(e): - raise - sleep(retry_wait) - retry_wait = min(retry_wait * 2, 0.05) - def execute(self, *args, **kwargs): - return self._timeout(lambda: sqlite3.Cursor.execute( - self, *args, **kwargs)) - - def commit(self): - return self._timeout(lambda: sqlite3.Cursor.commit(self)) + return _db_timeout( + self.timeout, self.db_file, lambda: sqlite3.Cursor.execute( + self, *args, **kwargs)) def dict_factory(crs, row): diff --git a/test/unit/common/test_db.py b/test/unit/common/test_db.py index 1901bae53a..2fd78323e7 100644 --- a/test/unit/common/test_db.py +++ b/test/unit/common/test_db.py @@ -29,7 +29,8 @@ from eventlet.timeout import Timeout import swift.common.db from swift.common.db import chexor, dict_factory, get_db_connection, \ - DatabaseBroker, DatabaseConnectionError, DatabaseAlreadyExists + DatabaseBroker, DatabaseConnectionError, DatabaseAlreadyExists, \ + GreenDBConnection from swift.common.utils import normalize_timestamp from swift.common.exceptions import LockTimeout @@ -82,6 +83,41 @@ class TestChexor(unittest.TestCase): normalize_timestamp(1)) +class TestGreenDBConnection(unittest.TestCase): + + def test_execute_when_locked(self): + # This test is dependant on the code under test calling execute and + # commit as sqlite3.Cursor.execute in a subclass. + class InterceptCursor(sqlite3.Cursor): + pass + db_error = sqlite3.OperationalError('database is locked') + InterceptCursor.execute = MagicMock(side_effect=db_error) + with patch('sqlite3.Cursor', new=InterceptCursor): + conn = sqlite3.connect(':memory:', check_same_thread=False, + factory=GreenDBConnection, timeout=0.1) + self.assertRaises(Timeout, conn.execute, 'select 1') + self.assertTrue(InterceptCursor.execute.called) + self.assertEqual(InterceptCursor.execute.call_args_list, + list((InterceptCursor.execute.call_args,) * + InterceptCursor.execute.call_count)) + + def text_commit_when_locked(self): + # This test is dependant on the code under test calling commit and + # commit as sqlite3.Connection.commit in a subclass. + class InterceptConnection(sqlite3.Connection): + pass + db_error = sqlite3.OperationalError('database is locked') + InterceptConnection.commit = MagicMock(side_effect=db_error) + with patch('sqlite3.Connection', new=InterceptConnection): + conn = sqlite3.connect(':memory:', check_same_thread=False, + factory=GreenDBConnection, timeout=0.1) + self.assertRaises(Timeout, conn.commit) + self.assertTrue(InterceptConnection.commit.called) + self.assertEqual(InterceptConnection.commit.call_args_list, + list((InterceptConnection.commit.call_args,) * + InterceptConnection.commit.call_count)) + + class TestGetDBConnection(unittest.TestCase): def test_normal_case(self): @@ -94,22 +130,15 @@ class TestGetDBConnection(unittest.TestCase): def test_locked_db(self): # This test is dependant on the code under test calling execute and - # commit as sqlite3.. in a subclass. - class InterceptConnection(sqlite3.Connection): - pass - + # commit as sqlite3.Cursor.execute in a subclass. class InterceptCursor(sqlite3.Cursor): pass db_error = sqlite3.OperationalError('database is locked') mock_db_cmd = MagicMock(side_effect=db_error) - InterceptConnection.execute = mock_db_cmd - InterceptConnection.commit = mock_db_cmd InterceptCursor.execute = mock_db_cmd - InterceptCursor.commit = mock_db_cmd - with patch.multiple('sqlite3', Connection=InterceptConnection, - Cursor=InterceptCursor): + with patch('sqlite3.Cursor', new=InterceptCursor): self.assertRaises(Timeout, get_db_connection, ':memory:', timeout=0.1) self.assertTrue(mock_db_cmd.called)