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