← 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-06-12 02:17:42 UTC
  • mfrom: (2521.1.1 56322)
  • Revision ID: pqm@pqm.ubuntu.com-20070612021742-uetsy3g747iq3xkk
merge init --create-prefix

Show diffs side-by-side

added added

removed removed

Lines of Context:
bzrlib/tests/test_lockdir.py
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
    )
24
31
from bzrlib.errors import (
25
32
        LockBreakMismatch,
26
33
        LockContention, LockError, UnlockableTransport,
28
35
        )
29
36
from bzrlib.lockdir import LockDir
30
37
from bzrlib.tests import TestCaseWithTransport
 
38
from bzrlib.trace import note
31
39
 
32
40
# These tests sometimes use threads to test the behaviour of lock files with
33
41
# concurrent actors.  This is not a typical (or necessarily supported) use;
42
50
class TestLockDir(TestCaseWithTransport):
43
51
    """Test LockDir operations"""
44
52
 
 
53
    def logging_report_function(self, fmt, *args):
 
54
        self._logged_reports.append((fmt, args))
 
55
 
 
56
    def setup_log_reporter(self, lock_dir):
 
57
        self._logged_reports = []
 
58
        lock_dir._report_function = self.logging_report_function
 
59
 
45
60
    def test_00_lock_creation(self):
46
61
        """Creation of lock file on a transport"""
47
62
        t = self.get_transport()
156
171
        lf1 = LockDir(t, 'test_lock')
157
172
        lf1.create()
158
173
        lf2 = LockDir(t, 'test_lock')
 
174
        self.setup_log_reporter(lf2)
159
175
        lf1.attempt_lock()
160
176
        try:
161
177
            before = time.time()
168
184
                    "took %f seconds to detect lock contention" % (after - before))
169
185
        finally:
170
186
            lf1.unlock()
 
187
        lock_base = lf2.transport.abspath(lf2.path)
 
188
        self.assertEqual(1, len(self._logged_reports))
 
189
        self.assertEqual('%s %s\n'
 
190
                         '%s\n%s\n'
 
191
                         'Will continue to try until %s\n',
 
192
                         self._logged_reports[0][0])
 
193
        args = self._logged_reports[0][1]
 
194
        self.assertEqual('Unable to obtain', args[0])
 
195
        self.assertEqual('lock %s' % (lock_base,), args[1])
 
196
        self.assertStartsWith(args[2], 'held by ')
 
197
        self.assertStartsWith(args[3], 'locked ')
 
198
        self.assertEndsWith(args[3], ' ago')
 
199
        self.assertContainsRe(args[4], r'\d\d:\d\d:\d\d')
171
200
 
172
201
    def test_31_lock_wait_easy(self):
173
202
        """Succeed when waiting on a lock with no contention.
175
204
        t = self.get_transport()
176
205
        lf1 = LockDir(t, 'test_lock')
177
206
        lf1.create()
 
207
        self.setup_log_reporter(lf1)
178
208
        try:
179
209
            before = time.time()
180
210
            lf1.wait_lock(timeout=0.4, poll=0.1)
182
212
            self.assertTrue(after - before <= 1.0)
183
213
        finally:
184
214
            lf1.unlock()
 
215
        self.assertEqual([], self._logged_reports)
185
216
 
186
217
    def test_32_lock_wait_succeed(self):
187
218
        """Succeed when trying to acquire a lock that gets released
201
232
        unlocker.start()
202
233
        try:
203
234
            lf2 = LockDir(t, 'test_lock')
 
235
            self.setup_log_reporter(lf2)
204
236
            before = time.time()
205
237
            # wait and then lock
206
238
            lf2.wait_lock(timeout=0.4, poll=0.1)
209
241
        finally:
210
242
            unlocker.join()
211
243
 
 
244
        # There should be only 1 report, even though it should have to
 
245
        # wait for a while
 
246
        lock_base = lf2.transport.abspath(lf2.path)
 
247
        self.assertEqual(1, len(self._logged_reports))
 
248
        self.assertEqual('%s %s\n'
 
249
                         '%s\n%s\n'
 
250
                         'Will continue to try until %s\n',
 
251
                         self._logged_reports[0][0])
 
252
        args = self._logged_reports[0][1]
 
253
        self.assertEqual('Unable to obtain', args[0])
 
254
        self.assertEqual('lock %s' % (lock_base,), args[1])
 
255
        self.assertStartsWith(args[2], 'held by ')
 
256
        self.assertStartsWith(args[3], 'locked ')
 
257
        self.assertEndsWith(args[3], ' ago')
 
258
        self.assertContainsRe(args[4], r'\d\d:\d\d:\d\d')
 
259
 
212
260
    def test_33_wait(self):
213
261
        """Succeed when waiting on a lock that gets released
214
262
 
236
284
        finally:
237
285
            unlocker.join()
238
286
 
 
287
    def test_34_lock_write_waits(self):
 
288
        """LockDir.lock_write() will wait for the lock.""" 
 
289
        # the test suite sets the default to 0 to make deadlocks fail fast.
 
290
        # change it for this test, as we want to try a manual deadlock.
 
291
        bzrlib.lockdir._DEFAULT_TIMEOUT_SECONDS = 300
 
292
        t = self.get_transport()
 
293
        lf1 = LockDir(t, 'test_lock')
 
294
        lf1.create()
 
295
        lf1.attempt_lock()
 
296
 
 
297
        def wait_and_unlock():
 
298
            time.sleep(0.1)
 
299
            lf1.unlock()
 
300
        unlocker = Thread(target=wait_and_unlock)
 
301
        unlocker.start()
 
302
        try:
 
303
            lf2 = LockDir(t, 'test_lock')
 
304
            self.setup_log_reporter(lf2)
 
305
            before = time.time()
 
306
            # wait and then lock
 
307
            lf2.lock_write()
 
308
            after = time.time()
 
309
        finally:
 
310
            unlocker.join()
 
311
 
 
312
        # There should be only 1 report, even though it should have to
 
313
        # wait for a while
 
314
        lock_base = lf2.transport.abspath(lf2.path)
 
315
        self.assertEqual(1, len(self._logged_reports))
 
316
        self.assertEqual('%s %s\n'
 
317
                         '%s\n%s\n'
 
318
                         'Will continue to try until %s\n',
 
319
                         self._logged_reports[0][0])
 
320
        args = self._logged_reports[0][1]
 
321
        self.assertEqual('Unable to obtain', args[0])
 
322
        self.assertEqual('lock %s' % (lock_base,), args[1])
 
323
        self.assertStartsWith(args[2], 'held by ')
 
324
        self.assertStartsWith(args[3], 'locked ')
 
325
        self.assertEndsWith(args[3], ' ago')
 
326
        self.assertContainsRe(args[4], r'\d\d:\d\d:\d\d')
 
327
 
 
328
    def test_35_wait_lock_changing(self):
 
329
        """LockDir.wait_lock() will report if the lock changes underneath.
 
330
        
 
331
        This is the stages we want to happen:
 
332
 
 
333
        0) Synchronization locks are created and locked.
 
334
        1) Lock1 obtains the lockdir, and releases the 'check' lock.
 
335
        2) Lock2 grabs the 'check' lock, and checks the lockdir.
 
336
           It sees the lockdir is already acquired, reports the fact, 
 
337
           and unsets the 'checked' lock.
 
338
        3) Thread1 blocks on acquiring the 'checked' lock, and then tells
 
339
           Lock1 to release and acquire the lockdir. This resets the 'check'
 
340
           lock.
 
341
        4) Lock2 acquires the 'check' lock, and checks again. It notices
 
342
           that the holder of the lock has changed, and so reports a new 
 
343
           lock holder.
 
344
        5) Thread1 blocks on the 'checked' lock, this time, it completely
 
345
           unlocks the lockdir, allowing Lock2 to acquire the lock.
 
346
        """
 
347
 
 
348
        wait_to_check_lock = Lock()
 
349
        wait_until_checked_lock = Lock()
 
350
 
 
351
        wait_to_check_lock.acquire()
 
352
        wait_until_checked_lock.acquire()
 
353
        note('locked check and checked locks')
 
354
 
 
355
        class LockDir1(LockDir):
 
356
            """Use the synchronization points for the first lock."""
 
357
 
 
358
            def attempt_lock(self):
 
359
                # Once we have acquired the lock, it is okay for
 
360
                # the other lock to check it
 
361
                try:
 
362
                    return super(LockDir1, self).attempt_lock()
 
363
                finally:
 
364
                    note('lock1: releasing check lock')
 
365
                    wait_to_check_lock.release()
 
366
 
 
367
        class LockDir2(LockDir):
 
368
            """Use the synchronization points for the second lock."""
 
369
 
 
370
            def attempt_lock(self):
 
371
                note('lock2: waiting for check lock')
 
372
                wait_to_check_lock.acquire()
 
373
                note('lock2: acquired check lock')
 
374
                try:
 
375
                    return super(LockDir2, self).attempt_lock()
 
376
                finally:
 
377
                    note('lock2: releasing checked lock')
 
378
                    wait_until_checked_lock.release()
 
379
 
 
380
        t = self.get_transport()
 
381
        lf1 = LockDir1(t, 'test_lock')
 
382
        lf1.create()
 
383
 
 
384
        lf2 = LockDir2(t, 'test_lock')
 
385
        self.setup_log_reporter(lf2)
 
386
 
 
387
        def wait_and_switch():
 
388
            lf1.attempt_lock()
 
389
            # Block until lock2 has had a chance to check
 
390
            note('lock1: waiting 1 for checked lock')
 
391
            wait_until_checked_lock.acquire()
 
392
            note('lock1: acquired for checked lock')
 
393
            note('lock1: released lockdir')
 
394
            lf1.unlock()
 
395
            note('lock1: acquiring lockdir')
 
396
            # Create a new nonce, so the lock looks different.
 
397
            lf1.nonce = osutils.rand_chars(20)
 
398
            lf1.lock_write()
 
399
            note('lock1: acquired lockdir')
 
400
 
 
401
            # Block until lock2 has peeked again
 
402
            note('lock1: waiting 2 for checked lock')
 
403
            wait_until_checked_lock.acquire()
 
404
            note('lock1: acquired for checked lock')
 
405
            # Now unlock, and let lock 2 grab the lock
 
406
            lf1.unlock()
 
407
            wait_to_check_lock.release()
 
408
 
 
409
        unlocker = Thread(target=wait_and_switch)
 
410
        unlocker.start()
 
411
        try:
 
412
            # Wait and play against the other thread
 
413
            lf2.wait_lock(timeout=1.0, poll=0.01)
 
414
        finally:
 
415
            unlocker.join()
 
416
        lf2.unlock()
 
417
 
 
418
        # There should be 2 reports, because the lock changed
 
419
        lock_base = lf2.transport.abspath(lf2.path)
 
420
        self.assertEqual(2, len(self._logged_reports))
 
421
 
 
422
        self.assertEqual('%s %s\n'
 
423
                         '%s\n%s\n'
 
424
                         'Will continue to try until %s\n',
 
425
                         self._logged_reports[0][0])
 
426
        args = self._logged_reports[0][1]
 
427
        self.assertEqual('Unable to obtain', 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')
 
433
 
 
434
        self.assertEqual('%s %s\n'
 
435
                         '%s\n%s\n'
 
436
                         'Will continue to try until %s\n',
 
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
 
239
446
    def test_40_confirm_easy(self):
240
447
        """Confirm a lock that's already held"""
241
448
        t = self.get_transport()
376
583
 
377
584
        lf1.unlock()
378
585
        self.failIf(t.has('test_lock/held/info'))
 
586
 
 
587
    def test__format_lock_info(self):
 
588
        ld1 = self.get_lock()
 
589
        ld1.create()
 
590
        ld1.lock_write()
 
591
        try:
 
592
            info_list = ld1._format_lock_info(ld1.peek())
 
593
        finally:
 
594
            ld1.unlock()
 
595
        self.assertEqual('lock %s' % (ld1.transport.abspath(ld1.path),),
 
596
                         info_list[0])
 
597
        self.assertContainsRe(info_list[1],
 
598
                              r'^held by .* on host .* \[process #\d*\]$')
 
599
        self.assertContainsRe(info_list[2], r'locked \d+ seconds? ago$')
 
600
 
 
601
    def test_lock_without_email(self):
 
602
        global_config = config.GlobalConfig()
 
603
        # Intentionally has no email address
 
604
        global_config.set_user_option('email', 'User Identity')
 
605
        ld1 = self.get_lock()
 
606
        ld1.create()
 
607
        ld1.lock_write()
 
608
        ld1.unlock()
 
609
 
 
610
    def test_lock_permission(self):
 
611
        if not osutils.supports_posix_readonly():
 
612
            raise tests.TestSkipped('Cannot induce a permission failure')
 
613
        ld1 = self.get_lock()
 
614
        lock_path = ld1.transport.local_abspath('test_lock')
 
615
        os.mkdir(lock_path)
 
616
        osutils.make_readonly(lock_path)
 
617
        self.assertRaises(errors.PermissionDenied, ld1.attempt_lock)