From 3ca8b453088ac6fb815e2f39c9a705b49bfb188c Mon Sep 17 00:00:00 2001 From: Mike Bayer Date: Wed, 7 Oct 2020 10:09:41 -0400 Subject: [PATCH] Revert "Use monotonic time for pool age measurement" This reverts commit 0220b58917b5a979891b5765f6ac5095e0368489. I completely misread https://www.python.org/dev/peps/pep-0418/#rationale and the accuracy of monotonic() is *worse* on windows than time.time(), which is bizarre. Change-Id: I2d571e268a2051bea68736507773d3904403af9e --- .../unreleased_14/monotonic_time.rst | 11 -------- lib/sqlalchemy/pool/base.py | 26 ++++++++++++------- lib/sqlalchemy/testing/requirements.py | 14 ++-------- lib/sqlalchemy/util/__init__.py | 1 - lib/sqlalchemy/util/compat.py | 3 --- test/engine/test_pool.py | 2 +- test/engine/test_reconnect.py | 8 ------ 7 files changed, 20 insertions(+), 45 deletions(-) delete mode 100644 doc/build/changelog/unreleased_14/monotonic_time.rst diff --git a/doc/build/changelog/unreleased_14/monotonic_time.rst b/doc/build/changelog/unreleased_14/monotonic_time.rst deleted file mode 100644 index dc733d8a9e..0000000000 --- a/doc/build/changelog/unreleased_14/monotonic_time.rst +++ /dev/null @@ -1,11 +0,0 @@ -.. change:: - :tags: change, bug - - The internal clock used by the :class:`_pool.Pool` object is now - time.monotonic_time() under Python 3. Under Python 2, time.time() is still - used, which is legacy. This clock is used to measure the age of a - connection against its starttime, and used in comparisons against the - pool_timeout setting as well as the last time the pool was marked as - invalid to determine if the connection should be recycled. Previously, - time.time() was used which was subject to inaccuracies as a result of - system clock changes as well as poor time resolution on windows. diff --git a/lib/sqlalchemy/pool/base.py b/lib/sqlalchemy/pool/base.py index 2f1959f7c8..87383fef71 100644 --- a/lib/sqlalchemy/pool/base.py +++ b/lib/sqlalchemy/pool/base.py @@ -11,15 +11,16 @@ """ from collections import deque +import time import weakref from .. import event from .. import exc from .. import log from .. import util -from ..util import monotonic_time from ..util import threading + reset_rollback = util.symbol("reset_rollback") reset_commit = util.symbol("reset_commit") reset_none = util.symbol("reset_none") @@ -260,7 +261,7 @@ class Pool(log.Identified): """ rec = getattr(connection, "_connection_record", None) if not rec or self._invalidate_time < rec.starttime: - self._invalidate_time = monotonic_time() + self._invalidate_time = time.time() if _checkin and getattr(connection, "is_valid", False): connection.invalidate(exception) @@ -509,7 +510,7 @@ class _ConnectionRecord(object): self.connection, ) if soft: - self._soft_invalidate_time = monotonic_time() + self._soft_invalidate_time = time.time() else: self.__close() self.connection = None @@ -518,16 +519,23 @@ class _ConnectionRecord(object): recycle = False # NOTE: the various comparisons here are assuming that measurable time - # passes between these state changes. on Python 2, we are still using - # time.time() which is not guaranteed to have millisecondsecond - # precision, i.e. on Windows. For Python 3 we now use monotonic_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() elif ( self.__pool._recycle > -1 - and monotonic_time() - self.starttime > self.__pool._recycle + and time.time() - self.starttime > self.__pool._recycle ): self.__pool.logger.info( "Connection %r exceeded timeout; recycling", self.connection @@ -569,7 +577,7 @@ class _ConnectionRecord(object): # creator fails, this attribute stays None self.connection = None try: - self.starttime = monotonic_time() + self.starttime = time.time() connection = pool._invoke_creator(self) pool.logger.debug("Created new connection %r", connection) self.connection = connection diff --git a/lib/sqlalchemy/testing/requirements.py b/lib/sqlalchemy/testing/requirements.py index e2c61a05ea..45a2fdf317 100644 --- a/lib/sqlalchemy/testing/requirements.py +++ b/lib/sqlalchemy/testing/requirements.py @@ -15,6 +15,7 @@ to provide specific inclusion/exclusions. """ +import platform import sys from . import exclusions @@ -1092,21 +1093,10 @@ class SuiteRequirements(Requirements): def _running_on_windows(self): return exclusions.LambdaPredicate( - lambda: util.win32, + lambda: platform.system() == "Windows", description="running on Windows", ) - @property - def millisecond_monotonic_time(self): - """the util.monotonic_time() function must be millisecond accurate. - - Under Python 2 we can't guarantee this on Windows. - - """ - return exclusions.skip_if( - lambda: util.win32 and sys.version_info < (3,) - ) - @property def timing_intensive(self): return exclusions.requires_tag("timing_intensive") diff --git a/lib/sqlalchemy/util/__init__.py b/lib/sqlalchemy/util/__init__.py index c0b328d5e9..8ef2f01032 100644 --- a/lib/sqlalchemy/util/__init__.py +++ b/lib/sqlalchemy/util/__init__.py @@ -64,7 +64,6 @@ from .compat import int_types # noqa from .compat import iterbytes # noqa from .compat import itertools_filter # noqa from .compat import itertools_filterfalse # noqa -from .compat import monotonic_time # noqa from .compat import namedtuple # noqa from .compat import next # noqa from .compat import osx # noqa diff --git a/lib/sqlalchemy/util/compat.py b/lib/sqlalchemy/util/compat.py index b94ea353e2..d3fefa5265 100644 --- a/lib/sqlalchemy/util/compat.py +++ b/lib/sqlalchemy/util/compat.py @@ -109,8 +109,6 @@ if py3k: from io import StringIO from itertools import zip_longest from time import perf_counter - from time import monotonic as monotonic_time - from urllib.parse import ( quote_plus, unquote_plus, @@ -209,7 +207,6 @@ else: from cStringIO import StringIO as byte_buffer # noqa from itertools import izip_longest as zip_longest # noqa from time import clock as perf_counter # noqa - from time import time as monotonic_time # noqa from urllib import quote # noqa from urllib import quote_plus # noqa from urllib import unquote # noqa diff --git a/test/engine/test_pool.py b/test/engine/test_pool.py index e01609b175..eb705da61a 100644 --- a/test/engine/test_pool.py +++ b/test/engine/test_pool.py @@ -1241,7 +1241,7 @@ class QueuePoolTest(PoolTestBase): ) def test_recycle(self): - with patch("sqlalchemy.pool.base.monotonic_time") as mock: + with patch("sqlalchemy.pool.base.time.time") as mock: mock.return_value = 10000 p = self._queuepool_fixture( diff --git a/test/engine/test_reconnect.py b/test/engine/test_reconnect.py index 8881620f78..df95798fdf 100644 --- a/test/engine/test_reconnect.py +++ b/test/engine/test_reconnect.py @@ -357,8 +357,6 @@ class PrePingMockTest(fixtures.TestBase): class MockReconnectTest(fixtures.TestBase): - __requires__ = ("millisecond_monotonic_time",) - def setup(self): self.dbapi = MockDBAPI() @@ -427,14 +425,8 @@ class MockReconnectTest(fixtures.TestBase): [[call()], []], ) - # checkout makes use of the same connection record. in - # get_connection(), recycle should be enabled because - # the age of the connection is older than the time at which - # the invalidation occurred. conn = self.db.connect() - # therefore the two connections should both have been closed - # when we connected again. eq_( [c.close.mock_calls for c in self.dbapi.connections], [[call()], [call()], []], -- 2.39.5