1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
44
45
46
47
48
49
50
51
52
53
54
55
56
57
58
59
60
61
62
63
64
65
66
67
68
69
70
71
72
73
74
75
76
77
78
79
80
81
82
83
84
85
86
87
88
89
90
91
92
93
94
95
96
97
98
99
100
101
102
103
104
105
106
107
108
109
110
111
112
113
114
115
116
117
118
119
120
121
122
123
124
125
126
127
128
129
130
131
132
133
134
135
136
137
138
139
140
141
142
143
144
145
146
147
148
149
150
151
152
153
154
155
|
# Copyright (C) 2008, 2009, 2010 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., 51 Franklin Street, Fifth Floor, Boston, MA 02110-1301 USA
"""Transport decorator that logs transport operations to .bzr.log."""
from __future__ import absolute_import
# 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 import decorator
class TransportLogDecorator(decorator.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.
See also TransportTraceDecorator, that records a machine-readable log in
memory for eg testing.
"""
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):
# We now consume everything from the generator so that we can show
# the results and the time it took to get them. However, to keep
# compatibility with callers that may specifically expect a result
# (see <https://launchpad.net/bugs/340347>) we also return a new
# generator, reset to the starting position.
result = list(result)
return_result = iter(result)
else:
return_result = 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)
# The log decorator no longer shows the elapsed time or transfer rate
# because they're available in the log prefixes and the transport
# activity display respectively.
if False:
elapsed = time.time() - before
if result_len and elapsed > 0:
# this is the rate of higher-level data, not the raw network
# speed using base-10 units (see HACKING.txt).
mutter(" %9.03fs %8dkB/s"
% (elapsed, result_len/elapsed/1000))
else:
mutter(" %9.03fs" % (elapsed))
return 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
def get_test_permutations():
"""Return the permutations to be used in testing."""
from bzrlib.tests import test_server
return [(TransportLogDecorator, test_server.LogDecoratorServer)]
|