← Back to branch summary

~bzr-pqm/bzr/bzr.dev

« back to all changes in this revision

Viewing changes to bzrlib/tests/test_lockdir.py

  • Committer: Canonical.com Patch Queue Manager
  • Date: 2010-11-22 22:27:58 UTC
  • mfrom: (5537.2.1 move-inter)
  • Revision ID: pqm@pqm.ubuntu.com-20101122222758-wr1j89eb778ypclt
(spiv) Move InterKnitRepo and InterWeaveRepo out of bzrlib/repository.py
 (Jelmer Vernooij)

Show diffs side-by-side

added added

removed removed

Lines of Context:
bzrlib/tests/test_lockdir.py
1
 
# Copyright (C) 2006-2011 Canonical Ltd
 
1
# Copyright (C) 2006-2010 Canonical Ltd
2
2
#
3
3
# This program is free software; you can redistribute it and/or modify
4
4
# it under the terms of the GNU General Public License as published by
16
16
 
17
17
"""Tests for LockDir"""
18
18
 
 
19
from cStringIO import StringIO
19
20
import os
 
21
from threading import Thread, Lock
20
22
import time
21
23
 
22
24
import bzrlib
32
34
    LockBreakMismatch,
33
35
    LockBroken,
34
36
    LockContention,
 
37
    LockError,
35
38
    LockFailed,
36
39
    LockNotHeld,
37
40
    )
38
41
from bzrlib.lockdir import LockDir
39
 
from bzrlib.tests import (
40
 
    features,
41
 
    TestCaseWithTransport,
42
 
    )
 
42
from bzrlib.tests import (features, TestCaseWithTransport)
43
43
from bzrlib.trace import note
44
44
 
 
45
# These tests sometimes use threads to test the behaviour of lock files with
 
46
# concurrent actors.  This is not a typical (or necessarily supported) use;
 
47
# they're really meant for guarding between processes.
 
48
 
45
49
# These tests are run on the default transport provided by the test framework
46
50
# (typically a local disk transport).  That can be changed by the --transport
47
51
# option to bzr selftest.  The required properties of the transport
219
223
            lf1.unlock()
220
224
        self.assertEqual([], self._logged_reports)
221
225
 
 
226
    def test_32_lock_wait_succeed(self):
 
227
        """Succeed when trying to acquire a lock that gets released
 
228
 
 
229
        One thread holds on a lock and then releases it; another
 
230
        tries to lock it.
 
231
        """
 
232
        # This test sometimes fails like this:
 
233
        # Traceback (most recent call last):
 
234
 
 
235
        #   File "/home/pqm/bzr-pqm-workdir/home/+trunk/bzrlib/tests/
 
236
        # test_lockdir.py", line 247, in test_32_lock_wait_succeed
 
237
        #     self.assertEqual(1, len(self._logged_reports))
 
238
        # AssertionError: not equal:
 
239
        # a = 1
 
240
        # b = 0
 
241
        raise tests.TestSkipped("Test fails intermittently")
 
242
        t = self.get_transport()
 
243
        lf1 = LockDir(t, 'test_lock')
 
244
        lf1.create()
 
245
        lf1.attempt_lock()
 
246
 
 
247
        def wait_and_unlock():
 
248
            time.sleep(0.1)
 
249
            lf1.unlock()
 
250
        unlocker = Thread(target=wait_and_unlock)
 
251
        unlocker.start()
 
252
        try:
 
253
            lf2 = LockDir(t, 'test_lock')
 
254
            self.setup_log_reporter(lf2)
 
255
            before = time.time()
 
256
            # wait and then lock
 
257
            lf2.wait_lock(timeout=0.4, poll=0.1)
 
258
            after = time.time()
 
259
            self.assertTrue(after - before <= 1.0)
 
260
        finally:
 
261
            unlocker.join()
 
262
 
 
263
        # There should be only 1 report, even though it should have to
 
264
        # wait for a while
 
265
        lock_base = lf2.transport.abspath(lf2.path)
 
266
        self.assertEqual(1, len(self._logged_reports))
 
267
        self.assertEqual('%s %s\n'
 
268
                         '%s\n%s\n'
 
269
                         'Will continue to try until %s\n',
 
270
                         self._logged_reports[0][0])
 
271
        args = self._logged_reports[0][1]
 
272
        self.assertEqual('Unable to obtain', args[0])
 
273
        self.assertEqual('lock %s' % (lock_base,), args[1])
 
274
        self.assertStartsWith(args[2], 'held by ')
 
275
        self.assertStartsWith(args[3], 'locked ')
 
276
        self.assertEndsWith(args[3], ' ago')
 
277
        self.assertContainsRe(args[4], r'\d\d:\d\d:\d\d')
 
278
 
 
279
    def test_34_lock_write_waits(self):
 
280
        """LockDir.lock_write() will wait for the lock."""
 
281
        # the test suite sets the default to 0 to make deadlocks fail fast.
 
282
        # change it for this test, as we want to try a manual deadlock.
 
283
        raise tests.TestSkipped('Timing-sensitive test')
 
284
        bzrlib.lockdir._DEFAULT_TIMEOUT_SECONDS = 300
 
285
        t = self.get_transport()
 
286
        lf1 = LockDir(t, 'test_lock')
 
287
        lf1.create()
 
288
        lf1.attempt_lock()
 
289
 
 
290
        def wait_and_unlock():
 
291
            time.sleep(0.1)
 
292
            lf1.unlock()
 
293
        unlocker = Thread(target=wait_and_unlock)
 
294
        unlocker.start()
 
295
        try:
 
296
            lf2 = LockDir(t, 'test_lock')
 
297
            self.setup_log_reporter(lf2)
 
298
            before = time.time()
 
299
            # wait and then lock
 
300
            lf2.lock_write()
 
301
            after = time.time()
 
302
        finally:
 
303
            unlocker.join()
 
304
 
 
305
        # There should be only 1 report, even though it should have to
 
306
        # wait for a while
 
307
        lock_base = lf2.transport.abspath(lf2.path)
 
308
        self.assertEqual(1, len(self._logged_reports))
 
309
        self.assertEqual('%s %s\n'
 
310
                         '%s\n%s\n'
 
311
                         'Will continue to try until %s\n',
 
312
                         self._logged_reports[0][0])
 
313
        args = self._logged_reports[0][1]
 
314
        self.assertEqual('Unable to obtain', args[0])
 
315
        self.assertEqual('lock %s' % (lock_base,), args[1])
 
316
        self.assertStartsWith(args[2], 'held by ')
 
317
        self.assertStartsWith(args[3], 'locked ')
 
318
        self.assertEndsWith(args[3], ' ago')
 
319
        self.assertContainsRe(args[4], r'\d\d:\d\d:\d\d')
 
320
 
 
321
    def test_35_wait_lock_changing(self):
 
322
        """LockDir.wait_lock() will report if the lock changes underneath.
 
323
 
 
324
        This is the stages we want to happen:
 
325
 
 
326
        0) Synchronization locks are created and locked.
 
327
        1) Lock1 obtains the lockdir, and releases the 'check' lock.
 
328
        2) Lock2 grabs the 'check' lock, and checks the lockdir.
 
329
           It sees the lockdir is already acquired, reports the fact,
 
330
           and unsets the 'checked' lock.
 
331
        3) Thread1 blocks on acquiring the 'checked' lock, and then tells
 
332
           Lock1 to release and acquire the lockdir. This resets the 'check'
 
333
           lock.
 
334
        4) Lock2 acquires the 'check' lock, and checks again. It notices
 
335
           that the holder of the lock has changed, and so reports a new
 
336
           lock holder.
 
337
        5) Thread1 blocks on the 'checked' lock, this time, it completely
 
338
           unlocks the lockdir, allowing Lock2 to acquire the lock.
 
339
        """
 
340
 
 
341
        raise tests.KnownFailure(
 
342
            "timing dependency in lock tests (#213182)")
 
343
 
 
344
        wait_to_check_lock = Lock()
 
345
        wait_until_checked_lock = Lock()
 
346
 
 
347
        wait_to_check_lock.acquire()
 
348
        wait_until_checked_lock.acquire()
 
349
        note('locked check and checked locks')
 
350
 
 
351
        class LockDir1(LockDir):
 
352
            """Use the synchronization points for the first lock."""
 
353
 
 
354
            def attempt_lock(self):
 
355
                # Once we have acquired the lock, it is okay for
 
356
                # the other lock to check it
 
357
                try:
 
358
                    return super(LockDir1, self).attempt_lock()
 
359
                finally:
 
360
                    note('lock1: releasing check lock')
 
361
                    wait_to_check_lock.release()
 
362
 
 
363
        class LockDir2(LockDir):
 
364
            """Use the synchronization points for the second lock."""
 
365
 
 
366
            def attempt_lock(self):
 
367
                note('lock2: waiting for check lock')
 
368
                wait_to_check_lock.acquire()
 
369
                note('lock2: acquired check lock')
 
370
                try:
 
371
                    return super(LockDir2, self).attempt_lock()
 
372
                finally:
 
373
                    note('lock2: releasing checked lock')
 
374
                    wait_until_checked_lock.release()
 
375
 
 
376
        t = self.get_transport()
 
377
        lf1 = LockDir1(t, 'test_lock')
 
378
        lf1.create()
 
379
 
 
380
        lf2 = LockDir2(t, 'test_lock')
 
381
        self.setup_log_reporter(lf2)
 
382
 
 
383
        def wait_and_switch():
 
384
            lf1.attempt_lock()
 
385
            # Block until lock2 has had a chance to check
 
386
            note('lock1: waiting 1 for checked lock')
 
387
            wait_until_checked_lock.acquire()
 
388
            note('lock1: acquired for checked lock')
 
389
            note('lock1: released lockdir')
 
390
            lf1.unlock()
 
391
            note('lock1: acquiring lockdir')
 
392
            # Create a new nonce, so the lock looks different.
 
393
            lf1.nonce = osutils.rand_chars(20)
 
394
            lf1.lock_write()
 
395
            note('lock1: acquired lockdir')
 
396
 
 
397
            # Block until lock2 has peeked again
 
398
            note('lock1: waiting 2 for checked lock')
 
399
            wait_until_checked_lock.acquire()
 
400
            note('lock1: acquired for checked lock')
 
401
            # Now unlock, and let lock 2 grab the lock
 
402
            lf1.unlock()
 
403
            wait_to_check_lock.release()
 
404
 
 
405
        unlocker = Thread(target=wait_and_switch)
 
406
        unlocker.start()
 
407
        try:
 
408
            # Wait and play against the other thread
 
409
            lf2.wait_lock(timeout=20.0, poll=0.01)
 
410
        finally:
 
411
            unlocker.join()
 
412
        lf2.unlock()
 
413
 
 
414
        # There should be 2 reports, because the lock changed
 
415
        lock_base = lf2.transport.abspath(lf2.path)
 
416
        self.assertEqual(2, len(self._logged_reports))
 
417
        lock_url = lf2.transport.abspath(lf2.path)
 
418
        self.assertEqual('%s %s\n'
 
419
                         '%s\n%s\n'
 
420
                         'Will continue to try until %s, unless '
 
421
                         'you press Ctrl-C.\n'
 
422
                         'See "bzr help break-lock" for more.',
 
423
                         self._logged_reports[0][0])
 
424
        args = self._logged_reports[0][1]
 
425
        self.assertEqual('Unable to obtain', args[0])
 
426
        self.assertEqual('lock %s' % (lock_base,), args[1])
 
427
        self.assertStartsWith(args[2], 'held by ')
 
428
        self.assertStartsWith(args[3], 'locked ')
 
429
        self.assertEndsWith(args[3], ' ago')
 
430
        self.assertContainsRe(args[4], r'\d\d:\d\d:\d\d')
 
431
 
 
432
        self.assertEqual('%s %s\n'
 
433
                         '%s\n%s\n'
 
434
                         'Will continue to try until %s, unless '
 
435
                         'you press Ctrl-C.\n'
 
436
                         'See "bzr help break-lock" for more.',
 
437
                         self._logged_reports[1][0])
 
438
        args = self._logged_reports[1][1]
 
439
        self.assertEqual('Lock owner changed for', args[0])
 
440
        self.assertEqual('lock %s' % (lock_base,), args[1])
 
441
        self.assertStartsWith(args[2], 'held by ')
 
442
        self.assertStartsWith(args[3], 'locked ')
 
443
        self.assertEndsWith(args[3], ' ago')
 
444
        self.assertContainsRe(args[4], r'\d\d:\d\d:\d\d')
 
445
 
222
446
    def test_40_confirm_easy(self):
223
447
        """Confirm a lock that's already held"""
224
448
        t = self.get_transport()
356
580
                self.prompts.append(('boolean', prompt))
357
581
                return True
358
582
        ui = LoggingUIFactory()
359
 
        self.overrideAttr(bzrlib.ui, 'ui_factory', ui)
360
 
        ld2.break_lock()
361
 
        self.assertLength(1, ui.prompts)
362
 
        self.assertEqual('boolean', ui.prompts[0][0])
363
 
        self.assertStartsWith(ui.prompts[0][1], 'Break (corrupt LockDir')
364
 
        self.assertRaises(LockBroken, ld.unlock)
 
583
        orig_factory = bzrlib.ui.ui_factory
 
584
        bzrlib.ui.ui_factory = ui
 
585
        try:
 
586
            ld2.break_lock()
 
587
            self.assertLength(1, ui.prompts)
 
588
            self.assertEqual('boolean', ui.prompts[0][0])
 
589
            self.assertStartsWith(ui.prompts[0][1], 'Break (corrupt LockDir')
 
590
            self.assertRaises(LockBroken, ld.unlock)
 
591
        finally:
 
592
            bzrlib.ui.ui_factory = orig_factory
365
593
 
366
594
    def test_break_lock_missing_info(self):
367
595
        """break_lock works even if the info file is missing (and tells the UI
403
631
        lf1 = LockDir(t, 'test_lock')
404
632
 
405
633
        lf1.create()
406
 
        self.assertTrue(t.has('test_lock'))
 
634
        self.failUnless(t.has('test_lock'))
407
635
 
408
636
        t.rmdir('test_lock')
409
 
        self.assertFalse(t.has('test_lock'))
 
637
        self.failIf(t.has('test_lock'))
410
638
 
411
639
        # This will create 'test_lock' if it needs to
412
640
        lf1.lock_write()
413
 
        self.assertTrue(t.has('test_lock'))
414
 
        self.assertTrue(t.has('test_lock/held/info'))
 
641
        self.failUnless(t.has('test_lock'))
 
642
        self.failUnless(t.has('test_lock/held/info'))
415
643
 
416
644
        lf1.unlock()
417
 
        self.assertFalse(t.has('test_lock/held/info'))
 
645
        self.failIf(t.has('test_lock/held/info'))
418
646
 
419
647
    def test__format_lock_info(self):
420
648
        ld1 = self.get_lock()
513
741
    def test_corrupt_lockdir_info(self):
514
742
        """We can cope with corrupt (and thus unparseable) info files."""
515
743
        # This seems like a fairly common failure case too - see
516
 
        # <https://bugs.launchpad.net/bzr/+bug/619872> for instance.
 
744
        # <https://bugs.edge.launchpad.net/bzr/+bug/619872> for instance.
517
745
        # In particular some systems tend to fill recently created files with
518
746
        # nul bytes after recovering from a system crash.
519
747
        t = self.get_transport()