1 """Test suite for the profile module.""" 2 3 import sys 4 import pstats 5 import unittest 6 import os 7 from difflib import unified_diff 8 from io import StringIO 9 from test.support import TESTFN, run_unittest, unlink 10 from contextlib import contextmanager 11 12 import profile 13 from test.profilee import testfunc, timer 14 15 16 class ProfileTest(unittest.TestCase): 17 18 profilerclass = profile.Profile 19 profilermodule = profile 20 methodnames = ['print_stats', 'print_callers', 'print_callees'] 21 expected_max_output = ':0(max)' 22 23 def tearDown(self): 24 unlink(TESTFN) 25 26 def get_expected_output(self): 27 return _ProfileOutput 28 29 @classmethod 30 def do_profiling(cls): 31 results = [] 32 prof = cls.profilerclass(timer, 0.001) 33 start_timer = timer() 34 prof.runctx("testfunc()", globals(), locals()) 35 results.append(timer() - start_timer) 36 for methodname in cls.methodnames: 37 s = StringIO() 38 stats = pstats.Stats(prof, stream=s) 39 stats.strip_dirs().sort_stats("stdname") 40 getattr(stats, methodname)() 41 output = s.getvalue().splitlines() 42 mod_name = testfunc.__module__.rsplit('.', 1)[1] 43 # Only compare against stats originating from the test file. 44 # Prevents outside code (e.g., the io module) from causing 45 # unexpected output. 46 output = [line.rstrip() for line in output if mod_name in line] 47 results.append('\n'.join(output)) 48 return results 49 50 def test_cprofile(self): 51 results = self.do_profiling() 52 expected = self.get_expected_output() 53 self.assertEqual(results[0], 1000) 54 fail = [] 55 for i, method in enumerate(self.methodnames): 56 a = expected[method] 57 b = results[i+1] 58 if a != b: 59 fail.append(f"\nStats.{method} output for " 60 f"{self.profilerclass.__name__} " 61 "does not fit expectation:") 62 fail.extend(unified_diff(a.split('\n'), b.split('\n'), 63 lineterm="")) 64 if fail: 65 self.fail("\n".join(fail)) 66 67 def test_calling_conventions(self): 68 # Issue #5330: profile and cProfile wouldn't report C functions called 69 # with keyword arguments. We test all calling conventions. 70 stmts = [ 71 "max([0])", 72 "max([0], key=int)", 73 "max([0], **dict(key=int))", 74 "max(*([0],))", 75 "max(*([0],), key=int)", 76 "max(*([0],), **dict(key=int))", 77 ] 78 for stmt in stmts: 79 s = StringIO() 80 prof = self.profilerclass(timer, 0.001) 81 prof.runctx(stmt, globals(), locals()) 82 stats = pstats.Stats(prof, stream=s) 83 stats.print_stats() 84 res = s.getvalue() 85 self.assertIn(self.expected_max_output, res, 86 "Profiling {0!r} didn't report max:\n{1}".format(stmt, res)) 87 88 def test_run(self): 89 with silent(): 90 self.profilermodule.run("int('1')") 91 self.profilermodule.run("int('1')", filename=TESTFN) 92 self.assertTrue(os.path.exists(TESTFN)) 93 94 def test_runctx(self): 95 with silent(): 96 self.profilermodule.runctx("testfunc()", globals(), locals()) 97 self.profilermodule.runctx("testfunc()", globals(), locals(), 98 filename=TESTFN) 99 self.assertTrue(os.path.exists(TESTFN)) 100 101 102 def regenerate_expected_output(filename, cls): 103 filename = filename.rstrip('co') 104 print('Regenerating %s...' % filename) 105 results = cls.do_profiling() 106 107 newfile = [] 108 with open(filename, 'r') as f: 109 for line in f: 110 newfile.append(line) 111 if line.startswith('#--cut'): 112 break 113 114 with open(filename, 'w') as f: 115 f.writelines(newfile) 116 f.write("_ProfileOutput = {}\n") 117 for i, method in enumerate(cls.methodnames): 118 f.write('_ProfileOutput[%r] = """\\\n%s"""\n' % ( 119 method, results[i+1])) 120 f.write('\nif __name__ == "__main__":\n main()\n') 121 122 @contextmanager 123 def silent(): 124 stdout = sys.stdout 125 try: 126 sys.stdout = StringIO() 127 yield 128 finally: 129 sys.stdout = stdout 130 131 def test_main(): 132 run_unittest(ProfileTest) 133 134 def main(): 135 if '-r' not in sys.argv: 136 test_main() 137 else: 138 regenerate_expected_output(__file__, ProfileTest) 139 140 141 # Don't remove this comment. Everything below it is auto-generated. 142 #--cut-------------------------------------------------------------------------- 143 _ProfileOutput = {} 144 _ProfileOutput['print_stats'] = """\ 145 28 27.972 0.999 27.972 0.999 profilee.py:110(__getattr__) 146 1 269.996 269.996 999.769 999.769 profilee.py:25(testfunc) 147 23/3 149.937 6.519 169.917 56.639 profilee.py:35(factorial) 148 20 19.980 0.999 19.980 0.999 profilee.py:48(mul) 149 2 39.986 19.993 599.830 299.915 profilee.py:55(helper) 150 4 115.984 28.996 119.964 29.991 profilee.py:73(helper1) 151 2 -0.006 -0.003 139.946 69.973 profilee.py:84(helper2_indirect) 152 8 311.976 38.997 399.912 49.989 profilee.py:88(helper2) 153 8 63.976 7.997 79.960 9.995 profilee.py:98(subhelper)""" 154 _ProfileOutput['print_callers'] = """\ 155 :0(append) <- profilee.py:73(helper1)(4) 119.964 156 :0(exc_info) <- profilee.py:73(helper1)(4) 119.964 157 :0(hasattr) <- profilee.py:73(helper1)(4) 119.964 158 profilee.py:88(helper2)(8) 399.912 159 profilee.py:110(__getattr__) <- :0(hasattr)(12) 11.964 160 profilee.py:98(subhelper)(16) 79.960 161 profilee.py:25(testfunc) <- <string>:1(<module>)(1) 999.767 162 profilee.py:35(factorial) <- profilee.py:25(testfunc)(1) 999.769 163 profilee.py:35(factorial)(20) 169.917 164 profilee.py:84(helper2_indirect)(2) 139.946 165 profilee.py:48(mul) <- profilee.py:35(factorial)(20) 169.917 166 profilee.py:55(helper) <- profilee.py:25(testfunc)(2) 999.769 167 profilee.py:73(helper1) <- profilee.py:55(helper)(4) 599.830 168 profilee.py:84(helper2_indirect) <- profilee.py:55(helper)(2) 599.830 169 profilee.py:88(helper2) <- profilee.py:55(helper)(6) 599.830 170 profilee.py:84(helper2_indirect)(2) 139.946 171 profilee.py:98(subhelper) <- profilee.py:88(helper2)(8) 399.912""" 172 _ProfileOutput['print_callees'] = """\ 173 :0(hasattr) -> profilee.py:110(__getattr__)(12) 27.972 174 <string>:1(<module>) -> profilee.py:25(testfunc)(1) 999.769 175 profilee.py:110(__getattr__) -> 176 profilee.py:25(testfunc) -> profilee.py:35(factorial)(1) 169.917 177 profilee.py:55(helper)(2) 599.830 178 profilee.py:35(factorial) -> profilee.py:35(factorial)(20) 169.917 179 profilee.py:48(mul)(20) 19.980 180 profilee.py:48(mul) -> 181 profilee.py:55(helper) -> profilee.py:73(helper1)(4) 119.964 182 profilee.py:84(helper2_indirect)(2) 139.946 183 profilee.py:88(helper2)(6) 399.912 184 profilee.py:73(helper1) -> :0(append)(4) -0.004 185 profilee.py:84(helper2_indirect) -> profilee.py:35(factorial)(2) 169.917 186 profilee.py:88(helper2)(2) 399.912 187 profilee.py:88(helper2) -> :0(hasattr)(8) 11.964 188 profilee.py:98(subhelper)(8) 79.960 189 profilee.py:98(subhelper) -> profilee.py:110(__getattr__)(16) 27.972""" 190 191 if __name__ == "__main__": 192 main() 193
