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