diff options
| author | Armin Rigo <arigo@tunes.org> | 2006-02-08 12:53:56 (GMT) |
|---|---|---|
| committer | Armin Rigo <arigo@tunes.org> | 2006-02-08 12:53:56 (GMT) |
| commit | a871ef2b3e924f058ec1b0aed7d4c83a546414b7 (patch) | |
| tree | 0f214529cc5f93d06b28e56569d36c1d1ee80996 /Lib/test/output/test_profile | |
| parent | 5eefdca65477bd8d3a408c380323d4af3228a667 (diff) | |
| download | cpython-a871ef2b3e924f058ec1b0aed7d4c83a546414b7.zip cpython-a871ef2b3e924f058ec1b0aed7d4c83a546414b7.tar.gz cpython-a871ef2b3e924f058ec1b0aed7d4c83a546414b7.tar.bz2 | |
Added the cProfile module.
Based on lsprof (patch #1212837) by Brett Rosen and Ted Czotter.
With further editing by Michael Hudson and myself.
History in svn repo: http://codespeak.net/svn/user/arigo/hack/misc/lsprof
* Module/_lsprof.c is the internal C module, Lib/cProfile.py a wrapper.
* pstats.py updated to display cProfile's caller/callee timings if available.
* setup.py and NEWS updated.
* documentation updates in the profiler section:
- explain the differences between the three profilers that we have now
- profile and cProfile can use a unified documentation, like (c)Pickle
- mention that hotshot is "for specialized usage" now
- removed references to the "old profiler" that no longer exists
* test updates:
- extended test_profile to cover delicate cases like recursion
- added tests for the caller/callee displays
- added test_cProfile, performing the same tests for cProfile
* TO-DO:
- cProfile gives a nicer name to built-in, particularly built-in methods,
which could be backported to profile.
- not tested on Windows recently!
Diffstat (limited to 'Lib/test/output/test_profile')
| -rw-r--r-- | Lib/test/output/test_profile | 78 |
1 files changed, 71 insertions, 7 deletions
diff --git a/Lib/test/output/test_profile b/Lib/test/output/test_profile index e745075..96bd77f 100644 --- a/Lib/test/output/test_profile +++ b/Lib/test/output/test_profile @@ -1,20 +1,84 @@ test_profile - 74 function calls in 1.000 CPU seconds + 127 function calls (107 primitive calls) in 1.000 CPU seconds Ordered by: standard name ncalls tottime percall cumtime percall filename:lineno(function) + 4 0.000 0.000 0.000 0.000 :0(append) + 4 0.000 0.000 0.000 0.000 :0(exc_info) 12 0.000 0.000 0.012 0.001 :0(hasattr) 8 0.000 0.000 0.000 0.000 :0(range) 1 0.000 0.000 0.000 0.000 :0(setprofile) 1 0.000 0.000 1.000 1.000 <string>:1(<module>) 0 0.000 0.000 profile:0(profiler) 1 0.000 0.000 1.000 1.000 profile:0(testfunc()) - 1 0.400 0.400 1.000 1.000 test_profile.py:23(testfunc) - 2 0.080 0.040 0.600 0.300 test_profile.py:32(helper) - 4 0.116 0.029 0.120 0.030 test_profile.py:50(helper1) - 8 0.312 0.039 0.400 0.050 test_profile.py:58(helper2) - 8 0.064 0.008 0.080 0.010 test_profile.py:68(subhelper) - 28 0.028 0.001 0.028 0.001 test_profile.py:80(__getattr__) + 8 0.064 0.008 0.080 0.010 test_profile.py:103(subhelper) + 28 0.028 0.001 0.028 0.001 test_profile.py:115(__getattr__) + 1 0.270 0.270 1.000 1.000 test_profile.py:30(testfunc) + 23/3 0.150 0.007 0.170 0.057 test_profile.py:40(factorial) + 20 0.020 0.001 0.020 0.001 test_profile.py:53(mul) + 2 0.040 0.020 0.600 0.300 test_profile.py:60(helper) + 4 0.116 0.029 0.120 0.030 test_profile.py:78(helper1) + 2 0.000 0.000 0.140 0.070 test_profile.py:89(helper2_indirect) + 8 0.312 0.039 0.400 0.050 test_profile.py:93(helper2) + + + Ordered by: standard name + +Function called... +:0(append) -> +:0(exc_info) -> +:0(hasattr) -> test_profile.py:115(__getattr__)(12) 0.028 +:0(range) -> +:0(setprofile) -> +<string>:1(<module>) -> test_profile.py:30(testfunc)(1) 1.000 +profile:0(profiler) -> profile:0(testfunc())(1) 1.000 +profile:0(testfunc()) -> :0(setprofile)(1) 0.000 + <string>:1(<module>)(1) 1.000 +test_profile.py:103(subhelper) -> :0(range)(8) 0.000 + test_profile.py:115(__getattr__)(16) 0.028 +test_profile.py:115(__getattr__) -> +test_profile.py:30(testfunc) -> test_profile.py:40(factorial)(1) 0.170 + test_profile.py:60(helper)(2) 0.600 +test_profile.py:40(factorial) -> test_profile.py:40(factorial)(20) 0.170 + test_profile.py:53(mul)(20) 0.020 +test_profile.py:53(mul) -> +test_profile.py:60(helper) -> test_profile.py:78(helper1)(4) 0.120 + test_profile.py:89(helper2_indirect)(2) 0.140 + test_profile.py:93(helper2)(6) 0.400 +test_profile.py:78(helper1) -> :0(append)(4) 0.000 + :0(exc_info)(4) 0.000 + :0(hasattr)(4) 0.012 +test_profile.py:89(helper2_indirect) -> test_profile.py:40(factorial)(2) 0.170 + test_profile.py:93(helper2)(2) 0.400 +test_profile.py:93(helper2) -> :0(hasattr)(8) 0.012 + test_profile.py:103(subhelper)(8) 0.080 + + + Ordered by: standard name + +Function was called by... +:0(append) <- test_profile.py:78(helper1)(4) 0.120 +:0(exc_info) <- test_profile.py:78(helper1)(4) 0.120 +:0(hasattr) <- test_profile.py:78(helper1)(4) 0.120 + test_profile.py:93(helper2)(8) 0.400 +:0(range) <- test_profile.py:103(subhelper)(8) 0.080 +:0(setprofile) <- profile:0(testfunc())(1) 1.000 +<string>:1(<module>) <- profile:0(testfunc())(1) 1.000 +profile:0(profiler) <- +profile:0(testfunc()) <- profile:0(profiler)(1) 0.000 +test_profile.py:103(subhelper) <- test_profile.py:93(helper2)(8) 0.400 +test_profile.py:115(__getattr__) <- :0(hasattr)(12) 0.012 + test_profile.py:103(subhelper)(16) 0.080 +test_profile.py:30(testfunc) <- <string>:1(<module>)(1) 1.000 +test_profile.py:40(factorial) <- test_profile.py:30(testfunc)(1) 1.000 + test_profile.py:40(factorial)(20) 0.170 + test_profile.py:89(helper2_indirect)(2) 0.140 +test_profile.py:53(mul) <- test_profile.py:40(factorial)(20) 0.170 +test_profile.py:60(helper) <- test_profile.py:30(testfunc)(2) 1.000 +test_profile.py:78(helper1) <- test_profile.py:60(helper)(4) 0.600 +test_profile.py:89(helper2_indirect) <- test_profile.py:60(helper)(2) 0.600 +test_profile.py:93(helper2) <- test_profile.py:60(helper)(6) 0.600 + test_profile.py:89(helper2_indirect)(2) 0.140 |