Merge pull request #222 from zopefoundation/feature/faster-tests

Avoid most calls to time.sleep() in the tests by mocking time.[gm]time

.travis.yml

@@ -23,8 +23,8 @@ install:
     - pip install -U setuptools zc.buildout
     - buildout $BUILOUT_OPTIONS
 script:
-    - if [[ $TRAVIS_PYTHON_VERSION != pypy* ]]; then bin/coverage run bin/coverage-test -v1j99; fi
-    - if [[ $TRAVIS_PYTHON_VERSION == pypy* ]]; then bin/test -v1j99; fi
+    - if [[ $TRAVIS_PYTHON_VERSION != pypy* ]]; then bin/coverage run bin/coverage-test -v; fi
+    - if [[ $TRAVIS_PYTHON_VERSION == pypy* ]]; then bin/test -v; fi
     - if [[ $TRAVIS_PYTHON_VERSION != pypy3* ]]; then make -C doc html; fi
     - if [[ $TRAVIS_PYTHON_VERSION != pypy* ]]; then pip install coveralls; fi # install early enough to get into the cache
 after_success:

CHANGES.rst

@@ -22,6 +22,8 @@
   exceptions on certain types of bad input. See `issue 216
   <https://github.com/zopefoundation/ZODB/issues/216>`_.
 
+- Make the tests run faster by avoiding calls to ``time.sleep()``.
+
 5.4.0 (2018-03-26)
 ==================
 

appveyor.yml

@@ -14,9 +14,10 @@ environment:
 install:
   - "SET PATH=C:\\Python%PYTHON%;c:\\Python%PYTHON%\\scripts;%PATH%"
   - echo "C:\Program Files\Microsoft SDKs\Windows\v7.1\Bin\SetEnv.cmd" /x64 > "C:\Program Files (x86)\Microsoft Visual Studio 10.0\VC\bin\amd64\vcvars64.bat"
-  - pip install -e .
-  - pip install zope.testrunner zope.testing manuel
-  - pip install zc.buildout zc.recipe.testrunner zc.recipe.egg
+  - python -m pip install -U pip setuptools wheel
+  - pip install -U -e .
+  - pip install -U zope.testrunner zope.testing manuel
+  - pip install -U zc.buildout zc.recipe.testrunner zc.recipe.egg
 
 build_script:
   - buildout bootstrap

setup.py

@@ -43,6 +43,7 @@ def read(path):
 
 tests_require = [
     'manuel',
+    'mock; python_version == "2.7"',
     'zope.testing',
     'zope.testrunner >= 4.4.6',
 ]

src/ZODB/scripts/tests/test_repozo.py

@@ -19,11 +19,11 @@
 
 import ZODB.tests.util  # layer used at class scope
 
-try:
-    from StringIO import StringIO
-    BytesIO = StringIO
-except ImportError:
-    from io import BytesIO, StringIO
+from io import BytesIO, StringIO
+if str is bytes:
+    NativeStringIO = BytesIO
+else:
+    NativeStringIO = StringIO
 
 
 _NOISY = os.environ.get('NOISY_REPOZO_TEST_OUTPUT')
@@ -94,19 +94,12 @@ def mutate(self):
 
 class Test_parseargs(unittest.TestCase):
 
-    # Python 2.6 lacks this
-    def assertIn(self, member, container, msg=None):
-        if member not in container:
-            standardMsg = '%s not found in %s' % (repr(member),
-                                                  repr(container))
-            self.fail(self._formatMessage(msg, standardMsg))
-
     def setUp(self):
         from ZODB.scripts import repozo
         self._old_verbosity = repozo.VERBOSE
         self._old_stderr = sys.stderr
         repozo.VERBOSE = False
-        sys.stderr = StringIO()
+        sys.stderr = NativeStringIO()
 
     def tearDown(self):
         from ZODB.scripts import repozo
@@ -134,7 +127,7 @@ def test_help(self):
         # zope.testrunner will happily print the traceback and failure message
         # into our StringIO before running our tearDown.
         old_stdout = sys.stdout
-        sys.stdout = StringIO()
+        sys.stdout = NativeStringIO()
         try:
             self.assertRaises(SystemExit, repozo.parseargs, ['--help'])
             self.assertIn('Usage:', sys.stdout.getvalue())
@@ -1099,6 +1092,7 @@ def _callRepozoMain(self, argv):
         from ZODB.scripts.repozo import main
         main(argv)
 
+    @ZODB.tests.util.time_monotonically_increases
     def test_via_monte_carlo(self):
         self.saved_snapshots = []  # list of (name, time) pairs for copies.
 
@@ -1142,8 +1136,7 @@ def mutate_pack_backup(self, i):
             copyfile(srcname, copyname)
             self.saved_snapshots.append((copyname, copytime))
 
-        # Make sure the clock moves at least a second.
-        sleep(1.01)
+        # The clock moves forward automatically on calls to time.time()
 
         # Verify current Data.fs can be reproduced exactly.
         self.assertRestored()

src/ZODB/tests/PackableStorage.py

@@ -30,6 +30,7 @@
 import transaction
 import ZODB.interfaces
 import ZODB.tests.util
+from ZODB.tests.util import time_monotonically_increases
 import zope.testing.setupstack
 
 from ZODB.utils import load_current
@@ -274,12 +275,15 @@ def cmp_by_time(a, b):
 
         db.close()
 
+    @time_monotonically_increases
     def checkPackWhileWriting(self):
         self._PackWhileWriting(pack_now=False)
 
+    @time_monotonically_increases
     def checkPackNowWhileWriting(self):
         self._PackWhileWriting(pack_now=True)
 
+    @time_monotonically_increases
     def checkPackLotsWhileWriting(self):
         # This is like the other pack-while-writing tests, except it packs
         # repeatedly until the client thread is done.  At the time it was
@@ -608,6 +612,7 @@ def checkPackUnlinkedFromRoot(self):
 
         eq(root['obj'].value, 7)
 
+    @time_monotonically_increases
     def checkRedundantPack(self):
         # It is an error to perform a pack with a packtime earlier
         # than a previous packtime.  The storage can't do a full
@@ -652,6 +657,7 @@ def checkRedundantPack(self):
         # it is reachable.
         load_current(self._storage, lost_oid)
 
+    @time_monotonically_increases(0.1)
     def checkPackUndoLog(self):
         self._initroot()
         # Create a `persistent' object
@@ -669,7 +675,7 @@ def checkPackUndoLog(self):
         self.assertEqual(3, len(self._storage.undoLog()))
         self._storage.pack(packtime, referencesf)
         # The undo log contains only the most resent transaction
-        self.assertEqual(1,len(self._storage.undoLog()))
+        self.assertEqual(1, len(self._storage.undoLog()))
 
     def dont_checkPackUndoLogUndoable(self):
         # A disabled test. I wanted to test that the content of the

src/ZODB/tests/RecoveryStorage.py

@@ -21,6 +21,7 @@
 from ZODB.serialize import referencesf
 
 from ZODB.utils import load_current
+from ZODB.tests.util import time_monotonically_increases
 
 import time
 
@@ -66,6 +67,7 @@ def checkRestoreAcrossPack(self):
         self._dst.tpc_vote(final)
         self._dst.tpc_finish(final)
 
+    @time_monotonically_increases
     def checkPackWithGCOnDestinationAfterRestore(self):
         raises = self.assertRaises
         db = DB(self._storage)

src/ZODB/tests/RevisionStorage.py

@@ -17,6 +17,7 @@
 from ZODB.tests.MinPO import MinPO
 from ZODB.tests.StorageTestBase import zodb_unpickle, zodb_pickle, snooze
 from ZODB.utils import p64, u64, load_current
+from ZODB.tests.util import time_monotonically_increases
 
 ZERO = '\0'*8
 
@@ -34,6 +35,7 @@ def checkLoadSerial(self):
             data = self._storage.loadSerial(oid, revid)
             self.assertEqual(zodb_unpickle(data), value)
 
+    @time_monotonically_increases
     def checkLoadBefore(self):
         # Store 10 revisions of one object and then make sure that we
         # can get all the non-current revisions back.
@@ -89,6 +91,7 @@ def checkLoadBeforeEdges(self):
         self.assertEqual(start, revid1)
         self.assertEqual(end, revid2)
 
+    @time_monotonically_increases
     def checkLoadBeforeOld(self):
         # Look for a very old revision.  With the BaseStorage implementation
         # this should require multple history() calls.

src/ZODB/tests/testCache.py

@@ -378,7 +378,12 @@ def add(key, obj):
             # structure that adds a new reference to None for each executed
             # line of code, which interferes with this test.  So check it
             # only if we're running without coverage tracing.
-            self.assertEqual(rc(None), nones)
+
+            # On Python 3.7, we can see the value of reference counts
+            # to None actually go *down* by a few. Possibly it has to
+            # do with the lazy tracking of frames?
+            # (https://github.com/python/cpython/commit/5a625d0aa6a6d9ec6574ee8344b41d63dcb9897e)
+            self.assertLessEqual(rc(None), nones)
 
     def testTwoCaches(self):
         jar2 = StubDataManager()

src/ZODB/tests/testblob.py

@@ -18,11 +18,7 @@
 from ZODB.tests.testConfig import ConfigTestBase
 from ZODB._compat import Pickler, Unpickler, _protocol
 
-import os
-if os.environ.get('USE_ZOPE_TESTING_DOCTEST'):
-    from zope.testing import doctest
-else:
-    import doctest
+import doctest
 
 import os
 import random
@@ -40,12 +36,7 @@
 import ZODB.tests.util
 import zope.testing.renormalizing
 
-
-try:
-    from StringIO import StringIO as BytesIO
-except ImportError:
-    # Py3
-    from io import BytesIO
+from io import BytesIO
 
 try:
     file_type = file
@@ -67,7 +58,11 @@ def new_time():
     now = new_time = time.time()
     while new_time <= now:
         new_time = time.time()
-    time.sleep(1)
+    if time.time() - new_time < 1.0:
+        # Detect if we're in a time monotonically increasing
+        # layer (two back-to-back calls of time.time() advance the clock
+        # by a whole second); if so, we don't need to sleep
+        time.sleep(1.0)
     return new_time
 
 
@@ -703,6 +698,14 @@ def setUp(test):
     ZODB.tests.util.setUp(test)
     test.globs['rmtree'] = zope.testing.setupstack.rmtree
 
+def timeIncreasesSetUp(test):
+    setUp(test)
+    l = test.globs['time_layer'] = ZODB.tests.util.MonotonicallyIncreasingTimeMinimalTestLayer('')
+    l.testSetUp()
+
+def timeIncreasesTearDown(test):
+    test.globs['time_layer'].testTearDown()
+    util.tearDown(test)
 
 def setUpBlobAdaptedFileStorage(test):
     setUp(test)
@@ -791,7 +794,7 @@ def add_test_based_on_test_class(class_):
     if test_undo:
         add_test_based_on_test_class(BlobUndoTests)
 
-    suite.layer = ZODB.tests.util.MininalTestLayer(prefix+'BlobTests')
+    suite.layer = ZODB.tests.util.MonotonicallyIncreasingTimeMinimalTestLayer(prefix+'BlobTests')
 
     return suite
 
@@ -804,12 +807,18 @@ def test_suite():
         "blob_basic.txt",
         "blob_consume.txt",
         "blob_tempdir.txt",
-        "blobstorage_packing.txt",
         setUp=setUp,
         tearDown=util.tearDown,
         optionflags=doctest.ELLIPSIS,
         checker=ZODB.tests.util.checker,
         ))
+    suite.addTest(doctest.DocFileSuite(
+        "blobstorage_packing.txt",
+        setUp=timeIncreasesSetUp,
+        tearDown=timeIncreasesTearDown,
+        optionflags=doctest.ELLIPSIS,
+        checker=ZODB.tests.util.checker,
+        ))
     suite.addTest(doctest.DocFileSuite(
         "blob_layout.txt",
         optionflags=doctest.ELLIPSIS|doctest.NORMALIZE_WHITESPACE,