~bzr-pqm/bzr/bzr.dev

« back to all changes in this revision

Viewing changes to bzrlib/tests/test_lockdir.py

  • Committer: Alexander Belchenko
  • Date: 2006-07-31 16:12:57 UTC
  • mto: (1711.2.111 jam-integration)
  • mto: This revision was merged to the branch mainline in revision 1906.
  • Revision ID: bialix@ukr.net-20060731161257-91a231523255332c
new official bzr.ico

Show diffs side-by-side

added added

removed removed

Lines of Context:
17
17
"""Tests for LockDir"""
18
18
 
19
19
from cStringIO import StringIO
20
 
import os
21
 
from threading import Thread, Lock
 
20
from threading import Thread
22
21
import time
23
22
 
24
23
import bzrlib
25
 
from bzrlib import (
26
 
    config,
27
 
    errors,
28
 
    osutils,
29
 
    tests,
30
 
    transport,
31
 
    )
32
24
from bzrlib.errors import (
33
25
        LockBreakMismatch,
34
26
        LockContention, LockError, UnlockableTransport,
36
28
        )
37
29
from bzrlib.lockdir import LockDir
38
30
from bzrlib.tests import TestCaseWithTransport
39
 
from bzrlib.trace import note
40
31
 
41
32
# These tests sometimes use threads to test the behaviour of lock files with
42
33
# concurrent actors.  This is not a typical (or necessarily supported) use;
51
42
class TestLockDir(TestCaseWithTransport):
52
43
    """Test LockDir operations"""
53
44
 
54
 
    def logging_report_function(self, fmt, *args):
55
 
        self._logged_reports.append((fmt, args))
56
 
 
57
 
    def setup_log_reporter(self, lock_dir):
58
 
        self._logged_reports = []
59
 
        lock_dir._report_function = self.logging_report_function
60
 
 
61
45
    def test_00_lock_creation(self):
62
46
        """Creation of lock file on a transport"""
63
47
        t = self.get_transport()
172
156
        lf1 = LockDir(t, 'test_lock')
173
157
        lf1.create()
174
158
        lf2 = LockDir(t, 'test_lock')
175
 
        self.setup_log_reporter(lf2)
176
159
        lf1.attempt_lock()
177
160
        try:
178
161
            before = time.time()
185
168
                    "took %f seconds to detect lock contention" % (after - before))
186
169
        finally:
187
170
            lf1.unlock()
188
 
        lock_base = lf2.transport.abspath(lf2.path)
189
 
        self.assertEqual(1, len(self._logged_reports))
190
 
        self.assertEqual('%s %s\n'
191
 
                         '%s\n%s\n'
192
 
                         'Will continue to try until %s\n',
193
 
                         self._logged_reports[0][0])
194
 
        args = self._logged_reports[0][1]
195
 
        self.assertEqual('Unable to obtain', args[0])
196
 
        self.assertEqual('lock %s' % (lock_base,), args[1])
197
 
        self.assertStartsWith(args[2], 'held by ')
198
 
        self.assertStartsWith(args[3], 'locked ')
199
 
        self.assertEndsWith(args[3], ' ago')
200
 
        self.assertContainsRe(args[4], r'\d\d:\d\d:\d\d')
201
171
 
202
172
    def test_31_lock_wait_easy(self):
203
173
        """Succeed when waiting on a lock with no contention.
205
175
        t = self.get_transport()
206
176
        lf1 = LockDir(t, 'test_lock')
207
177
        lf1.create()
208
 
        self.setup_log_reporter(lf1)
209
178
        try:
210
179
            before = time.time()
211
180
            lf1.wait_lock(timeout=0.4, poll=0.1)
213
182
            self.assertTrue(after - before <= 1.0)
214
183
        finally:
215
184
            lf1.unlock()
216
 
        self.assertEqual([], self._logged_reports)
217
185
 
218
186
    def test_32_lock_wait_succeed(self):
219
187
        """Succeed when trying to acquire a lock that gets released
221
189
        One thread holds on a lock and then releases it; another 
222
190
        tries to lock it.
223
191
        """
224
 
        # This test sometimes fails like this:
225
 
        # Traceback (most recent call last):
226
 
 
227
 
        #   File "/home/pqm/bzr-pqm-workdir/home/+trunk/bzrlib/tests/
228
 
        # test_lockdir.py", line 247, in test_32_lock_wait_succeed
229
 
        #     self.assertEqual(1, len(self._logged_reports))
230
 
        # AssertionError: not equal:
231
 
        # a = 1
232
 
        # b = 0
233
 
        raise tests.TestSkipped("Test fails intermittently")
234
192
        t = self.get_transport()
235
193
        lf1 = LockDir(t, 'test_lock')
236
194
        lf1.create()
243
201
        unlocker.start()
244
202
        try:
245
203
            lf2 = LockDir(t, 'test_lock')
246
 
            self.setup_log_reporter(lf2)
247
204
            before = time.time()
248
205
            # wait and then lock
249
206
            lf2.wait_lock(timeout=0.4, poll=0.1)
252
209
        finally:
253
210
            unlocker.join()
254
211
 
255
 
        # There should be only 1 report, even though it should have to
256
 
        # wait for a while
257
 
        lock_base = lf2.transport.abspath(lf2.path)
258
 
        self.assertEqual(1, len(self._logged_reports))
259
 
        self.assertEqual('%s %s\n'
260
 
                         '%s\n%s\n'
261
 
                         'Will continue to try until %s\n',
262
 
                         self._logged_reports[0][0])
263
 
        args = self._logged_reports[0][1]
264
 
        self.assertEqual('Unable to obtain', args[0])
265
 
        self.assertEqual('lock %s' % (lock_base,), args[1])
266
 
        self.assertStartsWith(args[2], 'held by ')
267
 
        self.assertStartsWith(args[3], 'locked ')
268
 
        self.assertEndsWith(args[3], ' ago')
269
 
        self.assertContainsRe(args[4], r'\d\d:\d\d:\d\d')
 
212
    def test_33_wait(self):
 
213
        """Succeed when waiting on a lock that gets released
270
214
 
271
 
    def test_34_lock_write_waits(self):
272
 
        """LockDir.lock_write() will wait for the lock.""" 
273
 
        # the test suite sets the default to 0 to make deadlocks fail fast.
274
 
        # change it for this test, as we want to try a manual deadlock.
275
 
        bzrlib.lockdir._DEFAULT_TIMEOUT_SECONDS = 300
 
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
        """
276
219
        t = self.get_transport()
277
220
        lf1 = LockDir(t, 'test_lock')
278
221
        lf1.create()
284
227
        unlocker = Thread(target=wait_and_unlock)
285
228
        unlocker.start()
286
229
        try:
287
 
            lf2 = LockDir(t, 'test_lock')
288
 
            self.setup_log_reporter(lf2)
 
230
            lf2 = LockDir(self.get_readonly_transport(), 'test_lock')
289
231
            before = time.time()
290
 
            # wait and then lock
291
 
            lf2.lock_write()
 
232
            # wait but don't lock
 
233
            lf2.wait(timeout=0.4, poll=0.1)
292
234
            after = time.time()
293
 
        finally:
294
 
            unlocker.join()
295
 
 
296
 
        # There should be only 1 report, even though it should have to
297
 
        # wait for a while
298
 
        lock_base = lf2.transport.abspath(lf2.path)
299
 
        self.assertEqual(1, len(self._logged_reports))
300
 
        self.assertEqual('%s %s\n'
301
 
                         '%s\n%s\n'
302
 
                         'Will continue to try until %s\n',
303
 
                         self._logged_reports[0][0])
304
 
        args = self._logged_reports[0][1]
305
 
        self.assertEqual('Unable to obtain', args[0])
306
 
        self.assertEqual('lock %s' % (lock_base,), args[1])
307
 
        self.assertStartsWith(args[2], 'held by ')
308
 
        self.assertStartsWith(args[3], 'locked ')
309
 
        self.assertEndsWith(args[3], ' ago')
310
 
        self.assertContainsRe(args[4], r'\d\d:\d\d:\d\d')
311
 
 
312
 
    def test_35_wait_lock_changing(self):
313
 
        """LockDir.wait_lock() will report if the lock changes underneath.
314
 
        
315
 
        This is the stages we want to happen:
316
 
 
317
 
        0) Synchronization locks are created and locked.
318
 
        1) Lock1 obtains the lockdir, and releases the 'check' lock.
319
 
        2) Lock2 grabs the 'check' lock, and checks the lockdir.
320
 
           It sees the lockdir is already acquired, reports the fact, 
321
 
           and unsets the 'checked' lock.
322
 
        3) Thread1 blocks on acquiring the 'checked' lock, and then tells
323
 
           Lock1 to release and acquire the lockdir. This resets the 'check'
324
 
           lock.
325
 
        4) Lock2 acquires the 'check' lock, and checks again. It notices
326
 
           that the holder of the lock has changed, and so reports a new 
327
 
           lock holder.
328
 
        5) Thread1 blocks on the 'checked' lock, this time, it completely
329
 
           unlocks the lockdir, allowing Lock2 to acquire the lock.
330
 
        """
331
 
 
332
 
        wait_to_check_lock = Lock()
333
 
        wait_until_checked_lock = Lock()
334
 
 
335
 
        wait_to_check_lock.acquire()
336
 
        wait_until_checked_lock.acquire()
337
 
        note('locked check and checked locks')
338
 
 
339
 
        class LockDir1(LockDir):
340
 
            """Use the synchronization points for the first lock."""
341
 
 
342
 
            def attempt_lock(self):
343
 
                # Once we have acquired the lock, it is okay for
344
 
                # the other lock to check it
345
 
                try:
346
 
                    return super(LockDir1, self).attempt_lock()
347
 
                finally:
348
 
                    note('lock1: releasing check lock')
349
 
                    wait_to_check_lock.release()
350
 
 
351
 
        class LockDir2(LockDir):
352
 
            """Use the synchronization points for the second lock."""
353
 
 
354
 
            def attempt_lock(self):
355
 
                note('lock2: waiting for check lock')
356
 
                wait_to_check_lock.acquire()
357
 
                note('lock2: acquired check lock')
358
 
                try:
359
 
                    return super(LockDir2, self).attempt_lock()
360
 
                finally:
361
 
                    note('lock2: releasing checked lock')
362
 
                    wait_until_checked_lock.release()
363
 
 
364
 
        t = self.get_transport()
365
 
        lf1 = LockDir1(t, 'test_lock')
366
 
        lf1.create()
367
 
 
368
 
        lf2 = LockDir2(t, 'test_lock')
369
 
        self.setup_log_reporter(lf2)
370
 
 
371
 
        def wait_and_switch():
372
 
            lf1.attempt_lock()
373
 
            # Block until lock2 has had a chance to check
374
 
            note('lock1: waiting 1 for checked lock')
375
 
            wait_until_checked_lock.acquire()
376
 
            note('lock1: acquired for checked lock')
377
 
            note('lock1: released lockdir')
378
 
            lf1.unlock()
379
 
            note('lock1: acquiring lockdir')
380
 
            # Create a new nonce, so the lock looks different.
381
 
            lf1.nonce = osutils.rand_chars(20)
382
 
            lf1.lock_write()
383
 
            note('lock1: acquired lockdir')
384
 
 
385
 
            # Block until lock2 has peeked again
386
 
            note('lock1: waiting 2 for checked lock')
387
 
            wait_until_checked_lock.acquire()
388
 
            note('lock1: acquired for checked lock')
389
 
            # Now unlock, and let lock 2 grab the lock
390
 
            lf1.unlock()
391
 
            wait_to_check_lock.release()
392
 
 
393
 
        unlocker = Thread(target=wait_and_switch)
394
 
        unlocker.start()
395
 
        try:
396
 
            # Wait and play against the other thread
397
 
            lf2.wait_lock(timeout=1.0, poll=0.01)
398
 
        finally:
399
 
            unlocker.join()
400
 
        lf2.unlock()
401
 
 
402
 
        # There should be 2 reports, because the lock changed
403
 
        lock_base = lf2.transport.abspath(lf2.path)
404
 
        self.assertEqual(2, len(self._logged_reports))
405
 
 
406
 
        self.assertEqual('%s %s\n'
407
 
                         '%s\n%s\n'
408
 
                         'Will continue to try until %s\n',
409
 
                         self._logged_reports[0][0])
410
 
        args = self._logged_reports[0][1]
411
 
        self.assertEqual('Unable to obtain', args[0])
412
 
        self.assertEqual('lock %s' % (lock_base,), args[1])
413
 
        self.assertStartsWith(args[2], 'held by ')
414
 
        self.assertStartsWith(args[3], 'locked ')
415
 
        self.assertEndsWith(args[3], ' ago')
416
 
        self.assertContainsRe(args[4], r'\d\d:\d\d:\d\d')
417
 
 
418
 
        self.assertEqual('%s %s\n'
419
 
                         '%s\n%s\n'
420
 
                         'Will continue to try until %s\n',
421
 
                         self._logged_reports[1][0])
422
 
        args = self._logged_reports[1][1]
423
 
        self.assertEqual('Lock owner changed for', args[0])
424
 
        self.assertEqual('lock %s' % (lock_base,), args[1])
425
 
        self.assertStartsWith(args[2], 'held by ')
426
 
        self.assertStartsWith(args[3], 'locked ')
427
 
        self.assertEndsWith(args[3], ' ago')
428
 
        self.assertContainsRe(args[4], r'\d\d:\d\d:\d\d')
 
235
            self.assertTrue(after - before <= 1.0)
 
236
        finally:
 
237
            unlocker.join()
429
238
 
430
239
    def test_40_confirm_easy(self):
431
240
        """Confirm a lock that's already held"""
543
352
            self.assertRaises(LockBroken, ld1.unlock)
544
353
        finally:
545
354
            bzrlib.ui.ui_factory = orig_factory
546
 
 
547
 
    def test_create_missing_base_directory(self):
548
 
        """If LockDir.path doesn't exist, it can be created
549
 
 
550
 
        Some people manually remove the entire lock/ directory trying
551
 
        to unlock a stuck repository/branch/etc. Rather than failing
552
 
        after that, just create the lock directory when needed.
553
 
        """
554
 
        t = self.get_transport()
555
 
        lf1 = LockDir(t, 'test_lock')
556
 
 
557
 
        lf1.create()
558
 
        self.failUnless(t.has('test_lock'))
559
 
 
560
 
        t.rmdir('test_lock')
561
 
        self.failIf(t.has('test_lock'))
562
 
 
563
 
        # This will create 'test_lock' if it needs to
564
 
        lf1.lock_write()
565
 
        self.failUnless(t.has('test_lock'))
566
 
        self.failUnless(t.has('test_lock/held/info'))
567
 
 
568
 
        lf1.unlock()
569
 
        self.failIf(t.has('test_lock/held/info'))
570
 
 
571
 
    def test__format_lock_info(self):
572
 
        ld1 = self.get_lock()
573
 
        ld1.create()
574
 
        ld1.lock_write()
575
 
        try:
576
 
            info_list = ld1._format_lock_info(ld1.peek())
577
 
        finally:
578
 
            ld1.unlock()
579
 
        self.assertEqual('lock %s' % (ld1.transport.abspath(ld1.path),),
580
 
                         info_list[0])
581
 
        self.assertContainsRe(info_list[1],
582
 
                              r'^held by .* on host .* \[process #\d*\]$')
583
 
        self.assertContainsRe(info_list[2], r'locked \d+ seconds? ago$')
584
 
 
585
 
    def test_lock_without_email(self):
586
 
        global_config = config.GlobalConfig()
587
 
        # Intentionally has no email address
588
 
        global_config.set_user_option('email', 'User Identity')
589
 
        ld1 = self.get_lock()
590
 
        ld1.create()
591
 
        ld1.lock_write()
592
 
        ld1.unlock()
593
 
 
594
 
    def test_lock_permission(self):
595
 
        if not osutils.supports_posix_readonly():
596
 
            raise tests.TestSkipped('Cannot induce a permission failure')
597
 
        ld1 = self.get_lock()
598
 
        lock_path = ld1.transport.local_abspath('test_lock')
599
 
        os.mkdir(lock_path)
600
 
        osutils.make_readonly(lock_path)
601
 
        self.assertRaises(errors.PermissionDenied, ld1.attempt_lock)
602
 
 
603
 
    def test_lock_by_token(self):
604
 
        ld1 = self.get_lock()
605
 
        token = ld1.lock_write()
606
 
        self.assertNotEqual(None, token)
607
 
        ld2 = self.get_lock()
608
 
        t2 = ld2.lock_write(token)
609
 
        self.assertEqual(token, t2)
610
 
 
611
 
    def test_lock_with_buggy_rename(self):
612
 
        # test that lock acquisition handles servers which pretend they
613
 
        # renamed correctly but that actually fail
614
 
        t = transport.get_transport('brokenrename+' + self.get_url())
615
 
        ld1 = LockDir(t, 'test_lock')
616
 
        ld1.create()
617
 
        ld1.attempt_lock()
618
 
        ld2 = LockDir(t, 'test_lock')
619
 
        # we should fail to lock
620
 
        e = self.assertRaises(errors.LockContention, ld2.attempt_lock)
621
 
        # now the original caller should succeed in unlocking
622
 
        ld1.unlock()
623
 
        # and there should be nothing left over
624
 
        self.assertEquals([], t.list_dir('test_lock'))
625
 
 
626
 
    def test_failed_lock_leaves_no_trash(self):
627
 
        # if we fail to acquire the lock, we don't leave pending directories
628
 
        # behind -- https://bugs.launchpad.net/bzr/+bug/109169
629
 
        ld1 = self.get_lock()
630
 
        ld2 = self.get_lock()
631
 
        # should be nothing before we start
632
 
        ld1.create()
633
 
        t = self.get_transport().clone('test_lock')
634
 
        def check_dir(a):
635
 
            self.assertEquals(a, t.list_dir('.'))
636
 
        check_dir([])
637
 
        # when held, that's all we see
638
 
        ld1.attempt_lock()
639
 
        check_dir(['held'])
640
 
        # second guy should fail
641
 
        self.assertRaises(errors.LockContention, ld2.attempt_lock)
642
 
        # no kibble
643
 
        check_dir(['held'])