← 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: Andrew Bennetts
  • Date: 2008-09-05 10:48:03 UTC
  • mto: This revision was merged to the branch mainline in revision 3693.
  • Revision ID: andrew.bennetts@canonical.com-20080905104803-6g72dz6wcldosfs2
Remove monkey-patching of branch._ensure_real from test_remote.py.

Show diffs side-by-side

added added

removed removed

Lines of Context:
bzrlib/tests/test_lockdir.py
1
 
# Copyright (C) 2006 Canonical Ltd
2
 
 
 
1
# Copyright (C) 2006, 2007 Canonical Ltd
 
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
5
5
# the Free Software Foundation; either version 2 of the License, or
6
6
# (at your option) any later version.
7
 
 
 
7
#
8
8
# This program is distributed in the hope that it will be useful,
9
9
# but WITHOUT ANY WARRANTY; without even the implied warranty of
10
10
# MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.  See the
11
11
# GNU General Public License for more details.
12
 
 
 
12
#
13
13
# You should have received a copy of the GNU General Public License
14
14
# along with this program; if not, write to the Free Software
15
15
# Foundation, Inc., 59 Temple Place, Suite 330, Boston, MA  02111-1307  USA
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
        lock_url = lf2.transport.abspath(lf2.path)
 
194
        self.assertEqual('%s %s\n'
 
195
                         '%s\n%s\n'
 
196
                         'Will continue to try until %s, unless '
 
197
                         'you press Ctrl-C\n'
 
198
                         'If you\'re sure that it\'s not being '
 
199
                         'modified, use bzr break-lock %s',
 
200
                         self._logged_reports[0][0])
 
201
        args = self._logged_reports[0][1]
 
202
        self.assertEqual('Unable to obtain', args[0])
 
203
        self.assertEqual('lock %s' % (lock_base,), args[1])
 
204
        self.assertStartsWith(args[2], 'held by ')
 
205
        self.assertStartsWith(args[3], 'locked ')
 
206
        self.assertEndsWith(args[3], ' ago')
 
207
        self.assertContainsRe(args[4], r'\d\d:\d\d:\d\d')
171
208
 
172
209
    def test_31_lock_wait_easy(self):
173
210
        """Succeed when waiting on a lock with no contention.
175
212
        t = self.get_transport()
176
213
        lf1 = LockDir(t, 'test_lock')
177
214
        lf1.create()
 
215
        self.setup_log_reporter(lf1)
178
216
        try:
179
217
            before = time.time()
180
218
            lf1.wait_lock(timeout=0.4, poll=0.1)
182
220
            self.assertTrue(after - before <= 1.0)
183
221
        finally:
184
222
            lf1.unlock()
 
223
        self.assertEqual([], self._logged_reports)
185
224
 
186
225
    def test_32_lock_wait_succeed(self):
187
226
        """Succeed when trying to acquire a lock that gets released
189
228
        One thread holds on a lock and then releases it; another 
190
229
        tries to lock it.
191
230
        """
 
231
        # This test sometimes fails like this:
 
232
        # Traceback (most recent call last):
 
233
 
 
234
        #   File "/home/pqm/bzr-pqm-workdir/home/+trunk/bzrlib/tests/
 
235
        # test_lockdir.py", line 247, in test_32_lock_wait_succeed
 
236
        #     self.assertEqual(1, len(self._logged_reports))
 
237
        # AssertionError: not equal:
 
238
        # a = 1
 
239
        # b = 0
 
240
        raise tests.TestSkipped("Test fails intermittently")
192
241
        t = self.get_transport()
193
242
        lf1 = LockDir(t, 'test_lock')
194
243
        lf1.create()
201
250
        unlocker.start()
202
251
        try:
203
252
            lf2 = LockDir(t, 'test_lock')
 
253
            self.setup_log_reporter(lf2)
204
254
            before = time.time()
205
255
            # wait and then lock
206
256
            lf2.wait_lock(timeout=0.4, poll=0.1)
209
259
        finally:
210
260
            unlocker.join()
211
261
 
212
 
    def test_33_wait(self):
213
 
        """Succeed when waiting on a lock that gets released
 
262
        # There should be only 1 report, even though it should have to
 
263
        # wait for a while
 
264
        lock_base = lf2.transport.abspath(lf2.path)
 
265
        self.assertEqual(1, len(self._logged_reports))
 
266
        self.assertEqual('%s %s\n'
 
267
                         '%s\n%s\n'
 
268
                         'Will continue to try until %s\n',
 
269
                         self._logged_reports[0][0])
 
270
        args = self._logged_reports[0][1]
 
271
        self.assertEqual('Unable to obtain', args[0])
 
272
        self.assertEqual('lock %s' % (lock_base,), args[1])
 
273
        self.assertStartsWith(args[2], 'held by ')
 
274
        self.assertStartsWith(args[3], 'locked ')
 
275
        self.assertEndsWith(args[3], ' ago')
 
276
        self.assertContainsRe(args[4], r'\d\d:\d\d:\d\d')
214
277
 
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
 
        """
 
278
    def test_34_lock_write_waits(self):
 
279
        """LockDir.lock_write() will wait for the lock.""" 
 
280
        # the test suite sets the default to 0 to make deadlocks fail fast.
 
281
        # change it for this test, as we want to try a manual deadlock.
 
282
        raise tests.TestSkipped('Timing-sensitive test')
 
283
        bzrlib.lockdir._DEFAULT_TIMEOUT_SECONDS = 300
219
284
        t = self.get_transport()
220
285
        lf1 = LockDir(t, 'test_lock')
221
286
        lf1.create()
227
292
        unlocker = Thread(target=wait_and_unlock)
228
293
        unlocker.start()
229
294
        try:
230
 
            lf2 = LockDir(self.get_readonly_transport(), 'test_lock')
 
295
            lf2 = LockDir(t, 'test_lock')
 
296
            self.setup_log_reporter(lf2)
231
297
            before = time.time()
232
 
            # wait but don't lock
233
 
            lf2.wait(timeout=0.4, poll=0.1)
 
298
            # wait and then lock
 
299
            lf2.lock_write()
234
300
            after = time.time()
235
 
            self.assertTrue(after - before <= 1.0)
236
 
        finally:
237
 
            unlocker.join()
 
301
        finally:
 
302
            unlocker.join()
 
303
 
 
304
        # There should be only 1 report, even though it should have to
 
305
        # wait for a while
 
306
        lock_base = lf2.transport.abspath(lf2.path)
 
307
        self.assertEqual(1, len(self._logged_reports))
 
308
        self.assertEqual('%s %s\n'
 
309
                         '%s\n%s\n'
 
310
                         'Will continue to try until %s\n',
 
311
                         self._logged_reports[0][0])
 
312
        args = self._logged_reports[0][1]
 
313
        self.assertEqual('Unable to obtain', args[0])
 
314
        self.assertEqual('lock %s' % (lock_base,), args[1])
 
315
        self.assertStartsWith(args[2], 'held by ')
 
316
        self.assertStartsWith(args[3], 'locked ')
 
317
        self.assertEndsWith(args[3], ' ago')
 
318
        self.assertContainsRe(args[4], r'\d\d:\d\d:\d\d')
 
319
 
 
320
    def test_35_wait_lock_changing(self):
 
321
        """LockDir.wait_lock() will report if the lock changes underneath.
 
322
        
 
323
        This is the stages we want to happen:
 
324
 
 
325
        0) Synchronization locks are created and locked.
 
326
        1) Lock1 obtains the lockdir, and releases the 'check' lock.
 
327
        2) Lock2 grabs the 'check' lock, and checks the lockdir.
 
328
           It sees the lockdir is already acquired, reports the fact, 
 
329
           and unsets the 'checked' lock.
 
330
        3) Thread1 blocks on acquiring the 'checked' lock, and then tells
 
331
           Lock1 to release and acquire the lockdir. This resets the 'check'
 
332
           lock.
 
333
        4) Lock2 acquires the 'check' lock, and checks again. It notices
 
334
           that the holder of the lock has changed, and so reports a new 
 
335
           lock holder.
 
336
        5) Thread1 blocks on the 'checked' lock, this time, it completely
 
337
           unlocks the lockdir, allowing Lock2 to acquire the lock.
 
338
        """
 
339
 
 
340
        raise tests.KnownFailure(
 
341
            "timing dependency in lock tests (#213182)")
 
342
 
 
343
        wait_to_check_lock = Lock()
 
344
        wait_until_checked_lock = Lock()
 
345
 
 
346
        wait_to_check_lock.acquire()
 
347
        wait_until_checked_lock.acquire()
 
348
        note('locked check and checked locks')
 
349
 
 
350
        class LockDir1(LockDir):
 
351
            """Use the synchronization points for the first lock."""
 
352
 
 
353
            def attempt_lock(self):
 
354
                # Once we have acquired the lock, it is okay for
 
355
                # the other lock to check it
 
356
                try:
 
357
                    return super(LockDir1, self).attempt_lock()
 
358
                finally:
 
359
                    note('lock1: releasing check lock')
 
360
                    wait_to_check_lock.release()
 
361
 
 
362
        class LockDir2(LockDir):
 
363
            """Use the synchronization points for the second lock."""
 
364
 
 
365
            def attempt_lock(self):
 
366
                note('lock2: waiting for check lock')
 
367
                wait_to_check_lock.acquire()
 
368
                note('lock2: acquired check lock')
 
369
                try:
 
370
                    return super(LockDir2, self).attempt_lock()
 
371
                finally:
 
372
                    note('lock2: releasing checked lock')
 
373
                    wait_until_checked_lock.release()
 
374
 
 
375
        t = self.get_transport()
 
376
        lf1 = LockDir1(t, 'test_lock')
 
377
        lf1.create()
 
378
 
 
379
        lf2 = LockDir2(t, 'test_lock')
 
380
        self.setup_log_reporter(lf2)
 
381
 
 
382
        def wait_and_switch():
 
383
            lf1.attempt_lock()
 
384
            # Block until lock2 has had a chance to check
 
385
            note('lock1: waiting 1 for checked lock')
 
386
            wait_until_checked_lock.acquire()
 
387
            note('lock1: acquired for checked lock')
 
388
            note('lock1: released lockdir')
 
389
            lf1.unlock()
 
390
            note('lock1: acquiring lockdir')
 
391
            # Create a new nonce, so the lock looks different.
 
392
            lf1.nonce = osutils.rand_chars(20)
 
393
            lf1.lock_write()
 
394
            note('lock1: acquired lockdir')
 
395
 
 
396
            # Block until lock2 has peeked again
 
397
            note('lock1: waiting 2 for checked lock')
 
398
            wait_until_checked_lock.acquire()
 
399
            note('lock1: acquired for checked lock')
 
400
            # Now unlock, and let lock 2 grab the lock
 
401
            lf1.unlock()
 
402
            wait_to_check_lock.release()
 
403
 
 
404
        unlocker = Thread(target=wait_and_switch)
 
405
        unlocker.start()
 
406
        try:
 
407
            # Wait and play against the other thread
 
408
            lf2.wait_lock(timeout=20.0, poll=0.01)
 
409
        finally:
 
410
            unlocker.join()
 
411
        lf2.unlock()
 
412
 
 
413
        # There should be 2 reports, because the lock changed
 
414
        lock_base = lf2.transport.abspath(lf2.path)
 
415
        self.assertEqual(2, len(self._logged_reports))
 
416
        lock_url = lf2.transport.abspath(lf2.path)
 
417
        self.assertEqual('%s %s\n'
 
418
                         '%s\n%s\n'
 
419
                         'Will continue to try until %s, unless '
 
420
                         'you press Ctrl-C\n'
 
421
                         'If you\'re sure that it\'s not being '
 
422
                         'modified, use bzr break-lock %s',
 
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
                         'If you\'re sure that it\'s not being '
 
437
                         'modified, use bzr break-lock %s',
 
438
                         self._logged_reports[1][0])
 
439
        args = self._logged_reports[1][1]
 
440
        self.assertEqual('Lock owner changed for', args[0])
 
441
        self.assertEqual('lock %s' % (lock_base,), args[1])
 
442
        self.assertStartsWith(args[2], 'held by ')
 
443
        self.assertStartsWith(args[3], 'locked ')
 
444
        self.assertEndsWith(args[3], ' ago')
 
445
        self.assertContainsRe(args[4], r'\d\d:\d\d:\d\d')
238
446
 
239
447
    def test_40_confirm_easy(self):
240
448
        """Confirm a lock that's already held"""
352
560
            self.assertRaises(LockBroken, ld1.unlock)
353
561
        finally:
354
562
            bzrlib.ui.ui_factory = orig_factory
 
563
 
 
564
    def test_create_missing_base_directory(self):
 
565
        """If LockDir.path doesn't exist, it can be created
 
566
 
 
567
        Some people manually remove the entire lock/ directory trying
 
568
        to unlock a stuck repository/branch/etc. Rather than failing
 
569
        after that, just create the lock directory when needed.
 
570
        """
 
571
        t = self.get_transport()
 
572
        lf1 = LockDir(t, 'test_lock')
 
573
 
 
574
        lf1.create()
 
575
        self.failUnless(t.has('test_lock'))
 
576
 
 
577
        t.rmdir('test_lock')
 
578
        self.failIf(t.has('test_lock'))
 
579
 
 
580
        # This will create 'test_lock' if it needs to
 
581
        lf1.lock_write()
 
582
        self.failUnless(t.has('test_lock'))
 
583
        self.failUnless(t.has('test_lock/held/info'))
 
584
 
 
585
        lf1.unlock()
 
586
        self.failIf(t.has('test_lock/held/info'))
 
587
 
 
588
    def test__format_lock_info(self):
 
589
        ld1 = self.get_lock()
 
590
        ld1.create()
 
591
        ld1.lock_write()
 
592
        try:
 
593
            info_list = ld1._format_lock_info(ld1.peek())
 
594
        finally:
 
595
            ld1.unlock()
 
596
        self.assertEqual('lock %s' % (ld1.transport.abspath(ld1.path),),
 
597
                         info_list[0])
 
598
        self.assertContainsRe(info_list[1],
 
599
                              r'^held by .* on host .* \[process #\d*\]$')
 
600
        self.assertContainsRe(info_list[2], r'locked \d+ seconds? ago$')
 
601
 
 
602
    def test_lock_without_email(self):
 
603
        global_config = config.GlobalConfig()
 
604
        # Intentionally has no email address
 
605
        global_config.set_user_option('email', 'User Identity')
 
606
        ld1 = self.get_lock()
 
607
        ld1.create()
 
608
        ld1.lock_write()
 
609
        ld1.unlock()
 
610
 
 
611
    def test_lock_permission(self):
 
612
        if not osutils.supports_posix_readonly():
 
613
            raise tests.TestSkipped('Cannot induce a permission failure')
 
614
        ld1 = self.get_lock()
 
615
        lock_path = ld1.transport.local_abspath('test_lock')
 
616
        os.mkdir(lock_path)
 
617
        osutils.make_readonly(lock_path)
 
618
        self.assertRaises(errors.LockFailed, ld1.attempt_lock)
 
619
 
 
620
    def test_lock_by_token(self):
 
621
        ld1 = self.get_lock()
 
622
        token = ld1.lock_write()
 
623
        self.assertNotEqual(None, token)
 
624
        ld2 = self.get_lock()
 
625
        t2 = ld2.lock_write(token)
 
626
        self.assertEqual(token, t2)
 
627
 
 
628
    def test_lock_with_buggy_rename(self):
 
629
        # test that lock acquisition handles servers which pretend they
 
630
        # renamed correctly but that actually fail
 
631
        t = transport.get_transport('brokenrename+' + self.get_url())
 
632
        ld1 = LockDir(t, 'test_lock')
 
633
        ld1.create()
 
634
        ld1.attempt_lock()
 
635
        ld2 = LockDir(t, 'test_lock')
 
636
        # we should fail to lock
 
637
        e = self.assertRaises(errors.LockContention, ld2.attempt_lock)
 
638
        # now the original caller should succeed in unlocking
 
639
        ld1.unlock()
 
640
        # and there should be nothing left over
 
641
        self.assertEquals([], t.list_dir('test_lock'))
 
642
 
 
643
    def test_failed_lock_leaves_no_trash(self):
 
644
        # if we fail to acquire the lock, we don't leave pending directories
 
645
        # behind -- https://bugs.launchpad.net/bzr/+bug/109169
 
646
        ld1 = self.get_lock()
 
647
        ld2 = self.get_lock()
 
648
        # should be nothing before we start
 
649
        ld1.create()
 
650
        t = self.get_transport().clone('test_lock')
 
651
        def check_dir(a):
 
652
            self.assertEquals(a, t.list_dir('.'))
 
653
        check_dir([])
 
654
        # when held, that's all we see
 
655
        ld1.attempt_lock()
 
656
        check_dir(['held'])
 
657
        # second guy should fail
 
658
        self.assertRaises(errors.LockContention, ld2.attempt_lock)
 
659
        # no kibble
 
660
        check_dir(['held'])