1527619 - Intermittent dom/vr/test/reftest/draw_rect.html | application timed out after 370 seconds with no output

Status: RESOLVED INCOMPLETE

(Core :: WebVR, defect, P5)

Description

[Treeherder Bug Filer]

#[markdown(off)]
Filed by: aiakab [at] mozilla.com

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

https://queue.taskcluster.net/v1/task/X0PTJZYnTgSKkf0xPPqG3g/runs/1/artifacts/public/logs/live_backing.log

https://hg.mozilla.org/mozilla-central/raw-file/tip/layout/tools/reftest/reftest-analyzer.xhtml#logurl=https://queue.taskcluster.net/v1/task/X0PTJZYnTgSKkf0xPPqG3g/runs/1/artifacts/public/logs/live_backing.log&only_show_unexpected=1

12:47:17 INFO - REFTEST TEST-START | file:///Z:/task_1550060904/build/tests/reftest/tests/dom/vr/test/reftest/draw_rect.html == file:///Z:/task_1550060904/build/tests/reftest/tests/dom/vr/test/reftest/wrapper.html?draw_rect.png
12:47:17 INFO - REFTEST INFO | SET PREFERENCE pref(dom.vr.puppet.enabled,true)
12:47:17 INFO - REFTEST INFO | SET PREFERENCE pref(dom.vr.test.enabled,true)
12:47:17 INFO - REFTEST INFO | SET PREFERENCE pref(dom.vr.require-gesture,false)
12:47:17 INFO - REFTEST INFO | SET PREFERENCE pref(dom.vr.puppet.submitframe,1)
12:47:17 INFO - REFTEST INFO | SET PREFERENCE pref(dom.vr.display.rafMaxDuration,200)
12:47:17 INFO - REFTEST INFO | SET PREFERENCE pref(dom.vr.display.enumerate.interval,0)
12:47:17 INFO - REFTEST INFO | SET PREFERENCE pref(dom.vr.controller.enumerate.interval,0)
12:47:17 INFO - REFTEST TEST-LOAD | file:///Z:/task_1550060904/build/tests/reftest/tests/dom/vr/test/reftest/draw_rect.html | 0 / 2 (0%)
12:47:17 INFO - ++DOMWINDOW == 6 (0000018D90664000) [pid = 7552] [serial = 6] [outer = 0000018D90963800]
12:47:17 INFO - [Child 7552, Main Thread] WARNING: NS_ENSURE_TRUE(nsContentUtils::IsJavascriptMIMEType(type)) failed: file z:/build/build/src/dom/script/ScriptLoader.cpp, line 1464
12:47:17 INFO - [Child 7552, Main Thread] WARNING: NS_ENSURE_TRUE(nsContentUtils::IsJavascriptMIMEType(type)) failed: file z:/build/build/src/dom/script/ScriptLoader.cpp, line 1464
12:47:17 INFO - WARN: initializeD3DDevice(770): Failed creating Debug D3D11 device - falling back to release runtime.
12:47:17 INFO - Initializing context 0000018D97247000 surface 0000018D97250040 on display 0000018D90602CD0
12:47:17 INFO - REFTEST INFO | drawWindow flags = DRAWWINDOW_DRAW_CARET | DRAWWINDOW_DRAW_VIEW | DRAWWINDOW_USE_WIDGET_LAYERS; window size = 816,1039; test browser size = 800,1000
12:47:17 INFO - ### XPCOM_MEM_BLOAT_LOG defined -- logging bloat/leaks to c:\users\task_1550060904\appdata\local\temp\tmpxfbcnt.mozrunner\runreftest_leaks_tab_pid5772.log
12:47:17 INFO - [Child 5772, Main Thread] WARNING: No CID found when attempting to map contract ID: file z:/build/build/src/xpcom/components/nsComponentManager.cpp, line 744
12:47:22 INFO - --DOMWINDOW == 5 (0000018D8E988400) [pid = 7552] [serial = 2] [outer = 0000000000000000] [url = about:blank]
12:47:24 INFO - --DOCSHELL 0000018D8904A000 == 1 [pid = 7552] [id = {c0fb9eda-b2ce-41f1-bc6b-1439be37c931}]
12:47:24 INFO - --DOMWINDOW == 4 (0000018D8E987400) [pid = 7552] [serial = 1] [outer = 0000000000000000] [url = chrome://gfxsanity/content/sanitytest.html]
12:47:28 INFO - --DOMWINDOW == 14 (000002B7004BB400) [pid = 11396] [serial = 9] [outer = 0000000000000000] [url = about:blank]
12:47:28 INFO - --DOMWINDOW == 13 (000002B70699AC00) [pid = 11396] [serial = 8] [outer = 0000000000000000] [url = about:blank]
12:47:28 INFO - --DOMWINDOW == 12 (000002B705EB5000) [pid = 11396] [serial = 6] [outer = 0000000000000000] [url = about:blank]
12:47:28 INFO - --DOMWINDOW == 11 (000002B70699BC00) [pid = 11396] [serial = 10] [outer = 0000000000000000] [url = about:blank]
12:47:28 INFO - --DOMWINDOW == 10 (000002B70699A000) [pid = 11396] [serial = 7] [outer = 0000000000000000] [url = about:blank]
12:47:28 INFO - --DOMWINDOW == 3 (0000018D90662C00) [pid = 7552] [serial = 3] [outer = 0000000000000000] [url = chrome://gfxsanity/content/sanitytest.html]
12:47:46 INFO - --DOMWINDOW == 2 (0000018D90964C00) [pid = 7552] [serial = 5] [outer = 0000000000000000] [url = about:blank]
12:53:56 ERROR - REFTEST ERROR | file:///Z:/task_1550060904/build/tests/reftest/tests/dom/vr/test/reftest/draw_rect.html | application timed out after 370 seconds with no output
12:53:56 ERROR - REFTEST ERROR | Force-terminating active process(es).
12:53:56 INFO - REFTEST TEST-INFO | started process screenshot
12:53:56 INFO - REFTEST TEST-INFO | screenshot: exit 0
12:53:56 INFO - TEST-INFO | crashinject: exit 0
12:57:01 INFO - WARNING | IO Completion Port failed to signal process shutdown
12:57:01 INFO - Parent process 1692 exited with children alive:
12:57:01 INFO - PIDS: 7552, 11396, 5772, 7564, 10900
12:57:01 INFO - Attempting to kill them, but no guarantee of success
12:57:01 ERROR - TEST-UNEXPECTED-FAIL | file:///Z:/task_1550060904/build/tests/reftest/tests/dom/vr/test/reftest/draw_rect.html | application terminated with exit code 3221225477
12:57:01 INFO - REFTEST INFO | Process mode: e10s
12:57:01 WARNING - leakcheck | refcount logging is off, so leaks can't be detected!
12:57:01 INFO - REFTEST INFO | Running tests in file:///Z:/task_1550060904/build/tests/reftest/tests/layout/reftests/writing-mode/abspos/reftest.list
12:57:01 INFO - REFTEST INFO | Running with e10s: True
12:57:01 INFO - REFTEST INFO | Application command: Z:\task_1550060904\build\application\firefox\firefox.exe -marionette --wait-for-browser -profile c:\users\task_1550060904\appdata\local\temp\tmp149flz.mozrunner
12:57:02 INFO - ### XPCOM_MEM_BLOAT_LOG defined -- logging bloat/leaks to c:\users\task_1550060904\appdata\local\temp\tmp149flz.mozrunner\runreftest_leaks.log
12:57:02 INFO - [2988, Main Thread] WARNING: CheckLinkStatus called on main thread! No check performed. Assuming link is up, status is unknown.: file z:/build/build/src/netwerk/system/win32/nsNotifyAddrListener.cpp, line 660
12:57:03 INFO - 1550062623106 [e-mail] WARN Loading extension '[e-mail]': Reading manifest: Invalid extension permission: mozillaAddons
12:57:03 INFO - 1550062623107 [e-mail] WARN Loading extension '[e-mail]': Reading manifest: Invalid extension permission: resource://pdf.js/
12:57:03 INFO - 1550062623107 [e-mail] WARN Loading extension '[e-mail]': Reading manifest: Invalid extension permission: about:reader*
12:57:03 INFO - [2988, Main Thread] WARNING: NS_ENSURE_SUCCESS(rv, rv) failed with result 0x80040111: file z:/build/build/src/netwerk/protocol/res/SubstitutingProtocolHandler.cpp, line 319
12:57:03 INFO - [2988, Main Thread] WARNING: NS_ENSURE_SUCCESS(rv, rv) failed with result 0x80040111: file z:/build/build/src/netwerk/protocol/res/SubstitutingProtocolHandler.cpp, line 319
12:57:03 INFO - [2988, Main Thread] WARNING: NS_ENSURE_SUCCESS(rv, rv) failed with result 0x80040111: file z:/build/build/src/netwerk/protocol/res/SubstitutingProtocolHandler.cpp, line 319
12:57:03 INFO - [2988, Main Thread] WARNING: NS_ENSURE_SUCCESS(rv, rv) failed with result 0x80040111: file z:/build/build/src/netwerk/protocol/res/SubstitutingProtocolHandler.cpp, line 319
12:57:03 INFO - [2988, Main Thread] WARNING: NS_ENSURE_SUCCESS(rv, rv) failed with result 0x80040111: file z:/build/build/src/netwerk/protocol/res/SubstitutingProtocolHandler.cpp, line 319
12:57:03 INFO - 1550062623511 Marionette TRACE Received observer notification profile-after-change
12:57:03 INFO - ++DOCSHELL 000001D97BBBA800 == 1 [pid = 2988] [id = {23427fc4-e594-44b2-b726-835863355003}]
12:57:03 INFO - ++DOMWINDOW == 1 (000001D907AB3400) [pid = 2988] [serial = 1] [outer = 0000000000000000]
12:57:03 INFO - ++DOMWINDOW == 2 (000001D907AB3C00) [pid = 2988] [serial = 2] [outer = 000001D907AB3400]
12:57:03 INFO - 1550062623588 Marionette TRACE Received observer notification toplevel-window-ready
12:57:03 INFO - ### XPCOM_MEM_BLOAT_LOG defined -- logging bloat/leaks to c:\users\task_1550060904\appdata\local\temp\tmp149flz.mozrunner\runreftest_leaks_gpu_pid5508.log
12:57:03 INFO - [GPU 5508, Main Thread] WARNING: NS_ENSURE_TRUE(InitStaticMembers()) failed: file z:/build/build/src/modules/libpref/Preferences.cpp, line 4819
12:57:03 INFO - [GPU 5508, Main Thread] WARNING: NS_ENSURE_TRUE(InitStaticMembers()) failed: file z:/build/build/src/obj-firefox/dist/include/mozilla/Preferences.h, line 190
12:57:03 INFO - [GPU 5508, Main Thread] WARNING: NS_ENSURE_TRUE(InitStaticMembers()) failed: file z:/build/build/src/modules/libpref/Preferences.cpp, line 4565
12:57:03 INFO - [GPU 5508, Main Thread] WARNING: NS_ENSURE_TRUE(InitStaticMembers()) failed: file z:/build/build/src/modules/libpref/Preferences.cpp, line 4600
12:57:03 INFO - [GPU 5508, Main Thread] WARNING: NS_ENSURE_TRUE(InitStaticMembers()) failed: file z:/build/build/src/modules/libpref/Preferences.cpp, line 4565
12:57:03 INFO - 1550062623706 Marionette TRACE Received observer notification command-line-startup
12:57:03 INFO - 1550062623707 Marionette TRACE Received observer notification nsPref:changed
12:57:03 INFO - 1550062623707 Marionette DEBUG Init aborted (running=false, enabled=true, finalUIStartup=false)
12:57:03 INFO - ++DOCSHELL 000001D97FF1A000 == 2 [pid = 2988] [id = {bb3a0134-4678-424a-b0a8-4f6384ac7ceb}]
12:57:03 INFO - ++DOMWINDOW == 3 (000001D9084EC800) [pid = 2988] [serial = 3] [outer = 0000000000000000]
12:57:03 INFO - ++DOMWINDOW == 4 (000001D9084ED000) [pid = 2988] [serial = 4] [outer = 000001D9084EC800]
12:57:03 INFO - [2988, Main Thread] WARNING: 'mIndex >= Count()', file z:/build/build/src/xpcom/ds/nsStringEnumerator.cpp, line 208
12:57:03 INFO - ++DOCSHELL 000001D908F26800 == 3 [pid = 2988] [id = {2236c69b-9dbc-4aea-9351-f7b4c8dec6bd}]
12:57:03 INFO - ++DOMWINDOW == 5 (000001D907AB2400) [pid = 2988] [serial = 5] [outer = 0000000000000000]
12:57:03 INFO - ++DOMWINDOW == 6 (000001D9084EF800) [pid = 2988] [serial = 6] [outer = 000001D907AB2400]
12:57:03 INFO - 1550062623979 Marionette TRACE Received observer notification toplevel-window-ready
12:57:04 INFO - ++DOMWINDOW == 7 (000001D908EF6800) [pid = 2988] [serial = 7] [outer = 000001D9084EC800]
12:57:05 INFO - Initializing context 0000027CC3951000 surface 0000027CB7E0A340 on display 0000027CC3927050
12:57:05 INFO - [GPU 5508, Renderer] WARNING: Robustness supported, strategy is not LOSE_CONTEXT_ON_RESET!: file z:/build/build/src/gfx/gl/GLContext.cpp, line 963
12:57:05 INFO - [GPU 5508, Renderer] WARNING: robustness marked as unsupported: file z:/build/build/src/gfx/gl/GLContextFeatures.cpp, line 620
12:57:05 INFO - WARN 2019-02-13T12:57:05Z: webrender_bindings::bindings: Could not find symbol "glCopyImageSubDataEXT" by glcontext
12:57:05 INFO - WARN 2019-02-13T12:57:05Z: webrender_bindings::bindings: Could not find symbol "glDebugMessageCallback" by glcontext
12:57:05 INFO - WARN 2019-02-13T12:57:05Z: webrender_bindings::bindings: Could not find symbol "glDebugMessageCallbackARB" by glcontext
12:57:05 INFO - WARN 2019-02-13T12:57:05Z: webrender_bindings::bindings: Could not find symbol "glDebugMessageControl" by glcontext
12:57:05 INFO - WARN 2019-02-13T12:57:05Z: webrender_bindings::bindings: Could not find symbol "glDebugMessageControlARB" by glcontext
12:57:05 INFO - WARN 2019-02-13T12:57:05Z: webrender_bindings::bindings: Could not find symbol "glDebugMessageInsert" by glcontext
12:57:05 INFO - WARN 2019-02-13T12:57:05Z: webrender_bindings::bindings: Could not find symbol "glDebugMessageInsertARB" by glcontext
12:57:05 INFO - WARN 2019-02-13T12:57:05Z: webrender_bindings::bindings: Could not find symbol "glGetDebugMessageLog" by glcontext
12:57:05 INFO - WARN 2019-02-13T12:57:05Z: webrender_bindings::bindings: Could not find symbol "glGetDebugMessageLogARB" by glcontext
12:57:05 INFO - WARN 2019-02-13T12:57:05Z: webrender_bindings::bindings: Could not find symbol "glGetObjectLabel" by glcontext
12:57:05 INFO - WARN 2019-02-13T12:57:05Z: webrender_bindings::bindings: Could not find symbol "glGetObjectPtrLabel" by glcontext
12:57:05 INFO - WARN 2019-02-13T12:57:05Z: webrender_bindings::bindings: Could not find symbol "glObjectLabel" by glcontext
12:57:05 INFO - WARN 2019-02-13T12:57:05Z: webrender_bindings::bindings: Could not find symbol "glObjectPtrLabel" by glcontext
12:57:05 INFO - WARN 2019-02-13T12:57:05Z: webrender_bindings::bindings: Could not find symbol "glPopDebugGroup" by glcontext
12:57:05 INFO - WARN 2019-02-13T12:57:05Z: webrender_bindings::bindings: Could not find symbol "glPushDebugGroup" by glcontext
12:57:05 INFO - WARN 2019-02-13T12:57:05Z: webrender_bindings::bindings: Could not find symbol "glTextureStorage1DEXT" by glcontext
12:57:05 INFO - WARN 2019-02-13T12:57:05Z: webrender_bindings::bindings: Could not find symbol "glTextureStorage2DEXT" by glcontext
12:57:05 INFO - WARN 2019-02-13T12:57:05Z: webrender_bindings::bindings: Could not find symbol "glTextureStorage3DEXT" by glcontext
12:57:05 INFO - WARN 2019-02-13T12:57:05Z: webrender_bindings::bindings: Could not find symbol "glCopyImageSubDataEXT" by glcontext
12:57:05 INFO - WARN 2019-02-13T12:57:05Z: webrender_bindings::bindings: Could not find symbol "glDebugMessageCallback" by glcontext
12:57:05 INFO - WARN 2019-02-13T12:57:05Z: webrender_bindings::bindings: Could not find symbol "glDebugMessageCallbackARB" by glcontext
12:57:05 INFO - WARN 2019-02-13T12:57:05Z: webrender_bindings::bindings: Could not find symbol "glDebugMessageControl" by glcontext
12:57:05 INFO - WARN 2019-02-13T12:57:05Z: webrender_bindings::bindings: Could not find symbol "glDebugMessageControlARB" by glcontext
12:57:05 INFO - WARN 2019-02-13T12:57:05Z: webrender_bindings::bindings: Could not find symbol "glDebugMessageInsert" by glcontext
12:57:05 INFO - WARN 2019-02-13T12:57:05Z: webrender_bindings::bindings: Could not find symbol "glDebugMessageInsertARB" by glcontext
12:57:05 INFO - WARN 2019-02-13T12:57:05Z: webrender_bindings::bindings: Could not find symbol "glGetDebugMessageLog" by glcontext
12:57:05 INFO - WARN 2019-02-13T12:57:05Z: webrender_bindings::bindings: Could not find symbol "glGetDebugMessageLogARB" by glcontext
12:57:05 INFO - WARN 2019-02-13T12:57:05Z: webrender_bindings::bindings: Could not find symbol "glGetObjectLabel" by glcontext
12:57:05 INFO - WARN 2019-02-13T12:57:05Z: webrender_bindings::bindings: Could not find symbol "glGetObjectPtrLabel" by glcontext
12:57:05 INFO - WARN 2019-02-13T12:57:05Z: webrender_bindings::bindings: Could not find symbol "glObjectLabel" by glcontext
12:57:05 INFO - WARN 2019-02-13T12:57:05Z: webrender_bindings::bindings: Could not find symbol "glObjectPtrLabel" by glcontext
12:57:05 INFO - WARN 2019-02-13T12:57:05Z: webrender_bindings::bindings: Could not find symbol "glPopDebugGroup" by glcontext
12:57:05 INFO - WARN 2019-02-13T12:57:05Z: webrender_bindings::bindings: Could not find symbol "glPushDebugGroup" by glcontext
12:57:05 INFO - WARN 2019-02-13T12:57:05Z: webrender_bindings::bindings: Could not find symbol "glTextureStorage1DEXT" by glcontext
12:57:05 INFO - WARN 2019-02-13T12:57:05Z: webrender_bindings::bindings: Could not find symbol "glTextureStorage2DEXT" by glcontext
12:57:05 INFO - WARN 2019-02-13T12:57:05Z: webrender_bindings::bindings: Could not find symbol "glTextureStorage3DEXT" by glcontext
12:57:05 INFO - ++DOCSHELL 000001D90B777000 == 4 [pid = 2988] [id = {39d22657-06ab-445e-b737-4c6918e28952}]
12:57:05 INFO - ++DOMWINDOW == 8 (000001D90B715800) [pid = 2988] [serial = 8] [outer = 0000000000000000]
12:57:05 INFO - ++DOCSHELL 000001D90AE4E800 == 5 [pid = 2988] [id = {ce6d1fb3-9cc9-45f0-8503-804ea5c21f89}]
12:57:05 INFO - ++DOMWINDOW == 9 (000001D9084F0400) [pid = 2988] [serial = 9] [outer = 0000000000000000]
12:57:05 INFO - ++DOMWINDOW == 10 (000001D90BA9C800) [pid = 2988] [serial = 10] [outer = 000001D9084F0400]
12:57:05 INFO - ### XPCOM_MEM_BLOAT_LOG defined -- logging bloat/leaks to c:\users\task_1550060904\appdata\local\temp\tmp149flz.mozrunner\runreftest_leaks_tab_pid3360.log
12:57:05 INFO - [Child 3360, Main Thread] WARNING: No CID found when attempting to map contract ID: file z:/build/build/src/xpcom/components/nsComponentManager.cpp, line 744
12:57:05 INFO - ++DOMWINDOW == 11 (000001D90BAAB800) [pid = 2988] [serial = 11] [outer = 000001D9084F0400]
12:57:05 INFO - [Parent 2988, Main Thread] WARNING: Need TabChild to get the nativeWindow from!: file z:/build/build/src/widget/PuppetWidget.cpp, line 1078
12:57:05 INFO - [Parent 2988, Main Thread] WARNING: Need TabChild to get the nativeWindow from!: file z:/build/build/src/widget/PuppetWidget.cpp, line 1078
12:57:05 INFO - [Parent 2988, Main Thread] WARNING: Need TabChild to get the nativeWindow from!: file z:/build/build/src/widget/PuppetWidget.cpp, line 1078
12:57:05 INFO - [Parent 2988, Main Thread] WARNING: Need TabChild to get the nativeWindow from!: file z:/build/build/src/widget/PuppetWidget.cpp, line 1078
12:57:05 INFO - [Parent 2988, Main Thread] WARNING: Need TabChild to get the nativeWindow from!: file z:/build/build/src/widget/PuppetWidget.cpp, line 1078
12:57:06 INFO - ### XPCOM_MEM_BLOAT_LOG defined -- logging bloat/leaks to c:\users\task_1550060904\appdata\local\temp\tmp149flz.mozrunner\runreftest_leaks_tab_pid12016.log
12:57:06 INFO - [Child 12016, Main Thread] WARNING: No CID found when attempting to map contract ID: file z:/build/build/src/xpcom/components/nsComponentManager.cpp, line 744

Comment 1

[Intermittent Failures Robot]

1 failures in 2832 pushes (0.0 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• mozilla-central: 1

Platform breakdown:

• windows10-64-qr: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1527619&startday=2019-02-11&endday=2019-02-17&tree=all

Comment 2

[Firefox Bug Husbandry Bot]

https://wiki.mozilla.org/Bug_Triage#Intermittent_Test_Failure_Cleanup