Closed Bug 1148593 Opened 10 years ago Closed 9 years ago

addEventListener should use JS::AutoSetAsyncStackForNewCalls

Categories

(Core :: DOM: Core & HTML, defect)

Product:
Core
Component:
DOM: Core & HTML
Platform:
x86
macOS
Type:
defect
Priority:
Not set
Severity:
normal

Tracking

()

Status:
RESOLVED FIXED
Milestone:
mozilla42
Tracking Flags:
Tracking Status
firefox42 --- fixed
relnote-firefox --- 42+

People

(Reporter: fitzgen, Assigned: tromey)

References

(Blocks 1 open bug)

Details

(Keywords: dev-doc-needed)

Attachments

(2 files, 25 obsolete files)

Pass JSContext to CallbackObject constructor.
11.29 KB, patch
tromey
: review+
Details | Diff | Splinter Review
create async stack in callback objects
50.38 KB, patch
tromey
: review+
Details | Diff | Splinter Review
So that we have async stacks that span from addEventListener to the event handler getting called.
Should this be generalized for all the (WebIDL) callbacks? AnimationFrame callbacks, events listeners and handlers, mutation observer callbacks, ...
(In reply to Olli Pettay [:smaug] from comment #1) > Should this be generalized for all the (WebIDL) callbacks? AnimationFrame > callbacks, events listeners and handlers, mutation observer callbacks, ... Are all webidl callbacks async? If so, yes. If not, then probably not.
Well, what do you mean with async? Callbacks are usually: you set the callback, and it is called later.
(In reply to Olli Pettay [:smaug] from comment #3) > Well, what do you mean with async? > Callbacks are usually: you set the callback, and it is called later. I guess I meant if it is going to run in another tick of the event loop or not. I'm not sure NodeFilter#acceptNode's callback would benefit much from an "async" stack being tagged on. But XHR, event listeners, etc yes for sure.
The common case for callbacks is to be called sometime later.
Here's a patch implementing the generic approach. It modifies CallbackObject to save the stack. I haven't written tests yet, but I have seen it make async stacks with XHR using the timeline. I think this approach would solve a handful of the dependencies of bug 981514. However, I'm concerned about the performance regression indicated in bug 1152893.
Yeah, I think we need to sort out bug 1152893 before landing the fix for this bug. Or at least make sure the slow code path isn't enabled on release builds.
Depends on: 1152893
(In reply to Olli Pettay [:smaug] from comment #7) > Or at least make sure the slow code path isn't enabled on release builds. That's bug 1158133. Then, as soon as both Promise and setTimeout both use async stacks, the plan is to enable them by default in early beta for some time on Desktop only, and move to Release if this doesn't create noticeable effects (excluding the synthetic benchmarks in bug 1152893).
Depends on: 1158133
No longer depends on: 1152893
Assignee: nobody → ttromey
Status: NEW → ASSIGNED
Here's the patch again, this time with tests. The tests show that we can close a number of other related bugs. I also included Nick's test from bug 1142577, slightly updated as the async cause is a bit different with this approach. It seems to me that, since there is a plan in place to address the performance issues, there is no reason to delay this patch.
Attachment #8600968 - Attachment is obsolete: true
Attachment #8620389 - Flags: review?(bugs)
Was about to comment that we should make sure that we get the test cases from https://bugzilla.mozilla.org/attachment.cgi?id=8589920 but I see you already have them! Carry on!
(In reply to :Paolo Amadini from comment #8) > (In reply to Olli Pettay [:smaug] from comment #7) > > Or at least make sure the slow code path isn't enabled on release builds. > > That's bug 1158133. Then, as soon as both Promise and setTimeout both use > async stacks, the plan is to enable them by default in early beta for some > time on Desktop only, and move to Release if this doesn't create noticeable > effects (excluding the synthetic benchmarks in bug 1152893). Why is that the plan? Shouldn't the slow stuff be disabled by default, and if one uses devtools, there should be some way to enable.
Blocks: 906239
Comment on attachment 8620389 [details] [diff] [review] create async stack in callback objects bz, I think you should review this given its changes to CallbackObject. But if you're busy with other stuff, put it back to my queue.
Attachment #8620389 - Flags: review?(bugs) → review?(bzbarsky)
> since there is a plan in place to address the performance issues Here's what I would like to know as input to that decision: 1) For a typical requestAnimationFrame consumer of this form: function f() { requestAnimationFrame(f); } f(); how much time does the requestAnimationFrame call take with and without this patch? Just measuring this on desktop is ok for now; I want to have an idea of what the frame budget looks like with/without this stuff. 2) Whether there is any impact on event dispatch times from this change. Olli has some testcases he can point you to.
tromey did run some of my tests, and seems like ~8% regression in event _handling_ perf, which is IMO quite a lot for some feature which might be on all the time bug actually used very rarely. I'd prefer to have some option in devtools to enable all this.
Comment on attachment 8620389 [details] [diff] [review] create async stack in callback objects >+ if (mAsyncStack->get()) { if (*mAsyncStack) { >+ mAsyncCause.emplace(cx, JS_NewStringCopyZ(cx, aExecutionReason)); This does not make me happy. We had a plan to just keep execution reasons as const char* until someone really needed something else, precisely to avoid this sort of GC churn. What happened to that plan? Why, exactly, do we require a full-up JSString for the async cause? The only good news here is that at least the handling of null aExecutionReason (the common case so far) is not insane. But since we're trying to move toward providing execution reasons more and more... Also, I can't evaluate whether aExecutionReason is even an appropriate thing to use for the async cause, because there is zero documentation for async cause anywhere I can find. Please fix that if you know what it's _supposed_ to be; then I can try to figure out whether this even makes sense. >+ if (mAsyncCause->get()) { if (*mAsyncCause) >+ JSObject* CreationStack() const Why do we not need JS::ExposeObjectToActiveJS here? At the very least it needs documentation, though I suspect we just need it. Also, this can return null, so should be called GetCreationStack. >+ return mCreationStack.get(); return mCreationStack; should work, no? r=me with those fixed and the performance numbers I asked for provided and acceptable.
Attachment #8620389 - Flags: review?(bzbarsky) → review+
> and seems like ~8% regression in event _handling_ perf, That's bad. Do we know why, exactly? That is, which of the lines in the CallSetup constructor contribute how much to that?
(In reply to Not doing reviews right now from comment #19) > >+ mAsyncCause.emplace(cx, JS_NewStringCopyZ(cx, aExecutionReason)); > > This does not make me happy. We had a plan to just keep execution reasons > as const char* until someone really needed something else, precisely to > avoid this sort of GC churn. What happened to that plan? Why, exactly, do > we require a full-up JSString for the async cause? The only good news here > is that at least the handling of null aExecutionReason (the common case so > far) is not insane. But since we're trying to move toward providing > execution reasons more and more... NI'ing Nick for this and... > Also, I can't evaluate whether aExecutionReason is even an appropriate thing > to use for the async cause, because there is zero documentation for async > cause anywhere I can find. Please fix that if you know what it's _supposed_ > to be; then I can try to figure out whether this even makes sense. ... this. > >+ if (mAsyncCause->get()) { > > if (*mAsyncCause) > > >+ JSObject* CreationStack() const > > Why do we not need JS::ExposeObjectToActiveJS here? At the very least it > needs documentation, though I suspect we just need it. I don't know but I will try to find out.
Flags: needinfo?(nfitzgerald)
(In reply to Not doing reviews right now from comment #20) > > and seems like ~8% regression in event _handling_ perf, > > That's bad. Do we know why, exactly? That is, which of the lines in the > CallSetup constructor contribute how much to that? There's some discussion in bug 1158133 and bug 1152893. My understanding is that adopting the async parent can be slow.
(In reply to Tom Tromey :tromey from comment #21) > (In reply to Not doing reviews right now from comment #19) > > > >+ mAsyncCause.emplace(cx, JS_NewStringCopyZ(cx, aExecutionReason)); > > > > This does not make me happy. We had a plan to just keep execution reasons > > as const char* until someone really needed something else, precisely to > > avoid this sort of GC churn. What happened to that plan? Why, exactly, do > > we require a full-up JSString for the async cause? The only good news here > > is that at least the handling of null aExecutionReason (the common case so > > far) is not insane. But since we're trying to move toward providing > > execution reasons more and more... > > NI'ing Nick for this and... I don't think there is any good reason this isn't a `const char *` and then lazily made into a JSString on demand when accessing the SavedFrame object's asyncCause. Maybe Paolo or Jim could provide a specific reason, who wrote and reviewed the patches that introduced the async stuff to SavedFrame respectively. > > Also, I can't evaluate whether aExecutionReason is even an appropriate thing > > to use for the async cause, because there is zero documentation for async > > cause anywhere I can find. Please fix that if you know what it's _supposed_ > > to be; then I can try to figure out whether this even makes sense. > > ... this. https://dxr.mozilla.org/mozilla-central/source/js/src/doc/SavedFrame/SavedFrame.md?from=SavedFrame.md#62-70 I think passing the execution reason as the asyncCause is entirely acceptable.
Flags: needinfo?(nfitzgerald)
> My understanding is that adopting the async parent can be slow. That only matters when a stack is captured when we have an async stack, right? But smaug's event dispatch don't capture a stack inside the event listener. So I don't think this would matter there. > https://dxr.mozilla.org/mozilla-central/source/js/src/doc/SavedFrame/SavedFrame.md?from=SavedFrame.md#62-70 Thanks. Can we get some of that, or a pointer to that, into jsapi.h?
Oh, need to have another test for adding event listeners. I think I have one somewhere.
and tromey, perhaps worth to re-run the _3 event handling test again. I wonder if there was some noise. (though it usually shouldn't be too noisy)
(In reply to Not doing reviews right now from comment #24) > > https://dxr.mozilla.org/mozilla-central/source/js/src/doc/SavedFrame/SavedFrame.md?from=SavedFrame.md#62-70 > > Thanks. Can we get some of that, or a pointer to that, into jsapi.h? Bug 1173513
> I don't think there is any good reason this isn't a `const char *` and then > lazily made into a JSString on demand when accessing the SavedFrame object's > asyncCause. Maybe Paolo or Jim could provide a specific reason, who wrote > and reviewed the patches that introduced the async stuff to SavedFrame > respectively. JS can make a call with an async stack, see xpcomcomponents.idl: /* * To be called from JS only. * * Call 'function', using the provided stack as the async stack responsible * for the call, and propagate its return value or the exception it throws. * The function is called with no arguments, and 'this' is 'undefined'. * * The code in the function will see the given stack frame as the * asyncCaller of its own stack frame, instead of the current caller. */ [implicit_jscontext] jsval callFunctionWithAsyncStack(in jsval function, in nsIStackFrame stack, in AString asyncCause); I think this is why this has to be a JSString. Adding a const char* overload wouldn't be impossible, and maybe only mildly bloaty in the saved frames?
Ugh... Can we disallow JS to explicitly control this? That seems nasty... Or maybe just disallow JS from providing its own asyncCause and have it be the generic "Async" string?
(In reply to Nick Fitzgerald [:fitzgen][:nf] from comment #30) > Ugh... Can we disallow JS to explicitly control this? That seems nasty... Or > maybe just disallow JS from providing its own asyncCause and have it be the > generic "Async" string? AFAICT, it is only used in tests.
(In reply to Nick Fitzgerald [:fitzgen][:nf] from comment #30) > Ugh... Can we disallow JS to explicitly control this? That seems nasty... Or > maybe just disallow JS from providing its own asyncCause and have it be the > generic "Async" string? Hmm, I believe I was planning to use this from JS to connect things like local DevTools RDP stacks (bug 1151414). Wouldn't I need this method to make the async stack link from JS, or do I misunderstand how this works?
(In reply to J. Ryan Stinnett [:jryans] (use ni?) from comment #32) > (In reply to Nick Fitzgerald [:fitzgen][:nf] from comment #30) > > Ugh... Can we disallow JS to explicitly control this? That seems nasty... Or > > maybe just disallow JS from providing its own asyncCause and have it be the > > generic "Async" string? > > Hmm, I believe I was planning to use this from JS to connect things like > local DevTools RDP stacks (bug 1151414). > > Wouldn't I need this method to make the async stack link from JS, or do I > misunderstand how this works? I don't think that the async stacks infrastructure is suited for tracing RDP messages because they are cross process (or even cross device). I think optionally adding a "_stack: Error().stack" property to each packet would suffice, but let's move this conversation to that bug.
(In reply to Olli Pettay [:smaug] ) from comment #15) > Shouldn't the slow stuff be disabled by default, and if one uses devtools, > there should be some way to enable. As far as I can tell, async stacks are not slow. That said, I'd like to see this discussion shift from generic claims like "slow" or "not slow", or tests run on one machine only, to peer-reviewable test cases. We should get answers to questions like the very specific one Boris asked in comment 17. I suggest providing some reproducible test cases that you think are relevant and that we can easily profile. We can then discuss how representative they are of usage in the wild (the Promises one probably wasn't). Additionally, if we think they are representative and there are regressions, we now have a tool we can use to optimize async stacks to reduce those regressions. We can do this in a separate bug - for the moment async stacks are enabled by default on Desktop Nightly and Developer Edition only.
With regard to the "JSString" versus "const char *" discussion, we're only talking about the type of the asyncCause argument of JS::AutoSetAsyncStackForNewCalls. Except for the fact that we're supporting non-ASCII characters for asyncCause, which is not a strong requirement, I don't see a disadvantage in using "const char *" there (and in the Activation field) if it makes more sense. However, this value will need to be converted back to a JSString when it's put inside a SavedFrame object when the stack is captured, since at that point we can't guarantee the original buffer will still be around. The callFunctionWithAsyncStack consumer can simply convert its XPCOM string argument to a "const char *" instead of a JSString like it does currently. We will use callFunctionWithAsyncStack in order to remove the current (only partially working) hack to simulate async stacks in Task.jsm (bug 1144353). I also suggest doing the argument type change, if you want to do it, in a separate bug.
Comment on attachment 8620389 [details] [diff] [review] create async stack in callback objects Review of attachment 8620389 [details] [diff] [review]: ----------------------------------------------------------------- ::: dom/base/test/test_async_setTimeout_stack.html @@ +39,5 @@ > + > + is(frames[0], "i"); > + is(frames[1], "h"); > + is(frames[2], "g"); > + is(frames[3], "setTimeout handler*SimpleTest_setTimeoutShim"); Can we have this indicated as "setTimeout*SimpleTest_setTimeoutShim" instead of "setTimeout handler*SimpleTest_setTimeoutShim"? This frame indicates where the setTimeout call happens, the handler is the next frame, that is "g()" in this case. It doesn't seem an insoluble problem, and we can avoid some developer confusion.
Based on profiler the perf regression in http://mozilla.pettay.fi/moztests/events/event_speed_3.html (event handling) is coming from JS_NewStringCopyZ call. I'm seeing 5-7% regression. Not acceptable, but sounds like we could pass const char* and not do slow JS_New* calls there. http://mozilla.pettay.fi/moztests/events/event_speed_6.html (adding/removing event listeners) shows us taking 2x time with the patch. And given that before the patch addEventListener and removeEventListener take about the same amount time in that test, the patch seems to make addEventListener 3x slower than what it is currently on trunk. And the performance profile for _6 totally changes with the patch: CaptureCurrentStack starts to dominate the profile by large margin.
> for the moment async stacks are enabled by default on Desktop Nightly and Developer > Edition only. Note that the patch in this bug is adding code that has overhead whether async stacks are enabled or not, both on the "create a callback" codepath and the "invoke a callback" codepath... > Except for the fact that we're supporting non-ASCII characters for asyncCause, which is > not a strong requirement const char* can totally support non-ASCII characters. UTF-8 exists. ;) > However, this value will need to be converted back to a JSString when it's put inside a > SavedFrame object when the stack is captured Sure. _If_ the stack is captured, yes? And then only if we end up not finding an existing relevant SavedFrame, I'd hope... > The callFunctionWithAsyncStack consumer can simply convert its XPCOM string argument to > a "const char *" This consumer could in fact convert to UTF-8 without too much trouble. And I guess that would outlive the possible places where the string could be used in the JS engine, so shouldn't be an issue, yeah. This sounds promising. > I also suggest doing the argument type change, if you want to do it, in a separate bug. Yes, very much so. > Can we have this indicated as "setTimeout*SimpleTest_setTimeoutShim" This is where the execution reason usage we have now and the needs of async stacks may not match up well. The execution reason is "why are we running g() at all"? And the answer is "it's a setTimeout handler"... so that's what we use as the execution reason. Using "setTimeout" here would make the other uses of execution reason in devtools a bit more confusing, I suspect. :( Make sure to talk to the folks who are using the execution reason elsewhere before you start changing those strings. > the perf regression in http://mozilla.pettay.fi/moztests/events/event_speed_3.html > (event handling) is coming from JS_NewStringCopyZ call. OK. So we need to address that before we can land this patch. > adding/removing event listeners) shows us taking 2x time with the patch. A few more questions here: 1) How realistic is this microbenchmark? That is, how common is it for event listener addition to be something sites do a lot? 2) What are the actual wall-clock times per addEventListener call with/without this patch? 3) What are the wall-clock times (or slowdown factor, if any) with this patch but with the "javascript.options.asyncstack" pref set to false?
(In reply to :Paolo Amadini from comment #35) > Except for the fact that we're supporting non-ASCII characters for > asyncCause, which is not a strong requirement, I don't see a disadvantage in > using "const char *" there (and in the Activation field) if it makes more > sense. However, this value will need to be converted back to a JSString when > it's put inside a SavedFrame object when the stack is captured, since at > that point we can't guarantee the original buffer will still be around. I understood the proposal to be to require the argument to be a string constant. > Can we have this indicated as "setTimeout*SimpleTest_setTimeoutShim" instead > of "setTimeout handler*SimpleTest_setTimeoutShim"? This frame indicates > where the setTimeout call happens, the handler is the next frame, that is > "g()" in this case. > > It doesn't seem an insoluble problem, and we can avoid some developer > confusion. I think this should probably also be a separate bug. Anyway the causes come from uses of AutoEntryScript. This one is here: https://dxr.mozilla.org/mozilla-central/source/dom/base/nsGlobalWindow.cpp?from=nsGlobalWindow.cpp&case=true#12434 Note that changes to entry reasons may require a corresponding tweak in some devtools code.
(In reply to Not doing reviews right now from comment #38) > > Can we have this indicated as "setTimeout*SimpleTest_setTimeoutShim" > > This is where the execution reason usage we have now and the needs of async > stacks may not match up well. The execution reason is "why are we running > g() at all"? And the answer is "it's a setTimeout handler"... so that's > what we use as the execution reason. > > Using "setTimeout" here would make the other uses of execution reason in > devtools a bit more confusing, I suspect. :( Make sure to talk to the > folks who are using the execution reason elsewhere before you start changing > those strings. For timeline the reasons are rewritten to be more clear; and this particular one is already rewritten to just "setTimeout": https://dxr.mozilla.org/mozilla-central/source/browser/devtools/performance/modules/logic/marker-utils.js?from=marker-utils.js&case=true#364 As far as I know only the timeline markers do any rewriting of the async cause. Elsewhere I think they appear in their more raw form (if at all -- the debugger does not yet show async stacks). So, I think changes here are fine, just a bit of care is needed.
[Why is this notable]: Async Stacks will be quite useful as a feature of Developer Edition, and this bug is enabling it in the general case. [Suggested wording]: Asynchronous call stacks now allow web developers to follow the code flow through setTimeout, DOM event handlers, and Promise handlers. [Links (documentation, blog post, etc)]: None at present. (Help with the exact wording is appreciated.)
relnote-firefox: --- → ?
Keywords: dev-doc-needed
(In reply to Not doing reviews right now from comment #38) > 1) How realistic is this microbenchmark? That is, how common is it for > event listener addition to be something sites do a lot? > Totally unrealistic, but I've seen "browser benchmarks" where lots of listeners were added. (trying to recall which one). Currently our perf in add+remove case is about the same as in blink. > 2) What are the actual wall-clock times per addEventListener call > with/without this patch? 3.5us without for add+remove, 7,5us with > 3) What are the wall-clock times (or slowdown factor, if any) with this > patch but with the "javascript.options.asyncstack" pref set to false? 5.5us
OK. So about half the perf hit for the "add" is still there even with saved stacks disabled. That's not ideal. :(
(In reply to Not doing reviews right now from comment #43) > OK. So about half the perf hit for the "add" is still there even with saved > stacks disabled. That's not ideal. :( I think we can do this at capture time: + if (JS::RuntimeOptionsRef(JS_GetRuntime(cx)).asyncStack() && + !JS::CaptureCurrentStack(cx, &stack)) {
Worth checking, but it might also be the AutoJSAPI creation that's costing.
(In reply to Not doing reviews right now from comment #45) > Worth checking, but it might also be the AutoJSAPI creation that's costing. The patch helps with the _3 test case (not completely but much closer); but with _6 it is indeed still slower, on the order of 20ms before and 25ms after.
This addresses the review comments, it removes a debugging "console.log" from a test, and it adds a check to see if the pref is enabled. This still doesn't fully solve the performance regression. I'm not sure what options we have there. Maybe we could cache the pref in a static member of CallbackObject and update it on changes? This would let us avoid the AutoJSAPI instantiation.
We could also try making callers pass in a JSContext instead of grabbing our own... Not sure how much work that would be.
(In reply to Not doing reviews right now from comment #48) > We could also try making callers pass in a JSContext instead of grabbing our > own... Not sure how much work that would be. I tried it out. I have a hack that nearly builds -- just one remaining error in a test that I have yet to track down. (Well, so far, maybe it is hiding more, I don't know, etc - let me emphasize the "hack" bit.) Most of the work is in Codegen.py. So it seems tractable in that way. However there is a lot I don't know about how everything is put together, like whether the way I use a convenient JSContext at various spots. I wonder whether sometimes this might be the wrong context to use. I can post the WIP patch if you want to see what it looks like so far. I am hoping to finish it soon but right now it is looking like it won't happen this week.
> I can post the WIP patch if you want to see what it looks like so far. That would be awesome.
Here's the WIP patch. Totally untested. Here are the remaining errors I see; they arise because the constructors in question need a JSContext* argument now, but I haven't modified Codegen.py to supply one in this situation. /home/tromey/firefox-git/gecko-dev/obj-x86_64-unknown-linux-gnu/dom/bindings/TestJSImplInheritanceGenBinding.cpp:1997:20: error: no matching function for call to ‘mozilla::dom::TestCImplementedInterface::TestCImplementedInterface(JS::Handle<JSObject*>&, nsIGlobalObject*&)’ /home/tromey/firefox-git/gecko-dev/obj-x86_64-unknown-linux-gnu/dom/bindings/TestJSImplInheritanceGenBinding.cpp:2378:20: error: no matching function for call to ‘mozilla::dom::TestJSImplInterface3::TestJSImplInterface3(JS::Handle<JSObject*>&, nsIGlobalObject*&)’ /home/tromey/firefox-git/gecko-dev/obj-x86_64-unknown-linux-gnu/dom/bindings/TestJSImplInheritanceGenBinding.cpp:2505:20: error: no matching function for call to ‘mozilla::dom::TestJSImplInterface6::TestJSImplInterface6(JS::Handle<JSObject*>&, nsIGlobalObject*&)’
Thanks. That's very helpful. So really, the JSContext is used for three things: rooting, checking the async stack option, and the compartment to capture the stack in. The first two of those only care about the runtime, not the context. So the only thing we need to check in terms of wheter it's OK to use the "convenient JSContext" is the stack capture compartment. Looking at the callsites in the patch: 1) In RequestAnimationFrame we're using the compartment of the caller that called requestAnimationFrame. This seems sensible. 2) In GetExternal we're not sure what. Compartment of the caller if called from JS, but otherwise we're ending up with a null compartment. We should probably just make CaptureCurrentStack() return null if not in a compartment... That said, the fact that this is a callback at all is an implementation detail. Passing null here, with a comment, would be ok with me. 3) nsJSScriptTimeoutHandler::Init... I think that code is basically dead. We should kill it off; file a followup bug please? 4) In CastableObjectUnwrapper, we're using the caller compartment, which makes sense: this is us creating a return value. Really, though, the fact that this is a callback at all is an internal implementation detail. I would be just fine with us passing a null cx here, as in item 2. 5) In CGCAllbackTempRoot, we're using the caller compartment, which makes sense. 6) In genConstructorBody, the situation is just like item 4. 7) Same thing in the CGJSImplClass code. In fact, if we decide we're OK with null in item 2/4/6, then we can just not take a JSContext in the constructor at all for the JSImplClass stuff, and just pass on null to the CallbackInterface constructor when we invoke that. That would incidentally help you with the situation with TestCImplementedInterface/TestJSImplInterface3/TestJSImplInterface6, none of which would need JSContext argument. 8) In DataStoreService, same thing as items 2/4/6. 9) In SetEventHandler, aCx is in the caller compartment, which makes sense. 10) In CompileEventHandlerInternal, I'm not sure the concept of a stack really makes sense; the stack there is more or less random (i.e. whoever happened to trigger the event first). Passing null here would make some sense to me. 11) In Promise::ResolveInternal... I'm not sure how much sense it makes to capture a stack there. Typically that stack is not particularly helpful. If we do decide we want to do this, I would prefer us making the MaybeResolve signature that takes a JSContext protected so we can make sure that callers aren't getting it wrong (and fix the callers to use the one-arg form of MaybeResolve instead). 12) ServiceWorkerRegistrationMainThread::GetPushManager is like items 2/4/6/8. 13) In nsXBLPrototypeHandler, the stack is basically whatever triggered the event, which doesn't seem like what we'd really want there. We should just pass null.
This patch compiles. It does not capture the stack at all, it just arranges to pass a JSContext to the CallbackObject constructor. The bad news is that this patch has a performance regression on the _3 test case we were discussing. For example when run with N=150, it goes from 70.87 to 73.2. It also regresses performance on the _6 test a bit; for N=150 it goes from 19.63 to 20.1. Note this patch is also incorrect, as it doesn't let us correctly capture the async stack when 'window.addEventListener' is called. I was too eager removing some of the Codegen.py changes -- just because I'm hacking around without really understanding the generator; and also since it seems like there is enough information now to decide whether this is worth pursuing. I would be interested in whether others observe the performance regression as well, and of course whether I should fix up the final buglet.
Attachment #8623033 - Attachment is obsolete: true
The post-review patch, rebased on top of the JSContext patch, and also avoiding the use of AutoJSAPI. As noted earlier, the tests don't all pass.
Attachment #8620389 - Attachment is obsolete: true
Attachment #8621129 - Attachment is obsolete: true
> The bad news is that this patch has a performance regression on the _3 > test case That's fairly surprising. What are the error bars on those numbers that were measured?
(In reply to Boris Zbarsky [:bz] from comment #55) > > The bad news is that this patch has a performance regression on the _3 > > test case > > That's fairly surprising. What are the error bars on those numbers that > were measured? The first batch are the baselines. The second batch are with the patch applied. Test N Mean StdDev _3 1 61.54 2.00 _3 150 71.96 2.00 _6 1 20.76 2.65 _6 150 20.62 3.04 _3 1 64.36 1.90 _3 150 74.82 3.25 _6 1 22 4.55 _6 150 21.74 3.69
OK, so pretty significant overlap between those ranges, though the new mean doesn't lie within the old stddev... That's really quite confusing; I would not expect just passing a single argument that's already on the stack or in a register in the caller to have any real effect on wall-clock measurements here.
(In reply to Boris Zbarsky [:bz] from comment #57) > OK, so pretty significant overlap between those ranges, though the new mean > doesn't lie within the old stddev... > > That's really quite confusing; I would not expect just passing a single > argument that's already on the stack or in a register in the caller to have > any real effect on wall-clock measurements here. Me neither. Could you try the patch as well and see if the results are reproducible?
> Could you try the patch as well and see if the results are reproducible? I get, all for N=150: Test Mean StddDev 3 bef. 58.7 1.1 6 bef. 21.4 0.6 3 aft. 58.2 0.6 6 aft. 21.1 0.3 so all within the noise (and in fact the "after" means came out slightly lower over here).
(In reply to Boris Zbarsky [:bz] from comment #52) > 3) nsJSScriptTimeoutHandler::Init... I think that code is basically dead. > We should kill > it off; file a followup bug please? https://bugzilla.mozilla.org/show_bug.cgi?id=1176083
Attachment #8624027 - Attachment is obsolete: true
Attachment #8624029 - Attachment is obsolete: true
Rebased and updated.
Comment on attachment 8625783 [details] [diff] [review] pass JSContext to CallbackObject constructor This is the updated patch to pass a JSContext to CallbackObject and fix up the fallout. I think based on discussion in the patch that this is reviewable now. Please let me know if you'd like me to file followup bugs for * the "const char*" issue * renaming the "setTimeout" entry reason
Attachment #8625783 - Flags: review?(bzbarsky)
Attachment #8625785 - Flags: review?(bzbarsky)
Comment on attachment 8625783 [details] [diff] [review] pass JSContext to CallbackObject constructor Please document the new argument in CallbackObject.h (and by reference to that documentation in CallbackFunction.h and CallbackInterface.h). In particular, the fact that null is allowed and what it means (and I guess by extension what the argument means in general) needs to be clearly documented. r=me with that
Attachment #8625783 - Flags: review?(bzbarsky) → review+
Oh, and yes, please file a followup bug on the const char* issue, since per comment 37 that probably needs to block turning on async stacks by default...
Comment on attachment 8625785 [details] [diff] [review] create async stack in callback objects >+++ b/dom/base/test/test_async_setTimeout_stack.html >+++ b/dom/base/test/test_async_setTimeout_stack_across_globals.html These tests should probably pushPrefEnv the asyncstack pref before doing the main test, right? >+++ b/dom/bindings/test/test_async_stacks.html Here too. >+ var ourFile = "http://mochi.test:8888/tests/dom/bindings/test/test_async_stacks.html"; How about: var ourFile = "test_async_stacks.html"; or var ourFile = location.href; r=me with that.
Attachment #8625785 - Flags: review?(bzbarsky) → review+
(In reply to Boris Zbarsky [:bz] from comment #65) > Oh, and yes, please file a followup bug on the const char* issue, since per > comment 37 that probably needs to block turning on async stacks by default... https://bugzilla.mozilla.org/show_bug.cgi?id=1177488
Updated per review.
Attachment #8625783 - Attachment is obsolete: true
Attachment #8625785 - Attachment is obsolete: true
Attachment #8626298 - Flags: review+
Attachment #8626299 - Flags: review+
Comment on attachment 8626299 [details] [diff] [review] create async stack in callback objects + SpecialPowers.pushPrefEnv( .... + addLoadEvent(runTests); I think it would be better to do this as: addLoadEvent(function() { SpecialPowers.pushPrefEnv(..., runTests); }); because otherwise you could have the load event fire before the pref env is pushed, and I'm not sure what happens if you addLoadEvent after onload has already fired.
Updated test.
Attachment #8626299 - Attachment is obsolete: true
Attachment #8626310 - Flags: review+
I've fixed most of those oranges but a couple are worth pointing out. This one: failed | Exception stack should still only show our code - got doTest@http://mochi.test:8888/tests/dom/bindings/test/test_exception_options_from_jsimplemented.html:20:7 Async*@http://mochi.test:8888/tests/dom/bindings/test/test_exception_options_from_jsimplemented.html:137:1 , expected doTest@http://mochi.test:8888/tests/dom/bindings/test/test_exception_options_from_jsimplemented.html:20:7 The stack trace here is correct, but not any more informative than the trace before async stacks were added. Perhaps we should consider not showing an "Async" frame like that if there are no other user-visible frames above it. I think this can be deferred to a new bug; or just ignored. js/xpconnect/tests/mochitest/test_bug960820.html fails with failed | dispatchClick should be in the stack The stack trace is helpfully printed by another test: 2 INFO TEST-PASS | js/xpconnect/tests/mochitest/test_bug960820.html | Invoked clickCallback. Stack: clickCallback@http://mochi.test:8888/tests/js/xpconnect/tests/mochitest/test_bug960820.html:24:18 Async*@http://mochi.test:8888/tests/js/xpconnect/tests/mochitest/test_bug960820.html:21:1 What is happening here is that we're dispatching an event synchronously, but because the code in CallbackObject is unconditional, the async stack parent is being used in preference to the sync parent -- but here I think the sync parent is more correct. I don't know what to do about this one. I haven't found anything that would indicate whether a given dispatch is synchronous or not. (I assume there isn't anything like this, but I don't actually know...)
> but not any more informative than the trace before async stacks were added. Why not? In this case, it's obvious that there is only one possible place that could have run toTest async. But I thought the whole point of async stacks was to indicate where you came from to get here in cases when there were multiple ways to do it. Put another way, this is no different than if the call to doTest were done directly at toplevel; we'd show a stack frame for toplevel in that case, right? > I haven't found anything that would indicate whether a given dispatch is synchronous or > not. Synchronous with what? But yes, this could be a more serious problem, since it changes web-visible behavior in a potentially undesirable way. I wonder what other UAs do here...
And in particular, for event dispatch the stack could represent two things: 1) Who added the listener? 2) Who fired the event? For events fired/triggered by C++ #1 might be more interesting just because #2 is not representable. For events fired/triggered by JS, you really want to know both....
Attached patch fix up some tests (obsolete) — — Splinter Review
This patch fixes up a few minor regressions. I will merge this into the real patch after I figure out what to do about the two remaining failures. For the canvas debugger tests, I thought it was simplest to make the test adapt to the possibility of an async stack. The timeline marker change is due to the callback now getting its async cause from the entry point. Changing Promise.cpp itself didn't seem warranted here, as there are other paths, I believe, that don't go through CallbackObject.
(In reply to Boris Zbarsky [:bz] from comment #74) > > but not any more informative than the trace before async stacks were added. > > Why not? In this case, it's obvious that there is only one possible place > that could have run toTest async. But I thought the whole point of async > stacks was to indicate where you came from to get here in cases when there > were multiple ways to do it. > > Put another way, this is no different than if the call to doTest were done > directly at toplevel; we'd show a stack frame for toplevel in that case, > right? Yeah, let me take that one back. I had been thinking that the plain "Async" note was sort of useless. But I suppose this does correspond to some code actually in the file. The case that would be un-useful would be if we could see a frame like this not corresponding to anything the user wrote. But that doesn't seem possible. > > I haven't found anything that would indicate whether a given dispatch is synchronous or > > not. > > Synchronous with what? > > But yes, this could be a more serious problem, since it changes web-visible > behavior in a potentially undesirable way. I wonder what other UAs do > here... The code here sets a click listener, then later does: function dispatchClick() { document.dispatchEvent(new MouseEvent('click')); } dispatchClick(); So "synchronous" just means that the event dispatch itself has a meaningful stack trace. But, the current approach drops this perfectly useful trace in favor of showing the spot where the handler is installed. One way to deal with this might be to have CallbackObject::CallSetup behave differently depending on whether there is a usable stack trace already present. Maybe "usable" could be something like "if there is an available frame and it would be returned by SavedStacks.cpp:GetFirstSubsumedFrame"? I don't know whether this would be correct. Another possible approach might be to defer this decision until the stack is actually captured.
> Another possible approach might be to defer this decision until the stack > is actually captured. This seems preferable if stack captures are rare and the decision is not extremely cheap.
(In reply to Tom Tromey :tromey from comment #77) > The code here sets a click listener, then later does: > > function dispatchClick() { > document.dispatchEvent(new MouseEvent('click')); > } > dispatchClick(); > > So "synchronous" just means that the event dispatch itself has a meaningful > stack trace. But, the current approach drops this perfectly useful trace > in favor of showing the spot where the handler is installed. If it is some framework/lib that dispatches the event, I could see the async stack being the one the dev might want. Otherwise, yes it seems like you would more likely want the stack pointing to the dispatchEvent call. Ideally, we would have both, but that seems like too much work for too little gain (at least initially). For now, I would lean towards your definition of "usable" stack, and if we have one, then don't use the async stack. > Maybe "usable" could be something like "if there is an available frame and > it would be returned by SavedStacks.cpp:GetFirstSubsumedFrame"? I don't > know whether this would be correct. Yeah this seems like a reasonable definition of usable. Is it an issue that this is a dynamic thing (depends on caller's principals) rather than something we can check only the one time?
(In reply to Nick Fitzgerald [:fitzgen][:nf] from comment #79) > If it is some framework/lib that dispatches the event, I could see the async > stack being the one the dev might want. Otherwise, yes it seems like you > would more likely want the stack pointing to the dispatchEvent call. > > Ideally, we would have both, but that seems like too much work for too > little gain (at least initially). For now, I would lean towards your > definition of "usable" stack, and if we have one, then don't use the async > stack. Thanks for this response -- after reading this I started thinking that the proposed change would break callFunctionWithAsyncStack. I will have to look to be sure, but it certainly seems like it would. I suppose we could add a flag for this case. But maybe some cleaner approach is available. > > Maybe "usable" could be something like "if there is an available frame and > > it would be returned by SavedStacks.cpp:GetFirstSubsumedFrame"? I don't > > know whether this would be correct. > > Yeah this seems like a reasonable definition of usable. Is it an issue that > this is a dynamic thing (depends on caller's principals) rather than > something we can check only the one time? Good question, I don't know.
(In reply to Tom Tromey :tromey from comment #80) > Thanks for this response -- after reading this I started thinking that the > proposed change would break callFunctionWithAsyncStack. I will have to look > to be sure, but it certainly seems like it would. > > I suppose we could add a flag for this case. But maybe some cleaner approach > is available. > > > > Maybe "usable" could be something like "if there is an available frame and > > > it would be returned by SavedStacks.cpp:GetFirstSubsumedFrame"? I don't > > > know whether this would be correct. > > > > Yeah this seems like a reasonable definition of usable. Is it an issue that > > this is a dynamic thing (depends on caller's principals) rather than > > something we can check only the one time? > > Good question, I don't know. Are you going to keep both around all the time and repeatedly do the "reasonable stack" check for every access to the stack, or did you want to do it once and throw one of the stacks away? The latter won't work with this definition of "reasonable stack". That said, I'm tempted to just say "always use the async stack" for now and see if it is annoying/frustrating in practice, at which time we can figure out a solution.
> That said, I'm tempted to just say "always use the async stack" for now This would make stacks strictly worse in the dispatchEvent case in many situations... and more importantly may have web compat impact that we need to watch out for. :(
(In reply to Boris Zbarsky [:bz] from comment #82) > > That said, I'm tempted to just say "always use the async stack" for now > > This would make stacks strictly worse in the dispatchEvent case in many > situations... and more importantly may have web compat impact that we need > to watch out for. :( I'm not sure it is strictly worse, it is a trade off between the dynamic stack vs the async/tracing stack. Web compat is an issue, but "at least" there isn't a spec for .stack other than it must be some sort of stack string. So maybe we do want to keep both around and repeatedly check for "reasonable stacks".
(In reply to Nick Fitzgerald [:fitzgen][:nf] from comment #81) > Are you going to keep both around all the time and repeatedly do the > "reasonable stack" check for every access to the stack, or did you want to > do it once and throw one of the stacks away? The latter won't work with this > definition of "reasonable stack". It seems to me that if we make the decision once -- when the stack is captured -- then we avoid any potential problems with different captures making different decisions and confusing things. What I've been thinking is, when noticing that an activation has an async parent (https://dxr.mozilla.org/mozilla-central/source/js/src/vm/SavedStacks.cpp?from=SavedStacks.cpp&case=true#914): 1. If the async parent was created using callFunctionWithAsyncStack, use it 2. If the current frame does not have a direct parent, use the async parent 3. If the current frame is content and the direct parent is chrome, use the async parent 4. Use the direct parent One problem is that I don't know how to code #3 :) I think this would work ok for users of the browser. For developers of the browser, it would mean that some async stack parents might not be seen. Though, it seems to me that in the "most useful" case where an event is triggered, it would probably (??) fall into case #2, and still work. Thoughts please? I tend to agree with comment #82 and think this patch can't be landed in its current form.
Agreed that making the decision once simplifies what we need to do. I would take it one step further and say that it seems to me that making decisions about using direct vs async stack based on principals is making this difficult because it doesn't cater to making a single decision. We have to keep checking because the subsumes relationship between principals depends on who's asking. So how about we skip (3) altogether? 1. If the async parent was created using callFunctionWithAsyncStack, use it 2. If the current frame does not have a direct parent, use the async stack 4. Otherwise, use the direct parent This would mean that if there are a bunch of chrome frames on the direct stack that call some content function that has an async stack, we accidentally lose out on the async stack. This is clearly suboptimal, however, it is not a regression and is the same behavior you would get if there was no async stack (like there isn't now). How does that sound?
(In reply to Nick Fitzgerald [:fitzgen][:nf] from comment #85) > So how about we skip (3) altogether? > > 1. If the async parent was created using callFunctionWithAsyncStack, use it > 2. If the current frame does not have a direct parent, use the async stack > 4. Otherwise, use the direct parent [...] > How does that sound? It sounds interesting and I'm giving it a try.
This implements the proposed heuristic and updates various test cases to follow. I'm attaching this separately because I believe it is easier to review this way; but I am happy to squash the patches if you would prefer. When landing I plan to squash patches #2-4 in the series into a single patch; leaving patch #1 separate as it is reasonably independent. In test_async_stacks, I needed a way to get an event without any JS on the stack, so the approach taken in the previous patch did not work. "onload" served this well enough, though it only works if the asyncstack pref is already set. If there's another way to generate an event from the test such that there is no JS on the stack when the handler is invoked, I can change the test; but I couldn't find a way to do that. I'm not sure who should review this.
> If there's another way to generate an event from the test such that there is no JS on the > stack when the handler is invoked It's _possible_ that this would work: setTimeout(target.dispatchEvent.bind(target, event), 0); though it's also possible that the self-hosted bind code will be "on the stack" for purposes of the stack code in that situation... Another option is to do something like this, after setting the pref: var link = document.createElement("link"); link.rel = "stylesheet"; link.href = "data:text/css,"; link.onload = function() { /* stuff */ } document.body.appendChild(link);
(In reply to Boris Zbarsky [:bz] from comment #88) > It's _possible_ that this would work: > setTimeout(target.dispatchEvent.bind(target, event), 0); Thanks, that worked.
Attachment #8628392 - Attachment is obsolete: true
Comment on attachment 8627299 [details] [diff] [review] fix up some tests Minor fallout from the initial patches. When landing I plan to squash this into patch #2; it is separate here because I believe it's simpler to review that way.
Attachment #8627299 - Flags: review?(bzbarsky)
Comment on attachment 8628418 [details] [diff] [review] mark async stacks coming from callFunctionWithAsyncStack Implement Nick's variant of the heuristic.
Attachment #8628418 - Flags: review?(bzbarsky)
Comment on attachment 8627299 [details] [diff] [review] fix up some tests >- is(frame.parent.asyncParent.asyncCause, "Promise", >+ is(frame.parent.asyncParent.asyncCause, "promise callback", Hmm. So do we still need the code in PromiseCallbackTask::Run that messes with async stack/cause stuff? Are there situations in which it's still relevant, or can we just remove it because it'll just get overriden by the callback anyway? r=me on this patch, but we should figure out what's going on there....
Attachment #8627299 - Flags: review?(bzbarsky) → review+
Comment on attachment 8628418 [details] [diff] [review] mark async stacks coming from callFunctionWithAsyncStack >+ setTimeout(window.dispatchEvent.bind(window, new CustomEvent("zebra")), 0); Ah, looks like bug 1000780 hasn't actually landed yet. Once it lands, will this test fail or will it start testing the wrong thing? If it's the former, that's probably ok; we'll just need to fix the test at that point... >+ "doTest@http://mochi.test:8888/tests/dom/bindings/test/test_promise_rejections_from_jsimplemented.html:44:7\n" + (asyncStack ? "Async*@http://mochi.test:8888/tests/dom/bindings/test/test_promise_rejections_from_jsimplemented.html:103:1\n" : ""))), Please, a line-break after the '+'. Same in the other cases in this file. >+hasParentFrame(const FrameIter& iter) This function should probably MOZ_ASSERT(!iter.done()) up front. Also, how expensive is copying a FrameIter? I'm assuming not too expensive. Anyway, r=me as far as it goes but the SpiderMonkey bits should really get review from Nick or someone.
Attachment #8628418 - Flags: review?(nfitzgerald)
Attachment #8628418 - Flags: review?(bzbarsky)
Attachment #8628418 - Flags: review+
(In reply to Boris Zbarsky [:bz] from comment #93) > Comment on attachment 8627299 [details] [diff] [review] > fix up some tests > > >- is(frame.parent.asyncParent.asyncCause, "Promise", > >+ is(frame.parent.asyncParent.asyncCause, "promise callback", > > Hmm. So do we still need the code in PromiseCallbackTask::Run that messes > with async stack/cause stuff? Are there situations in which it's still > relevant, or can we just remove it because it'll just get overriden by the > callback anyway? > > r=me on this patch, but we should figure out what's going on there.... Yeah, from comment #76: > Changing Promise.cpp itself didn't seem > warranted here, as there are other paths, I believe, that don't go > through CallbackObject.
(In reply to Boris Zbarsky [:bz] from comment #94) > Please, a line-break after the '+'. Same in the other cases in this file. Ok. This was me being lazy because the test cases all hard-code their own line numbers, so any change means more edits. > >+hasParentFrame(const FrameIter& iter) > > This function should probably MOZ_ASSERT(!iter.done()) up front. > > Also, how expensive is copying a FrameIter? I'm assuming not too expensive. https://dxr.mozilla.org/mozilla-central/source/js/src/vm/Stack.cpp?from=Stack.cpp&case=true#646 It copies a POD (data_) and an inline frame iterator. The latter is https://dxr.mozilla.org/mozilla-central/source/js/src/jit/JitFrames.cpp?from=JitFrames.cpp#2395 I would not say it is especially cheap. FrameIter::operator++ is complicated enough that it isn't clear if adding a special "is there a next frame" method is a good idea. Another approach could be to redo the logic in insertFrames to defer the decision until the next loop iteration. This would be a bit more complicated but cheaper. > Anyway, r=me as far as it goes but the SpiderMonkey bits should really get > review from Nick or someone. Thank you.
> I would not say it is especially cheap. Then it may be worth adding a warning comment about that (and checking that it doesn't slow down stack capture noticeably in practice).
(In reply to Boris Zbarsky [:bz] from comment #94) > >+ setTimeout(window.dispatchEvent.bind(window, new CustomEvent("zebra")), 0); > > Ah, looks like bug 1000780 hasn't actually landed yet. > > Once it lands, will this test fail or will it start testing the wrong thing? > If it's the former, that's probably ok; we'll just need to fix the test at > that point... Forgot to reply to this part. I think it will just start failing, because there will be one more JS frame, and so the async stack won't be applied. Your other suggestion in comment #88 seems more robust against this sort of change. I will try it out.
Comment on attachment 8628418 [details] [diff] [review] mark async stacks coming from callFunctionWithAsyncStack Review of attachment 8628418 [details] [diff] [review]: ----------------------------------------------------------------- Unfortunately, we really want to avoid that copy constructor if possible :( This patch would undo the relevant half of bug 1030938. Is there any way we could re-write that check to be a part of the start of the next iteration of the loop in SavedStacks::insertFrames (and therefore avoiding the copy)? Would the following work? if (asyncStack && activation == asyncActivation) asyncStack = nullptr; (In reply to Boris Zbarsky [:bz] from bug 1030938 comment #1) > Created attachment 8446729 [details] [diff] [review] > Stop copy-constructing iterators in SavedStacks code, because that copy > constructor is really slow. ::: js/src/jsapi.h @@ +4044,3 @@ > > public: > + enum AsyncCallKind { enum class AsyncCallKind @@ +4046,5 @@ > + enum AsyncCallKind { > + // The ordinary kind of call, where we may apply an async > + // parent if there is no ordinary parent. > + IMPLICIT, > + // An explicit async parent, e.g., callFunctionWithStack, callFunctionWithAsyncStack
Attachment #8628418 - Flags: review?(nfitzgerald)
(In reply to Nick Fitzgerald [:fitzgen][:nf] from comment #99) > Is there any way we could re-write that check to be a part of the start of > the next iteration of the loop in SavedStacks::insertFrames (and therefore > avoiding the copy)? Would the following work? > > if (asyncStack && activation == asyncActivation) > asyncStack = nullptr; Based on the comments, the code is trying to attach the activation's async parent after after the oldest frame in the activation. So, we can't do that exactly. Instead with just a little rearrangement I came up with: diff --git a/js/src/vm/SavedStacks.cpp b/js/src/vm/SavedStacks.cpp index 7142304..e9b706e 100644 --- a/js/src/vm/SavedStacks.cpp +++ b/js/src/vm/SavedStacks.cpp @@ -910,6 +910,17 @@ SavedStacks::insertFrames(JSContext* cx, FrameIter& iter, MutableHandleSavedFram while (!iter.done()) { Activation& activation = *iter.activation(); + if (asyncActivation && asyncActivation != &activation) { + // We found an async stack in the previous activation, and we + // walked past the oldest frame of that activation, we're done. + // However, we only want to use the async parent if it was + // explicitly requested; if we got here otherwise, we have + // a direct parent, which we prefer. + if (asyncActivation->asyncCallIsExplicit()) + break; + asyncActivation = nullptr; + } + if (!asyncActivation) { asyncStack = activation.asyncStack(); if (asyncStack) { @@ -921,10 +932,6 @@ SavedStacks::insertFrames(JSContext* cx, FrameIter& iter, MutableHandleSavedFram asyncCause = activation.asyncCause(); asyncActivation = &activation; } - } else if (asyncActivation != &activation) { - // We found an async stack in the previous activation, and we - // walked past the oldest frame of that activation, we're done. - break; } AutoLocationValueRooter location(cx);
Rebased.
Attachment #8626298 - Attachment is obsolete: true
Attachment #8626310 - Attachment is obsolete: true
Attachment #8627299 - Attachment is obsolete: true
Attachment #8628418 - Attachment is obsolete: true
Rebased and squashed. All review comments addressed. I switched test_async_stacks.html to the more robust way to test event listeners.
Attachment #8629012 - Flags: review+
Comment on attachment 8629013 [details] [diff] [review] create async stack in callback objects Sorry about this Nick, but I thought I saw an r+ so I went ahead and squashed; but then noticed there wasn't one. I think probably all that you wanted to re-review is the SavedStacks change, so I'm requesting r? on the squashed patch. However if you want to see it in isolation I will un-squash it.
Attachment #8629013 - Flags: review?(nfitzgerald)
Comment on attachment 8629013 [details] [diff] [review] create async stack in callback objects Review of attachment 8629013 [details] [diff] [review]: ----------------------------------------------------------------- ::: js/src/vm/SavedStacks.cpp @@ +918,5 @@ > + // a direct parent, which we prefer. > + if (asyncActivation->asyncCallIsExplicit()) > + break; > + asyncActivation = nullptr; > + } This is great! :D
Attachment #8629013 - Flags: review?(nfitzgerald) → review+
Most of the oranges are trivia, e.g., I forgot to add EXPLICIT in TestingFunctions.cpp. Buried in there is a regression in test_protocol_stack.js which turns out to be interesting. The basic problem is that this test expects to see an async stack. But, it is also using Promise-backend.js; and the new heuristic breaks this due to other JS frames appearing on the stack. One fix for this is to (1) add EXPLICIT in Promise.cpp, followed by (2) change AutoSetAsyncStackForNewCalls to only set the async stack if it has not already been set. #1 is needed to make the async stack "take hold". This change seems like a hack to me, as I don't think there's a principled reason this particular AutoSetAsyncStackForNewCalls use should be explicit -- the justification is "work around Promise-backend.js". #2 is needed because in this situation, a second AutoSetAsyncStackForNewCalls is instantiated without an intervening activation. The innermost one comes from the CallbackObject and has to be ignored for the async stack from #1 to be used. This also lets us remove the change pointed out in comment #93, so is arguably an improvement. I think another way to fix this bug would be to add async stack capturing to Promise-backend.js. I haven't written this yet but I suspect it will be cleaner than the above.
Here's what the Promise-backend.js patch looks like. (Thanks to Nick for helping me figure out how to access Components here.) diff --git a/toolkit/modules/Promise-backend.js b/toolkit/modules/Promise-backend.js index bf21053..4d7c6ca 100644 --- a/toolkit/modules/Promise-backend.js +++ b/toolkit/modules/Promise-backend.js @@ -43,6 +43,7 @@ let Cu = this.require ? require("chrome").Cu : Components.utils; let Cc = this.require ? require("chrome").Cc : Components.classes; let Ci = this.require ? require("chrome").Ci : Components.interfaces; +let Components_ = this.require ? require("chrome").components : Components; // If Cu is defined, use it to lazily define the FinalizationWitnessService. if (Cu) { @@ -737,7 +738,15 @@ this.PromiseWalker = { // If Cu is defined, this file is loaded on the main thread. Otherwise, it // is loaded on the worker thread. if (Cu) { - DOMPromise.resolve().then(() => this.walkerLoop()); + let stack = Components_ ? Components_.stack : null; + if (stack) { + DOMPromise.resolve().then(() => { + Cu.callFunctionWithAsyncStack(this.walkerLoop.bind(this), stack, + "Promise") + }); + } else { + DOMPromise.resolve().then(() => this.walkerLoop()); + } } else { setImmediate(this.walkerLoop); }
Attached patch fix regressions (obsolete) — — Splinter Review
This fixes the regressions found by the try push. I plan to squash it into the second patch before landing. The test_exception_options_from_jsimplemented patch is just bookkeeping, updating the test to account of async stacks. The TestingFunctions.cpp change is an oversight from the introduction of EXPLICIT. Pretty obvious IMO. The remaining change is to Promise-backend.js, as discussed in the comments.
Attachment #8632231 - Flags: review?(bzbarsky)
Comment on attachment 8632231 [details] [diff] [review] fix regressions There is at least one more regression, so cancelling the r? for now.
Attachment #8632231 - Flags: review?(bzbarsky)
Attached patch fix regressions (obsolete) — — Splinter Review
This one seems to remove the Windows crash in M(2). Unfortunately I don't have a good explanation for it. I noticed, belatedly, that the AutoSetAsyncStackForNewCalls initialization was happening in a block that was marked AutoSuppressGCAnalysis. So on the theory that maybe I had accidentally suppressed some rooting bug that I couldn't find by inspection, I moved it -- and the crash went away. I don't think the code was actually unsafe, though. And I would perhaps have expected the call to JS_NewStringCopyZ to assert in this situation; whereas in reality the symptom was a more mysterious crash. I'm mildly reluctant to ask for review on this. But perhaps you will have some better insight. As before I intend to squash this into patch #2; it is separate just to make the review a bit simpler. If you prefer a squashed patch let me know.
Attachment #8632231 - Attachment is obsolete: true
Attachment #8634921 - Flags: review?(bzbarsky)
Comment on attachment 8634921 [details] [diff] [review] fix regressions Emplacing the rooted stack stuff only once we know we plan to run script makes sense, but was it actually breaking something to do it the other way? I guess we weren't in a request? >+ var file = "http://mochi.test:8888/tests/dom/bindings/test/test_exception_options_from_jsimplemented.html"; How about location.href? And please use template strings instead of string concat with '+', throughout this test. You can still throw \n in there if you want to avoid shifting all the line numbers... but you're shifting them all anyway, right? The testThrowCallbackError case is a bit weird because it claims there's an async stack when there really kind of isn't. Please file a followup to see whether we can make that case better. r=me with that
Attachment #8634921 - Flags: review?(bzbarsky) → review+
(In reply to Boris Zbarsky [:bz] from comment #113) > Comment on attachment 8634921 [details] [diff] [review] > fix regressions > > Emplacing the rooted stack stuff only once we know we plan to run script > makes sense, but was it actually breaking something to do it the other way? > I guess we weren't in a request? See the try run in comment #109, in particular the M(2) failure. I don't have a theory to explain why the failure went away with this patch, though :( > The testThrowCallbackError case is a bit weird because it claims there's an > async stack when there really kind of isn't. Please file a followup to see > whether we can make that case better. The test is in doTest, which is called via: SpecialPowers.pushPrefEnv({set: [['dom.expose_test_interfaces', true]]}, doTest); ... which seems to use setTimeout to call the callback. So I think there is an async call here, or maybe I am misunderstanding what you mean.
Rebased.
Attachment #8629012 - Attachment is obsolete: true
Attachment #8629013 - Attachment is obsolete: true
Attachment #8634921 - Attachment is obsolete: true
Rebased; regression fixes merged in; review comments addressed.
Attachment #8635302 - Flags: review+
Attachment #8635303 - Flags: review+
Keywords: checkin-needed
> I don't have a theory to explain why the failure went away with this patch, though Yeah, ok. It was crashing before the code you added (in the old version) which is pretty weird. And looking carefully, the old code was in fact in a request by the time it ran... So I don't have a theory either. :( > So I think there is an async call here, or maybe I am misunderstanding what you mean. Ah, I see. I misread the stack string being asserted because it had the first two lines on one line but the third on a different line. I agree the stack being produced here is good; sorry for the noise.
Backed out for test_async_setTimeout_stack.html and test_async_setTimeout_stack_across_globals.html failures on at least Mulet. https://treeherder.mozilla.org/logviewer.html#?job_id=11831549&repo=mozilla-inbound https://hg.mozilla.org/integration/mozilla-inbound/rev/7d05fa306c73
(In reply to Ryan VanderMeulen [:RyanVM UTC-4] from comment #119) > Backed out for test_async_setTimeout_stack.html and > test_async_setTimeout_stack_across_globals.html failures on at least Mulet. Failed on Android too
Async stacks are disabled on android and b2g, last I checked... The test either needs to enable them around itself or check the pref and have different expected results or something...
(In reply to Boris Zbarsky [:bz] from comment #122) > Async stacks are disabled on android and b2g, last I checked... The test > either needs to enable them around itself or check the pref and have > different expected results or something... One of the tests does this, but gets different results if the pref is false at startup. I'm working on fixes for these.
> One of the tests does this, but gets different results if the pref is false > at startup. My theory for this is that the async stack isn't captured because the pref is off at the time of capture; so when the pref is enabled it is too late. At least for the test I'm currently looking at, this doesn't affect the usefulness of the test; but I will check each one to be sure.
The patch required two kinds of changes. First, I just removed a bit from a couple of tests, like this (relative to the latest patch in this bug): --- a/dom/base/test/test_async_setTimeout_stack.html +++ b/dom/base/test/test_async_setTimeout_stack.html @@ -48,8 +48,6 @@ https://bugzilla.mozilla.org/show_bug.cgi?id=1142577 is(frames[8], "c"); is(frames[9], "b"); is(frames[10], "a"); - // One extra frame due to pushPrefEnv. - is(frames.length, 12); SimpleTest.finish(); } This test could only really be ">= 11" -- but that's already effectively tested by examining frames 0-10. Second, a couple spots needed this sort of treatment: + var asyncFrame; + if (SpecialPowers.getBoolPref("javascript.options.asyncstack")) { + asyncFrame = `Async*@${file}:143:1\n`; + } else { + asyncFrame = ""; + } In these cases, enabling the pref would cause it to take effect too late; and since the tests aren't targeting this feature, it was simpler to just adapt. I retested locally with the pref defaulting to both on and off; but will push the result through a more complete try run before requesting checkin. I consider the above changes trivial enough to carry over the r+ when the time comes.
Rebased.
Attachment #8635302 - Attachment is obsolete: true
Attachment #8635303 - Attachment is obsolete: true
Rebased; cleaned up test failures for platforms where javascript.options.asyncstack is false by default.
Attachment #8636025 - Attachment is obsolete: true
Attachment #8636026 - Attachment is obsolete: true
Fix up tests for e10s failures.
Somehow I neglected to update one line number when patching the test.
Attachment #8636652 - Attachment is obsolete: true
Attachment #8636651 - Flags: review+
Comment on attachment 8636754 [details] [diff] [review] create async stack in callback objects Sorry about this, but you will probably want to check what I had to do in the tests dom/bindings/test/test_exception_options_from_jsimplemented.html and dom/bindings/test/test_promise_rejections_from_jsimplemented.html What's going on here is just that there's some difference due to e10s, so the tests have to depend both on the setting of the async stack pref and on whether e10s is in use. The way I detect e10s seems iffy. Another approach might be to always allow either form of the stack trace. On the plus side I finally got a green-enough try run. There were no issues with the patch itself, just some difficulties updating the tests properly.
Attachment #8636754 - Flags: review?(bzbarsky)
Comment on attachment 8636754 [details] [diff] [review] create async stack in callback objects >+ /* Async parent frames don't show up in e10s. */ You mean the async parent frame from pushPrefEnv, right? In general I assume they do! Please adjust the comments as needed. As long as you're changing all the line numbers again, it really would be nice to replace the \n in the middle of backtick strings with actual newlines. It would make things much clearer... r=me if the only thing you wanted me to look at was those two test files (test_exception_options_from_jsimplemented.html and test_promise_rejections_from_jsimplemented.html).
Attachment #8636754 - Flags: review?(bzbarsky) → review+
Bug 1187123 turns out to be unrelated to this bug.
No longer depends on: 1187123
Rebased.
Attachment #8636651 - Attachment is obsolete: true
Attachment #8636754 - Attachment is obsolete: true
Addressed review comments.
Attachment #8638537 - Flags: review+
Attachment #8638536 - Flags: review+
Keywords: checkin-needed
https://hg.mozilla.org/mozilla-central/rev/e741b5a17b19 https://hg.mozilla.org/mozilla-central/rev/01675d584873
Status: ASSIGNED → RESOLVED
Closed: 9 years ago
status-firefox42: --- → fixed
Flags: in-testsuite+
Resolution: --- → FIXED
Target Milestone: --- → mozilla42
Added using "Asynchronous call stacks now allow web developers to follow the code flow through setTimeout, DOM event handlers, and Promise handlers. " as wording. Having a link to a doc or a blog post would be appreciated as it is not an obvious feature.
relnote-firefox: ? → 42+
Component: DOM → DOM: Core & HTML
You need to log in before you can comment on or make changes to this bug.

Attachment

General

Creator:
Created:
Updated:
Size: