Modified version of Extended Profiling Middleware
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 228 229 230 231 232 233 234 235 236 237 238 239 240 241 242 243 244 245 246 247 248 249 250 251 252 253 254 255 256 257 258 259 260 261 262 263 264 265 266 267 268 269 270 271 272 273 274 275 276 277 278 279 280 281 282 283 284 285 286 287 288 289 290 291 292 293 294 295 296 297 298 299 300 301 302 303 304 305 306 307 308 309 310 311 312 313 314 315 316 | # Original version taken from http://www.djangosnippets.org/snippets/186/
# Original author: udfalkso
# Modified version taken from http://djangosnippets.org/snippets/605/
# Modified by: Shwagroo Team
# Modified further by Doug Stryke
from collections import defaultdict
import pstats
import re
import os
import cProfile
import tempfile
import time
import resource
from django.conf import settings
from django.db import connections
from cStringIO import StringIO
# FIXME change log base to something appropriate for the particular installation
PROFILE_LOG_BASE = '/var/tmp/django'
# FIXME change if needed
DATABASE_CONNECTION = 'default'
time_columns = [
('Middleware time', 'middleware_time'),
('Elapsed time', 'total_time'),
('User cpu', 'utime'),
('System cpu', 'stime'),
('Query time', 'query_time'),
('Query count', 'query_count'),
('Max RSS(kb)', 'max_rss'),
]
time_labels = [col[0] for col in time_columns]
time_fields = [col[1] for col in time_columns]
time_stats = {}
# Django middleware is class-based. The module is imported, the profiling class
# is instantiated, and the instance added to the middleware stack.
# We put this profiling module on both ends of the middleware stack to obtain
# the time spent in middleware. Consequently we have one imported module but
# two instances so most state is maintained at the module level.
_start_time = None
_middleware_start_time = None
_current_stats = None
words_re = re.compile(r'\s+')
group_prefix_re = [
re.compile("^.*/django/[^/]+"),
re.compile("^(.*)/[^/]+$"), # extract module path
re.compile(".*"), # catch strange entries
]
_log_file_path = None
_prof = None
_profile_layer = False
class ProfileMiddleware(object):
"""Displays timing or profiling for any view.
http://yoursite.com/yourview/?time or http://yoursite.com/yourview/?prof
Record the time taken by Django and the project code to generate the web page and by the database to make the
queries. Accumulate repeated web page visits and display the accumulated
statistics in the web browser in place of the normal web page. The availability of this middleware is
controlled by the DEBUG flas in settings.py. To time a page, add '?time' (or '&time'). To clear
out accumulated timings, add '&reset'.
Alternatively, profile the python function calls executed to create the web page and
display the profiling statistics in the web browser. To profile a page,
add '?prof' (or '&prof') to the url. By default the statistics are sorted by cumulative time. To
specify an alternative sort, add one or more 'sort' parameters, e.g.,
'&sort=time&sort=calls'. By default the display is limited to the first 40 function calls. To
specify an alternative, add a limit parameter, e.g., '&limit=.50'. To write the profile data to
a permanent file in `PROFILE_LOG_BASE` add '&log'. To strip the directory paths from the profile
statistics, add '&strip'. (Note that the file and group summaries are also removed by 'strip'.)
"""
def __init__(self):
self._last_uri = None
def process_request(self, request):
global _middleware_start_time, _start_time, _log_file_path, _prof
if settings.DEBUG:
if 'time' in request.GET:
# outer layer of middleware onion
if _middleware_start_time is None:
_middleware_start_time = time.time()
else:
# inner layer of onion
if 'reset' in request.GET:
time_stats.clear()
else:
self._auto_reset_time(request)
_start_time = time.time()
self._start_rusage = resource.getrusage(resource.RUSAGE_SELF)
elif 'prof' in request.GET:
if _prof is None:
_prof = cProfile.Profile()
if 'log' in request.GET and _log_file_path is None:
_log_file_path = get_log_file_path('middleware.profile', time.gmtime())
def process_view(self, request, callback, callback_args, callback_kwargs):
if settings.DEBUG and ('prof' in request.GET):
return _prof.runcall(callback, request, *callback_args, **callback_kwargs)
def process_response(self, request, response):
global _current_stats, _middleware_start_time, _log_file_path, _profile_layer, _prof
if settings.DEBUG:
if 'time' in request.GET:
if _current_stats is None:
# inner layer of onion
_current_stats = self._collect_time()
else:
# outer layer of onion
_current_stats['middleware_time'] = (time.time() -
_middleware_start_time - _current_stats['total_time'])
self._display_time(request, response)
_middleware_start_time = None
_current_stats = None
elif 'prof' in request.GET:
if _profile_layer:
self._profile(request, response)
_prof = None
_log_file_path = None
_profile_layer = False
else:
_profile_layer = True
return response
# detect when we start timing a different page and auto-reset stats
# (another option would be to maintain separate stats)
def _auto_reset_time(self, request):
uri = self._get_real_uri(request)
if self._last_uri is None:
self._last_uri = uri
else:
if uri != self._last_uri:
time_stats.clear()
self._last_uri = uri
_reUri = re.compile(r'^(http.+/)[?&]time.*$')
def _get_real_uri(self, request):
uri = request.build_absolute_uri()
m = self._reUri.match(uri)
if m is not None:
return m.group(1)
def _collect_time(self):
# record stats from this request
stats = time_stats.setdefault(_start_time, {})
stats['total_time'] = (time.time() - _start_time)
self._end_rusage = resource.getrusage(resource.RUSAGE_SELF)
stats['max_rss'] = self._end_rusage.ru_maxrss
stats['utime'] = self._elapsed_ru('ru_utime')
stats['stime'] = self._elapsed_ru('ru_stime')
queries = connections['DATABASE_CONNECTION'].queries
stats['query_time'] = sum([float(query['time']) for query in queries])
stats['query_count'] = len(queries)
return stats
def _display_time(self, request, response):
# display all stats since last reset
stats_str = "%-4s %-24s %13s %14s %10s %12s %12s %12s %12s\n" % tuple(
['Req', 'Start time'] + time_labels)
count = 0
mins = defaultdict(int)
sums = defaultdict(int)
maxs = defaultdict(int)
values = defaultdict(list)
for start_time in sorted(time_stats.keys()):
stats = time_stats[start_time]
# accumulate times for summary, except for first request
count += 1
for field in time_fields:
mins[field] = min(stats[field], mins.get(field, 99999))
sums[field] += stats[field]
maxs[field] = max(stats[field], maxs[field])
values[field].append(stats[field])
# display line
stats_str += "%-4s %-24s %15.3f %14.3f %10.3f %12.3f %12.3f %12d %12d\n" % tuple(
[count, time.ctime(start_time)] + [stats[field] for field in
time_fields])
# display summary statistics
stats_str += "\n%-4s %-24s %15.3f %14.3f %10.3f %12.3f %12.3f %12d %12d\n" % tuple(
['', 'Minimum'] + [mins[field] for field in time_fields])
stats_str += "%-4s %-24s %15.3f %14.3f %10.3f %12.3f %12.3f %12d %12d\n" % tuple(
['', 'Mean'] + [sums[field] / count for field in time_fields])
stats_str += "%-4s %-24s %15.3f %14.3f %10.3f %12.3f %12.3f %12d %12d\n" % tuple(
['', 'Maximum'] + [maxs[field] for field in time_fields])
if count > 1:
stats_str += "%-4s %-24s %15.3f %14.3f %10.3f %12.3f %12.3f %12d %12d\n" % tuple(
['', 'Standard deviation'] + [stdev(values[field]) for field in time_fields])
if response and response.content and stats_str:
response.content = "<pre>%s\n\noptions: &reset (clear all stats)\n\n%s</pre>" % (request.build_absolute_uri(), stats_str)
def _elapsed_ru(self, name):
return getattr(self._end_rusage, name) - getattr(self._start_rusage, name)
def _profile(self, request, response):
out = StringIO()
if 'log' in request.GET and _log_file_path is not None:
_prof.dump_stats(_log_file_path)
stats = pstats.Stats(_log_file_path, stream=out)
else:
with tempfile.NamedTemporaryFile(dir='/tmp') as temp_file:
_prof.dump_stats(temp_file.name)
stats = pstats.Stats(temp_file.name, stream=out)
_prof.clear()
if 'strip' in request.GET:
stats.strip_dirs()
sorts = request.GET.getlist('sort')
if sorts:
stats.sort_stats(*sorts)
else:
stats.sort_stats('cumulative')
limit = request.GET.get('limit')
if limit is None:
limit = 40
else:
try:
limit = int(limit)
except ValueError:
try:
limit = float(limit)
except ValueError:
pass
stats.print_stats(limit)
stats_str = out.getvalue()
if response and response.content and stats_str:
response.content = "<pre>%s\n\noptions: &log (write data to file) &strip (remove directories) &limit=LIMIT (lines or fraction)\n &sort=KEY (e.g., cumulative (default), time, calls, pcalls, etc.)\n\n%s</pre>" % (request.build_absolute_uri(), stats_str)
if 'strip' not in request.GET:
response.content += self._summary_for_files(stats_str)
def _get_group(self, file_name):
for g in group_prefix_re:
name = g.findall(file_name)
if name:
return name[0]
def _get_summary(self, results_dict, total):
items = [(item[1], item[0]) for item in results_dict.items()]
items.sort(reverse=True)
items = items[:40]
res = " tottime\n"
for item in items:
res += "%4.1f%% %7.3f %s\n" % ( 100 * item[0] / total if total else 0, item[0], item[1] )
return res
def _summary_for_files(self, stats_str):
stats_str = stats_str.split("\n")[8:]
mystats = {}
mygroups = {}
ttl = 0
for s in stats_str:
fields = words_re.split(s)
if len(fields) == 7:
time = float(fields[2])
ttl += time
file_name = fields[6].split(":")[0]
if not file_name in mystats:
mystats[file_name] = 0
mystats[file_name] += time
group = self._get_group(file_name)
if not group in mygroups:
mygroups[group] = 0
mygroups[group] += time
return "<pre>" +\
" ---- By file ----\n\n" + self._get_summary(mystats, ttl) + "\n" +\
" ---- By group ---\n\n" + self._get_summary(mygroups, ttl) +\
"</pre>"
def get_log_file_path(log_file_path, called_time):
if not os.path.isabs(log_file_path):
log_file_path = os.path.join(PROFILE_LOG_BASE, log_file_path)
log_dir_path = os.path.dirname(log_file_path)
try:
os.makedirs(log_dir_path)
except os.error:
pass
(base, ext) = os.path.splitext(log_file_path)
base = base + "_" + time.strftime("%Y%m%d-%H%M%S", called_time)
return base + ext
def stdev(x):
"""Calculate mean and standard deviation of data x[]:
mean = {\sum_i x_i \over n}
std = sqrt(\sum_i (x_i - mean)^2 \over n-1)
http://www.physics.rutgers.edu/~masud/computing/WPark_recipes_in_python.html
"""
from math import sqrt
n, mean, std = len(x), 0, 0
for a in x:
mean += a
mean /= float(n)
for a in x:
std += (a - mean)**2
std = sqrt(std / float(n-1))
return std
|
More like this
- Template tag - list punctuation for a list of items by shapiromatron 8 months, 3 weeks ago
- JSONRequestMiddleware adds a .json() method to your HttpRequests by cdcarter 9 months ago
- Serializer factory with Django Rest Framework by julio 1 year, 3 months ago
- Image compression before saving the new model / work with JPG, PNG by Schleidens 1 year, 4 months ago
- Help text hyperlinks by sa2812 1 year, 5 months ago
Comments
The Green Book is a coffee table book, an encyclopaedic presentation of all the aspects of Green & Sustainability for Green Products, Green Architecture, sustainable design and green buildings.
#
Please login first before commenting.