1462789 - Permanent false-positive PID 6105 | Assertion failure: GetReadyStateEnum() == nsIDocument::READYSTATE_LOADING (Bad readyState), at /builds/worker/workspace/build/src/dom/html/MediaDocument.cpp:197

Status: RESOLVED FIXED

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

Description

[Treeherder Bug Filer]

Filed by: toros [at] mozilla.com

https://treeherder.mozilla.org/logviewer.html#?job_id=179189932&repo=mozilla-inbound

https://queue.taskcluster.net/v1/task/Agd-hd6PQoOFPXQTyqc63g/runs/0/artifacts/public/logs/live_backing.log

[task 2018-05-18T14:58:15.145Z] 14:58:15     INFO - TEST-START | /html/dom/dynamic-markup-insertion/document-write/contentType.window.html
[task 2018-05-18T14:58:15.147Z] 14:58:15     INFO - PID 6105 | [Parent 6105, Cache2 I/O] WARNING: 'NS_FAILED(aResult)', file /builds/worker/workspace/build/src/netwerk/cache2/CacheFile.cpp, line 686
[task 2018-05-18T14:58:15.284Z] 14:58:15     INFO - PID 6105 | ++DOCSHELL 0x7fb7c96d4800 == 2 [pid = 6168] [id = {1756363f-e49f-4d17-8f47-22c494d6b5c9}]
[task 2018-05-18T14:58:15.285Z] 14:58:15     INFO - PID 6105 | ++DOMWINDOW == 5 (0x7fb7c9651400) [pid = 6168] [serial = 5] [outer = (nil)]
[task 2018-05-18T14:58:15.387Z] 14:58:15     INFO - PID 6105 | ++DOMWINDOW == 6 (0x7fb7d2505000) [pid = 6168] [serial = 6] [outer = 0x7fb7c9651400]
[task 2018-05-18T14:58:15.525Z] 14:58:15     INFO - PID 6105 | ++DOMWINDOW == 7 (0x7fb7d2504c00) [pid = 6168] [serial = 7] [outer = 0x7fb7c9651400]
[task 2018-05-18T14:58:15.695Z] 14:58:15     INFO - PID 6105 | ++DOCSHELL 0x7fb7c96db800 == 3 [pid = 6168] [id = {a0ba1a5c-2f6f-4fe0-b9b8-7a21233cd166}]
[task 2018-05-18T14:58:15.695Z] 14:58:15     INFO - PID 6105 | ++DOMWINDOW == 8 (0x7fb7c9652400) [pid = 6168] [serial = 8] [outer = (nil)]
[task 2018-05-18T14:58:15.735Z] 14:58:15     INFO - PID 6105 | ++DOMWINDOW == 9 (0x7fb7d250e400) [pid = 6168] [serial = 9] [outer = 0x7fb7c9652400]
[task 2018-05-18T14:58:15.881Z] 14:58:15     INFO - PID 6105 | ++DOMWINDOW == 10 (0x7fb7cf181c00) [pid = 6168] [serial = 10] [outer = 0x7fb7c9652400]
[task 2018-05-18T14:58:16.080Z] 14:58:16     INFO - PID 6105 | ++DOCSHELL 0x7fb7c96ec000 == 4 [pid = 6168] [id = {2cde92dc-1365-4bca-b91c-c1bccd252d25}]
[task 2018-05-18T14:58:16.080Z] 14:58:16     INFO - PID 6105 | ++DOMWINDOW == 11 (0x7fb7cd4c4c00) [pid = 6168] [serial = 11] [outer = (nil)]
[task 2018-05-18T14:58:16.080Z] 14:58:16     INFO - PID 6105 | ++DOMWINDOW == 12 (0x7fb7cf180c00) [pid = 6168] [serial = 12] [outer = 0x7fb7cd4c4c00]
[task 2018-05-18T14:58:16.117Z] 14:58:16     INFO - PID 6105 | ++DOCSHELL 0x7fb7c96ee800 == 5 [pid = 6168] [id = {51c658ff-d773-451b-88bd-98190f8fbbd5}]
[task 2018-05-18T14:58:16.117Z] 14:58:16     INFO - PID 6105 | ++DOMWINDOW == 13 (0x7fb7c9654400) [pid = 6168] [serial = 13] [outer = (nil)]
[task 2018-05-18T14:58:16.117Z] 14:58:16     INFO - PID 6105 | ++DOMWINDOW == 14 (0x7fb7cf184800) [pid = 6168] [serial = 14] [outer = 0x7fb7c9654400]
[task 2018-05-18T14:58:16.140Z] 14:58:16     INFO - PID 6105 | ++DOCSHELL 0x7fb7c96f1000 == 6 [pid = 6168] [id = {06c8853f-9a11-4b66-b7d3-eb85c4e18d6e}]
[task 2018-05-18T14:58:16.140Z] 14:58:16     INFO - PID 6105 | ++DOMWINDOW == 15 (0x7fb7e8a98e00) [pid = 6168] [serial = 15] [outer = (nil)]
[task 2018-05-18T14:58:16.144Z] 14:58:16     INFO - PID 6105 | ++DOMWINDOW == 16 (0x7fb7cf185800) [pid = 6168] [serial = 16] [outer = 0x7fb7e8a98e00]
[task 2018-05-18T14:58:16.170Z] 14:58:16     INFO - PID 6105 | ++DOCSHELL 0x7fb7cf11b000 == 7 [pid = 6168] [id = {360bc009-6c61-46e1-9c36-30195e88a76e}]
[task 2018-05-18T14:58:16.170Z] 14:58:16     INFO - PID 6105 | ++DOMWINDOW == 17 (0x7fb7e8a9b200) [pid = 6168] [serial = 17] [outer = (nil)]
[task 2018-05-18T14:58:16.172Z] 14:58:16     INFO - PID 6105 | ++DOMWINDOW == 18 (0x7fb7cf186400) [pid = 6168] [serial = 18] [outer = 0x7fb7e8a9b200]
[task 2018-05-18T14:58:16.235Z] 14:58:16     INFO - PID 6105 | [Child 6168, Main Thread] WARNING: '!aWindow', file /builds/worker/workspace/build/src/dom/audiochannel/AudioChannelAgent.cpp, line 137
[task 2018-05-18T14:58:16.235Z] 14:58:16     INFO - PID 6105 | [Child 6168, Main Thread] WARNING: 'NS_FAILED(rv)', file /builds/worker/workspace/build/src/dom/html/HTMLMediaElement.cpp, line 903
[task 2018-05-18T14:58:16.235Z] 14:58:16     INFO - PID 6105 | [Child 6168, Main Thread] WARNING: '!aWindow', file /builds/worker/workspace/build/src/dom/audiochannel/AudioChannelAgent.cpp, line 137
[task 2018-05-18T14:58:16.235Z] 14:58:16     INFO - PID 6105 | [Child 6168, Main Thread] WARNING: 'NS_FAILED(rv)', file /builds/worker/workspace/build/src/dom/html/HTMLMediaElement.cpp, line 903
[task 2018-05-18T14:58:16.235Z] 14:58:16     INFO - PID 6105 | [Child 6168, Main Thread] WARNING: '!aWindow', file /builds/worker/workspace/build/src/dom/audiochannel/AudioChannelAgent.cpp, line 137
[task 2018-05-18T14:58:16.235Z] 14:58:16     INFO - PID 6105 | [Child 6168, Main Thread] WARNING: 'NS_FAILED(rv)', file /builds/worker/workspace/build/src/dom/html/HTMLMediaElement.cpp, line 903
[task 2018-05-18T14:58:16.236Z] 14:58:16     INFO - PID 6105 | [Child 6168, Main Thread] WARNING: '!aWindow', file /builds/worker/workspace/build/src/dom/audiochannel/AudioChannelAgent.cpp, line 137
[task 2018-05-18T14:58:16.238Z] 14:58:16     INFO - PID 6105 | [Child 6168, Main Thread] WARNING: 'NS_FAILED(rv)', file /builds/worker/workspace/build/src/dom/html/HTMLMediaElement.cpp, line 903
[task 2018-05-18T14:58:16.239Z] 14:58:16     INFO - PID 6105 | [Child 6168, Main Thread] WARNING: '!aWindow', file /builds/worker/workspace/build/src/dom/audiochannel/AudioChannelAgent.cpp, line 137
[task 2018-05-18T14:58:16.240Z] 14:58:16     INFO - PID 6105 | [Child 6168, Main Thread] WARNING: 'NS_FAILED(rv)', file /builds/worker/workspace/build/src/dom/html/HTMLMediaElement.cpp, line 903
[task 2018-05-18T14:58:16.241Z] 14:58:16     INFO - PID 6105 | [Child 6168, Main Thread] WARNING: '!aWindow', file /builds/worker/workspace/build/src/dom/audiochannel/AudioChannelAgent.cpp, line 137
[task 2018-05-18T14:58:16.242Z] 14:58:16     INFO - PID 6105 | [Child 6168, Main Thread] WARNING: 'NS_FAILED(rv)', file /builds/worker/workspace/build/src/dom/html/HTMLMediaElement.cpp, line 903
[task 2018-05-18T14:58:16.245Z] 14:58:16     INFO - PID 6105 | [Child 6168, Main Thread] WARNING: '!aWindow', file /builds/worker/workspace/build/src/dom/audiochannel/AudioChannelAgent.cpp, line 137
[task 2018-05-18T14:58:16.246Z] 14:58:16     INFO - PID 6105 | [Child 6168, Main Thread] WARNING: 'NS_FAILED(rv)', file /builds/worker/workspace/build/src/dom/html/HTMLMediaElement.cpp, line 903
[task 2018-05-18T14:58:16.425Z] 14:58:16     INFO - PID 6105 | [Child 6168, Main Thread] WARNING: Subsequent listeners are not retargetable: file /builds/worker/workspace/build/src/netwerk/protocol/http/HttpChannelChild.cpp, line 3587
[task 2018-05-18T14:58:16.481Z] 14:58:16     INFO - PID 6105 | [Child 6168, Main Thread] WARNING: Subsequent listeners are not retargetable: file /builds/worker/workspace/build/src/netwerk/protocol/http/HttpChannelChild.cpp, line 3587
[task 2018-05-18T14:58:17.305Z] 14:58:17     INFO - PID 6105 | ++DOMWINDOW == 19 (0x7fb7bdf42c00) [pid = 6168] [serial = 19] [outer = 0x7fb7e8a9b200]
[task 2018-05-18T14:58:17.450Z] 14:58:17     INFO - PID 6105 | ++DOMWINDOW == 20 (0x7fb7bdf47800) [pid = 6168] [serial = 20] [outer = 0x7fb7cd4c4c00]
[task 2018-05-18T14:58:17.455Z] 14:58:17     INFO - PID 6105 | Assertion failure: GetReadyStateEnum() == nsIDocument::READYSTATE_LOADING (Bad readyState), at /builds/worker/workspace/build/src/dom/html/MediaDocument.cpp:197
[task 2018-05-18T14:58:17.791Z] 14:58:17     INFO - PID 6105 | #01: mozilla::dom::VideoDocument::SetScriptGlobalObject(nsIScriptGlobalObject*) (/builds/worker/workspace/build/application/firefox/libxul.so)
[task 2018-05-18T14:58:17.799Z] 14:58:17     INFO - PID 6105 | #02: nsGlobalWindowOuter::SetNewDocument(nsIDocument*, nsISupports*, bool) (/builds/worker/workspace/build/application/firefox/libxul.so)
[task 2018-05-18T14:58:17.803Z] 14:58:17     INFO - PID 6105 | #03: nsHTMLDocument::Open(JSContext*, mozilla::dom::Optional<nsTSubstring<char16_t> > const&, nsTSubstring<char16_t> const&, mozilla::ErrorResult&) (/builds/worker/workspace/build/application/firefox/libxul.so)
[task 2018-05-18T14:58:17.811Z] 14:58:17     INFO - PID 6105 | #04: nsHTMLDocument::WriteCommon(JSContext*, nsTSubstring<char16_t> const&, bool, mozilla::ErrorResult&) (/builds/worker/workspace/build/application/firefox/libxul.so)
[task 2018-05-18T14:58:17.815Z] 14:58:17     INFO - PID 6105 | #05: nsHTMLDocument::WriteCommon(JSContext*, mozilla::dom::Sequence<nsTString<char16_t> > const&, bool, mozilla::ErrorResult&) (/builds/worker/workspace/build/application/firefox/libxul.so)
[task 2018-05-18T14:58:17.823Z] 14:58:17     INFO - PID 6105 | #06: mozilla::dom::HTMLDocumentBinding::write(JSContext*, JS::Handle<JSObject*>, nsHTMLDocument*, JSJitMethodCallArgs const&) (/builds/worker/workspace/build/application/firefox/libxul.so)
[task 2018-05-18T14:58:17.831Z] 14:58:17     INFO - PID 6105 | #07: bool mozilla::dom::binding_detail::GenericMethod<mozilla::dom::binding_detail::NormalThisPolicy, mozilla::dom::binding_detail::ThrowExceptions>(JSContext*, unsigned int, JS::Value*) (/builds/worker/workspace/build/application/firefox/libxul.so)
[task 2018-05-18T14:58:17.835Z] 14:58:17     INFO - PID 6105 | #08: js::CallJSNative(JSContext*, bool (*)(JSContext*, unsigned int, JS::Value*), JS::CallArgs const&) (/builds/worker/workspace/build/application/firefox/libxul.so)
[task 2018-05-18T14:58:17.843Z] 14:58:17     INFO - PID 6105 | #09: js::InternalCallOrConstruct(JSContext*, JS::CallArgs const&, js::MaybeConstruct) (/builds/worker/workspace/build/application/firefox/libxul.so)
[task 2018-05-18T14:58:17.847Z] 14:58:17     INFO - PID 6105 | #10: InternalCall(JSContext*, js::AnyInvokeArgs const&) (/builds/worker/workspace/build/application/firefox/libxul.so)
[task 2018-05-18T14:58:17.855Z] 14:58:17     INFO - PID 6105 | #11: js::Call(JSContext*, JS::Handle<JS::Value>, JS::Handle<JS::Value>, js::AnyInvokeArgs const&, JS::MutableHandle<JS::Value>) (/builds/worker/workspace/build/application/firefox/libxul.so)
[task 2018-05-18T14:58:17.859Z] 14:58:17     INFO - PID 6105 | #12: js::ForwardingProxyHandler::call(JSContext*, JS::Handle<JSObject*>, JS::CallArgs const&) const (/builds/worker/workspace/build/application/firefox/libxul.so)
[task 2018-05-18T14:58:17.868Z] 14:58:17     INFO - PID 6105 | #13: js::CrossCompartmentWrapper::call(JSContext*, JS::Handle<JSObject*>, JS::CallArgs const&) const (/builds/worker/workspace/build/application/firefox/libxul.so)
[task 2018-05-18T14:58:17.870Z] 14:58:17     INFO - PID 6105 | #14: js::Proxy::call(JSContext*, JS::Handle<JSObject*>, JS::CallArgs const&) (/builds/worker/workspace/build/application/firefox/libxul.so)
[task 2018-05-18T14:58:17.879Z] 14:58:17     INFO - PID 6105 | #15: js::proxy_Call(JSContext*, unsigned int, JS::Value*) (/builds/worker/workspace/build/application/firefox/libxul.so)
[task 2018-05-18T14:58:17.879Z] 14:58:17     INFO - PID 6105 | #16: js::CallJSNative(JSContext*, bool (*)(JSContext*, unsigned int, JS::Value*), JS::CallArgs const&) (/builds/worker/workspace/build/application/firefox/libxul.so)
[task 2018-05-18T14:58:17.882Z] 14:58:17     INFO - PID 6105 | #17: js::InternalCallOrConstruct(JSContext*, JS::CallArgs const&, js::MaybeConstruct) (/builds/worker/workspace/build/application/firefox/libxul.so)
[task 2018-05-18T14:58:17.882Z] 14:58:17     INFO - PID 6105 | #18: InternalCall(JSContext*, js::AnyInvokeArgs const&) (/builds/worker/workspace/build/application/firefox/libxul.so)
[task 2018-05-18T14:58:17.892Z] 14:58:17     INFO - PID 6105 | #19: Interpret(JSContext*, js::RunState&) (/builds/worker/workspace/build/application/firefox/libxul.so)
[task 2018-05-18T14:58:17.893Z] 14:58:17     INFO - PID 6105 | #20: js::RunScript(JSContext*, js::RunState&) (/builds/worker/workspace/build/application/firefox/libxul.so)
[task 2018-05-18T14:58:17.901Z] 14:58:17     INFO - PID 6105 | #21: js::InternalCallOrConstruct(JSContext*, JS::CallArgs const&, js::MaybeConstruct) (/builds/worker/workspace/build/application/firefox/libxul.so)
[task 2018-05-18T14:58:17.909Z] 14:58:17     INFO - PID 6105 | #22: InternalCall(JSContext*, js::AnyInvokeArgs const&) (/builds/worker/workspace/build/application/firefox/libxul.so)
[task 2018-05-18T14:58:17.910Z] 14:58:17     INFO - PID 6105 | #23: js::Call(JSContext*, JS::Handle<JS::Value>, JS::Handle<JS::Value>, js::AnyInvokeArgs const&, JS::MutableHandle<JS::Value>) (/builds/worker/workspace/build/application/firefox/libxul.so)
[task 2018-05-18T14:58:17.911Z] 14:58:17     INFO - PID 6105 | #24: js::fun_apply(JSContext*, unsigned int, JS::Value*) (/builds/worker/workspace/build/application/firefox/libxul.so)
[task 2018-05-18T14:58:17.912Z] 14:58:17     INFO - PID 6105 | #25: js::CallJSNative(JSContext*, bool (*)(JSContext*, unsigned int, JS::Value*), JS::CallArgs const&) (/builds/worker/workspace/build/application/firefox/libxul.so)
[task 2018-05-18T14:58:17.913Z] 14:58:17     INFO - PID 6105 | #26: js::InternalCallOrConstruct(JSContext*, JS::CallArgs const&, js::MaybeConstruct) (/builds/worker/workspace/build/application/firefox/libxul.so)
[task 2018-05-18T14:58:17.915Z] 14:58:17     INFO - PID 6105 | #27: InternalCall(JSContext*, js::AnyInvokeArgs const&) (/builds/worker/workspace/build/application/firefox/libxul.so)
[task 2018-05-18T14:58:17.916Z] 14:58:17     INFO - PID 6105 | #28: Interpret(JSContext*, js::RunState&) (/builds/worker/workspace/build/application/firefox/libxul.so)
[task 2018-05-18T14:58:17.917Z] 14:58:17     INFO - PID 6105 | #29: js::RunScript(JSContext*, js::RunState&) (/builds/worker/workspace/build/application/firefox/libxul.so)
[task 2018-05-18T14:58:17.918Z] 14:58:17     INFO - PID 6105 | #30: js::InternalCallOrConstruct(JSContext*, JS::CallArgs const&, js::MaybeConstruct) (/builds/worker/workspace/build/application/firefox/libxul.so)
[task 2018-05-18T14:58:17.919Z] 14:58:17     INFO - PID 6105 | #31: InternalCall(JSContext*, js::AnyInvokeArgs const&) (/builds/worker/workspace/build/application/firefox/libxul.so)
[task 2018-05-18T14:58:17.920Z] 14:58:17     INFO - PID 6105 | #32: js::Call(JSContext*, JS::Handle<JS::Value>, JS::Handle<JS::Value>, js::AnyInvokeArgs const&, JS::MutableHandle<JS::Value>) (/builds/worker/workspace/build/application/firefox/libxul.so)
[task 2018-05-18T14:58:17.921Z] 14:58:17     INFO - PID 6105 | #33: js::fun_apply(JSContext*, unsigned int, JS::Value*) (/builds/worker/workspace/build/application/firefox/libxul.so)
[task 2018-05-18T14:58:17.922Z] 14:58:17     INFO - PID 6105 | #34: js::CallJSNative(JSContext*, bool (*)(JSContext*, unsigned int, JS::Value*), JS::CallArgs const&) (/builds/worker/workspace/build/application/firefox/libxul.so)
[task 2018-05-18T14:58:17.923Z] 14:58:17     INFO - PID 6105 | #35: js::InternalCallOrConstruct(JSContext*, JS::CallArgs const&, js::MaybeConstruct) (/builds/worker/workspace/build/application/firefox/libxul.so)
[task 2018-05-18T14:58:17.924Z] 14:58:17     INFO - PID 6105 | #36: InternalCall(JSContext*, js::AnyInvokeArgs const&) (/builds/worker/workspace/build/application/firefox/libxul.so)
[task 2018-05-18T14:58:17.925Z] 14:58:17     INFO - PID 6105 | #37: Interpret(JSContext*, js::RunState&) (/builds/worker/workspace/build/application/firefox/libxul.so)
[task 2018-05-18T14:58:17.926Z] 14:58:17     INFO - PID 6105 | #38: js::RunScript(JSContext*, js::RunState&) (/builds/worker/workspace/build/application/firefox/libxul.so)
[task 2018-05-18T14:58:17.927Z] 14:58:17     INFO - PID 6105 | #39: js::InternalCallOrConstruct(JSContext*, JS::CallArgs const&, js::MaybeConstruct) (/builds/worker/workspace/build/application/firefox/libxul.so)
[task 2018-05-18T14:58:17.928Z] 14:58:17     INFO - PID 6105 | #40: InternalCall(JSContext*, js::AnyInvokeArgs const&) (/builds/worker/workspace/build/application/firefox/libxul.so)
[task 2018-05-18T14:58:17.929Z] 14:58:17     INFO - PID 6105 | #41: js::Call(JSContext*, JS::Handle<JS::Value>, JS::Handle<JS::Value>, js::AnyInvokeArgs const&, JS::MutableHandle<JS::Value>) (/builds/worker/workspace/build/application/firefox/libxul.so)
[task 2018-05-18T14:58:17.930Z] 14:58:17     INFO - PID 6105 | #42: JS::Call(JSContext*, JS::Handle<JS::Value>, JS::Handle<JS::Value>, JS::HandleValueArray const&, JS::MutableHandle<JS::Value>) (/builds/worker/workspace/build/application/firefox/libxul.so)
[task 2018-05-18T14:58:17.931Z] 14:58:17     INFO - PID 6105 | #43: mozilla::dom::EventHandlerNonNull::Call(JSContext*, JS::Handle<JS::Value>, mozilla::dom::Event&, JS::MutableHandle<JS::Value>, mozilla::ErrorResult&) (/builds/worker/workspace/build/application/firefox/libxul.so)
[task 2018-05-18T14:58:17.932Z] 14:58:17     INFO - PID 6105 | #44: mozilla::JSEventHandler::HandleEvent(mozilla::dom::Event*) (/builds/worker/workspace/build/application/firefox/libxul.so)
[task 2018-05-18T14:58:17.933Z] 14:58:17     INFO - PID 6105 | #45: mozilla::EventListenerManager::HandleEventSubType(mozilla::EventListenerManager::Listener*, mozilla::dom::Event*, mozilla::dom::EventTarget*) (/builds/worker/workspace/build/application/firefox/libxul.so)
[task 2018-05-18T14:58:17.934Z] 14:58:17     INFO - PID 6105 | #46: mozilla::EventListenerManager::HandleEventInternal(nsPresContext*, mozilla::WidgetEvent*, mozilla::dom::Event**, mozilla::dom::EventTarget*, nsEventStatus*) (/builds/worker/workspace/build/application/firefox/libxul.so)
[task 2018-05-18T14:58:17.943Z] 14:58:17     INFO - PID 6105 | #47: mozilla::EventTargetChainItem::HandleEvent(mozilla::EventChainPostVisitor&, mozilla::ELMCreationDetector&) (/builds/worker/workspace/build/application/firefox/libxul.so)
[task 2018-05-18T14:58:17.947Z] 14:58:17     INFO - PID 6105 | #48: mozilla::EventTargetChainItem::HandleEventTargetChain(nsTArray<mozilla::EventTargetChainItem>&, mozilla::EventChainPostVisitor&, mozilla::EventDispatchingCallback*, mozilla::ELMCreationDetector&) (/builds/worker/workspace/build/application/firefox/libxul.so)
[task 2018-05-18T14:58:17.955Z] 14:58:17     INFO - PID 6105 | #49: mozilla::EventDispatcher::Dispatch(nsISupports*, nsPresContext*, mozilla::WidgetEvent*, mozilla::dom::Event*, nsEventStatus*, mozilla::EventDispatchingCallback*, nsTArray<mozilla::dom::EventTarget*>*) (/builds/worker/workspace/build/application/firefox/libxul.so)
[task 2018-05-18T14:58:17.957Z] 14:58:17     INFO - PID 6105 | #50: nsGlobalWindowInner::PostHandleEvent(mozilla::EventChainPostVisitor&) (/builds/worker/workspace/build/application/firefox/libxul.so)
[task 2018-05-18T14:58:17.966Z] 14:58:17     INFO - PID 6105 | #51: mozilla::EventTargetChainItem::HandleEventTargetChain(nsTArray<mozilla::EventTargetChainItem>&, mozilla::EventChainPostVisitor&, mozilla::EventDispatchingCallback*, mozilla::ELMCreationDetector&) (/builds/worker/workspace/build/application/firefox/libxul.so)
[task 2018-05-18T14:58:17.967Z] 14:58:17     INFO - PID 6105 | #52: mozilla::EventTargetChainItem::HandleEventTargetChain(nsTArray<mozilla::EventTargetChainItem>&, mozilla::EventChainPostVisitor&, mozilla::EventDispatchingCallback*, mozilla::ELMCreationDetector&) (/builds/worker/workspace/build/application/firefox/libxul.so)
[task 2018-05-18T14:58:17.968Z] 14:58:17     INFO - PID 6105 | #53: mozilla::EventDispatcher::Dispatch(nsISupports*, nsPresContext*, mozilla::WidgetEvent*, mozilla::dom::Event*, nsEventStatus*, mozilla::EventDispatchingCallback*, nsTArray<mozilla::dom::EventTarget*>*) (/builds/worker/workspace/build/application/firefox/libxul.so)
[task 2018-05-18T14:58:17.970Z] 14:58:17     INFO - PID 6105 | #54: nsDocumentViewer::LoadComplete(nsresult) (/builds/worker/workspace/build/application/firefox/libxul.so)
[task 2018-05-18T14:58:17.978Z] 14:58:17     INFO - PID 6105 | #55: nsDocShell::EndPageLoad(nsIWebProgress*, nsIChannel*, nsresult) [clone .part.550] (/builds/worker/workspace/build/application/firefox/libxul.so)
[task 2018-05-18T14:58:17.981Z] 14:58:17     INFO - PID 6105 | #56: nsDocShell::OnStateChange(nsIWebProgress*, nsIRequest*, unsigned int, nsresult) (/builds/worker/workspace/build/application/firefox/libxul.so)
[task 2018-05-18T14:58:17.989Z] 14:58:17     INFO - PID 6105 | #57: nsDocLoader::DoFireOnStateChange(nsIWebProgress*, nsIRequest*, int&, nsresult) (/builds/worker/workspace/build/application/firefox/libxul.so)
[task 2018-05-18T14:58:17.991Z] 14:58:17     INFO - PID 6105 | #58: nsDocLoader::doStopDocumentLoad(nsIRequest*, nsresult) (/builds/worker/workspace/build/application/firefox/libxul.so)
[task 2018-05-18T14:58:17.999Z] 14:58:17     INFO - PID 6105 | #59: nsDocLoader::DocLoaderIsEmpty(bool) (/builds/worker/workspace/build/application/firefox/libxul.so)
[task 2018-05-18T14:58:18.003Z] 14:58:18     INFO - PID 6105 | #60: nsDocLoader::OnStopRequest(nsIRequest*, nsISupports*, nsresult) (/builds/worker/workspace/build/application/firefox/libxul.so)
[task 2018-05-18T14:58:18.012Z] 14:58:18     INFO - PID 6105 | #61: mozilla::net::nsLoadGroup::RemoveRequest(nsIRequest*, nsISupports*, nsresult) (/builds/worker/workspace/build/application/firefox/libxul.so)
[task 2018-05-18T14:58:18.016Z] 14:58:18     INFO - PID 6105 | #62: imgRequestProxy::RemoveFromLoadGroup() (/builds/worker/workspace/build/application/firefox/libxul.so)
[task 2018-05-18T14:58:18.020Z] 14:58:18     INFO - PID 6105 | #63: imgRequestProxy::OnLoadComplete(bool) (/builds/worker/workspace/build/application/firefox/libxul.so)
[task 2018-05-18T14:58:18.028Z] 14:58:18     INFO - PID 6105 | #64: void mozilla::image::ImageObserverNotifier<mozilla::image::ObserverTable const*>::operator()<void mozilla::image::SyncNotifyInternal<mozilla::image::ObserverTable const*>(mozilla::image::ObserverTable const* const&, bool, unsigned int, mozilla::gfx::IntRectTyped<mozilla::gfx::UnknownUnits> const&)::{lambda(mozilla::image::IProgressObserver*)#7}>(void mozilla::image::SyncNotifyInternal<mozilla::image::ObserverTable const*>(mozilla::image::ObserverTable const* const&, bool, unsigned int, mozilla::gfx::IntRectTyped<mozilla::gfx::UnknownUnits> const&)::{lambda(mozilla::image::IProgressObserver*)#7}) (/builds/worker/workspace/build/application/firefox/libxul.so)
[task 2018-05-18T14:58:18.032Z] 14:58:18     INFO - PID 6105 | #65: void mozilla::image::SyncNotifyInternal<mozilla::image::ObserverTable const*>(mozilla::image::ObserverTable const* const&, bool, unsigned int, mozilla::gfx::IntRectTyped<mozilla::gfx::UnknownUnits> const&) (/builds/worker/workspace/build/application/firefox/libxul.so)
[task 2018-05-18T14:58:18.040Z] 14:58:18     INFO - PID 6105 | #66: mozilla::image::ProgressTracker::SyncNotifyProgress(unsigned int, mozilla::gfx::IntRectTyped<mozilla::gfx::UnknownUnits> const&) (/builds/worker/workspace/build/application/firefox/libxul.so)
[task 2018-05-18T14:58:18.041Z] 14:58:18     INFO - PID 6105 | #67: mozilla::image::VectorImage::OnSVGDocumentLoaded() (/builds/worker/workspace/build/application/firefox/libxul.so)
[task 2018-05-18T14:58:18.051Z] 14:58:18     INFO - PID 6105 | #68: mozilla::image::SVGLoadEventListener::HandleEvent(mozilla::dom::Event*) (/builds/worker/workspace/build/application/firefox/libxul.so)
[task 2018-05-18T14:58:18.051Z] 14:58:18     INFO - PID 6105 | #69: mozilla::EventListenerManager::HandleEventSubType(mozilla::EventListenerManager::Listener*, mozilla::dom::Event*, mozilla::dom::EventTarget*) (/builds/worker/workspace/build/application/firefox/libxul.so)
[task 2018-05-18T14:58:18.051Z] 14:58:18     INFO - PID 6105 | #70: mozilla::EventListenerManager::HandleEventInternal(nsPresContext*, mozilla::WidgetEvent*, mozilla::dom::Event**, mozilla::dom::EventTarget*, nsEventStatus*) (/builds/worker/workspace/build/application/firefox/libxul.so)
[task 2018-05-18T14:58:18.052Z] 14:58:18     INFO - PID 6105 | #71: mozilla::EventTargetChainItem::HandleEvent(mozilla::EventChainPostVisitor&, mozilla::ELMCreationDetector&) (/builds/worker/workspace/build/application/firefox/libxul.so)
[task 2018-05-18T14:58:18.052Z] 14:58:18     INFO - PID 6105 | #72: mozilla::EventTargetChainItem::HandleEventTargetChain(nsTArray<mozilla::EventTargetChainItem>&, mozilla::EventChainPostVisitor&, mozilla::EventDispatchingCallback*, mozilla::ELMCreationDetector&) (/builds/worker/workspace/build/application/firefox/libxul.so)
[task 2018-05-18T14:58:18.052Z] 14:58:18     INFO - PID 6105 | #73: mozilla::EventDispatcher::Dispatch(nsISupports*, nsPresContext*, mozilla::WidgetEvent*, mozilla::dom::Event*, nsEventStatus*, mozilla::EventDispatchingCallback*, nsTArray<mozilla::dom::EventTarget*>*) (/builds/worker/workspace/build/application/firefox/libxul.so)
[task 2018-05-18T14:58:18.056Z] 14:58:18     INFO - PID 6105 | #74: mozilla::EventDispatcher::DispatchDOMEvent(nsISupports*, mozilla::WidgetEvent*, mozilla::dom::Event*, nsPresContext*, nsEventStatus*) (/builds/worker/workspace/build/application/firefox/libxul.so)
[task 2018-05-18T14:58:18.061Z] 14:58:18     INFO - PID 6105 | #75: nsINode::DispatchEvent(mozilla::dom::Event&, mozilla::dom::CallerType, mozilla::ErrorResult&) (/builds/worker/workspace/build/application/firefox/libxul.so)
[task 2018-05-18T14:58:18.065Z] 14:58:18     INFO - PID 6105 | #76: mozilla::dom::EventTarget::DispatchEvent(mozilla::dom::Event&) (/builds/worker/workspace/build/application/firefox/libxul.so)
[task 2018-05-18T14:58:18.075Z] 14:58:18     INFO - PID 6105 | #77: mozilla::AsyncEventDispatcher::Run() (/builds/worker/workspace/build/application/firefox/libxul.so)
[task 2018-05-18T14:58:18.077Z] 14:58:18     INFO - PID 6105 | #78: nsThread::ProcessNextEvent(bool, bool*) [clone .part.288] (/builds/worker/workspace/build/application/firefox/libxul.so)
[task 2018-05-18T14:58:18.081Z] 14:58:18     INFO - PID 6105 | #79: NS_ProcessNextEvent(nsIThread*, bool) (/builds/worker/workspace/build/application/firefox/libxul.so)
[task 2018-05-18T14:58:18.086Z] 14:58:18     INFO - PID 6105 | #80: mozilla::ipc::MessagePump::Run(base::MessagePump::Delegate*) (/builds/worker/workspace/build/application/firefox/libxul.so)
[task 2018-05-18T14:58:18.092Z] 14:58:18     INFO - PID 6105 | #81: MessageLoop::RunInternal() (/builds/worker/workspace/build/application/firefox/libxul.so)
[task 2018-05-18T14:58:18.097Z] 14:58:18     INFO - PID 6105 | #82: MessageLoop::Run() (/builds/worker/workspace/build/application/firefox/libxul.so)
[task 2018-05-18T14:58:18.106Z] 14:58:18     INFO - PID 6105 | #83: nsBaseAppShell::Run() (/builds/worker/workspace/build/application/firefox/libxul.so)
[task 2018-05-18T14:58:18.108Z] 14:58:18     INFO - PID 6105 | #84: XRE_RunAppShell() (/builds/worker/workspace/build/application/firefox/libxul.so)
[task 2018-05-18T14:58:18.117Z] 14:58:18     INFO - PID 6105 | #85: mozilla::ipc::MessagePumpForChildProcess::Run(base::MessagePump::Delegate*) (/builds/worker/workspace/build/application/firefox/libxul.so)
[task 2018-05-18T14:58:18.119Z] 14:58:18     INFO - PID 6105 | #86: MessageLoop::RunInternal() (/builds/worker/workspace/build/application/firefox/libxul.so)
[task 2018-05-18T14:58:18.120Z] 14:58:18     INFO - PID 6105 | #87: MessageLoop::Run() (/builds/worker/workspace/build/application/firefox/libxul.so)
[task 2018-05-18T14:58:18.121Z] 14:58:18     INFO - PID 6105 | #88: XRE_InitChildProcess(int, char**, XREChildData const*) (/builds/worker/workspace/build/application/firefox/libxul.so)
[task 2018-05-18T14:58:18.243Z] 14:58:18     INFO - PID 6105 | #89: content_process_main(mozilla::Bootstrap*, int, char**) (/builds/worker/workspace/build/application/firefox/firefox)
[task 2018-05-18T14:58:18.243Z] 14:58:18     INFO - PID 6105 | #90: main (/builds/worker/workspace/build/application/firefox/firefox)
[task 2018-05-18T14:58:22.073Z] 14:58:22     INFO - PID 6105 | #91: __libc_start_main (/build/glibc-Cl5G7W/glibc-2.23/csu/../csu/libc-start.c:325)
[task 2018-05-18T14:58:22.074Z] 14:58:22     INFO - PID 6105 | #92: _start (/builds/worker/workspace/build/application/firefox/firefox)
[task 2018-05-18T14:58:22.074Z] 14:58:22     INFO - PID 6105 | [Parent 6105, Gecko_IOThread] WARNING: pipe error (90): Connection reset by peer: file /builds/worker/workspace/build/src/ipc/chromium/src/chrome/common/ipc_channel_posix.cc, line 353
[task 2018-05-18T14:58:22.074Z] 14:58:22     INFO - PID 6105 | ###!!! [Parent][MessageChannel] Error: (msgtype=0x160080,name=PBrowser::Msg_Destroy) Channel error: cannot send/recv
[task 2018-05-18T14:58:22.076Z] 14:58:22     INFO - PID 6105 | [GFX1-]: Unknown pipeline used for iframe IframeDisplayItem { clip_id: Clip(4, PipelineId(1, 1)), pipeline_id: PipelineId(1, 3) }
[task 2018-05-18T14:58:22.076Z] 14:58:22     INFO - PID 6105 | ERROR 2018-05-18T14:58:17Z: webrender::display_list_flattener: Unknown pipeline used for iframe IframeDisplayItem { clip_id: Clip(4, PipelineId(1, 1)), pipeline_id: PipelineId(1, 3) }
[task 2018-05-18T14:58:22.076Z] 14:58:22     INFO - PID 6105 | [GFX1-]: Unknown pipeline used for iframe IframeDisplayItem { clip_id: Clip(4, PipelineId(1, 1)), pipeline_id: PipelineId(1, 3) }
[task 2018-05-18T14:58:22.076Z] 14:58:22     INFO - PID 6105 | ERROR 2018-05-18T14:58:17Z: webrender::display_list_flattener: Unknown pipeline used for iframe IframeDisplayItem { clip_id: Clip(4, PipelineId(1, 1)), pipeline_id: PipelineId(1, 3) }
[task 2018-05-18T14:58:22.076Z] 14:58:22     INFO - PID 6105 |  WARN 2018-05-18T14:58:17Z: webrender::render_backend: Built the scene several times without rendering it.
[task 2018-05-18T14:58:22.077Z] 14:58:22     INFO - PID 6105 | [GFX1-]: Unknown pipeline used for iframe IframeDisplayItem { clip_id: Clip(4, PipelineId(1, 1)), pipeline_id: PipelineId(1, 3) }
[task 2018-05-18T14:58:22.077Z] 14:58:22     INFO - PID 6105 | ERROR 2018-05-18T14:58:17Z: webrender::display_list_flattener: Unknown pipeline used for iframe IframeDisplayItem { clip_id: Clip(4, PipelineId(1, 1)), pipeline_id: PipelineId(1, 3) }
[task 2018-05-18T14:58:22.077Z] 14:58:22     INFO - PID 6105 |  WARN 2018-05-18T14:58:17Z: webrender::render_backend: Built the scene several times without rendering it.
[task 2018-05-18T14:58:22.079Z] 14:58:22     INFO - PID 6105 | ++DOCSHELL 0x7f01f53ab800 == 7 [pid = 6105] [id = {25685243-4896-46bf-9d53-67134fe9be92}]
[task 2018-05-18T14:58:22.079Z] 14:58:22     INFO - PID 6105 | ++DOMWINDOW == 17 (0x7f01fc9fd600) [pid = 6105] [serial = 17] [outer = (nil)]

Comment 1

[Natalia Csoregi [:nataliaCs]]

Looks like a false positive failure - checked one of the successful jobs https://treeherder.mozilla.org/logviewer.html#?job_id=179296552&repo=mozilla-inbound&lineNumber=14502

task details https://tools.taskcluster.net/groups/OQDzKdkDQhqhAkkqANslbQ/tasks/PanPI1kbQW6MYnIIyqzihg


[task 2018-05-19T03:55:46.387Z] 03:55:46     INFO - PID 6162 | Assertion failure: GetReadyStateEnum() == nsIDocument::READYSTATE_LOADING (Bad readyState), at /builds/worker/workspace/build/src/dom/html/MediaDocument.cpp:197
[task 2018-05-19T03:55:46.650Z] 03:55:46     INFO - PID 6162 | #01: mozilla::dom::ImageDocument::SetScriptGlobalObject(nsIScriptGlobalObject*) (/builds/worker/workspace/build/application/firefox/libxul.so)
[task 2018-05-19T03:55:46.659Z] 03:55:46     INFO - PID 6162 | #02: nsGlobalWindowOuter::SetNewDocument(nsIDocument*, nsISupports*, bool) (/builds/worker/workspace/build/application/firefox/libxul.so)
[task 2018-05-19T03:55:46.667Z] 03:55:46     INFO - PID 6162 | #03: nsHTMLDocument::Open(JSContext*, mozilla::dom::Optional<nsTSubstring<char16_t> > const&, nsTSubstring<char16_t> const&, mozilla::ErrorResult&) (/builds/worker/workspace/build/application/firefox/libxul.so)
[task 2018-05-19T03:55:46.675Z] 03:55:46     INFO - PID 6162 | #04: nsHTMLDocument::WriteCommon(JSContext*, nsTSubstring<char16_t> const&, bool, mozilla::ErrorResult&) (/builds/worker/workspace/build/application/firefox/libxul.so)
[task 2018-05-19T03:55:46.683Z] 03:55:46     INFO - PID 6162 | #05: nsHTMLDocument::WriteCommon(JSContext*, mozilla::dom::Sequence<nsTString<char16_t> > const&, bool, mozilla::ErrorResult&) (/builds/worker/workspace/build/application/firefox/libxul.so)
[task 2018-05-19T03:55:46.691Z] 03:55:46     INFO - PID 6162 | #06: mozilla::dom::HTMLDocumentBinding::write(JSContext*, JS::Handle<JSObject*>, nsHTMLDocument*, JSJitMethodCallArgs const&) (/builds/worker/workspace/build/application/firefox/libxul.so)
[task 2018-05-19T03:55:46.700Z] 03:55:46     INFO - PID 6162 | #07: bool mozilla::dom::binding_detail::GenericMethod<mozilla::dom::binding_detail::NormalThisPolicy, mozilla::dom::binding_detail::ThrowExceptions>(JSContext*, unsigned int, JS::Value*) (/builds/worker/workspace/build/application/firefox/libxul.so)
[task 2018-05-19T03:55:46.704Z] 03:55:46     INFO - PID 6162 | #08: js::CallJSNative(JSContext*, bool (*)(JSContext*, unsigned int, JS::Value*), JS::CallArgs const&) (/builds/worker/workspace/build/application/firefox/libxul.so)
[task 2018-05-19T03:55:46.712Z] 03:55:46     INFO - PID 6162 | #09: js::InternalCallOrConstruct(JSContext*, JS::CallArgs const&, js::MaybeConstruct) (/builds/worker/workspace/build/application/firefox/libxul.so)
[task 2018-05-19T03:55:46.716Z] 03:55:46     INFO - PID 6162 | #10: InternalCall(JSContext*, js::AnyInvokeArgs const&) (/builds/worker/workspace/build/application/firefox/libxul.so)

Comment 3

[Intermittent Failures Robot]

32 failures in 639 pushes (0.05 failures/push) were associated with this bug in the last 7 days. 

This is the #42 most frequent failure this week.  

** This failure happened more than 30 times this week! Resolving this bug is a high priority. **

** Try to resolve this bug as soon as possible. If unresolved for 2 weeks, the affected test(s) may be disabled. **  

Repository breakdown:
* mozilla-inbound: 14
* autoland: 12
* mozilla-central: 6

Platform breakdown:
* linux64-qr: 18
* osx-10-10: 4
* linux64: 4
* windows7-32: 3
* windows10-64: 3

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1462789&startday=2018-05-14&endday=2018-05-20&tree=trunk

Comment 4

[Robert O'Callahan (:roc) (email my personal email if necessary)]

We captured this bug and made it debuggable in the Pernosco debugger:
https://pernos.co/debug/STyDiHTLi8b0Bj3aTBMrIw/index.html#{f:{m:[295092,291978],t:[114,1209],f:{e:[295092,291972],s:{a:6675608371200,b:218,o:372948211,f:'m',u:371485025}}}}
Access details here: https://mana.mozilla.org/wiki/display/TS/Debugging+with+Pernosco
Email me if you need any help.

Comment 5

[Boris Zbarsky [:bzbarsky]]

roc, thank you, having that capture was really helpful!

So the test at testing/web-platform/tests/html/dom/dynamic-markup-insertion/document-write/contentType.window.js basically looks like this:

1)  Create an iframe pointing to an image.
2)  Wait for it to load.
3)  Call document.open() on it.

When this happens, nsHTMLDocument::Open does:

    SetReadyStateInternal(READYSTATE_UNINITIALIZED);

before calling window->SetNewDocument(this, ...).

Then it calls SetNewDocument(), which calls ImageDocument::SetScriptGlobalObject which calls ediaDocument::BecomeInteractive.  BecomeInteractive has this bit:

  if (GetReadyStateEnum() != nsIDocument::READYSTATE_COMPLETE) {
    MOZ_ASSERT(GetReadyStateEnum() == nsIDocument::READYSTATE_LOADING,
               "Bad readyState");

and that's the failing assert, because our state is READYSTATE_UNINITIALIZED at this point.  Much later through Open() it sets readystate to READYSTATE_LOADING, but by that point it's too late.

So I would expect this to always fail, on all debug platforms.  And indeed it does, but the ini file annotates this as a known failure on some platforms but not others; for example it's not annotated as failing on webrender (James, any idea how that happened?).

Anyway, I have some ideas for how to fix this.  Working on a fix now.

Comment 6

[Boris Zbarsky [:bzbarsky]]

Attachment: Fix readystate assertions when document.open() is used on an image document

There are a few things going on here:

1)  Better tracking of whether we've done our synthetic document stuff so we
don't redo it when it's not needed.  We should only be doing it on initial
load.

2)  Better handling of our readystate transitions.  We're only responsible for
the transition to READYSTATE_INTERACTIVE if we're the ones setting up the DOM.
Otherwise whoever is doing that should do the readystate transition.

Both of these really use the same mechanism, which is why I ended up doing them
together.

Comment 7

[Henri Sivonen (:hsivonen)]

Comment on attachment 8979753 [details] [diff] [review]
Fix readystate assertions when document.open() is used on an image document

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

Thank you for figuring this out and fixing!

::: dom/html/ImageDocument.cpp
@@ +288,5 @@
>      }
>  
>      target = do_QueryInterface(aScriptGlobalObject);
>      target->AddEventListener(NS_LITERAL_STRING("resize"), this, false);
>      target->AddEventListener(NS_LITERAL_STRING("keypress"), this, false);

Not really about this bug, but I wonder if adding these listerners is appropriate if initial setup has been done and something like document.open() is happening.

Comment 9

[James Graham [:jgraham]]

> So I would expect this to always fail, on all debug platforms.  And indeed it does, but the ini file annotates this as a known failure on some platforms but not others; for example it's not annotated as failing on webrender (James, any idea how that happened?).

Looks like it intermittently times out rather than crashing on webrender, so at some point the metadata got updated to reflect that.

Comment 10

[Boris Zbarsky [:bzbarsky]]

> but I wonder if adding these listerners is appropriate if initial setup has been done and something like document.open() is happening

It's not, really.  I just filed followup bug 1463757.

Comment 11

[Pulsebot]

Pushed by [e-mail]:
https://hg.mozilla.org/integration/mozilla-inbound/rev/9f9763a01686
Fix readystate assertions when document.open() is used on an image document.  r=hsivonen

Comment 12

[Eliza Balazs [:ebalazs_]]

https://hg.mozilla.org/mozilla-central/rev/9f9763a01686

Comment 14

[Intermittent Failures Robot]

21 failures in 632 pushes (0.033 failures/push) were associated with this bug in the last 7 days.    

Repository breakdown:
* mozilla-inbound: 16
* autoland: 5

Platform breakdown:
* linux64-qr: 20
* osx-10-10: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1462789&startday=2018-05-21&endday=2018-05-27&tree=trunk