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
|
import os
import time
import logging
from os import mkdir
from os.path import dirname, join, abspath, exists
from itertools import izip, islice
from inspect import getargspec
import cherrypy
from cherrypy.lib import profiler
prof_dir = abspath(cherrypy.config.get('server.profile_dir', 'profile'))
prof_on = cherrypy.config.get('server.profile_on', False)
if prof_on and not exists(prof_dir):
mkdir(prof_dir)
__PROFILES = {}
def to_kw(func, args, kw):
argnames, defaults = getargspec(func)[::3]
defaults = defaults or []
kw = kw.copy()
kv = zip(islice(argnames, 0, len(argnames) - len(defaults)), args)
kw.update(kv)
return args[len(argnames)-len(defaults):], kw
_RPCTIME = 0
def profile(name, log=[], cb=None):
"""
Profile decorator.
@param name: name for the profile (should be unique)og
@param log: list of argument name to be logged, for var args give
index value, will be logger in sequence
@param cb: callback to be used to log custom message then from args
>>> @profile("my_say", log=[0, 2, 'something', 'format'])
>>> def say(what, something, tosay, format=None, *args):
>>> ...
"""
logger = logging.getLogger(name)
logger.setLevel(logging.INFO)
handler = logging.FileHandler(join(prof_dir, name + '.log'))
logger.addHandler(handler)
formatter = logging.Formatter("%(time)10.3f %(rpctime)10.3f %(efftime)10.3f -- %(message)s")
handler.setFormatter(formatter)
def message(fn, *args, **kw):
if callable(cb):
return "%s" % cb(*args, **kw)
_a, kw = to_kw(fn, args, kw)
res = []
for n in log:
if isinstance(n, int):
try:
res.append("%s" % args[n])
except:
pass
else:
res.append("%s=%s" % (n, kw.get(n)))
return ", ".join(res)
def wrapper(func):
def func_wrapper(*args, **kw):
global _RPCTIME
rt = _RPCTIME
t1 = time.time()
res = func(*args, **kw)
t2 = time.time()
t = t2 - t1
if name == "rpc.execute":
_RPCTIME += t
rt2 = _RPCTIME
rt = rt2 - rt
dct = dict(time=t, rpctime=rt, efftime=t-rt)
logger.info(message(func, *args, **kw), extra=dct)
return res
func_wrapper.__name__ = func.__name__
func_wrapper.__doc__ = func.__doc__
func_wrapper.__dict__ = func.__dict__.copy()
func_wrapper.__module__ = func.__module__
return func_wrapper
return wrapper
if not prof_on:
def profile(*args, **kw):
return lambda f: f
class ProfileViewer(object):
def statfiles(self):
if not exists(prof_dir): return []
return [f for f in os.listdir(prof_dir) if f.endswith(".log")]
def index(self):
return """<html>
<head><title>Profile Information</title></head>
<frameset cols='200, 1*'>
<frame src='menu' />
<frame name='main' src=''/>
</frameset>
</html>
"""
index.exposed = True
def menu(self):
yield "<h2>Profiling logs</h2>"
yield "<p>Click on one of the log below to see profiling data.</p>"
runs = self.statfiles()
runs.sort()
for i in runs:
yield "<a href='report?filename=%s' target='main'>%s</a><br />" % (i, i[:-4])
pass
menu.exposed = True
def report(self, filename):
import cherrypy
cherrypy.response.headers['Content-Type'] = 'text/plain'
yield "%10s %10s %10s\n%s\n" % ('time', 'rpctime', 'efftime', ('-' * 33))
yield open(join(prof_dir, filename)).read()
report.exposed = True
profile.profiler = ProfileViewer()
__builtins__['profile'] = profile
|