Closed Bug 1009603 Opened 11 years ago Closed 8 years ago

TraceLogger doesn't pass the test suite

Categories

(Core :: JavaScript Engine: JIT, defect)

x86_64
Linux
defect
Not set
normal

Tracking

()

RESOLVED FIXED

People

(Reporter: bbouvier, Assigned: h4writer)

References

Details

(Whiteboard: [leave open])

Attachments

(7 files, 2 obsolete files)

"Assertion failure: entry.textId() == id" shows up everywhere. That's a debug mode check in TraceLogStopEvent: if there was an entry on the stack, its text id should be the same as the one we're trying to stop. There might be other issues (see for instance bug 1006630 for an assertion that blows up if there is no filename when creating a text id). There are different reasons why this shows up. For instance, auto-regress/bug953337.js asserts with parallel compilation enabled, but doesn't if we disable parallel compilation. However, disabling parallel compilation doesn't make the entire jit-test suite pass. This assertion failing suggests that some tracelogging results might be wrong in some cases, so let's fix that.
Attached patch tracelogging-debug.patch (deleted) — Splinter Review
Useful for debugging.
Use an AutoTraceLog rather than manually starting and stoping events. This is ugly because it adds one level of indentation, but the alternative is to have the TraceLogStopEvent in all branches that return nullptr, so I am not sure which one is better.
Attachment #8421766 - Flags: review?(hv1989)
Comment on attachment 8421766 [details] [diff] [review] Part 1: Auto-stop register allocation when encountering any error Review of attachment 8421766 [details] [diff] [review]: ----------------------------------------------------------------- Yeah, the reason I didn't use an Auto was due to the extra tab. Now it seems this is a better solution then adding the stop event everywhere.
Attachment #8421766 - Flags: review?(hv1989) → review+
Thanks for the review! Bug 657197 is the first one failing locally after this patch (and the first one of bug 1006630). I reduced it to function g() { throw 'hi' } new g; I suspect the big goto in Interpret() to be the reason why the scriptLogId doesn't correspond the one when we enter, but that's just a wild guess. Also, in ~TraceLogger, there is code that just empties the entry stack by manually stopping all remaining events. That seems kinda bogus. Users should call TraceLogStop (or a variant that calls it) the correct amount of times. Could we change this code into an assertion that the entry stack is actually empty?
Attached patch Part 2: Fix throw statements (obsolete) (deleted) — Splinter Review
This brings it down from 236 to 120 issues
Blocks: 1006630
Attached patch Part 2: Fix throw statements (deleted) — Splinter Review
Down to 38 issues. Note: I think I might have found an SPS issue here. Since it never pushes the SPS information, when there are inlined frames. It should do once for the top script!
Assignee: nobody → hv1989
(In reply to Hannes Verschore [:h4writer] from comment #8) > Created attachment 8422420 [details] [diff] [review] > Part 2: Fix throw statements > > Down to 38 issues. Ok, only 18 anymore with the asm.js fix of Benjamin. > > Note: I think I might have found an SPS issue here. Since it never pushes > the SPS information, when there are inlined frames. It should do once for > the top script! It seems to be correct.
Attached patch Part 3: filename can be empty (obsolete) (deleted) — Splinter Review
Tried to find where we can have this. But didn't find it :(, so fixing it in TL itself.
Attachment #8422400 - Attachment is obsolete: true
Attachment #8421766 - Attachment description: tracelog-1.patch → Part 1: Auto-stop register allocation when encountering any error
Attached patch Part 3: Filename can be empty (deleted) — Splinter Review
Attachment #8422489 - Attachment is obsolete: true
Attachment #8423210 - Flags: review?(benj)
Attachment #8423206 - Flags: review?(benj)
Attachment #8423204 - Flags: review?(jdemooij)
Attachment #8422420 - Flags: review?(benj)
Comment on attachment 8423210 [details] [diff] [review] Part 3: Filename can be empty Review of attachment 8423210 [details] [diff] [review]: ----------------------------------------------------------------- Could you please open a follow-up bug to investigate why some scripts don't have a filename, and add a TODO in these two functions?
Attachment #8423210 - Flags: review?(benj) → review+
Comment on attachment 8422420 [details] [diff] [review] Part 2: Fix throw statements Review of attachment 8422420 [details] [diff] [review]: ----------------------------------------------------------------- Very nice find! ::: js/src/jit/IonFrames.cpp @@ +648,5 @@ > > // When profiling, each frame popped needs a notification that > // the function has exited, so invoke the probe that a function > // is exiting. > + if (!frames.more()) { nit: this same condition is tested a few lines afterwards, without any side effects in between, could you group the if bodies below?
Attachment #8422420 - Flags: review?(benj) → review+
Comment on attachment 8423204 [details] [diff] [review] Part 4: Handle debugger resumption value Review of attachment 8423204 [details] [diff] [review]: ----------------------------------------------------------------- ::: js/src/jit/VMFunctions.cpp @@ +783,3 @@ > DebugEpilogue(JSContext *cx, BaselineFrame *frame, jsbytecode *pc, bool ok) > { > + bool prevOk = ok; Remove. Not part of this patch @@ +818,5 @@ > > IonJSFrameLayout *prefix = frame->framePrefix(); > EnsureExitFrame(prefix); > cx->mainThread().jitTop = (uint8_t *)prefix; > + Remove. Not part of this patch.
Comment on attachment 8423206 [details] [diff] [review] Part 5: Handle stack mismatch gracefully (for release builds) Review of attachment 8423206 [details] [diff] [review]: ----------------------------------------------------------------- After discussion on IRC: there needs to be a stack entry, acting as the parent, so next_ should always be > 0.
Attachment #8423206 - Flags: review?(benj)
Comment on attachment 8423206 [details] [diff] [review] Part 5: Handle stack mismatch gracefully (for release builds) Review of attachment 8423206 [details] [diff] [review]: ----------------------------------------------------------------- Sorry, pressed Publish by mistake :/ Just one comment: in ~Tracelogging, could you add, before we manually empty the stack, a JS_ASSERT that stack.size() == 1? (as it only contains the parent entry, unless I am missing something else). Hopefully, it shouldn't make tests fail.
Attachment #8423206 - Flags: review+
Comment on attachment 8423204 [details] [diff] [review] Part 4: Handle debugger resumption value Review of attachment 8423204 [details] [diff] [review]: ----------------------------------------------------------------- Sorry for the delay, but I'd like to understand this a bit better before we add another function. ::: js/src/jit/VMFunctions.cpp @@ +771,5 @@ > + // the tracelogEvent. But we will run the exception handling and > + // just skipped this frame above. So run the stop event here. > + TraceLogger *logger = TraceLoggerForMainThread(cx->runtime()); > + TraceLogStopEvent(logger); > + TraceLogStopEvent(logger); Sorry if you explained this before, but why can't we do this in DebugEpilogue, right before we call EnsureExitFrame?
Attachment #8423204 - Flags: review?(jdemooij)
Comment on attachment 8423204 [details] [diff] [review] Part 4: Handle debugger resumption value Review of attachment 8423204 [details] [diff] [review]: ----------------------------------------------------------------- ::: js/src/jit/VMFunctions.cpp @@ +771,5 @@ > + // the tracelogEvent. But we will run the exception handling and > + // just skipped this frame above. So run the stop event here. > + TraceLogger *logger = TraceLoggerForMainThread(cx->runtime()); > + TraceLogStopEvent(logger); > + TraceLogStopEvent(logger); DebugEpilogue is not only used by a VM call on BaselineReturn: HandleException calls -> HandleExceptionBaseline calls -> DebugEpilogue HandleException already takes care of popping. So popping in DebugEpilogue would be bad. In order to distinguish between HandleException usecase and the VM call out of Baseline on JSOP_RETURN. I introduced the DebugEpilogueOnBaselineReturn function that is the same as DebugEpilogue, except to distinguish when it has to pop or not. (Note: I think it is bad practice to have a function in VMFunction.cpp used in jit/IonFrames.cpp though)
What you are suggesting was my first patch, though. But looking at the next jit-failures I implemented this solution to fix the issue described in previous comment.
See comment 21 for the answer on your question.
Flags: needinfo?(jdemooij)
Comment on attachment 8423204 [details] [diff] [review] Part 4: Handle debugger resumption value Review of attachment 8423204 [details] [diff] [review]: ----------------------------------------------------------------- Sorry for the delay! You could also check in HandleException(Baseline) if calledDebugEpilogue == true, in that case you can skip the TraceLogStopEvent calls. I'm fine with either approach. As discussed on IRC last week, I'm not sure if leaving Baseline here is correct because we can re-enter Baseline from the exception handler (for a catch block). As this is TraceLogger + debug-mode only though, I'll r+ this patch. ::: js/src/jit/VMFunctions.cpp @@ +768,5 @@ > +{ > + if (!DebugEpilogue(cx, frame, pc, true)) { > + // We would have returned gracefully and ran the epilogue which pops > + // the tracelogEvent. But we will run the exception handling and > + // just skipped this frame above. So run the stop event here. // DebugEpilogue popped the frame by updating jitTop, so run the stop event // here before we enter the exception handler. @@ +770,5 @@ > + // We would have returned gracefully and ran the epilogue which pops > + // the tracelogEvent. But we will run the exception handling and > + // just skipped this frame above. So run the stop event here. > + TraceLogger *logger = TraceLoggerForMainThread(cx->runtime()); > + TraceLogStopEvent(logger); Please explain briefly what these two TraceLogStopEvent calls do, something like: TraceLogStopEvent(logger); // Leave script. TraceLogStopEvent(logger); // Leave Baseline. Or something.
Attachment #8423204 - Flags: review+
Flags: needinfo?(jdemooij)
Backed out for compilation errors: eg https://tbpl.mozilla.org/php/getParsedLog.php?id=41350296&tree=Mozilla-Inbound /builds/slave/m-in-linux32_g-d-0000000000000/build/js/src/jit/IonFrames.cpp: In function 'void js::jit::HandleException(js::jit::ResumeFromException*)': /builds/slave/m-in-linux32_g-d-0000000000000/build/js/src/jit/IonFrames.cpp:586:5: error: 'TraceLogger' was not declared in this scope /builds/slave/m-in-linux32_g-d-0000000000000/build/js/src/jit/IonFrames.cpp:586:18: error: 'logger' was not declared in this scope /builds/slave/m-in-linux32_g-d-0000000000000/build/js/src/jit/IonFrames.cpp:586:65: error: 'TraceLoggerForMainThread' was not declared in this scope /builds/slave/m-in-linux32_g-d-0000000000000/build/js/src/jit/IonFrames.cpp:641:47: error: 'TraceLogger' is not a class, namespace, or enumeration /builds/slave/m-in-linux32_g-d-0000000000000/build/js/src/jit/IonFrames.cpp:641:69: error: 'TraceLogStopEvent' was not declared in this scope /builds/slave/m-in-linux32_g-d-0000000000000/build/js/src/jit/IonFrames.cpp:672:39: error: 'TraceLogger' is not a class, namespace, or enumeration /builds/slave/m-in-linux32_g-d-0000000000000/build/js/src/jit/IonFrames.cpp:672:60: error: 'TraceLogStopEvent' was not declared in this scope remote: https://hg.mozilla.org/integration/mozilla-inbound/rev/c2157cc57374 remote: https://hg.mozilla.org/integration/mozilla-inbound/rev/57e78bbcbebc remote: https://hg.mozilla.org/integration/mozilla-inbound/rev/0f62aa632347 remote: https://hg.mozilla.org/integration/mozilla-inbound/rev/febd5a89bd11
Status: NEW → RESOLVED
Closed: 8 years ago
Resolution: --- → FIXED
You need to log in before you can comment on or make changes to this bug.

Attachment

General

Created:
Updated:
Size: