1 | """Profiling support for unit and performance tests. |
---|
2 | |
---|
3 | These are special purpose profiling methods which operate |
---|
4 | in a more fine-grained way than nose's profiling plugin. |
---|
5 | |
---|
6 | """ |
---|
7 | |
---|
8 | import os, sys |
---|
9 | from sqlalchemy.util import function_named |
---|
10 | import config |
---|
11 | |
---|
12 | __all__ = 'profiled', 'function_call_count', 'conditional_call_count' |
---|
13 | |
---|
14 | all_targets = set() |
---|
15 | profile_config = { 'targets': set(), |
---|
16 | 'report': True, |
---|
17 | 'sort': ('time', 'calls'), |
---|
18 | 'limit': None } |
---|
19 | profiler = None |
---|
20 | |
---|
21 | def profiled(target=None, **target_opts): |
---|
22 | """Optional function profiling. |
---|
23 | |
---|
24 | @profiled('label') |
---|
25 | or |
---|
26 | @profiled('label', report=True, sort=('calls',), limit=20) |
---|
27 | |
---|
28 | Enables profiling for a function when 'label' is targetted for |
---|
29 | profiling. Report options can be supplied, and override the global |
---|
30 | configuration and command-line options. |
---|
31 | """ |
---|
32 | |
---|
33 | # manual or automatic namespacing by module would remove conflict issues |
---|
34 | if target is None: |
---|
35 | target = 'anonymous_target' |
---|
36 | elif target in all_targets: |
---|
37 | print "Warning: redefining profile target '%s'" % target |
---|
38 | all_targets.add(target) |
---|
39 | |
---|
40 | filename = "%s.prof" % target |
---|
41 | |
---|
42 | def decorator(fn): |
---|
43 | def profiled(*args, **kw): |
---|
44 | if (target not in profile_config['targets'] and |
---|
45 | not target_opts.get('always', None)): |
---|
46 | return fn(*args, **kw) |
---|
47 | |
---|
48 | elapsed, load_stats, result = _profile( |
---|
49 | filename, fn, *args, **kw) |
---|
50 | |
---|
51 | report = target_opts.get('report', profile_config['report']) |
---|
52 | if report: |
---|
53 | sort_ = target_opts.get('sort', profile_config['sort']) |
---|
54 | limit = target_opts.get('limit', profile_config['limit']) |
---|
55 | print "Profile report for target '%s' (%s)" % ( |
---|
56 | target, filename) |
---|
57 | |
---|
58 | stats = load_stats() |
---|
59 | stats.sort_stats(*sort_) |
---|
60 | if limit: |
---|
61 | stats.print_stats(limit) |
---|
62 | else: |
---|
63 | stats.print_stats() |
---|
64 | #stats.print_callers() |
---|
65 | os.unlink(filename) |
---|
66 | return result |
---|
67 | return function_named(profiled, fn.__name__) |
---|
68 | return decorator |
---|
69 | |
---|
70 | def function_call_count(count=None, versions={}, variance=0.05): |
---|
71 | """Assert a target for a test case's function call count. |
---|
72 | |
---|
73 | count |
---|
74 | Optional, general target function call count. |
---|
75 | |
---|
76 | versions |
---|
77 | Optional, a dictionary of Python version strings to counts, |
---|
78 | for example:: |
---|
79 | |
---|
80 | { '2.5.1': 110, |
---|
81 | '2.5': 100, |
---|
82 | '2.4': 150 } |
---|
83 | |
---|
84 | The best match for the current running python will be used. |
---|
85 | If none match, 'count' will be used as the fallback. |
---|
86 | |
---|
87 | variance |
---|
88 | An +/- deviation percentage, defaults to 5%. |
---|
89 | """ |
---|
90 | |
---|
91 | # this could easily dump the profile report if --verbose is in effect |
---|
92 | |
---|
93 | version_info = list(sys.version_info) |
---|
94 | py_version = '.'.join([str(v) for v in sys.version_info]) |
---|
95 | |
---|
96 | while version_info: |
---|
97 | version = '.'.join([str(v) for v in version_info]) |
---|
98 | if version in versions: |
---|
99 | count = versions[version] |
---|
100 | break |
---|
101 | version_info.pop() |
---|
102 | |
---|
103 | if count is None: |
---|
104 | return lambda fn: fn |
---|
105 | |
---|
106 | def decorator(fn): |
---|
107 | def counted(*args, **kw): |
---|
108 | try: |
---|
109 | filename = "%s.prof" % fn.__name__ |
---|
110 | |
---|
111 | elapsed, stat_loader, result = _profile( |
---|
112 | filename, fn, *args, **kw) |
---|
113 | |
---|
114 | stats = stat_loader() |
---|
115 | calls = stats.total_calls |
---|
116 | |
---|
117 | stats.sort_stats('calls', 'cumulative') |
---|
118 | stats.print_stats() |
---|
119 | #stats.print_callers() |
---|
120 | deviance = int(count * variance) |
---|
121 | if (calls < (count - deviance) or |
---|
122 | calls > (count + deviance)): |
---|
123 | raise AssertionError( |
---|
124 | "Function call count %s not within %s%% " |
---|
125 | "of expected %s. (Python version %s)" % ( |
---|
126 | calls, (variance * 100), count, py_version)) |
---|
127 | |
---|
128 | return result |
---|
129 | finally: |
---|
130 | if os.path.exists(filename): |
---|
131 | os.unlink(filename) |
---|
132 | return function_named(counted, fn.__name__) |
---|
133 | return decorator |
---|
134 | |
---|
135 | def conditional_call_count(discriminator, categories): |
---|
136 | """Apply a function call count conditionally at runtime. |
---|
137 | |
---|
138 | Takes two arguments, a callable that returns a key value, and a dict |
---|
139 | mapping key values to a tuple of arguments to function_call_count. |
---|
140 | |
---|
141 | The callable is not evaluated until the decorated function is actually |
---|
142 | invoked. If the `discriminator` returns a key not present in the |
---|
143 | `categories` dictionary, no call count assertion is applied. |
---|
144 | |
---|
145 | Useful for integration tests, where running a named test in isolation may |
---|
146 | have a function count penalty not seen in the full suite, due to lazy |
---|
147 | initialization in the DB-API, SA, etc. |
---|
148 | """ |
---|
149 | |
---|
150 | def decorator(fn): |
---|
151 | def at_runtime(*args, **kw): |
---|
152 | criteria = categories.get(discriminator(), None) |
---|
153 | if criteria is None: |
---|
154 | return fn(*args, **kw) |
---|
155 | |
---|
156 | rewrapped = function_call_count(*criteria)(fn) |
---|
157 | return rewrapped(*args, **kw) |
---|
158 | return function_named(at_runtime, fn.__name__) |
---|
159 | return decorator |
---|
160 | |
---|
161 | |
---|
162 | def _profile(filename, fn, *args, **kw): |
---|
163 | global profiler |
---|
164 | if not profiler: |
---|
165 | profiler = 'hotshot' |
---|
166 | if sys.version_info > (2, 5): |
---|
167 | try: |
---|
168 | import cProfile |
---|
169 | profiler = 'cProfile' |
---|
170 | except ImportError: |
---|
171 | pass |
---|
172 | |
---|
173 | if profiler == 'cProfile': |
---|
174 | return _profile_cProfile(filename, fn, *args, **kw) |
---|
175 | else: |
---|
176 | return _profile_hotshot(filename, fn, *args, **kw) |
---|
177 | |
---|
178 | def _profile_cProfile(filename, fn, *args, **kw): |
---|
179 | import cProfile, gc, pstats, time |
---|
180 | |
---|
181 | load_stats = lambda: pstats.Stats(filename) |
---|
182 | gc.collect() |
---|
183 | |
---|
184 | began = time.time() |
---|
185 | cProfile.runctx('result = fn(*args, **kw)', globals(), locals(), |
---|
186 | filename=filename) |
---|
187 | ended = time.time() |
---|
188 | |
---|
189 | return ended - began, load_stats, locals()['result'] |
---|
190 | |
---|
191 | def _profile_hotshot(filename, fn, *args, **kw): |
---|
192 | import gc, hotshot, hotshot.stats, time |
---|
193 | load_stats = lambda: hotshot.stats.load(filename) |
---|
194 | |
---|
195 | gc.collect() |
---|
196 | prof = hotshot.Profile(filename) |
---|
197 | began = time.time() |
---|
198 | prof.start() |
---|
199 | try: |
---|
200 | result = fn(*args, **kw) |
---|
201 | finally: |
---|
202 | prof.stop() |
---|
203 | ended = time.time() |
---|
204 | prof.close() |
---|
205 | |
---|
206 | return ended - began, load_stats, result |
---|
207 | |
---|