[pypy-commit] pypy vecopt: added some temporary timing code for the trace execution

[plan_rich]

Author: Richard Plangger <rich at pasra.at>
Branch: vecopt
Changeset: r78255:052ab2d7af35
Date: 2015-06-23 12:10 +0200
http://bitbucket.org/pypy/pypy/changeset/052ab2d7af35/

Log:	added some temporary timing code for the trace execution

diff --git a/rpython/jit/metainterp/compile.py b/rpython/jit/metainterp/compile.py
--- a/rpython/jit/metainterp/compile.py
+++ b/rpython/jit/metainterp/compile.py
@@ -530,6 +530,10 @@
             self.status = hash & self.ST_SHIFT_MASK
 
     def handle_fail(self, deadframe, metainterp_sd, jitdriver_sd):
+        # XXX debug purpose only
+        from rpython.jit.metainterp.optimizeopt.vectorize import xxx_clock_stop
+        xxx_clock_stop(jitdriver_sd, fail=True)
+        # XXX debug purpose only end
         if self.must_compile(deadframe, metainterp_sd, jitdriver_sd):
             self.start_compiling()
             try:
diff --git a/rpython/jit/metainterp/optimizeopt/vectorize.py b/rpython/jit/metainterp/optimizeopt/vectorize.py
--- a/rpython/jit/metainterp/optimizeopt/vectorize.py
+++ b/rpython/jit/metainterp/optimizeopt/vectorize.py
@@ -28,13 +28,26 @@
 from rpython.rlib.jit import Counters
 from rpython.rtyper.lltypesystem import lltype, rffi
 
-class NotAVectorizeableLoop(JitException):
-    def __str__(self):
-        return 'NotAVectorizeableLoop()'
+import time
+XXXBench = {}
+def xxx_clock_start(jitdriver_sd):
+    XXXBench[jitdriver_sd] = time.clock()
+def xxx_clock_stop(jitdriver_sd, fail=False):
+    end = time.clock()
+    if jitdriver_sd not in XXXBench:
+        raise AssertionError("trying to stop clock but timing for jit driver sd has never started")
+    start = XXXBench[jitdriver_sd]
+    name = "<unkown>"
+    if jitdriver_sd.jitdriver:
+        name = jitdriver_sd.jitdriver.name
+    unique_id = jitdriver_sd 
+    ns = (end - start) * 10**9
+    debug_start("xxx-clock-stop")
+    debug_print("name: %s id(jdsd): %s exe time: %dns fail? %d vec? %d" % \
+            (name, unique_id, int(ns), int(fail), int(jitdriver_sd.vectorize)))
+    debug_stop("xxx-clock-stop")
 
-class NotAProfitableLoop(JitException):
-    def __str__(self):
-        return 'NotAProfitableLoop()'
+
 
 def debug_print_operations(loop):
     """ NOT_RPYTHON """
@@ -51,6 +64,15 @@
             else:
                 print ""
 
+
+class NotAVectorizeableLoop(JitException):
+    def __str__(self):
+        return 'NotAVectorizeableLoop()'
+
+class NotAProfitableLoop(JitException):
+    def __str__(self):
+        return 'NotAProfitableLoop()'
+
 def optimize_vector(metainterp_sd, jitdriver_sd, loop, optimizations,
                     inline_short_preamble, start_state, cost_threshold):
     optimize_unroll(metainterp_sd, jitdriver_sd, loop, optimizations,
@@ -68,13 +90,15 @@
         end = time.clock()
         metainterp_sd.profiler.count(Counters.OPT_VECTORIZED)
         metainterp_sd.logger_noopt.log_loop(loop.inputargs, loop.operations, -2, None, None, "post vectorize")
+        #
+        ns = int((end-start)*10.0**9)
         debug_start("vec-opt-clock")
         debug_print("unroll: %d gso count: %d opcount: (%d -> %d) took %fns" % \
                       (opt.unroll_count+1,
                        gso.strength_reduced,
                        len(orig_ops),
                        len(loop.operations),
-                       (end-start)*10.0**9))
+                       ns)
         debug_stop("vec-opt-clock")
 
     except NotAVectorizeableLoop:
diff --git a/rpython/jit/metainterp/warmspot.py b/rpython/jit/metainterp/warmspot.py
--- a/rpython/jit/metainterp/warmspot.py
+++ b/rpython/jit/metainterp/warmspot.py
@@ -829,6 +829,12 @@
                     else:
                         value = cast_base_ptr_to_instance(Exception, value)
                         raise Exception, value
+                finally:
+                    # XXX debug purpose only
+                    from rpython.jit.metainterp.optimizeopt.vectorize import xxx_clock_stop
+                    xxx_clock_stop(jd, fail=False)
+                    # XXX debug purpose only end
+
 
         def handle_jitexception(e):
             # XXX the bulk of this function is mostly a copy-paste from above
diff --git a/rpython/jit/metainterp/warmstate.py b/rpython/jit/metainterp/warmstate.py
--- a/rpython/jit/metainterp/warmstate.py
+++ b/rpython/jit/metainterp/warmstate.py
@@ -368,7 +368,11 @@
             if vinfo is not None:
                 virtualizable = args[index_of_virtualizable]
                 vinfo.clear_vable_token(virtualizable)
-            
+            # XXX debug purpose only
+            from rpython.jit.metainterp.optimizeopt.vectorize import xxx_clock_start
+            xxx_clock_start(jitdriver_sd)
+            # XXX debug purpose only end
+
             deadframe = func_execute_token(loop_token, *args)
             #
             # Record in the memmgr that we just ran this loop,