[MERGE] timing sensitive test can cause spurious failures

Andrew Bennetts andrew at canonical.com
Wed Aug 30 09:18:00 BST 2006


I just got a spurious failure:

======================================================================
FAIL: test_time_creates_benchmark_in_result (bzrlib.tests.test_selftest.TestTestCase)

vvvv[log from bzrlib.tests.test_selftest.TestTestCase.test_time_creates_benchmark_in_result]

^^^^[log from bzrlib.tests.test_selftest.TestTestCase.test_time_creates_benchmark_in_result]
----------------------------------------------------------------------
Traceback (most recent call last):
  File ".../bzrlib/tests/test_selftest.py", line 795, in test_time_creates_benchmark_in_result
    "[1-9][0-9]ms/   [1-9][0-9]ms\n$")
  File ".../bzrlib/tests/__init__.py", line 540, in assertContainsRe
    raise AssertionError('pattern "%s" not found in "%s"'
AssertionError: pattern "[1-9][0-9]ms/   [1-9][0-9]ms
$" not found in "test_selftest.TestTestCase.method_that_times_a_bit_twice                                                               OK    14ms/  711ms
"
======================================================================

Timing-sensitive tests suck.  They will always break for someone somewhere,
because there's always a system that's faster or slower than you ever expected.

Also, it's probably a good habit to think of time.sleep as a low-resolution
hint, rather than something to be trusted.

Here's the obvious fix:

=== modified file 'bzrlib/tests/test_selftest.py'
--- bzrlib/tests/test_selftest.py       2006-08-30 02:53:00 +0000
+++ bzrlib/tests/test_selftest.py       2006-08-30 08:06:35 +0000
@@ -792,7 +792,7 @@
         sample_test.run(result)
         self.assertContainsRe(
             output_stream.getvalue(),
-            "[1-9][0-9]ms/   [1-9][0-9]ms\n$")
+            "[1-9][0-9]+ms/ *[1-9][0-9]+ms\n$")

     def test__gather_lsprof_in_benchmarks(self):
         """When _gather_lsprof_in_benchmarks is on, accumulate profile data.


Except even this is too weak.  Really, it should be this:

-            "[1-9][0-9]ms/   [1-9][0-9]ms\n$")
+            "[0-9]+ms/ *[0-9]+ms\n$")

At some point the assumption that the result will be in milliseconds will
probably be wrong too, of course ;)

-Andrew.





More information about the bazaar mailing list