Closed Bug 1674919 Opened 4 years ago Closed 4 years ago

Intermittent editor/libeditor/tests/test_bug549262.html | many other 5 mochites | Test timed out. | log contains Error: Unable to restore focus, expect failures and timeouts.

Categories

(Core :: DOM: Editor, defect, P5)

defect

Tracking

()

RESOLVED INCOMPLETE

People

(Reporter: intermittent-bug-filer, Unassigned)

References

Details

(Keywords: intermittent-failure)

Filed by: btara [at] mozilla.com
Parsed log: https://treeherder.mozilla.org/logviewer?job_id=320506354&repo=autoland
Full log: https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/A39iK1F-RdGyW0tK755XeQ/runs/0/artifacts/public/logs/live_backing.log


[task 2020-11-02T20:46:48.088Z] 20:46:48     INFO - TEST-START | editor/libeditor/tests/test_bug549262.html
[task 2020-11-02T20:46:48.227Z] 20:46:48     INFO - GECKO(8500) | [Parent 6884, Main Thread] WARNING: NS_ENSURE_TRUE(rootFrame) failed: file /builds/worker/checkouts/gecko/dom/base/nsGlobalWindowOuter.cpp:4282
[task 2020-11-02T20:46:48.369Z] 20:46:48     INFO - GECKO(8500) | [Parent 6884, Main Thread] WARNING: 'NS_FAILED(targetPrincipal->GetAsciiOrigin(targetOrigin))', file /builds/worker/checkouts/gecko/toolkit/components/antitracking/AntiTrackingUtils.cpp:347
[task 2020-11-02T20:46:48.408Z] 20:46:48     INFO - GECKO(8500) | [2020-11-02T20:46:48Z WARN  webrender_bindings::bindings] Could not find symbol "glBlendBarrierKHR" by glcontext
[task 2020-11-02T20:46:48.410Z] 20:46:48     INFO - GECKO(8500) | [2020-11-02T20:46:48Z WARN  webrender_bindings::bindings] Could not find symbol "glCopyImageSubDataEXT" by glcontext
[task 2020-11-02T20:46:48.410Z] 20:46:48     INFO - GECKO(8500) | [2020-11-02T20:46:48Z WARN  webrender_bindings::bindings] Could not find symbol "glDebugMessageCallback" by glcontext
[task 2020-11-02T20:46:48.411Z] 20:46:48     INFO - GECKO(8500) | [2020-11-02T20:46:48Z WARN  webrender_bindings::bindings] Could not find symbol "glDebugMessageCallbackARB" by glcontext
[task 2020-11-02T20:46:48.411Z] 20:46:48     INFO - GECKO(8500) | [2020-11-02T20:46:48Z WARN  webrender_bindings::bindings] Could not find symbol "glDebugMessageControl" by glcontext
[task 2020-11-02T20:46:48.411Z] 20:46:48     INFO - GECKO(8500) | [2020-11-02T20:46:48Z WARN  webrender_bindings::bindings] Could not find symbol "glDebugMessageControlARB" by glcontext
[task 2020-11-02T20:46:48.412Z] 20:46:48     INFO - GECKO(8500) | [2020-11-02T20:46:48Z WARN  webrender_bindings::bindings] Could not find symbol "glDebugMessageInsert" by glcontext
[task 2020-11-02T20:46:48.412Z] 20:46:48     INFO - GECKO(8500) | [2020-11-02T20:46:48Z WARN  webrender_bindings::bindings] Could not find symbol "glDebugMessageInsertARB" by glcontext
[task 2020-11-02T20:46:48.412Z] 20:46:48     INFO - GECKO(8500) | [2020-11-02T20:46:48Z WARN  webrender_bindings::bindings] Could not find symbol "glGetDebugMessageLog" by glcontext
[task 2020-11-02T20:46:48.412Z] 20:46:48     INFO - GECKO(8500) | [2020-11-02T20:46:48Z WARN  webrender_bindings::bindings] Could not find symbol "glGetDebugMessageLogARB" by glcontext
[task 2020-11-02T20:46:48.412Z] 20:46:48     INFO - GECKO(8500) | [2020-11-02T20:46:48Z WARN  webrender_bindings::bindings] Could not find symbol "glGetObjectLabel" by glcontext
[task 2020-11-02T20:46:48.413Z] 20:46:48     INFO - GECKO(8500) | [2020-11-02T20:46:48Z WARN  webrender_bindings::bindings] Could not find symbol "glGetObjectPtrLabel" by glcontext
[task 2020-11-02T20:46:48.413Z] 20:46:48     INFO - GECKO(8500) | [2020-11-02T20:46:48Z WARN  webrender_bindings::bindings] Could not find symbol "glObjectLabel" by glcontext
[task 2020-11-02T20:46:48.413Z] 20:46:48     INFO - GECKO(8500) | [2020-11-02T20:46:48Z WARN  webrender_bindings::bindings] Could not find symbol "glObjectPtrLabel" by glcontext
[task 2020-11-02T20:46:48.413Z] 20:46:48     INFO - GECKO(8500) | [2020-11-02T20:46:48Z WARN  webrender_bindings::bindings] Could not find symbol "glPopDebugGroup" by glcontext
[task 2020-11-02T20:46:48.413Z] 20:46:48     INFO - GECKO(8500) | [2020-11-02T20:46:48Z WARN  webrender_bindings::bindings] Could not find symbol "glPushDebugGroup" by glcontext
[task 2020-11-02T20:46:48.413Z] 20:46:48     INFO - GECKO(8500) | [2020-11-02T20:46:48Z WARN  webrender_bindings::bindings] Could not find symbol "glTextureStorage1DEXT" by glcontext
[task 2020-11-02T20:46:48.413Z] 20:46:48     INFO - GECKO(8500) | [2020-11-02T20:46:48Z WARN  webrender_bindings::bindings] Could not find symbol "glTextureStorage2DEXT" by glcontext
[task 2020-11-02T20:46:48.413Z] 20:46:48     INFO - GECKO(8500) | [2020-11-02T20:46:48Z WARN  webrender_bindings::bindings] Could not find symbol "glTextureStorage3DEXT" by glcontext
[task 2020-11-02T20:46:48.413Z] 20:46:48     INFO - GECKO(8500) | [2020-11-02T20:46:48Z WARN  webrender::device::gl] Missing optimized shader source for gpu_cache_update
[task 2020-11-02T20:46:48.439Z] 20:46:48     INFO - GECKO(8500) | [Parent 6884, Main Thread] WARNING: NS_ENSURE_TRUE(presShell) failed: file /builds/worker/checkouts/gecko/dom/base/nsGlobalWindowOuter.cpp:4280
[task 2020-11-02T20:46:48.740Z] 20:46:48     INFO - GECKO(8500) | [Child 10148, Main Thread] WARNING: mozInlineSpellCHecker::UpdateCurrentDictionary() failed, but ignored: 'NS_SUCCEEDED(rvIgnored)', file /builds/worker/checkouts/gecko/editor/libeditor/EditorBase.cpp:4635
[task 2020-11-02T20:46:48.759Z] 20:46:48     INFO - GECKO(8500) | PromiseApzRepaintsFlushed: Flushed APZ repaints, waiting for callback...
[task 2020-11-02T20:46:48.759Z] 20:46:48     INFO - GECKO(8500) | PromiseApzRepaintsFlushed: APZ flush done
[task 2020-11-02T20:46:48.805Z] 20:46:48     INFO - GECKO(8500) | [Child 10148, Main Thread] WARNING: NS_ENSURE_TRUE(info) failed: file /builds/worker/checkouts/gecko/extensions/permissions/PermissionDelegateHandler.cpp:348
[task 2020-11-02T20:46:48.805Z] 20:46:48     INFO - GECKO(8500) | [Child 10148, Main Thread] WARNING: NS_ENSURE_TRUE(info) failed: file /builds/worker/checkouts/gecko/extensions/permissions/PermissionDelegateHandler.cpp:348
[task 2020-11-02T20:46:48.885Z] 20:46:48     INFO - GECKO(8500) | PromiseApzRepaintsFlushed: Flushed APZ repaints, waiting for callback...
[task 2020-11-02T20:46:48.885Z] 20:46:48     INFO - GECKO(8500) | PromiseApzRepaintsFlushed: APZ flush done
[task 2020-11-02T20:46:48.889Z] 20:46:48     INFO - GECKO(8500) | [Child 10148, Main Thread] WARNING: Wrong inner/outer window combination!: file /builds/worker/checkouts/gecko/dom/base/Document.cpp:7201
[task 2020-11-02T20:46:48.948Z] 20:46:48     INFO - GECKO(8500) | PromiseApzRepaintsFlushed: Flushed APZ repaints, waiting for callback...
[task 2020-11-02T20:46:48.948Z] 20:46:48     INFO - GECKO(8500) | PromiseApzRepaintsFlushed: APZ flush done
[task 2020-11-02T20:46:48.986Z] 20:46:48     INFO - GECKO(8500) | [Child 10148, Main Thread] WARNING: mozInlineSpellCHecker::UpdateCurrentDictionary() failed, but ignored: 'NS_SUCCEEDED(rvIgnored)', file /builds/worker/checkouts/gecko/editor/libeditor/EditorBase.cpp:4635
[task 2020-11-02T20:46:49.024Z] 20:46:49     INFO - GECKO(8500) | PromiseApzRepaintsFlushed: Flushed APZ repaints, waiting for callback...
[task 2020-11-02T20:46:49.024Z] 20:46:49     INFO - GECKO(8500) | PromiseApzRepaintsFlushed: APZ flush done
[task 2020-11-02T20:46:49.049Z] 20:46:49     INFO - GECKO(8500) | [Child 5500, Main Thread] WARNING: '!aContent->GetComposedDoc()', file /builds/worker/checkouts/gecko/layout/base/nsCSSFrameConstructor.cpp:8490
[task 2020-11-02T20:46:49.049Z] 20:46:49     INFO - GECKO(8500) | [Child 5500, Main Thread] WARNING: '!aContent->GetComposedDoc()', file /builds/worker/checkouts/gecko/layout/base/nsCSSFrameConstructor.cpp:8490
[task 2020-11-02T20:46:49.049Z] 20:46:49     INFO - GECKO(8500) | [Child 5500, Main Thread] WARNING: '!aContent->GetComposedDoc()', file /builds/worker/checkouts/gecko/layout/base/nsCSSFrameConstructor.cpp:8490
[task 2020-11-02T20:46:49.051Z] 20:46:49     INFO - GECKO(8500) | [Child 5500, Main Thread] WARNING: '!aContent->GetComposedDoc()', file /builds/worker/checkouts/gecko/layout/base/nsCSSFrameConstructor.cpp:8490
[task 2020-11-02T20:46:49.053Z] 20:46:49     INFO - GECKO(8500) | [Child 5500, Main Thread] WARNING: '!aContent->GetComposedDoc()', file /builds/worker/checkouts/gecko/layout/base/nsCSSFrameConstructor.cpp:8490
[task 2020-11-02T20:46:49.053Z] 20:46:49     INFO - GECKO(8500) | [Child 5500, Main Thread] WARNING: '!aContent->GetComposedDoc()', file /builds/worker/checkouts/gecko/layout/base/nsCSSFrameConstructor.cpp:8490
[task 2020-11-02T20:47:52.536Z] 20:47:52     INFO - GECKO(8500) | [Parent 6884, Jump List] WARNING: NS_ENSURE_SUCCESS(rv, rv) failed with result 0x80520012 (NS_ERROR_FILE_NOT_FOUND): file /builds/worker/checkouts/gecko/widget/windows/WinUtils.cpp:1391
[task 2020-11-02T20:49:52.557Z] 20:49:52     INFO - GECKO(8500) | [Parent 6884, Jump List] WARNING: NS_ENSURE_SUCCESS(rv, rv) failed with result 0x80520012 (NS_ERROR_FILE_NOT_FOUND): file /builds/worker/checkouts/gecko/widget/windows/WinUtils.cpp:1391
[task 2020-11-02T20:51:48.017Z] 20:51:48     INFO -  [2116, Main Thread] WARNING: NS_ENSURE_SUCCESS(rv, rv) failed with result 0x80004005 (NS_ERROR_FAILURE): file /builds/worker/checkouts/gecko/toolkit/components/places/Database.cpp:538
[task 2020-11-02T20:51:48.017Z] 20:51:48     INFO -  [2116, Main Thread] WARNING: Unable to get a connection to vacuum database: file /builds/worker/checkouts/gecko/storage/VacuumManager.cpp:129
[task 2020-11-02T20:51:48.057Z] 20:51:48     INFO -  [2116, IPDL Background] WARNING: '!gBasePath', file /builds/worker/checkouts/gecko/dom/quota/ActorsParent.cpp:3640
[task 2020-11-02T20:51:48.057Z] 20:51:48     INFO -  [2116, IPDL Background] WARNING: profile-do-change must precede QuotaManager::GetOrCreate(): file /builds/worker/checkouts/gecko/dom/quota/ActorsParent.cpp:3641
[task 2020-11-02T20:51:48.057Z] 20:51:48     INFO -  [2116, IPDL Background] WARNING: '!quotaManager', file /builds/worker/checkouts/gecko/dom/quota/ActorsParent.cpp:8527
[task 2020-11-02T20:51:54.089Z] 20:51:54     INFO - TEST-INFO | started process screenshot
[task 2020-11-02T20:51:54.152Z] 20:51:54     INFO - TEST-INFO | screenshot: exit 0
[task 2020-11-02T20:51:54.152Z] 20:51:54     INFO - Buffered messages logged at 20:46:48
[task 2020-11-02T20:51:54.153Z] 20:51:54     INFO - must wait for load
[task 2020-11-02T20:51:54.154Z] 20:51:54     INFO - must wait for focus
[task 2020-11-02T20:51:54.154Z] 20:51:54     INFO - TEST-PASS | editor/libeditor/tests/test_bug549262.html | Sanity check 
[task 2020-11-02T20:51:54.154Z] 20:51:54     INFO - TEST-PASS | editor/libeditor/tests/test_bug549262.html | Page is scrolled down 
[task 2020-11-02T20:51:54.155Z] 20:51:54     INFO - TEST-PASS | editor/libeditor/tests/test_bug549262.html | The content of the editable element has not changed 
[task 2020-11-02T20:51:54.155Z] 20:51:54     INFO - TEST-PASS | editor/libeditor/tests/test_bug549262.html | Page is scrolled up 
[task 2020-11-02T20:51:54.156Z] 20:51:54     INFO - TEST-PASS | editor/libeditor/tests/test_bug549262.html | The content of the editable element has not changed 
[task 2020-11-02T20:51:54.156Z] 20:51:54     INFO - TEST-PASS | editor/libeditor/tests/test_bug549262.html | check that we didn't get a scroll 
[task 2020-11-02T20:51:54.156Z] 20:51:54     INFO - TEST-PASS | editor/libeditor/tests/test_bug549262.html | Page is not scrolled down 
[task 2020-11-02T20:51:54.156Z] 20:51:54     INFO - TEST-PASS | editor/libeditor/tests/test_bug549262.html | The content of the editable element has changed 
[task 2020-11-02T20:51:54.156Z] 20:51:54     INFO - Buffered messages finished
[task 2020-11-02T20:51:54.156Z] 20:51:54     INFO - TEST-UNEXPECTED-FAIL | editor/libeditor/tests/test_bug549262.html | Test timed out. 
[task 2020-11-02T20:51:54.156Z] 20:51:54     INFO -     SimpleTest.ok@SimpleTest/SimpleTest.js:417:16
[task 2020-11-02T20:51:54.156Z] 20:51:54     INFO -     reportError@SimpleTest/TestRunner.js:143:22
[task 2020-11-02T20:51:54.157Z] 20:51:54     INFO -     TestRunner._checkForHangs@SimpleTest/TestRunner.js:165:18
[task 2020-11-02T20:51:55.129Z] 20:51:55     INFO - GECKO(8500) | MEMORY STAT | vsize 2104025MB | vsizeMaxContiguous 66722026MB | residentFast 127MB | heapAllocated 10MB
[task 2020-11-02T20:51:55.148Z] 20:51:55     INFO - TEST-OK | editor/libeditor/tests/test_bug549262.html | took 307066ms
[task 2020-11-02T20:51:58.156Z] 20:51:58     INFO - Error: Unable to restore focus, expect failures and timeouts.
[task 2020-11-02T20:51:58.181Z] 20:51:58     INFO - TEST-START | editor/libeditor/tests/test_bug550434.html
[task 2020-11-02T20:56:19.366Z] 20:56:19     INFO - GECKO(8500) | 1604350579357	addons.xpi	ERROR	System addon update list error Error: got node name: html, expected: updates
[task 2020-11-02T20:57:24.220Z] 20:57:24     INFO - Not taking screenshot here: see the one that was previously logged
[task 2020-11-02T20:57:24.221Z] 20:57:24     INFO - Buffered messages logged at 20:52:01
[task 2020-11-02T20:57:24.221Z] 20:57:24     INFO - Error: Unable to restore focus, expect failures and timeouts.
[task 2020-11-02T20:57:24.222Z] 20:57:24     INFO - must wait for load
[task 2020-11-02T20:57:24.222Z] 20:57:24     INFO - must wait for focus
[task 2020-11-02T20:57:24.222Z] 20:57:24     INFO - Buffered messages finished
[task 2020-11-02T20:57:24.222Z] 20:57:24     INFO - TEST-UNEXPECTED-FAIL | editor/libeditor/tests/test_bug550434.html | Test timed out. 
[task 2020-11-02T20:57:24.222Z] 20:57:24     INFO -     SimpleTest.ok@SimpleTest/SimpleTest.js:417:16
[task 2020-11-02T20:57:24.223Z] 20:57:24     INFO -     reportError@SimpleTest/TestRunner.js:143:22
[task 2020-11-02T20:57:24.223Z] 20:57:24     INFO -     TestRunner._checkForHangs@SimpleTest/TestRunner.js:165:18
[task 2020-11-02T20:57:25.228Z] 20:57:25     INFO - Not taking screenshot here: see the one that was previously logged
[task 2020-11-02T20:57:25.228Z] 20:57:25     INFO - TEST-UNEXPECTED-FAIL | editor/libeditor/tests/test_bug550434.html | [SimpleTest.finish()] waitForFocus() was called a different number of times from the number of callbacks run.  Maybe the test terminated prematurely -- be sure to use SimpleTest.waitForExplicitFinish(). - got 1, expected +0
[task 2020-11-02T20:57:25.228Z] 20:57:25     INFO -     SimpleTest.is@SimpleTest/SimpleTest.js:500:14
[task 2020-11-02T20:57:25.228Z] 20:57:25     INFO -     afterCleanup@SimpleTest/SimpleTest.js:1537:18
[task 2020-11-02T20:57:25.228Z] 20:57:25     INFO -     executeCleanupFunction@SimpleTest/SimpleTest.js:1613:7
[task 2020-11-02T20:57:25.229Z] 20:57:25     INFO -     SimpleTest.finish@SimpleTest/SimpleTest.js:1633:3
[task 2020-11-02T20:57:25.229Z] 20:57:25     INFO -     killTest@SimpleTest/TestRunner.js:152:22
[task 2020-11-02T20:57:25.269Z] 20:57:25     INFO - GECKO(8500) | MEMORY STAT | vsize 2104025MB | vsizeMaxContiguous 66722026MB | residentFast 127MB | heapAllocated 10MB
[task 2020-11-02T20:57:25.286Z] 20:57:25     INFO - TEST-OK | editor/libeditor/tests/test_bug550434.html | took 327096ms
[task 2020-11-02T20:57:28.286Z] 20:57:28     INFO - Error: Unable to restore focus, expect failures and timeouts.
[task 2020-11-02T20:57:28.296Z] 20:57:28    ERROR - TEST-UNEXPECTED-FAIL | /tests/editor/libeditor/tests/test_bug550434.html logged result after SimpleTest.finish(): [SimpleTest.finish()] waitForFocus() was called a different number of times from the number of callbacks run.  Maybe the test terminated prematurely -- be sure to use SimpleTest.waitForExplicitFinish().
[task 2020-11-02T20:57:28.314Z] 20:57:28     INFO - TEST-START | editor/libeditor/tests/test_bug551704.html
[task 2020-11-02T21:00:48.264Z] 21:00:48     INFO -  JavaScript error: resource://gre/modules/PlacesExpiration.jsm, line 895: TypeError: can't access property "createAsyncStatement", this._db is undefined
[task 2020-11-02T21:02:54.334Z] 21:02:54     INFO - Not taking screenshot here: see the one that was previously logged
[task 2020-11-02T21:02:54.334Z] 21:02:54     INFO - Buffered messages logged at 20:57:31
[task 2020-11-02T21:02:54.334Z] 21:02:54     INFO - Error: Unable to restore focus, expect failures and timeouts.
[task 2020-11-02T21:02:54.335Z] 21:02:54     INFO - must wait for load
[task 2020-11-02T21:02:54.335Z] 21:02:54     INFO - must wait for focus
[task 2020-11-02T21:02:54.335Z] 21:02:54     INFO - Buffered messages finished
[task 2020-11-02T21:02:54.335Z] 21:02:54     INFO - TEST-UNEXPECTED-FAIL | editor/libeditor/tests/test_bug551704.html | Test timed out. 
[task 2020-11-02T21:02:54.336Z] 21:02:54     INFO -     SimpleTest.ok@SimpleTest/SimpleTest.js:417:16
[task 2020-11-02T21:02:54.336Z] 21:02:54     INFO -     reportError@SimpleTest/TestRunner.js:143:22
[task 2020-11-02T21:02:54.336Z] 21:02:54     INFO -     TestRunner._checkForHangs@SimpleTest/TestRunner.js:165:18
[task 2020-11-02T21:02:55.344Z] 21:02:55     INFO - Not taking screenshot here: see the one that was previously logged
[task 2020-11-02T21:02:55.344Z] 21:02:55     INFO - TEST-UNEXPECTED-FAIL | editor/libeditor/tests/test_bug551704.html | [SimpleTest.finish()] waitForFocus() was called a different number of times from the number of callbacks run.  Maybe the test terminated prematurely -- be sure to use SimpleTest.waitForExplicitFinish(). - got 1, expected +0
[task 2020-11-02T21:02:55.344Z] 21:02:55     INFO -     SimpleTest.is@SimpleTest/SimpleTest.js:500:14
...```
Status: NEW → RESOLVED
Closed: 4 years ago
Resolution: --- → INCOMPLETE
You need to log in before you can comment on or make changes to this bug.