Closed Bug 1302417 Opened 3 years ago Closed 3 years ago

Assertion failure: prev >= TraceLogger_Last, at js/src/vm/TraceLogging.cpp:542 with OOM

Categories

(Core :: JavaScript Engine, defect, critical)

x86_64
Linux
defect
Not set
critical

Tracking

()

RESOLVED FIXED
mozilla52
Tracking Status
firefox51 --- fix-optional
firefox52 --- fixed

People

(Reporter: decoder, Assigned: h4writer)

References

(Blocks 2 open bugs)

Details

(Keywords: assertion, jsbugmon, testcase, Whiteboard: [jsbugmon:update,bisect])

Attachments

(2 files, 1 obsolete file)

The following testcase crashes on mozilla-central revision cfdb7af3af2e (build with --enable-posix-nspr-emulation --enable-valgrind --enable-gczeal --disable-tests --enable-debug --enable-optimize, run with --fuzzing-safe --ion-offthread-compile=off):

lfLogBuffer = `
  var du = new Debugger;
  du.setupTraceLoggerScriptCalls();
  startTraceLogger();
`;
loadFile(lfLogBuffer);
 function loadFile(lfVarx) {
     oomTest(function() {
         m = parseModule(lfVarx);
         m.declarationInstantiation();
         m.evaluation();
     })
 }



Backtrace:

 received signal SIGSEGV, Segmentation fault.
0x000000000051a58d in js::TraceLoggerThread::stopEvent (this=0x7ffff69a0040, id=23) at js/src/vm/TraceLogging.cpp:542
#0  0x000000000051a58d in js::TraceLoggerThread::stopEvent (this=0x7ffff69a0040, id=23) at js/src/vm/TraceLogging.cpp:542
#1  0x00007ffff7e35fea in ?? ()
[...]
#6  0x0000000000000000 in ?? ()
rax	0x0	0
rbx	0x7ffff69a0040	140737330675776
rcx	0x7ffff6c28a2d	140737333332525
rdx	0x0	0
rsi	0x7ffff6ef7770	140737336276848
rdi	0x7ffff6ef6540	140737336272192
rbp	0x7fffffffb7d0	140737488336848
rsp	0x7fffffffb7b0	140737488336816
r8	0x7ffff6ef7770	140737336276848
r9	0x7ffff7fe4740	140737354024768
r10	0x58	88
r11	0x7ffff6b9f750	140737332770640
r12	0x17	23
r13	0x7fffffffc370	140737488339824
r14	0x2044	8260
r15	0x7fffffffbd40	140737488338240
rip	0x51a58d <js::TraceLoggerThread::stopEvent(unsigned int)+381>
=> 0x51a58d <js::TraceLoggerThread::stopEvent(unsigned int)+381>:	movl   $0x0,0x0
   0x51a598 <js::TraceLoggerThread::stopEvent(unsigned int)+392>:	ud2
Flags: needinfo?(hv1989)
When we encounter TL_Error anything could have happened and everything after that could be wrong (wrt creating the graph). For now I disable the checking the corresponding debug stack slot. Though it could be I'll have to disable checking after seeing TL_Error anymore. But lets try this first.
Assignee: nobody → hv1989
Flags: needinfo?(hv1989)
Attachment #8791598 - Flags: review?(bbouvier)
Duplicate of this bug: 1302411
Comment on attachment 8791598 [details] [diff] [review]
Patch: Don't check stack corresponds when one is TL_Error

Review of attachment 8791598 [details] [diff] [review]:
-----------------------------------------------------------------

::: js/src/vm/TraceLogging.cpp
@@ +535,5 @@
>  #ifdef DEBUG
>      if (enabled_ > 0 && !graphStack.empty()) {
>          uint32_t prev = graphStack.popCopy();
> +        if (id == TraceLogger_Error || prev == TraceLogger_Error) {
> +            // Ignore

Can you add a light comment why it needs ignoring?
Attachment #8791598 - Flags: review?(bbouvier) → review+
Pushed by hv1989@gmail.com:
https://hg.mozilla.org/integration/mozilla-inbound/rev/5caa69daaa2a
TraceLogging - Don't run the debug check when the item is an error, r=bbouvier
Backed out for asserting at TraceLogging.cpp line 548 in many spidermonkey tests:

https://hg.mozilla.org/integration/mozilla-inbound/rev/106eed4b1b0a

Push with failures: https://treeherder.mozilla.org/#/jobs?repo=mozilla-inbound&revision=416c73ba796b2d0a5f4c6ce8f8cd4ab6029b9f81
Failure log: https://treeherder.mozilla.org/logviewer.html#?job_id=36141619&repo=mozilla-inbound

opt: check for oomTest is missing: https://treeherder.mozilla.org/logviewer.html#?job_id=36141619&repo=mozilla-inbound
debug: assertion: https://treeherder.mozilla.org/logviewer.html#?job_id=36141609&repo=mozilla-inbound

TEST-PASS | js/src/jit-test/tests/tracelogger/setupTraceLogger.js | Success (code 0, args "")
Assertion failure: strcmp(eventText(id), eventText(prev)) == 0, at /home/worker/workspace/build/src/js/src/vm/TraceLogging.cpp:548
Exit code: -11
FAIL - tracelogger/bug1302417.js
TEST-UNEXPECTED-FAIL | js/src/jit-test/tests/tracelogger/bug1302417.js | Assertion failure: strcmp(eventText(id), eventText(prev)) == 0, at /home/worker/workspace/build/src/js/src/vm/TraceLogging.cpp:548 (code -11, args "--no-baseline --no-ion")
INFO exit-status     : -11
INFO timed-out       : False
INFO stderr         2> Assertion failure: strcmp(eventText(id), eventText(prev)) == 0, at /home/worker/workspace/build/src/js/src/vm/TraceLogging.cpp:548
Flags: needinfo?(hv1989)
Attached patch Fix testing with oomTest (obsolete) — Splinter Review
oomTest runs the same function the whole time again (with resetting everything), which confuses TraceLogger. Therefore forcefully reset tracelogger if that happens.
Flags: needinfo?(hv1989)
Attachment #8792912 - Flags: review?(bbouvier)
(In reply to Hannes Verschore [:h4writer] from comment #6)
> Created attachment 8792912 [details] [diff] [review]
> Fix testing with oomTest
> 
> oomTest runs the same function the whole time again (without resetting
> everything), which confuses TraceLogger. Therefore forcefully reset
> tracelogger if that happens.
Duplicate of this bug: 1302412
Comment on attachment 8792912 [details] [diff] [review]
Fix testing with oomTest

Review of attachment 8792912 [details] [diff] [review]:
-----------------------------------------------------------------

Sorry, i spotted a small issue which can cause an iloop, so I'm curious to see what the righteous fix would look like here.

::: js/src/builtin/TestingFunctions.cpp
@@ +1400,5 @@
> +            // Reset the TraceLogger state if enabled.
> +            TraceLoggerThread* logger = TraceLoggerForMainThread(cx->runtime());
> +            if (logger->enabled()) {
> +                while (logger->enabled())
> +                    logger->disable();

logger->disable() can return false and not decrement enabled_ if it is in the failed_ state.
Attachment #8792912 - Flags: review?(bbouvier)
Failed and enabled is linked to each other.
When failed_ is set to true, enabled_ is also set to 0.

See:
https://dxr.mozilla.org/mozilla-central/rev/62f79d676e0e11b3ad59a5425b3ebb3ec5bbefb5/js/src/vm/TraceLogging.cpp#198

I added an assert to make that more clear.
Attachment #8792912 - Attachment is obsolete: true
Attachment #8793339 - Flags: review?(bbouvier)
Comment on attachment 8793339 [details] [diff] [review]
Fix testing with oomTest

Review of attachment 8793339 [details] [diff] [review]:
-----------------------------------------------------------------

Works for me, thanks!

::: js/src/jit-test/tests/tracelogger/bug1302417.js
@@ +1,3 @@
>  
> +if (!('oomTest' in this))
> +        quit();

uber-nit: indent!
Attachment #8793339 - Flags: review?(bbouvier) → review+
Pushed by hv1989@gmail.com:
https://hg.mozilla.org/integration/mozilla-inbound/rev/c414e9547045
TraceLogging - Don't run the debug check when the item is an error, r=bbouvier
Folded the two patches before commit.
Depends on: 1304628
Pushed by hv1989@gmail.com:
https://hg.mozilla.org/integration/mozilla-inbound/rev/f7cc9e00d064
TraceLogging - Don't run the debug check when the item is an error, r=bbouvier
https://hg.mozilla.org/mozilla-central/rev/f7cc9e00d064
Status: NEW → RESOLVED
Closed: 3 years ago
Resolution: --- → FIXED
Target Milestone: --- → mozilla52
Note on uplifting to FF51. 
Patch 1) This assert was an overly strict assert that was fixed. I can backport it, but it has no extra value.
Patch 2) Reset TL when using oomTest. This is a fuzzers only functions. Again no extra value of having it backported.

I have no issue on backporting. But not seeing immediate reason to do it. If there are no complains, I will not backport.
Per comment #17, mark 51 as fix-optional. If it's worth uplifting to 51, feel free to nominate it.
(In reply to Hannes Verschore [:h4writer] from comment #17)
> I have no issue on backporting. But not seeing immediate reason to do it. If
> there are no complains, I will not backport.

Please backport, while the signature numbers on mozilla-aurora for fuzzing is not a lot, it still would be nice to have this one. Thanks!
Flags: needinfo?(hv1989)
(In reply to Gary Kwong [:gkw] [:nth10sd] from comment #19)
> (In reply to Hannes Verschore [:h4writer] from comment #17)
> > I have no issue on backporting. But not seeing immediate reason to do it. If
> > there are no complains, I will not backport.
> 
> Please backport, while the signature numbers on mozilla-aurora for fuzzing
> is not a lot, it still would be nice to have this one. Thanks!

I could make these asserts Nightly only if that helps? That way we won't have these fuzzing signatures on aurora.
Or uplift a patch that removes these asserts on aurora for now? Since this fix is on nightly we have the asserts again when merging to aurora but not the errors since they are fixed?
Flags: needinfo?(hv1989)
For this bug, let's just wait for the aurora merge then, I'm not too worried.
You need to log in before you can comment on or make changes to this bug.