183
180
after = time.time()
184
181
# it should only take about 0.4 seconds, but we allow more time in
185
182
# case the machine is heavily loaded
186
self.assertTrue(after - before <= 8.0,
183
self.assertTrue(after - before <= 8.0,
187
184
"took %f seconds to detect lock contention" % (after - before))
187
lock_base = lf2.transport.abspath(lf2.path)
190
188
self.assertEqual(1, len(self._logged_reports))
191
self.assertEqual(self._logged_reports[0][0],
192
'%s lock %s held by %s\n'
193
'at %s [process #%s], acquired %s.\n'
194
'Will continue to try until %s, unless '
195
'you press Ctrl-C.\n'
196
'See "bzr help break-lock" for more.')
197
start, lock_url, user, hostname, pid, time_ago, deadline_str = \
198
self._logged_reports[0][1]
199
self.assertEqual(start, u'Unable to obtain')
200
self.assertEqual(user, u'jrandom@example.com')
202
self.assertContainsRe(pid, r'\d+')
203
self.assertContainsRe(time_ago, r'.* ago')
204
self.assertContainsRe(deadline_str, r'\d{2}:\d{2}:\d{2}')
189
self.assertEqual('%s %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')
206
201
def test_31_lock_wait_easy(self):
207
202
"""Succeed when waiting on a lock with no contention.
220
215
self.assertEqual([], self._logged_reports)
217
def test_32_lock_wait_succeed(self):
218
"""Succeed when trying to acquire a lock that gets released
220
One thread holds on a lock and then releases it; another
223
t = self.get_transport()
224
lf1 = LockDir(t, 'test_lock')
228
def wait_and_unlock():
231
unlocker = Thread(target=wait_and_unlock)
234
lf2 = LockDir(t, 'test_lock')
235
self.setup_log_reporter(lf2)
238
lf2.wait_lock(timeout=0.4, poll=0.1)
240
self.assertTrue(after - before <= 1.0)
244
# There should be only 1 report, even though it should have to
246
lock_base = lf2.transport.abspath(lf2.path)
247
self.assertEqual(1, len(self._logged_reports))
248
self.assertEqual('%s %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')
260
def test_33_wait(self):
261
"""Succeed when waiting on a lock that gets released
263
The difference from test_32_lock_wait_succeed is that the second
264
caller does not actually acquire the lock, but just waits for it
265
to be released. This is done over a readonly transport.
267
t = self.get_transport()
268
lf1 = LockDir(t, 'test_lock')
272
def wait_and_unlock():
275
unlocker = Thread(target=wait_and_unlock)
278
lf2 = LockDir(self.get_readonly_transport(), 'test_lock')
280
# wait but don't lock
281
lf2.wait(timeout=0.4, poll=0.1)
283
self.assertTrue(after - before <= 1.0)
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')
297
def wait_and_unlock():
300
unlocker = Thread(target=wait_and_unlock)
303
lf2 = LockDir(t, 'test_lock')
304
self.setup_log_reporter(lf2)
312
# There should be only 1 report, even though it should have to
314
lock_base = lf2.transport.abspath(lf2.path)
315
self.assertEqual(1, len(self._logged_reports))
316
self.assertEqual('%s %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')
328
def test_35_wait_lock_changing(self):
329
"""LockDir.wait_lock() will report if the lock changes underneath.
331
This is the stages we want to happen:
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'
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
344
5) Thread1 blocks on the 'checked' lock, this time, it completely
345
unlocks the lockdir, allowing Lock2 to acquire the lock.
348
wait_to_check_lock = Lock()
349
wait_until_checked_lock = Lock()
351
wait_to_check_lock.acquire()
352
wait_until_checked_lock.acquire()
353
note('locked check and checked locks')
355
class LockDir1(LockDir):
356
"""Use the synchronization points for the first lock."""
358
def attempt_lock(self):
359
# Once we have acquired the lock, it is okay for
360
# the other lock to check it
362
return super(LockDir1, self).attempt_lock()
364
note('lock1: releasing check lock')
365
wait_to_check_lock.release()
367
class LockDir2(LockDir):
368
"""Use the synchronization points for the second lock."""
370
def attempt_lock(self):
371
note('lock2: waiting for check lock')
372
wait_to_check_lock.acquire()
373
note('lock2: acquired check lock')
375
return super(LockDir2, self).attempt_lock()
377
note('lock2: releasing checked lock')
378
wait_until_checked_lock.release()
380
t = self.get_transport()
381
lf1 = LockDir1(t, 'test_lock')
384
lf2 = LockDir2(t, 'test_lock')
385
self.setup_log_reporter(lf2)
387
def wait_and_switch():
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')
395
note('lock1: acquiring lockdir')
396
# Create a new nonce, so the lock looks different.
397
lf1.nonce = osutils.rand_chars(20)
399
note('lock1: acquired lockdir')
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
407
wait_to_check_lock.release()
409
unlocker = Thread(target=wait_and_switch)
412
# Wait and play against the other thread
413
lf2.wait_lock(timeout=1.0, poll=0.01)
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))
422
self.assertEqual('%s %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')
434
self.assertEqual('%s %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')
222
446
def test_40_confirm_easy(self):
223
447
"""Confirm a lock that's already held"""
224
448
t = self.get_transport()
225
449
lf1 = LockDir(t, 'test_lock')
227
451
lf1.attempt_lock()
228
self.addCleanup(lf1.unlock)
231
454
def test_41_confirm_not_held(self):
333
551
# do this without IO redirection to ensure it doesn't prompt.
334
552
self.assertRaises(AssertionError, ld1.break_lock)
335
553
orig_factory = bzrlib.ui.ui_factory
336
bzrlib.ui.ui_factory = bzrlib.ui.CannedInputUIFactory([True])
554
# silent ui - no need for stdout
555
bzrlib.ui.ui_factory = bzrlib.ui.SilentUIFactory()
556
bzrlib.ui.ui_factory.stdin = StringIO("y\n")
339
559
self.assertRaises(LockBroken, ld1.unlock)
341
561
bzrlib.ui.ui_factory = orig_factory
343
def test_break_lock_corrupt_info(self):
344
"""break_lock works even if the info file is corrupt (and tells the UI
348
ld2 = self.get_lock()
351
ld.transport.put_bytes_non_atomic('test_lock/held/info', '\0')
352
class LoggingUIFactory(bzrlib.ui.SilentUIFactory):
355
def get_boolean(self, prompt):
356
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')
375
class LoggingUIFactory(bzrlib.ui.SilentUIFactory):
378
def get_boolean(self, prompt):
379
self.prompts.append(('boolean', prompt))
381
ui = LoggingUIFactory()
382
orig_factory = bzrlib.ui.ui_factory
383
bzrlib.ui.ui_factory = ui
386
self.assertRaises(LockBroken, ld.unlock)
387
self.assertLength(0, ui.prompts)
389
bzrlib.ui.ui_factory = orig_factory
390
# Suppress warnings due to ld not being unlocked
391
# XXX: if lock_broken hook was invoked in this case, this hack would
392
# not be necessary. - Andrew Bennetts, 2010-09-06.
393
del self._lock_actions[:]
395
563
def test_create_missing_base_directory(self):
396
564
"""If LockDir.path doesn't exist, it can be created
441
610
def test_lock_permission(self):
442
self.requireFeature(features.not_running_as_root)
443
611
if not osutils.supports_posix_readonly():
444
612
raise tests.TestSkipped('Cannot induce a permission failure')
445
613
ld1 = self.get_lock()
446
614
lock_path = ld1.transport.local_abspath('test_lock')
447
615
os.mkdir(lock_path)
448
616
osutils.make_readonly(lock_path)
449
self.assertRaises(errors.LockFailed, ld1.attempt_lock)
451
def test_lock_by_token(self):
452
ld1 = self.get_lock()
453
token = ld1.lock_write()
454
self.addCleanup(ld1.unlock)
455
self.assertNotEqual(None, token)
456
ld2 = self.get_lock()
457
t2 = ld2.lock_write(token)
458
self.addCleanup(ld2.unlock)
459
self.assertEqual(token, t2)
461
def test_lock_with_buggy_rename(self):
462
# test that lock acquisition handles servers which pretend they
463
# renamed correctly but that actually fail
464
t = transport.get_transport('brokenrename+' + self.get_url())
465
ld1 = LockDir(t, 'test_lock')
468
ld2 = LockDir(t, 'test_lock')
469
# we should fail to lock
470
e = self.assertRaises(errors.LockContention, ld2.attempt_lock)
471
# now the original caller should succeed in unlocking
473
# and there should be nothing left over
474
self.assertEquals([], t.list_dir('test_lock'))
476
def test_failed_lock_leaves_no_trash(self):
477
# if we fail to acquire the lock, we don't leave pending directories
478
# behind -- https://bugs.launchpad.net/bzr/+bug/109169
479
ld1 = self.get_lock()
480
ld2 = self.get_lock()
481
# should be nothing before we start
483
t = self.get_transport().clone('test_lock')
485
self.assertEquals(a, t.list_dir('.'))
487
# when held, that's all we see
489
self.addCleanup(ld1.unlock)
491
# second guy should fail
492
self.assertRaises(errors.LockContention, ld2.attempt_lock)
496
def test_no_lockdir_info(self):
497
"""We can cope with empty info files."""
498
# This seems like a fairly common failure case - see
499
# <https://bugs.launchpad.net/bzr/+bug/185103> and all its dupes.
500
# Processes are often interrupted after opening the file
501
# before the actual contents are committed.
502
t = self.get_transport()
504
t.mkdir('test_lock/held')
505
t.put_bytes('test_lock/held/info', '')
506
lf = LockDir(t, 'test_lock')
508
formatted_info = lf._format_lock_info(info)
510
['<unknown>', '<unknown>', '<unknown>', '(unknown)'],
513
def test_corrupt_lockdir_info(self):
514
"""We can cope with corrupt (and thus unparseable) info files."""
515
# This seems like a fairly common failure case too - see
516
# <https://bugs.launchpad.net/bzr/+bug/619872> for instance.
517
# In particular some systems tend to fill recently created files with
518
# nul bytes after recovering from a system crash.
519
t = self.get_transport()
521
t.mkdir('test_lock/held')
522
t.put_bytes('test_lock/held/info', '\0')
523
lf = LockDir(t, 'test_lock')
524
self.assertRaises(errors.LockCorrupt, lf.peek)
525
# Currently attempt_lock gives LockContention, but LockCorrupt would be
526
# a reasonable result too.
528
(errors.LockCorrupt, errors.LockContention), lf.attempt_lock)
529
self.assertRaises(errors.LockCorrupt, lf.validate_token, 'fake token')
531
def test_missing_lockdir_info(self):
532
"""We can cope with absent info files."""
533
t = self.get_transport()
535
t.mkdir('test_lock/held')
536
lf = LockDir(t, 'test_lock')
537
# In this case we expect the 'not held' result from peek, because peek
538
# cannot be expected to notice that there is a 'held' directory with no
540
self.assertEqual(None, lf.peek())
541
# And lock/unlock may work or give LockContention (but not any other
545
except LockContention:
546
# LockContention is ok, and expected on Windows
549
# no error is ok, and expected on POSIX (because POSIX allows
550
# os.rename over an empty directory).
552
# Currently raises TokenMismatch, but LockCorrupt would be reasonable
555
(errors.TokenMismatch, errors.LockCorrupt),
556
lf.validate_token, 'fake token')
559
class TestLockDirHooks(TestCaseWithTransport):
562
super(TestLockDirHooks, self).setUp()
566
return LockDir(self.get_transport(), 'test_lock')
568
def record_hook(self, result):
569
self._calls.append(result)
571
def test_LockDir_acquired_success(self):
572
# the LockDir.lock_acquired hook fires when a lock is acquired.
573
LockDir.hooks.install_named_hook('lock_acquired',
574
self.record_hook, 'record_hook')
577
self.assertEqual([], self._calls)
578
result = ld.attempt_lock()
579
lock_path = ld.transport.abspath(ld.path)
580
self.assertEqual([lock.LockResult(lock_path, result)], self._calls)
582
self.assertEqual([lock.LockResult(lock_path, result)], self._calls)
584
def test_LockDir_acquired_fail(self):
585
# the LockDir.lock_acquired hook does not fire on failure.
588
ld2 = self.get_lock()
590
# install a lock hook now, when the disk lock is locked
591
LockDir.hooks.install_named_hook('lock_acquired',
592
self.record_hook, 'record_hook')
593
self.assertRaises(errors.LockContention, ld.attempt_lock)
594
self.assertEqual([], self._calls)
596
self.assertEqual([], self._calls)
598
def test_LockDir_released_success(self):
599
# the LockDir.lock_released hook fires when a lock is acquired.
600
LockDir.hooks.install_named_hook('lock_released',
601
self.record_hook, 'record_hook')
604
self.assertEqual([], self._calls)
605
result = ld.attempt_lock()
606
self.assertEqual([], self._calls)
608
lock_path = ld.transport.abspath(ld.path)
609
self.assertEqual([lock.LockResult(lock_path, result)], self._calls)
611
def test_LockDir_released_fail(self):
612
# the LockDir.lock_released hook does not fire on failure.
615
ld2 = self.get_lock()
617
ld2.force_break(ld2.peek())
618
LockDir.hooks.install_named_hook('lock_released',
619
self.record_hook, 'record_hook')
620
self.assertRaises(LockBroken, ld.unlock)
621
self.assertEqual([], self._calls)
623
def test_LockDir_broken_success(self):
624
# the LockDir.lock_broken hook fires when a lock is broken.
627
ld2 = self.get_lock()
628
result = ld.attempt_lock()
629
LockDir.hooks.install_named_hook('lock_broken',
630
self.record_hook, 'record_hook')
631
ld2.force_break(ld2.peek())
632
lock_path = ld.transport.abspath(ld.path)
633
self.assertEqual([lock.LockResult(lock_path, result)], self._calls)
635
def test_LockDir_broken_failure(self):
636
# the LockDir.lock_broken hook does not fires when a lock is already
640
ld2 = self.get_lock()
641
result = ld.attempt_lock()
642
holder_info = ld2.peek()
644
LockDir.hooks.install_named_hook('lock_broken',
645
self.record_hook, 'record_hook')
646
ld2.force_break(holder_info)
647
lock_path = ld.transport.abspath(ld.path)
648
self.assertEqual([], self._calls)
617
self.assertRaises(errors.PermissionDenied, ld1.attempt_lock)