Rev 2558: Simple lock tracing in LockDir in http://sourcefrog.net/bzr/dlock
Martin Pool
mbp at sourcefrog.net
Wed Jun 27 09:10:11 BST 2007
At http://sourcefrog.net/bzr/dlock
------------------------------------------------------------
revno: 2558
revision-id: mbp at sourcefrog.net-20070627081010-k0j4wgcyjjfabbe9
parent: mbp at sourcefrog.net-20070627080625-3rtudtycgo3ud4ip
committer: Martin Pool <mbp at sourcefrog.net>
branch nick: dlock
timestamp: Wed 2007-06-27 18:10:10 +1000
message:
Simple lock tracing in LockDir
modified:
bzrlib/lockdir.py lockdir.py-20060220222025-98258adf27fbdda3
bzrlib/tests/__init__.py selftest.py-20050531073622-8d0e3c8845c97a64
bzrlib/tests/blackbox/test_debug.py test_debug.py-20061026142942-q76cgg41785b3mdk-1
=== modified file 'bzrlib/lockdir.py'
--- a/bzrlib/lockdir.py 2007-04-13 01:57:12 +0000
+++ b/bzrlib/lockdir.py 2007-06-27 08:10:10 +0000
@@ -1,4 +1,4 @@
-# Copyright (C) 2006 Canonical Ltd
+# Copyright (C) 2006, 2007 Canonical Ltd
#
# This program is free software; you can redistribute it and/or modify
# it under the terms of the GNU General Public License as published by
@@ -99,6 +99,7 @@
from cStringIO import StringIO
from bzrlib import (
+ debug,
errors,
)
import bzrlib.config
@@ -197,6 +198,8 @@
if self.transport.is_readonly():
raise UnlockableTransport(self.transport)
try:
+ self._trace("lock_write...")
+ start_time = time.time()
tmpname = '%s/pending.%s.tmp' % (self.path, rand_chars(20))
try:
self.transport.mkdir(tmpname)
@@ -221,11 +224,16 @@
self.transport.rename(tmpname, self._held_dir)
self._lock_held = True
self.confirm()
+ # FIXME: we should remove the pending lock if we fail,
+ # https://bugs.launchpad.net/bzr/+bug/109169
except errors.PermissionDenied:
+ self._trace("... lock failed, permission denied")
raise
except (PathError, DirectoryNotEmpty, FileExists, ResourceBusy), e:
- mutter("contention on %r: %s", self, e)
+ self._trace("... contention, %s", e)
raise LockContention(self)
+ self._trace("... lock succeeded after %dms",
+ (time.time() - start_time) * 1000)
def unlock(self):
"""Release a held lock
@@ -241,6 +249,8 @@
else:
# rename before deleting, because we can't atomically remove the
# whole tree
+ start_time = time.time()
+ self._trace("unlocking")
tmpname = '%s/releasing.%s.tmp' % (self.path, rand_chars(20))
# gotta own it to unlock
self.confirm()
@@ -248,6 +258,8 @@
self._lock_held = False
self.transport.delete(tmpname + self.__INFO_NAME)
self.transport.rmdir(tmpname)
+ self._trace("... unlock succeeded after %dms",
+ (time.time() - start_time) * 1000)
def break_lock(self):
"""Break a lock not held by this instance of LockDir.
@@ -341,11 +353,12 @@
"""
try:
info = self._read_info_file(self._held_info_path)
+ self._trace("peek -> held")
assert isinstance(info, dict), \
"bad parse result %r" % info
return info
except NoSuchFile, e:
- return None
+ self._trace("peek -> not held")
def _prepare_info(self):
"""Write information about a pending lock to a temporary file.
@@ -394,7 +407,7 @@
except LockContention:
pass
new_info = self.peek()
- mutter('last_info: %s, new info: %s', last_info, new_info)
+ self._trace('last_info: %s, new info: %s', last_info, new_info)
if new_info is not None and new_info != last_info:
if last_info is None:
start = 'Unable to obtain'
@@ -477,8 +490,10 @@
if self.peek():
return
if time.time() + poll < deadline:
+ self._trace("Waiting %ss", poll)
time.sleep(poll)
else:
+ self._trace("Timeout after waiting %ss", timeout)
raise LockContention(self)
def _format_lock_info(self, info):
@@ -501,4 +516,10 @@
lock_token = info.get('nonce')
if token != lock_token:
raise errors.TokenMismatch(token, lock_token)
+ else:
+ self._trace("Revalidated by token %r", token)
+ def _trace(self, format, *args):
+ if 'lock' not in debug.debug_flags:
+ return
+ mutter(str(self) + ": " + (format % args))
=== modified file 'bzrlib/tests/__init__.py'
--- a/bzrlib/tests/__init__.py 2007-06-27 06:33:31 +0000
+++ b/bzrlib/tests/__init__.py 2007-06-27 08:10:10 +0000
@@ -820,8 +820,8 @@
return
if message is None:
message = "texts not equal:\n"
- raise AssertionError(message +
- self._ndiff_strings(a, b))
+ raise AssertionError(message +
+ self._ndiff_strings(a, b))
def assertEqualMode(self, mode, mode_test):
self.assertEqual(mode, mode_test,
=== modified file 'bzrlib/tests/blackbox/test_debug.py'
--- a/bzrlib/tests/blackbox/test_debug.py 2007-04-24 04:51:31 +0000
+++ b/bzrlib/tests/blackbox/test_debug.py 2007-06-27 08:10:10 +0000
@@ -22,9 +22,9 @@
import sys
import time
-from bzrlib.tests import TestCase, TestSkipped
+from bzrlib.tests import TestCaseInTempDir, TestSkipped
-class TestDebugOption(TestCase):
+class TestDebugOption(TestCaseInTempDir):
def test_dash_derror(self):
"""With -Derror, tracebacks are shown even for user errors"""
@@ -34,3 +34,9 @@
# here but it may be missing if the source is not in sync with the
# pyc file.
self.assertContainsRe(err, "Traceback \\(most recent call last\\)")
+
+ def test_dash_dlock(self):
+ # With -Dlock, locking and unlocking is recorded into the log
+ self.run_bzr("-Dlock init foo")
+ trace_messages = self._get_log(keep_log_file=True)
+ self.assertContainsRe(trace_messages, "lock_write")
More information about the bazaar-commits
mailing list