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
156
157
158
159
160
161
162
163
164
165
166
167
168
169
170
171
172
173
174
175
176
177
178
179
180
181
182
183
184
185
186
187
188
189
190
191
192
193
194
195
196
197
198
199
200
201
202
203
204
205
206
207
208
209
210
211
212
213
214
215
216
217
218
219
220
221
222
223
224
225
226
227
|
# (c) 2005 Ian Bicking and contributors; written for Paste (http://pythonpaste.org)
# Licensed under the MIT license: http://www.opensource.org/licenses/mit-license.php
"""
Middleware that profiles the request and displays profiling
information at the bottom of each page.
"""
import sys
import os
import hotshot
import hotshot.stats
import threading
import cgi
import time
from cStringIO import StringIO
from paste import response
__all__ = ['ProfileMiddleware', 'profile_decorator']
class ProfileMiddleware(object):
"""
Middleware that profiles all requests.
All HTML pages will have profiling information appended to them.
The data is isolated to that single request, and does not include
data from previous requests.
This uses the ``hotshot`` module, which affects performance of the
application. It also runs in a single-threaded mode, so it is
only usable in development environments.
"""
style = ('clear: both; background-color: #ff9; color: #000; '
'border: 2px solid #000; padding: 5px;')
def __init__(self, app, global_conf=None,
log_filename='profile.log.tmp',
limit=40):
self.app = app
self.lock = threading.Lock()
self.log_filename = log_filename
self.limit = limit
def __call__(self, environ, start_response):
catch_response = []
body = []
def replace_start_response(status, headers, exc_info=None):
catch_response.extend([status, headers])
start_response(status, headers, exc_info)
return body.append
def run_app():
app_iter = self.app(environ, replace_start_response)
try:
body.extend(app_iter)
finally:
if hasattr(app_iter, 'close'):
app_iter.close()
self.lock.acquire()
try:
prof = hotshot.Profile(self.log_filename)
prof.addinfo('URL', environ.get('PATH_INFO', ''))
try:
prof.runcall(run_app)
finally:
prof.close()
body = ''.join(body)
headers = catch_response[1]
content_type = response.header_value(headers, 'content-type')
if content_type is None or not content_type.startswith('text/html'):
# We can't add info to non-HTML output
return [body]
stats = hotshot.stats.load(self.log_filename)
stats.strip_dirs()
stats.sort_stats('time', 'calls')
output = capture_output(stats.print_stats, self.limit)
output_callers = capture_output(
stats.print_callers, self.limit)
body += '<pre style="%s">%s\n%s</pre>' % (
self.style, cgi.escape(output), cgi.escape(output_callers))
return [body]
finally:
self.lock.release()
def capture_output(func, *args, **kw):
# Not threadsafe! (that's okay when ProfileMiddleware uses it,
# though, since it synchronizes itself.)
out = StringIO()
old_stdout = sys.stdout
sys.stdout = out
try:
func(*args, **kw)
finally:
sys.stdout = old_stdout
return out.getvalue()
def profile_decorator(**options):
"""
Profile a single function call.
Used around a function, like::
@profile_decorator(options...)
def ...
All calls to the function will be profiled. The options are
all keywords, and are:
log_file:
The filename to log to (or ``'stdout'`` or ``'stderr'``).
Default: stderr.
display_limit:
Only show the top N items, default: 20.
sort_stats:
A list of string-attributes to sort on. Default
``('time', 'calls')``.
strip_dirs:
Strip directories/module names from files? Default True.
add_info:
If given, this info will be added to the report (for your
own tracking). Default: none.
log_filename:
The temporary filename to log profiling data to. Default;
``./profile_data.log.tmp``
no_profile:
If true, then don't actually profile anything. Useful for
conditional profiling.
"""
if options.get('no_profile'):
def decorator(func):
return func
return decorator
def decorator(func):
def replacement(*args, **kw):
return DecoratedProfile(func, **options)(*args, **kw)
return replacement
return decorator
class DecoratedProfile(object):
lock = threading.Lock()
def __init__(self, func, **options):
self.func = func
self.options = options
def __call__(self, *args, **kw):
self.lock.acquire()
try:
return self.profile(self.func, *args, **kw)
finally:
self.lock.release()
def profile(self, func, *args, **kw):
ops = self.options
prof_filename = ops.get('log_filename', 'profile_data.log.tmp')
prof = hotshot.Profile(prof_filename)
prof.addinfo('Function Call',
self.format_function(func, *args, **kw))
if ops.get('add_info'):
prof.addinfo('Extra info', ops['add_info'])
exc_info = None
try:
start_time = time.time()
try:
result = prof.runcall(func, *args, **kw)
except:
exc_info = sys.exc_info()
end_time = time.time()
finally:
prof.close()
stats = hotshot.stats.load(prof_filename)
os.unlink(prof_filename)
if ops.get('strip_dirs', True):
stats.strip_dirs()
stats.sort_stats(*ops.get('sort_stats', ('time', 'calls')))
display_limit = ops.get('display_limit', 20)
output = capture_output(stats.print_stats, display_limit)
output_callers = capture_output(
stats.print_callers, display_limit)
output_file = ops.get('log_file')
if output_file in (None, 'stderr'):
f = sys.stderr
elif output_file in ('-', 'stdout'):
f = sys.stdout
else:
f = open(output_file, 'a')
f.write('\n%s\n' % ('-'*60))
f.write('Date: %s\n' % time.strftime('%c'))
f.write('Function call: %s\n'
% self.format_function(func, *args, **kw))
f.write('Wall time: %0.2f seconds\n'
% (end_time - start_time))
f.write(output)
f.write(output_callers)
if output_file not in (None, '-', 'stdout', 'stderr'):
f.close()
if exc_info:
# We captured an exception earlier, now we re-raise it
raise exc_info[0], exc_info[1], exc_info[2]
return result
def format_function(self, func, *args, **kw):
args = map(repr, args)
args.extend(
['%s=%r' % (k, v) for k, v in kw.items()])
return '%s(%s)' % (func.__name__, ', '.join(args))
def make_profile_middleware(
app, global_conf,
log_filename='profile.log.tmp',
limit=40):
"""
Wrap the application in a component that will profile each
request. The profiling data is then appended to the output
of each page.
Note that this serializes all requests (i.e., removing
concurrency). Therefore never use this in production.
"""
limit = int(limit)
return ProfileMiddleware(
app, log_filename=log_filename, limit=limit)
|
