← Back to branch summary

~bzr-pqm/bzr/bzr.dev

« back to all changes in this revision

Viewing changes to bzrlib/transport/log.py

[merge] robert's knit-performance work

Show diffs side-by-side

added added

removed removed

Lines of Context:
bzrlib/transport/log.py
1
 
# Copyright (C) 2008, 2009, 2010 Canonical Ltd
2
 
#
3
 
# This program is free software; you can redistribute it and/or modify
4
 
# it under the terms of the GNU General Public License as published by
5
 
# the Free Software Foundation; either version 2 of the License, or
6
 
# (at your option) any later version.
7
 
#
8
 
# This program is distributed in the hope that it will be useful,
9
 
# but WITHOUT ANY WARRANTY; without even the implied warranty of
10
 
# MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.  See the
11
 
# GNU General Public License for more details.
12
 
#
13
 
# You should have received a copy of the GNU General Public License
14
 
# along with this program; if not, write to the Free Software
15
 
# Foundation, Inc., 51 Franklin Street, Fifth Floor, Boston, MA 02110-1301 USA
16
 
 
17
 
"""Transport decorator that logs transport operations to .bzr.log."""
18
 
 
19
 
 
20
 
# see also the transportstats plugin, which gives you some summary information
21
 
# in a machine-readable dump
22
 
 
23
 
import StringIO
24
 
import cStringIO
25
 
import time
26
 
import types
27
 
 
28
 
from bzrlib.trace import mutter
29
 
from bzrlib.transport import decorator
30
 
 
31
 
 
32
 
class TransportLogDecorator(decorator.TransportDecorator):
33
 
    """Decorator for Transports that logs interesting operations to .bzr.log.
34
 
 
35
 
    In general we want to log things that usually take a network round trip
36
 
    and may be slow.
37
 
 
38
 
    Not all operations are logged yet.
39
 
 
40
 
    See also TransportTraceDecorator, that records a machine-readable log in 
41
 
    memory for eg testing.
42
 
    """
43
 
 
44
 
    def __init__(self, *args, **kw):
45
 
        super(TransportLogDecorator, self).__init__(*args, **kw)
46
 
        def _make_hook(hookname):
47
 
            def _hook(relpath, *args, **kw):
48
 
                return self._log_and_call(hookname, relpath, *args, **kw)
49
 
            return _hook
50
 
        for methodname in (
51
 
            'append_bytes',
52
 
            'append_file',
53
 
            'copy_to',
54
 
            'delete',
55
 
            'get',
56
 
            'has',
57
 
            'open_write_stream',
58
 
            'mkdir',
59
 
            'move',
60
 
            'put_bytes', 'put_bytes_non_atomic', 'put_file put_file_non_atomic',
61
 
            'list_dir', 'lock_read', 'lock_write',
62
 
            'readv', 'rename', 'rmdir',
63
 
            'stat',
64
 
            'ulock',
65
 
            ):
66
 
            setattr(self, methodname, _make_hook(methodname))
67
 
 
68
 
    @classmethod
69
 
    def _get_url_prefix(self):
70
 
        return 'log+'
71
 
 
72
 
    def iter_files_recursive(self):
73
 
        # needs special handling because it does not have a relpath parameter
74
 
        mutter("%s %s"
75
 
            % ('iter_files_recursive', self._decorated.base))
76
 
        return self._call_and_log_result('iter_files_recursive', (), {})
77
 
 
78
 
    def _log_and_call(self, methodname, relpath, *args, **kwargs):
79
 
        if kwargs:
80
 
            kwargs_str = dict(kwargs)
81
 
        else:
82
 
            kwargs_str = ''
83
 
        mutter("%s %s %s %s"
84
 
               % (methodname, self._decorated.abspath(relpath),
85
 
                  self._shorten(self._strip_tuple_parens(args)),
86
 
                  kwargs_str))
87
 
        return self._call_and_log_result(methodname, (relpath,) + args, kwargs)
88
 
 
89
 
    def _call_and_log_result(self, methodname, args, kwargs):
90
 
        before = time.time()
91
 
        try:
92
 
            result = getattr(self._decorated, methodname)(*args, **kwargs)
93
 
        except Exception, e:
94
 
            mutter("  --> %s" % e)
95
 
            mutter("      %.03fs" % (time.time() - before))
96
 
            raise
97
 
        return self._show_result(before, methodname, result)
98
 
 
99
 
    def _show_result(self, before, methodname, result):
100
 
        result_len = None
101
 
        if isinstance(result, types.GeneratorType):
102
 
            # We now consume everything from the generator so that we can show
103
 
            # the results and the time it took to get them.  However, to keep
104
 
            # compatibility with callers that may specifically expect a result
105
 
            # (see <https://launchpad.net/bugs/340347>) we also return a new
106
 
            # generator, reset to the starting position.
107
 
            result = list(result)
108
 
            return_result = iter(result)
109
 
        else:
110
 
            return_result = result
111
 
        if isinstance(result, (cStringIO.OutputType, StringIO.StringIO)):
112
 
            val = repr(result.getvalue())
113
 
            result_len = len(val)
114
 
            shown_result = "%s(%s) (%d bytes)" % (result.__class__.__name__,
115
 
                self._shorten(val), result_len)
116
 
        elif methodname == 'readv':
117
 
            num_hunks = len(result)
118
 
            total_bytes = sum((len(d) for o,d in result))
119
 
            shown_result = "readv response, %d hunks, %d total bytes" % (
120
 
                num_hunks, total_bytes)
121
 
            result_len = total_bytes
122
 
        else:
123
 
            shown_result = self._shorten(self._strip_tuple_parens(result))
124
 
        mutter("  --> %s" % shown_result)
125
 
        # The log decorator no longer shows the elapsed time or transfer rate
126
 
        # because they're available in the log prefixes and the transport
127
 
        # activity display respectively.
128
 
        if False:
129
 
            elapsed = time.time() - before
130
 
            if result_len and elapsed > 0:
131
 
                # this is the rate of higher-level data, not the raw network
132
 
                # speed using base-10 units (see HACKING.txt).
133
 
                mutter("      %9.03fs %8dkB/s"
134
 
                       % (elapsed, result_len/elapsed/1000))
135
 
            else:
136
 
                mutter("      %9.03fs" % (elapsed))
137
 
        return return_result
138
 
 
139
 
    def _shorten(self, x):
140
 
        if len(x) > 70:
141
 
            x = x[:67] + '...'
142
 
        return x
143
 
 
144
 
    def _strip_tuple_parens(self, t):
145
 
        t = repr(t)
146
 
        if t[0] == '(' and t[-1] == ')':
147
 
            t = t[1:-1]
148
 
        return t
149
 
 
150
 
 
151
 
def get_test_permutations():
152
 
    """Return the permutations to be used in testing."""
153
 
    from bzrlib.tests import test_server
154
 
    return [(TransportLogDecorator, test_server.LogDecoratorServer)]