~bzr-pqm/bzr/bzr.dev

« back to all changes in this revision

Viewing changes to bzrlib/tests/test_lockdir.py

  • Committer: John Arbash Meinel
  • Date: 2006-09-20 16:32:06 UTC
  • mto: This revision was merged to the branch mainline in revision 2050.
  • Revision ID: john@arbash-meinel.com-20060920163206-f996c191184dd0f7
Add the ability to report if the lock changes from underneath you

Show diffs side-by-side

added added

removed removed

Lines of Context:
17
17
"""Tests for LockDir"""
18
18
 
19
19
from cStringIO import StringIO
20
 
from threading import Thread
 
20
from threading import Thread, Lock
21
21
import time
22
22
 
23
23
import bzrlib
 
24
from bzrlib import (
 
25
    osutils,
 
26
    )
24
27
from bzrlib.errors import (
25
28
        LockBreakMismatch,
26
29
        LockContention, LockError, UnlockableTransport,
28
31
        )
29
32
from bzrlib.lockdir import LockDir, _DEFAULT_TIMEOUT_SECONDS
30
33
from bzrlib.tests import TestCaseWithTransport
 
34
from bzrlib.trace import note
31
35
 
32
36
# These tests sometimes use threads to test the behaviour of lock files with
33
37
# concurrent actors.  This is not a typical (or necessarily supported) use;
177
181
        finally:
178
182
            lf1.unlock()
179
183
        lock_base = lf2.transport.abspath(lf2.path)
180
 
        self.assertEqual([('Unable to obtain lock on %s\n'
181
 
                           'Will continue to try for %s seconds\n',
182
 
                           (lock_base, 0.4)),
183
 
                         ], self._logged_reports)
 
184
        self.assertEqual(1, len(self._logged_reports))
 
185
        self.assertEqual('Unable to obtain %s\n'
 
186
                         '%s\n%s\n'
 
187
                         'Will continue to try for %s seconds\n',
 
188
                         self._logged_reports[0][0])
 
189
        args = self._logged_reports[0][1]
 
190
        self.assertEqual('lock %s' % (lock_base,), args[0])
 
191
        self.assertStartsWith(args[1], 'held by ')
 
192
        self.assertStartsWith(args[2], 'locked ')
 
193
        self.assertEndsWith(args[2], ' ago')
184
194
 
185
195
    def test_31_lock_wait_easy(self):
186
196
        """Succeed when waiting on a lock with no contention.
228
238
        # There should be only 1 report, even though it should have to
229
239
        # wait for a while
230
240
        lock_base = lf2.transport.abspath(lf2.path)
231
 
        self.assertEqual([('Unable to obtain lock on %s\n'
232
 
                           'Will continue to try for %s seconds\n',
233
 
                           (lock_base, 0.4)),
234
 
                         ], self._logged_reports)
 
241
        self.assertEqual(1, len(self._logged_reports))
 
242
        self.assertEqual('Unable to obtain %s\n'
 
243
                         '%s\n%s\n'
 
244
                         'Will continue to try for %s seconds\n',
 
245
                         self._logged_reports[0][0])
 
246
        args = self._logged_reports[0][1]
 
247
        self.assertEqual('lock %s' % (lock_base,), args[0])
 
248
        self.assertStartsWith(args[1], 'held by ')
 
249
        self.assertStartsWith(args[2], 'locked ')
 
250
        self.assertEndsWith(args[2], ' ago')
235
251
 
236
252
    def test_33_wait(self):
237
253
        """Succeed when waiting on a lock that gets released
286
302
        # There should be only 1 report, even though it should have to
287
303
        # wait for a while
288
304
        lock_base = lf2.transport.abspath(lf2.path)
289
 
        self.assertEqual([('Unable to obtain lock on %s\n'
290
 
                           'Will continue to try for %s seconds\n',
291
 
                           (lock_base, _DEFAULT_TIMEOUT_SECONDS)),
292
 
                         ], self._logged_reports)
293
 
 
 
305
        self.assertEqual(1, len(self._logged_reports))
 
306
        self.assertEqual('Unable to obtain %s\n'
 
307
                         '%s\n%s\n'
 
308
                         'Will continue to try for %s seconds\n',
 
309
                         self._logged_reports[0][0])
 
310
        args = self._logged_reports[0][1]
 
311
        self.assertEqual('lock %s' % (lock_base,), args[0])
 
312
        self.assertStartsWith(args[1], 'held by ')
 
313
        self.assertStartsWith(args[2], 'locked ')
 
314
        self.assertEndsWith(args[2], ' ago')
 
315
 
 
316
    def test_35_wait_lock_changing(self):
 
317
        """LockDir.wait_lock() will report if the lock changes underneath.
 
318
        
 
319
        This is the stages we want to happen:
 
320
 
 
321
        0) Synchronization locks are created and locked.
 
322
        1) Lock1 obtains the lockdir, and releases the 'check' lock.
 
323
        2) Lock2 grabs the 'check' lock, and checks the lockdir.
 
324
           It sees the lockdir is already acquired, reports the fact, 
 
325
           and unsets the 'peek' lock.
 
326
        3) Thread1 blocks on acquiring the 'peek' lock, and then tells
 
327
           Lock1 to release and acquire the lockdir. This resets the 'check'
 
328
           lock.
 
329
        4) Lock2 acquires the 'check' lock, and checks again. It notices
 
330
           that the holder of the lock has changed, and so reports a new 
 
331
           lock holder.
 
332
        5) Thread1 blocks on the 'peek' lock, this time, it completely
 
333
           unlocks the lockdir, allowing Lock2 to acquire the lock.
 
334
        """
 
335
 
 
336
        wait_to_check_lock = Lock()
 
337
        wait_until_peek_lock = Lock()
 
338
 
 
339
        wait_to_check_lock.acquire()
 
340
        wait_until_peek_lock.acquire()
 
341
        note('locked check and peek locks')
 
342
 
 
343
        class LockDir1(LockDir):
 
344
            """Use the synchronization points for the first lock."""
 
345
 
 
346
            def attempt_lock(self):
 
347
                # Once we have acquired the lock, it is okay for
 
348
                # the other lock to check it
 
349
                try:
 
350
                    return super(LockDir1, self).attempt_lock()
 
351
                finally:
 
352
                    note('lock1: releasing check lock')
 
353
                    wait_to_check_lock.release()
 
354
 
 
355
        class LockDir2(LockDir):
 
356
            """Use the synchronization points for the second lock."""
 
357
 
 
358
            def peek(self):
 
359
                note('lock2: waiting for check lock')
 
360
                wait_to_check_lock.acquire()
 
361
                note('lock2: acquired check lock')
 
362
                try:
 
363
                    return super(LockDir2, self).peek()
 
364
                finally:
 
365
                    note('lock2: releasing peek lock')
 
366
                    wait_until_peek_lock.release()
 
367
 
 
368
        t = self.get_transport()
 
369
        lf1 = LockDir1(t, 'test_lock')
 
370
        lf1.create()
 
371
 
 
372
        lf2 = LockDir2(t, 'test_lock')
 
373
        self.setup_log_reporter(lf2)
 
374
 
 
375
        def wait_and_switch():
 
376
            lf1.attempt_lock()
 
377
            # Block until lock2 has had a chance to peek
 
378
            note('lock1: waiting 1 for peek lock')
 
379
            wait_until_peek_lock.acquire()
 
380
            note('lock1: acquired for peek lock')
 
381
            note('lock1: released lockdir')
 
382
            lf1.unlock()
 
383
            note('lock1: acquiring lockdir')
 
384
            # Create a new nonce, so the lock looks different.
 
385
            lf1.nonce = osutils.rand_chars(20)
 
386
            lf1.lock_write()
 
387
            note('lock1: acquired lockdir')
 
388
 
 
389
            # Block until lock2 has peeked again
 
390
            note('lock1: waiting 2 for peek lock')
 
391
            wait_until_peek_lock.acquire()
 
392
            note('lock1: acquired for peek lock')
 
393
            lf1.unlock()
 
394
            # We need to allow check 2 times
 
395
            wait_to_check_lock.release()
 
396
            wait_until_peek_lock.acquire()
 
397
            wait_to_check_lock.release()
 
398
 
 
399
        unlocker = Thread(target=wait_and_switch)
 
400
        unlocker.start()
 
401
        try:
 
402
            # Start the other thread
 
403
            time.sleep(0.1)
 
404
            # wait and then lock
 
405
            lf2.wait_lock(timeout=2.0, poll=0.2)
 
406
        finally:
 
407
            unlocker.join()
 
408
        lf2.unlock()
 
409
 
 
410
        # There should be 2 reports, because the lock changed
 
411
        lock_base = lf2.transport.abspath(lf2.path)
 
412
        self.assertEqual(2, len(self._logged_reports))
 
413
        def check_one(index):
 
414
            self.assertEqual('Unable to obtain %s\n'
 
415
                             '%s\n%s\n'
 
416
                             'Will continue to try for %s seconds\n',
 
417
                             self._logged_reports[index][0])
 
418
            args = self._logged_reports[index][1]
 
419
            self.assertEqual('lock %s' % (lock_base,), args[0])
 
420
            self.assertStartsWith(args[1], 'held by ')
 
421
            self.assertStartsWith(args[2], 'locked ')
 
422
            self.assertEndsWith(args[2], ' ago')
 
423
        check_one(0)
 
424
        check_one(1)
294
425
 
295
426
    def test_40_confirm_easy(self):
296
427
        """Confirm a lock that's already held"""