- vastly improve the "safe close cursor" tests in test_reconnect

- Fixed bug which would occur if a DBAPI exception
occurs when the engine first connects and does its initial checks,
and the exception is not a disconnect exception, yet the cursor
raises an error when we try to close it.  In this case the real
exception would be quashed as we tried to log the cursor close
exception via the connection pool and failed, as we were trying
to access the pool's logger in a way that is inappropriate
in this very specific scenario. fixes #3063

4 files changed, 74 insertions, 17 deletions

diff --git a/doc/build/changelog/changelog_09.rst b/doc/build/changelog/changelog_09.rst
index 3e1e06226..d79badd4d 100644
--- a/doc/build/changelog/changelog_09.rst
+++ b/doc/build/changelog/changelog_09.rst
@@ -15,6 +15,20 @@
     :version: 0.9.5
 
     .. change::
+        :tags: bug, engine
+        :versions: 1.0.0
+        :tickets: 3063
+
+        Fixed bug which would occur if a DBAPI exception
+        occurs when the engine first connects and does its initial checks,
+        and the exception is not a disconnect exception, yet the cursor
+        raises an error when we try to close it.  In this case the real
+        exception would be quashed as we tried to log the cursor close
+        exception via the connection pool and failed, as we were trying
+        to access the pool's logger in a way that is inappropriate
+        in this very specific scenario.
+
+    .. change::
         :tags: feature, postgresql
         :versions: 1.0.0
         :pullreq: github:88
diff --git a/lib/sqlalchemy/engine/base.py b/lib/sqlalchemy/engine/base.py
index f9fc04d76..249c494fe 100644
--- a/lib/sqlalchemy/engine/base.py
+++ b/lib/sqlalchemy/engine/base.py
@@ -1054,8 +1054,9 @@ class Connection(Connectable):
         except (SystemExit, KeyboardInterrupt):
             raise
         except Exception:
-            self.connection._logger.error(
-                                    "Error closing cursor", exc_info=True)
+            # log the error through the connection pool's logger.
+            self.engine.pool.logger.error(
+                                "Error closing cursor", exc_info=True)
 
     _reentrant_error = False
     _is_disconnect = False
diff --git a/lib/sqlalchemy/engine/strategies.py b/lib/sqlalchemy/engine/strategies.py
index a8a63bb3d..691c06a8c 100644
--- a/lib/sqlalchemy/engine/strategies.py
+++ b/lib/sqlalchemy/engine/strategies.py
@@ -161,7 +161,6 @@ class DefaultEngineStrategy(EngineStrategy):
             def first_connect(dbapi_connection, connection_record):
                 c = base.Connection(engine, connection=dbapi_connection,
                             _has_events=False)
-
                 dialect.initialize(c)
             event.listen(pool, 'first_connect', first_connect, once=True)
 
diff --git a/test/engine/test_reconnect.py b/test/engine/test_reconnect.py
index 23a3b3703..e6897b13d 100644
--- a/test/engine/test_reconnect.py
+++ b/test/engine/test_reconnect.py
@@ -373,33 +373,76 @@ class MockReconnectTest(fixtures.TestBase):
 
 
 class CursorErrTest(fixtures.TestBase):
+    # this isn't really a "reconnect" test, it's more of
+    # a generic "recovery".   maybe this test suite should have been
+    # named "test_error_recovery".
+    def _fixture(self, explode_on_exec, initialize):
+        class DBAPIError(Exception):
+            pass
 
-    def setup(self):
         def MockDBAPI():
             def cursor():
                 while True:
-                    yield Mock(
-                        description=[],
-                        close=Mock(side_effect=Exception("explode")))
+                    if explode_on_exec:
+                        yield Mock(
+                            description=[],
+                            close=Mock(side_effect=DBAPIError("explode")),
+                            execute=Mock(side_effect=DBAPIError("explode"))
+                        )
+                    else:
+                        yield Mock(
+                            description=[],
+                            close=Mock(side_effect=Exception("explode")),
+                        )
             def connect():
                 while True:
-                    yield Mock(cursor=Mock(side_effect=cursor()))
-
-            return Mock(connect=Mock(side_effect=connect()))
-
+                    yield Mock(
+                                spec=['cursor', 'commit', 'rollback', 'close'],
+                                cursor=Mock(side_effect=cursor()),
+                            )
+
+            return Mock(
+                        Error = DBAPIError,
+                        paramstyle='qmark',
+                        connect=Mock(side_effect=connect())
+                    )
         dbapi = MockDBAPI()
-        self.db = testing_engine(
-                    'postgresql://foo:bar@localhost/test',
-                    options=dict(module=dbapi, _initialize=False))
+
+        from sqlalchemy.engine import default
+        url = Mock(
+                    get_dialect=lambda: default.DefaultDialect,
+                    translate_connect_args=lambda: {},
+                    query={},
+                )
+        eng = testing_engine(
+                    url,
+                    options=dict(module=dbapi, _initialize=initialize))
+        eng.pool.logger = Mock()
+        return eng
 
     def test_cursor_explode(self):
-        conn = self.db.connect()
+        db = self._fixture(False, False)
+        conn = db.connect()
         result = conn.execute("select foo")
         result.close()
         conn.close()
+        eq_(
+            db.pool.logger.error.mock_calls,
+            [call('Error closing cursor', exc_info=True)]
+        )
+
+    def test_cursor_shutdown_in_initialize(self):
+        db = self._fixture(True, True)
+        assert_raises_message(
+            exc.SAWarning,
+            "Exception attempting to detect",
+            db.connect
+        )
+        eq_(
+            db.pool.logger.error.mock_calls,
+            [call('Error closing cursor', exc_info=True)]
+        )
 
-    def teardown(self):
-        self.db.dispose()
 
 
 def _assert_invalidated(fn, *args):