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