185
188
after = time.time()
186
189
# it should only take about 0.4 seconds, but we allow more time in
187
190
# case the machine is heavily loaded
188
self.assertTrue(after - before <= 8.0,
189
"took %f seconds to detect lock contention" % (after - before))
191
self.assertTrue(after - before <= 8.0,
192
"took %f seconds to detect lock contention" % (after - before))
192
lock_base = lf2.transport.abspath(lf2.path)
193
195
self.assertEqual(1, len(self._logged_reports))
194
lock_url = lf2.transport.abspath(lf2.path)
195
self.assertEqual('%s %s\n'
197
'Will continue to try until %s, unless '
199
'If you\'re sure that it\'s not being '
200
'modified, use bzr break-lock %s',
201
self._logged_reports[0][0])
202
args = self._logged_reports[0][1]
203
self.assertEqual('Unable to obtain', args[0])
204
self.assertEqual('lock %s' % (lock_base,), args[1])
205
self.assertStartsWith(args[2], 'held by ')
206
self.assertStartsWith(args[3], 'locked ')
207
self.assertEndsWith(args[3], ' ago')
208
self.assertContainsRe(args[4], r'\d\d:\d\d:\d\d')
196
self.assertContainsRe(self._logged_reports[0][0],
197
r'Unable to obtain lock .* held by jrandom@example\.com on .*'
198
r' \(process #\d+\), acquired .* ago\.\n'
199
r'Will continue to try until \d{2}:\d{2}:\d{2}, unless '
200
r'you press Ctrl-C.\n'
201
r'See "bzr help break-lock" for more.')
210
203
def test_31_lock_wait_easy(self):
211
204
"""Succeed when waiting on a lock with no contention.
224
217
self.assertEqual([], self._logged_reports)
226
def test_32_lock_wait_succeed(self):
227
"""Succeed when trying to acquire a lock that gets released
229
One thread holds on a lock and then releases it; another
232
# This test sometimes fails like this:
233
# Traceback (most recent call last):
235
# File "/home/pqm/bzr-pqm-workdir/home/+trunk/bzrlib/tests/
236
# test_lockdir.py", line 247, in test_32_lock_wait_succeed
237
# self.assertEqual(1, len(self._logged_reports))
238
# AssertionError: not equal:
241
raise tests.TestSkipped("Test fails intermittently")
242
t = self.get_transport()
243
lf1 = LockDir(t, 'test_lock')
247
def wait_and_unlock():
250
unlocker = Thread(target=wait_and_unlock)
253
lf2 = LockDir(t, 'test_lock')
254
self.setup_log_reporter(lf2)
257
lf2.wait_lock(timeout=0.4, poll=0.1)
259
self.assertTrue(after - before <= 1.0)
263
# There should be only 1 report, even though it should have to
265
lock_base = lf2.transport.abspath(lf2.path)
266
self.assertEqual(1, len(self._logged_reports))
267
self.assertEqual('%s %s\n'
269
'Will continue to try until %s\n',
270
self._logged_reports[0][0])
271
args = self._logged_reports[0][1]
272
self.assertEqual('Unable to obtain', args[0])
273
self.assertEqual('lock %s' % (lock_base,), args[1])
274
self.assertStartsWith(args[2], 'held by ')
275
self.assertStartsWith(args[3], 'locked ')
276
self.assertEndsWith(args[3], ' ago')
277
self.assertContainsRe(args[4], r'\d\d:\d\d:\d\d')
279
def test_34_lock_write_waits(self):
280
"""LockDir.lock_write() will wait for the lock."""
281
# the test suite sets the default to 0 to make deadlocks fail fast.
282
# change it for this test, as we want to try a manual deadlock.
283
raise tests.TestSkipped('Timing-sensitive test')
284
bzrlib.lockdir._DEFAULT_TIMEOUT_SECONDS = 300
285
t = self.get_transport()
286
lf1 = LockDir(t, 'test_lock')
290
def wait_and_unlock():
293
unlocker = Thread(target=wait_and_unlock)
296
lf2 = LockDir(t, 'test_lock')
297
self.setup_log_reporter(lf2)
305
# There should be only 1 report, even though it should have to
307
lock_base = lf2.transport.abspath(lf2.path)
308
self.assertEqual(1, len(self._logged_reports))
309
self.assertEqual('%s %s\n'
311
'Will continue to try until %s\n',
312
self._logged_reports[0][0])
313
args = self._logged_reports[0][1]
314
self.assertEqual('Unable to obtain', args[0])
315
self.assertEqual('lock %s' % (lock_base,), args[1])
316
self.assertStartsWith(args[2], 'held by ')
317
self.assertStartsWith(args[3], 'locked ')
318
self.assertEndsWith(args[3], ' ago')
319
self.assertContainsRe(args[4], r'\d\d:\d\d:\d\d')
321
def test_35_wait_lock_changing(self):
322
"""LockDir.wait_lock() will report if the lock changes underneath.
324
This is the stages we want to happen:
326
0) Synchronization locks are created and locked.
327
1) Lock1 obtains the lockdir, and releases the 'check' lock.
328
2) Lock2 grabs the 'check' lock, and checks the lockdir.
329
It sees the lockdir is already acquired, reports the fact,
330
and unsets the 'checked' lock.
331
3) Thread1 blocks on acquiring the 'checked' lock, and then tells
332
Lock1 to release and acquire the lockdir. This resets the 'check'
334
4) Lock2 acquires the 'check' lock, and checks again. It notices
335
that the holder of the lock has changed, and so reports a new
337
5) Thread1 blocks on the 'checked' lock, this time, it completely
338
unlocks the lockdir, allowing Lock2 to acquire the lock.
341
raise tests.KnownFailure(
342
"timing dependency in lock tests (#213182)")
344
wait_to_check_lock = Lock()
345
wait_until_checked_lock = Lock()
347
wait_to_check_lock.acquire()
348
wait_until_checked_lock.acquire()
349
note('locked check and checked locks')
351
class LockDir1(LockDir):
352
"""Use the synchronization points for the first lock."""
354
def attempt_lock(self):
355
# Once we have acquired the lock, it is okay for
356
# the other lock to check it
358
return super(LockDir1, self).attempt_lock()
360
note('lock1: releasing check lock')
361
wait_to_check_lock.release()
363
class LockDir2(LockDir):
364
"""Use the synchronization points for the second lock."""
366
def attempt_lock(self):
367
note('lock2: waiting for check lock')
368
wait_to_check_lock.acquire()
369
note('lock2: acquired check lock')
371
return super(LockDir2, self).attempt_lock()
373
note('lock2: releasing checked lock')
374
wait_until_checked_lock.release()
376
t = self.get_transport()
377
lf1 = LockDir1(t, 'test_lock')
380
lf2 = LockDir2(t, 'test_lock')
381
self.setup_log_reporter(lf2)
383
def wait_and_switch():
385
# Block until lock2 has had a chance to check
386
note('lock1: waiting 1 for checked lock')
387
wait_until_checked_lock.acquire()
388
note('lock1: acquired for checked lock')
389
note('lock1: released lockdir')
391
note('lock1: acquiring lockdir')
392
# Create a new nonce, so the lock looks different.
393
lf1.nonce = osutils.rand_chars(20)
395
note('lock1: acquired lockdir')
397
# Block until lock2 has peeked again
398
note('lock1: waiting 2 for checked lock')
399
wait_until_checked_lock.acquire()
400
note('lock1: acquired for checked lock')
401
# Now unlock, and let lock 2 grab the lock
403
wait_to_check_lock.release()
405
unlocker = Thread(target=wait_and_switch)
408
# Wait and play against the other thread
409
lf2.wait_lock(timeout=20.0, poll=0.01)
414
# There should be 2 reports, because the lock changed
415
lock_base = lf2.transport.abspath(lf2.path)
416
self.assertEqual(2, len(self._logged_reports))
417
lock_url = lf2.transport.abspath(lf2.path)
418
self.assertEqual('%s %s\n'
420
'Will continue to try until %s, unless '
422
'If you\'re sure that it\'s not being '
423
'modified, use bzr break-lock %s',
424
self._logged_reports[0][0])
425
args = self._logged_reports[0][1]
426
self.assertEqual('Unable to obtain', args[0])
427
self.assertEqual('lock %s' % (lock_base,), args[1])
428
self.assertStartsWith(args[2], 'held by ')
429
self.assertStartsWith(args[3], 'locked ')
430
self.assertEndsWith(args[3], ' ago')
431
self.assertContainsRe(args[4], r'\d\d:\d\d:\d\d')
433
self.assertEqual('%s %s\n'
435
'Will continue to try until %s, unless '
437
'If you\'re sure that it\'s not being '
438
'modified, use bzr break-lock %s',
439
self._logged_reports[1][0])
440
args = self._logged_reports[1][1]
441
self.assertEqual('Lock owner changed for', args[0])
442
self.assertEqual('lock %s' % (lock_base,), args[1])
443
self.assertStartsWith(args[2], 'held by ')
444
self.assertStartsWith(args[3], 'locked ')
445
self.assertEndsWith(args[3], ' ago')
446
self.assertContainsRe(args[4], r'\d\d:\d\d:\d\d')
448
219
def test_40_confirm_easy(self):
449
220
"""Confirm a lock that's already held"""
450
221
t = self.get_transport()
451
222
lf1 = LockDir(t, 'test_lock')
453
224
lf1.attempt_lock()
225
self.addCleanup(lf1.unlock)
456
228
def test_41_confirm_not_held(self):
553
330
# do this without IO redirection to ensure it doesn't prompt.
554
331
self.assertRaises(AssertionError, ld1.break_lock)
555
332
orig_factory = bzrlib.ui.ui_factory
556
# silent ui - no need for stdout
557
bzrlib.ui.ui_factory = bzrlib.ui.SilentUIFactory()
558
bzrlib.ui.ui_factory.stdin = StringIO("y\n")
333
bzrlib.ui.ui_factory = bzrlib.ui.CannedInputUIFactory([True])
561
336
self.assertRaises(LockBroken, ld1.unlock)
563
338
bzrlib.ui.ui_factory = orig_factory
340
def test_break_lock_corrupt_info(self):
341
"""break_lock works even if the info file is corrupt (and tells the UI
345
ld2 = self.get_lock()
348
ld.transport.put_bytes_non_atomic('test_lock/held/info', '\0')
350
class LoggingUIFactory(bzrlib.ui.SilentUIFactory):
354
def get_boolean(self, prompt):
355
self.prompts.append(('boolean', prompt))
358
ui = LoggingUIFactory()
359
self.overrideAttr(bzrlib.ui, 'ui_factory', ui)
361
self.assertLength(1, ui.prompts)
362
self.assertEqual('boolean', ui.prompts[0][0])
363
self.assertStartsWith(ui.prompts[0][1], 'Break (corrupt LockDir')
364
self.assertRaises(LockBroken, ld.unlock)
366
def test_break_lock_missing_info(self):
367
"""break_lock works even if the info file is missing (and tells the UI
371
ld2 = self.get_lock()
374
ld.transport.delete('test_lock/held/info')
376
class LoggingUIFactory(bzrlib.ui.SilentUIFactory):
380
def get_boolean(self, prompt):
381
self.prompts.append(('boolean', prompt))
384
ui = LoggingUIFactory()
385
orig_factory = bzrlib.ui.ui_factory
386
bzrlib.ui.ui_factory = ui
389
self.assertRaises(LockBroken, ld.unlock)
390
self.assertLength(0, ui.prompts)
392
bzrlib.ui.ui_factory = orig_factory
393
# Suppress warnings due to ld not being unlocked
394
# XXX: if lock_broken hook was invoked in this case, this hack would
395
# not be necessary. - Andrew Bennetts, 2010-09-06.
396
del self._lock_actions[:]
565
398
def test_create_missing_base_directory(self):
566
399
"""If LockDir.path doesn't exist, it can be created
649
483
# should be nothing before we start
651
485
t = self.get_transport().clone('test_lock')
652
487
def check_dir(a):
653
488
self.assertEquals(a, t.list_dir('.'))
655
491
# when held, that's all we see
656
492
ld1.attempt_lock()
493
self.addCleanup(ld1.unlock)
657
494
check_dir(['held'])
658
495
# second guy should fail
659
496
self.assertRaises(errors.LockContention, ld2.attempt_lock)
661
498
check_dir(['held'])
500
def test_no_lockdir_info(self):
501
"""We can cope with empty info files."""
502
# This seems like a fairly common failure case - see
503
# <https://bugs.launchpad.net/bzr/+bug/185103> and all its dupes.
504
# Processes are often interrupted after opening the file
505
# before the actual contents are committed.
506
t = self.get_transport()
508
t.mkdir('test_lock/held')
509
t.put_bytes('test_lock/held/info', '')
510
lf = LockDir(t, 'test_lock')
512
formatted_info = info.to_readable_dict()
514
dict(user='<unknown>', hostname='<unknown>', pid='<unknown>',
515
time_ago='(unknown)'),
518
def test_corrupt_lockdir_info(self):
519
"""We can cope with corrupt (and thus unparseable) info files."""
520
# This seems like a fairly common failure case too - see
521
# <https://bugs.launchpad.net/bzr/+bug/619872> for instance.
522
# In particular some systems tend to fill recently created files with
523
# nul bytes after recovering from a system crash.
524
t = self.get_transport()
526
t.mkdir('test_lock/held')
527
t.put_bytes('test_lock/held/info', '\0')
528
lf = LockDir(t, 'test_lock')
529
self.assertRaises(errors.LockCorrupt, lf.peek)
530
# Currently attempt_lock gives LockContention, but LockCorrupt would be
531
# a reasonable result too.
533
(errors.LockCorrupt, errors.LockContention), lf.attempt_lock)
534
self.assertRaises(errors.LockCorrupt, lf.validate_token, 'fake token')
536
def test_missing_lockdir_info(self):
537
"""We can cope with absent info files."""
538
t = self.get_transport()
540
t.mkdir('test_lock/held')
541
lf = LockDir(t, 'test_lock')
542
# In this case we expect the 'not held' result from peek, because peek
543
# cannot be expected to notice that there is a 'held' directory with no
545
self.assertEqual(None, lf.peek())
546
# And lock/unlock may work or give LockContention (but not any other
550
except LockContention:
551
# LockContention is ok, and expected on Windows
554
# no error is ok, and expected on POSIX (because POSIX allows
555
# os.rename over an empty directory).
557
# Currently raises TokenMismatch, but LockCorrupt would be reasonable
560
(errors.TokenMismatch, errors.LockCorrupt),
561
lf.validate_token, 'fake token')
564
class TestLockDirHooks(TestCaseWithTransport):
567
super(TestLockDirHooks, self).setUp()
571
return LockDir(self.get_transport(), 'test_lock')
663
573
def record_hook(self, result):
664
574
self._calls.append(result)
666
def reset_hooks(self):
667
self._old_hooks = lock.Lock.hooks
668
self.addCleanup(self.restore_hooks)
669
lock.Lock.hooks = lock.LockHooks()
671
def restore_hooks(self):
672
lock.Lock.hooks = self._old_hooks
674
576
def test_LockDir_acquired_success(self):
675
577
# the LockDir.lock_acquired hook fires when a lock is acquired.
678
578
LockDir.hooks.install_named_hook('lock_acquired',
679
self.record_hook, 'record_hook')
579
self.record_hook, 'record_hook')
680
580
ld = self.get_lock()
682
582
self.assertEqual([], self._calls)
720
616
def test_LockDir_released_fail(self):
721
617
# the LockDir.lock_released hook does not fire on failure.
724
618
ld = self.get_lock()
726
620
ld2 = self.get_lock()
727
621
ld.attempt_lock()
728
622
ld2.force_break(ld2.peek())
729
623
LockDir.hooks.install_named_hook('lock_released',
730
self.record_hook, 'record_hook')
624
self.record_hook, 'record_hook')
731
625
self.assertRaises(LockBroken, ld.unlock)
732
626
self.assertEqual([], self._calls)
628
def test_LockDir_broken_success(self):
629
# the LockDir.lock_broken hook fires when a lock is broken.
632
ld2 = self.get_lock()
633
result = ld.attempt_lock()
634
LockDir.hooks.install_named_hook('lock_broken',
635
self.record_hook, 'record_hook')
636
ld2.force_break(ld2.peek())
637
lock_path = ld.transport.abspath(ld.path)
638
self.assertEqual([lock.LockResult(lock_path, result)], self._calls)
640
def test_LockDir_broken_failure(self):
641
# the LockDir.lock_broken hook does not fires when a lock is already
645
ld2 = self.get_lock()
646
result = ld.attempt_lock()
647
holder_info = ld2.peek()
649
LockDir.hooks.install_named_hook('lock_broken',
650
self.record_hook, 'record_hook')
651
ld2.force_break(holder_info)
652
lock_path = ld.transport.abspath(ld.path)
653
self.assertEqual([], self._calls)
656
class TestLockHeldInfo(TestCase):
657
"""Can get information about the lock holder, and detect whether they're
661
info = LockHeldInfo.for_this_process(None)
662
self.assertContainsRe(repr(info), r"LockHeldInfo\(.*\)")
664
def test_unicode(self):
665
info = LockHeldInfo.for_this_process(None)
666
self.assertContainsRe(unicode(info),
667
r'held by .* on .* \(process #\d+\), acquired .* ago')
669
def test_is_locked_by_this_process(self):
670
info = LockHeldInfo.for_this_process(None)
671
self.assertTrue(info.is_locked_by_this_process())
673
def test_is_not_locked_by_this_process(self):
674
info = LockHeldInfo.for_this_process(None)
675
info.info_dict['pid'] = '123123123123123'
676
self.assertFalse(info.is_locked_by_this_process())
678
def test_lock_holder_live_process(self):
679
"""Detect that the holder (this process) is still running."""
680
info = LockHeldInfo.for_this_process(None)
681
self.assertFalse(info.is_lock_holder_known_dead())
683
def test_lock_holder_dead_process(self):
684
"""Detect that the holder (this process) is still running."""
685
self.overrideAttr(lockdir, 'get_host_name',
686
lambda: 'aproperhostname')
687
info = LockHeldInfo.for_this_process(None)
688
info.info_dict['pid'] = '123123123'
689
self.assertTrue(info.is_lock_holder_known_dead())
691
def test_lock_holder_other_machine(self):
692
"""The lock holder isn't here so we don't know if they're alive."""
693
info = LockHeldInfo.for_this_process(None)
694
info.info_dict['hostname'] = 'egg.example.com'
695
info.info_dict['pid'] = '123123123'
696
self.assertFalse(info.is_lock_holder_known_dead())
698
def test_lock_holder_other_user(self):
699
"""Only auto-break locks held by this user."""
700
info = LockHeldInfo.for_this_process(None)
701
info.info_dict['user'] = 'notme@example.com'
702
info.info_dict['pid'] = '123123123'
703
self.assertFalse(info.is_lock_holder_known_dead())
705
def test_no_good_hostname(self):
706
"""Correctly handle ambiguous hostnames.
708
If the lock's recorded with just 'localhost' we can't really trust
709
it's the same 'localhost'. (There are quite a few of them. :-)
710
So even if the process is known not to be alive, we can't say that's
713
self.overrideAttr(lockdir, 'get_host_name',
715
info = LockHeldInfo.for_this_process(None)
716
info.info_dict['pid'] = '123123123'
717
self.assertFalse(info.is_lock_holder_known_dead())
720
class TestStaleLockDir(TestCaseWithTransport):
721
"""Can automatically break stale locks.
723
:see: https://bugs.launchpad.net/bzr/+bug/220464
726
def test_auto_break_stale_lock(self):
727
"""Locks safely known to be stale are just cleaned up.
729
This generates a warning but no other user interaction.
731
self.overrideAttr(lockdir, 'get_host_name',
732
lambda: 'aproperhostname')
733
# This is off by default at present; see the discussion in the bug.
734
# If you change the default, don't forget to update the docs.
735
config.GlobalConfig().set_user_option('locks.steal_dead', True)
736
# Create a lock pretending to come from a different nonexistent
737
# process on the same machine.
738
l1 = LockDir(self.get_transport(), 'a',
739
extra_holder_info={'pid': '12312313'})
740
token_1 = l1.attempt_lock()
741
l2 = LockDir(self.get_transport(), 'a')
742
token_2 = l2.attempt_lock()
743
# l1 will notice its lock was stolen.
744
self.assertRaises(errors.LockBroken,
748
def test_auto_break_stale_lock_configured_off(self):
749
"""Automatic breaking can be turned off"""
750
l1 = LockDir(self.get_transport(), 'a',
751
extra_holder_info={'pid': '12312313'})
752
token_1 = l1.attempt_lock()
753
self.addCleanup(l1.unlock)
754
l2 = LockDir(self.get_transport(), 'a')
755
# This fails now, because dead lock breaking is off by default.
756
self.assertRaises(LockContention,
758
# and it's in fact not broken