Rev 2584: (mbp, r=john, r=robertc) -Dlock and lockdir fixes in file:///home/pqm/archives/thelove/bzr/%2Btrunk/

Canonical.com Patch Queue Manager pqm at pqm.ubuntu.com
Wed Jul 4 10:53:22 BST 2007


At file:///home/pqm/archives/thelove/bzr/%2Btrunk/

------------------------------------------------------------
revno: 2584
revision-id: pqm at pqm.ubuntu.com-20070704095320-41p0gvstimqqzvtx
parent: pqm at pqm.ubuntu.com-20070704090428-7up5xgpxdtt234u3
parent: mbp at sourcefrog.net-20070704092414-oql4gkeief8aq5oh
committer: Canonical.com Patch Queue Manager<pqm at pqm.ubuntu.com>
branch nick: +trunk
timestamp: Wed 2007-07-04 10:53:20 +0100
message:
  (mbp,r=john,r=robertc) -Dlock and lockdir fixes
added:
  bzrlib/transport/brokenrename.py brokenrename.py-20070628050843-mbwebk50srn93rut-1
modified:
  NEWS                           NEWS-20050323055033-4e00b5db738777ff
  bzrlib/debug.py                debug.py-20061102062349-vdhrw9qdpck8cl35-1
  bzrlib/lock.py                 lock.py-20050527050856-ec090bb51bc03349
  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
  bzrlib/tests/test_lockdir.py   test_lockdir.py-20060220222025-33d4221569a3d600
  bzrlib/transport/__init__.py   transport.py-20050711165921-4978aa7ce1285ad5
  doc/developers/profiling.txt   profiling.txt-20070531045713-j15mxufywgzwdeu8-1
    ------------------------------------------------------------
    revno: 2555.3.22
    merged: mbp at sourcefrog.net-20070704092414-oql4gkeief8aq5oh
    parent: mbp at sourcefrog.net-20070704092156-us6h516qevsps4dg
    committer: Martin Pool <mbp at sourcefrog.net>
    branch nick: dlock
    timestamp: Wed 2007-07-04 19:24:14 +1000
    message:
      hook docs
    ------------------------------------------------------------
    revno: 2555.3.21
    merged: mbp at sourcefrog.net-20070704092156-us6h516qevsps4dg
    parent: mbp at sourcefrog.net-20070704091023-7ngb0ux89dnxbppi
    committer: Martin Pool <mbp at sourcefrog.net>
    branch nick: dlock
    timestamp: Wed 2007-07-04 19:21:56 +1000
    message:
      Remove LockDir.wait()
    ------------------------------------------------------------
    revno: 2555.3.20
    merged: mbp at sourcefrog.net-20070704091023-7ngb0ux89dnxbppi
    parent: mbp at sourcefrog.net-20070704090420-xyi51gwbmcoxdbjr
    committer: Martin Pool <mbp at sourcefrog.net>
    branch nick: dlock
    timestamp: Wed 2007-07-04 19:10:23 +1000
    message:
      rename _lock_core to _attempt_lock
    ------------------------------------------------------------
    revno: 2555.3.19
    merged: mbp at sourcefrog.net-20070704090420-xyi51gwbmcoxdbjr
    parent: mbp at sourcefrog.net-20070703092445-lxrbtbwncyyolqgz
    parent: pqm at pqm.ubuntu.com-20070704083613-v2o3pj6chp4hiqky
    committer: Martin Pool <mbp at sourcefrog.net>
    branch nick: dlock
    timestamp: Wed 2007-07-04 19:04:20 +1000
    message:
      merge news from trunk
    ------------------------------------------------------------
    revno: 2555.3.18
    merged: mbp at sourcefrog.net-20070703092445-lxrbtbwncyyolqgz
    parent: mbp at sourcefrog.net-20070703092317-7uf5ftvnu268m4ls
    committer: Martin Pool <mbp at sourcefrog.net>
    branch nick: dlock
    timestamp: Tue 2007-07-03 19:24:45 +1000
    message:
      Don't fail hard when removing pending lockdir
    ------------------------------------------------------------
    revno: 2555.3.17
    merged: mbp at sourcefrog.net-20070703092317-7uf5ftvnu268m4ls
    parent: mbp at sourcefrog.net-20070703091157-r98tvj1rwxorobog
    committer: Martin Pool <mbp at sourcefrog.net>
    branch nick: dlock
    timestamp: Tue 2007-07-03 19:23:17 +1000
    message:
      Remove outdated comments
    ------------------------------------------------------------
    revno: 2555.3.16
    merged: mbp at sourcefrog.net-20070703091157-r98tvj1rwxorobog
    parent: mbp at sourcefrog.net-20070703090919-85qfphsxv3pp2czj
    committer: Martin Pool <mbp at sourcefrog.net>
    branch nick: dlock
    timestamp: Tue 2007-07-03 19:11:57 +1000
    message:
      Clean up patch to make divergence from mainline smaller.
      
      Separate out LockDir._remove_pending_dir.
      
      Put some behaviour back that was depended upon by test cases that override
      attempt_lock.
      
      Typos.
    ------------------------------------------------------------
    revno: 2555.3.15
    merged: mbp at sourcefrog.net-20070703090919-85qfphsxv3pp2czj
    parent: mbp at sourcefrog.net-20070703072442-y3pwex52rrtsa8gg
    committer: Martin Pool <mbp at sourcefrog.net>
    branch nick: dlock
    timestamp: Tue 2007-07-03 19:09:19 +1000
    message:
      remove pdb
    ------------------------------------------------------------
    revno: 2555.3.14
    merged: mbp at sourcefrog.net-20070703072442-y3pwex52rrtsa8gg
    parent: mbp at sourcefrog.net-20070703070030-vayxt8668a4nappy
    committer: Martin Pool <mbp at sourcefrog.net>
    branch nick: dlock
    timestamp: Tue 2007-07-03 17:24:42 +1000
    message:
      Better handling in LockDir of rename that moves one directory within another
    ------------------------------------------------------------
    revno: 2555.3.13
    merged: mbp at sourcefrog.net-20070703070030-vayxt8668a4nappy
    parent: mbp at sourcefrog.net-20070628080901-o0xsxrgsqodeqvcu
    committer: Martin Pool <mbp at sourcefrog.net>
    branch nick: dlock
    timestamp: Tue 2007-07-03 17:00:30 +1000
    message:
      LockDir cleanups
    ------------------------------------------------------------
    revno: 2555.3.12
    merged: mbp at sourcefrog.net-20070628080901-o0xsxrgsqodeqvcu
    parent: mbp at sourcefrog.net-20070628075315-ewq68yfptqwx7nj8
    committer: Martin Pool <mbp at sourcefrog.net>
    branch nick: dlock
    timestamp: Thu 2007-06-28 18:09:01 +1000
    message:
      Add test for https://bugs.launchpad.net/bzr/+bug/109169 -- test_failed_lock_leaves_no_trash
    ------------------------------------------------------------
    revno: 2555.3.11
    merged: mbp at sourcefrog.net-20070628075315-ewq68yfptqwx7nj8
    parent: mbp at sourcefrog.net-20070628074325-fewhyi24ittr3kyz
    committer: Martin Pool <mbp at sourcefrog.net>
    branch nick: dlock
    timestamp: Thu 2007-06-28 17:53:15 +1000
    message:
      fix up doctest example for token being returned from wait_lock
    ------------------------------------------------------------
    revno: 2555.3.10
    merged: mbp at sourcefrog.net-20070628074325-fewhyi24ittr3kyz
    parent: mbp at sourcefrog.net-20070628060630-n7ygr23xhjcnay9w
    committer: Martin Pool <mbp at sourcefrog.net>
    branch nick: dlock
    timestamp: Thu 2007-06-28 17:43:25 +1000
    message:
      doc
    ------------------------------------------------------------
    revno: 2555.3.9
    merged: mbp at sourcefrog.net-20070628060630-n7ygr23xhjcnay9w
    parent: mbp at sourcefrog.net-20070628060052-2st5avps6i86neat
    committer: Martin Pool <mbp at sourcefrog.net>
    branch nick: dlock
    timestamp: Thu 2007-06-28 16:06:30 +1000
    message:
      Add test and fix for locking robustly when rename of directories doesn't act as a mutex (thank John)
    ------------------------------------------------------------
    revno: 2555.3.8
    merged: mbp at sourcefrog.net-20070628060052-2st5avps6i86neat
    parent: mbp at sourcefrog.net-20070627093945-36tc2vu397tk1k6a
    committer: Martin Pool <mbp at sourcefrog.net>
    branch nick: dlock
    timestamp: Thu 2007-06-28 16:00:52 +1000
    message:
      Add new BrokenRenameTransportDecorator
    ------------------------------------------------------------
    revno: 2555.3.7
    merged: mbp at sourcefrog.net-20070627093945-36tc2vu397tk1k6a
    parent: mbp at sourcefrog.net-20070627092240-c75i6lwuwnc5gf2l
    committer: Martin Pool <mbp at sourcefrog.net>
    branch nick: dlock
    timestamp: Wed 2007-06-27 19:39:45 +1000
    message:
      Docs on -Dlock
    ------------------------------------------------------------
    revno: 2555.3.6
    merged: mbp at sourcefrog.net-20070627092240-c75i6lwuwnc5gf2l
    parent: mbp at sourcefrog.net-20070627091722-ouf4om2ib0e4s7ft
    committer: Martin Pool <mbp at sourcefrog.net>
    branch nick: dlock
    timestamp: Wed 2007-06-27 19:22:40 +1000
    message:
      Restore disabled LockDir trace message
    ------------------------------------------------------------
    revno: 2555.3.5
    merged: mbp at sourcefrog.net-20070627091722-ouf4om2ib0e4s7ft
    parent: mbp at sourcefrog.net-20070627081353-f3402usvh4zlcs7q
    committer: Martin Pool <mbp at sourcefrog.net>
    branch nick: dlock
    timestamp: Wed 2007-06-27 19:17:22 +1000
    message:
      Return token directly from LockDir.acquire to avoid unnecessary peek()
    ------------------------------------------------------------
    revno: 2555.3.4
    merged: mbp at sourcefrog.net-20070627081353-f3402usvh4zlcs7q
    parent: mbp at sourcefrog.net-20070627081010-k0j4wgcyjjfabbe9
    committer: Martin Pool <mbp at sourcefrog.net>
    branch nick: dlock
    timestamp: Wed 2007-06-27 18:13:53 +1000
    message:
      Remove unnecessary confirmation after acquiring LockDir
    ------------------------------------------------------------
    revno: 2555.3.3
    merged: 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
    ------------------------------------------------------------
    revno: 2555.3.2
    merged: mbp at sourcefrog.net-20070627080625-3rtudtycgo3ud4ip
    parent: mbp at sourcefrog.net-20070627063331-42nj4x28k15zmqan
    committer: Martin Pool <mbp at sourcefrog.net>
    branch nick: dlock
    timestamp: Wed 2007-06-27 18:06:25 +1000
    message:
      rename _base_Lock to _OSLock
    ------------------------------------------------------------
    revno: 2555.3.1
    merged: mbp at sourcefrog.net-20070627063331-42nj4x28k15zmqan
    parent: pqm at pqm.ubuntu.com-20070627023032-h316n5k05g1nqqem
    committer: Martin Pool <mbp at sourcefrog.net>
    branch nick: dlock
    timestamp: Wed 2007-06-27 16:33:31 +1000
    message:
      Better messages from assertContainsRe
=== added file 'bzrlib/transport/brokenrename.py'
--- a/bzrlib/transport/brokenrename.py	1970-01-01 00:00:00 +0000
+++ b/bzrlib/transport/brokenrename.py	2007-07-03 07:24:42 +0000
@@ -0,0 +1,60 @@
+# Copyright (C) 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
+# the Free Software Foundation; either version 2 of the License, or
+# (at your option) any later version.
+#
+# This program is distributed in the hope that it will be useful,
+# but WITHOUT ANY WARRANTY; without even the implied warranty of
+# MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.  See the
+# GNU General Public License for more details.
+#
+# You should have received a copy of the GNU General Public License
+# along with this program; if not, write to the Free Software
+# Foundation, Inc., 59 Temple Place, Suite 330, Boston, MA  02111-1307  USA
+
+"""Transport implementation that doesn't detect clashing renames.
+"""
+
+from stat import S_ISDIR
+
+from bzrlib import (
+        errors,
+        urlutils,
+        )
+from bzrlib.transport.decorator import TransportDecorator, DecoratorServer
+
+
+class BrokenRenameTransportDecorator(TransportDecorator):
+    """A transport that fails to detect clashing renames"""
+
+    @classmethod
+    def _get_url_prefix(self):
+        """FakeNFS transports are identified by 'brokenrename+'"""
+        return 'brokenrename+'
+
+    def rename(self, rel_from, rel_to):
+        """See Transport.rename().
+        """
+        try:
+            if self._decorated.has(rel_to):
+                rel_to = urlutils.join(rel_to, urlutils.basename(rel_from))
+            self._decorated.rename(rel_from, rel_to)
+        except (errors.DirectoryNotEmpty, errors.FileExists), e:
+            # absorb the error
+            return
+
+
+class BrokenRenameServer(DecoratorServer):
+    """Server for the BrokenRenameTransportDecorator for testing with."""
+
+    def get_decorator_class(self):
+        return BrokenRenameTransportDecorator
+
+
+def get_test_permutations():
+    """Return the permutations to be used in testing."""
+    # we don't use this for general testing, only for the tests that
+    # specifically want it
+    return []

=== modified file 'NEWS'
--- a/NEWS	2007-07-04 08:08:08 +0000
+++ b/NEWS	2007-07-04 09:21:56 +0000
@@ -23,6 +23,9 @@
     * Fix ``bzr log -r`` to support selecting merge revisions, both 
       individually and as part of revision ranges.
       (Kent Gibson, #4663)
+ 
+    * Don't leave cruft behind when failing to acquire a lockdir.
+      (Martin Pool, #109169)
 
   IMPROVEMENTS:
 
@@ -72,6 +75,9 @@
       library users and plugins. See the ``bzrlib.api`` module for details.
       (Robert Collins)
 
+    * Remove unnecessary lock probes when acquiring a lockdir.
+      (Martin Pool)
+
     * ``bzr --version`` now shows the location of the bzr log file, which
       is especially useful on Windows.  (Martin Pool)
 
@@ -113,10 +119,15 @@
     * ``bzrlib.add.FastPath`` is now private and moved to 
       ``bzrlib.mutabletree._FastPath``. (Robert Collins, Martin Pool)
 
+    * ``LockDir.wait`` removed.  (Martin Pool)
+
   INTERNALS:
 
     * New SMTPConnection class to unify email handling.  (Adeodato Simó)
 
+    * New ``-Dlock`` option to log (to ~/.bzr.log) information on when 
+      lockdirs are taken or released.  (Martin Pool)
+
     * ``bzrlib`` Hooks are now nameable using ``Hooks.name_hook``. This 
       allows a nicer UI when hooks are running as the current hook can
       be displayed. (Robert Collins)

=== modified file 'bzrlib/debug.py'
--- a/bzrlib/debug.py	2007-06-28 08:29:44 +0000
+++ b/bzrlib/debug.py	2007-07-04 09:24:14 +0000
@@ -16,6 +16,14 @@
 
 
 debug_flags = set()
-"""Set of flags that enable different debug behaviour"""
-
-# hooks - debug activity about hooks.
+"""Set of flags that enable different debug behaviour.
+
+These are set with eg ``-Dlock`` on the bzr command line.
+
+Options include:
+    
+ * hooks 
+ * lock - trace when lockdir locks are taken or released
+ * error - show stack traces for all top level exceptions
+
+"""

=== modified file 'bzrlib/lock.py'
--- a/bzrlib/lock.py	2007-04-01 06:19:16 +0000
+++ b/bzrlib/lock.py	2007-06-27 08:06:25 +0000
@@ -44,7 +44,7 @@
     )
 
 
-class _base_Lock(object):
+class _OSLock(object):
 
     def __init__(self):
         self.f = None
@@ -109,7 +109,7 @@
     lock_EX = fcntl.LOCK_EX
 
 
-    class _fcntl_FileLock(_base_Lock):
+    class _fcntl_FileLock(_OSLock):
 
         def _unlock(self):
             fcntl.lockf(self.f, fcntl.LOCK_UN)
@@ -196,7 +196,7 @@
             return True, wlock
 
 
-    class _fcntl_TemporaryWriteLock(_base_Lock):
+    class _fcntl_TemporaryWriteLock(_OSLock):
         """A token used when grabbing a temporary_write_lock.
 
         Call restore_read_lock() when you are done with the write lock.
@@ -258,7 +258,7 @@
     LOCK_NB = win32con.LOCKFILE_FAIL_IMMEDIATELY
 
 
-    class _w32c_FileLock(_base_Lock):
+    class _w32c_FileLock(_OSLock):
 
         def _lock(self, filename, openmode, lockmode):
             self._open(filename, openmode)
@@ -374,7 +374,7 @@
                     ('hEvent', ctypes.c_void_p), # HANDLE
                    ]
 
-    class _ctypes_FileLock(_base_Lock):
+    class _ctypes_FileLock(_OSLock):
 
         def _lock(self, filename, openmode, lockmode):
             self._open(filename, openmode)

=== modified file 'bzrlib/lockdir.py'
--- a/bzrlib/lockdir.py	2007-04-13 01:57:12 +0000
+++ b/bzrlib/lockdir.py	2007-07-04 09:21:56 +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
@@ -88,17 +88,27 @@
 >>> t = MemoryTransport()
 >>> l = LockDir(t, 'sample-lock')
 >>> l.create()
->>> l.wait_lock()
+>>> token = l.wait_lock()
 >>> # do something here
 >>> l.unlock()
 
 """
 
+
+# TODO: We sometimes have the problem that our attempt to rename '1234' to
+# 'held' fails because the transport server moves into an existing directory,
+# rather than failing the rename.  If we made the info file name the same as
+# the locked directory name we would avoid this problem because moving into
+# the held directory would implicitly clash.  However this would not mesh with
+# the existing locking code and needs a new format of the containing object.
+# -- robertc, mbp 20070628
+
 import os
 import time
 from cStringIO import StringIO
 
 from bzrlib import (
+    debug,
     errors,
     )
 import bzrlib.config
@@ -184,48 +194,88 @@
         """
         if self.transport.is_readonly():
             raise UnlockableTransport(self.transport)
+        self._trace("create lock directory")
         self.transport.mkdir(self.path, mode=mode)
 
-    def attempt_lock(self):
-        """Take the lock; fail if it's already held.
+    def _attempt_lock(self):
+        """Make the pending directory and attempt to rename into place.
         
-        If you wish to block until the lock can be obtained, call wait_lock()
-        instead.
+        If the rename succeeds, we read back the info file to check that we
+        really got the lock.
+
+        If we fail to acquire the lock, this method is responsible for
+        cleaning up the pending directory if possible.  (But it doesn't do
+        that yet.)
+
+        :returns: The nonce of the lock, if it was successfully acquired.
+
+        :raises LockContention: If the lock is held by someone else.  The exception
+            contains the info of the current holder of the lock.
         """
-        if self._fake_read_lock:
-            raise LockContention(self)
-        if self.transport.is_readonly():
-            raise UnlockableTransport(self.transport)
+        self._trace("lock_write...")
+        start_time = time.time()
+        tmpname = self._create_pending_dir()
         try:
-            tmpname = '%s/pending.%s.tmp' % (self.path, rand_chars(20))
-            try:
-                self.transport.mkdir(tmpname)
-            except NoSuchFile:
-                # This may raise a FileExists exception
-                # which is okay, it will be caught later and determined
-                # to be a LockContention.
-                self.create(mode=self._dir_modebits)
-                
-                # After creating the lock directory, try again
-                self.transport.mkdir(tmpname)
-
-            self.nonce = rand_chars(20)
-            info_bytes = self._prepare_info()
-            # We use put_file_non_atomic because we just created a new unique
-            # directory so we don't have to worry about files existing there.
-            # We'll rename the whole directory into place to get atomic
-            # properties
-            self.transport.put_bytes_non_atomic(tmpname + self.__INFO_NAME,
-                                                info_bytes)
-
             self.transport.rename(tmpname, self._held_dir)
-            self._lock_held = True
-            self.confirm()
-        except errors.PermissionDenied:
+        except (PathError, DirectoryNotEmpty, FileExists, ResourceBusy), e:
+            self._trace("... contention, %s", e)
+            self._remove_pending_dir(tmpname)
+            raise LockContention(self)
+        except Exception, e:
+            self._trace("... lock failed, %s", e)
+            self._remove_pending_dir(tmpname)
             raise
-        except (PathError, DirectoryNotEmpty, FileExists, ResourceBusy), e:
-            mutter("contention on %r: %s", self, e)
+        # We must check we really got the lock, because Launchpad's sftp
+        # server at one time had a bug were the rename would successfully
+        # move the new directory into the existing directory, which was
+        # incorrect.  It's possible some other servers or filesystems will
+        # have a similar bug allowing someone to think they got the lock
+        # when it's already held.
+        info = self.peek()
+        self._trace("after locking, info=%r", info)
+        if info['nonce'] != self.nonce:
+            self._trace("rename succeeded, "
+                "but lock is still held by someone else")
             raise LockContention(self)
+        self._lock_held = True
+        self._trace("... lock succeeded after %dms",
+                (time.time() - start_time) * 1000)
+        return self.nonce
+
+    def _remove_pending_dir(self, tmpname):
+        """Remove the pending directory
+
+        This is called if we failed to rename into place, so that the pending 
+        dirs don't clutter up the lockdir.
+        """
+        self._trace("remove %s", tmpname)
+        try:
+            self.transport.delete(tmpname + self.__INFO_NAME)
+            self.transport.rmdir(tmpname)
+        except PathError, e:
+            note("error removing pending lock: %s", e)
+
+    def _create_pending_dir(self):
+        tmpname = '%s/%s.tmp' % (self.path, rand_chars(10))
+        try:
+            self.transport.mkdir(tmpname)
+        except NoSuchFile:
+            # This may raise a FileExists exception
+            # which is okay, it will be caught later and determined
+            # to be a LockContention.
+            self._trace("lock directory does not exist, creating it")
+            self.create(mode=self._dir_modebits)
+            # After creating the lock directory, try again
+            self.transport.mkdir(tmpname)
+        self.nonce = rand_chars(20)
+        info_bytes = self._prepare_info()
+        # We use put_file_non_atomic because we just created a new unique
+        # directory so we don't have to worry about files existing there.
+        # We'll rename the whole directory into place to get atomic
+        # properties
+        self.transport.put_bytes_non_atomic(tmpname + self.__INFO_NAME,
+                                            info_bytes)
+        return tmpname
 
     def unlock(self):
         """Release a held lock
@@ -241,13 +291,29 @@
         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()
             self.transport.rename(self._held_dir, tmpname)
             self._lock_held = False
             self.transport.delete(tmpname + self.__INFO_NAME)
-            self.transport.rmdir(tmpname)
+            try:
+                self.transport.rmdir(tmpname)
+            except DirectoryNotEmpty, e:
+                # There might have been junk left over by a rename that moved
+                # another locker within the 'held' directory.  do a slower
+                # deletion where we list the directory and remove everything
+                # within it.
+                #
+                # Maybe this should be broader to allow for ftp servers with
+                # non-specific error messages?
+                self._trace("doing recursive deletion of non-empty directory "
+                        "%s", tmpname)
+                self.transport.delete_tree(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 +407,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.
@@ -368,7 +435,22 @@
     def _parse_info(self, info_file):
         return read_stanza(info_file.readlines()).as_dict()
 
-    def wait_lock(self, timeout=None, poll=None):
+    def attempt_lock(self):
+        """Take the lock; fail if it's already held.
+        
+        If you wish to block until the lock can be obtained, call wait_lock()
+        instead.
+
+        :return: The lock token.
+        :raises LockContention: if the lock is held by someone else.
+        """
+        if self._fake_read_lock:
+            raise LockContention(self)
+        if self.transport.is_readonly():
+            raise UnlockableTransport(self.transport)
+        return self._attempt_lock()
+
+    def wait_lock(self, timeout=None, poll=None, max_attempts=None):
         """Wait a certain period for a lock.
 
         If the lock can be acquired within the bounded time, it
@@ -376,25 +458,41 @@
         is raised.  Either way, this function should return within
         approximately `timeout` seconds.  (It may be a bit more if
         a transport operation takes a long time to complete.)
+
+        :param timeout: Approximate maximum amount of time to wait for the
+        lock, in seconds.
+         
+        :param poll: Delay in seconds between retrying the lock.
+
+        :param max_attempts: Maximum number of times to try to lock.
+
+        :return: The lock token.
         """
         if timeout is None:
             timeout = _DEFAULT_TIMEOUT_SECONDS
         if poll is None:
             poll = _DEFAULT_POLL_SECONDS
-
-        # XXX: the transport interface doesn't let us guard 
-        # against operations there taking a long time.
+        # XXX: the transport interface doesn't let us guard against operations
+        # there taking a long time, so the total elapsed time or poll interval
+        # may be more than was requested.
         deadline = time.time() + timeout
         deadline_str = None
         last_info = None
+        attempt_count = 0
         while True:
+            attempt_count += 1
             try:
-                self.attempt_lock()
-                return
+                return self.attempt_lock()
             except LockContention:
+                # possibly report the blockage, then try again
                 pass
+            # TODO: In a few cases, we find out that there's contention by
+            # reading the held info and observing that it's not ours.  In
+            # those cases it's a bit redundant to read it again.  However,
+            # the normal case (??) is that the rename fails and so we
+            # don't know who holds the lock.  For simplicity we peek
+            # always.
             new_info = self.peek()
-            mutter('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'
@@ -415,9 +513,14 @@
                                       formatted_info[2],
                                       deadline_str)
 
+            if (max_attempts is not None) and (attempt_count >= max_attempts):
+                self._trace("exceeded %d attempts")
+                raise LockContention(self)
             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 leave_in_place(self):
@@ -450,8 +553,7 @@
             self._locked_via_token = True
             return token
         else:
-            self.wait_lock()
-            return self.peek().get('nonce')
+            return self.wait_lock()
 
     def lock_read(self):
         """Compatibility-mode shared lock.
@@ -468,19 +570,6 @@
             raise LockContention(self)
         self._fake_read_lock = True
 
-    def wait(self, timeout=20, poll=0.5):
-        """Wait a certain period for a lock to be released."""
-        # XXX: the transport interface doesn't let us guard 
-        # against operations there taking a long time.
-        deadline = time.time() + timeout
-        while True:
-            if self.peek():
-                return
-            if time.time() + poll < deadline:
-                time.sleep(poll)
-            else:
-                raise LockContention(self)
-
     def _format_lock_info(self, info):
         """Turn the contents of peek() into something for the user"""
         lock_url = self.transport.abspath(self.path)
@@ -501,4 +590,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-07-03 07:37:11 +0000
+++ b/bzrlib/tests/__init__.py	2007-07-04 09:04:20 +0000
@@ -828,8 +828,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,
@@ -847,8 +847,14 @@
     def assertContainsRe(self, haystack, needle_re):
         """Assert that a contains something matching a regular expression."""
         if not re.search(needle_re, haystack):
-            raise AssertionError('pattern "%r" not found in "%r"'
-                    % (needle_re, haystack))
+            if '\n' in haystack or len(haystack) > 60:
+                # a long string, format it in a more readable way
+                raise AssertionError(
+                        'pattern "%s" not found in\n"""\\\n%s"""\n'
+                        % (needle_re, haystack))
+            else:
+                raise AssertionError('pattern "%s" not found in "%s"'
+                        % (needle_re, haystack))
 
     def assertNotContainsRe(self, haystack, needle_re):
         """Assert that a does not match a regular expression"""

=== 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")

=== modified file 'bzrlib/tests/test_lockdir.py'
--- a/bzrlib/tests/test_lockdir.py	2007-06-12 16:24:23 +0000
+++ b/bzrlib/tests/test_lockdir.py	2007-07-04 09:21:56 +0000
@@ -27,6 +27,7 @@
     errors,
     osutils,
     tests,
+    transport,
     )
 from bzrlib.errors import (
         LockBreakMismatch,
@@ -267,33 +268,6 @@
         self.assertEndsWith(args[3], ' ago')
         self.assertContainsRe(args[4], r'\d\d:\d\d:\d\d')
 
-    def test_33_wait(self):
-        """Succeed when waiting on a lock that gets released
-
-        The difference from test_32_lock_wait_succeed is that the second 
-        caller does not actually acquire the lock, but just waits for it
-        to be released.  This is done over a readonly transport.
-        """
-        t = self.get_transport()
-        lf1 = LockDir(t, 'test_lock')
-        lf1.create()
-        lf1.attempt_lock()
-
-        def wait_and_unlock():
-            time.sleep(0.1)
-            lf1.unlock()
-        unlocker = Thread(target=wait_and_unlock)
-        unlocker.start()
-        try:
-            lf2 = LockDir(self.get_readonly_transport(), 'test_lock')
-            before = time.time()
-            # wait but don't lock
-            lf2.wait(timeout=0.4, poll=0.1)
-            after = time.time()
-            self.assertTrue(after - before <= 1.0)
-        finally:
-            unlocker.join()
-
     def test_34_lock_write_waits(self):
         """LockDir.lock_write() will wait for the lock.""" 
         # the test suite sets the default to 0 to make deadlocks fail fast.
@@ -625,3 +599,45 @@
         os.mkdir(lock_path)
         osutils.make_readonly(lock_path)
         self.assertRaises(errors.PermissionDenied, ld1.attempt_lock)
+
+    def test_lock_by_token(self):
+        ld1 = self.get_lock()
+        token = ld1.lock_write()
+        self.assertNotEqual(None, token)
+        ld2 = self.get_lock()
+        t2 = ld2.lock_write(token)
+        self.assertEqual(token, t2)
+
+    def test_lock_with_buggy_rename(self):
+        # test that lock acquisition handles servers which pretend they
+        # renamed correctly but that actually fail
+        t = transport.get_transport('brokenrename+' + self.get_url())
+        ld1 = LockDir(t, 'test_lock')
+        ld1.create()
+        ld1.attempt_lock()
+        ld2 = LockDir(t, 'test_lock')
+        # we should fail to lock
+        e = self.assertRaises(errors.LockContention, ld2.attempt_lock)
+        # now the original caller should succeed in unlocking
+        ld1.unlock()
+        # and there should be nothing left over
+        self.assertEquals([], t.list_dir('test_lock'))
+
+    def test_failed_lock_leaves_no_trash(self):
+        # if we fail to acquire the lock, we don't leave pending directories
+        # behind -- https://bugs.launchpad.net/bzr/+bug/109169
+        ld1 = self.get_lock()
+        ld2 = self.get_lock()
+        # should be nothing before we start
+        ld1.create()
+        t = self.get_transport().clone('test_lock')
+        def check_dir(a):
+            self.assertEquals(a, t.list_dir('.'))
+        check_dir([])
+        # when held, that's all we see
+        ld1.attempt_lock()
+        check_dir(['held'])
+        # second guy should fail
+        self.assertRaises(errors.LockContention, ld2.attempt_lock)
+        # no kibble
+        check_dir(['held'])

=== modified file 'bzrlib/transport/__init__.py'
--- a/bzrlib/transport/__init__.py	2007-07-03 07:03:32 +0000
+++ b/bzrlib/transport/__init__.py	2007-07-04 09:04:20 +0000
@@ -1257,8 +1257,14 @@
 #              help="This modifier converts any transport to be readonly."
             )
 register_lazy_transport('readonly+', 'bzrlib.transport.readonly', 'ReadonlyTransportDecorator')
+
 register_transport_proto('fakenfs+')
 register_lazy_transport('fakenfs+', 'bzrlib.transport.fakenfs', 'FakeNFSTransportDecorator')
+
+register_transport_proto('brokenrename+')
+register_lazy_transport('brokenrename+', 'bzrlib.transport.brokenrename',
+        'BrokenRenameTransportDecorator')
+
 register_transport_proto('vfat+')
 register_lazy_transport('vfat+',
                         'bzrlib.transport.fakevfat',

=== modified file 'doc/developers/profiling.txt'
--- a/doc/developers/profiling.txt	2007-06-25 06:22:27 +0000
+++ b/doc/developers/profiling.txt	2007-06-27 09:39:45 +0000
@@ -33,3 +33,16 @@
 can get with::
 
   svn co http://codespeak.net/svn/user/arigo/hack/misc/lsprof
+
+
+Profiling locks
+---------------
+
+Bazaar can log when locks are taken or released, which can help in
+identifying unnecessary lock traffic.  This is activated by the ``-Dlock``
+global option.
+
+This writes messages into ~/.bzr.log.
+At present this only logs actions relating to the on-disk lockdir.  It 
+doesn't describe actions on in-memory lock counters, or OS locks (which
+are used for dirstate.)




More information about the bazaar-commits mailing list