~bzr-pqm/bzr/bzr.dev

« back to all changes in this revision

Viewing changes to bzrlib/tests/test_lockdir.py

Merge bzr.dev

Show diffs side-by-side

added added

removed removed

Lines of Context:
1
1
# Copyright (C) 2006 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
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
    )
24
31
from bzrlib.errors import (
25
32
        LockBreakMismatch,
26
33
        LockContention, LockError, UnlockableTransport,
27
34
        LockNotHeld, LockBroken
28
35
        )
29
 
from bzrlib.lockdir import LockDir
 
36
from bzrlib.lockdir import LockDir, _DEFAULT_TIMEOUT_SECONDS
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
        t = self.get_transport()
 
290
        lf1 = LockDir(t, 'test_lock')
 
291
        lf1.create()
 
292
        lf1.attempt_lock()
 
293
 
 
294
        def wait_and_unlock():
 
295
            time.sleep(0.1)
 
296
            lf1.unlock()
 
297
        unlocker = Thread(target=wait_and_unlock)
 
298
        unlocker.start()
 
299
        try:
 
300
            lf2 = LockDir(t, 'test_lock')
 
301
            self.setup_log_reporter(lf2)
 
302
            before = time.time()
 
303
            # wait and then lock
 
304
            lf2.lock_write()
 
305
            after = time.time()
 
306
        finally:
 
307
            unlocker.join()
 
308
 
 
309
        # There should be only 1 report, even though it should have to
 
310
        # wait for a while
 
311
        lock_base = lf2.transport.abspath(lf2.path)
 
312
        self.assertEqual(1, len(self._logged_reports))
 
313
        self.assertEqual('%s %s\n'
 
314
                         '%s\n%s\n'
 
315
                         'Will continue to try until %s\n',
 
316
                         self._logged_reports[0][0])
 
317
        args = self._logged_reports[0][1]
 
318
        self.assertEqual('Unable to obtain', args[0])
 
319
        self.assertEqual('lock %s' % (lock_base,), args[1])
 
320
        self.assertStartsWith(args[2], 'held by ')
 
321
        self.assertStartsWith(args[3], 'locked ')
 
322
        self.assertEndsWith(args[3], ' ago')
 
323
        self.assertContainsRe(args[4], r'\d\d:\d\d:\d\d')
 
324
 
 
325
    def test_35_wait_lock_changing(self):
 
326
        """LockDir.wait_lock() will report if the lock changes underneath.
 
327
        
 
328
        This is the stages we want to happen:
 
329
 
 
330
        0) Synchronization locks are created and locked.
 
331
        1) Lock1 obtains the lockdir, and releases the 'check' lock.
 
332
        2) Lock2 grabs the 'check' lock, and checks the lockdir.
 
333
           It sees the lockdir is already acquired, reports the fact, 
 
334
           and unsets the 'checked' lock.
 
335
        3) Thread1 blocks on acquiring the 'checked' lock, and then tells
 
336
           Lock1 to release and acquire the lockdir. This resets the 'check'
 
337
           lock.
 
338
        4) Lock2 acquires the 'check' lock, and checks again. It notices
 
339
           that the holder of the lock has changed, and so reports a new 
 
340
           lock holder.
 
341
        5) Thread1 blocks on the 'checked' lock, this time, it completely
 
342
           unlocks the lockdir, allowing Lock2 to acquire the lock.
 
343
        """
 
344
 
 
345
        wait_to_check_lock = Lock()
 
346
        wait_until_checked_lock = Lock()
 
347
 
 
348
        wait_to_check_lock.acquire()
 
349
        wait_until_checked_lock.acquire()
 
350
        note('locked check and checked locks')
 
351
 
 
352
        class LockDir1(LockDir):
 
353
            """Use the synchronization points for the first lock."""
 
354
 
 
355
            def attempt_lock(self):
 
356
                # Once we have acquired the lock, it is okay for
 
357
                # the other lock to check it
 
358
                try:
 
359
                    return super(LockDir1, self).attempt_lock()
 
360
                finally:
 
361
                    note('lock1: releasing check lock')
 
362
                    wait_to_check_lock.release()
 
363
 
 
364
        class LockDir2(LockDir):
 
365
            """Use the synchronization points for the second lock."""
 
366
 
 
367
            def attempt_lock(self):
 
368
                note('lock2: waiting for check lock')
 
369
                wait_to_check_lock.acquire()
 
370
                note('lock2: acquired check lock')
 
371
                try:
 
372
                    return super(LockDir2, self).attempt_lock()
 
373
                finally:
 
374
                    note('lock2: releasing checked lock')
 
375
                    wait_until_checked_lock.release()
 
376
 
 
377
        t = self.get_transport()
 
378
        lf1 = LockDir1(t, 'test_lock')
 
379
        lf1.create()
 
380
 
 
381
        lf2 = LockDir2(t, 'test_lock')
 
382
        self.setup_log_reporter(lf2)
 
383
 
 
384
        def wait_and_switch():
 
385
            lf1.attempt_lock()
 
386
            # Block until lock2 has had a chance to check
 
387
            note('lock1: waiting 1 for checked lock')
 
388
            wait_until_checked_lock.acquire()
 
389
            note('lock1: acquired for checked lock')
 
390
            note('lock1: released lockdir')
 
391
            lf1.unlock()
 
392
            note('lock1: acquiring lockdir')
 
393
            # Create a new nonce, so the lock looks different.
 
394
            lf1.nonce = osutils.rand_chars(20)
 
395
            lf1.lock_write()
 
396
            note('lock1: acquired lockdir')
 
397
 
 
398
            # Block until lock2 has peeked again
 
399
            note('lock1: waiting 2 for checked lock')
 
400
            wait_until_checked_lock.acquire()
 
401
            note('lock1: acquired for checked lock')
 
402
            # Now unlock, and let lock 2 grab the lock
 
403
            lf1.unlock()
 
404
            wait_to_check_lock.release()
 
405
 
 
406
        unlocker = Thread(target=wait_and_switch)
 
407
        unlocker.start()
 
408
        try:
 
409
            # Wait and play against the other thread
 
410
            lf2.wait_lock(timeout=1.0, poll=0.01)
 
411
        finally:
 
412
            unlocker.join()
 
413
        lf2.unlock()
 
414
 
 
415
        # There should be 2 reports, because the lock changed
 
416
        lock_base = lf2.transport.abspath(lf2.path)
 
417
        self.assertEqual(2, len(self._logged_reports))
 
418
 
 
419
        self.assertEqual('%s %s\n'
 
420
                         '%s\n%s\n'
 
421
                         'Will continue to try until %s\n',
 
422
                         self._logged_reports[0][0])
 
423
        args = self._logged_reports[0][1]
 
424
        self.assertEqual('Unable to obtain', args[0])
 
425
        self.assertEqual('lock %s' % (lock_base,), args[1])
 
426
        self.assertStartsWith(args[2], 'held by ')
 
427
        self.assertStartsWith(args[3], 'locked ')
 
428
        self.assertEndsWith(args[3], ' ago')
 
429
        self.assertContainsRe(args[4], r'\d\d:\d\d:\d\d')
 
430
 
 
431
        self.assertEqual('%s %s\n'
 
432
                         '%s\n%s\n'
 
433
                         'Will continue to try until %s\n',
 
434
                         self._logged_reports[1][0])
 
435
        args = self._logged_reports[1][1]
 
436
        self.assertEqual('Lock owner changed for', args[0])
 
437
        self.assertEqual('lock %s' % (lock_base,), args[1])
 
438
        self.assertStartsWith(args[2], 'held by ')
 
439
        self.assertStartsWith(args[3], 'locked ')
 
440
        self.assertEndsWith(args[3], ' ago')
 
441
        self.assertContainsRe(args[4], r'\d\d:\d\d:\d\d')
 
442
 
239
443
    def test_40_confirm_easy(self):
240
444
        """Confirm a lock that's already held"""
241
445
        t = self.get_transport()
352
556
            self.assertRaises(LockBroken, ld1.unlock)
353
557
        finally:
354
558
            bzrlib.ui.ui_factory = orig_factory
 
559
 
 
560
    def test_create_missing_base_directory(self):
 
561
        """If LockDir.path doesn't exist, it can be created
 
562
 
 
563
        Some people manually remove the entire lock/ directory trying
 
564
        to unlock a stuck repository/branch/etc. Rather than failing
 
565
        after that, just create the lock directory when needed.
 
566
        """
 
567
        t = self.get_transport()
 
568
        lf1 = LockDir(t, 'test_lock')
 
569
 
 
570
        lf1.create()
 
571
        self.failUnless(t.has('test_lock'))
 
572
 
 
573
        t.rmdir('test_lock')
 
574
        self.failIf(t.has('test_lock'))
 
575
 
 
576
        # This will create 'test_lock' if it needs to
 
577
        lf1.lock_write()
 
578
        self.failUnless(t.has('test_lock'))
 
579
        self.failUnless(t.has('test_lock/held/info'))
 
580
 
 
581
        lf1.unlock()
 
582
        self.failIf(t.has('test_lock/held/info'))
 
583
 
 
584
    def test__format_lock_info(self):
 
585
        ld1 = self.get_lock()
 
586
        ld1.create()
 
587
        ld1.lock_write()
 
588
        try:
 
589
            info_list = ld1._format_lock_info(ld1.peek())
 
590
        finally:
 
591
            ld1.unlock()
 
592
        self.assertEqual('lock %s' % (ld1.transport.abspath(ld1.path),),
 
593
                         info_list[0])
 
594
        self.assertContainsRe(info_list[1],
 
595
                              r'^held by .* on host .* \[process #\d*\]$')
 
596
        self.assertContainsRe(info_list[2], r'locked \d+ seconds? ago$')
 
597
 
 
598
    def test_lock_without_email(self):
 
599
        global_config = config.GlobalConfig()
 
600
        # Intentionally has no email address
 
601
        global_config.set_user_option('email', 'User Identity')
 
602
        ld1 = self.get_lock()
 
603
        ld1.create()
 
604
        ld1.lock_write()
 
605
        ld1.unlock()
 
606
 
 
607
    def test_lock_permission(self):
 
608
        if not osutils.supports_posix_readonly():
 
609
            raise tests.TestSkipped('Cannot induce a permission failure')
 
610
        ld1 = self.get_lock()
 
611
        lock_path = ld1.transport.local_abspath('test_lock')
 
612
        os.mkdir(lock_path)
 
613
        osutils.make_readonly(lock_path)
 
614
        self.assertRaises(errors.PermissionDenied, ld1.attempt_lock)