~bzr-pqm/bzr/bzr.dev

« back to all changes in this revision

Viewing changes to bzrlib/tests/test_lockdir.py

  • Committer: Jelmer Vernooij
  • Date: 2011-05-20 13:04:19 UTC
  • mto: This revision was merged to the branch mainline in revision 5952.
  • Revision ID: jelmer@samba.org-20110520130419-p0wmuca3unsqnndw
Remove some unnecessary code.

Show diffs side-by-side

added added

removed removed

Lines of Context:
1
 
# Copyright (C) 2006-2010 Canonical Ltd
 
1
# Copyright (C) 2006-2011 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
20
19
import os
21
 
from threading import Thread, Lock
22
20
import time
23
21
 
24
22
import bzrlib
34
32
    LockBreakMismatch,
35
33
    LockBroken,
36
34
    LockContention,
37
 
    LockError,
38
35
    LockFailed,
39
36
    LockNotHeld,
40
37
    )
41
38
from bzrlib.lockdir import LockDir
42
 
from bzrlib.tests import TestCaseWithTransport
 
39
from bzrlib.tests import (
 
40
    features,
 
41
    TestCaseWithTransport,
 
42
    )
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
 
 
49
45
# These tests are run on the default transport provided by the test framework
50
46
# (typically a local disk transport).  That can be changed by the --transport
51
47
# option to bzr selftest.  The required properties of the transport
223
219
            lf1.unlock()
224
220
        self.assertEqual([], self._logged_reports)
225
221
 
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
 
 
446
222
    def test_40_confirm_easy(self):
447
223
        """Confirm a lock that's already held"""
448
224
        t = self.get_transport()
564
340
        finally:
565
341
            bzrlib.ui.ui_factory = orig_factory
566
342
 
 
343
    def test_break_lock_corrupt_info(self):
 
344
        """break_lock works even if the info file is corrupt (and tells the UI
 
345
        that it is corrupt).
 
346
        """
 
347
        ld = self.get_lock()
 
348
        ld2 = self.get_lock()
 
349
        ld.create()
 
350
        ld.lock_write()
 
351
        ld.transport.put_bytes_non_atomic('test_lock/held/info', '\0')
 
352
        class LoggingUIFactory(bzrlib.ui.SilentUIFactory):
 
353
            def __init__(self):
 
354
                self.prompts = []
 
355
            def get_boolean(self, prompt):
 
356
                self.prompts.append(('boolean', prompt))
 
357
                return True
 
358
        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)
 
365
 
 
366
    def test_break_lock_missing_info(self):
 
367
        """break_lock works even if the info file is missing (and tells the UI
 
368
        that it is corrupt).
 
369
        """
 
370
        ld = self.get_lock()
 
371
        ld2 = self.get_lock()
 
372
        ld.create()
 
373
        ld.lock_write()
 
374
        ld.transport.delete('test_lock/held/info')
 
375
        class LoggingUIFactory(bzrlib.ui.SilentUIFactory):
 
376
            def __init__(self):
 
377
                self.prompts = []
 
378
            def get_boolean(self, prompt):
 
379
                self.prompts.append(('boolean', prompt))
 
380
                return True
 
381
        ui = LoggingUIFactory()
 
382
        orig_factory = bzrlib.ui.ui_factory
 
383
        bzrlib.ui.ui_factory = ui
 
384
        try:
 
385
            ld2.break_lock()
 
386
            self.assertRaises(LockBroken, ld.unlock)
 
387
            self.assertLength(0, ui.prompts)
 
388
        finally:
 
389
            bzrlib.ui.ui_factory = orig_factory
 
390
        # Suppress warnings due to ld not being unlocked
 
391
        # XXX: if lock_broken hook was invoked in this case, this hack would
 
392
        # not be necessary.  - Andrew Bennetts, 2010-09-06.
 
393
        del self._lock_actions[:]
 
394
 
567
395
    def test_create_missing_base_directory(self):
568
396
        """If LockDir.path doesn't exist, it can be created
569
397
 
575
403
        lf1 = LockDir(t, 'test_lock')
576
404
 
577
405
        lf1.create()
578
 
        self.failUnless(t.has('test_lock'))
 
406
        self.assertTrue(t.has('test_lock'))
579
407
 
580
408
        t.rmdir('test_lock')
581
 
        self.failIf(t.has('test_lock'))
 
409
        self.assertFalse(t.has('test_lock'))
582
410
 
583
411
        # This will create 'test_lock' if it needs to
584
412
        lf1.lock_write()
585
 
        self.failUnless(t.has('test_lock'))
586
 
        self.failUnless(t.has('test_lock/held/info'))
 
413
        self.assertTrue(t.has('test_lock'))
 
414
        self.assertTrue(t.has('test_lock/held/info'))
587
415
 
588
416
        lf1.unlock()
589
 
        self.failIf(t.has('test_lock/held/info'))
 
417
        self.assertFalse(t.has('test_lock/held/info'))
590
418
 
591
419
    def test__format_lock_info(self):
592
420
        ld1 = self.get_lock()
611
439
        ld1.unlock()
612
440
 
613
441
    def test_lock_permission(self):
 
442
        self.requireFeature(features.not_running_as_root)
614
443
        if not osutils.supports_posix_readonly():
615
444
            raise tests.TestSkipped('Cannot induce a permission failure')
616
445
        ld1 = self.get_lock()
681
510
            ['<unknown>', '<unknown>', '<unknown>', '(unknown)'],
682
511
            formatted_info)
683
512
 
 
513
    def test_corrupt_lockdir_info(self):
 
514
        """We can cope with corrupt (and thus unparseable) info files."""
 
515
        # This seems like a fairly common failure case too - see
 
516
        # <https://bugs.launchpad.net/bzr/+bug/619872> for instance.
 
517
        # In particular some systems tend to fill recently created files with
 
518
        # nul bytes after recovering from a system crash.
 
519
        t = self.get_transport()
 
520
        t.mkdir('test_lock')
 
521
        t.mkdir('test_lock/held')
 
522
        t.put_bytes('test_lock/held/info', '\0')
 
523
        lf = LockDir(t, 'test_lock')
 
524
        self.assertRaises(errors.LockCorrupt, lf.peek)
 
525
        # Currently attempt_lock gives LockContention, but LockCorrupt would be
 
526
        # a reasonable result too.
 
527
        self.assertRaises(
 
528
            (errors.LockCorrupt, errors.LockContention), lf.attempt_lock)
 
529
        self.assertRaises(errors.LockCorrupt, lf.validate_token, 'fake token')
 
530
 
 
531
    def test_missing_lockdir_info(self):
 
532
        """We can cope with absent info files."""
 
533
        t = self.get_transport()
 
534
        t.mkdir('test_lock')
 
535
        t.mkdir('test_lock/held')
 
536
        lf = LockDir(t, 'test_lock')
 
537
        # In this case we expect the 'not held' result from peek, because peek
 
538
        # cannot be expected to notice that there is a 'held' directory with no
 
539
        # 'info' file.
 
540
        self.assertEqual(None, lf.peek())
 
541
        # And lock/unlock may work or give LockContention (but not any other
 
542
        # error).
 
543
        try:
 
544
            lf.attempt_lock()
 
545
        except LockContention:
 
546
            # LockContention is ok, and expected on Windows
 
547
            pass
 
548
        else:
 
549
            # no error is ok, and expected on POSIX (because POSIX allows
 
550
            # os.rename over an empty directory).
 
551
            lf.unlock()
 
552
        # Currently raises TokenMismatch, but LockCorrupt would be reasonable
 
553
        # too.
 
554
        self.assertRaises(
 
555
            (errors.TokenMismatch, errors.LockCorrupt),
 
556
            lf.validate_token, 'fake token')
 
557
 
684
558
 
685
559
class TestLockDirHooks(TestCaseWithTransport):
686
560