Note time passage requirement for pool.invalidate()

For Windows, time.time() may only have 16 millisecond
accuracy, so invalidation routines which compare
the time.time() of invalidate() to the time.time() when
the ConnectionRecord last connected may fail in a unit test
environment that does not pause at least this much time
since the ConnectionRecord startup.  Using >= for comparison
instead of > was considered but this only leads to more confusing
results as the ConnecitonRecord goes into a re-connect loop
as time continues to not pass.

Overall, while using routines such as Python 3.7's time_ns()
might be helpful, for now make sure tests which rely on this
are marked under timing intensive and add small sleeps.

Change-Id: I1a7162e67912d22c135fa517b687a073f8fd9151

diff --git a/lib/sqlalchemy/pool/base.py b/lib/sqlalchemy/pool/base.py
index db1197eeca6b4dcd9563fcf0a0bea9960448d68d..276dfad8678aae75d5dcf2c37eea184fc199099c 100644 (file)
--- a/lib/sqlalchemy/pool/base.py
+++ b/lib/sqlalchemy/pool/base.py
@@ -511,6 +511,19 @@ class _ConnectionRecord(object):
 
     def get_connection(self):
         recycle = False
+
+        # NOTE: the various comparisons here are assuming that measurable time
+        # passes between these state changes.  however, time.time() is not
+        # guaranteed to have sub-second precision.  comparisons of
+        # "invalidation time" to "starttime" should perhaps use >= so that the
+        # state change can take place assuming no measurable  time has passed,
+        # however this does not guarantee correct behavior here as if time
+        # continues to not pass, it will try to reconnect repeatedly until
+        # these timestamps diverge, so in that sense using > is safer.  Per
+        # https://stackoverflow.com/a/1938096/34549, Windows time.time() may be
+        # within 16 milliseconds accuracy, so unit tests for connection
+        # invalidation need a sleep of at least this long between initial start
+        # time and invalidation for the logic below to work reliably.
         if self.connection is None:
             self.info.clear()
             self.__connect()

diff --git a/test/engine/test_pool.py b/test/engine/test_pool.py
index ced42c78d87138b7167d6c4e30d611edbc01da44..31b89373492315ca1fdaa89462fd4c36d46dbdc4 100644 (file)
--- a/test/engine/test_pool.py
+++ b/test/engine/test_pool.py
@@ -1217,11 +1217,16 @@ class QueuePoolTest(PoolTestBase):
         is_(c2.connection, c_ref())
 
         c2_rec = c2._connection_record
+
+        # ensure pool invalidate time will be later than starttime
+        # for ConnectionRecord objects above
+        time.sleep(0.1)
         c2.invalidate(soft=True)
+
         is_(c2_rec.connection, c2.connection)
 
         c2.close()
-        time.sleep(0.5)
+
         c3 = p.connect()
         is_not_(c3.connection, c_ref())
         is_(c3._connection_record, c2_rec)
@@ -1285,6 +1290,7 @@ class QueuePoolTest(PoolTestBase):
         time.sleep(1.5)
         self._assert_cleanup_on_pooled_reconnect(dbapi, p)
 
+    @testing.requires.timing_intensive
     def test_connect_handler_not_called_for_recycled(self):
         """test [ticket:3497]"""
 
@@ -1300,6 +1306,10 @@ class QueuePoolTest(PoolTestBase):
 
         dbapi.shutdown(True)
 
+        # ensure pool invalidate time will be later than starttime
+        # for ConnectionRecord objects above
+        time.sleep(0.1)
+
         bad = p.connect()
         p._invalidate(bad)
         bad.close()
@@ -1323,6 +1333,7 @@ class QueuePoolTest(PoolTestBase):
             [call.connect(ANY, ANY), call.checkout(ANY, ANY, ANY)],
         )
 
+    @testing.requires.timing_intensive
     def test_connect_checkout_handler_always_gets_info(self):
         """test [ticket:3497]"""
 
@@ -1336,6 +1347,10 @@ class QueuePoolTest(PoolTestBase):
 
         dbapi.shutdown(True)
 
+        # ensure pool invalidate time will be later than starttime
+        # for ConnectionRecord objects above
+        time.sleep(0.1)
+
         bad = p.connect()
         p._invalidate(bad)
         bad.close()