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
t = self.get_transport()
290
lf1 = LockDir(t, 'test_lock')
294
def wait_and_unlock():
297
unlocker = Thread(target=wait_and_unlock)
300
lf2 = LockDir(t, 'test_lock')
301
self.setup_log_reporter(lf2)
309
# There should be only 1 report, even though it should have to
311
lock_base = lf2.transport.abspath(lf2.path)
312
self.assertEqual(1, len(self._logged_reports))
313
self.assertEqual('%s %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')
325
def test_35_wait_lock_changing(self):
326
"""LockDir.wait_lock() will report if the lock changes underneath.
328
This is the stages we want to happen:
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'
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
341
5) Thread1 blocks on the 'checked' lock, this time, it completely
342
unlocks the lockdir, allowing Lock2 to acquire the lock.
345
wait_to_check_lock = Lock()
346
wait_until_checked_lock = Lock()
348
wait_to_check_lock.acquire()
349
wait_until_checked_lock.acquire()
350
note('locked check and checked locks')
352
class LockDir1(LockDir):
353
"""Use the synchronization points for the first lock."""
355
def attempt_lock(self):
356
# Once we have acquired the lock, it is okay for
357
# the other lock to check it
359
return super(LockDir1, self).attempt_lock()
361
note('lock1: releasing check lock')
362
wait_to_check_lock.release()
364
class LockDir2(LockDir):
365
"""Use the synchronization points for the second lock."""
367
def attempt_lock(self):
368
note('lock2: waiting for check lock')
369
wait_to_check_lock.acquire()
370
note('lock2: acquired check lock')
372
return super(LockDir2, self).attempt_lock()
374
note('lock2: releasing checked lock')
375
wait_until_checked_lock.release()
377
t = self.get_transport()
378
lf1 = LockDir1(t, 'test_lock')
381
lf2 = LockDir2(t, 'test_lock')
382
self.setup_log_reporter(lf2)
384
def wait_and_switch():
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')
392
note('lock1: acquiring lockdir')
393
# Create a new nonce, so the lock looks different.
394
lf1.nonce = osutils.rand_chars(20)
396
note('lock1: acquired lockdir')
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
404
wait_to_check_lock.release()
406
unlocker = Thread(target=wait_and_switch)
409
# Wait and play against the other thread
410
lf2.wait_lock(timeout=1.0, poll=0.01)
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))
419
self.assertEqual('%s %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')
431
self.assertEqual('%s %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')
222
443
def test_40_confirm_easy(self):
223
444
"""Confirm a lock that's already held"""
224
445
t = self.get_transport()
225
446
lf1 = LockDir(t, 'test_lock')
227
448
lf1.attempt_lock()
228
self.addCleanup(lf1.unlock)
231
451
def test_41_confirm_not_held(self):
333
548
# do this without IO redirection to ensure it doesn't prompt.
334
549
self.assertRaises(AssertionError, ld1.break_lock)
335
550
orig_factory = bzrlib.ui.ui_factory
336
bzrlib.ui.ui_factory = bzrlib.ui.CannedInputUIFactory([True])
551
# silent ui - no need for stdout
552
bzrlib.ui.ui_factory = bzrlib.ui.SilentUIFactory()
553
bzrlib.ui.ui_factory.stdin = StringIO("y\n")
339
556
self.assertRaises(LockBroken, ld1.unlock)
341
558
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
560
def test_create_missing_base_directory(self):
396
561
"""If LockDir.path doesn't exist, it can be created
441
607
def test_lock_permission(self):
442
self.requireFeature(features.not_running_as_root)
443
608
if not osutils.supports_posix_readonly():
444
609
raise tests.TestSkipped('Cannot induce a permission failure')
445
610
ld1 = self.get_lock()
446
611
lock_path = ld1.transport.local_abspath('test_lock')
447
612
os.mkdir(lock_path)
448
613
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)
614
self.assertRaises(errors.PermissionDenied, ld1.attempt_lock)