← 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: 2007-10-24 12:49:17 UTC
  • mfrom: (2935.1.1 ianc-integration)
  • Revision ID: pqm@pqm.ubuntu.com-20071024124917-xb75eckyxx6vkrlg
Makefile fixes - hooks.html generation & allow python to be overridden (Ian Clatworthy)

Show diffs side-by-side

added added

removed removed

Lines of Context:
bzrlib/tests/test_lockdir.py
1
 
# Copyright (C) 2006 Canonical Ltd
 
1
# Copyright (C) 2006, 2007 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
17
17
"""Tests for LockDir"""
18
18
 
19
19
from cStringIO import StringIO
20
 
from threading import Thread
 
20
import os
 
21
from threading import Thread, Lock
21
22
import time
22
23
 
23
24
import bzrlib
 
25
from bzrlib import (
 
26
    config,
 
27
    errors,
 
28
    osutils,
 
29
    tests,
 
30
    transport,
 
31
    )
24
32
from bzrlib.errors import (
25
 
        LockBreakMismatch,
26
 
        LockContention, LockError, UnlockableTransport,
27
 
        LockNotHeld, LockBroken
28
 
        )
 
33
    LockBreakMismatch,
 
34
    LockBroken,
 
35
    LockContention,
 
36
    LockError,
 
37
    LockFailed,
 
38
    LockNotHeld,
 
39
    )
29
40
from bzrlib.lockdir import LockDir
30
41
from bzrlib.tests import TestCaseWithTransport
 
42
from bzrlib.trace import note
31
43
 
32
44
# These tests sometimes use threads to test the behaviour of lock files with
33
45
# concurrent actors.  This is not a typical (or necessarily supported) use;
42
54
class TestLockDir(TestCaseWithTransport):
43
55
    """Test LockDir operations"""
44
56
 
 
57
    def logging_report_function(self, fmt, *args):
 
58
        self._logged_reports.append((fmt, args))
 
59
 
 
60
    def setup_log_reporter(self, lock_dir):
 
61
        self._logged_reports = []
 
62
        lock_dir._report_function = self.logging_report_function
 
63
 
45
64
    def test_00_lock_creation(self):
46
65
        """Creation of lock file on a transport"""
47
66
        t = self.get_transport()
89
108
        """Fail to create lock on readonly transport"""
90
109
        t = self.get_readonly_transport()
91
110
        lf = LockDir(t, 'test_lock')
92
 
        self.assertRaises(UnlockableTransport, lf.create)
 
111
        self.assertRaises(LockFailed, lf.create)
93
112
 
94
113
    def test_12_lock_readonly_transport(self):
95
114
        """Fail to lock on readonly transport"""
96
115
        lf = LockDir(self.get_transport(), 'test_lock')
97
116
        lf.create()
98
117
        lf = LockDir(self.get_readonly_transport(), 'test_lock')
99
 
        self.assertRaises(UnlockableTransport, lf.attempt_lock)
 
118
        self.assertRaises(LockFailed, lf.attempt_lock)
100
119
 
101
120
    def test_20_lock_contested(self):
102
121
        """Contention to get a lock"""
156
175
        lf1 = LockDir(t, 'test_lock')
157
176
        lf1.create()
158
177
        lf2 = LockDir(t, 'test_lock')
 
178
        self.setup_log_reporter(lf2)
159
179
        lf1.attempt_lock()
160
180
        try:
161
181
            before = time.time()
168
188
                    "took %f seconds to detect lock contention" % (after - before))
169
189
        finally:
170
190
            lf1.unlock()
 
191
        lock_base = lf2.transport.abspath(lf2.path)
 
192
        self.assertEqual(1, len(self._logged_reports))
 
193
        self.assertEqual('%s %s\n'
 
194
                         '%s\n%s\n'
 
195
                         'Will continue to try until %s\n',
 
196
                         self._logged_reports[0][0])
 
197
        args = self._logged_reports[0][1]
 
198
        self.assertEqual('Unable to obtain', args[0])
 
199
        self.assertEqual('lock %s' % (lock_base,), args[1])
 
200
        self.assertStartsWith(args[2], 'held by ')
 
201
        self.assertStartsWith(args[3], 'locked ')
 
202
        self.assertEndsWith(args[3], ' ago')
 
203
        self.assertContainsRe(args[4], r'\d\d:\d\d:\d\d')
171
204
 
172
205
    def test_31_lock_wait_easy(self):
173
206
        """Succeed when waiting on a lock with no contention.
175
208
        t = self.get_transport()
176
209
        lf1 = LockDir(t, 'test_lock')
177
210
        lf1.create()
 
211
        self.setup_log_reporter(lf1)
178
212
        try:
179
213
            before = time.time()
180
214
            lf1.wait_lock(timeout=0.4, poll=0.1)
182
216
            self.assertTrue(after - before <= 1.0)
183
217
        finally:
184
218
            lf1.unlock()
 
219
        self.assertEqual([], self._logged_reports)
185
220
 
186
221
    def test_32_lock_wait_succeed(self):
187
222
        """Succeed when trying to acquire a lock that gets released
189
224
        One thread holds on a lock and then releases it; another 
190
225
        tries to lock it.
191
226
        """
 
227
        # This test sometimes fails like this:
 
228
        # Traceback (most recent call last):
 
229
 
 
230
        #   File "/home/pqm/bzr-pqm-workdir/home/+trunk/bzrlib/tests/
 
231
        # test_lockdir.py", line 247, in test_32_lock_wait_succeed
 
232
        #     self.assertEqual(1, len(self._logged_reports))
 
233
        # AssertionError: not equal:
 
234
        # a = 1
 
235
        # b = 0
 
236
        raise tests.TestSkipped("Test fails intermittently")
192
237
        t = self.get_transport()
193
238
        lf1 = LockDir(t, 'test_lock')
194
239
        lf1.create()
201
246
        unlocker.start()
202
247
        try:
203
248
            lf2 = LockDir(t, 'test_lock')
 
249
            self.setup_log_reporter(lf2)
204
250
            before = time.time()
205
251
            # wait and then lock
206
252
            lf2.wait_lock(timeout=0.4, poll=0.1)
209
255
        finally:
210
256
            unlocker.join()
211
257
 
212
 
    def test_33_wait(self):
213
 
        """Succeed when waiting on a lock that gets released
 
258
        # There should be only 1 report, even though it should have to
 
259
        # wait for a while
 
260
        lock_base = lf2.transport.abspath(lf2.path)
 
261
        self.assertEqual(1, len(self._logged_reports))
 
262
        self.assertEqual('%s %s\n'
 
263
                         '%s\n%s\n'
 
264
                         'Will continue to try until %s\n',
 
265
                         self._logged_reports[0][0])
 
266
        args = self._logged_reports[0][1]
 
267
        self.assertEqual('Unable to obtain', args[0])
 
268
        self.assertEqual('lock %s' % (lock_base,), args[1])
 
269
        self.assertStartsWith(args[2], 'held by ')
 
270
        self.assertStartsWith(args[3], 'locked ')
 
271
        self.assertEndsWith(args[3], ' ago')
 
272
        self.assertContainsRe(args[4], r'\d\d:\d\d:\d\d')
214
273
 
215
 
        The difference from test_32_lock_wait_succeed is that the second 
216
 
        caller does not actually acquire the lock, but just waits for it
217
 
        to be released.  This is done over a readonly transport.
218
 
        """
 
274
    def test_34_lock_write_waits(self):
 
275
        """LockDir.lock_write() will wait for the lock.""" 
 
276
        # the test suite sets the default to 0 to make deadlocks fail fast.
 
277
        # change it for this test, as we want to try a manual deadlock.
 
278
        raise tests.TestSkipped('Timing-sensitive test')
 
279
        bzrlib.lockdir._DEFAULT_TIMEOUT_SECONDS = 300
219
280
        t = self.get_transport()
220
281
        lf1 = LockDir(t, 'test_lock')
221
282
        lf1.create()
227
288
        unlocker = Thread(target=wait_and_unlock)
228
289
        unlocker.start()
229
290
        try:
230
 
            lf2 = LockDir(self.get_readonly_transport(), 'test_lock')
 
291
            lf2 = LockDir(t, 'test_lock')
 
292
            self.setup_log_reporter(lf2)
231
293
            before = time.time()
232
 
            # wait but don't lock
233
 
            lf2.wait(timeout=0.4, poll=0.1)
 
294
            # wait and then lock
 
295
            lf2.lock_write()
234
296
            after = time.time()
235
 
            self.assertTrue(after - before <= 1.0)
236
 
        finally:
237
 
            unlocker.join()
 
297
        finally:
 
298
            unlocker.join()
 
299
 
 
300
        # There should be only 1 report, even though it should have to
 
301
        # wait for a while
 
302
        lock_base = lf2.transport.abspath(lf2.path)
 
303
        self.assertEqual(1, len(self._logged_reports))
 
304
        self.assertEqual('%s %s\n'
 
305
                         '%s\n%s\n'
 
306
                         'Will continue to try until %s\n',
 
307
                         self._logged_reports[0][0])
 
308
        args = self._logged_reports[0][1]
 
309
        self.assertEqual('Unable to obtain', args[0])
 
310
        self.assertEqual('lock %s' % (lock_base,), args[1])
 
311
        self.assertStartsWith(args[2], 'held by ')
 
312
        self.assertStartsWith(args[3], 'locked ')
 
313
        self.assertEndsWith(args[3], ' ago')
 
314
        self.assertContainsRe(args[4], r'\d\d:\d\d:\d\d')
 
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 'checked' lock.
 
326
        3) Thread1 blocks on acquiring the 'checked' 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 'checked' 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_checked_lock = Lock()
 
338
 
 
339
        wait_to_check_lock.acquire()
 
340
        wait_until_checked_lock.acquire()
 
341
        note('locked check and checked 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 attempt_lock(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).attempt_lock()
 
364
                finally:
 
365
                    note('lock2: releasing checked lock')
 
366
                    wait_until_checked_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 check
 
378
            note('lock1: waiting 1 for checked lock')
 
379
            wait_until_checked_lock.acquire()
 
380
            note('lock1: acquired for checked 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 checked lock')
 
391
            wait_until_checked_lock.acquire()
 
392
            note('lock1: acquired for checked lock')
 
393
            # Now unlock, and let lock 2 grab the lock
 
394
            lf1.unlock()
 
395
            wait_to_check_lock.release()
 
396
 
 
397
        unlocker = Thread(target=wait_and_switch)
 
398
        unlocker.start()
 
399
        try:
 
400
            # Wait and play against the other thread
 
401
            lf2.wait_lock(timeout=20.0, poll=0.01)
 
402
        finally:
 
403
            unlocker.join()
 
404
        lf2.unlock()
 
405
 
 
406
        # There should be 2 reports, because the lock changed
 
407
        lock_base = lf2.transport.abspath(lf2.path)
 
408
        self.assertEqual(2, len(self._logged_reports))
 
409
 
 
410
        self.assertEqual('%s %s\n'
 
411
                         '%s\n%s\n'
 
412
                         'Will continue to try until %s\n',
 
413
                         self._logged_reports[0][0])
 
414
        args = self._logged_reports[0][1]
 
415
        self.assertEqual('Unable to obtain', args[0])
 
416
        self.assertEqual('lock %s' % (lock_base,), args[1])
 
417
        self.assertStartsWith(args[2], 'held by ')
 
418
        self.assertStartsWith(args[3], 'locked ')
 
419
        self.assertEndsWith(args[3], ' ago')
 
420
        self.assertContainsRe(args[4], r'\d\d:\d\d:\d\d')
 
421
 
 
422
        self.assertEqual('%s %s\n'
 
423
                         '%s\n%s\n'
 
424
                         'Will continue to try until %s\n',
 
425
                         self._logged_reports[1][0])
 
426
        args = self._logged_reports[1][1]
 
427
        self.assertEqual('Lock owner changed for', args[0])
 
428
        self.assertEqual('lock %s' % (lock_base,), args[1])
 
429
        self.assertStartsWith(args[2], 'held by ')
 
430
        self.assertStartsWith(args[3], 'locked ')
 
431
        self.assertEndsWith(args[3], ' ago')
 
432
        self.assertContainsRe(args[4], r'\d\d:\d\d:\d\d')
238
433
 
239
434
    def test_40_confirm_easy(self):
240
435
        """Confirm a lock that's already held"""
352
547
            self.assertRaises(LockBroken, ld1.unlock)
353
548
        finally:
354
549
            bzrlib.ui.ui_factory = orig_factory
 
550
 
 
551
    def test_create_missing_base_directory(self):
 
552
        """If LockDir.path doesn't exist, it can be created
 
553
 
 
554
        Some people manually remove the entire lock/ directory trying
 
555
        to unlock a stuck repository/branch/etc. Rather than failing
 
556
        after that, just create the lock directory when needed.
 
557
        """
 
558
        t = self.get_transport()
 
559
        lf1 = LockDir(t, 'test_lock')
 
560
 
 
561
        lf1.create()
 
562
        self.failUnless(t.has('test_lock'))
 
563
 
 
564
        t.rmdir('test_lock')
 
565
        self.failIf(t.has('test_lock'))
 
566
 
 
567
        # This will create 'test_lock' if it needs to
 
568
        lf1.lock_write()
 
569
        self.failUnless(t.has('test_lock'))
 
570
        self.failUnless(t.has('test_lock/held/info'))
 
571
 
 
572
        lf1.unlock()
 
573
        self.failIf(t.has('test_lock/held/info'))
 
574
 
 
575
    def test__format_lock_info(self):
 
576
        ld1 = self.get_lock()
 
577
        ld1.create()
 
578
        ld1.lock_write()
 
579
        try:
 
580
            info_list = ld1._format_lock_info(ld1.peek())
 
581
        finally:
 
582
            ld1.unlock()
 
583
        self.assertEqual('lock %s' % (ld1.transport.abspath(ld1.path),),
 
584
                         info_list[0])
 
585
        self.assertContainsRe(info_list[1],
 
586
                              r'^held by .* on host .* \[process #\d*\]$')
 
587
        self.assertContainsRe(info_list[2], r'locked \d+ seconds? ago$')
 
588
 
 
589
    def test_lock_without_email(self):
 
590
        global_config = config.GlobalConfig()
 
591
        # Intentionally has no email address
 
592
        global_config.set_user_option('email', 'User Identity')
 
593
        ld1 = self.get_lock()
 
594
        ld1.create()
 
595
        ld1.lock_write()
 
596
        ld1.unlock()
 
597
 
 
598
    def test_lock_permission(self):
 
599
        if not osutils.supports_posix_readonly():
 
600
            raise tests.TestSkipped('Cannot induce a permission failure')
 
601
        ld1 = self.get_lock()
 
602
        lock_path = ld1.transport.local_abspath('test_lock')
 
603
        os.mkdir(lock_path)
 
604
        osutils.make_readonly(lock_path)
 
605
        self.assertRaises(errors.LockFailed, ld1.attempt_lock)
 
606
 
 
607
    def test_lock_by_token(self):
 
608
        ld1 = self.get_lock()
 
609
        token = ld1.lock_write()
 
610
        self.assertNotEqual(None, token)
 
611
        ld2 = self.get_lock()
 
612
        t2 = ld2.lock_write(token)
 
613
        self.assertEqual(token, t2)
 
614
 
 
615
    def test_lock_with_buggy_rename(self):
 
616
        # test that lock acquisition handles servers which pretend they
 
617
        # renamed correctly but that actually fail
 
618
        t = transport.get_transport('brokenrename+' + self.get_url())
 
619
        ld1 = LockDir(t, 'test_lock')
 
620
        ld1.create()
 
621
        ld1.attempt_lock()
 
622
        ld2 = LockDir(t, 'test_lock')
 
623
        # we should fail to lock
 
624
        e = self.assertRaises(errors.LockContention, ld2.attempt_lock)
 
625
        # now the original caller should succeed in unlocking
 
626
        ld1.unlock()
 
627
        # and there should be nothing left over
 
628
        self.assertEquals([], t.list_dir('test_lock'))
 
629
 
 
630
    def test_failed_lock_leaves_no_trash(self):
 
631
        # if we fail to acquire the lock, we don't leave pending directories
 
632
        # behind -- https://bugs.launchpad.net/bzr/+bug/109169
 
633
        ld1 = self.get_lock()
 
634
        ld2 = self.get_lock()
 
635
        # should be nothing before we start
 
636
        ld1.create()
 
637
        t = self.get_transport().clone('test_lock')
 
638
        def check_dir(a):
 
639
            self.assertEquals(a, t.list_dir('.'))
 
640
        check_dir([])
 
641
        # when held, that's all we see
 
642
        ld1.attempt_lock()
 
643
        check_dir(['held'])
 
644
        # second guy should fail
 
645
        self.assertRaises(errors.LockContention, ld2.attempt_lock)
 
646
        # no kibble
 
647
        check_dir(['held'])