/Lib/test/test_profile.py

http://unladen-swallow.googlecode.com/ · Python · 190 lines · 167 code · 18 blank · 5 comment · 11 complexity · a2fadf34d3c5758f39bcde27887c7f66 MD5 · raw file

  1. """Test suite for the profile module."""
  2. import os
  3. import sys
  4. import pstats
  5. import unittest
  6. from StringIO import StringIO
  7. from test.test_support import run_unittest
  8. import profile
  9. from test.profilee import testfunc, timer
  10. class ProfileTest(unittest.TestCase):
  11. profilerclass = profile.Profile
  12. methodnames = ['print_stats', 'print_callers', 'print_callees']
  13. expected_output = {}
  14. expected_list_sort_output = ':0(sort)'
  15. @classmethod
  16. def do_profiling(cls):
  17. results = []
  18. prof = cls.profilerclass(timer, 0.001)
  19. start_timer = timer()
  20. prof.runctx("testfunc()", globals(), locals())
  21. results.append(timer() - start_timer)
  22. for methodname in cls.methodnames:
  23. s = StringIO()
  24. stats = pstats.Stats(prof, stream=s)
  25. stats.strip_dirs().sort_stats("stdname")
  26. getattr(stats, methodname)()
  27. results.append(s.getvalue())
  28. return results
  29. def test_cprofile(self):
  30. results = self.do_profiling()
  31. self.assertEqual(results[0], 1000)
  32. for i, method in enumerate(self.methodnames):
  33. self.assertEqual(results[i+1], self.expected_output[method],
  34. "Stats.%s output for %s doesn't fit expectation!" %
  35. (method, self.profilerclass.__name__))
  36. def test_calling_conventions(self):
  37. # Issue #5330: profile and cProfile wouldn't report C functions called
  38. # with keyword arguments. We test all calling conventions.
  39. stmts = [
  40. "[].sort()",
  41. "[].sort(reverse=True)",
  42. "[].sort(*(None, None, True))",
  43. "[].sort(**dict(reverse=True))",
  44. ]
  45. for stmt in stmts:
  46. s = StringIO()
  47. prof = self.profilerclass(timer, 0.001)
  48. prof.runctx(stmt, globals(), locals())
  49. stats = pstats.Stats(prof, stream=s)
  50. stats.print_stats()
  51. res = s.getvalue()
  52. self.assertTrue(self.expected_list_sort_output in res,
  53. "Profiling {0!r} didn't report list.sort:\n{1}".format(stmt, res))
  54. def regenerate_expected_output(filename, cls):
  55. filename = filename.rstrip('co')
  56. print 'Regenerating %s...' % filename
  57. results = cls.do_profiling()
  58. newfile = []
  59. with open(filename, 'r') as f:
  60. for line in f:
  61. newfile.append(line)
  62. if line[:6] == '#--cut':
  63. break
  64. with open(filename, 'w') as f:
  65. f.writelines(newfile)
  66. for i, method in enumerate(cls.methodnames):
  67. f.write('%s.expected_output[%r] = """\\\n%s"""\n' % (
  68. cls.__name__, method, results[i+1]))
  69. f.write('\nif __name__ == "__main__":\n main()\n')
  70. def test_main():
  71. run_unittest(ProfileTest)
  72. def main():
  73. if '-r' not in sys.argv:
  74. test_main()
  75. else:
  76. regenerate_expected_output(__file__, ProfileTest)
  77. # Don't remove this comment. Everything below it is auto-generated.
  78. #--cut--------------------------------------------------------------------------
  79. ProfileTest.expected_output['print_stats'] = """\
  80. 128 function calls (108 primitive calls) in 999.747 CPU seconds
  81. Ordered by: standard name
  82. ncalls tottime percall cumtime percall filename:lineno(function)
  83. 1 -0.002 -0.002 999.749 999.749 :0(#@exec)
  84. 4 -0.004 -0.001 -0.004 -0.001 :0(append)
  85. 4 -0.004 -0.001 -0.004 -0.001 :0(exc_info)
  86. 12 -0.024 -0.002 11.964 0.997 :0(hasattr)
  87. 8 -0.008 -0.001 -0.008 -0.001 :0(range)
  88. 1 0.000 0.000 0.000 0.000 :0(setprofile)
  89. 1 -0.002 -0.002 999.751 999.751 <string>:1(<module>)
  90. 0 0.000 0.000 profile:0(profiler)
  91. 1 -0.002 -0.002 999.747 999.747 profile:0(testfunc())
  92. 28 27.972 0.999 27.972 0.999 profilee.py:110(__getattr__)
  93. 1 269.996 269.996 999.753 999.753 profilee.py:25(testfunc)
  94. 23/3 149.937 6.519 169.917 56.639 profilee.py:35(factorial)
  95. 20 19.980 0.999 19.980 0.999 profilee.py:48(mul)
  96. 2 39.986 19.993 599.814 299.907 profilee.py:55(helper)
  97. 4 115.984 28.996 119.964 29.991 profilee.py:73(helper1)
  98. 2 -0.006 -0.003 139.942 69.971 profilee.py:84(helper2_indirect)
  99. 8 311.976 38.997 399.896 49.987 profilee.py:88(helper2)
  100. 8 63.968 7.996 79.944 9.993 profilee.py:98(subhelper)
  101. """
  102. ProfileTest.expected_output['print_callers'] = """\
  103. Ordered by: standard name
  104. Function was called by...
  105. :0(#@exec) <- profile:0(testfunc())(1) 999.747
  106. :0(append) <- profilee.py:73(helper1)(4) 119.964
  107. :0(exc_info) <- profilee.py:73(helper1)(4) 119.964
  108. :0(hasattr) <- profilee.py:73(helper1)(4) 119.964
  109. profilee.py:88(helper2)(8) 399.896
  110. :0(range) <- profilee.py:98(subhelper)(8) 79.944
  111. :0(setprofile) <- profile:0(testfunc())(1) 999.747
  112. <string>:1(<module>) <- :0(#@exec)(1) 999.749
  113. profile:0(profiler) <-
  114. profile:0(testfunc()) <- profile:0(profiler)(1) 0.000
  115. profilee.py:110(__getattr__) <- :0(hasattr)(12) 11.964
  116. profilee.py:98(subhelper)(16) 79.944
  117. profilee.py:25(testfunc) <- <string>:1(<module>)(1) 999.751
  118. profilee.py:35(factorial) <- profilee.py:25(testfunc)(1) 999.753
  119. profilee.py:35(factorial)(20) 169.917
  120. profilee.py:84(helper2_indirect)(2) 139.942
  121. profilee.py:48(mul) <- profilee.py:35(factorial)(20) 169.917
  122. profilee.py:55(helper) <- profilee.py:25(testfunc)(2) 999.753
  123. profilee.py:73(helper1) <- profilee.py:55(helper)(4) 599.814
  124. profilee.py:84(helper2_indirect) <- profilee.py:55(helper)(2) 599.814
  125. profilee.py:88(helper2) <- profilee.py:55(helper)(6) 599.814
  126. profilee.py:84(helper2_indirect)(2) 139.942
  127. profilee.py:98(subhelper) <- profilee.py:88(helper2)(8) 399.896
  128. """
  129. ProfileTest.expected_output['print_callees'] = """\
  130. Ordered by: standard name
  131. Function called...
  132. :0(#@exec) -> <string>:1(<module>)(1) 999.751
  133. :0(append) ->
  134. :0(exc_info) ->
  135. :0(hasattr) -> profilee.py:110(__getattr__)(12) 27.972
  136. :0(range) ->
  137. :0(setprofile) ->
  138. <string>:1(<module>) -> profilee.py:25(testfunc)(1) 999.753
  139. profile:0(profiler) -> profile:0(testfunc())(1) 999.747
  140. profile:0(testfunc()) -> :0(#@exec)(1) 999.749
  141. :0(setprofile)(1) 0.000
  142. profilee.py:110(__getattr__) ->
  143. profilee.py:25(testfunc) -> profilee.py:35(factorial)(1) 169.917
  144. profilee.py:55(helper)(2) 599.814
  145. profilee.py:35(factorial) -> profilee.py:35(factorial)(20) 169.917
  146. profilee.py:48(mul)(20) 19.980
  147. profilee.py:48(mul) ->
  148. profilee.py:55(helper) -> profilee.py:73(helper1)(4) 119.964
  149. profilee.py:84(helper2_indirect)(2) 139.942
  150. profilee.py:88(helper2)(6) 399.896
  151. profilee.py:73(helper1) -> :0(append)(4) -0.004
  152. :0(exc_info)(4) -0.004
  153. :0(hasattr)(4) 11.964
  154. profilee.py:84(helper2_indirect) -> profilee.py:35(factorial)(2) 169.917
  155. profilee.py:88(helper2)(2) 399.896
  156. profilee.py:88(helper2) -> :0(hasattr)(8) 11.964
  157. profilee.py:98(subhelper)(8) 79.944
  158. profilee.py:98(subhelper) -> :0(range)(8) -0.008
  159. profilee.py:110(__getattr__)(16) 27.972
  160. """
  161. if __name__ == "__main__":
  162. main()