Bazaar

Merge lp:~spiv/bzr/debug-flag-relock into lp:bzr

  1. debug-flag-relock
  2. Merge into bzr.dev
Proposed by Andrew Bennetts
Status: Merged
Merged at revision: not available
Proposed branch: lp:~spiv/bzr/debug-flag-relock
Merge into: lp:bzr
Diff against target: 231 lines
7 files modified
NEWS (+4/-0)
bzrlib/branch.py (+6/-1)
bzrlib/help_topics/en/debug-flags.txt (+5/-3)
bzrlib/lock.py (+21/-0)
bzrlib/remote.py (+6/-2)
bzrlib/repofmt/pack_repo.py (+7/-0)
bzrlib/repository.py (+4/-1)
To merge this branch: bzr merge lp:~spiv/bzr/debug-flag-relock
Reviewer Review Type Date Requested Status
Martin Pool Approve
John A Meinel Approve
Vincent Ladeuil Pending
Review via email: mp+12972@code.launchpad.net

This proposal supersedes a proposal from 2009-10-07.

To post a comment you must log in.
Revision history for this message
Andrew Bennetts (spiv) wrote : Posted in a previous version of this proposal

This is an idea I had while looking at bug 389413. It adds a -Drelock debug flag to make noise about cases where we probably should take more care to just hold one lock rather than locking/unlocking/locking-again.

Here's some sample output:

$ ./bzr diff -c 4148 . -Drelock > /dev/null
BzrBranch7('file:///home/andrew/warthogs/bzr/debug-flag-relock/') was read locked again
CHKInventoryRepository('file:///home/andrew/warthogs/bzr/.bzr/repository/') was read locked again
CHKInventoryRepository('file:///home/andrew/warthogs/bzr/.bzr/repository/') was read locked again
CHKInventoryRepository('file:///home/andrew/warthogs/bzr/.bzr/repository/') was read locked again
BzrBranch7('file:///home/andrew/warthogs/bzr/debug-flag-relock/') was read locked again
CHKInventoryRepository('file:///home/andrew/warthogs/bzr/.bzr/repository/') was read locked again
BzrBranch7('file:///home/andrew/warthogs/bzr/debug-flag-relock/') was read locked again
CHKInventoryRepository('file:///home/andrew/warthogs/bzr/.bzr/repository/') was read locked again
CHKInventoryRepository('file:///home/andrew/warthogs/bzr/.bzr/repository/') was read locked again
CHKInventoryRepository('file:///home/andrew/warthogs/bzr/.bzr/repository/') was read locked again
BzrBranch7('file:///home/andrew/warthogs/bzr/debug-flag-relock/') was read locked again

Hopefully that gives some idea of how much we can improve :)

Possibly we should have a more generic hook point for lock/unlock operations so that tests can assert "object X is only locked once", similar to the existing HPSS effort tests... but this seems cheap and useful. (The existing hook points for lockdir lock_acquired/lock_released would only catch lock_write, not lock_read, so they aren't sufficient for this case.)

Revision history for this message
Martin Pool (mbp) wrote : Posted in a previous version of this proposal

That sounds good.

I think note() may not be the best interface to call because the ui
changes turn it into something more like "display a message to the
user" and you wouldn't want popup dialogs for each hit. But maybe
that's the best one for now and I can change it later.

So I think it's actually an idea for me to add a kind of 'loud mutter'
rather than a change for you.

The duplication is ugly though - I think you should put this into a
(possibly mixed in) base class.

--
Martin <http://launchpad.net/~mbp/>

Revision history for this message
Vincent Ladeuil (vila) wrote : Posted in a previous version of this proposal

More a tweak really.

You lost your 'manner' for --strict-locks in reordering the help messages.

review: Needs Fixing
Revision history for this message
Andrew Bennetts (spiv) wrote :

I've removed the duplication with a mixin, and fixed the 'manner' glitch in debug-flags.txt.

p.s.:
$ ./bzr -Drelock push
BzrBranch7('file:///home/andrew/warthogs/bzr/debug-flag-relock/') was read locked again
CHKInventoryRepository('file:///home/andrew/warthogs/bzr/.bzr/repository/') was read locked again
BzrBranch7('file:///home/andrew/warthogs/bzr/debug-flag-relock/') was read locked again
CHKInventoryRepository('file:///home/andrew/warthogs/bzr/.bzr/repository/') was read locked again
Using saved push location: lp:~spiv/bzr/debug-flag-relock
BzrBranch7('file:///home/andrew/warthogs/bzr/debug-flag-relock/') was read locked again
CHKInventoryRepository('file:///home/andrew/warthogs/bzr/.bzr/repository/') was read locked again
Pushed up to revision 4734.
HPSS calls: 23 (2 vfs) SmartSSHClientMedium(connected=False, username=u'spiv', host='bazaar.launchpad.net', port=None)

Revision history for this message
John A Meinel (jameinel) wrote :

-----BEGIN PGP SIGNED MESSAGE-----
Hash: SHA1

Andrew Bennetts wrote:
> Andrew Bennetts has proposed merging lp:~spiv/bzr/debug-flag-relock into lp:bzr.
>
> Requested reviews:
> Martin Pool (mbp):
> Vincent Ladeuil (vila)
>
>

So do I understand correctly that this is only triggered when an object
*loses* the lock and then re-acquires it?

So doing:

foo.lock_read()
foo.lock_read()
foo.unlock()
foo.unlock()

would not trigger it, but

foo.lock_read()
foo.unlock()
foo.lock_read()
foo.unlock()

would.

I agree that we should probably have a hook, or some sort of mechanism
for testing this, as it is worthwhile to test. Perhaps you could have a
global state in "lock" like our "symbol_versioning.warn" functionality?

 review: approve

Subject to Martin/Vincent's vote, since they reviewed first.

John
=:->
-----BEGIN PGP SIGNATURE-----
Version: GnuPG v1.4.9 (Cygwin)
Comment: Using GnuPG with Mozilla - http://enigmail.mozdev.org/

iEYEARECAAYFAkrMmdwACgkQJdeBCYSNAAPRFwCgrTbQAjq8SDggQnngugjdyEpk
odkAoIaGHnfDPa0nYVkn6zVPgQekcLcS
=UHav
-----END PGP SIGNATURE-----

review: Approve
Revision history for this message
Andrew Bennetts (spiv) wrote :

John A Meinel wrote:
[...]
> So doing:
>
> foo.lock_read()
> foo.lock_read()
> foo.unlock()
> foo.unlock()
>
> would not trigger it, but
>
> foo.lock_read()
> foo.unlock()
> foo.lock_read()
> foo.unlock()
>
> would.

That's correct.

> I agree that we should probably have a hook, or some sort of mechanism
> for testing this, as it is worthwhile to test. Perhaps you could have a
> global state in "lock" like our "symbol_versioning.warn" functionality?

You mean so that tests can assert “X was locked once”, rather than so that
we can test this debug flag? I think that would be nice, but it's probably
best to let whoever writes the first test along those lines (quite possibly
me!) do that refactoring. i.e. I think it's easy to add this sort of thing
later, and that it is best to add this sort of thing when it will actually
be used so we know we got the API right.

-Andrew.

Revision history for this message
Martin Pool (mbp) :
review: Approve

Preview Diff

[H/L] Next/Prev Comment, [J/K] Next/Prev File, [N/P] Next/Prev Hunk
=== modified file 'NEWS'
--- NEWS 2009-10-08 16:15:00 +0000
+++ NEWS 2009-10-08 22:56:11 +0000
@@ -202,6 +202,10 @@
202Internals202Internals
203*********203*********
204204
205* Added ``-Drelock`` debug flag. It will ``note`` a message every time a
206 repository or branch object is unlocked then relocked the same way.
207 (Andrew Bennetts)
208
205* ``BTreeLeafParser.extract_key`` has been tweaked slightly to reduce209* ``BTreeLeafParser.extract_key`` has been tweaked slightly to reduce
206 mallocs while parsing the index (approx 3=>1 mallocs per key read).210 mallocs while parsing the index (approx 3=>1 mallocs per key read).
207 This results in a 10% speedup while reading an index.211 This results in a 10% speedup while reading an index.
208212
=== modified file 'bzrlib/branch.py'
--- bzrlib/branch.py 2009-09-30 07:02:41 +0000
+++ bzrlib/branch.py 2009-10-08 22:56:11 +0000
@@ -49,6 +49,7 @@
49from bzrlib.decorators import needs_read_lock, needs_write_lock, only_raises49from bzrlib.decorators import needs_read_lock, needs_write_lock, only_raises
50from bzrlib.hooks import HookPoint, Hooks50from bzrlib.hooks import HookPoint, Hooks
51from bzrlib.inter import InterObject51from bzrlib.inter import InterObject
52from bzrlib.lock import _RelockDebugMixin
52from bzrlib import registry53from bzrlib import registry
53from bzrlib.symbol_versioning import (54from bzrlib.symbol_versioning import (
54 deprecated_in,55 deprecated_in,
@@ -2079,7 +2080,7 @@
2079 _legacy_formats[0].network_name(), _legacy_formats[0].__class__)2080 _legacy_formats[0].network_name(), _legacy_formats[0].__class__)
20802081
20812082
2082class BzrBranch(Branch):2083class BzrBranch(Branch, _RelockDebugMixin):
2083 """A branch stored in the actual filesystem.2084 """A branch stored in the actual filesystem.
20842085
2085 Note that it's "local" in the context of the filesystem; it doesn't2086 Note that it's "local" in the context of the filesystem; it doesn't
@@ -2131,6 +2132,8 @@
2131 return self.control_files.is_locked()2132 return self.control_files.is_locked()
21322133
2133 def lock_write(self, token=None):2134 def lock_write(self, token=None):
2135 if not self.is_locked():
2136 self._note_lock('w')
2134 # All-in-one needs to always unlock/lock.2137 # All-in-one needs to always unlock/lock.
2135 repo_control = getattr(self.repository, 'control_files', None)2138 repo_control = getattr(self.repository, 'control_files', None)
2136 if self.control_files == repo_control or not self.is_locked():2139 if self.control_files == repo_control or not self.is_locked():
@@ -2146,6 +2149,8 @@
2146 raise2149 raise
21472150
2148 def lock_read(self):2151 def lock_read(self):
2152 if not self.is_locked():
2153 self._note_lock('r')
2149 # All-in-one needs to always unlock/lock.2154 # All-in-one needs to always unlock/lock.
2150 repo_control = getattr(self.repository, 'control_files', None)2155 repo_control = getattr(self.repository, 'control_files', None)
2151 if self.control_files == repo_control or not self.is_locked():2156 if self.control_files == repo_control or not self.is_locked():
21522157
=== modified file 'bzrlib/help_topics/en/debug-flags.txt'
--- bzrlib/help_topics/en/debug-flags.txt 2009-08-20 05:02:45 +0000
+++ bzrlib/help_topics/en/debug-flags.txt 2009-10-08 22:56:11 +0000
@@ -22,16 +22,18 @@
22-Dhttp Trace http connections, requests and responses.22-Dhttp Trace http connections, requests and responses.
23-Dindex Trace major index operations.23-Dindex Trace major index operations.
24-Dknit Trace knit operations.24-Dknit Trace knit operations.
25-Dstrict_locks Trace when OS locks are potentially used in a non-portable
26 manner.
27-Dlock Trace when lockdir locks are taken or released.25-Dlock Trace when lockdir locks are taken or released.
28-Dprogress Trace progress bar operations.26-Dprogress Trace progress bar operations.
29-Dmerge Emit information for debugging merges.27-Dmerge Emit information for debugging merges.
30-Dno_apport Don't use apport to report crashes.28-Dno_apport Don't use apport to report crashes.
31-Dunlock Some errors during unlock are treated as warnings.
32-Dpack Emit information about pack operations.29-Dpack Emit information about pack operations.
30-Drelock Emit a message every time a branch or repository object is
31 unlocked then relocked the same way.
33-Dsftp Trace SFTP internals.32-Dsftp Trace SFTP internals.
34-Dstream Trace fetch streams.33-Dstream Trace fetch streams.
34-Dstrict_locks Trace when OS locks are potentially used in a non-portable
35 manner.
36-Dunlock Some errors during unlock are treated as warnings.
35-DIDS_never Never use InterDifferingSerializer when fetching.37-DIDS_never Never use InterDifferingSerializer when fetching.
36-DIDS_always Always use InterDifferingSerializer to fetch if appropriate38-DIDS_always Always use InterDifferingSerializer to fetch if appropriate
37 for the format, even for non-local fetches.39 for the format, even for non-local fetches.
3840
=== modified file 'bzrlib/lock.py'
--- bzrlib/lock.py 2009-07-31 16:51:48 +0000
+++ bzrlib/lock.py 2009-10-08 22:56:11 +0000
@@ -518,3 +518,24 @@
518# We default to using the first available lock class.518# We default to using the first available lock class.
519_lock_type, WriteLock, ReadLock = _lock_classes[0]519_lock_type, WriteLock, ReadLock = _lock_classes[0]
520520
521
522class _RelockDebugMixin(object):
523 """Mixin support for -Drelock flag.
524
525 Add this as a base class then call self._note_lock with 'r' or 'w' when
526 acquiring a read- or write-lock. If this object was previously locked (and
527 locked the same way), and -Drelock is set, then this will trace.note a
528 message about it.
529 """
530
531 _prev_lock = None
532
533 def _note_lock(self, lock_type):
534 if 'relock' in debug.debug_flags and self._prev_lock == lock_type:
535 if lock_type == 'r':
536 type_name = 'read'
537 else:
538 type_name = 'write'
539 trace.note('%r was %s locked again', self, type_name)
540 self._prev_lock = lock_type
541
521542
=== modified file 'bzrlib/remote.py'
--- bzrlib/remote.py 2009-10-08 01:50:30 +0000
+++ bzrlib/remote.py 2009-10-08 22:56:11 +0000
@@ -619,7 +619,7 @@
619 return self._custom_format._serializer619 return self._custom_format._serializer
620620
621621
622class RemoteRepository(_RpcHelper):622class RemoteRepository(_RpcHelper, lock._RelockDebugMixin):
623 """Repository accessed over rpc.623 """Repository accessed over rpc.
624624
625 For the moment most operations are performed using local transport-backed625 For the moment most operations are performed using local transport-backed
@@ -949,6 +949,7 @@
949 def lock_read(self):949 def lock_read(self):
950 # wrong eventually - want a local lock cache context950 # wrong eventually - want a local lock cache context
951 if not self._lock_mode:951 if not self._lock_mode:
952 self._note_lock('r')
952 self._lock_mode = 'r'953 self._lock_mode = 'r'
953 self._lock_count = 1954 self._lock_count = 1
954 self._unstacked_provider.enable_cache(cache_misses=True)955 self._unstacked_provider.enable_cache(cache_misses=True)
@@ -974,6 +975,7 @@
974975
975 def lock_write(self, token=None, _skip_rpc=False):976 def lock_write(self, token=None, _skip_rpc=False):
976 if not self._lock_mode:977 if not self._lock_mode:
978 self._note_lock('w')
977 if _skip_rpc:979 if _skip_rpc:
978 if self._lock_token is not None:980 if self._lock_token is not None:
979 if token != self._lock_token:981 if token != self._lock_token:
@@ -2082,7 +2084,7 @@
2082 return self._custom_format.supports_set_append_revisions_only()2084 return self._custom_format.supports_set_append_revisions_only()
20832085
20842086
2085class RemoteBranch(branch.Branch, _RpcHelper):2087class RemoteBranch(branch.Branch, _RpcHelper, lock._RelockDebugMixin):
2086 """Branch stored on a server accessed by HPSS RPC.2088 """Branch stored on a server accessed by HPSS RPC.
20872089
2088 At the moment most operations are mapped down to simple file operations.2090 At the moment most operations are mapped down to simple file operations.
@@ -2319,6 +2321,7 @@
2319 def lock_read(self):2321 def lock_read(self):
2320 self.repository.lock_read()2322 self.repository.lock_read()
2321 if not self._lock_mode:2323 if not self._lock_mode:
2324 self._note_lock('r')
2322 self._lock_mode = 'r'2325 self._lock_mode = 'r'
2323 self._lock_count = 12326 self._lock_count = 1
2324 if self._real_branch is not None:2327 if self._real_branch is not None:
@@ -2344,6 +2347,7 @@
23442347
2345 def lock_write(self, token=None):2348 def lock_write(self, token=None):
2346 if not self._lock_mode:2349 if not self._lock_mode:
2350 self._note_lock('w')
2347 # Lock the branch and repo in one remote call.2351 # Lock the branch and repo in one remote call.
2348 remote_tokens = self._remote_lock_write(token)2352 remote_tokens = self._remote_lock_write(token)
2349 self._lock_token, self._repo_lock_token = remote_tokens2353 self._lock_token, self._repo_lock_token = remote_tokens
23502354
=== modified file 'bzrlib/repofmt/pack_repo.py'
--- bzrlib/repofmt/pack_repo.py 2009-09-30 07:02:41 +0000
+++ bzrlib/repofmt/pack_repo.py 2009-10-08 22:56:11 +0000
@@ -73,6 +73,7 @@
73 )73 )
74from bzrlib.trace import (74from bzrlib.trace import (
75 mutter,75 mutter,
76 note,
76 warning,77 warning,
77 )78 )
7879
@@ -2300,6 +2301,9 @@
2300 if self._write_lock_count == 1:2301 if self._write_lock_count == 1:
2301 self._transaction = transactions.WriteTransaction()2302 self._transaction = transactions.WriteTransaction()
2302 if not locked:2303 if not locked:
2304 if 'relock' in debug.debug_flags and self._prev_lock == 'w':
2305 note('%r was write locked again', self)
2306 self._prev_lock = 'w'
2303 for repo in self._fallback_repositories:2307 for repo in self._fallback_repositories:
2304 # Writes don't affect fallback repos2308 # Writes don't affect fallback repos
2305 repo.lock_read()2309 repo.lock_read()
@@ -2312,6 +2316,9 @@
2312 else:2316 else:
2313 self.control_files.lock_read()2317 self.control_files.lock_read()
2314 if not locked:2318 if not locked:
2319 if 'relock' in debug.debug_flags and self._prev_lock == 'r':
2320 note('%r was read locked again', self)
2321 self._prev_lock = 'r'
2315 for repo in self._fallback_repositories:2322 for repo in self._fallback_repositories:
2316 repo.lock_read()2323 repo.lock_read()
2317 self._refresh_data()2324 self._refresh_data()
23182325
=== modified file 'bzrlib/repository.py'
--- bzrlib/repository.py 2009-10-08 01:50:30 +0000
+++ bzrlib/repository.py 2009-10-08 22:56:11 +0000
@@ -50,6 +50,7 @@
50""")50""")
5151
52from bzrlib.decorators import needs_read_lock, needs_write_lock, only_raises52from bzrlib.decorators import needs_read_lock, needs_write_lock, only_raises
53from bzrlib.lock import _RelockDebugMixin
53from bzrlib.inter import InterObject54from bzrlib.inter import InterObject
54from bzrlib.inventory import (55from bzrlib.inventory import (
55 Inventory,56 Inventory,
@@ -856,7 +857,7 @@
856# Repositories857# Repositories
857858
858859
859class Repository(object):860class Repository(_RelockDebugMixin):
860 """Repository holding history for one or more branches.861 """Repository holding history for one or more branches.
861862
862 The repository holds and retrieves historical information including863 The repository holds and retrieves historical information including
@@ -1381,6 +1382,7 @@
1381 locked = self.is_locked()1382 locked = self.is_locked()
1382 result = self.control_files.lock_write(token=token)1383 result = self.control_files.lock_write(token=token)
1383 if not locked:1384 if not locked:
1385 self._note_lock('w')
1384 for repo in self._fallback_repositories:1386 for repo in self._fallback_repositories:
1385 # Writes don't affect fallback repos1387 # Writes don't affect fallback repos
1386 repo.lock_read()1388 repo.lock_read()
@@ -1391,6 +1393,7 @@
1391 locked = self.is_locked()1393 locked = self.is_locked()
1392 self.control_files.lock_read()1394 self.control_files.lock_read()
1393 if not locked:1395 if not locked:
1396 self._note_lock('r')
1394 for repo in self._fallback_repositories:1397 for repo in self._fallback_repositories:
1395 repo.lock_read()1398 repo.lock_read()
1396 self._refresh_data()1399 self._refresh_data()