PageRenderTime 28ms CodeModel.GetById 20ms app.highlight 4ms RepoModel.GetById 2ms app.codeStats 0ms

/Lib/test/test_profile.py

http://unladen-swallow.googlecode.com/
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()