[pypy-svn] r68807 - in pypy/branch/logging/pypy/jit/metainterp: . test

arigo at codespeak.net arigo at codespeak.net
Wed Oct 28 11:25:05 CET 2009


Author: arigo
Date: Wed Oct 28 11:25:05 2009
New Revision: 68807

Modified:
   pypy/branch/logging/pypy/jit/metainterp/logger.py
   pypy/branch/logging/pypy/jit/metainterp/optimizeopt.py
   pypy/branch/logging/pypy/jit/metainterp/pyjitpl.py
   pypy/branch/logging/pypy/jit/metainterp/resume.py
   pypy/branch/logging/pypy/jit/metainterp/simple_optimize.py
   pypy/branch/logging/pypy/jit/metainterp/test/test_basic.py
   pypy/branch/logging/pypy/jit/metainterp/test/test_logger.py
   pypy/branch/logging/pypy/jit/metainterp/test/test_loop.py
   pypy/branch/logging/pypy/jit/metainterp/test/test_optimizeopt.py
Log:
Use rlog instead of PYPYJITLOG and PYPYJITRESUMELOG.
In-progress.


Modified: pypy/branch/logging/pypy/jit/metainterp/logger.py
==============================================================================
--- pypy/branch/logging/pypy/jit/metainterp/logger.py	(original)
+++ pypy/branch/logging/pypy/jit/metainterp/logger.py	Wed Oct 28 11:25:05 2009
@@ -1,48 +1,37 @@
 import os
-from pypy.rlib.objectmodel import compute_unique_id
+from pypy.rlib import rlog
 from pypy.jit.metainterp.resoperation import rop
 from pypy.jit.metainterp.history import Const, ConstInt, Box, \
      BoxInt, ConstAddr, ConstFloat, BoxFloat, AbstractFailDescr
-from pypy.rlib.streamio import open_file_as_stream
 
 class Logger(object):
 
     def __init__(self, ts, guard_number=False):
-        self.log_stream = None
         self.ts = ts
         self.guard_number=guard_number
 
-    def create_log(self, extension='.ops'):
-        if self.log_stream is not None:
-            return self.log_stream        
-        s = os.environ.get('PYPYJITLOG')
-        if not s:
-            return None
-        s += extension
-        try:
-            self.log_stream = open_file_as_stream(s, 'w')
-        except OSError:
-            os.write(2, "could not create log file\n")
-            return None
-        return self.log_stream
-
-    def log_loop(self, inputargs, operations, number=0, type=None):
-        if self.log_stream is None:
+    def log_loop(self, inputargs, operations, number=-1, type="unoptimized"):
+        if not rlog.has_log():
             return
-        if type is not None:
-            self.log_stream.write("# Loop%d (%s), %d ops\n" % (number,
-                                                              type,
-                                                              len(operations)))
+        rlog.debug_log("jit-log-loop-{",
+                       "# Loop%(number)d (%(type)s), %(length)d ops",
+                       number = number,
+                       type   = type,
+                       length = len(operations))
         self._log_operations(inputargs, operations, {})
+        rlog.debug_log("jit-log-loop-}",
+                       "# End")
 
     def log_bridge(self, inputargs, operations, number=-1):
-        if self.log_stream is None:
+        if not rlog.has_log():
             return
-        if number != -1:
-            self.log_stream.write("# bridge out of Guard%d, %d ops\n" % (number,
-                                                               len(operations)))
+        rlog.debug_log("jit-log-bridge-{",
+                       "# Bridge out of Guard%(guard)d, %(length)d ops",
+                       guard  = number,
+                       length = len(operations))
         self._log_operations(inputargs, operations, {})
-        
+        rlog.debug_log("jit-log-bridge-}",
+                       "# End")
 
     def repr_of_descr(self, descr):
         return descr.repr_of_descr()
@@ -73,12 +62,16 @@
     def _log_operations(self, inputargs, operations, memo):
         if inputargs is not None:
             args = ", ".join([self.repr_of_arg(memo, arg) for arg in inputargs])
-            self.log_stream.write('[' + args + ']\n')
+            rlog.debug_log("jit-log-head",
+                           "[%(inputargs)s]",
+                           inputargs = args)
         for i in range(len(operations)):
             op = operations[i]
             if op.opnum == rop.DEBUG_MERGE_POINT:
                 loc = op.args[0]._get_str()
-                self.log_stream.write("debug_merge_point('%s')\n" % (loc,))
+                rlog.debug_log("jit-log-mgpt",
+                               "debug_merge_point(%(loc)r)",
+                               loc = loc)
                 continue
             args = ", ".join([self.repr_of_arg(memo, arg) for arg in op.args])
             if op.result is not None:
@@ -99,6 +92,9 @@
                                               for arg in op.fail_args]) + ']'
             else:
                 fail_args = ''
-            self.log_stream.write(res + op.getopname() +
-                                  '(' + args + ')' + fail_args + '\n')
-        self.log_stream.flush()
+            rlog.debug_log("jit-log-insn",
+                           "%(res)s%(opname)s(%(args)s)%(fail_args)s",
+                           res       = res,
+                           opname    = op.getopname(),
+                           args      = args,
+                           fail_args = fail_args)

Modified: pypy/branch/logging/pypy/jit/metainterp/optimizeopt.py
==============================================================================
--- pypy/branch/logging/pypy/jit/metainterp/optimizeopt.py	(original)
+++ pypy/branch/logging/pypy/jit/metainterp/optimizeopt.py	Wed Oct 28 11:25:05 2009
@@ -518,8 +518,7 @@
     def store_final_boxes_in_guard(self, op):
         descr = op.descr
         assert isinstance(descr, compile.ResumeGuardDescr)
-        modifier = resume.ResumeDataVirtualAdder(descr, self.resumedata_memo,
-                               self.metainterp_sd.globaldata.storedebug)
+        modifier = resume.ResumeDataVirtualAdder(descr, self.resumedata_memo)
         newboxes = modifier.finish(self.values)
         if len(newboxes) > self.metainterp_sd.options.failargs_limit:
             raise compile.GiveUp

Modified: pypy/branch/logging/pypy/jit/metainterp/pyjitpl.py
==============================================================================
--- pypy/branch/logging/pypy/jit/metainterp/pyjitpl.py	(original)
+++ pypy/branch/logging/pypy/jit/metainterp/pyjitpl.py	Wed Oct 28 11:25:05 2009
@@ -1027,9 +1027,6 @@
                 self.profiler.start()
                 self.profiler.initialized = True
             self.globaldata.initialized = True
-            self.logger_noopt.create_log('.noopt')
-            self.logger_ops.create_log('.ops')
-            self.globaldata.storedebug = os.environ.get('PYPYJITRESUMELOG')
 
     def _setup_class_sizes(self):
         class_sizes = {}

Modified: pypy/branch/logging/pypy/jit/metainterp/resume.py
==============================================================================
--- pypy/branch/logging/pypy/jit/metainterp/resume.py	(original)
+++ pypy/branch/logging/pypy/jit/metainterp/resume.py	Wed Oct 28 11:25:05 2009
@@ -3,6 +3,7 @@
 from pypy.jit.metainterp.resoperation import rop
 from pypy.rpython.lltypesystem import rffi
 from pypy.rlib import rarithmetic
+from pypy.rlib import rlog
 from pypy.rlib.objectmodel import we_are_translated
 
 # Logic to encode the chain of frames and the state of the boxes at a
@@ -179,10 +180,9 @@
 
 class ResumeDataVirtualAdder(object):
 
-    def __init__(self, storage, memo, debug_storage=None):
+    def __init__(self, storage, memo):
         self.storage = storage
         self.memo = memo
-        self.debug_storage = debug_storage
         #self.virtuals = []
         #self.vfieldboxes = []
 
@@ -258,8 +258,8 @@
         self._number_virtuals(liveboxes)
 
         storage.rd_consts = self.memo.consts
-        if self.debug_storage:
-            dump_storage(self.debug_storage, storage, liveboxes)
+        if rlog.has_log():
+            dump_storage(storage, liveboxes)
         return liveboxes[:]
 
     def _number_virtuals(self, liveboxes):
@@ -425,38 +425,48 @@
 
 # ____________________________________________________________
 
-def dump_storage(logname, storage, liveboxes):
+def dump_storage(storage, liveboxes):
     "For profiling only."
-    import os
     from pypy.rlib import objectmodel
-    assert logname is not None    # annotator hack
-    fd = os.open(logname, os.O_WRONLY | os.O_APPEND | os.O_CREAT, 0666)
-    os.write(fd, 'Log(%d, [\n' % objectmodel.compute_unique_id(storage))
-    frameinfo = storage.rd_frame_info_list
-    while True:
-        os.write(fd, '\t("%s", %d, %d) at %xd,\n' % (
-            frameinfo.jitcode, frameinfo.pc, frameinfo.exception_target,
-            objectmodel.compute_unique_id(frameinfo)))
-        frameinfo = frameinfo.prev
-        if frameinfo is None:
-            break
-    os.write(fd, '\t],\n\t[\n')
+    rlog.debug_log("jit-resume-{",
+                   "Storage entry %(id)d",
+                   id = objectmodel.compute_unique_id(storage))
+    try:
+        frameinfo = storage.rd_frame_info_list
+    except AttributeError:
+        pass     # for tests
+    else:
+        while True:
+            rlog.debug_log("jit-resume-frameinfo",
+                "(%(jitcode)r, %(pc)d, %(exception_target)d) at %(id)d",
+                jitcode          = frameinfo.jitcode,
+                pc               = frameinfo.pc,
+                exception_target = frameinfo.exception_target,
+                id               = objectmodel.compute_unique_id(frameinfo))
+            frameinfo = frameinfo.prev
+            if frameinfo is None:
+                break
     numb = storage.rd_numb
     while True:
-        os.write(fd, '\t\t%s at %xd,\n' % ([untag(i) for i in numb.nums],
-                                           objectmodel.compute_unique_id(numb)))
+        rlog.debug_log("jit-resume-numb",
+                       "%(nums)s at %(id)d",
+                       nums = str([untag(i) for i in numb.nums]),
+                       id   = objectmodel.compute_unique_id(numb))
         numb = numb.prev
         if numb is None:
             break
-    os.write(fd, '\t], [\n')
     for const in storage.rd_consts:
-        os.write(fd, '\t"%s",\n' % (const.repr_rpython(),))
-    os.write(fd, '\t], [\n')
+        rlog.debug_log("jit-resume-const",
+                       "%(const)s",
+                       const = const.repr_rpython())
     for box in liveboxes:
-        os.write(fd, '\t"%s",\n' % (box.repr_rpython(),))
-    os.write(fd, '\t], [\n')
+        rlog.debug_log("jit-resume-box",
+                       "%(box)s",
+                       box = box.repr_rpython())
     if storage.rd_virtuals is not None:
         for virtual in storage.rd_virtuals:
-            os.write(fd, '\t%s,\n' % (virtual.repr_rpython(),))
-    os.write(fd, '\t])\n')
-    os.close(fd)
+            rlog.debug_log("jit-resume-virtual",
+                           "%(virtual)s",
+                           virtual = virtual.repr_rpython())
+    rlog.debug_log("jit-resume-}",
+                   "End")

Modified: pypy/branch/logging/pypy/jit/metainterp/simple_optimize.py
==============================================================================
--- pypy/branch/logging/pypy/jit/metainterp/simple_optimize.py	(original)
+++ pypy/branch/logging/pypy/jit/metainterp/simple_optimize.py	Wed Oct 28 11:25:05 2009
@@ -22,8 +22,7 @@
             if op.is_guard():
                 descr = op.descr
                 assert isinstance(descr, compile.ResumeGuardDescr)
-                modifier = resume.ResumeDataVirtualAdder(descr, memo,
-                                            metainterp_sd.globaldata.storedebug)
+                modifier = resume.ResumeDataVirtualAdder(descr, memo)
                 newboxes = modifier.finish(EMPTY_VALUES)
                 descr.store_final_boxes(op, newboxes)
             newoperations.append(op)

Modified: pypy/branch/logging/pypy/jit/metainterp/test/test_basic.py
==============================================================================
--- pypy/branch/logging/pypy/jit/metainterp/test/test_basic.py	(original)
+++ pypy/branch/logging/pypy/jit/metainterp/test/test_basic.py	Wed Oct 28 11:25:05 2009
@@ -4,7 +4,7 @@
 from pypy.rlib.jit import OPTIMIZER_FULL, OPTIMIZER_SIMPLE
 from pypy.jit.metainterp.warmspot import ll_meta_interp, get_stats
 from pypy.jit.backend.llgraph import runner
-from pypy.jit.metainterp import support, codewriter, pyjitpl, history
+from pypy.jit.metainterp import support, codewriter, pyjitpl, history, resume
 from pypy.jit.metainterp.policy import JitPolicy, StopAtXPolicy
 from pypy import conftest
 from pypy.rlib.rarithmetic import ovfcheck
@@ -830,7 +830,12 @@
             return r() is None
         #
         assert f(30) == 1
-        res = self.meta_interp(f, [30], no_stats=True)
+        old_dump_storage = resume.dump_storage
+        resume.dump_storage = lambda *args: None
+        try:
+            res = self.meta_interp(f, [30], no_stats=True)
+        finally:
+            resume.dump_storage = old_dump_storage
         assert res == 1
 
     def test_pass_around(self):

Modified: pypy/branch/logging/pypy/jit/metainterp/test/test_logger.py
==============================================================================
--- pypy/branch/logging/pypy/jit/metainterp/test/test_logger.py	(original)
+++ pypy/branch/logging/pypy/jit/metainterp/test/test_logger.py	Wed Oct 28 11:25:05 2009
@@ -3,18 +3,30 @@
 from pypy.jit.metainterp import logger
 from pypy.jit.metainterp.typesystem import llhelper
 from StringIO import StringIO
+from pypy.rlib import rlog
 from pypy.jit.metainterp.test.test_optimizeopt import equaloplists
 from pypy.jit.metainterp.history import AbstractDescr, LoopToken, BasicFailDescr
 
 class Descr(AbstractDescr):
     pass
 
+def capturing(func, *args, **kwds):
+    log_stream = StringIO()
+    def write_to_log_stream(_cat, _msg, **_kwds):
+        print >> log_stream, _msg % _kwds
+    old_debug_log = rlog.debug_log
+    try:
+        rlog.debug_log = write_to_log_stream
+        func(*args, **kwds)
+    finally:
+        rlog.debug_log = old_debug_log
+    return log_stream.getvalue()
+
 class Logger(logger.Logger):
     def log_loop(self, loop, namespace={}):
-        self.log_stream = StringIO()
         self.namespace = namespace
-        logger.Logger.log_loop(self, loop.inputargs, loop.operations)
-        return self.log_stream.getvalue()
+        return capturing(logger.Logger.log_loop, self,
+                         loop.inputargs, loop.operations)
 
     def repr_of_descr(self, descr):
         for k, v in self.namespace.items():
@@ -92,7 +104,7 @@
         loop = pure_parse(inp, namespace=namespace)
         logger = Logger(self.ts)
         output = logger.log_loop(loop)
-        assert output.splitlines()[-1] == "jump(i0, descr=<Loop3>)"
+        assert output.splitlines()[-2] == "jump(i0, descr=<Loop3>)"
         pure_parse(output)
         
     def test_guard(self):
@@ -104,7 +116,7 @@
         loop = pure_parse(inp, namespace=namespace)
         logger = Logger(self.ts, guard_number=True)
         output = logger.log_loop(loop)
-        assert output.splitlines()[-1] == "guard_true(i0, descr=<Guard4>) [i0]"
+        assert output.splitlines()[-2] == "guard_true(i0, descr=<Guard4>) [i0]"
         pure_parse(output)
         
         def boom():
@@ -112,20 +124,16 @@
         namespace['fdescr'].get_index = boom
         logger = Logger(self.ts, guard_number=False)
         output = logger.log_loop(loop)
-        assert output.splitlines()[-1].startswith("guard_true(i0, descr=<")
+        assert output.splitlines()[-2].startswith("guard_true(i0, descr=<")
 
     def test_intro_loop(self):
         bare_logger = logger.Logger(self.ts)
-        bare_logger.log_stream = StringIO()
-        bare_logger.log_loop([], [], 1, "foo")
-        output = bare_logger.log_stream.getvalue()
+        output = capturing(bare_logger.log_loop, [], [], 1, "foo")
         assert output.splitlines()[0] == "# Loop1 (foo), 0 ops"
         pure_parse(output)
 
     def test_intro_bridge(self):
         bare_logger = logger.Logger(self.ts)
-        bare_logger.log_stream = StringIO()
-        bare_logger.log_bridge([], [], 3)
-        output = bare_logger.log_stream.getvalue()
-        assert output.splitlines()[0] == "# bridge out of Guard3, 0 ops"        
+        output = capturing(bare_logger.log_bridge, [], [], 3)
+        assert output.splitlines()[0] == "# Bridge out of Guard3, 0 ops"
         pure_parse(output)

Modified: pypy/branch/logging/pypy/jit/metainterp/test/test_loop.py
==============================================================================
--- pypy/branch/logging/pypy/jit/metainterp/test/test_loop.py	(original)
+++ pypy/branch/logging/pypy/jit/metainterp/test/test_loop.py	Wed Oct 28 11:25:05 2009
@@ -594,25 +594,6 @@
 
         res = self.meta_interp(f, [200])
 
-    def test_dump_storage(self):
-        import os
-        from pypy.tool.udir import udir
-        logfile = udir.join('resume.log')
-        os.environ['PYPYJITRESUMELOG'] = str(logfile)
-        try:
-            jitdriver = JitDriver(greens = [], reds = ['i', 'n'])
-
-            def f(n):
-                i = 0
-                while i < n:
-                    jitdriver.can_enter_jit(n=n, i=i)
-                    jitdriver.jit_merge_point(n=n, i=i)
-                    i += 1
-                return i
-            res = self.meta_interp(f, [10])
-            data = logfile.read() # assert did not crash
-        finally:
-            del os.environ['PYPYJITRESUMELOG']
 
 class TestOOtype(LoopTest, OOJitMixin):
     pass

Modified: pypy/branch/logging/pypy/jit/metainterp/test/test_optimizeopt.py
==============================================================================
--- pypy/branch/logging/pypy/jit/metainterp/test/test_optimizeopt.py	(original)
+++ pypy/branch/logging/pypy/jit/metainterp/test/test_optimizeopt.py	Wed Oct 28 11:25:05 2009
@@ -25,7 +25,6 @@
 
 class Fake(object):
     failargs_limit = 1000
-    storedebug = None
 
 class FakeMetaInterpStaticData(object):
 



More information about the Pypy-commit mailing list