Ensure weakref finalize_fairy operates upon the current connection

Fixed a fairly serious connection pool bug where a connection that is
acquired after being refreshed as a result of a user-defined
:class:`.DisconnectionError` or due to the 1.2-released "pre_ping" feature
would not be correctly reset if the connection were returned to the pool by
weakref cleanup (e.g. the front-facing object is garbage collected); the
weakref would still refer to the previously invalidated DBAPI connection
which would have the reset operation erroneously called upon it instead.
This would lead to stack traces in the logs and a connection being checked
into the pool without being reset, which can cause locking issues.

Change-Id: Iabd9f3a63a1d0207d0de0054a6ced3560818cf9c
Fixes: #4184

diff --git a/doc/build/changelog/unreleased_11/4184.rst b/doc/build/changelog/unreleased_11/4184.rst
new file mode 100644 (file)
index 0000000..4e0eb45
--- /dev/null
+++ b/doc/build/changelog/unreleased_11/4184.rst
@@ -0,0 +1,14 @@
+.. change::
+    :tags: bug, pool
+    :tickets: 4184
+
+    Fixed a fairly serious connection pool bug where a connection that is
+    acquired after being refreshed as a result of a user-defined
+    :class:`.DisconnectionError` or due to the 1.2-released "pre_ping" feature
+    would not be correctly reset if the connection were returned to the pool by
+    weakref cleanup (e.g. the front-facing object is garbage collected); the
+    weakref would still refer to the previously invalidated DBAPI connection
+    which would have the reset operation erroneously called upon it instead.
+    This would lead to stack traces in the logs and a connection being checked
+    into the pool without being reset, which can cause locking issues.
+

diff --git a/lib/sqlalchemy/pool.py b/lib/sqlalchemy/pool.py
index 45b02d5f50cc6b2ec1c79e1ea74f55734436a8ee..102d50c18ea5dfb76e11c2a1a68356a156d5b601 100644 (file)
--- a/lib/sqlalchemy/pool.py
+++ b/lib/sqlalchemy/pool.py
@@ -541,7 +541,7 @@ class _ConnectionRecord(object):
             fairy,
             lambda ref: _finalize_fairy and
             _finalize_fairy(
-                dbapi_connection,
+                None,
                 rec, pool, ref, echo)
         )
         _refs.add(rec)
@@ -687,9 +687,11 @@ def _finalize_fairy(connection, connection_record,
     """
     _refs.discard(connection_record)
 
-    if ref is not None and \
-            connection_record.fairy_ref is not ref:
-        return
+    if ref is not None:
+        if connection_record.fairy_ref is not ref:
+            return
+        assert connection is None
+        connection = connection_record.connection
 
     if connection is not None:
         if connection_record and echo:
@@ -826,13 +828,14 @@ class _ConnectionFairy(object):
                     pool.logger.info(
                         "Disconnection detected on checkout, "
                         "invalidating all pooled connections prior to "
-                        "current timestamp: %r", e)
+                        "current timestamp (reason: %r)", e)
                     fairy._connection_record.invalidate(e)
                     pool._invalidate(fairy, e, _checkin=False)
                 else:
                     pool.logger.info(
                         "Disconnection detected on checkout, "
-                        "invalidating individual connection: %r", e)
+                        "invalidating individual connection %s (reason: %r)",
+                        fairy.connection, e)
                     fairy._connection_record.invalidate(e)
                 try:
                     fairy.connection = \

diff --git a/test/engine/test_pool.py b/test/engine/test_pool.py
index a556c97a15c8eaff142e21feedc13b2ae5dad060..e3f34dfa797ba054e2e5f5c77e5135aae5b926dd 100644 (file)
--- a/test/engine/test_pool.py
+++ b/test/engine/test_pool.py
@@ -1758,6 +1758,40 @@ class QueuePoolTest(PoolTestBase):
 
         self._assert_cleanup_on_pooled_reconnect(dbapi, p)
 
+    @testing.requires.predictable_gc
+    def test_userspace_disconnectionerror_weakref_finalizer(self):
+        dbapi, pool = self._queuepool_dbapi_fixture(
+            pool_size=1,
+            max_overflow=2)
+
+        @event.listens_for(pool, "checkout")
+        def handle_checkout_event(dbapi_con, con_record, con_proxy):
+            if getattr(dbapi_con, 'boom') == 'yes':
+                raise tsa.exc.DisconnectionError()
+
+        conn = pool.connect()
+        old_dbapi_conn = conn.connection
+        conn.close()
+
+        eq_(old_dbapi_conn.mock_calls, [call.rollback()])
+
+        old_dbapi_conn.boom = 'yes'
+
+        conn = pool.connect()
+        dbapi_conn = conn.connection
+        del conn
+        gc_collect()
+
+        # new connection was reset on return appropriately
+        eq_(dbapi_conn.mock_calls, [call.rollback()])
+
+        # old connection was just closed - did not get an
+        # erroneous reset on return
+        eq_(
+            old_dbapi_conn.mock_calls,
+            [call.rollback(), call.close()]
+        )
+
     @testing.requires.timing_intensive
     def test_recycle_pool_no_race(self):
         def slow_close():

diff --git a/test/engine/test_reconnect.py b/test/engine/test_reconnect.py
index c690ae77285c56e26117daccbe4a7f9f57e355a5..d0b6cc959044bd771934e63b0a3f399e5992d1f1 100644 (file)
--- a/test/engine/test_reconnect.py
+++ b/test/engine/test_reconnect.py
@@ -13,6 +13,7 @@ from sqlalchemy.testing import fixtures
 from sqlalchemy.testing.engines import testing_engine
 from sqlalchemy.testing.mock import Mock, call, patch
 from sqlalchemy import event
+from sqlalchemy.testing.util import gc_collect
 
 
 class MockError(Exception):
@@ -206,6 +207,34 @@ class PrePingMockTest(fixtures.TestBase):
             cursor.execute, "foo"
         )
 
+    @testing.requires.predictable_gc
+    def test_pre_ping_weakref_finalizer(self):
+        pool = self._pool_fixture(pre_ping=True)
+
+        conn = pool.connect()
+        old_dbapi_conn = conn.connection
+        conn.close()
+
+        eq_(old_dbapi_conn.mock_calls, [call.cursor(), call.rollback()])
+
+        self.dbapi.shutdown("execute", stop=True)
+        self.dbapi.restart()
+
+        conn = pool.connect()
+        dbapi_conn = conn.connection
+        del conn
+        gc_collect()
+
+        # new connection was reset on return appropriately
+        eq_(dbapi_conn.mock_calls, [call.cursor(), call.rollback()])
+
+        # old connection was just closed - did not get an
+        # erroneous reset on return
+        eq_(
+            old_dbapi_conn.mock_calls,
+            [call.cursor(), call.rollback(), call.cursor(), call.close()]
+        )
+
 
 class MockReconnectTest(fixtures.TestBase):
     def setup(self):