[3] | 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 | |
---|