TestLockDir.test_35_wait_lock_changing is timing-dependent

[Martin Pool]

======================================================================
FAIL: test_35_wait_lock_changing (bzrlib.tests.test_lockdir.TestLockDir)

vvvv[log from bzrlib.tests.test_lockdir.TestLockDir.test_35_wait_lock_changing]
    INFO locked check and checked locks
    INFO lock2: waiting for check lock
    INFO lock1: releasing check lock
    INFO lock1: waiting 1 for checked lock
    INFO lock2: acquired check lock
    INFO lock2: releasing checked lock
    INFO lock1: acquired for checked lock
    INFO lock1: released lockdir
    INFO lock1: acquiring lockdir
    INFO lock1: releasing check lock
    INFO lock1: acquired lockdir
    INFO lock1: waiting 2 for checked lock
    INFO lock2: waiting for check lock
    INFO lock2: acquired check lock
    INFO lock2: releasing checked lock
    INFO lock1: acquired for checked lock
    INFO lock2: waiting for check lock
    INFO lock2: acquired check lock
    INFO lock2: releasing checked lock
82.559 opening working tree '/tmp/testbzr-BpBBLC.tmp'

^^^^[log from bzrlib.tests.test_lockdir.TestLockDir.test_35_wait_lock_changing]
----------------------------------------------------------------------
Traceback (most recent call last):
  File "/home/mbp/bzr/trivial/bzrlib/tests/test_lockdir.py", line 408, in test_35_wait_lock_changing
    self.assertEqual(2, len(self._logged_reports))
AssertionError: not equal:
a = 2
b = 1

----------------------------------------------------------------------
Ran 1843 tests in 80.635s

FAILED (failures=1, known_failure_count=3)
14 tests skipped

[Martin Pool (mbp)]

Notes:

A problem here is that the tests should be observing static events in a deterministic way, rather than trying to measure them in real time.

I think we can test that more easily if we add interfaces saying "I failed to get the lock", "I'm going to sleep waiting for the lock" and then we can just test them in isolation -- both the default implementation and also as a point to hook in for more testing. This should help other UIs that want different reporting while waiting for locks or to override the policy.

Open questions: wait_lock currently takes parameters saying how long to wait and how often to try - are these still needed if not used from the test suite?

If the UI wants to override these methods, presumably it would want to do so across all locks. Should it just patch them into the LockDir class?

[Martin Pool (mbp)]

As a stopgap I put up a patch which disables this test.

[Martin Pool (mbp)]

One approach, attempted in <https://code.edge.launchpad.net/~mbp/bzr/172392-ssh-locking> (from bug 172392) is to add a different exception class for "I waited for the lock and then timed out" vs "I immediately detected contention for the lock." However, I don't think there's really an inherent difference between these cases. It might be relevant to put the amount of time we waited into the tests, and it may help with this bug to more clearly distinguish or rearrange code that does "wait for a lock" vs "attempt to lock".

In a more useful direction, I have a commit outstanding that adds a callback and uses that to inspect progress deterministically.

[Martin Pool (mbp)]

This test is now disabled.