[pypy-commit] pypy stmgc-c7: First step: reporting in the logs (PYPYLOG=stm-report:-)

arigo noreply at buildbot.pypy.org
Sat Apr 19 21:56:46 CEST 2014


Author: Armin Rigo <arigo at tunes.org>
Branch: stmgc-c7
Changeset: r70785:eb2840c9b83c
Date: 2014-04-19 21:53 +0200
http://bitbucket.org/pypy/pypy/changeset/eb2840c9b83c/

Log:	First step: reporting in the logs (PYPYLOG=stm-report:-)

diff --git a/rpython/translator/c/genc.py b/rpython/translator/c/genc.py
--- a/rpython/translator/c/genc.py
+++ b/rpython/translator/c/genc.py
@@ -884,6 +884,7 @@
     print >> f
     print >> f, '#include "preimpl.h"'
     print >> f, '#include "src/rtyper.h"'
+    print >> f, '#include "src/debug_print.h"'
     print >> f, '#include "src_stm/extracode.h"'
 
 def commondefs(defines):
diff --git a/rpython/translator/stm/src_stm/extracode.h b/rpython/translator/stm/src_stm/extracode.h
--- a/rpython/translator/stm/src_stm/extracode.h
+++ b/rpython/translator/stm/src_stm/extracode.h
@@ -73,47 +73,71 @@
     RPyStringSpace0 *co_filename;
     RPyStringSpace0 *co_name;
     RPyStringSpace0 *co_lnotab;
+    char *ntrunc = "", *fntrunc = "";
+    long fnlen, nlen, line;
+    char *fn, *name;
 
-    co_filename    = _fetch_rpyspace0(segment_base, o, g_co_filename_ofs);
-    co_name        = _fetch_rpyspace0(segment_base, o, g_co_name_ofs);
-    co_firstlineno = _fetch_lngspace0(segment_base, o, g_co_firstlineno_ofs);
-    co_lnotab      = _fetch_rpyspace0(segment_base, o, g_co_lnotab_ofs);
+    if (o) {
+        co_filename   =_fetch_rpyspace0(segment_base, o, g_co_filename_ofs);
+        co_name       =_fetch_rpyspace0(segment_base, o, g_co_name_ofs);
+        co_firstlineno=_fetch_lngspace0(segment_base, o, g_co_firstlineno_ofs);
+        co_lnotab     =_fetch_rpyspace0(segment_base, o, g_co_lnotab_ofs);
 
-    char *ntrunc = "", *fntrunc = "";
+        long remaining = outputbufsize - 32;
+        nlen = RPyString_Size(co_name);
+        name = _RPyString_AsString(co_name);
+        if (nlen > remaining / 2) {
+            nlen = remaining / 2;
+            ntrunc = "...";
+        }
+        remaining -= nlen;
 
-    long remaining = outputbufsize - 32;
-    long nlen = RPyString_Size(co_name);
-    char *name = _RPyString_AsString(co_name);
-    if (nlen > remaining / 2) {
-        nlen = remaining / 2;
-        ntrunc = "...";
+        fnlen = RPyString_Size(co_filename);
+        fn = _RPyString_AsString(co_filename);
+        if (fnlen > remaining) {
+            fn += (fnlen - remaining);
+            fnlen = remaining;
+            fntrunc = "...";
+        }
+
+        long lnotablen = RPyString_Size(co_lnotab);
+        char *lnotab = _RPyString_AsString(co_lnotab);
+        uintptr_t next_instr = odd_number >> 1;
+        line = co_firstlineno;
+        uintptr_t i, addr = 0;
+        for (i = 0; i < lnotablen; i += 2) {
+            addr += ((unsigned char *)lnotab)[i];
+            if (addr > next_instr)
+                break;
+            line += ((unsigned char *)lnotab)[i + 1];
+        }
     }
-    remaining -= nlen;
-
-    long fnlen = RPyString_Size(co_filename);
-    char *fn = _RPyString_AsString(co_filename);
-    if (fnlen > remaining) {
-        fn += (fnlen - remaining);
-        fnlen = remaining;
-        fntrunc = "...";
-    }
-
-    long lnotablen = RPyString_Size(co_lnotab);
-    char *lnotab = _RPyString_AsString(co_lnotab);
-    uintptr_t next_instr = odd_number >> 1;
-    long line = co_firstlineno;
-    uintptr_t i, addr = 0;
-    for (i = 0; i < lnotablen; i += 2) {
-        addr += ((unsigned char *)lnotab)[i];
-        if (addr > next_instr)
-            break;
-        line += ((unsigned char *)lnotab)[i + 1];
+    else {
+        fnlen = 1;
+        fn = "?";
+        nlen = 1;
+        name = "?";
+        line = 0;
     }
 
     snprintf(outputbuf, outputbufsize, "File \"%s%.*s\", line %ld, in %.*s%s",
              fntrunc, (int)fnlen, fn, line, (int)nlen, name, ntrunc);
 }
 
+#define REPORT_MINIMUM_TIME   0.0001    /* 0.1 millisecond; xxx tweak */
+
+static void _stm_cb_debug_print(const char *cause, double time,
+                                const char *marker)
+{
+    if (time >= REPORT_MINIMUM_TIME) {
+        PYPY_DEBUG_START("stm-report");
+        fprintf(PYPY_DEBUG_FILE, "%s  %s\n%s    %.6fs: %s\n",
+                pypy_debug_threadid, marker,
+                pypy_debug_threadid, time, cause);
+        PYPY_DEBUG_STOP("stm-report");
+    }
+}
+
 void pypy_stm_setup_expand_marker(long co_filename_ofs,
                                   long co_name_ofs,
                                   long co_firstlineno_ofs,
@@ -124,4 +148,10 @@
     g_co_firstlineno_ofs = co_firstlineno_ofs;
     g_co_lnotab_ofs = co_lnotab_ofs;
     stmcb_expand_marker = _stm_expand_marker_for_pypy;
+
+    PYPY_DEBUG_START("stm-report");
+    if (PYPY_HAVE_DEBUG_PRINTS) {
+        stmcb_debug_print = _stm_cb_debug_print;
+    }
+    PYPY_DEBUG_STOP("stm-report");
 }
diff --git a/rpython/translator/stm/test/test_ztranslated.py b/rpython/translator/stm/test/test_ztranslated.py
--- a/rpython/translator/stm/test/test_ztranslated.py
+++ b/rpython/translator/stm/test/test_ztranslated.py
@@ -152,7 +152,6 @@
             print '<', x.count, y.count, '>'
             return 0
         #
-        perform_transaction = rstm.make_perform_transaction(check, PS)
         t, cbuilder = self.compile(entry_point, backendopt=True)
         data = cbuilder.cmdexec('a b c d')
         assert '< 5 1000 >' in data, "got: %r" % (data,)
@@ -185,7 +184,6 @@
             print bug2(1)
             return 0
         #
-        perform_transaction = rstm.make_perform_transaction(check, PS)
         t, cbuilder = self.compile(entry_point, backendopt=True)
         data = cbuilder.cmdexec('')
         assert '12\n12\n' in data, "got: %r" % (data,)
@@ -219,7 +217,6 @@
             do_stuff()
             return 0
         #
-        perform_transaction = rstm.make_perform_transaction(check, PS)
         t, cbuilder = self.compile(main)
         data = cbuilder.cmdexec('')
         assert '42\n' in data, "got: %r" % (data,)
@@ -561,3 +558,40 @@
         assert ('starting some_extremely_longish_and_boring_function_name\n'
                 'File "...bla/br/project/foobaz.py", line 81,'
                 ' in some_extremely_longish_a...\n') in data
+
+    def test_pypy_marker_2(self):
+        import time
+        class PyCode(object):
+            def __init__(self, co_filename, co_name,
+                         co_firstlineno, co_lnotab):
+                self.co_filename = co_filename
+                self.co_name = co_name
+                self.co_firstlineno = co_firstlineno
+                self.co_lnotab = co_lnotab
+        #
+        def check(foobar, retry_counter):
+            if retry_counter <= 1:
+                rstm.push_marker(29, lltype.nullptr(rffi.CCHARP.TO))
+                start = time.time()
+                while abs(time.time() - start) < 0.1:
+                    pass
+                rstm.abort_and_retry()
+            return 0
+        #
+        S = lltype.GcStruct('S', ('got_exception', OBJECTPTR))
+        PS = lltype.Ptr(S)
+        perform_transaction = rstm.make_perform_transaction(check, PS)
+        def entry_point(argv):
+            pycode1 = PyCode("/tmp/foobar.py", "baz", 40, "\x00\x01\x05\x01")
+            llop.stm_setup_expand_marker_for_pypy(
+                lltype.Void, pycode1,
+                "co_filename", "co_name", "co_firstlineno", "co_lnotab")
+            perform_transaction(lltype.malloc(S))
+            return 0
+        #
+        t, cbuilder = self.compile(entry_point, backendopt=True)
+        data, err = cbuilder.cmdexec('a b c d', err=True,
+                                     env={'PYPYLOG': 'stm-report:-'})
+        assert '0#  File "?", line 0, in ?\n' in err
+        assert '0#    0.1' in err
+        assert 's: run aborted other\n' in err


More information about the pypy-commit mailing list