blob: fdbd542c73d327993181eeaa4efc035126653c5c [file] [log] [blame]
Georg Brandl5a6cfee2008-02-02 11:46:07 +00001import sys
2import cProfile
3import pstats
4import test.test_support
5
6#################################
7# Warning!
8# This stuff is touchy. If you modify anything above the test_main function,
9# you'll have to regenerate the stats for the doctest!
10################################
11
12TICKS = 42000
13
14def timer():
15 return TICKS
16
17def testfunc():
18 # 1 call
19 # 1000 ticks total: 270 ticks local, 730 ticks in subfunctions
20 global TICKS
21 TICKS += 99
22 helper() # 300
23 helper() # 300
24 TICKS += 171
25 factorial(14) # 130
26
27def factorial(n):
28 # 23 calls total
29 # 170 ticks total, 150 ticks local
30 # 3 primitive calls, 130, 20 and 20 ticks total
31 # including 116, 17, 17 ticks local
32 global TICKS
33 if n > 0:
34 TICKS += n
35 return mul(n, factorial(n-1))
36 else:
37 TICKS += 11
38 return 1
39
40def mul(a, b):
41 # 20 calls
42 # 1 tick, local
43 global TICKS
44 TICKS += 1
45 return a * b
46
47def helper():
48 # 2 calls
49 # 300 ticks total: 20 ticks local, 260 ticks in subfunctions
50 global TICKS
51 TICKS += 1
52 helper1() # 30
53 TICKS += 2
54 helper1() # 30
55 TICKS += 6
56 helper2() # 50
57 TICKS += 3
58 helper2() # 50
59 TICKS += 2
60 helper2() # 50
61 TICKS += 5
62 helper2_indirect() # 70
63 TICKS += 1
64
65def helper1():
66 # 4 calls
67 # 30 ticks total: 29 ticks local, 1 tick in subfunctions
68 global TICKS
69 TICKS += 10
70 hasattr(C(), "foo") # 1
71 TICKS += 19
72 lst = []
73 lst.append(42) # 0
74 sys.exc_info() # 0
75
76def helper2_indirect():
77 helper2() # 50
78 factorial(3) # 20
79
80def helper2():
81 # 8 calls
82 # 50 ticks local: 39 ticks local, 11 ticks in subfunctions
83 global TICKS
84 TICKS += 11
85 hasattr(C(), "bar") # 1
86 TICKS += 13
87 subhelper() # 10
88 TICKS += 15
89
90def subhelper():
91 # 8 calls
92 # 10 ticks total: 8 ticks local, 2 ticks in subfunctions
93 global TICKS
94 TICKS += 2
95 for i in range(2): # 0
96 try:
97 C().foo # 1 x 2
98 except AttributeError:
99 TICKS += 3 # 3 x 2
100
101class C:
102 def __getattr__(self, name):
103 # 28 calls
104 # 1 tick, local
105 global TICKS
106 TICKS += 1
107 raise AttributeError
108
109def test_main():
110 """
111 >>> prof = cProfile.Profile(timer, 0.001)
112 >>> prof.runctx("testfunc()", globals(), locals()) #doctest: +ELLIPSIS
113 <cProfile.Profile object at ...>
114 >>> timer()
115 43000
116 >>> stats = pstats.Stats(prof)
117 >>> stats.strip_dirs().sort_stats("stdname") #doctest: +ELLIPSIS
118 <pstats.Stats ...>
119 >>> stats.print_stats() #doctest: +ELLIPSIS
120 126 function calls (106 primitive calls) in 1.000 CPU seconds
121 <BLANKLINE>
122 Ordered by: standard name
123 <BLANKLINE>
124 ncalls tottime percall cumtime percall filename:lineno(function)
125 1 0.000 0.000 1.000 1.000 <string>:1(<module>)
126 28 0.028 0.001 0.028 0.001 test_cprofile.py:102(__getattr__)
127 1 0.270 0.270 1.000 1.000 test_cprofile.py:17(testfunc)
128 23/3 0.150 0.007 0.170 0.057 test_cprofile.py:27(factorial)
129 20 0.020 0.001 0.020 0.001 test_cprofile.py:40(mul)
130 2 0.040 0.020 0.600 0.300 test_cprofile.py:47(helper)
131 4 0.116 0.029 0.120 0.030 test_cprofile.py:65(helper1)
132 2 0.000 0.000 0.140 0.070 test_cprofile.py:76(helper2_indirect)
133 8 0.312 0.039 0.400 0.050 test_cprofile.py:80(helper2)
134 8 0.064 0.008 0.080 0.010 test_cprofile.py:90(subhelper)
135 12 0.000 0.000 0.012 0.001 {hasattr}
136 4 0.000 0.000 0.000 0.000 {method 'append' of 'list' objects}
137 1 0.000 0.000 0.000 0.000 {method 'disable' of '_lsprof.Profiler' objects}
138 8 0.000 0.000 0.000 0.000 {range}
139 4 0.000 0.000 0.000 0.000 {sys.exc_info}
140 <BLANKLINE>
141 <BLANKLINE>
142 <pstats.Stats instance at ...>
143 >>> stats.print_callers() #doctest: +ELLIPSIS
144 Ordered by: standard name
145 <BLANKLINE>
146 Function was called by...
147 ncalls tottime cumtime
148 <string>:1(<module>) <-
149 test_cprofile.py:102(__getattr__) <- 16 0.016 0.016 test_cprofile.py:90(subhelper)
150 12 0.012 0.012 {hasattr}
151 test_cprofile.py:17(testfunc) <- 1 0.270 1.000 <string>:1(<module>)
152 test_cprofile.py:27(factorial) <- 1 0.014 0.130 test_cprofile.py:17(testfunc)
153 20/3 0.130 0.147 test_cprofile.py:27(factorial)
154 2 0.006 0.040 test_cprofile.py:76(helper2_indirect)
155 test_cprofile.py:40(mul) <- 20 0.020 0.020 test_cprofile.py:27(factorial)
156 test_cprofile.py:47(helper) <- 2 0.040 0.600 test_cprofile.py:17(testfunc)
157 test_cprofile.py:65(helper1) <- 4 0.116 0.120 test_cprofile.py:47(helper)
158 test_cprofile.py:76(helper2_indirect) <- 2 0.000 0.140 test_cprofile.py:47(helper)
159 test_cprofile.py:80(helper2) <- 6 0.234 0.300 test_cprofile.py:47(helper)
160 2 0.078 0.100 test_cprofile.py:76(helper2_indirect)
161 test_cprofile.py:90(subhelper) <- 8 0.064 0.080 test_cprofile.py:80(helper2)
162 {hasattr} <- 4 0.000 0.004 test_cprofile.py:65(helper1)
163 8 0.000 0.008 test_cprofile.py:80(helper2)
164 {method 'append' of 'list' objects} <- 4 0.000 0.000 test_cprofile.py:65(helper1)
165 {method 'disable' of '_lsprof.Profiler' objects} <-
166 {range} <- 8 0.000 0.000 test_cprofile.py:90(subhelper)
167 {sys.exc_info} <- 4 0.000 0.000 test_cprofile.py:65(helper1)
168 <BLANKLINE>
169 <BLANKLINE>
170 <pstats.Stats instance at ...>
171 >>> stats.print_callees() #doctest: +ELLIPSIS
172 Ordered by: standard name
173 <BLANKLINE>
174 Function called...
175 ncalls tottime cumtime
176 <string>:1(<module>) -> 1 0.270 1.000 test_cprofile.py:17(testfunc)
177 test_cprofile.py:102(__getattr__) ->
178 test_cprofile.py:17(testfunc) -> 1 0.014 0.130 test_cprofile.py:27(factorial)
179 2 0.040 0.600 test_cprofile.py:47(helper)
180 test_cprofile.py:27(factorial) -> 20/3 0.130 0.147 test_cprofile.py:27(factorial)
181 20 0.020 0.020 test_cprofile.py:40(mul)
182 test_cprofile.py:40(mul) ->
183 test_cprofile.py:47(helper) -> 4 0.116 0.120 test_cprofile.py:65(helper1)
184 2 0.000 0.140 test_cprofile.py:76(helper2_indirect)
185 6 0.234 0.300 test_cprofile.py:80(helper2)
186 test_cprofile.py:65(helper1) -> 4 0.000 0.004 {hasattr}
187 4 0.000 0.000 {method 'append' of 'list' objects}
188 4 0.000 0.000 {sys.exc_info}
189 test_cprofile.py:76(helper2_indirect) -> 2 0.006 0.040 test_cprofile.py:27(factorial)
190 2 0.078 0.100 test_cprofile.py:80(helper2)
191 test_cprofile.py:80(helper2) -> 8 0.064 0.080 test_cprofile.py:90(subhelper)
192 8 0.000 0.008 {hasattr}
193 test_cprofile.py:90(subhelper) -> 16 0.016 0.016 test_cprofile.py:102(__getattr__)
194 8 0.000 0.000 {range}
195 {hasattr} -> 12 0.012 0.012 test_cprofile.py:102(__getattr__)
196 {method 'append' of 'list' objects} ->
197 {method 'disable' of '_lsprof.Profiler' objects} ->
198 {range} ->
199 {sys.exc_info} ->
200 <BLANKLINE>
201 <BLANKLINE>
202 <pstats.Stats instance at ...>
203 """
204 from test import test_cprofile
205 test.test_support.run_doctest(test_cprofile)
206
207if __name__ == "__main__":
208 test_main()