~bzr-pqm/bzr/bzr.dev

« back to all changes in this revision

Viewing changes to bzrlib/tests/test_lockdir.py

  • Committer: Martin Pool
  • Date: 2008-07-03 10:44:34 UTC
  • mfrom: (3512.3.2 setlocale.mini)
  • mto: This revision was merged to the branch mainline in revision 3518.
  • Revision ID: mbp@sourcefrog.net-20080703104434-v4qgzvxd2wxg8etl
Set locale from environment for third party libs and day of week.

Show diffs side-by-side

added added

removed removed

Lines of Context:
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
16
16
 
17
17
"""Tests for LockDir"""
18
18
 
19
 
from threading import Thread
 
19
from cStringIO import StringIO
 
20
import os
 
21
from threading import Thread, Lock
20
22
import time
21
23
 
 
24
import bzrlib
 
25
from bzrlib import (
 
26
    config,
 
27
    errors,
 
28
    osutils,
 
29
    tests,
 
30
    transport,
 
31
    )
22
32
from bzrlib.errors import (
23
 
        LockBreakMismatch,
24
 
        LockContention, LockError, UnlockableTransport,
25
 
        LockNotHeld, LockBroken
26
 
        )
 
33
    LockBreakMismatch,
 
34
    LockBroken,
 
35
    LockContention,
 
36
    LockError,
 
37
    LockFailed,
 
38
    LockNotHeld,
 
39
    )
27
40
from bzrlib.lockdir import LockDir
28
41
from bzrlib.tests import TestCaseWithTransport
 
42
from bzrlib.trace import note
29
43
 
30
44
# These tests sometimes use threads to test the behaviour of lock files with
31
45
# concurrent actors.  This is not a typical (or necessarily supported) use;
40
54
class TestLockDir(TestCaseWithTransport):
41
55
    """Test LockDir operations"""
42
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
 
43
64
    def test_00_lock_creation(self):
44
65
        """Creation of lock file on a transport"""
45
66
        t = self.get_transport()
56
77
        lf = LockDir(self.get_transport(), 'test_lock')
57
78
        self.assertEqual(lf.peek(), None)
58
79
 
 
80
    def get_lock(self):
 
81
        return LockDir(self.get_transport(), 'test_lock')
 
82
 
 
83
    def test_unlock_after_break_raises(self):
 
84
        ld = self.get_lock()
 
85
        ld2 = self.get_lock()
 
86
        ld.create()
 
87
        ld.attempt_lock()
 
88
        ld2.force_break(ld2.peek())
 
89
        self.assertRaises(LockBroken, ld.unlock)
 
90
 
59
91
    def test_03_readonly_peek(self):
60
92
        lf = LockDir(self.get_readonly_transport(), 'test_lock')
61
93
        self.assertEqual(lf.peek(), None)
76
108
        """Fail to create lock on readonly transport"""
77
109
        t = self.get_readonly_transport()
78
110
        lf = LockDir(t, 'test_lock')
79
 
        self.assertRaises(UnlockableTransport, lf.create)
 
111
        self.assertRaises(LockFailed, lf.create)
80
112
 
81
113
    def test_12_lock_readonly_transport(self):
82
114
        """Fail to lock on readonly transport"""
83
115
        lf = LockDir(self.get_transport(), 'test_lock')
84
116
        lf.create()
85
117
        lf = LockDir(self.get_readonly_transport(), 'test_lock')
86
 
        self.assertRaises(UnlockableTransport, lf.attempt_lock)
 
118
        self.assertRaises(LockFailed, lf.attempt_lock)
87
119
 
88
120
    def test_20_lock_contested(self):
89
121
        """Contention to get a lock"""
143
175
        lf1 = LockDir(t, 'test_lock')
144
176
        lf1.create()
145
177
        lf2 = LockDir(t, 'test_lock')
 
178
        self.setup_log_reporter(lf2)
146
179
        lf1.attempt_lock()
147
180
        try:
148
181
            before = time.time()
149
182
            self.assertRaises(LockContention, lf2.wait_lock,
150
183
                              timeout=0.4, poll=0.1)
151
184
            after = time.time()
152
 
            self.assertTrue(after - before <= 1.0)
 
185
            # it should only take about 0.4 seconds, but we allow more time in
 
186
            # case the machine is heavily loaded
 
187
            self.assertTrue(after - before <= 8.0, 
 
188
                    "took %f seconds to detect lock contention" % (after - before))
153
189
        finally:
154
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')
155
208
 
156
209
    def test_31_lock_wait_easy(self):
157
210
        """Succeed when waiting on a lock with no contention.
159
212
        t = self.get_transport()
160
213
        lf1 = LockDir(t, 'test_lock')
161
214
        lf1.create()
 
215
        self.setup_log_reporter(lf1)
162
216
        try:
163
217
            before = time.time()
164
218
            lf1.wait_lock(timeout=0.4, poll=0.1)
166
220
            self.assertTrue(after - before <= 1.0)
167
221
        finally:
168
222
            lf1.unlock()
 
223
        self.assertEqual([], self._logged_reports)
169
224
 
170
225
    def test_32_lock_wait_succeed(self):
171
226
        """Succeed when trying to acquire a lock that gets released
173
228
        One thread holds on a lock and then releases it; another 
174
229
        tries to lock it.
175
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")
176
241
        t = self.get_transport()
177
242
        lf1 = LockDir(t, 'test_lock')
178
243
        lf1.create()
185
250
        unlocker.start()
186
251
        try:
187
252
            lf2 = LockDir(t, 'test_lock')
 
253
            self.setup_log_reporter(lf2)
188
254
            before = time.time()
189
255
            # wait and then lock
190
256
            lf2.wait_lock(timeout=0.4, poll=0.1)
193
259
        finally:
194
260
            unlocker.join()
195
261
 
196
 
    def test_33_wait(self):
197
 
        """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')
198
277
 
199
 
        The difference from test_32_lock_wait_succeed is that the second 
200
 
        caller does not actually acquire the lock, but just waits for it
201
 
        to be released.  This is done over a readonly transport.
202
 
        """
 
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
203
284
        t = self.get_transport()
204
285
        lf1 = LockDir(t, 'test_lock')
205
286
        lf1.create()
211
292
        unlocker = Thread(target=wait_and_unlock)
212
293
        unlocker.start()
213
294
        try:
214
 
            lf2 = LockDir(self.get_readonly_transport(), 'test_lock')
 
295
            lf2 = LockDir(t, 'test_lock')
 
296
            self.setup_log_reporter(lf2)
215
297
            before = time.time()
216
 
            # wait but don't lock
217
 
            lf2.wait(timeout=0.4, poll=0.1)
 
298
            # wait and then lock
 
299
            lf2.lock_write()
218
300
            after = time.time()
219
 
            self.assertTrue(after - before <= 1.0)
220
 
        finally:
221
 
            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')
222
446
 
223
447
    def test_40_confirm_easy(self):
224
448
        """Confirm a lock that's already held"""
318
542
        self.assertTrue(t.has('test_lock/held/info'))
319
543
        lf1.unlock()
320
544
        self.assertFalse(t.has('test_lock/held/info'))
 
545
 
 
546
    def test_break_lock(self):
 
547
        # the ui based break_lock routine should Just Work (tm)
 
548
        ld1 = self.get_lock()
 
549
        ld2 = self.get_lock()
 
550
        ld1.create()
 
551
        ld1.lock_write()
 
552
        # do this without IO redirection to ensure it doesn't prompt.
 
553
        self.assertRaises(AssertionError, ld1.break_lock)
 
554
        orig_factory = bzrlib.ui.ui_factory
 
555
        # silent ui - no need for stdout
 
556
        bzrlib.ui.ui_factory = bzrlib.ui.SilentUIFactory()
 
557
        bzrlib.ui.ui_factory.stdin = StringIO("y\n")
 
558
        try:
 
559
            ld2.break_lock()
 
560
            self.assertRaises(LockBroken, ld1.unlock)
 
561
        finally:
 
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'])