12,000 instances of "WARNING: [nsFrameLoader] ReallyStartLoadingInternal tried but couldn't show remote browser." emitted from none during linux64 debug testing

RESOLVED FIXED in Firefox 59

Status

()

P3
normal
RESOLVED FIXED
2 years ago
a year ago

People

(Reporter: erahm, Assigned: erahm)

Tracking

(Blocks: 1 bug)

Trunk
mozilla59
Points:
---
Dependency tree / graph

Firefox Tracking Flags

(firefox59 fixed)

Details

Attachments

(1 attachment)

> 10075 WARNING: [nsFrameLoader] ReallyStartLoadingInternal tried but couldn't show remote browser.

This warning [1] shows up in the following test suites:

>   1228 - test-linux64/debug-web-platform-tests-e10s-8 wpt8
>    961 - test-linux64/debug-web-platform-tests-e10s-5 wpt5
>    958 - test-linux64/debug-web-platform-tests-e10s-9 wpt9
>    889 - test-linux64/debug-web-platform-tests-e10s-10 wpt10
>    882 - test-linux64/debug-web-platform-tests-e10s-11 wpt11
>    799 - test-linux64/debug-web-platform-tests-e10s-3 wpt3
>    641 - test-linux64/debug-web-platform-tests-e10s-2 wpt2
>    624 - test-linux64/debug-web-platform-tests-e10s-6 wpt6
>    556 - test-linux64/debug-web-platform-tests-e10s-1 wpt1
>    513 - test-linux64/debug-web-platform-tests-e10s-4 wpt4
>    474 - test-linux64/debug-web-platform-tests-e10s-12 wpt12
>    445 - test-linux64/debug-web-platform-tests-e10s-7 wpt7
>    140 - test-linux64/debug-mochitest-e10s-3 3
>    135 - test-linux64/debug-mochitest-e10s-10 10
>    124 - test-linux64/debug-mochitest-e10s-1 1
>    108 - test-linux64/debug-mochitest-e10s-5 5
>     69 - test-linux64/debug-mochitest-2 2
>     55 - test-linux64/debug-mochitest-e10s-8 8
>     51 - test-linux64/debug-mochitest-e10s-9 9
>     41 - test-linux64/debug-mochitest-browser-chrome-e10s-2 bc2
>     40 - test-linux64/debug-mochitest-e10s-2 2
>     39 - test-linux64/debug-web-platform-tests-reftests-e10s Wr
>     38 - test-linux64/debug-mochitest-e10s-6 6
>     38 - test-linux64/debug-mochitest-devtools-chrome-e10s-7 dt7
>     30 - test-linux64/debug-mochitest-browser-chrome-e10s-14 bc14
>     28 - test-linux64/debug-mochitest-browser-chrome-e10s-16 bc16
>     24 - test-linux64/debug-mochitest-e10s-7 7
>     17 - test-linux64/debug-mochitest-clipboard-e10s cl
>     17 - test-linux64/debug-mochitest-4 4
>     13 - test-linux64/debug-mochitest-media-e10s-2 mda2
>     13 - test-linux64/debug-mochitest-browser-chrome-e10s-9 bc9
>     12 - test-linux64/debug-mochitest-browser-chrome-e10s-5 bc5
>     10 - test-linux64/debug-mochitest-chrome-1 c1
>     10 - test-linux64/debug-mochitest-browser-chrome-e10s-13 bc13
>      8 - test-linux64/debug-mochitest-browser-chrome-e10s-15 bc15
>      8 - test-linux64/debug-mochitest-browser-chrome-e10s-3 bc3
>      6 - test-linux64/debug-mochitest-browser-chrome-e10s-7 bc7
>      5 - test-linux64/debug-mochitest-browser-chrome-e10s-11 bc11
>      3 - test-linux64/debug-mochitest-3 3
>      3 - test-linux64/debug-crashtest-e10s C
>      3 - test-linux64/debug-mochitest-8 8
>      3 - test-linux64/debug-mochitest-10 10
>      2 - test-linux64/debug-mochitest-e10s-4 4
>      2 - test-linux64/debug-mochitest-browser-chrome-e10s-4 bc4
>      2 - test-linux64/debug-mochitest-media-e10s-1 mda1
>      1 - test-linux64/debug-web-platform-tests-wdspec-e10s Wd
>      1 - test-linux64/debug-mochitest-1 1
>      1 - test-linux64/debug-mochitest-a11y a11y
>      1 - test-linux64/debug-mochitest-clipboard cl
>      1 - test-linux64/debug-mochitest-browser-chrome-e10s-8 bc8
>      1 - test-linux64/debug-mochitest-media-e10s-3 mda3
>      1 - test-linux64/debug-firefox-ui-functional-local-e10s en-US
>      1 - test-linux64/debug-web-platform-tests-wdspec Wd

It shows up in 9168 tests. A few of the most prevalent:

>     48 - [e10s] dom/tests/mochitest/bugs/test_bug260264.html
>     21 - [e10s] /url/failure.html
>     20 - [e10s] /html/browsers/the-window-object/apis-for-creating-and-navigating-browsing-contexts-by-name/open-features-tokenization-noopener.html
>     19 - [e10s] /html/browsers/the-window-object/apis-for-creating-and-navigating-browsing-contexts-by-name/open-features-tokenization-width-height.html
>     18 - [e10s] dom/html/test/test_fullscreen-api.html
>     18 - [e10s] dom/tests/mochitest/pointerlock/test_pointerlock-api.html
>     17 - [e10s] /html/browsers/the-window-object/apis-for-creating-and-navigating-browsing-contexts-by-name/open-features-tokenization-top-left.html
>     16 - [e10s] dom/events/test/pointerevents/test_touch_action.html
>     16 - [e10s] /html/browsers/the-window-object/apis-for-creating-and-navigating-browsing-contexts-by-name/open-features-non-integer-width.html
>     16 - [e10s] /html/browsers/the-window-object/apis-for-creating-and-navigating-browsing-contexts-by-name/open-features-non-integer-height.html

[1] https://hg.mozilla.org/mozilla-central/annotate/cc65f9233e5b/none#l0
Bisection points to the following range:

https://hg.mozilla.org/integration/mozilla-inbound/pushloghtml?fromchange=f77767c9f2bcc78addef282be397ac869cb3dca8&tochange=6e6ac52493bacffec99472488c6c7395676a9b76

The most likely culprit is bug 1353060, Kris can you take a look?
Blocks: 1353060
Flags: needinfo?(kmaglione+bmo)
Thanks, this should help me track down bug 1362378.
Flags: needinfo?(kmaglione+bmo)
Depends on: 1362378
as this blocks a P1 bug 1353060, mirroring the priority here.
Priority: -- → P1
Kris this warning is still around, it looks like bug 1362378 didn't fix it. Can you take another look?
Flags: needinfo?(kmaglione+bmo)
Priority: P1 → P3
This continues to be a top warning.
Summary: 10,100 instances of "WARNING: [nsFrameLoader] ReallyStartLoadingInternal tried but couldn't show remote browser." emitted from none during linux64 debug testing → 12,000 instances of "WARNING: [nsFrameLoader] ReallyStartLoadingInternal tried but couldn't show remote browser." emitted from none during linux64 debug testing
This is the #2 most verbose warning during testing.
We should probably just remove the warning. At this point, it's expected in some situations, and we just retry later if it fails.
Assignee: nobody → kmaglione+bmo
Flags: needinfo?(kmaglione+bmo)
Example stack I'm seeing from |./mach test dom/tests/browser/browser_noopener.js|

C++ stack:

> GECKO(2187) | #01: ~RefPtr (/var/dev/erahm/mozilla-unified/obj-x86_64-pc-linux-gnu-clang/dist/include/mozilla/RefPtr.h:78)
> GECKO(2187) | #02: nsDocument::EndUpdate(unsigned int) (/var/dev/erahm/mozilla-unified/dom/base/nsDocument.cpp:5428)
> GECKO(2187) | #03: mozilla::dom::XULDocument::EndUpdate(unsigned int) (/var/dev/erahm/mozilla-unified/dom/xul/XULDocument.cpp:3196)
> GECKO(2187) | #04: ~nsCOMPtr_base (/var/dev/erahm/mozilla-unified/obj-x86_64-pc-linux-gnu-clang/dist/include/nsCOMPtr.h:313)
> GECKO(2187) | #05: nsINode::InsertBefore(nsINode&, nsINode*, mozilla::ErrorResult&) (/var/dev/erahm/mozilla-unified/dom/base/nsINode.h:1838)
> GECKO(2187) | #06: mozilla::dom::GenericBindingMethod(JSContext*, unsigned int, JS::Value*) (/var/dev/erahm/mozilla-unified/dom/bindings/BindingUtils.cpp:3040 (discriminator 2))
> GECKO(2187) | #07: js::CallJSNative(JSContext*, bool (*)(JSContext*, unsigned int, JS::Value*), JS::CallArgs const&) (/var/dev/erahm/mozilla-unified/js/src/jscntxtinlines.h:292)
> GECKO(2187) | #08: Interpret(JSContext*, js::RunState&) (/var/dev/erahm/mozilla-unified/js/src/vm/Interpreter.cpp:3061)
> GECKO(2187) | #09: js::RunScript(JSContext*, js::RunState&) (/var/dev/erahm/mozilla-unified/js/src/vm/Interpreter.cpp:422)
> GECKO(2187) | #10: js::InternalCallOrConstruct(JSContext*, JS::CallArgs const&, js::MaybeConstruct) (/var/dev/erahm/mozilla-unified/js/src/vm/Interpreter.cpp:494)
> GECKO(2187) | #11: Interpret(JSContext*, js::RunState&) (/var/dev/erahm/mozilla-unified/js/src/vm/Interpreter.cpp:3061)
> GECKO(2187) | #12: js::RunScript(JSContext*, js::RunState&) (/var/dev/erahm/mozilla-unified/js/src/vm/Interpreter.cpp:422)
> GECKO(2187) | #13: js::InternalCallOrConstruct(JSContext*, JS::CallArgs const&, js::MaybeConstruct) (/var/dev/erahm/mozilla-unified/js/src/vm/Interpreter.cpp:494)
> GECKO(2187) | #14: js::Call(JSContext*, JS::Handle<JS::Value>, JS::Handle<JS::Value>, js::AnyInvokeArgs const&, JS::MutableHandle<JS::Value>) (/var/dev/erahm/mozilla-unified/js/src/vm/Interpreter.cpp:540)
> GECKO(2187) | #15: JS::Call(JSContext*, JS::Handle<JS::Value>, JS::Handle<JS::Value>, JS::HandleValueArray const&, JS::MutableHandle<JS::Value>) (/var/dev/erahm/mozilla-unified/js/src/jsapi.cpp:3032)
> GECKO(2187) | #16: mozilla::dom::EventListener::HandleEvent(JSContext*, JS::Handle<JS::Value>, mozilla::dom::Event&, mozilla::ErrorResult&) (/var/dev/erahm/mozilla-unified/obj-x86_64-pc-linux-gnu-clang/dom/bindings/EventListenerBinding.cpp:47)
> GECKO(2187) | #17: void mozilla::dom::EventListener::HandleEvent<mozilla::dom::EventTarget*>(mozilla::dom::EventTarget* const&, mozilla::dom::Event&, mozilla::ErrorResult&, char const*, mozilla::dom::CallbackObject::ExceptionHandling, JSCompartment*) (/var/dev/erahm/mozilla-unified/obj-x86_64-pc-linux-gnu-clang/dist/include/mozilla/dom/EventListenerBinding.h:65 (discriminator 2))
> GECKO(2187) | #18: mozilla::EventListenerManager::HandleEventInternal(nsPresContext*, mozilla::WidgetEvent*, nsIDOMEvent**, mozilla::dom::EventTarget*, nsEventStatus*) (/var/dev/erahm/mozilla-unified/dom/events/EventListenerManager.cpp:1296)
> GECKO(2187) | #19: mozilla::EventTargetChainItem::HandleEventTargetChain(nsTArray<mozilla::EventTargetChainItem>&, mozilla::EventChainPostVisitor&, mozilla::EventDispatchingCallback*, mozilla::ELMCreationDetector&) (/var/dev/erahm/mozilla-unified/dom/events/EventDispatcher.cpp:486)
> GECKO(2187) | #20: mozilla::EventDispatcher::Dispatch(nsISupports*, nsPresContext*, mozilla::WidgetEvent*, nsIDOMEvent*, nsEventStatus*, mozilla::EventDispatchingCallback*, nsTArray<mozilla::dom::EventTarget*>*) (/var/dev/erahm/mozilla-unified/dom/events/EventDispatcher.cpp:829)
> GECKO(2187) | #21: mozilla::EventDispatcher::DispatchDOMEvent(nsISupports*, mozilla::WidgetEvent*, nsIDOMEvent*, nsPresContext*, nsEventStatus*) (crtstuff.c:?)
> GECKO(2187) | #22: nsINode::DispatchEvent(nsIDOMEvent*, bool*) (/var/dev/erahm/mozilla-unified/dom/base/nsINode.cpp:1357)
> GECKO(2187) | #23: nsContentUtils::DispatchEvent(nsIDocument*, nsISupports*, nsTSubstring<char16_t> const&, bool, bool, bool, bool*, bool) (/var/dev/erahm/mozilla-unified/dom/base/nsContentUtils.cpp:4607 (discriminator 3))
> GECKO(2187) | #24: nsContentUtils::DispatchTrustedEvent(nsIDocument*, nsISupports*, nsTSubstring<char16_t> const&, bool, bool, bool*) (/var/dev/erahm/mozilla-unified/dom/base/nsContentUtils.cpp:4575)
> GECKO(2187) | #25: nsDocument::DispatchContentLoadedEvents() (crtstuff.c:?)
> GECKO(2187) | #26: mozilla::dom::XULDocument::DoneWalking() (/var/dev/erahm/mozilla-unified/dom/xul/XULDocument.cpp:3045)
> GECKO(2187) | #27: non-virtual thunk to mozilla::dom::XULDocument::StyleSheetLoaded(mozilla::StyleSheet*, bool, nsresult) (crtstuff.c:?)
> GECKO(2187) | #28: mozilla::css::Loader::SheetComplete(mozilla::css::SheetLoadData*, nsresult) (/var/dev/erahm/mozilla-unified/layout/style/Loader.cpp:1709 (discriminator 2))
> GECKO(2187) | #29: mozilla::css::Loader::HandleLoadEvent(mozilla::css::SheetLoadData*) (/var/dev/erahm/mozilla-unified/layout/style/Loader.cpp:2431)
> GECKO(2187) | #30: mozilla::Maybe<mozilla::AutoTimeDurationHelper>::isSome() const (/var/dev/erahm/mozilla-unified/obj-x86_64-pc-linux-gnu-clang/dist/include/mozilla/Maybe.h:224)
> GECKO(2187) | #31: NS_ProcessNextEvent(nsIThread*, bool) (/var/dev/erahm/mozilla-unified/xpcom/threads/nsThreadUtils.cpp:513)
> GECKO(2187) | #32: bool mozilla::SpinEventLoopUntil<(mozilla::ProcessFailureBehavior)1, nsXULWindow::CreateNewContentWindow(int, nsITabParent*, mozIDOMWindowProxy*, unsigned long, nsIXULWindow**)::$_1>(nsXULWindow::CreateNewContentWindow(int, nsITabParent*, mozIDOMWindowProxy*, unsigned long, nsIXULWindow**)::$_1&&, nsIThread*) (/var/dev/erahm/mozilla-unified/obj-x86_64-pc-linux-gnu-clang/dist/include/nsThreadUtils.h:323)
> GECKO(2187) | #33: nsAppStartup::CreateChromeWindow2(nsIWebBrowserChrome*, unsigned int, nsITabParent*, mozIDOMWindowProxy*, unsigned long, bool*, nsIWebBrowserChrome**) (/var/dev/erahm/mozilla-unified/toolkit/components/startup/nsAppStartup.cpp:661 (discriminator 1))
> GECKO(2187) | #34: nsWindowWatcher::CreateChromeWindow(nsTSubstring<char> const&, nsIWebBrowserChrome*, unsigned int, nsITabParent*, mozIDOMWindowProxy*, unsigned long, nsIWebBrowserChrome**) (/var/dev/erahm/mozilla-unified/toolkit/components/windowwatcher/nsWindowWatcher.cpp:496 (discriminator 1))
> GECKO(2187) | #35: nsWindowWatcher::OpenWindowWithTabParent(nsITabParent*, nsTSubstring<char> const&, bool, float, unsigned long, bool, nsITabParent**) (/var/dev/erahm/mozilla-unified/toolkit/components/windowwatcher/nsWindowWatcher.cpp:613 (discriminator 1))
> GECKO(2187) | #36: mozilla::dom::ContentParent::CommonCreateWindow(mozilla::dom::PBrowserParent*, bool, unsigned int const&, bool const&, bool const&, bool const&, nsIURI*, nsTString<char> const&, nsTString<char> const&, float const&, unsigned long, nsTString<char16_t> const&, nsresult&, nsCOMPtr<nsITabParent>&, bool*, nsIPrincipal*, bool) (/var/dev/erahm/mozilla-unified/dom/ipc/ContentParent.cpp:4614 (discriminator 2))
> GECKO(2187) | #37: mozilla::dom::ContentParent::RecvCreateWindow(mozilla::dom::PBrowserParent*, mozilla::dom::PBrowserParent*, mozilla::layout::PRenderFrameParent*, unsigned int const&, bool const&, bool const&, bool const&, mozilla::ipc::OptionalURIParams const&, nsTString<char> const&, nsTString<char> const&, float const&, IPC::Principal const&, std::function<void (mozilla::dom::CreatedWindowInfo const&)>&&) (/var/dev/erahm/mozilla-unified/dom/ipc/ContentParent.cpp:4717)
> GECKO(2187) | #38: mozilla::dom::PContentParent::OnMessageReceived(IPC::Message const&) (/var/dev/erahm/mozilla-unified/obj-x86_64-pc-linux-gnu-clang/ipc/ipdl/PContentParent.cpp:6044 (discriminator 13))
> GECKO(2187) | #39: ~AutoSetValue (/var/dev/erahm/mozilla-unified/obj-x86_64-pc-linux-gnu-clang/dist/include/mozilla/ipc/MessageChannel.h:635)
> GECKO(2187) | #40: mozilla::ipc::MessageChannel::DispatchMessage(IPC::Message&&) (/var/dev/erahm/mozilla-unified/ipc/glue/MessageChannel.cpp:2049)
> GECKO(2187) | #41: mozilla::OffTheBooksMutex::Unlock() (/var/dev/erahm/mozilla-unified/obj-x86_64-pc-linux-gnu-clang/dist/include/mozilla/Mutex.h:70)
> GECKO(2187) | #42: mozilla::Maybe<mozilla::AutoTimeDurationHelper>::isSome() const (/var/dev/erahm/mozilla-unified/obj-x86_64-pc-linux-gnu-clang/dist/include/mozilla/Maybe.h:224)
> GECKO(2187) | #43: NS_ProcessNextEvent(nsIThread*, bool) (/var/dev/erahm/mozilla-unified/xpcom/threads/nsThreadUtils.cpp:513)
> GECKO(2187) | #44: mozilla::ipc::MessagePump::Run(base::MessagePump::Delegate*) (/var/dev/erahm/mozilla-unified/ipc/glue/MessagePump.cpp:97)
> GECKO(2187) | #45: ~AutoRunState (/var/dev/erahm/mozilla-unified/ipc/chromium/src/base/message_loop.cc:599)
> GECKO(2187) | #46: nsBaseAppShell::Run() (/var/dev/erahm/mozilla-unified/widget/nsBaseAppShell.cpp:160)
> GECKO(2187) | #47: nsAppStartup::Run() (crtstuff.c:?)
> GECKO(2187) | #48: XREMain::XRE_mainRun() (/var/dev/erahm/mozilla-unified/toolkit/xre/nsAppRunner.cpp:4675 (discriminator 1))
> GECKO(2187) | #49: XREMain::XRE_main(int, char**, mozilla::BootstrapConfig const&) (/var/dev/erahm/mozilla-unified/toolkit/xre/nsAppRunner.cpp:4837)
> GECKO(2187) | #50: XRE_main(int, char**, mozilla::BootstrapConfig const&) (/var/dev/erahm/mozilla-unified/toolkit/xre/nsAppRunner.cpp:4932)
> GECKO(2187) | #51: main (/var/dev/erahm/mozilla-unified/browser/app/nsBrowserApp.cpp:?)
> GECKO(2187) | #52: __libc_start_main (/build/glibc-bfm8X4/glibc-2.23/csu/../csu/libc-start.c:325)
> GECKO(2187) | #53: _start (/var/dev/erahm/mozilla-unified/obj-x86_64-pc-linux-gnu-clang/dist/bin/firefox)
> GECKO(2187) | #54: ??? (???:???)

JS Stack:

> GECKO(2187) | 0 updateBrowserRemoteness() ["chrome://browser/content/tabbrowser.xml":2036]
> GECKO(2187) | 1 onDOMContentLoaded() ["chrome://browser/content/browser.js":1225]
> GECKO(2187) | 2 anonymous() ["chrome://browser/content/browser.js":1173]
Created attachment 8937864 [details] [diff] [review]
Remove overly verbose warning from ReallyStartLoadingInternal

This removes the extremely verbose "[nsFrameLoader] ReallyStartLoadingInternal
tried but couldn't show remote browser" warning. We already return NS_OK in
this case, so the behavior is expected.

Boris, can you take a look at this or forward to the right person? kmag has
indicated this is expected behavior, there's a stack in comment 8 if you're
interested.
Attachment #8937864 - Flags: review?(bzbarsky)
Assignee: kmaglione+bmo → erahm
Status: NEW → ASSIGNED
Attachment #8937864 - Flags: review?(bzbarsky) → review?(kmaglione+bmo)
Comment on attachment 8937864 [details] [diff] [review]
Remove overly verbose warning from ReallyStartLoadingInternal

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

::: dom/base/nsFrameLoader.cpp
@@ +900,5 @@
>      // FIXME get error codes from child
>      mRemoteBrowser->LoadURL(mURIToLoad);
>  
> +    if (!mRemoteBrowserShown) {
> +      Unused << ShowRemoteFrame(ScreenIntSize(0, 0));

Please add a comment explaining that this is allowed to fail if it's too early to show the frame, and will be retried later.
Attachment #8937864 - Flags: review?(kmaglione+bmo) → review+

Comment 11

a year ago
Pushed by erahm@mozilla.com:
https://hg.mozilla.org/integration/mozilla-inbound/rev/316f20b5e79b
Remove overly verbose warning from ReallyStartLoadingInternal. r=kmag

Comment 12

a year ago
bugherder
https://hg.mozilla.org/mozilla-central/rev/316f20b5e79b
Status: ASSIGNED → RESOLVED
Last Resolved: a year ago
status-firefox59: --- → fixed
Resolution: --- → FIXED
Target Milestone: --- → mozilla59
You need to log in before you can comment on or make changes to this bug.