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