1307354 - Crash [@ js::TraceLoggerEvent::TraceLoggerEvent]

Status: RESOLVED FIXED

(Core :: JavaScript Engine, defect)

Description

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

The following testcase crashes on mozilla-central revision 955840bfd3c2 (build with --enable-debug --enable-more-deterministic, run with --fuzzing-safe --no-threads --no-baseline --no-ion):

function h1(f) {
    for (var j = 0; j < 99; ++j) {
        try {
            f();
        } catch (e) {
            "" + e;
        }
    }
}
function m(x) {
    Function(x)()
}
m("\
    function g1() {\
        du.setupTraceLoggerScriptCalls();\
        du.startTraceLogger();\
    }\
    function g2() {\
        g1();\
    }\
    var du = Debugger();\
    g2();\
");
m("\
    h1(function() {});\
    function h2() {\
        return function ()(\
            function h3() {\
                h3();\
            }()\
        );\
    }\
    h1(h2());\
")


Backtrace:

0   js-dbg-64-dm-clang-darwin-955840bfd3c2	0x000000010852f33c js::TraceLoggerEvent::TraceLoggerEvent(js::TraceLoggerThread*, TraceLoggerTextId, JSScript*) + 76 (TraceLogging.h:150)
1   js-dbg-64-dm-clang-darwin-955840bfd3c2	0x0000000108bfad49 Interpret(JSContext*, js::RunState&) + 34921 (Interpreter.cpp:2989)
2   js-dbg-64-dm-clang-darwin-955840bfd3c2	0x0000000108bf22e4 js::RunScript(JSContext*, js::RunState&) + 452 (Interpreter.cpp:404)
3   js-dbg-64-dm-clang-darwin-955840bfd3c2	0x0000000108c0507f js::ExecuteKernel(JSContext*, JS::Handle<JSScript*>, JSObject&, JS::Value const&, js::AbstractFramePtr, JS::Value*) + 511 (Interpreter.cpp:685)
/snip

For detailed crash information, see attachment.

Comment 1

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

Attachment: Detailed Crash Information

Comment 2

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

autoBisect shows this is probably related to the following changeset:

The first bad revision is:
changeset:   https://hg.mozilla.org/mozilla-central/rev/7a942a270777
user:        Hannes Verschore
date:        Tue Jun 21 13:52:11 2016 +0200
summary:     Bug 1280648 - Tracelogger: Don't cache based on pointers to movable gc things, r=bbouvier

Hannes, is bug 1280648 a likely regressor?

Note that this may take 10-15 seconds to crash. Also, it would be good to backport this at least to mozilla-aurora, because it is hard to get a reliable testcase.

Comment 3

[Hannes Verschore [:h4writer]]

Attachment: Patch

This fixes the issue. The AutoTraceLog could overflow the memory and as a result we would check every Payload and remove if the "use count" was 0. Since we just created it, it is still zero. We only increase it in the caller. 
Fix is to temporarily set it to 0. Making sure we survive the AutoTraceLog and set it to 0, just before returning.

Comment 4

[Benjamin Bouvier [:bbouvier] (inactive)]

Comment on attachment 8802898 [details] [diff] [review]
Patch

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

Sorry, cancelling review: I'd like to see a simpler (if possible) test case triggering this, included in the patch. I don't understand the initial issue (this AutoTraceLog uses the uint32_t ctor, not the Event ctor, so there's no use count involved here?), so I don't understand the fix either. The usage of ScopeExit could probably be made simpler.

::: js/src/vm/TraceLogging.cpp
@@ +384,5 @@
>          return nullptr;
>      }
>  
> +    // Temporarily mark the payload as used. To make sure it doesn't get GC'ed.
> +    payload->use();

I think this needs its own ScopeExit with a payload->release() (if one of the functions are failing too in the meanwhile, like the call to pointerMap.add)

@@ +396,5 @@
>          return nullptr;
>  
> +    // Emit the end of the internal time and remove the temporary mark.
> +    guardInternalStopEvent.release();
> +    stopEvent(TraceLogger_Internal);

The comment at the top of MakeScopeExit seems to say that the functor is called at the end of scope anyways; in this case, we could just remove the last two lines, right?

@@ +477,5 @@
>  
> +    // Emit the end of the internal time and remove the temporary mark.
> +    guardInternalStopEvent.release();
> +    stopEvent(TraceLogger_Internal);
> +    payload->release();

Same comments apply.

Comment 5

[Hannes Verschore [:h4writer]]

Attachment: Patch

After discussion on irc we think this is better? Like said on IRC adding a testcase will be hard, since it needs to be timed and consume the whole buffer.

Comment 6

[Hannes Verschore [:h4writer]]

Attachment: Patch

With better hgrc to include more context

Comment 7

[Hannes Verschore [:h4writer]]

Comment on attachment 8803312 [details] [diff] [review]
Patch

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

::: js/src/vm/TraceLogging.cpp
@@ +383,5 @@
>          return nullptr;
>      }
>  
>      if (!textIdPayloads.putNew(textId, payload)) {
>          js_delete(payload);

add
payload = nullptr;

Comment 8

[Benjamin Bouvier [:bbouvier] (inactive)]

Comment on attachment 8803312 [details] [diff] [review]
Patch

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

Thanks for the explanation on IRC (and for including more context in your patches).

::: js/src/vm/TraceLogging.cpp
@@ +383,5 @@
>          return nullptr;
>      }
>  
>      if (!textIdPayloads.putNew(textId, payload)) {
>          js_delete(payload);

Alternatively: in the guard, if (payload && payload->uses())

This way, you could even use a UniquePtr<TraceLoggerEventPayload> and remove these ugly calls to js_delete ;)

Comment 9

[Pulsebot]

Pushed by [e-mail]:
https://hg.mozilla.org/integration/mozilla-inbound/rev/062db36d2f0b
TraceLogging - Make sure the payload is marked as used during creation, r=bbouvier

Comment 10

[Carsten Book [:Tomcat]]

https://hg.mozilla.org/mozilla-central/rev/062db36d2f0b