193
188
# it should only take about 0.4 seconds, but we allow more time in
194
189
# case the machine is heavily loaded
195
190
self.assertTrue(after - before <= 8.0,
196
"took %f seconds to detect lock contention" % (after - before))
191
"took %f seconds to detect lock contention" % (after - before))
199
194
self.assertEqual(1, len(self._logged_reports))
200
self.assertContainsRe(self._logged_reports[0][0],
201
r'Unable to obtain lock .* held by jrandom@example\.com on .*'
202
r' \(process #\d+\), acquired .* ago\.\n'
203
r'Will continue to try until \d{2}:\d{2}:\d{2}, unless '
204
r'you press Ctrl-C.\n'
205
r'See "brz help break-lock" for more.')
195
self.assertEqual(self._logged_reports[0][0],
196
'%s lock %s held by %s\n'
197
'at %s [process #%s], acquired %s.\n'
198
'Will continue to try until %s, unless '
199
'you press Ctrl-C.\n'
200
'See "bzr help break-lock" for more.')
201
start, lock_url, user, hostname, pid, time_ago, deadline_str = \
202
self._logged_reports[0][1]
203
self.assertEqual(start, u'Unable to obtain')
204
self.assertEqual(user, u'jrandom@example.com')
206
self.assertContainsRe(pid, r'\d+')
207
self.assertContainsRe(time_ago, r'.* ago')
208
self.assertContainsRe(deadline_str, r'\d{2}:\d{2}:\d{2}')
207
210
def test_31_lock_wait_easy(self):
208
211
"""Succeed when waiting on a lock with no contention.
221
224
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 '
421
'you press Ctrl-C.\n'
422
'See "bzr help break-lock" for more.',
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')
432
self.assertEqual('%s %s\n'
434
'Will continue to try until %s, unless '
435
'you press Ctrl-C.\n'
436
'See "bzr help break-lock" for more.',
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')
223
446
def test_40_confirm_easy(self):
224
447
"""Confirm a lock that's already held"""
225
448
t = self.get_transport()
334
557
# do this without IO redirection to ensure it doesn't prompt.
335
558
self.assertRaises(AssertionError, ld1.break_lock)
336
orig_factory = breezy.ui.ui_factory
337
breezy.ui.ui_factory = breezy.ui.CannedInputUIFactory([True])
559
orig_factory = bzrlib.ui.ui_factory
560
bzrlib.ui.ui_factory = bzrlib.ui.CannedInputUIFactory([True])
340
563
self.assertRaises(LockBroken, ld1.unlock)
342
breezy.ui.ui_factory = orig_factory
344
def test_break_lock_corrupt_info(self):
345
"""break_lock works even if the info file is corrupt (and tells the UI
349
ld2 = self.get_lock()
352
ld.transport.put_bytes_non_atomic('test_lock/held/info', b'\0')
354
class LoggingUIFactory(breezy.ui.SilentUIFactory):
358
def get_boolean(self, prompt):
359
self.prompts.append(('boolean', prompt))
362
ui = LoggingUIFactory()
363
self.overrideAttr(breezy.ui, 'ui_factory', ui)
365
self.assertLength(1, ui.prompts)
366
self.assertEqual('boolean', ui.prompts[0][0])
367
self.assertStartsWith(ui.prompts[0][1], 'Break (corrupt LockDir')
368
self.assertRaises(LockBroken, ld.unlock)
370
def test_break_lock_missing_info(self):
371
"""break_lock works even if the info file is missing (and tells the UI
375
ld2 = self.get_lock()
378
ld.transport.delete('test_lock/held/info')
380
class LoggingUIFactory(breezy.ui.SilentUIFactory):
384
def get_boolean(self, prompt):
385
self.prompts.append(('boolean', prompt))
388
ui = LoggingUIFactory()
389
orig_factory = breezy.ui.ui_factory
390
breezy.ui.ui_factory = ui
393
self.assertRaises(LockBroken, ld.unlock)
394
self.assertLength(0, ui.prompts)
396
breezy.ui.ui_factory = orig_factory
397
# Suppress warnings due to ld not being unlocked
398
# XXX: if lock_broken hook was invoked in this case, this hack would
399
# not be necessary. - Andrew Bennetts, 2010-09-06.
400
del self._lock_actions[:]
565
bzrlib.ui.ui_factory = orig_factory
402
567
def test_create_missing_base_directory(self):
403
568
"""If LockDir.path doesn't exist, it can be created
410
575
lf1 = LockDir(t, 'test_lock')
413
self.assertTrue(t.has('test_lock'))
578
self.failUnless(t.has('test_lock'))
415
580
t.rmdir('test_lock')
416
self.assertFalse(t.has('test_lock'))
581
self.failIf(t.has('test_lock'))
418
583
# This will create 'test_lock' if it needs to
420
self.assertTrue(t.has('test_lock'))
421
self.assertTrue(t.has('test_lock/held/info'))
585
self.failUnless(t.has('test_lock'))
586
self.failUnless(t.has('test_lock/held/info'))
424
self.assertFalse(t.has('test_lock/held/info'))
589
self.failIf(t.has('test_lock/held/info'))
426
def test_display_form(self):
591
def test__format_lock_info(self):
427
592
ld1 = self.get_lock()
431
info_list = ld1.peek().to_readable_dict()
596
info_list = ld1._format_lock_info(ld1.peek())
434
self.assertEqual(info_list['user'], u'jrandom@example.com')
435
self.assertContainsRe(info_list['pid'], '^\\d+$')
436
self.assertContainsRe(info_list['time_ago'], '^\\d+ seconds? ago$')
599
self.assertEqual(info_list[0], u'jrandom@example.com')
600
# info_list[1] is hostname. we skip this.
601
self.assertContainsRe(info_list[2], '^\d+$') # pid
602
self.assertContainsRe(info_list[3], r'^\d+ seconds? ago$') # time_ago
438
604
def test_lock_without_email(self):
439
global_config = config.GlobalStack()
605
global_config = config.GlobalConfig()
440
606
# Intentionally has no email address
441
global_config.set('email', 'User Identity')
607
global_config.set_user_option('email', 'User Identity')
442
608
ld1 = self.get_lock()
447
613
def test_lock_permission(self):
448
self.requireFeature(features.not_running_as_root)
449
614
if not osutils.supports_posix_readonly():
450
615
raise tests.TestSkipped('Cannot induce a permission failure')
451
616
ld1 = self.get_lock()
511
673
t = self.get_transport()
512
674
t.mkdir('test_lock')
513
675
t.mkdir('test_lock/held')
514
t.put_bytes('test_lock/held/info', b'')
676
t.put_bytes('test_lock/held/info', '')
515
677
lf = LockDir(t, 'test_lock')
517
formatted_info = info.to_readable_dict()
519
dict(user='<unknown>', hostname='<unknown>', pid='<unknown>',
520
time_ago='(unknown)'),
679
formatted_info = lf._format_lock_info(info)
681
['<unknown>', '<unknown>', '<unknown>', '(unknown)'],
523
def test_corrupt_lockdir_info(self):
524
"""We can cope with corrupt (and thus unparseable) info files."""
525
# This seems like a fairly common failure case too - see
526
# <https://bugs.launchpad.net/bzr/+bug/619872> for instance.
527
# In particular some systems tend to fill recently created files with
528
# nul bytes after recovering from a system crash.
529
t = self.get_transport()
531
t.mkdir('test_lock/held')
532
t.put_bytes('test_lock/held/info', b'\0')
533
lf = LockDir(t, 'test_lock')
534
self.assertRaises(errors.LockCorrupt, lf.peek)
535
# Currently attempt_lock gives LockContention, but LockCorrupt would be
536
# a reasonable result too.
538
(errors.LockCorrupt, errors.LockContention), lf.attempt_lock)
539
self.assertRaises(errors.LockCorrupt, lf.validate_token, 'fake token')
541
def test_missing_lockdir_info(self):
542
"""We can cope with absent info files."""
543
t = self.get_transport()
545
t.mkdir('test_lock/held')
546
lf = LockDir(t, 'test_lock')
547
# In this case we expect the 'not held' result from peek, because peek
548
# cannot be expected to notice that there is a 'held' directory with no
550
self.assertEqual(None, lf.peek())
551
# And lock/unlock may work or give LockContention (but not any other
555
except LockContention:
556
# LockContention is ok, and expected on Windows
559
# no error is ok, and expected on POSIX (because POSIX allows
560
# os.rename over an empty directory).
562
# Currently raises TokenMismatch, but LockCorrupt would be reasonable
565
(errors.TokenMismatch, errors.LockCorrupt),
566
lf.validate_token, 'fake token')
569
685
class TestLockDirHooks(TestCaseWithTransport):
656
772
ld2.force_break(holder_info)
657
773
lock_path = ld.transport.abspath(ld.path)
658
774
self.assertEqual([], self._calls)
661
class TestLockHeldInfo(TestCaseInTempDir):
662
"""Can get information about the lock holder, and detect whether they're
666
info = LockHeldInfo.for_this_process(None)
667
self.assertContainsRe(repr(info), r"LockHeldInfo\(.*\)")
669
def test_unicode(self):
670
info = LockHeldInfo.for_this_process(None)
671
self.assertContainsRe(text_type(info),
672
r'held by .* on .* \(process #\d+\), acquired .* ago')
674
def test_is_locked_by_this_process(self):
675
info = LockHeldInfo.for_this_process(None)
676
self.assertTrue(info.is_locked_by_this_process())
678
def test_is_not_locked_by_this_process(self):
679
info = LockHeldInfo.for_this_process(None)
680
info.info_dict['pid'] = '123123123123123'
681
self.assertFalse(info.is_locked_by_this_process())
683
def test_lock_holder_live_process(self):
684
"""Detect that the holder (this process) is still running."""
685
info = LockHeldInfo.for_this_process(None)
686
self.assertFalse(info.is_lock_holder_known_dead())
688
def test_lock_holder_dead_process(self):
689
"""Detect that the holder (this process) is still running."""
690
self.overrideAttr(lockdir, 'get_host_name',
691
lambda: 'aproperhostname')
692
info = LockHeldInfo.for_this_process(None)
693
info.info_dict['pid'] = '123123123'
694
self.assertTrue(info.is_lock_holder_known_dead())
696
def test_lock_holder_other_machine(self):
697
"""The lock holder isn't here so we don't know if they're alive."""
698
info = LockHeldInfo.for_this_process(None)
699
info.info_dict['hostname'] = 'egg.example.com'
700
info.info_dict['pid'] = '123123123'
701
self.assertFalse(info.is_lock_holder_known_dead())
703
def test_lock_holder_other_user(self):
704
"""Only auto-break locks held by this user."""
705
info = LockHeldInfo.for_this_process(None)
706
info.info_dict['user'] = 'notme@example.com'
707
info.info_dict['pid'] = '123123123'
708
self.assertFalse(info.is_lock_holder_known_dead())
710
def test_no_good_hostname(self):
711
"""Correctly handle ambiguous hostnames.
713
If the lock's recorded with just 'localhost' we can't really trust
714
it's the same 'localhost'. (There are quite a few of them. :-)
715
So even if the process is known not to be alive, we can't say that's
718
self.overrideAttr(lockdir, 'get_host_name',
720
info = LockHeldInfo.for_this_process(None)
721
info.info_dict['pid'] = '123123123'
722
self.assertFalse(info.is_lock_holder_known_dead())
725
class TestStaleLockDir(TestCaseWithTransport):
726
"""Can automatically break stale locks.
728
:see: https://bugs.launchpad.net/bzr/+bug/220464
731
def test_auto_break_stale_lock(self):
732
"""Locks safely known to be stale are just cleaned up.
734
This generates a warning but no other user interaction.
736
self.overrideAttr(lockdir, 'get_host_name',
737
lambda: 'aproperhostname')
738
# Stealing dead locks is enabled by default.
739
# Create a lock pretending to come from a different nonexistent
740
# process on the same machine.
741
l1 = LockDir(self.get_transport(), 'a',
742
extra_holder_info={'pid': '12312313'})
743
token_1 = l1.attempt_lock()
744
l2 = LockDir(self.get_transport(), 'a')
745
token_2 = l2.attempt_lock()
746
# l1 will notice its lock was stolen.
747
self.assertRaises(errors.LockBroken,
751
def test_auto_break_stale_lock_configured_off(self):
752
"""Automatic breaking can be turned off"""
753
l1 = LockDir(self.get_transport(), 'a',
754
extra_holder_info={'pid': '12312313'})
755
# Stealing dead locks is enabled by default, so disable it.
756
config.GlobalStack().set('locks.steal_dead', False)
757
token_1 = l1.attempt_lock()
758
self.addCleanup(l1.unlock)
759
l2 = LockDir(self.get_transport(), 'a')
760
# This fails now, because dead lock breaking is disabled.
761
self.assertRaises(LockContention,
763
# and it's in fact not broken