Hello,
I am not certain if I understand the .enable() and .disable() methods
correctly, but it seems like they should make a profiling object stop
collecting profiling information. When I run the below python program,
I am seeing results that I am not expecting. If anyone has insight
into why my expectations and reality are not meeting up (just with
regards to the below program, not all my hopes and dreams), I would be
happy to hear them.
--------------------------------------------------- Begin Example Code
from cProfile import *
from pstats import *
p=Profile()
def foo():
a=[]
for i in xrange(1000):
bar()
a.append(i)
#print a
def bar():
d={}
a=[]
p.disable()
for i in xrange(1000):
d[i]=[i+1]
a.append(i)
p.enable()
def main():
p.run("foo()")
#p.print_stats()
p.dump_stats("foo.prof")
s=Stats("foo.prof")
s.print_stats()
s.print_callers()
if __name__ == "__main__":
main()
--------------------------------------------------- End Example Code
OK, so I want to profile the a.append(i) within foo, and not profile
the a.append(i) within bar. Here are the results I receive:
--------------------------------------------------- Begin Results for Example
[EMAIL PROTECTED] ~/spider_project $ ./profiler_tester.py
Mon Oct 20 20:13:51 2008 foo.prof
3003 function calls in 0.002 CPU seconds
Random listing order was used
ncalls tottime percall cumtime percall filename:lineno(function)
1000 0.001 0.000 0.001 0.000 ./profiler_tester.py:18(bar)
1000 0.000 0.000 0.000 0.000 {method 'append' of
'list' objects}
1001 0.000 0.000 0.000 0.000 {method 'disable' of
'_lsprof.Profiler' objects}
1 0.000 0.000 0.000 0.000 ./profiler_tester.py:11(foo)
1 0.000 0.000 0.000 0.000 <string>:1(<module>)
Random listing order was used
Function was called by...
ncalls tottime cumtime
./profiler_tester.py:18(bar) <- 1 0.000
0.000 ./profiler_tester.py:11(foo)
{method 'append' of 'list' objects} <-
{method 'disable' of '_lsprof.Profiler' objects} <- 1000 0.000
0.000 ./profiler_tester.py:18(bar)
./profiler_tester.py:11(foo) <- 1 0.000
0.000 <string>:1(<module>)
<string>:1(<module>) <-
--------------------------------------------------- End Results for Example
The results from s.print_stats() look OK. 1000 calls to append. This
makes sense, since foo is calling it 1000 times. However, when we look
at the s.print_callers() I become confused by append. The data for
append looks like it is missing.
When I comment out the disable and enable profiling commands, I get
what I am expecting:
--------------------------------------------------- Begin Results for
Commented Out disable and enable
Mon Oct 20 20:21:33 2008 foo.prof
1002003 function calls in 1.243 CPU seconds
Random listing order was used
ncalls tottime percall cumtime percall filename:lineno(function)
1000 0.895 0.001 1.153 0.001 ./profiler_tester.py:18(bar)
1001000 0.258 0.000 0.258 0.000 {method 'append' of
'list' objects}
1 0.000 0.000 0.000 0.000 {method 'disable' of
'_lsprof.Profiler' objects}
1 0.089 0.089 1.243 1.243 ./profiler_tester.py:11(foo)
1 0.000 0.000 1.243 1.243 <string>:1(<module>)
Random listing order was used
Function was called by...
ncalls tottime cumtime
./profiler_tester.py:18(bar) <- 1000 0.895
1.153 ./profiler_tester.py:11(foo)
{method 'append' of 'list' objects} <- 1000 0.000
0.000 ./profiler_tester.py:11(foo)
1000000 0.258
0.258 ./profiler_tester.py:18(bar)
{method 'disable' of '_lsprof.Profiler' objects} <-
./profiler_tester.py:11(foo) <- 1 0.089
1.243 <string>:1(<module>)
<string>:1(<module>) <-
--------------------------------------------------- End Results for
Commend Out disable and enable
So, when I avoid using enable or disable, the results from everything
look like what we are expecting.
Am I doing something wrong (or excepting something wrong), or is
cProfile doing something wrong?
Thanks,
-Brian J. Stinar-
--
http://mail.python.org/mailman/listinfo/python-list
