[pypy-svn] r59535 - pypy/trunk/pypy/module/_lsprof/test
arigo at codespeak.net
arigo at codespeak.net
Thu Oct 30 11:13:18 CET 2008
Author: arigo
Date: Thu Oct 30 11:13:18 2008
New Revision: 59535
Modified:
pypy/trunk/pypy/module/_lsprof/test/test_cprofile.py
Log:
Fix the test to expect built-in function calls,
and to give a readable display of the differences
in case of failure. Still skipped, but at least
now we can start fixing :-)
Modified: pypy/trunk/pypy/module/_lsprof/test/test_cprofile.py
==============================================================================
--- pypy/trunk/pypy/module/_lsprof/test/test_cprofile.py (original)
+++ pypy/trunk/pypy/module/_lsprof/test/test_cprofile.py Thu Oct 30 11:13:18 2008
@@ -113,22 +113,24 @@
res, prof = do_profiling(Profile)
assert res[0] == 1000
- skip("when we reach this point, things seem to work; "
- "but we need to review carefully what we expect as output")
+ skip("XXX FIX ME")
for i, method in enumerate(methodnames):
- if not res[i + 1] == self.expected_output[method]:
- print method
- print res[i + 1]
- print self.expected_output[method]
- one = res[i + 1].split("\n")
- two = self.expected_output[method].split("\n")
- for k in range(len(res[i + 1])):
- if one[k] != two[k]:
- print k
- print one[k]
- print two[k]
- import pdb
- pdb.set_trace()
+ got = res[i + 1]
+ expected = self.expected_output[method]
+ if got != expected:
+ print method, 'differs:'
+ print '---------- GOT: ----------'
+ print got
+ print '---------- EXPECTED: ----------'
+ print expected
+ print '----------'
+ for line1, line2 in zip(got.splitlines(),
+ expected.splitlines()):
+ if line1 != line2:
+ print 'Difference is here:'
+ print ' GOT:', line1.rstrip('\n')
+ print 'EXPECTED:', line2.rstrip('\n')
+ break
assert 0
#assert res[i + 1] == self.expected_output[method]
finally:
@@ -136,79 +138,6 @@
expected_output = {}
expected_output['print_stats'] = """\
- 98 function calls (78 primitive calls) in 1.000 CPU seconds
-
- Ordered by: standard name
-
- ncalls tottime percall cumtime percall filename:lineno(function)
- 1 0.000 0.000 1.000 1.000 <string>:0(<module>)
- 1 0.000 0.000 0.000 0.000 ?:1(<module>)
- 28 0.028 0.001 0.028 0.001 profilee.py:110(__getattr__)
- 1 0.270 0.270 1.000 1.000 profilee.py:25(testfunc)
- 23/3 0.150 0.007 0.170 0.057 profilee.py:35(factorial)
- 20 0.020 0.001 0.020 0.001 profilee.py:48(mul)
- 2 0.040 0.020 0.600 0.300 profilee.py:55(helper)
- 4 0.116 0.029 0.120 0.030 profilee.py:73(helper1)
- 2 0.000 0.000 0.140 0.070 profilee.py:84(helper2_indirect)
- 8 0.312 0.039 0.400 0.050 profilee.py:88(helper2)
- 8 0.064 0.008 0.080 0.010 profilee.py:98(subhelper)
-
-
-"""
-expected_output['print_callers'] = """\
- Ordered by: standard name
-
-Function was called by...
- ncalls tottime cumtime
-<string>:0(<module>) <-
-?:1(<module>) <-
-profilee.py:110(__getattr__) <- 4 0.004 0.004 profilee.py:73(helper1)
- 8 0.008 0.008 profilee.py:88(helper2)
- 16 0.016 0.016 profilee.py:98(subhelper)
-profilee.py:25(testfunc) <- 1 0.270 1.000 <string>:0(<module>)
-profilee.py:35(factorial) <- 1 0.014 0.130 profilee.py:25(testfunc)
- 20/3 0.130 0.147 profilee.py:35(factorial)
- 2 0.006 0.040 profilee.py:84(helper2_indirect)
-profilee.py:48(mul) <- 20 0.020 0.020 profilee.py:35(factorial)
-profilee.py:55(helper) <- 2 0.040 0.600 profilee.py:25(testfunc)
-profilee.py:73(helper1) <- 4 0.116 0.120 profilee.py:55(helper)
-profilee.py:84(helper2_indirect) <- 2 0.000 0.140 profilee.py:55(helper)
-profilee.py:88(helper2) <- 6 0.234 0.300 profilee.py:55(helper)
- 2 0.078 0.100 profilee.py:84(helper2_indirect)
-profilee.py:98(subhelper) <- 8 0.064 0.080 profilee.py:88(helper2)
-
-
-"""
-expected_output['print_callees'] = """\
- Ordered by: standard name
-
-Function called...
- ncalls tottime cumtime
-<string>:0(<module>) -> 1 0.270 1.000 profilee.py:25(testfunc)
-?:1(<module>) ->
-profilee.py:110(__getattr__) ->
-profilee.py:25(testfunc) -> 1 0.014 0.130 profilee.py:35(factorial)
- 2 0.040 0.600 profilee.py:55(helper)
-profilee.py:35(factorial) -> 20/3 0.130 0.147 profilee.py:35(factorial)
- 20 0.020 0.020 profilee.py:48(mul)
-profilee.py:48(mul) ->
-profilee.py:55(helper) -> 4 0.116 0.120 profilee.py:73(helper1)
- 2 0.000 0.140 profilee.py:84(helper2_indirect)
- 6 0.234 0.300 profilee.py:88(helper2)
-profilee.py:73(helper1) -> 4 0.004 0.004 profilee.py:110(__getattr__)
-profilee.py:84(helper2_indirect) -> 2 0.006 0.040 profilee.py:35(factorial)
- 2 0.078 0.100 profilee.py:88(helper2)
-profilee.py:88(helper2) -> 8 0.064 0.080 profilee.py:98(subhelper)
- 8 0.008 0.008 profilee.py:110(__getattr__)
-profilee.py:98(subhelper) -> 16 0.016 0.016 profilee.py:110(__getattr__)
-
-
-"""
-
-# this is how stuff would look like if we trace built-in calls
-
-real_expected_output = {}
-real_expected_output['print_stats'] = """\
126 function calls (106 primitive calls) in 1.000 CPU seconds
Ordered by: standard name
@@ -232,7 +161,7 @@
"""
-real_expected_output['print_callers'] = """\
+expected_output['print_callers'] = """\
Ordered by: standard name
Function was called by...
@@ -260,7 +189,7 @@
"""
-real_expected_output['print_callees'] = """\
+expected_output['print_callees'] = """\
Ordered by: standard name
Function called...
More information about the Pypy-commit
mailing list