Rev 3684: (mbp) log+ transport decorator in file:///home/pqm/archives/thelove/bzr/%2Btrunk/
Canonical.com Patch Queue Manager
pqm at pqm.ubuntu.com
Wed Sep 3 10:47:08 BST 2008
At file:///home/pqm/archives/thelove/bzr/%2Btrunk/
------------------------------------------------------------
revno: 3684
revision-id: pqm at pqm.ubuntu.com-20080903094659-lkj3i4hd83d35fov
parent: pqm at pqm.ubuntu.com-20080903083249-e76ygekseh1peidm
parent: mbp at sourcefrog.net-20080903091120-kbv9rv5ocgsavcbx
committer: Canonical.com Patch Queue Manager <pqm at pqm.ubuntu.com>
branch nick: +trunk
timestamp: Wed 2008-09-03 10:46:59 +0100
message:
(mbp) log+ transport decorator
added:
bzrlib/tests/test_transport_log.py test_transport_log.p-20080902041816-vh8x5yt5nvdzvew3-3
bzrlib/transport/log.py log.py-20080902041816-vh8x5yt5nvdzvew3-5
modified:
NEWS NEWS-20050323055033-4e00b5db738777ff
bzrlib/tests/__init__.py selftest.py-20050531073622-8d0e3c8845c97a64
bzrlib/transport/__init__.py transport.py-20050711165921-4978aa7ce1285ad5
bzrlib/transport/http/__init__.py http_transport.py-20050711212304-506c5fd1059ace96
bzrlib/transport/trace.py trace.py-20070828055009-7kt0bbc4t4b92apz-1
------------------------------------------------------------
revno: 3675.1.4
revision-id: mbp at sourcefrog.net-20080903091120-kbv9rv5ocgsavcbx
parent: mbp at sourcefrog.net-20080903075721-2z9xp6ktnporkmtg
parent: pqm at pqm.ubuntu.com-20080903083249-e76ygekseh1peidm
committer: Martin Pool <mbp at sourcefrog.net>
branch nick: transport-logging
timestamp: Wed 2008-09-03 19:11:20 +1000
message:
merge trunk
added:
bzrlib/_readdir_py.py readdir.py-20060609152855-rm6v321vuaqyh9tu-3
bzrlib/_readdir_pyx.pyx readdir.pyx-20060609152855-rm6v321vuaqyh9tu-1
bzrlib/readdir.h readdir.h-20060609152855-rm6v321vuaqyh9tu-2
modified:
.bzrignore bzrignore-20050311232317-81f7b71efa2db11a
NEWS NEWS-20050323055033-4e00b5db738777ff
bzrlib/_dirstate_helpers_c.pyx dirstate_helpers.pyx-20070503201057-u425eni465q4idwn-3
bzrlib/_dirstate_helpers_py.py _dirstate_helpers_py-20070710145033-90nz6cqglsk150jy-1
bzrlib/benchmarks/bench_osutils.py bench_osutils.py-20060608153714-apso8cyz1bu2z1ig-1
bzrlib/branch.py branch.py-20050309040759-e4baf4e0d046576e
bzrlib/bzrdir.py bzrdir.py-20060131065624-156dfea39c4387cb
bzrlib/errors.py errors.py-20050309040759-20512168c4e14fbd
bzrlib/index.py index.py-20070712131115-lolkarso50vjr64s-1
bzrlib/osutils.py osutils.py-20050309040759-eeaff12fbf77ac86
bzrlib/push.py push.py-20080606021927-5fe39050e8xne9un-1
bzrlib/repofmt/pack_repo.py pack_repo.py-20070813041115-gjv5ma7ktfqwsjgn-1
bzrlib/repository.py rev_storage.py-20051111201905-119e9401e46257e3
bzrlib/tests/blackbox/test_branch.py test_branch.py-20060524161337-noms9gmcwqqrfi8y-1
bzrlib/tests/bzrdir_implementations/test_bzrdir.py test_bzrdir.py-20060131065642-0ebeca5e30e30866
bzrlib/tests/test__dirstate_helpers.py test_dirstate_helper-20070504035751-jsbn00xodv0y1eve-2
bzrlib/tests/test_bzrdir.py test_bzrdir.py-20060131065654-deba40eef51cf220
bzrlib/tests/test_errors.py test_errors.py-20060210110251-41aba2deddf936a8
bzrlib/tests/test_index.py test_index.py-20070712131115-lolkarso50vjr64s-2
bzrlib/tests/test_osutils.py test_osutils.py-20051201224856-e48ee24c12182989
bzrlib/tests/test_pack_repository.py test_pack_repository-20080801043947-eaw0e6h2gu75kwmy-1
bzrlib/transport/__init__.py transport.py-20050711165921-4978aa7ce1285ad5
bzrlib/workingtree.py workingtree.py-20050511021032-29b6ec0a681e02e3
doc/developers/development-repo.txt developmentrepo.txt-20080102200205-raj42k61dch8pjmj-1
setup.py setup.py-20050314065409-02f8a0a6e3f9bc70
------------------------------------------------------------
revno: 3675.1.3
revision-id: mbp at sourcefrog.net-20080903075721-2z9xp6ktnporkmtg
parent: mbp at sourcefrog.net-20080902074413-vmbmhuo0dpitjrvj
committer: Martin Pool <mbp at sourcefrog.net>
branch nick: transport-logging
timestamp: Wed 2008-09-03 17:57:21 +1000
message:
Mention log+ in NEWS
modified:
NEWS NEWS-20050323055033-4e00b5db738777ff
------------------------------------------------------------
revno: 3675.1.2
revision-id: mbp at sourcefrog.net-20080902074413-vmbmhuo0dpitjrvj
parent: mbp at sourcefrog.net-20080902043423-bjnv3wj9fltjvbrj
committer: Martin Pool <mbp at sourcefrog.net>
branch nick: transport-logging
timestamp: Tue 2008-09-02 17:44:13 +1000
message:
log+ decorator needs special handling for iter_files_recursive, which does not take a path
modified:
bzrlib/transport/log.py log.py-20080902041816-vh8x5yt5nvdzvew3-5
------------------------------------------------------------
revno: 3675.1.1
revision-id: mbp at sourcefrog.net-20080902043423-bjnv3wj9fltjvbrj
parent: pqm at pqm.ubuntu.com-20080902030648-j9uoa5awcsjabasf
committer: Martin Pool <mbp at sourcefrog.net>
branch nick: transport-logging
timestamp: Tue 2008-09-02 14:34:23 +1000
message:
Merge and update log+ transport decorator
added:
bzrlib/tests/test_transport_log.py test_transport_log.p-20080902041816-vh8x5yt5nvdzvew3-3
bzrlib/transport/log.py log.py-20080902041816-vh8x5yt5nvdzvew3-5
modified:
bzrlib/tests/__init__.py selftest.py-20050531073622-8d0e3c8845c97a64
bzrlib/transport/__init__.py transport.py-20050711165921-4978aa7ce1285ad5
bzrlib/transport/http/__init__.py http_transport.py-20050711212304-506c5fd1059ace96
bzrlib/transport/trace.py trace.py-20070828055009-7kt0bbc4t4b92apz-1
=== modified file 'NEWS'
--- a/NEWS 2008-09-02 19:46:10 +0000
+++ b/NEWS 2008-09-03 09:11:20 +0000
@@ -23,6 +23,10 @@
IMPROVEMENTS:
+ * A url like ``log+file:///tmp`` will log all access to that Transport
+ to ``.bzr.log``, which may help in debugging or profiling.
+ (Martin Pool)
+
* ``bzr branch`` and ``bzr push`` use the default stacking policy if the
branch format supports it. (Aaron Bentley)
=== modified file 'bzrlib/tests/__init__.py'
--- a/bzrlib/tests/__init__.py 2008-09-01 09:01:24 +0000
+++ b/bzrlib/tests/__init__.py 2008-09-02 04:34:23 +0000
@@ -2868,6 +2868,7 @@
'bzrlib.tests.test_transform',
'bzrlib.tests.test_transport',
'bzrlib.tests.test_transport_implementations',
+ 'bzrlib.tests.test_transport_log',
'bzrlib.tests.test_tree',
'bzrlib.tests.test_treebuilder',
'bzrlib.tests.test_tsort',
=== added file 'bzrlib/tests/test_transport_log.py'
--- a/bzrlib/tests/test_transport_log.py 1970-01-01 00:00:00 +0000
+++ b/bzrlib/tests/test_transport_log.py 2008-09-02 04:34:23 +0000
@@ -0,0 +1,44 @@
+# Copyright (C) 2004, 2005, 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
+# 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
+
+
+"""Tests for log+ transport decorator."""
+
+
+from bzrlib.tests import TestCaseWithMemoryTransport
+from bzrlib.trace import mutter
+from bzrlib.transport import get_transport
+
+
+class TestTransportLog(TestCaseWithMemoryTransport):
+
+ def test_log_transport(self):
+ base_transport = self.get_transport('')
+ logging_transport = get_transport('log+' + base_transport.base)
+
+ # operations such as mkdir are logged
+ mutter('where are you?')
+ logging_transport.mkdir('subdir')
+ self.assertContainsRe(self._get_log(True),
+ r'mkdir memory\+\d+://.*subdir')
+ self.assertContainsRe(self._get_log(True),
+ ' --> None')
+ # they have the expected effect
+ self.assertTrue(logging_transport.has('subdir'))
+ # and they operate on the underlying transport
+ self.assertTrue(base_transport.has('subdir'))
+
+
=== modified file 'bzrlib/transport/__init__.py'
--- a/bzrlib/transport/__init__.py 2008-09-02 05:28:37 +0000
+++ b/bzrlib/transport/__init__.py 2008-09-03 09:11:20 +0000
@@ -1758,6 +1758,9 @@
register_lazy_transport('fakenfs+', 'bzrlib.transport.fakenfs',
'FakeNFSTransportDecorator')
+register_transport_proto('log+')
+register_lazy_transport('log+', 'bzrlib.transport.log', 'TransportLogDecorator')
+
register_transport_proto('trace+')
register_lazy_transport('trace+', 'bzrlib.transport.trace',
'TransportTraceDecorator')
=== modified file 'bzrlib/transport/http/__init__.py'
--- a/bzrlib/transport/http/__init__.py 2008-08-14 02:15:31 +0000
+++ b/bzrlib/transport/http/__init__.py 2008-09-02 04:34:23 +0000
@@ -27,6 +27,7 @@
import sys
from bzrlib import (
+ debug,
errors,
ui,
urlutils,
@@ -230,7 +231,8 @@
# Turn it into a list, we will iterate it several times
coalesced = list(coalesced)
- mutter('http readv of %s offsets => %s collapsed %s',
+ if 'http' in debug.debug_flags:
+ mutter('http readv of %s offsets => %s collapsed %s',
relpath, len(offsets), len(coalesced))
# Cache the data read, but only until it's been used
=== added file 'bzrlib/transport/log.py'
--- a/bzrlib/transport/log.py 1970-01-01 00:00:00 +0000
+++ b/bzrlib/transport/log.py 2008-09-02 07:44:13 +0000
@@ -0,0 +1,157 @@
+# 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 decorator that logs transport operations to .bzr.log."""
+
+
+# see also the transportstats plugin, which gives you some summary information
+# in a machine-readable dump
+
+import StringIO
+import cStringIO
+import time
+import types
+
+from bzrlib.trace import mutter
+from bzrlib.transport.decorator import (
+ TransportDecorator,
+ )
+from bzrlib.transport.trace import (
+ DecoratorServer,
+ TransportTraceDecorator,
+ )
+
+
+
+
+class TransportLogDecorator(TransportDecorator):
+ """Decorator for Transports that logs interesting operations to .bzr.log.
+
+ In general we want to log things that usually take a network round trip
+ and may be slow.
+
+ Not all operations are logged yet.
+ """
+
+ def __init__(self, *args, **kw):
+ super(TransportLogDecorator, self).__init__(*args, **kw)
+ def _make_hook(hookname):
+ def _hook(relpath, *args, **kw):
+ return self._log_and_call(hookname, relpath, *args, **kw)
+ return _hook
+ for methodname in (
+ 'append_bytes',
+ 'append_file',
+ 'copy_to',
+ 'delete',
+ 'get',
+ 'has',
+ 'open_write_stream',
+ 'mkdir',
+ 'move',
+ 'put_bytes', 'put_bytes_non_atomic', 'put_file put_file_non_atomic',
+ 'list_dir', 'lock_read', 'lock_write',
+ 'readv', 'rename', 'rmdir',
+ 'stat',
+ 'ulock',
+ ):
+ setattr(self, methodname, _make_hook(methodname))
+
+ @classmethod
+ def _get_url_prefix(self):
+ return 'log+'
+
+ def iter_files_recursive(self):
+ # needs special handling because it does not have a relpath parameter
+ mutter("%s %s"
+ % ('iter_files_recursive', self._decorated.base))
+ return self._call_and_log_result('iter_files_recursive', (), {})
+
+ def _log_and_call(self, methodname, relpath, *args, **kwargs):
+ if kwargs:
+ kwargs_str = dict(kwargs)
+ else:
+ kwargs_str = ''
+ mutter("%s %s %s %s"
+ % (methodname, self._decorated.abspath(relpath),
+ self._shorten(self._strip_tuple_parens(args)),
+ kwargs_str))
+ return self._call_and_log_result(methodname, (relpath,) + args, kwargs)
+
+ def _call_and_log_result(self, methodname, args, kwargs):
+ before = time.time()
+ try:
+ result = getattr(self._decorated, methodname)(*args, **kwargs)
+ except Exception, e:
+ mutter(" --> %s" % e)
+ mutter(" %.03fs" % (time.time() - before))
+ raise
+ return self._show_result(before, methodname, result)
+
+ def _show_result(self, before, methodname, result):
+ result_len = None
+ if isinstance(result, types.GeneratorType):
+ # eagerly pull in all the contents, so that we can measure how
+ # long it takes to get them. this does make the behaviour a bit
+ # different, but we hope not noticably so
+ result = list(result)
+ if isinstance(result, (cStringIO.OutputType, StringIO.StringIO)):
+ val = repr(result.getvalue())
+ result_len = len(val)
+ shown_result = "%s(%s) (%d bytes)" % (result.__class__.__name__,
+ self._shorten(val), result_len)
+ elif methodname == 'readv':
+ num_hunks = len(result)
+ total_bytes = sum((len(d) for o,d in result))
+ shown_result = "readv response, %d hunks, %d total bytes" % (
+ num_hunks, total_bytes)
+ result_len = total_bytes
+ else:
+ shown_result = self._shorten(self._strip_tuple_parens(result))
+ mutter(" --> %s" % shown_result)
+ # XXX: the time may be wrong when e.g. a generator object is returned from
+ # an http readv, if the object is returned before the bulk data
+ # is read.
+ elapsed = time.time() - before
+ if result_len and elapsed > 0:
+ # this is the rate of higher-level data, not the raw network speed
+ mutter(" %9.03fs %8dkB/s" % (elapsed, result_len/elapsed/1024))
+ else:
+ mutter(" %9.03fs" % (elapsed))
+ return result
+
+ def _shorten(self, x):
+ if len(x) > 70:
+ x = x[:67] + '...'
+ return x
+
+ def _strip_tuple_parens(self, t):
+ t = repr(t)
+ if t[0] == '(' and t[-1] == ')':
+ t = t[1:-1]
+ return t
+
+
+class LogDecoratorServer(DecoratorServer):
+ """Server for testing."""
+
+ def get_decorator_class(self):
+ return TransportLogDecorator
+
+
+def get_test_permutations():
+ """Return the permutations to be used in testing."""
+ return [(TransportLogDecorator, LogDecoratorServer)]
=== modified file 'bzrlib/transport/trace.py'
--- a/bzrlib/transport/trace.py 2008-07-04 06:05:10 +0000
+++ b/bzrlib/transport/trace.py 2008-09-02 04:34:23 +0000
@@ -33,10 +33,6 @@
Not all operations are logged at this point, if you need an unlogged
operation please add a test to the tests of this transport, for the logging
of the operation you want logged.
-
- Another future enhancement would be to log to bzrlib.trace.mutter when
- trace+ is used from the command line (or perhaps as well/instead use
- -Dtransport), to make tracing operations of the entire program easily.
"""
def __init__(self, url, _decorated=None, _from_transport=None):
@@ -76,7 +72,7 @@
def get(self, relpath):
"""See Transport.get()."""
- self._activity.append(('get', relpath))
+ self._trace(('get', relpath))
return self._decorated.get(relpath)
def get_smart_client(self):
@@ -92,6 +88,7 @@
def mkdir(self, relpath, mode=None):
"""See Transport.mkdir()."""
+ self._trace(('mkdir', relpath, mode))
return self._decorated.mkdir(relpath, mode)
def open_write_stream(self, relpath, mode=None):
@@ -104,7 +101,7 @@
def put_bytes(self, relpath, bytes, mode=None):
"""See Transport.put_bytes()."""
- self._activity.append(('put_bytes', relpath, len(bytes), mode))
+ self._trace(('put_bytes', relpath, len(bytes), mode))
return self._decorated.put_bytes(relpath, bytes, mode)
def listable(self):
@@ -122,7 +119,7 @@
def readv(self, relpath, offsets, adjust_for_latency=False,
upper_limit=None):
"""See Transport.readv."""
- self._activity.append(('readv', relpath, offsets, adjust_for_latency,
+ self._trace(('readv', relpath, offsets, adjust_for_latency,
upper_limit))
return self._decorated.readv(relpath, offsets, adjust_for_latency,
upper_limit)
@@ -151,6 +148,13 @@
"""See Transport.lock_write."""
return self._decorated.lock_write(relpath)
+ def _trace(self, operation_tuple):
+ """Record that a transport operation occured.
+
+ :param operation: Tuple of transport call name and arguments.
+ """
+ self._activity.append(operation_tuple)
+
class TraceServer(DecoratorServer):
"""Server for the TransportTraceDecorator for testing with."""
More information about the bazaar-commits
mailing list