Use a higher resolution clock for timing.

.travis.yml

@@ -96,6 +96,7 @@ install:
   - echo $BUILD_RUNTIMES/snakepit/$TRAVIS_PYTHON_VERSION.d
   - ls -l $BUILD_RUNTIMES/snakepit/$TRAVIS_PYTHON_VERSION.d
   - python -c 'import gevent; print(gevent.__version__)'
+  - python -c 'from gevent._compat import get_clock_info; print(get_clock_info("perf_counter"))'
 script:
   # The generic script for the matrix expansion is to
   # test the defaults.

src/gevent/_compat.py

@@ -188,7 +188,11 @@ except ImportError:
 try:
     # Python 3.3+ (PEP 418)
     from time import perf_counter
+    from time import get_clock_info
+    from time import monotonic
     perf_counter = perf_counter
+    monotonic = monotonic
+    get_clock_info = get_clock_info
 except ImportError:
     import time
 
@@ -196,7 +200,9 @@ except ImportError:
         perf_counter = time.clock # pylint:disable=no-member
     else:
         perf_counter = time.time
-
+    monotonic = perf_counter
+    def get_clock_info(_):
+        return 'Unknown'
 
 ## Monitoring
 def get_this_psutil_process():

src/gevent/testing/testcase.py

@@ -20,7 +20,6 @@
 from __future__ import absolute_import, print_function, division
 
 import sys
-from time import time
 import os.path
 from contextlib import contextmanager
 from unittest import TestCase as BaseTestCase
@@ -28,6 +27,8 @@ from functools import wraps
 
 import gevent
 from gevent._util import LazyOnClass
+from gevent._compat import perf_counter
+from gevent._compat import get_clock_info
 
 from . import sysinfo
 from . import params
@@ -63,13 +64,17 @@ class TimeAssertMixin(object):
                 fuzzy = expected * 5.0
             else:
                 fuzzy = expected / 2.0
-        start = time()
-        yield
-        elapsed = time() - start
+        min_time = expected - fuzzy
+        max_time = expected + fuzzy
+        start = perf_counter()
+        yield (min_time, max_time)
+        elapsed = perf_counter() - start
         try:
             self.assertTrue(
-                expected - fuzzy <= elapsed <= expected + fuzzy,
-                'Expected: %r; elapsed: %r; fuzzy %r' % (expected, elapsed, fuzzy))
+                min_time <= elapsed <= max_time,
+                'Expected: %r; elapsed: %r; fuzzy %r; clock_info: %s' % (
+                    expected, elapsed, fuzzy, get_clock_info('perf_counter')
+                ))
         except AssertionError:
             flaky.reraiseFlakyTestRaceCondition()
 

src/gevent/testing/testrunner.py

@@ -5,7 +5,6 @@ import sys
 import os
 import glob
 import traceback
-import time
 import importlib
 from datetime import timedelta
 
@@ -135,7 +134,7 @@ class Runner(object):
 
     def _reap_all(self):
         while self._reap() > 0:
-            time.sleep(self.TIME_WAIT_REAP)
+            util.sleep(self.TIME_WAIT_REAP)
 
     def _spawn(self, pool, cmd, options):
         while True:
@@ -144,7 +143,7 @@ class Runner(object):
                 self._running_jobs.append(job)
                 return
 
-            time.sleep(self.TIME_WAIT_SPAWN)
+            util.sleep(self.TIME_WAIT_SPAWN)
 
     def __call__(self):
         util.log("Running tests in parallel with concurrency %s" % (self._worker_count,),)
@@ -153,11 +152,11 @@ class Runner(object):
         # sequentially.
         util.BUFFER_OUTPUT = self._worker_count > 1 or self._quiet
 
-        start = time.time()
+        start = util.perf_counter()
         try:
             self._run_tests()
         except KeyboardInterrupt:
-            self._report(time.time() - start, exit=False)
+            self._report(util.perf_counter() - start, exit=False)
             util.log('(partial results)\n')
             raise
         except:
@@ -165,7 +164,7 @@ class Runner(object):
             raise
 
         self._reap_all()
-        self._report(time.time() - start, exit=True)
+        self._report(util.perf_counter() - start, exit=True)
 
     def _run_tests(self):
         "Runs the tests, produces no report."
@@ -215,7 +214,7 @@ class TravisFoldingRunner(object):
     def __init__(self, runner, travis_fold_msg):
         self._runner = runner
         self._travis_fold_msg = travis_fold_msg
-        self._travis_fold_name = str(int(time.time()))
+        self._travis_fold_name = str(int(util.perf_counter()))
 
         # A zope-style acquisition proxy would be convenient here.
         run_tests = runner._run_tests

src/gevent/testing/timing.py

@@ -18,9 +18,8 @@
 # OUT OF OR IN CONNECTION WITH THE SOFTWARE OR THE USE OR OTHER DEALINGS IN
 # THE SOFTWARE.
 
-import time
-
 import gevent
+from gevent._compat import perf_counter
 
 from . import sysinfo
 from . import leakcheck
@@ -69,11 +68,11 @@ class _DelayWaitMixin(object):
         seconds = getattr(timeout, 'seconds', timeout)
 
         gevent.get_hub().loop.update_now()
-        start = time.time()
+        start = perf_counter()
         try:
             result = self.wait(timeout)
         finally:
-            self._check_delay_bounds(seconds, time.time() - start,
+            self._check_delay_bounds(seconds, perf_counter() - start,
                                      self._default_delay_min_adj,
                                      self._default_delay_max_adj)
         return result

src/gevent/testing/util.py

@@ -6,10 +6,11 @@ import traceback
 import unittest
 import threading
 import subprocess
-import time
+from time import sleep
 
 from . import six
 from gevent._config import validate_bool
+from gevent._compat import perf_counter
 from gevent.monkey import get_original
 
 # pylint: disable=broad-except,attribute-defined-outside-init
@@ -391,9 +392,9 @@ def run(command, **kwargs): # pylint:disable=too-many-locals
     name = popen.name
 
     try:
-        time_start = time.time()
+        time_start = perf_counter()
         out, err = popen.communicate()
-        took = time.time() - time_start
+        took = perf_counter() - time_start
         if popen.was_killed or popen.poll() is None:
             result = 'TIMEOUT'
         else:
@@ -611,7 +612,7 @@ class TestServer(ExampleMixin,
 
     def before(self):
         if self.before_delay is not None:
-            time.sleep(self.before_delay)
+            sleep(self.before_delay)
         self.assertIsNone(self.popen.poll(),
                           '%s died with code %s' % (
                               self.example, self.popen.poll(),
@@ -619,7 +620,7 @@ class TestServer(ExampleMixin,
 
     def after(self):
         if self.after_delay is not None:
-            time.sleep(self.after_delay)
+            sleep(self.after_delay)
         self.assertIsNone(self.popen.poll(),
                           '%s died with code %s' % (
                               self.example, self.popen.poll(),
@@ -646,6 +647,6 @@ class alarm(threading.Thread):
         self.start()
 
     def run(self):
-        time.sleep(self.timeout)
+        sleep(self.timeout)
         sys.stderr.write('Timeout.\n')
         os._exit(5)

src/gevent/tests/test__subprocess.py

@@ -510,7 +510,7 @@ class RunFuncTestCase(greentest.TestCase):
     def test_run_with_shell_timeout_and_capture_output(self):
         #Output capturing after a timeout mustn't hang forever on open filehandles
         with self.runs_in_given_time(0.1):
-            with self.assertRaises(subprocess.TimeoutExpired) as c:
+            with self.assertRaises(subprocess.TimeoutExpired):
                 subprocess.run('sleep 3', shell=True, timeout=0.1,
                                capture_output=True)  # New session unspecified.