[pypy-svn] pypy jitypes2: add a more complete logging of what happens during the fficall optimization

[antocuni]

Author: Antonio Cuni <anto.cuni at gmail.com>
Branch: jitypes2
Changeset: r41351:7d9ed6268794
Date: 2011-01-26 14:56 +0100
http://bitbucket.org/pypy/pypy/changeset/7d9ed6268794/

Log:	add a more complete logging of what happens during the fficall
	optimization

diff --git a/pypy/jit/metainterp/optimizeopt/fficall.py b/pypy/jit/metainterp/optimizeopt/fficall.py
--- a/pypy/jit/metainterp/optimizeopt/fficall.py
+++ b/pypy/jit/metainterp/optimizeopt/fficall.py
@@ -1,6 +1,7 @@
 from pypy.rpython.annlowlevel import cast_base_ptr_to_instance
 from pypy.rlib.objectmodel import we_are_translated
 from pypy.rlib.libffi import Func
+from pypy.rlib.debug import debug_start, debug_stop, debug_print, have_debug_prints
 from pypy.jit.codewriter.effectinfo import EffectInfo
 from pypy.jit.metainterp.resoperation import rop, ResOperation
 from pypy.jit.metainterp.optimizeutil import _findall
@@ -68,33 +69,39 @@
             return f.inst_argtypes, f.inst_restype
 
 
-from pypy.rlib.debug import debug_start, debug_stop, debug_print
-
 class OptFfiCall(Optimization):
 
-    def __init__(self):
+    def setup(self):
         self.funcinfo = None
+        self.logger = self.optimizer.metainterp_sd.logger_ops
+
+    def propagate_begin_forward(self):
+        debug_start('jit-log-ffiopt')
+        Optimization.propagate_begin_forward(self)
+
+    def propagate_end_forward(self):
+        debug_stop('jit-log-ffiopt')
+        Optimization.propagate_end_forward(self)
 
     def reconstruct_for_next_iteration(self, optimizer, valuemap):
         return OptFfiCall()
         # FIXME: Should any status be saved for next iteration?
 
     def begin_optimization(self, funcval, op):
-        self.rollback_maybe('begin_optimization ' + op.repr())
+        self.rollback_maybe('begin_optimization', op)
         self.funcinfo = FuncInfo(funcval, self.optimizer.cpu, op)
 
     def commit_optimization(self):
         self.funcinfo = None
 
-    def rollback_maybe(self, msg):
+    def rollback_maybe(self, msg, op):
         if self.funcinfo is None:
             return # nothing to rollback
         #
         # we immediately set funcinfo to None to prevent recursion when
         # calling emit_op
-        debug_start('jit-log-opt-debug-ffi')
-        debug_print('rollback: ' + msg)
-        debug_stop('jit-log-opt-debug-ffi')
+        if have_debug_prints():
+            debug_print('rollback: ' + msg + ': ', self.logger.repr_of_op(op))
         funcinfo = self.funcinfo
         self.funcinfo = None
         self.emit_operation(funcinfo.prepare_op)
@@ -105,7 +112,7 @@
 
     def emit_operation(self, op):
         # we cannot emit any operation during the optimization
-        self.rollback_maybe('invalid operation: ' + op.repr())
+        self.rollback_maybe('invalid op', op)
         Optimization.emit_operation(self, op)
 
     def optimize_CALL(self, op):
@@ -152,7 +159,7 @@
             self.funcinfo.force_token_op = op
 
     def do_prepare_call(self, op):
-        self.rollback_maybe('prepare call: ' + op.repr())
+        self.rollback_maybe('prepare call', op)
         funcval = self._get_funcval(op)
         if not funcval.is_constant():
             return [op] # cannot optimize
@@ -186,6 +193,8 @@
         return ops
 
     def propagate_forward(self, op):
+        if have_debug_prints():
+            debug_print(self.logger.repr_of_op(op))
         opnum = op.getopnum()
         for value, func in optimize_ops:
             if opnum == value:

diff --git a/pypy/jit/metainterp/test/test_optimizebasic.py b/pypy/jit/metainterp/test/test_optimizebasic.py
--- a/pypy/jit/metainterp/test/test_optimizebasic.py
+++ b/pypy/jit/metainterp/test/test_optimizebasic.py
@@ -3,6 +3,7 @@
 from pypy.jit.metainterp.test.test_optimizeutil import (LLtypeMixin,
                                                         #OOtypeMixin,
                                                         BaseTest)
+from pypy.jit.metainterp.test.test_compile import FakeLogger
 import pypy.jit.metainterp.optimizeopt.optimizer as optimizeopt
 import pypy.jit.metainterp.optimizeopt.virtualize as virtualize
 from pypy.jit.metainterp.optimizeutil import InvalidLoop
@@ -31,6 +32,7 @@
         self.profiler = EmptyProfiler()
         self.options = Fake()
         self.globaldata = Fake()
+        self.logger_ops = FakeLogger()
 
 def test_store_final_boxes_in_guard():
     from pypy.jit.metainterp.compile import ResumeGuardDescr

diff --git a/pypy/jit/metainterp/test/test_compile.py b/pypy/jit/metainterp/test/test_compile.py
--- a/pypy/jit/metainterp/test/test_compile.py
+++ b/pypy/jit/metainterp/test/test_compile.py
@@ -37,6 +37,9 @@
     def log_loop(self, inputargs, operations, number=0, type=None):
         pass
 
+    def repr_of_op(self, op):
+        return repr(op)
+
 class FakeState:
     optimize_loop = staticmethod(nounroll_optimize.optimize_loop)
 

diff --git a/pypy/jit/metainterp/optimizeopt/optimizer.py b/pypy/jit/metainterp/optimizeopt/optimizer.py
--- a/pypy/jit/metainterp/optimizeopt/optimizer.py
+++ b/pypy/jit/metainterp/optimizeopt/optimizer.py
@@ -169,6 +169,14 @@
 
 class Optimization(object):
     next_optimization = None
+
+    def propagate_begin_forward(self):
+        if self.next_optimization:
+            self.next_optimization.propagate_begin_forward()
+
+    def propagate_end_forward(self):
+        if self.next_optimization:
+            self.next_optimization.propagate_end_forward()
     
     def propagate_forward(self, op):
         raise NotImplementedError
@@ -389,11 +397,13 @@
         # ^^^ at least at the start of bridges.  For loops, we could set
         # it to False, but we probably don't care
         self.newoperations = []
+        self.first_optimization.propagate_begin_forward()
         self.i = 0
         while self.i < len(self.loop.operations):
             op = self.loop.operations[self.i]
             self.first_optimization.propagate_forward(op)
             self.i += 1
+        self.first_optimization.propagate_end_forward()
         self.loop.operations = self.newoperations
         # accumulate counters
         self.resumedata_memo.update_counters(self.metainterp_sd.profiler)