We have a newtab preloader per browser window. The preloaded browser is created after the first new tab is opened in that window[1]. This means that if you open a new window, you essentially "reset" the preloaded behaviour for the first newtab open in that window, and you only get the preloaded behaviour again after that first newtab in that window is opened. Is there a better time when we can preload that about:newtab? Note also that about:newtab and about:home is slated to be replaced by Activity Stream Real Soon Now. What I suggest is to try using window.requestIdleCallback to preload the newtab when we feel that the browser is "idle": https://developer.mozilla.org/en-US/docs/Web/API/Window/requestIdleCallback I suggest some probes to go along with this: 1) How long since a window has opened before the first new tab is preloaded 2) How long it takes to preload the new tab 3) How often a new tab is opened and the preloaded tab is not available [1]: http://searchfox.org/mozilla-central/rev/990055a4902952e038cc350c9ffe1ac426d1c943/browser/base/content/tabbrowser.xml#6428

I also thought about preloading the about:newtab page better. Two ideas I came up with: - we currently load the about:newtab page for the first time when the user clicks the "+" button. We could start loading it when the user moves the mouse over that + button. - we display about:newtab fast the second time by swapping docshells. I don't see what prevents us from doing docshell swapping across windows, as long as we keep creating a second about:newtab page in the edge case where the existing about:newtab page is currently the selected tab in an existing window.

(In reply to Florian Quèze [:florian] [:flo] from comment #1) > - we currently load the about:newtab page for the first time when the user > clicks the "+" button. We could start loading it when the user moves the > mouse over that + button. Yep, that's not a bad idea either - though I wonder how much time there is between the user hovering that button, and the user clicking that button... That also doesn't take the Ctrl-T keyboard shortcut into account. > - we display about:newtab fast the second time by swapping docshells. I thought this was the case as well, but that's no longer true. Bug 1077652 switched us over to swapping in a background <xul:browser> instead of doing a DocShell / Frameloader swap. In fact, bug 1077652 switched us _away_ from having a global preloaded about:newtab.

(In reply to Mike Conley (:mconley) (Very high latency until April 3rd) from comment #2) > (In reply to Florian Quèze [:florian] [:flo] from comment #1) > > - we currently load the about:newtab page for the first time when the user > > clicks the "+" button. We could start loading it when the user moves the > > mouse over that + button. > > Yep, that's not a bad idea either - though I wonder how much time there is > between the user hovering that button, and the user clicking that button... > > That also doesn't take the Ctrl-T keyboard shortcut into account. I would expect the time between the mouseover and click events to be significantly longer than between mousedown and click (mouseup). And the latter is already ~100ms on average if I remember correctly the data phlsa showed me. Note that I mostly have in mind the case of users interacting mostly with the mouse (ie. not me; I use Cmd+T all the time...). I think they are the majority. > > - we display about:newtab fast the second time by swapping docshells. > > I thought this was the case as well, but that's no longer true. Bug 1077652 > switched us over to swapping in a background <xul:browser> instead of doing > a DocShell / Frameloader swap. In fact, bug 1077652 switched us _away_ from > having a global preloaded about:newtab. So the bug description there says that swapping a xul:browser within a window is faster than swapping a docshell from the hidden window... but I wonder if there was a reason to not combine the two approach, and do a docshell swap when it's across different windows, and a xul:browser swap when it's in the same window.

(In reply to Florian Quèze [:florian] [:flo] from comment #3) > So the bug description there says that swapping a xul:browser within a > window is faster than swapping a docshell from the hidden window... but I > wonder if there was a reason to not combine the two approach, and do a > docshell swap when it's across different windows, and a xul:browser swap > when it's in the same window. Doubtful if ttaubert or dao remembers (this landed quite a while ago), but let's check.

(In reply to Mike Conley (:mconley) - At work week, slow to respond from comment #4) > (In reply to Florian Quèze [:florian] [:flo] from comment #3) > > So the bug description there says that swapping a xul:browser within a > > window is faster than swapping a docshell from the hidden window... but I > > wonder if there was a reason to not combine the two approach, and do a > > docshell swap when it's across different windows, and a xul:browser swap > > when it's in the same window. > > Doubtful if ttaubert or dao remembers (this landed quite a while ago), but > let's check. Probably wasn't considered worth the complexity.

This works but regresses talos: https://treeherder.mozilla.org/perf.html#/compare?originalProject=try&originalRevision=d91d968b3081b2c7fca4eba85c9c6765780489dd&newProject=try&newRevision=30b29ec75a7b1c4cdf0ed2d8865796b9dfa968b7&framework=1&showOnlyConfident=1 This might be expected. I suspect tpo5 never opens a new tab without a specific URL, so it doesn't hit about:newtab preloading at all without this patch. I'm however a bit disappointed that requestIdleCallback doesn't prevent the responsiveness regression.

Comment on attachment 8886645 [details] [diff] [review] prototype patch Review of attachment 8886645 [details] [diff] [review]: ----------------------------------------------------------------- Looks reasonable, and sorry for the delay before I looked at this patch. I'm afraid I can't really help with the Talos regressions, Mike is the expert on this, so forwarding to him. ::: browser/base/content/tabbrowser.xml @@ +2045,5 @@ > + > + window.requestIdleCallback(() => this._createPreloadBrowser()); > + } > + }; > + Services.idle.addIdleObserver(this._preloadBrowserIdleObserver, 1); this._preloadBrowserMinUserIdleSeconds instead of '1'?

Let's see if some profiles help illuminate what's happening: Baseline: https://treeherder.mozilla.org/#/jobs?repo=try&revision=9a970fd9f163111345156fe4d502a0366c552220 With patch: https://treeherder.mozilla.org/#/jobs?repo=try&revision=b7feb407a40e13c9aec823d084d410a3c87a9f70

So I gathered some profiles, and one thing that stands out immediately is that without this patch, there's a single content process... and with the patch, there are 3. Obviously there's a content process for the pages we're loading in the tab... and I guess there'll be a content process for the preloaded page now that Activity Stream loads in the content process... not sure where that third one is coming from. I'm not sure if the increase in content processes is in any way related to the drag on event responsiveness, but it's all that's really standing out to me in these profiles. I wonder if that third content process is for the thumbnailer? I'm going to re-push with browser-thumbnails.js neutered to see how that affects things.

So I (finally!) got back around to this. I had to re-base the patch a bit, but here is a comparison against yesterday's mozilla-central: https://treeherder.mozilla.org/perf.html#/compare?originalProject=try&originalRevision=98818f8b3ac5&newProject=try&newRevision=413556ac2c16&framework=1 So the characteristics have changed. The responsiveness regression is gone. Instead, I see tresize regressions and a tsvg_static regression. I suspect the tsvg_static one can be avoided by disabling preloading in that test (tsvg really only cares about SVG rendering performance - noise caused by the rest of the browser is... noise). The tresize one is more interesting, and I'll investigate that next.

Comment on attachment 8886645 [details] [diff] [review] prototype patch Wow, sorry for the massive delay. I have news. So I poked at this a bit today, and it turns out that even if the browser is doing something very frequently (say, resizing the window every 20ms or so after a paint, like what tresize does), an idle callback might still fire. Heck, I was able to shrink that window down to 0ms after each paint, and idle callbacks _still_ fired. There are little zones of idleness between the resize, the paint, and the next resize, and so the preloaded browser is getting loaded in there. That's causing us to do work that (I believe) is adding noise to the tsvg and tresize tests. One thing we might do: Callbacks passed to requestIdleCallback get passed an IdleDeadline object[1]. The IdleDeadline object has a timeRemaining() method on it that returns an estimate of how much time is remaining in the idle period. What I propose is that we have our idle callback check the timeRemaining(), and make sure it's greater than some threshold - otherwise, we postpone. I'll post a patch trying that shortly and push it to try. [1]: https://developer.mozilla.org/en-US/docs/Web/API/IdleDeadline

Comparison: https://treeherder.mozilla.org/perf.html#/compare?originalProject=try&originalRevision=3d54b4662ee5&newProject=try&newRevision=28bc988f51a0&framework=1&showOnlyImportant=0

That appears to have done it for both tsvg / tscroll. Hey dao, did you still want to do this, or can I take it off your hands?

Comment on attachment 8900931 [details] Bug 1353013 - Be less aggressive about preloading about:newtab. https://reviewboard.mozilla.org/r/172378/#review179562 Looks good to me. ::: browser/base/content/tabbrowser.xml:2057 (Diff revision 2) > ]]> > </body> > </method> > > + <field name="_preloadBrowserMinUserIdleSeconds">1</field> > + <field name="_preloadBrowserMinIdlePeriodMs">40</field> I'm surprised we can get an idle deadline that's longer than a frame, but I assume you have tested this :-). ::: browser/base/content/tabbrowser.xml:2069 (Diff revision 2) > + !this._isPreloadingEnabled()) { > + return; > + } > + > + this._preloadBrowserIdleObserver = (aSubject, aTopic) => { > + if (aTopic == "idle") { nit: return early instead to reduce the indent of the whole function? ::: browser/base/content/tabbrowser.xml:2072 (Diff revision 2) > + this._preloadBrowserIdleObserver = null; > + > + let idleCallback = (deadline) => { nit: you don't need the parenthesis

Comment on attachment 8900931 [details] Bug 1353013 - Be less aggressive about preloading about:newtab. https://reviewboard.mozilla.org/r/172378/#review179562 > I'm surprised we can get an idle deadline that's longer than a frame, but I assume you have tested this :-). Indeed I have! > nit: return early instead to reduce the indent of the whole function? Good idea.

Pushed by mconley@mozilla.com: https://hg.mozilla.org/integration/autoland/rev/5d320d8864e9 Be less aggressive about preloading about:newtab. r=florian

Backed out for failing e.g. test_accessiblecaret_cursor_mode.py of Marionette headless on OS X: https://hg.mozilla.org/integration/autoland/rev/5ea49e6b1af6164ddf78dee5fe00c2a947b0bfcf Push with failures: https://treeherder.mozilla.org/#/jobs?repo=autoland&revision=5d320d8864e90aa9684462251fee5b60f055ea9b&filter-resultStatus=testfailed&filter-resultStatus=busted&filter-resultStatus=exception&filter-resultStatus=retry&filter-resultStatus=usercancel&filter-resultStatus=runnable Marionette failure: https://treeherder.mozilla.org/logviewer.html#?job_id=128643966&repo=autoland TEST-UNEXPECTED-FAIL | test_accessiblecaret_cursor_mode.py AccessibleCaretCursorModeTestCase.test_caret_not_jump_when_dragging_to_editable_content_boundary_contenteditable | AssertionError: u'ABCDEFGHI!' == u'ABCDEFGHI!' a11y failure (at least on Linux stylo): https://treeherder.mozilla.org/logviewer.html#?job_id=128646572&repo=autoland > FAIL | accessible/tests/mochitest/relations/test_tabbrowser.xul | [ 'notificationbox node', address: [object XULElement] ] is not a target of relation of 'label for' type for '[ 'tab node', address: [object XULElement] ]'. chrome failure on Linux: https://treeherder.mozilla.org/logviewer.html#?job_id=128646579&repo=autoland > TEST-UNEXPECTED-FAIL | layout/style/test/chrome/test_hover.html | Test timed out.

This also triggers assertions on stylo: https://treeherder.mozilla.org/logviewer.html#?job_id=128646780&repo=autoland [task 2017-09-05T20:21:36.683712Z] 20:21:36 INFO - TEST-START | dom/events/test/test_bug336682_1.html [task 2017-09-05T20:21:36.726594Z] 20:21:36 INFO - GECKO(1641) | [Child 1687] WARNING: stylo: ServoStyleSets cannot respond to document state changes yet (only matters for chrome documents). See bug 1290285.: file /builds/worker/workspace/build/src/layout/base/PresShell.cpp, line 4318 [task 2017-09-05T20:21:36.866211Z] 20:21:36 INFO - GECKO(1641) | ++DOMWINDOW == 49 (0x7fc66291c800) [pid = 1687] [serial = 64] [outer = 0x7fc666acb800] [task 2017-09-05T20:21:36.963378Z] 20:21:36 INFO - GECKO(1641) | [Child 1687] WARNING: stylo: Web Components not supported yet: file /builds/worker/workspace/build/src/dom/base/nsDocument.cpp, line 6418 [task 2017-09-05T20:21:36.972717Z] 20:21:36 INFO - GECKO(1641) | [Child 1687] WARNING: stylo: Web Components not supported yet: file /builds/worker/workspace/build/src/dom/base/nsDocument.cpp, line 6418 [task 2017-09-05T20:21:37.211619Z] 20:21:37 INFO - GECKO(1641) | [Child 1687] WARNING: stylo: ServoStyleSets cannot respond to document state changes yet (only matters for chrome documents). See bug 1290285.: file /builds/worker/workspace/build/src/layout/base/PresShell.cpp, line 4318 [task 2017-09-05T20:21:37.430673Z] 20:21:37 INFO - GECKO(1641) | Assertion failure: IsSafeToRun(), at /builds/worker/workspace/build/src/obj-firefox/dist/include/mozilla/SchedulerGroup.h:74 [task 2017-09-05T20:22:31.219134Z] 20:22:31 INFO - GECKO(1641) | #01: nsDocument::GetEventTargetParent [dom/base/nsDocument.cpp:8312] [task 2017-09-05T20:22:31.219613Z] 20:22:31 INFO - [task 2017-09-05T20:22:31.221953Z] 20:22:31 INFO - GECKO(1641) | #02: mozilla::EventTargetChainItem::GetEventTargetParent [dom/events/EventDispatcher.cpp:211] [task 2017-09-05T20:22:31.222182Z] 20:22:31 INFO - [task 2017-09-05T20:22:31.223984Z] 20:22:31 INFO - GECKO(1641) | #03: mozilla::EventDispatcher::Dispatch [dom/events/EventDispatcher.cpp:788] [task 2017-09-05T20:22:31.225633Z] 20:22:31 INFO - [task 2017-09-05T20:22:31.227447Z] 20:22:31 INFO - GECKO(1641) | #04: mozilla::EventDispatcher::DispatchDOMEvent [dom/events/EventDispatcher.cpp:892] [task 2017-09-05T20:22:31.230305Z] 20:22:31 INFO - [task 2017-09-05T20:22:31.234408Z] 20:22:31 INFO - GECKO(1641) | #05: nsINode::DispatchEvent [dom/base/nsINode.cpp:1342] [task 2017-09-05T20:22:31.235988Z] 20:22:31 INFO - [task 2017-09-05T20:22:31.238477Z] 20:22:31 INFO - GECKO(1641) | #06: nsContentUtils::DispatchEvent [dom/base/nsContentUtils.cpp:4554] [task 2017-09-05T20:22:31.240973Z] 20:22:31 INFO - [task 2017-09-05T20:22:31.243860Z] 20:22:31 INFO - GECKO(1641) | #07: nsContentUtils::DispatchTrustedEvent [dom/base/nsContentUtils.cpp:4524] [task 2017-09-05T20:22:31.246848Z] 20:22:31 INFO - [task 2017-09-05T20:22:31.248821Z] 20:22:31 INFO - GECKO(1641) | #08: nsGlobalWindow::FireOfflineStatusEventIfChanged [dom/base/nsGlobalWindow.cpp:11549] [task 2017-09-05T20:22:31.251614Z] 20:22:31 INFO - [task 2017-09-05T20:22:31.254611Z] 20:22:31 INFO - GECKO(1641) | #09: nsGlobalWindow::Observe [dom/base/nsGlobalWindow.cpp:12188] [task 2017-09-05T20:22:31.256805Z] 20:22:31 INFO - [task 2017-09-05T20:22:31.259290Z] 20:22:31 INFO - GECKO(1641) | #10: nsObserverList::NotifyObservers [xpcom/ds/nsObserverList.cpp:111] [task 2017-09-05T20:22:31.261861Z] 20:22:31 INFO - [task 2017-09-05T20:22:31.264582Z] 20:22:31 INFO - GECKO(1641) | #11: nsObserverService::NotifyObservers [xpcom/ds/nsTHashtable.h:136] [task 2017-09-05T20:22:31.266879Z] 20:22:31 INFO - [task 2017-09-05T20:22:31.268880Z] 20:22:31 INFO - GECKO(1641) | #12: mozilla::net::nsIOService::SetOffline [netwerk/base/nsIOService.cpp:1157] [task 2017-09-05T20:22:31.271751Z] 20:22:31 INFO - [task 2017-09-05T20:22:31.274417Z] 20:22:31 INFO - GECKO(1641) | #13: NS_InvokeByIndex [task 2017-09-05T20:22:31.278965Z] 20:22:31 INFO - [task 2017-09-05T20:22:31.281870Z] 20:22:31 INFO - GECKO(1641) | #14: CallMethodHelper::Call [js/xpconnect/src/xpcprivate.h:776] [task 2017-09-05T20:22:31.283595Z] 20:22:31 INFO - [task 2017-09-05T20:22:31.286855Z] 20:22:31 INFO - GECKO(1641) | #15: XPCWrappedNative::CallMethod [js/xpconnect/src/XPCWrappedNative.cpp:1282] [task 2017-09-05T20:22:31.288809Z] 20:22:31 INFO - [task 2017-09-05T20:22:31.292098Z] 20:22:31 INFO - GECKO(1641) | #16: XPC_WN_GetterSetter [js/xpconnect/src/XPCWrappedNativeJSOps.cpp:957] [task 2017-09-05T20:22:31.294523Z] 20:22:31 INFO - [task 2017-09-05T20:22:31.297777Z] 20:22:31 INFO - GECKO(1641) | #17: js::CallJSNative [js/src/jscntxtinlines.h:294] [task 2017-09-05T20:22:31.300000Z] 20:22:31 INFO - [task 2017-09-05T20:22:31.301965Z] 20:22:31 INFO - GECKO(1641) | #18: js::InternalCallOrConstruct [js/src/vm/Interpreter.cpp:494] [task 2017-09-05T20:22:31.304888Z] 20:22:31 INFO - [task 2017-09-05T20:22:31.307698Z] 20:22:31 INFO - GECKO(1641) | #19: js::Call [js/src/vm/Interpreter.cpp:558] [task 2017-09-05T20:22:31.310074Z] 20:22:31 INFO - [task 2017-09-05T20:22:31.312606Z] 20:22:31 INFO - GECKO(1641) | #20: js::CallSetter [js/src/vm/Interpreter.cpp:686] [task 2017-09-05T20:22:31.315038Z] 20:22:31 INFO - [task 2017-09-05T20:22:31.318354Z] 20:22:31 INFO - GECKO(1641) | #21: SetExistingProperty [js/src/vm/NativeObject.cpp:2749] [task 2017-09-05T20:22:31.320600Z] 20:22:31 INFO - [task 2017-09-05T20:22:31.322590Z] 20:22:31 INFO - GECKO(1641) | #22: js::NativeSetProperty<(js::QualifiedBool)1u> [js/src/vm/NativeObject.cpp:2785] [task 2017-09-05T20:22:31.325470Z] 20:22:31 INFO - [task 2017-09-05T20:22:31.327920Z] 20:22:31 INFO - GECKO(1641) | #23: Reflect_set [js/src/vm/NativeObject.h:1555] [task 2017-09-05T20:22:31.330510Z] 20:22:31 INFO - [task 2017-09-05T20:22:31.333375Z] 20:22:31 INFO - GECKO(1641) | #24: js::CallJSNative [js/src/jscntxtinlines.h:294] [task 2017-09-05T20:22:31.337539Z] 20:22:31 INFO - [task 2017-09-05T20:22:31.339351Z] 20:22:31 INFO - GECKO(1641) | #25: js::InternalCallOrConstruct [js/src/vm/Interpreter.cpp:494] [task 2017-09-05T20:22:31.340976Z] 20:22:31 INFO - [task 2017-09-05T20:22:31.347414Z] 20:22:31 INFO - GECKO(1641) | #26: Interpret [js/src/vm/Interpreter.cpp:3093] [task 2017-09-05T20:22:31.349067Z] 20:22:31 INFO - [task 2017-09-05T20:22:31.350836Z] 20:22:31 INFO - GECKO(1641) | #27: js::RunScript [js/src/vm/Interpreter.cpp:405] [task 2017-09-05T20:22:31.352395Z] 20:22:31 INFO - [task 2017-09-05T20:22:31.355424Z] 20:22:31 INFO - GECKO(1641) | #28: js::InternalCallOrConstruct [js/src/vm/Interpreter.cpp:512] [task 2017-09-05T20:22:31.358307Z] 20:22:31 INFO - [task 2017-09-05T20:22:31.360286Z] 20:22:31 INFO - GECKO(1641) | #29: js::Call [js/src/vm/Interpreter.cpp:558] [task 2017-09-05T20:22:31.366108Z] 20:22:31 INFO - [task 2017-09-05T20:22:31.367949Z] 20:22:31 INFO - GECKO(1641) | #30: js::ScriptedProxyHandler::set [js/src/proxy/ScriptedProxyHandler.cpp:1082] [task 2017-09-05T20:22:31.369541Z] 20:22:31 INFO - [task 2017-09-05T20:22:31.371298Z] 20:22:31 INFO - GECKO(1641) | #31: js::Proxy::setInternal [js/src/proxy/Proxy.cpp:390] [task 2017-09-05T20:22:31.374897Z] 20:22:31 INFO - [task 2017-09-05T20:22:31.377509Z] 20:22:31 INFO - GECKO(1641) | #32: js::Proxy::set [js/src/proxy/Proxy.cpp:399] [task 2017-09-05T20:22:31.379215Z] 20:22:31 INFO - [task 2017-09-05T20:22:31.381323Z] 20:22:31 INFO - GECKO(1641) | #33: JSObject::nonNativeSetProperty [js/src/jsobj.cpp:1041] [task 2017-09-05T20:22:31.383854Z] 20:22:31 INFO - [task 2017-09-05T20:22:31.385805Z] 20:22:31 INFO - GECKO(1641) | #34: js::ForwardingProxyHandler::set [js/src/vm/NativeObject.h:1554] [task 2017-09-05T20:22:31.389335Z] 20:22:31 INFO - [task 2017-09-05T20:22:31.391158Z] 20:22:31 INFO - GECKO(1641) | #35: js::CrossCompartmentWrapper::set [js/src/proxy/CrossCompartmentWrapper.cpp:238] [task 2017-09-05T20:22:31.392723Z] 20:22:31 INFO - [task 2017-09-05T20:22:31.394564Z] 20:22:31 INFO - GECKO(1641) | #36: js::Proxy::setInternal [js/src/proxy/Proxy.cpp:390] [task 2017-09-05T20:22:31.396165Z] 20:22:31 INFO - [task 2017-09-05T20:22:31.399260Z] 20:22:31 INFO - GECKO(1641) | #37: js::Proxy::set [js/src/proxy/Proxy.cpp:399] [task 2017-09-05T20:22:31.400888Z] 20:22:31 INFO - [task 2017-09-05T20:22:31.402705Z] 20:22:31 INFO - GECKO(1641) | #38: JSObject::nonNativeSetProperty [js/src/jsobj.cpp:1041] [task 2017-09-05T20:22:31.404248Z] 20:22:31 INFO - [task 2017-09-05T20:22:31.406128Z] 20:22:31 INFO - GECKO(1641) | #39: js::SetProperty [js/src/vm/NativeObject.h:1556] [task 2017-09-05T20:22:31.407667Z] 20:22:31 INFO - [task 2017-09-05T20:22:31.410102Z] 20:22:31 INFO - GECKO(1641) | #40: Interpret [js/src/vm/Interpreter.cpp:268] [task 2017-09-05T20:22:31.411646Z] 20:22:31 INFO - [task 2017-09-05T20:22:31.413595Z] 20:22:31 INFO - GECKO(1641) | #41: js::RunScript [js/src/vm/Interpreter.cpp:405] [task 2017-09-05T20:22:31.415176Z] 20:22:31 INFO - [task 2017-09-05T20:22:31.421403Z] 20:22:31 INFO - GECKO(1641) | #42: js::InternalCallOrConstruct [js/src/vm/Interpreter.cpp:512] [task 2017-09-05T20:22:31.423027Z] 20:22:31 INFO - [task 2017-09-05T20:22:31.424819Z] 20:22:31 INFO - GECKO(1641) | #43: js::Call [js/src/vm/Interpreter.cpp:558] [task 2017-09-05T20:22:31.429557Z] 20:22:31 INFO - [task 2017-09-05T20:22:31.431361Z] 20:22:31 INFO - GECKO(1641) | #44: js::fun_apply [js/src/jsfun.cpp:1306] [task 2017-09-05T20:22:31.432927Z] 20:22:31 INFO - [task 2017-09-05T20:22:31.434695Z] 20:22:31 INFO - GECKO(1641) | #45: js::CallJSNative [js/src/jscntxtinlines.h:294] [task 2017-09-05T20:22:31.436235Z] 20:22:31 INFO - [task 2017-09-05T20:22:31.438027Z] 20:22:31 INFO - GECKO(1641) | #46: js::InternalCallOrConstruct [js/src/vm/Interpreter.cpp:494] [task 2017-09-05T20:22:31.439815Z] 20:22:31 INFO - [task 2017-09-05T20:22:31.443847Z] 20:22:31 INFO - GECKO(1641) | #47: Interpret [js/src/vm/Interpreter.cpp:3093] [task 2017-09-05T20:22:31.445446Z] 20:22:31 INFO - [task 2017-09-05T20:22:31.447196Z] 20:22:31 INFO - GECKO(1641) | #48: js::RunScript [js/src/vm/Interpreter.cpp:405] [task 2017-09-05T20:22:31.448770Z] 20:22:31 INFO - [task 2017-09-05T20:22:31.450541Z] 20:22:31 INFO - GECKO(1641) | #49: js::InternalCallOrConstruct [js/src/vm/Interpreter.cpp:512] [task 2017-09-05T20:22:31.453344Z] 20:22:31 INFO - [task 2017-09-05T20:22:31.455133Z] 20:22:31 INFO - GECKO(1641) | #50: js::Call [js/src/vm/Interpreter.cpp:558] [task 2017-09-05T20:22:31.456772Z] 20:22:31 INFO - [task 2017-09-05T20:22:31.460209Z] 20:22:31 INFO - GECKO(1641) | #51: JS::Call [js/src/jsapi.cpp:2937] [task 2017-09-05T20:22:31.461806Z] 20:22:31 INFO - [task 2017-09-05T20:22:31.463868Z] 20:22:31 INFO - GECKO(1641) | #52: mozilla::dom::EventHandlerNonNull::Call [s3:gecko-generated-sources:a74e9167ed4abbea1a7e9c415f889f61cd08d508be96276b8e3ab3a810441ec213bf1f2f7e0a571d855d6c770f010a4bda5422bbef494642dc5e121077b09766/dom/bindings/EventHandlerBinding.cpp::260] [task 2017-09-05T20:22:31.466840Z] 20:22:31 INFO - [task 2017-09-05T20:22:31.468984Z] 20:22:31 INFO - GECKO(1641) | #53: mozilla::JSEventHandler::HandleEvent [s3:gecko-generated-sources:d0cd062a8f2e61a1842e705e1539dafa6e2559f266e0cf39cc24ecbc1de67828060d8f7d4015631bcfe7c22d53ac77e562e84587fe96e76b41b346b32ed4aeb6/dist/include/mozilla/dom/EventHandlerBinding.h::357] [task 2017-09-05T20:22:31.470632Z] 20:22:31 INFO - [task 2017-09-05T20:22:31.473692Z] 20:22:31 INFO - GECKO(1641) | #54: mozilla::EventListenerManager::HandleEventSubType [dom/events/EventListenerManager.cpp:1114] [task 2017-09-05T20:22:31.475293Z] 20:22:31 INFO - [task 2017-09-05T20:22:31.481150Z] 20:22:31 INFO - GECKO(1641) | #55: mozilla::EventListenerManager::HandleEventInternal [dom/events/EventListenerManager.cpp:1283] [task 2017-09-05T20:22:31.482809Z] 20:22:31 INFO - [task 2017-09-05T20:22:31.484619Z] 20:22:31 INFO - GECKO(1641) | #56: mozilla::EventTargetChainItem::HandleEvent [dom/events/EventListenerManager.h:376] [task 2017-09-05T20:22:31.486199Z] 20:22:31 INFO - [task 2017-09-05T20:22:31.488019Z] 20:22:31 INFO - GECKO(1641) | #57: mozilla::EventTargetChainItem::HandleEventTargetChain [dom/events/EventDispatcher.cpp:462] [task 2017-09-05T20:22:31.489619Z] 20:22:31 INFO - [task 2017-09-05T20:22:31.491385Z] 20:22:31 INFO - GECKO(1641) | #58: mozilla::EventDispatcher::Dispatch [dom/events/EventDispatcher.cpp:827] [task 2017-09-05T20:22:31.492939Z] 20:22:31 INFO - [task 2017-09-05T20:22:31.494724Z] 20:22:31 INFO - GECKO(1641) | #59: nsDocumentViewer::LoadComplete [layout/base/nsDocumentViewer.cpp:1082] [task 2017-09-05T20:22:31.497552Z] 20:22:31 INFO - [task 2017-09-05T20:22:31.499323Z] 20:22:31 INFO - GECKO(1641) | #60: nsDocShell::EndPageLoad [docshell/base/nsDocShell.cpp:7726] [task 2017-09-05T20:22:31.501980Z] 20:22:31 INFO - [task 2017-09-05T20:22:31.503806Z] 20:22:31 INFO - GECKO(1641) | #61: nsDocShell::OnStateChange [docshell/base/nsDocShell.cpp:7522] [task 2017-09-05T20:22:31.505517Z] 20:22:31 INFO - [task 2017-09-05T20:22:31.507522Z] 20:22:31 INFO - GECKO(1641) | #62: nsDocLoader::DoFireOnStateChange [uriloader/base/nsDocLoader.cpp:1320] [task 2017-09-05T20:22:31.509708Z] 20:22:31 INFO - [task 2017-09-05T20:22:31.511704Z] 20:22:31 INFO - GECKO(1641) | #63: nsDocLoader::doStopDocumentLoad [uriloader/base/nsDocLoader.cpp:860] [task 2017-09-05T20:22:31.516524Z] 20:22:31 INFO - [task 2017-09-05T20:22:31.518413Z] 20:22:31 INFO - GECKO(1641) | #64: nsDocLoader::DocLoaderIsEmpty [uriloader/base/nsDocLoader.cpp:752] [task 2017-09-05T20:22:31.520011Z] 20:22:31 INFO - [task 2017-09-05T20:22:31.521865Z] 20:22:31 INFO - GECKO(1641) | #65: nsDocLoader::OnStopRequest [uriloader/base/nsDocLoader.cpp:625] [task 2017-09-05T20:22:31.523466Z] 20:22:31 INFO - [task 2017-09-05T20:22:31.525339Z] 20:22:31 INFO - GECKO(1641) | #66: mozilla::net::nsLoadGroup::RemoveRequest [netwerk/base/nsLoadGroup.cpp:631] [task 2017-09-05T20:22:31.528238Z] 20:22:31 INFO - [task 2017-09-05T20:22:31.530125Z] 20:22:31 INFO - GECKO(1641) | #67: nsDocument::DoUnblockOnload [dom/base/nsDocument.cpp:9247] [task 2017-09-05T20:22:31.533761Z] 20:22:31 INFO - [task 2017-09-05T20:22:31.535637Z] 20:22:31 INFO - GECKO(1641) | #68: nsDocument::UnblockOnload [dom/base/nsDocument.cpp:9171] [task 2017-09-05T20:22:31.537258Z] 20:22:31 INFO - [task 2017-09-05T20:22:31.539134Z] 20:22:31 INFO - GECKO(1641) | #69: nsDocument::DispatchContentLoadedEvents [dom/base/nsDocument.cpp:5558] [task 2017-09-05T20:22:31.540844Z] 20:22:31 INFO - [task 2017-09-05T20:22:31.542991Z] 20:22:31 INFO - GECKO(1641) | #70: mozilla::detail::RunnableMethodImpl<nsDocument*, void (nsDocument::*)(), true, (mozilla::RunnableKind)0u>::Run [xpcom/threads/nsThreadUtils.h:1196] [task 2017-09-05T20:22:31.547339Z] 20:22:31 INFO - [task 2017-09-05T20:22:31.549259Z] 20:22:31 INFO - GECKO(1641) | #71: mozilla::SchedulerGroup::Runnable::Run [xpcom/threads/SchedulerGroup.cpp:396] [task 2017-09-05T20:22:31.550905Z] 20:22:31 INFO - [task 2017-09-05T20:22:31.552723Z] 20:22:31 INFO - GECKO(1641) | #72: nsThread::ProcessNextEvent [mfbt/Maybe.h:445] [task 2017-09-05T20:22:31.554366Z] 20:22:31 INFO - [task 2017-09-05T20:22:31.557314Z] 20:22:31 INFO - GECKO(1641) | #73: NS_ProcessNextEvent [xpcom/threads/nsThreadUtils.cpp:521] [task 2017-09-05T20:22:31.558958Z] 20:22:31 INFO - [task 2017-09-05T20:22:31.561869Z] 20:22:31 INFO - GECKO(1641) | #74: mozilla::ipc::MessagePump::Run [ipc/glue/MessagePump.cpp:98] [task 2017-09-05T20:22:31.563411Z] 20:22:31 INFO - [task 2017-09-05T20:22:31.565259Z] 20:22:31 INFO - GECKO(1641) | #75: MessageLoop::RunInternal [ipc/chromium/src/base/message_loop.cc:327] [task 2017-09-05T20:22:31.569983Z] 20:22:31 INFO - [task 2017-09-05T20:22:31.571817Z] 20:22:31 INFO - GECKO(1641) | #76: MessageLoop::Run [ipc/chromium/src/base/message_loop.cc:298] [task 2017-09-05T20:22:31.573436Z] 20:22:31 INFO - [task 2017-09-05T20:22:31.575226Z] 20:22:31 INFO - GECKO(1641) | #77: nsBaseAppShell::Run [widget/nsBaseAppShell.cpp:160] [task 2017-09-05T20:22:31.576810Z] 20:22:31 INFO - [task 2017-09-05T20:22:31.578627Z] 20:22:31 INFO - GECKO(1641) | #78: XRE_RunAppShell [toolkit/xre/nsEmbedFunctions.cpp:823] [task 2017-09-05T20:22:31.580455Z] 20:22:31 INFO - [task 2017-09-05T20:22:31.584398Z] 20:22:31 INFO - GECKO(1641) | #79: mozilla::ipc::MessagePumpForChildProcess::Run [ipc/glue/MessagePump.cpp:269] [task 2017-09-05T20:22:31.585997Z] 20:22:31 INFO - [task 2017-09-05T20:22:31.587792Z] 20:22:31 INFO - GECKO(1641) | #80: MessageLoop::RunInternal [ipc/chromium/src/base/message_loop.cc:327] [task 2017-09-05T20:22:31.589411Z] 20:22:31 INFO - [task 2017-09-05T20:22:31.591252Z] 20:22:31 INFO - GECKO(1641) | #81: MessageLoop::Run [ipc/chromium/src/base/message_loop.cc:298] [task 2017-09-05T20:22:31.595031Z] 20:22:31 INFO - [task 2017-09-05T20:22:31.596839Z] 20:22:31 INFO - GECKO(1641) | #82: XRE_InitChildProcess [toolkit/xre/nsEmbedFunctions.cpp:695] [task 2017-09-05T20:22:31.598381Z] 20:22:31 INFO - [task 2017-09-05T20:22:31.616957Z] 20:22:31 INFO - GECKO(1641) | #83: content_process_main [ipc/contentproc/plugin-container.cpp:65] [task 2017-09-05T20:22:31.617288Z] 20:22:31 INFO - [task 2017-09-05T20:22:31.618901Z] 20:22:31 INFO - GECKO(1641) | #84: main [browser/app/nsBrowserApp.cpp:288] [task 2017-09-05T20:22:31.619317Z] 20:22:31 INFO - [task 2017-09-05T20:22:31.620915Z] 20:22:31 INFO - GECKO(1641) | #85: libc.so.6 + 0x20830 [task 2017-09-05T20:22:31.622476Z] 20:22:31 INFO - [task 2017-09-05T20:22:31.624231Z] 20:22:31 INFO - GECKO(1641) | #86: _start

This also seems to cause an intermittent failure in browser_startup.js https://treeherder.mozilla.org/logviewer.html#?job_id=128675876&repo=autoland https://treeherder.mozilla.org/logviewer.html#?job_id=128668413&repo=autoland This was originally attributed to bug 1392081, but it looked unlikely considered my changes only affect Places views that are not used by browser_startup.js I retriggered the b-c tests multiple times (see bc11 on linux32-stylo-debug) https://treeherder.mozilla.org/#/jobs?repo=autoland&revision=cf5b68506bef58600c4e8ec1654102fd36bf0c52&selectedJob=128644629 https://treeherder.mozilla.org/#/jobs?repo=autoland&revision=5d320d8864e90aa9684462251fee5b60f055ea9b&selectedJob=128861282 My theory is that by delaying about:newtab, something else is happening sooner. A possibility could be the Star button (TBV), since even if it's hidden, its onLocationChange handler will still be invoked and that will initialize Places. http://searchfox.org/mozilla-central/rev/4d8e389498a08668cce9ebf6232cc96be178c3e4/browser/base/content/browser-places.js#1814 Another possibility is that newtab itself somehow anticipates work, but from what Florian said this patch should only delay things...

(In reply to Marco Bonardo [::mak] from comment #24) > My theory is that by delaying about:newtab, something else is happening > sooner. It's possible that it's simpler than that - the patch in here makes loading about:newtab less aggressive, but also makes it so that we attempt to preload one after first paint after 1 second of idle time and at least 40ms of idle callback budget. Digging into this...

I think I've got a handle on the test failures. Try push here: https://treeherder.mozilla.org/#/jobs?repo=try&revision=530a8e5542d5a09ca1215c1a4579d19dc4a8c654

I think I've found a way to make this work.

This is needed to avoid some intermittent shutdown leaks being reported from automation that patches later in this series unhappily seem to trigger quite often. MozReview-Commit-ID: 2HVOILBXWP

Pushed by gijskruitbosch@gmail.com: https://hg.mozilla.org/integration/autoland/rev/976afd1adf84 move new tab preload browser tracking into a separate module, r=dthayer https://hg.mozilla.org/integration/autoland/rev/a3d1302b06c0 allow using the preloaded new tab page in private windows, too, r=dthayer https://hg.mozilla.org/integration/autoland/rev/af8bce2330e9 create preloaded newtab browser from an idle task, only in top window(s), r=dthayer

Backout by shindli@mozilla.com: https://hg.mozilla.org/integration/autoland/rev/dde899c9bfb9 Backed out 3 changesets for a11y failures in accessible/tests/mochitest/relations/test_tabbrowser.xul CLOSED TREE

Pushed by gijskruitbosch@gmail.com: https://hg.mozilla.org/integration/autoland/rev/d37ddb68b340 move new tab preload browser tracking into a separate module, r=dthayer https://hg.mozilla.org/integration/autoland/rev/ef5f455b726f allow using the preloaded new tab page in private windows, too, r=dthayer https://hg.mozilla.org/integration/autoland/rev/26973fbde8f4 create preloaded newtab browser from an idle task, only in top window(s), r=dthayer