profiling.py 11 KB

123456789101112131415161718192021222324252627282930313233343536373839404142434445464748495051525354555657585960616263646566676869707172737475767778798081828384858687888990919293949596979899100101102103104105106107108109110111112113114115116117118119120121122123124125126127128129130131132133134135136137138139140141142143144145146147148149150151152153154155156157158159160161162163164165166167168169170171172173174175176177178179180181182183184185186187188189190191192193194195196197198199200201202203204205206207208209210211212213214215216217218219220221222223224225226227228229230231232233234235236237238239240241242243244245246247248249250251252253254255256257258259260261262263264265266267268269270271272273274275276277278279280281282283284285286287288289290291292293294295296297298299300301302303304305306307308309310311312313314315316317318319320321322323324325326327328329330331332333334335
  1. # testing/profiling.py
  2. # Copyright (C) 2005-2022 the SQLAlchemy authors and contributors
  3. # <see AUTHORS file>
  4. #
  5. # This module is part of SQLAlchemy and is released under
  6. # the MIT License: https://www.opensource.org/licenses/mit-license.php
  7. """Profiling support for unit and performance tests.
  8. These are special purpose profiling methods which operate
  9. in a more fine-grained way than nose's profiling plugin.
  10. """
  11. import collections
  12. import contextlib
  13. import os
  14. import platform
  15. import pstats
  16. import re
  17. import sys
  18. from . import config
  19. from .util import gc_collect
  20. from ..util import has_compiled_ext
  21. try:
  22. import cProfile
  23. except ImportError:
  24. cProfile = None
  25. _profile_stats = None
  26. """global ProfileStatsFileInstance.
  27. plugin_base assigns this at the start of all tests.
  28. """
  29. _current_test = None
  30. """String id of current test.
  31. plugin_base assigns this at the start of each test using
  32. _start_current_test.
  33. """
  34. def _start_current_test(id_):
  35. global _current_test
  36. _current_test = id_
  37. if _profile_stats.force_write:
  38. _profile_stats.reset_count()
  39. class ProfileStatsFile(object):
  40. """Store per-platform/fn profiling results in a file.
  41. There was no json module available when this was written, but now
  42. the file format which is very deterministically line oriented is kind of
  43. handy in any case for diffs and merges.
  44. """
  45. def __init__(self, filename, sort="cumulative", dump=None):
  46. self.force_write = (
  47. config.options is not None and config.options.force_write_profiles
  48. )
  49. self.write = self.force_write or (
  50. config.options is not None and config.options.write_profiles
  51. )
  52. self.fname = os.path.abspath(filename)
  53. self.short_fname = os.path.split(self.fname)[-1]
  54. self.data = collections.defaultdict(
  55. lambda: collections.defaultdict(dict)
  56. )
  57. self.dump = dump
  58. self.sort = sort
  59. self._read()
  60. if self.write:
  61. # rewrite for the case where features changed,
  62. # etc.
  63. self._write()
  64. @property
  65. def platform_key(self):
  66. dbapi_key = config.db.name + "_" + config.db.driver
  67. if config.db.name == "sqlite" and config.db.dialect._is_url_file_db(
  68. config.db.url
  69. ):
  70. dbapi_key += "_file"
  71. # keep it at 2.7, 3.1, 3.2, etc. for now.
  72. py_version = ".".join([str(v) for v in sys.version_info[0:2]])
  73. platform_tokens = [
  74. platform.machine(),
  75. platform.system().lower(),
  76. platform.python_implementation().lower(),
  77. py_version,
  78. dbapi_key,
  79. ]
  80. platform_tokens.append(
  81. "nativeunicode"
  82. if config.db.dialect.convert_unicode
  83. else "dbapiunicode"
  84. )
  85. _has_cext = has_compiled_ext()
  86. platform_tokens.append(_has_cext and "cextensions" or "nocextensions")
  87. return "_".join(platform_tokens)
  88. def has_stats(self):
  89. test_key = _current_test
  90. return (
  91. test_key in self.data and self.platform_key in self.data[test_key]
  92. )
  93. def result(self, callcount):
  94. test_key = _current_test
  95. per_fn = self.data[test_key]
  96. per_platform = per_fn[self.platform_key]
  97. if "counts" not in per_platform:
  98. per_platform["counts"] = counts = []
  99. else:
  100. counts = per_platform["counts"]
  101. if "current_count" not in per_platform:
  102. per_platform["current_count"] = current_count = 0
  103. else:
  104. current_count = per_platform["current_count"]
  105. has_count = len(counts) > current_count
  106. if not has_count:
  107. counts.append(callcount)
  108. if self.write:
  109. self._write()
  110. result = None
  111. else:
  112. result = per_platform["lineno"], counts[current_count]
  113. per_platform["current_count"] += 1
  114. return result
  115. def reset_count(self):
  116. test_key = _current_test
  117. # since self.data is a defaultdict, don't access a key
  118. # if we don't know it's there first.
  119. if test_key not in self.data:
  120. return
  121. per_fn = self.data[test_key]
  122. if self.platform_key not in per_fn:
  123. return
  124. per_platform = per_fn[self.platform_key]
  125. if "counts" in per_platform:
  126. per_platform["counts"][:] = []
  127. def replace(self, callcount):
  128. test_key = _current_test
  129. per_fn = self.data[test_key]
  130. per_platform = per_fn[self.platform_key]
  131. counts = per_platform["counts"]
  132. current_count = per_platform["current_count"]
  133. if current_count < len(counts):
  134. counts[current_count - 1] = callcount
  135. else:
  136. counts[-1] = callcount
  137. if self.write:
  138. self._write()
  139. def _header(self):
  140. return (
  141. "# %s\n"
  142. "# This file is written out on a per-environment basis.\n"
  143. "# For each test in aaa_profiling, the corresponding "
  144. "function and \n"
  145. "# environment is located within this file. "
  146. "If it doesn't exist,\n"
  147. "# the test is skipped.\n"
  148. "# If a callcount does exist, it is compared "
  149. "to what we received. \n"
  150. "# assertions are raised if the counts do not match.\n"
  151. "# \n"
  152. "# To add a new callcount test, apply the function_call_count \n"
  153. "# decorator and re-run the tests using the --write-profiles \n"
  154. "# option - this file will be rewritten including the new count.\n"
  155. "# \n"
  156. ) % (self.fname)
  157. def _read(self):
  158. try:
  159. profile_f = open(self.fname)
  160. except IOError:
  161. return
  162. for lineno, line in enumerate(profile_f):
  163. line = line.strip()
  164. if not line or line.startswith("#"):
  165. continue
  166. test_key, platform_key, counts = line.split()
  167. per_fn = self.data[test_key]
  168. per_platform = per_fn[platform_key]
  169. c = [int(count) for count in counts.split(",")]
  170. per_platform["counts"] = c
  171. per_platform["lineno"] = lineno + 1
  172. per_platform["current_count"] = 0
  173. profile_f.close()
  174. def _write(self):
  175. print(("Writing profile file %s" % self.fname))
  176. profile_f = open(self.fname, "w")
  177. profile_f.write(self._header())
  178. for test_key in sorted(self.data):
  179. per_fn = self.data[test_key]
  180. profile_f.write("\n# TEST: %s\n\n" % test_key)
  181. for platform_key in sorted(per_fn):
  182. per_platform = per_fn[platform_key]
  183. c = ",".join(str(count) for count in per_platform["counts"])
  184. profile_f.write("%s %s %s\n" % (test_key, platform_key, c))
  185. profile_f.close()
  186. def function_call_count(variance=0.05, times=1, warmup=0):
  187. """Assert a target for a test case's function call count.
  188. The main purpose of this assertion is to detect changes in
  189. callcounts for various functions - the actual number is not as important.
  190. Callcounts are stored in a file keyed to Python version and OS platform
  191. information. This file is generated automatically for new tests,
  192. and versioned so that unexpected changes in callcounts will be detected.
  193. """
  194. # use signature-rewriting decorator function so that pytest fixtures
  195. # still work on py27. In Py3, update_wrapper() alone is good enough,
  196. # likely due to the introduction of __signature__.
  197. from sqlalchemy.util import decorator
  198. from sqlalchemy.util import deprecations
  199. from sqlalchemy.engine import row
  200. from sqlalchemy.testing import mock
  201. @decorator
  202. def wrap(fn, *args, **kw):
  203. with mock.patch.object(
  204. deprecations, "SQLALCHEMY_WARN_20", False
  205. ), mock.patch.object(
  206. row.LegacyRow, "_default_key_style", row.KEY_OBJECTS_NO_WARN
  207. ):
  208. for warm in range(warmup):
  209. fn(*args, **kw)
  210. timerange = range(times)
  211. with count_functions(variance=variance):
  212. for time in timerange:
  213. rv = fn(*args, **kw)
  214. return rv
  215. return wrap
  216. @contextlib.contextmanager
  217. def count_functions(variance=0.05):
  218. if cProfile is None:
  219. raise config._skip_test_exception("cProfile is not installed")
  220. if not _profile_stats.has_stats() and not _profile_stats.write:
  221. config.skip_test(
  222. "No profiling stats available on this "
  223. "platform for this function. Run tests with "
  224. "--write-profiles to add statistics to %s for "
  225. "this platform." % _profile_stats.short_fname
  226. )
  227. gc_collect()
  228. pr = cProfile.Profile()
  229. pr.enable()
  230. # began = time.time()
  231. yield
  232. # ended = time.time()
  233. pr.disable()
  234. # s = compat.StringIO()
  235. stats = pstats.Stats(pr, stream=sys.stdout)
  236. # timespent = ended - began
  237. callcount = stats.total_calls
  238. expected = _profile_stats.result(callcount)
  239. if expected is None:
  240. expected_count = None
  241. else:
  242. line_no, expected_count = expected
  243. print(("Pstats calls: %d Expected %s" % (callcount, expected_count)))
  244. stats.sort_stats(*re.split(r"[, ]", _profile_stats.sort))
  245. stats.print_stats()
  246. if _profile_stats.dump:
  247. base, ext = os.path.splitext(_profile_stats.dump)
  248. test_name = _current_test.split(".")[-1]
  249. dumpfile = "%s_%s%s" % (base, test_name, ext or ".profile")
  250. stats.dump_stats(dumpfile)
  251. print("Dumped stats to file %s" % dumpfile)
  252. # stats.print_callers()
  253. if _profile_stats.force_write:
  254. _profile_stats.replace(callcount)
  255. elif expected_count:
  256. deviance = int(callcount * variance)
  257. failed = abs(callcount - expected_count) > deviance
  258. if failed:
  259. if _profile_stats.write:
  260. _profile_stats.replace(callcount)
  261. else:
  262. raise AssertionError(
  263. "Adjusted function call count %s not within %s%% "
  264. "of expected %s, platform %s. Rerun with "
  265. "--write-profiles to "
  266. "regenerate this callcount."
  267. % (
  268. callcount,
  269. (variance * 100),
  270. expected_count,
  271. _profile_stats.platform_key,
  272. )
  273. )