~bzr-pqm/bzr/bzr.dev

« back to all changes in this revision

Viewing changes to bzrlib/transport/log.py

(vila) Fix test failures blocking package builds. (Vincent Ladeuil)

Show diffs side-by-side

added added

removed removed

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