improve tracing/recording diagnostics
authorshaver@mozilla.org
Sun, 20 Jul 2008 15:42:19 -0400
changeset 17766 55ed09e74ccf4dcbd06b209fff1a76a0e79b8c47
parent 17765 6f2f72b0dc05aab20d81c1cf90c873dfc5d92652
child 17767 fb2591c91c916e7cd188da0fe399e937e4f91c2b
child 17769 c4a57a85b10101a4a63e2390253358a72e170b13
push id1452
push usershaver@mozilla.com
push dateFri, 22 Aug 2008 00:08:22 +0000
treeherderautoland@d13bb0868596 [default view] [failures only]
perfherder[talos] [build metrics] [platform microbench] (compared to previous push)
milestone1.9.1a1pre
improve tracing/recording diagnostics
js/src/jsinterp.cpp
js/src/jstracer.cpp
js/src/jstracer.h
--- a/js/src/jsinterp.cpp
+++ b/js/src/jsinterp.cpp
@@ -2738,25 +2738,25 @@ js_Interpret(JSContext *cx)
 #define LOAD_OBJECT(PCOFF)                                                    \
     JS_GET_SCRIPT_OBJECT(script, GET_FULL_INDEX(PCOFF), obj)
 
 #define LOAD_FUNCTION(PCOFF)                                                  \
     JS_GET_SCRIPT_FUNCTION(script, GET_FULL_INDEX(PCOFF), fun)
 
 #ifdef JS_TRACER
 
-#define MONITOR_BRANCH()                                                      \
+#define MONITOR_BRANCH(oldpc)                                                 \
     JS_BEGIN_MACRO                                                            \
         if (TRACING_ENABLED(cx))                                              \
-            ENABLE_TRACER(js_LoopEdge(cx));                                   \
+            ENABLE_TRACER(js_LoopEdge(cx, oldpc));                            \
     JS_END_MACRO
 
 #else /* !JS_TRACER */
 
-#define MONITOR_BRANCH() do { } while(0)
+#define MONITOR_BRANCH(oldpc) do { } while(0)
 
 #endif /* !JS_TRACER */
 
     /*
      * Prepare to call a user-supplied branch handler, and abort the script
      * if it returns false.
      */
 #define CHECK_BRANCH()                                                        \
@@ -2766,17 +2766,17 @@ js_Interpret(JSContext *cx)
                 goto error;                                                   \
         }                                                                     \
     JS_END_MACRO
 
 #define BRANCH(n)                                                             \
     JS_BEGIN_MACRO                                                            \
         regs.pc += n;                                                         \
         if (n <= 0) {                                                         \
-            MONITOR_BRANCH();                                                 \
+            MONITOR_BRANCH(regs.pc - n);                                      \
             CHECK_BRANCH();                                                   \
         }                                                                     \
         op = (JSOp) *regs.pc;                                                 \
         DO_OP();                                                              \
     JS_END_MACRO
 
     /*
      * Optimized Get and SetVersion for proper script language versioning.
--- a/js/src/jstracer.cpp
+++ b/js/src/jstracer.cpp
@@ -441,18 +441,19 @@ TraceRecorder::TraceRecorder(JSContext* 
     this->lirbuf = _fragment->lirbuf;
     this->fragmentInfo = (VMFragmentInfo*)_fragment->root->vmprivate;
     JS_ASSERT(fragmentInfo != NULL);
     this->entryFrame = fragmentInfo->entryFrame;
     this->entryRegs = &fragmentInfo->entryRegs;
     this->atoms = cx->fp->script->atomMap.vector;
 
 #ifdef DEBUG
-    printf("recording starting from %s:%u\n", cx->fp->script->filename,
-           js_PCToLineNumber(cx, cx->fp->script, entryRegs->pc));
+    printf("recording starting from %s:%u@%u\n", cx->fp->script->filename,
+           js_PCToLineNumber(cx, cx->fp->script, entryRegs->pc),
+           entryRegs->pc - cx->fp->script->code);
 #endif
 
     lir = lir_buf_writer = new (&gc) LirBufWriter(lirbuf);
 #ifdef DEBUG
     lir = verbose_filter = new (&gc) VerboseWriter(&gc, lir, lirbuf->names);
 #endif
     lir = cse_filter = new (&gc) CseFilter(lir, &gc);
     lir = expr_filter = new (&gc) ExprFilter(lir);
@@ -1080,17 +1081,17 @@ js_StartRecorder(JSContext* cx, GuardRec
 {
     /* start recording if no exception during construction */
     JS_TRACE_MONITOR(cx).recorder = new (&gc) TraceRecorder(cx, anchor, f, typeMap);
     if (anchor) {
         f->calldepth = anchor->calldepth;
         f->addLink(anchor);
     }
     if (cx->throwing) {
-        js_AbortRecording(cx, "setting up recorder failed");
+        js_AbortRecording(cx, NULL, "setting up recorder failed");
         return false;
     }
     return true;
 }
 
 static bool
 js_IsLoopExit(JSContext* cx, JSScript* script, jsbytecode* pc)
 {
@@ -1118,17 +1119,17 @@ js_IsLoopExit(JSContext* cx, JSScript* s
         return true;
     }
     return false;
 }
 
 #define HOTLOOP 10
 
 bool
-js_LoopEdge(JSContext* cx)
+js_LoopEdge(JSContext* cx, jsbytecode* oldpc)
 {
     JSTraceMonitor* tm = &JS_TRACE_MONITOR(cx);
 
     /* is the recorder currently active? */
     if (tm->recorder) {
         TraceRecorder* r = tm->recorder;
 #ifdef JS_THREADSAFE
         /* XXX should this test not be earlier, to avoid even recording? */
@@ -1140,17 +1141,21 @@ js_LoopEdge(JSContext* cx)
         }
 #endif
         if (cx->fp->regs->pc == r->getFragment()->root->ip) { /* did we hit the start point? */
             AUDIT(traceCompleted);
             r->closeLoop(JS_TRACE_MONITOR(cx).fragmento);
             js_DeleteRecorder(cx);
         } else {
             AUDIT(returnToDifferentLoopHeader);
-            js_AbortRecording(cx, "Loop edge does not return to header");
+            debug_only(printf("loop edge %d -> %d, header %d\n",
+                              oldpc - cx->fp->script->code,
+                              cx->fp->regs->pc - cx->fp->script->code,
+                              (jsbytecode*)r->getFragment()->root->ip - cx->fp->script->code));
+            js_AbortRecording(cx, oldpc, "Loop edge does not return to header");
         }
         return false; /* done recording */
     }
 
     Fragment* f = tm->fragmento->getLoop(cx->fp->regs->pc);
     if (!f->code()) {
         if (++f->hits() == HOTLOOP) {
             AUDIT(recorderStarted);
@@ -1209,17 +1214,19 @@ js_LoopEdge(JSContext* cx)
     }
 
     AUDIT(traceTriggered);
 
     /* execute previously recorded trace */
     VMFragmentInfo* fi = (VMFragmentInfo*)f->vmprivate;
     if (OBJ_SCOPE(JS_GetGlobalForObject(cx, cx->fp->scopeChain))->shape != fi->globalShape) {
         AUDIT(globalShapeMismatchAtEntry);
-        debug_only(printf("global shape mismatch, discarding trace.\n");)
+        debug_only(printf("global shape mismatch, discarding trace (started pc %u line %u).\n",
+                          (jsbytecode*)f->root->ip - cx->fp->script->code,
+                          js_PCToLineNumber(cx, cx->fp->script, (jsbytecode*)f->root->ip));)
         f->releaseCode(tm->fragmento);
         return false;
     }
 
     double* native = (double *)alloca((fi->maxNativeFrameSlots+1) * sizeof(double));
     debug_only(*(uint64*)&native[fi->maxNativeFrameSlots] = 0xdeadbeefdeadbeefLL;)
     if (!unbox(cx, fi->ngslots, fi->gslots, cx->fp, cx->fp, fi->typeMap, native)) {
         AUDIT(typeMapMismatchAtEntry);
@@ -1232,29 +1239,31 @@ js_LoopEdge(JSContext* cx)
     InterpState state;
     state.ip = cx->fp->regs->pc;
     state.sp = (void*)entry_sp;
     state.rp = callstack;
     state.cx = cx;
     union { NIns *code; GuardRecord* (FASTCALL *func)(InterpState*, Fragment*); } u;
     u.code = f->code();
 #if defined(DEBUG) && defined(NANOJIT_IA32)
-    printf("entering trace at %s:%u, sp=%p\n",
+    printf("entering trace at %s:%u@%u, sp=%p\n",
            cx->fp->script->filename, js_PCToLineNumber(cx, cx->fp->script, cx->fp->regs->pc),
+           cx->fp->regs->pc - cx->fp->script->code,
            state.sp);
     uint64 start = rdtsc();
 #endif
     GuardRecord* lr = u.func(&state, NULL);
     JS_ASSERT(lr->calldepth == 0);
     cx->fp->regs->sp += (lr->exit->sp_adj / sizeof(double));
     cx->fp->regs->pc += lr->exit->ip_adj;
 #if defined(DEBUG) && defined(NANOJIT_IA32)
-    printf("leaving trace at %s:%u, sp=%p, cycles=%llu\n",
+    printf("leaving trace at %s:%u@%u, sp=%p, ip=%p, cycles=%llu\n",
            cx->fp->script->filename, js_PCToLineNumber(cx, cx->fp->script, cx->fp->regs->pc),
-           state.sp,
+           cx->fp->regs->pc - cx->fp->script->code,
+           state.sp, lr->jmp,
            (rdtsc() - start));
 #endif
     box(cx, fi->ngslots, fi->gslots, cx->fp, cx->fp, lr->exit->typeMap, native);
     JS_ASSERT(*(uint64*)&native[fi->maxNativeFrameSlots] == 0xdeadbeefdeadbeefLL);
 
     AUDIT(sideExitIntoInterpreter);
     
     /* if the side exit terminates the loop, don't try to attach a trace here */
@@ -1272,22 +1281,23 @@ js_LoopEdge(JSContext* cx)
     c->root = f->root;
     c->calldepth = lr->calldepth;
 
     /* record secondary trace */
     return js_StartRecorder(cx, lr, c, lr->guard->exit()->typeMap);
 }
 
 void
-js_AbortRecording(JSContext* cx, const char* reason)
+js_AbortRecording(JSContext* cx, jsbytecode* abortpc, const char* reason)
 {
     AUDIT(recorderAborted);
-    debug_only(printf("Abort recording (line %d, pc %d): %s.\n",
-                      js_PCToLineNumber(cx, cx->fp->script, cx->fp->regs->pc),
-                      cx->fp->regs->pc - cx->fp->script->code, reason);)
+    debug_only(if (!abortpc) abortpc = cx->fp->regs->pc;
+               printf("Abort recording (line %d, pc %d): %s.\n",
+                      js_PCToLineNumber(cx, cx->fp->script, abortpc),
+                      abortpc - cx->fp->script->code, reason);)
     JS_ASSERT(JS_TRACE_MONITOR(cx).recorder != NULL);
     Fragment* f = JS_TRACE_MONITOR(cx).recorder->getFragment();
     f->blacklist();
     if (f->root == f) {
         AUDIT(typeMapTrashed);
         debug_only(printf("Root fragment aborted, trashing the type map.\n");)
         VMFragmentInfo* fi = (VMFragmentInfo*)f->vmprivate;
         JS_ASSERT(fi->typeMap);
--- a/js/src/jstracer.h
+++ b/js/src/jstracer.h
@@ -236,26 +236,26 @@ public:
 };
 
 #define TRACING_ENABLED(cx)       JS_HAS_OPTION(cx, JSOPTION_JIT)
 
 #define RECORD(x)                                                             \
     JS_BEGIN_MACRO                                                            \
         TraceRecorder* r = JS_TRACE_MONITOR(cx).recorder;                     \
         if (!r->record_##x()) {                                               \
-            js_AbortRecording(cx, #x);                                        \
+            js_AbortRecording(cx, NULL, #x);                                  \
             ENABLE_TRACER(0);                                                 \
         }                                                                     \
     JS_END_MACRO
 
 extern bool
-js_LoopEdge(JSContext* cx);
+js_LoopEdge(JSContext* cx, jsbytecode* oldpc);
 
 extern void
-js_AbortRecording(JSContext* cx, const char* reason);
+js_AbortRecording(JSContext* cx, jsbytecode* abortpc, const char* reason);
 
 extern void
 js_InitJIT(JSContext* cx);
 
 extern void
 js_DestroyJIT(JSContext* cx);
 
 #endif /* jstracer_h___ */