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

Status: RESOLVED FIXED

(Core :: JavaScript Engine, defect)

Description

[Christian Holler (:decoder)]

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

Comment 1

[Hannes Verschore [:h4writer]]

Attachment: Patch: Don't check stack corresponds when one is TL_Error

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.

Comment 3

[Benjamin Bouvier [:bbouvier] (inactive)]

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?

Comment 4

[Pulsebot]

Pushed by [e-mail]:
https://hg.mozilla.org/integration/mozilla-inbound/rev/5caa69daaa2a
TraceLogging - Don't run the debug check when the item is an error, r=bbouvier

Comment 5

[Sebastian Hengst [:aryx] (needinfo me if it's about an intermittent or backout)]

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

Comment 6

[Hannes Verschore [:h4writer]]

Attachment: Fix testing with oomTest

oomTest runs the same function the whole time again (with resetting everything), which confuses TraceLogger. Therefore forcefully reset tracelogger if that happens.

Comment 7

[Hannes Verschore [:h4writer]]

(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.

Comment 9

[Benjamin Bouvier [:bbouvier] (inactive)]

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.

Comment 10

[Hannes Verschore [:h4writer]]

Attachment: Fix testing with oomTest

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.

Comment 11

[Benjamin Bouvier [:bbouvier] (inactive)]

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!

Comment 12

[Pulsebot]

Pushed by [e-mail]:
https://hg.mozilla.org/integration/mozilla-inbound/rev/c414e9547045
TraceLogging - Don't run the debug check when the item is an error, r=bbouvier

Comment 13

[Hannes Verschore [:h4writer]]

Folded the two patches before commit.

Comment 14

[Wes Kocher (:KWierso) (Not reading bugmail; email directly if needed)]

Backed out because something from this push broke android tests like https://treeherder.mozilla.org/logviewer.html#?job_id=36245856&repo=mozilla-inbound
https://hg.mozilla.org/integration/mozilla-inbound/rev/a92600d8bbfc

Comment 15

[Pulsebot]

Pushed by [e-mail]:
https://hg.mozilla.org/integration/mozilla-inbound/rev/f7cc9e00d064
TraceLogging - Don't run the debug check when the item is an error, r=bbouvier

Comment 16

[Iris Hsiao [:ihsiao]]

https://hg.mozilla.org/mozilla-central/rev/f7cc9e00d064

Comment 17

[Hannes Verschore [:h4writer]]

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.

Comment 18

[Gerry Chang [:gchang]]

Per comment #17, mark 51 as fix-optional. If it's worth uplifting to 51, feel free to nominate it.

Comment 19

[Gary Kwong [:gkw] [:nth10sd] (NOT official MoCo now)]

(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!

Comment 20

[Hannes Verschore [:h4writer]]

(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?

Comment 21

[Gary Kwong [:gkw] [:nth10sd] (NOT official MoCo now)]

For this bug, let's just wait for the aurora merge then, I'm not too worried.