[pypy-svn] r55605 - in pypy/dist/pypy/module/_lsprof: . testing

fijal at codespeak.net fijal at codespeak.net
Thu Jun 5 21:57:54 CEST 2008


Author: fijal
Date: Thu Jun  5 21:57:53 2008
New Revision: 55605

Added:
   pypy/dist/pypy/module/_lsprof/   (props changed)
   pypy/dist/pypy/module/_lsprof/__init__.py   (contents, props changed)
   pypy/dist/pypy/module/_lsprof/interp_lsprof.py   (contents, props changed)
   pypy/dist/pypy/module/_lsprof/testing/   (props changed)
   pypy/dist/pypy/module/_lsprof/testing/__init__.py   (contents, props changed)
   pypy/dist/pypy/module/_lsprof/testing/test_cprofile.py   (contents, props changed)
Log:
_lsprof module. Not enough to past test yet, but I'm not sure whether test
is faulty or module is not doing well (ie if we track builtin calls
or not)


Added: pypy/dist/pypy/module/_lsprof/__init__.py
==============================================================================
--- (empty file)
+++ pypy/dist/pypy/module/_lsprof/__init__.py	Thu Jun  5 21:57:53 2008
@@ -0,0 +1,12 @@
+
+""" _lsprof module
+"""
+
+from pypy.interpreter.mixedmodule import MixedModule
+
+class Module(MixedModule):
+    applevelname = '_lsprof'
+
+    interpleveldefs = {'Profiler':'interp_lsprof.W_Profiler'}
+
+    appleveldefs = {}

Added: pypy/dist/pypy/module/_lsprof/interp_lsprof.py
==============================================================================
--- (empty file)
+++ pypy/dist/pypy/module/_lsprof/interp_lsprof.py	Thu Jun  5 21:57:53 2008
@@ -0,0 +1,232 @@
+
+from pypy.interpreter.baseobjspace import (W_Root, ObjSpace, Wrappable,
+                                           Arguments)
+from pypy.interpreter.typedef import (TypeDef, GetSetProperty,
+                                      interp_attrproperty)
+from pypy.interpreter.gateway import interp2app
+import time
+
+class W_StatsEntry(Wrappable):
+    def __init__(self, space, frame, callcount, reccallcount, tt, it,
+                 w_sublist):
+        self.frame = frame
+        self.callcount = callcount
+        self.reccallcount = reccallcount
+        self.it = it
+        self.tt = tt
+        self.w_calls = w_sublist
+
+    def get_calls(space, self):
+        return self.w_calls
+
+W_StatsEntry.typedef = TypeDef(
+    'StatsEntry',
+    code = interp_attrproperty('frame', W_StatsEntry),
+    callcount = interp_attrproperty('callcount', W_StatsEntry),
+    reccallcount = interp_attrproperty('reccallcount', W_StatsEntry),
+    inlinetime = interp_attrproperty('it', W_StatsEntry),
+    totaltime = interp_attrproperty('tt', W_StatsEntry),
+    calls = GetSetProperty(W_StatsEntry.get_calls),
+)
+
+class W_StatsSubEntry(Wrappable):
+    def __init__(self, space, frame, callcount, reccallcount, tt, it):
+        self.frame = frame
+        self.callcount = callcount
+        self.reccallcount = reccallcount
+        self.it = it
+        self.tt = tt
+
+W_StatsSubEntry.typedef = TypeDef(
+    'SubStatsEntry',
+    code = interp_attrproperty('frame', W_StatsSubEntry),
+    callcount = interp_attrproperty('callcount', W_StatsSubEntry),
+    reccallcount = interp_attrproperty('reccallcount', W_StatsSubEntry),
+    inlinetime = interp_attrproperty('it', W_StatsSubEntry),
+    totaltime = interp_attrproperty('tt', W_StatsSubEntry),
+)
+
+def stats(space, data, factor):
+    l_w = []
+    for v in data.values():
+        if v.callcount != 0:
+            l_w.append(v.stats(space, factor))
+    return space.newlist(l_w)
+
+class ProfilerEntry(object):
+    def __init__(self, frame):
+        self.frame = frame
+        self.tt = 0
+        self.it = 0
+        self.callcount = 0
+        self.recursivecallcount = 0
+        self.recursionLevel = 0
+        self.calls = {}
+
+    def stats(self, space, factor):
+        if self.calls:
+            w_sublist = space.newlist([sub_entry.stats(space, self, factor)
+                                       for sub_entry in self.calls.values()])
+        else:
+            w_sublist = space.w_None
+        w_se = W_StatsEntry(space, self.frame, self.callcount,
+                            self.recursivecallcount,
+                            factor * self.tt, factor * self.it, w_sublist)
+        return space.wrap(w_se)
+
+class ProfilerSubEntry(object):
+    def __init__(self, caller):
+        # self.key = caller # XXX why?
+        self.tt = 0
+        self.it = 0
+        self.callcount = 0
+        self.recursivecallcount = 0
+        self.recursionLevel = 0
+
+    def stats(self, space, parent, factor):
+        w_sse = W_StatsSubEntry(space, parent.frame,
+                                self.callcount, self.recursivecallcount,
+                                factor * self.tt, factor * self.it)
+        return space.wrap(w_sse)
+
+class ProfilerContext(object):
+    def __init__(self, profobj, entry):
+        self.entry = entry
+        self.subt = 0
+        self.previous = profobj.current_context
+        entry.recursionLevel += 1
+        if profobj.subcalls and self.previous:
+            subentry = ProfilerSubEntry(entry)
+            entry.calls[entry] = subentry
+            subentry.recursionLevel += 1
+        self.t0 = profobj.timer()
+
+    def _stop(self, profobj, entry):
+        # XXX factor out two pieces of the same code
+        tt = profobj.timer() - self.t0
+        it = tt - self.subt
+        if self.previous:
+            self.previous.subt += tt
+        entry.recursionLevel -= 1
+        if entry.recursionLevel == 0:
+            entry.tt += tt
+        else:
+            entry.recursivecallcount += 1
+        entry.it += it
+        entry.callcount += 1
+        if profobj.subcalls and self.previous:
+            caller = self.previous.entry
+            try:
+                subentry = caller.calls[entry]
+            except KeyError:
+                pass
+            else:
+                subentry.recursionLevel -= 1
+                if subentry.recursionLevel == 0:
+                    subentry.tt += tt
+                else:
+                    subentry.recursivecallcount += 1
+                subentry.it += it
+                subentry.callcount += 1
+    
+def lsprof_call(space, w_self, frame, event, w_arg):
+    assert isinstance(w_self, W_Profiler)
+    if event == 'call':
+        w_self._enter_call(frame.getcode())
+    elif event == 'return':
+        w_self._enter_return(frame.getcode())
+    else:
+        raise NotImplementedError("Call to %s" % event)
+    # we don't support builtin calls here...
+
+class W_Profiler(Wrappable):
+    def __init__(self, space, w_callable, time_unit, subcalls, builtins):
+        self.subcalls = subcalls
+        self.builtins = builtins
+        self.current_context = None
+        self.w_callable = w_callable
+        self.time_unit = time_unit
+        # XXX _lsprof uses rotatingtree. We use plain dict here,
+        #     not sure how big difference is, but we should probably
+        #     implement rotating tree
+        self.data = {}
+        self.space = space
+
+    def timer(self):
+        if self.w_callable:
+            space = self.space
+            return space.float_w(space.call_function(self.w_callable))
+        return time.time()
+
+    def enable(self, space, subcalls=True, builtins=True):
+        self.subcalls = subcalls
+        self.builtins = builtins
+        # set profiler hook
+        space.getexecutioncontext().setllprofile(lsprof_call, space.wrap(self))
+    enable.unwrap_spec = ['self', ObjSpace, bool, bool]
+
+    def _enter_call(self, f_code):
+        # we have superb gc, no point in freelist :)
+        try:
+            entry = self.data[f_code]
+        except KeyError:
+            entry = ProfilerEntry(f_code)
+            self.data[f_code] = entry
+        self.current_context = ProfilerContext(self, entry)
+
+    def _enter_return(self, f_code):
+        context = self.current_context
+        if context is None:
+            return
+        try:
+            entry = self.data[f_code]
+            context._stop(self, entry)
+        except KeyError:
+            pass
+        self.current_context = context.previous
+
+    def _flush_unmatched(self):
+        context = self.current_context
+        while context:
+            entry = context.entry
+            if entry:
+                context._stop(self, entry)
+            context = context.previous
+        self.current_context = None
+
+    def disable(self, space):
+        # unset profiler hook
+        self._flush_unmatched()
+        space.getexecutioncontext().setllprofile(None, None)
+    disable.unwrap_spec = ['self', ObjSpace]
+
+    def delete(self, space):
+        self._flush_unmatched()
+        space.getexecutioncontext().setllprofile(None, None)
+    delete.unwrap_spec = ['self', ObjSpace]
+
+    def getstats(self, space):
+        if self.w_callable is None:
+            factor = 0.000001
+        elif self.time_unit > 0.0:
+            factor = self.time_unit
+        else:
+            factor = 1.0 / sys.maxint
+        return stats(space, self.data, factor)
+    getstats.unwrap_spec = ['self', ObjSpace]
+
+def descr_new_profile(space, w_type, w_callable=None, time_unit=0.0,
+                      subcalls=True, builtins=True):
+    p = space.allocate_instance(W_Profiler, w_type)
+    p.__init__(space, w_callable, time_unit, subcalls, builtins)
+    return space.wrap(p)
+descr_new_profile.unwrap_spec = [ObjSpace, W_Root, W_Root, float, bool, bool]
+
+W_Profiler.typedef = TypeDef(
+    'Profiler',
+    __new__ = interp2app(descr_new_profile),
+    enable = interp2app(W_Profiler.enable),
+    disable = interp2app(W_Profiler.disable),
+    getstats = interp2app(W_Profiler.getstats),
+    __del__ = interp2app(W_Profiler.delete),
+)

Added: pypy/dist/pypy/module/_lsprof/testing/__init__.py
==============================================================================

Added: pypy/dist/pypy/module/_lsprof/testing/test_cprofile.py
==============================================================================
--- (empty file)
+++ pypy/dist/pypy/module/_lsprof/testing/test_cprofile.py	Thu Jun  5 21:57:53 2008
@@ -0,0 +1,133 @@
+
+from pypy.conftest import gettestobjspace
+
+class AppTestCProfile(object):
+    def setup_class(cls):
+        space = gettestobjspace(usemodules=('_lsprof',))
+        cls.w_expected_output = space.wrap(expected_output)
+        cls.space = space
+    
+    def test_cprofile(self):
+        skip("fails")
+        import sys
+        from cProfile import Profile
+        from test.profilee import testfunc, timer
+        
+        methodnames = ['print_stats', 'print_callers', 'print_callees']
+
+        def do_profiling(cls):
+            results = []
+            prof = cls(timer, 0.001)
+            start_timer = timer()
+            prof.runctx("testfunc()", {'testfunc':testfunc}, locals())
+            results.append(timer() - start_timer)
+            for methodname in methodnames:
+                import pstats
+                from StringIO import StringIO
+                s = StringIO()
+                stats = pstats.Stats(prof, stream=s)
+                stats.strip_dirs().sort_stats("stdname")
+                getattr(stats, methodname)()
+                results.append(s.getvalue())
+            return results
+
+        res = do_profiling(Profile)
+        assert res[0] == 1000
+        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]
+                assert 0
+            #assert res[i + 1] == self.expected_output[method]
+
+expected_output = {}
+expected_output['print_stats'] = """\
+         127 function calls (107 primitive calls) in 999.749 CPU seconds
+
+   Ordered by: standard name
+
+   ncalls  tottime  percall  cumtime  percall filename:lineno(function)
+        4   -0.004   -0.001   -0.004   -0.001 :0(append)
+        4   -0.004   -0.001   -0.004   -0.001 :0(exc_info)
+       12   -0.024   -0.002   11.964    0.997 :0(hasattr)
+        8   -0.008   -0.001   -0.008   -0.001 :0(range)
+        1    0.000    0.000    0.000    0.000 :0(setprofile)
+        1   -0.002   -0.002  999.751  999.751 <string>:1(<module>)
+        0    0.000             0.000          profile:0(profiler)
+        1   -0.002   -0.002  999.749  999.749 profile:0(testfunc())
+       28   27.972    0.999   27.972    0.999 profilee.py:110(__getattr__)
+        1  269.996  269.996  999.753  999.753 profilee.py:25(testfunc)
+     23/3  149.937    6.519  169.917   56.639 profilee.py:35(factorial)
+       20   19.980    0.999   19.980    0.999 profilee.py:48(mul)
+        2   39.986   19.993  599.814  299.907 profilee.py:55(helper)
+        4  115.984   28.996  119.964   29.991 profilee.py:73(helper1)
+        2   -0.006   -0.003  139.942   69.971 profilee.py:84(helper2_indirect)
+        8  311.976   38.997  399.896   49.987 profilee.py:88(helper2)
+        8   63.968    7.996   79.944    9.993 profilee.py:98(subhelper)
+
+
+"""
+expected_output['print_callers'] = """\
+   Ordered by: standard name
+
+Function                          was called by...
+:0(append)                        <- profilee.py:73(helper1)(4)  119.964
+:0(exc_info)                      <- profilee.py:73(helper1)(4)  119.964
+:0(hasattr)                       <- profilee.py:73(helper1)(4)  119.964
+                                     profilee.py:88(helper2)(8)  399.896
+:0(range)                         <- profilee.py:98(subhelper)(8)   79.944
+:0(setprofile)                    <- profile:0(testfunc())(1)  999.749
+<string>:1(<module>)              <- profile:0(testfunc())(1)  999.749
+profile:0(profiler)               <-
+profile:0(testfunc())             <- profile:0(profiler)(1)    0.000
+profilee.py:110(__getattr__)      <- :0(hasattr)(12)   11.964
+                                     profilee.py:98(subhelper)(16)   79.944
+profilee.py:25(testfunc)          <- <string>:1(<module>)(1)  999.751
+profilee.py:35(factorial)         <- profilee.py:25(testfunc)(1)  999.753
+                                     profilee.py:35(factorial)(20)  169.917
+                                     profilee.py:84(helper2_indirect)(2)  139.942
+profilee.py:48(mul)               <- profilee.py:35(factorial)(20)  169.917
+profilee.py:55(helper)            <- profilee.py:25(testfunc)(2)  999.753
+profilee.py:73(helper1)           <- profilee.py:55(helper)(4)  599.814
+profilee.py:84(helper2_indirect)  <- profilee.py:55(helper)(2)  599.814
+profilee.py:88(helper2)           <- profilee.py:55(helper)(6)  599.814
+                                     profilee.py:84(helper2_indirect)(2)  139.942
+profilee.py:98(subhelper)         <- profilee.py:88(helper2)(8)  399.896
+
+
+"""
+expected_output['print_callees'] = """\
+   Ordered by: standard name
+
+Function                          called...
+:0(append)                        ->
+:0(exc_info)                      ->
+:0(hasattr)                       -> profilee.py:110(__getattr__)(12)   27.972
+:0(range)                         ->
+:0(setprofile)                    ->
+<string>:1(<module>)              -> profilee.py:25(testfunc)(1)  999.753
+profile:0(profiler)               -> profile:0(testfunc())(1)  999.749
+profile:0(testfunc())             -> :0(setprofile)(1)    0.000
+                                     <string>:1(<module>)(1)  999.751
+profilee.py:110(__getattr__)      ->
+profilee.py:25(testfunc)          -> profilee.py:35(factorial)(1)  169.917
+                                     profilee.py:55(helper)(2)  599.814
+profilee.py:35(factorial)         -> profilee.py:35(factorial)(20)  169.917
+                                     profilee.py:48(mul)(20)   19.980
+profilee.py:48(mul)               ->
+profilee.py:55(helper)            -> profilee.py:73(helper1)(4)  119.964
+                                     profilee.py:84(helper2_indirect)(2)  139.942
+                                     profilee.py:88(helper2)(6)  399.896
+profilee.py:73(helper1)           -> :0(append)(4)   -0.004
+                                     :0(exc_info)(4)   -0.004
+                                     :0(hasattr)(4)   11.964
+profilee.py:84(helper2_indirect)  -> profilee.py:35(factorial)(2)  169.917
+                                     profilee.py:88(helper2)(2)  399.896
+profilee.py:88(helper2)           -> :0(hasattr)(8)   11.964
+                                     profilee.py:98(subhelper)(8)   79.944
+profilee.py:98(subhelper)         -> :0(range)(8)   -0.008
+                                     profilee.py:110(__getattr__)(16)   27.972
+
+
+"""



More information about the Pypy-commit mailing list