Hopefully fix the profiler right. Add a test suite that checks that

it deals correctly with some anomalous cases; according to this test
suite I've fixed it right.

The anomalous cases had to do with 'exception' events: these aren't
generated when they would be most helpful, and the profiler has to
work hard to recover the right information.  The problems occur when C
code (such as hasattr(), which is used as the example here) calls back
into Python code and clears an exception raised by that Python code.
Consider this example:

    def foo():
        hasattr(obj, "bar")

Where obj is an instance from a class like this:

    class C:
        def __getattr__(self, name):
            raise AttributeError

The profiler sees the following sequence of events:

    call (foo)
    call (__getattr__)
    exception (in __getattr__)
    return (from foo)

Previously, the profiler would assume the return event returned from
__getattr__. An if statement checking for this condition and raising
an exception was commented out...  This version does the right thing.

2 files changed, 103 insertions, 0 deletions

diff --git a/Lib/test/output/test_profile b/Lib/test/output/test_profile
new file mode 100644
index 0000000..b36a016
--- /dev/null
+++ b/Lib/test/output/test_profile
@@ -0,0 +1,17 @@
+test_profile
+         53 function 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>:1(?)
+        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:21(testfunc)
+        2    0.080    0.040    0.600    0.300 test_profile.py:30(helper)
+        4    0.116    0.029    0.120    0.030 test_profile.py:48(helper1)
+        8    0.312    0.039    0.400    0.050 test_profile.py:56(helper2)
+        8    0.064    0.008    0.080    0.010 test_profile.py:66(subhelper)
+       28    0.028    0.001    0.028    0.001 test_profile.py:78(__getattr__)
+
+
diff --git a/Lib/test/test_profile.py b/Lib/test/test_profile.py
new file mode 100644
index 0000000..460d56f
--- /dev/null
+++ b/Lib/test/test_profile.py
@@ -0,0 +1,86 @@
+"""Test suite for the profile module."""
+
+import profile
+
+# In order to have reproducible time, we simulate a timer in the global
+# variable 'ticks', which represents simulated time in milliseconds.
+# (We can't use a helper function increment the timer since it would be
+# included in the profile and would appear to consume all the time.)
+ticks = 0
+    
+def test_main():
+    global ticks
+    ticks = 0
+    prof = profile.Profile(timer)
+    prof.runctx("testfunc()", globals(), globals())
+    prof.print_stats()
+
+def timer():
+    return ticks*0.001
+
+def testfunc():
+    # 1 call
+    # 1000 ticks total: 400 ticks local, 600 ticks in subfunctions
+    global ticks
+    ticks += 199
+    helper()                            # 300
+    helper()                            # 300
+    ticks += 201
+
+def helper():
+    # 2 calls
+    # 300 ticks total: 40 ticks local, 260 ticks in subfunctions
+    global ticks
+    ticks += 1
+    helper1()                           # 30
+    ticks += 3
+    helper1()                           # 30
+    ticks += 6
+    helper2()                           # 50
+    ticks += 5
+    helper2()                           # 50
+    ticks += 4
+    helper2()                           # 50
+    ticks += 7
+    helper2()                           # 50
+    ticks += 14
+
+def helper1():
+    # 4 calls
+    # 30 ticks total: 29 ticks local, 1 tick in subfunctions
+    global ticks
+    ticks += 10
+    hasattr(C(), "foo")
+    ticks += 19
+
+def helper2():
+    # 8 calls
+    # 50 ticks local: 39 ticks local, 11 ticks in subfunctions
+    global ticks
+    ticks += 11
+    hasattr(C(), "bar")                 # 1
+    ticks += 13
+    subhelper()                         # 10
+    ticks += 15
+
+def subhelper():
+    # 8 calls
+    # 10 ticks total: 8 ticks local, 2 ticks in subfunctions
+    global ticks
+    ticks += 2
+    for i in range(2):
+        try:
+            C().foo                     # 1 x 2
+        except AttributeError:
+            ticks += 3                  # 3 x 2
+
+class C:
+    def __getattr__(self, name):
+        # 28 calls
+        # 1 tick, local
+        global ticks
+        ticks += 1
+        raise AttributeError
+
+if __name__ == "__main__":
+    test_main()