Closed Bug 1721570 Opened 5 years ago Closed 4 years ago

Intermittent TV editor/spellchecker/tests/test_bug<random number>.html | Test timed out. - | followed by [SimpleTest.finish()] No checks actually run. (You need to call ok(), is(), or similar functions at least once. Make sure you use SimpleTest.wait...

Categories

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

defect

Tracking

()

RESOLVED INCOMPLETE
Tracking Status
firefox-esr78 --- unaffected
firefox90 --- unaffected
firefox91 --- unaffected
firefox92 --- affected

People

(Reporter: intermittent-bug-filer, Unassigned)

References

(Regression)

Details

(Keywords: intermittent-failure, regression)

Filed by: imoraru [at] mozilla.com
Parsed log: https://treeherder.mozilla.org/logviewer?job_id=345852752&repo=autoland
Full log: https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/GhbQV52fStKBpS78XHCSoQ/runs/0/artifacts/public/logs/live_backing.log
Reftest URL: https://hg.mozilla.org/mozilla-central/raw-file/tip/layout/tools/reftest/reftest-analyzer.xhtml#logurl=https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/GhbQV52fStKBpS78XHCSoQ/runs/0/artifacts/public/logs/live_backing.log&only_show_unexpected=1


[task 2021-07-21T06:14:50.443Z] 06:14:50     INFO - TEST-START | editor/spellchecker/tests/test_bug1602526.html
[task 2021-07-21T06:14:51.473Z] 06:14:51     INFO - GECKO(1553) | [Child 1622, Main Thread] WARNING: early callback, or time went backwards: '!aAllowIdleDispatch', file /builds/worker/checkouts/gecko/xpcom/threads/IdleTaskRunner.cpp:179
[task 2021-07-21T06:14:51.518Z] 06:14:51     INFO - GECKO(1553) | [Child 1622, Main Thread] WARNING: early callback, or time went backwards: '!aAllowIdleDispatch', file /builds/worker/checkouts/gecko/xpcom/threads/IdleTaskRunner.cpp:179
[task 2021-07-21T06:14:51.531Z] 06:14:51     INFO - GECKO(1553) | [Child 1622, Main Thread] WARNING: early callback, or time went backwards: '!aAllowIdleDispatch', file /builds/worker/checkouts/gecko/xpcom/threads/IdleTaskRunner.cpp:179
[task 2021-07-21T06:14:52.286Z] 06:14:52     INFO - GECKO(1553) | [Child 1622, Main Thread] WARNING: '!aChild->IsContent()', file /builds/worker/workspace/obj-build/dist/include/mozilla/EditorDOMPoint.h:460
[task 2021-07-21T06:14:52.355Z] 06:14:52     INFO - GECKO(1553) | [Child 1622, Main Thread] WARNING: NS_ENSURE_TRUE(info) failed: file /builds/worker/checkouts/gecko/extensions/permissions/PermissionDelegateHandler.cpp:348
[task 2021-07-21T06:14:55.078Z] 06:14:55     INFO - GECKO(1553) | MEMORY STAT vsizeMaxContiguous not supported in this build configuration.
[task 2021-07-21T06:14:55.081Z] 06:14:55     INFO - GECKO(1553) | MEMORY STAT | vsize 2537MB | residentFast 150MB | heapAllocated 8MB
[task 2021-07-21T06:14:55.098Z] 06:14:55     INFO - TEST-OK | editor/spellchecker/tests/test_bug1602526.html | took 4656ms
[task 2021-07-21T06:14:55.170Z] 06:14:55     INFO - TEST-START | Shutdown
[task 2021-07-21T06:14:55.171Z] 06:14:55     INFO - Passed:  3
[task 2021-07-21T06:14:55.172Z] 06:14:55     INFO - Failed:  0
[task 2021-07-21T06:14:55.173Z] 06:14:55     INFO - Todo:    0
[task 2021-07-21T06:14:55.174Z] 06:14:55     INFO - Mode:    e10s
[task 2021-07-21T06:14:55.175Z] 06:14:55     INFO - Slowest: 4656ms - /tests/editor/spellchecker/tests/test_bug1602526.html
[task 2021-07-21T06:14:55.176Z] 06:14:55     INFO - SimpleTest START Loop 2
<...>
[task 2021-07-21T06:18:40.074Z] 06:18:40     INFO - SimpleTest START
[task 2021-07-21T06:18:40.087Z] 06:18:40     INFO - TEST-START | editor/spellchecker/tests/test_bug1602526.html
[task 2021-07-21T06:18:40.353Z] 06:18:40     INFO - GECKO(3836) | ### XPCOM_MEM_BLOAT_LOG defined -- logging bloat/leaks to /tmp/tmpu7zm3325.mozrunner/runtests_leaks_tab_pid4005.log
[task 2021-07-21T06:18:40.355Z] 06:18:40     INFO - GECKO(3836) | [4005, Main Thread] WARNING: XPCOM_MEM_BLOAT_LOG is set, disabling native allocations.: file /builds/worker/checkouts/gecko/tools/profiler/core/platform.cpp:250
[task 2021-07-21T06:18:40.376Z] 06:18:40     INFO - GECKO(3836) | [Child 4005, Main Thread] WARNING: could not set real-time limit in CubebUtils::InitLibrary: file /builds/worker/checkouts/gecko/dom/media/CubebUtils.cpp:619
[task 2021-07-21T06:18:41.221Z] 06:18:41     INFO - GECKO(3836) | [Child 3893, Main Thread] WARNING: early callback, or time went backwards: '!aAllowIdleDispatch', file /builds/worker/checkouts/gecko/xpcom/threads/IdleTaskRunner.cpp:179
[task 2021-07-21T06:18:41.253Z] 06:18:41     INFO - GECKO(3836) | [Child 3893, Main Thread] WARNING: early callback, or time went backwards: '!aAllowIdleDispatch', file /builds/worker/checkouts/gecko/xpcom/threads/IdleTaskRunner.cpp:179
[task 2021-07-21T06:18:42.122Z] 06:18:42     INFO - GECKO(3836) | [Child 3893, Main Thread] WARNING: '!aChild->IsContent()', file /builds/worker/workspace/obj-build/dist/include/mozilla/EditorDOMPoint.h:460
[task 2021-07-21T06:18:42.212Z] 06:18:42     INFO - GECKO(3836) | [Child 3893, Main Thread] WARNING: NS_ENSURE_TRUE(info) failed: file /builds/worker/checkouts/gecko/extensions/permissions/PermissionDelegateHandler.cpp:348
[task 2021-07-21T06:24:10.088Z] 06:24:10     INFO - TEST-INFO | started process screentopng
[task 2021-07-21T06:24:10.299Z] 06:24:10     INFO - TEST-INFO | screentopng: exit 0
[task 2021-07-21T06:24:10.299Z] 06:24:10     INFO - Buffered messages logged at 06:18:42
[task 2021-07-21T06:24:10.299Z] 06:24:10     INFO - must wait for load
[task 2021-07-21T06:24:10.299Z] 06:24:10     INFO - Buffered messages finished
[task 2021-07-21T06:24:10.299Z] 06:24:10     INFO - TEST-UNEXPECTED-FAIL | editor/spellchecker/tests/test_bug1602526.html | Test timed out. - 
[task 2021-07-21T06:24:11.096Z] 06:24:11     INFO - Not taking screenshot here: see the one that was previously logged
[task 2021-07-21T06:24:11.096Z] 06:24:11     INFO - TEST-UNEXPECTED-FAIL | editor/spellchecker/tests/test_bug1602526.html | [SimpleTest.finish()] No checks actually run. (You need to call ok(), is(), or similar functions at least once.  Make sure you use SimpleTest.waitForExplicitFinish() if you need it.) 
[task 2021-07-21T06:24:11.097Z] 06:24:11     INFO -     SimpleTest.ok@SimpleTest/SimpleTest.js:417:16
[task 2021-07-21T06:24:11.097Z] 06:24:11     INFO -     afterCleanup@SimpleTest/SimpleTest.js:1423:18
[task 2021-07-21T06:24:11.097Z] 06:24:11     INFO -     executeCleanupFunction@SimpleTest/SimpleTest.js:1488:7
[task 2021-07-21T06:24:11.097Z] 06:24:11     INFO -     SimpleTest.finish@SimpleTest/SimpleTest.js:1508:3
[task 2021-07-21T06:24:11.097Z] 06:24:11     INFO -     killTest@SimpleTest/TestRunner.js:194:22
[task 2021-07-21T06:24:11.111Z] 06:24:11     INFO - GECKO(3836) | MEMORY STAT vsizeMaxContiguous not supported in this build configuration.
[task 2021-07-21T06:24:11.113Z] 06:24:11     INFO - GECKO(3836) | MEMORY STAT | vsize 3436MB | residentFast 1046MB | heapAllocated 897MB
[task 2021-07-21T06:24:40.088Z] 06:24:40     INFO - Not taking screenshot here: see the one that was previously logged
[task 2021-07-21T06:24:40.089Z] 06:24:40     INFO - TEST-UNEXPECTED-FAIL | editor/spellchecker/tests/test_bug1602526.html | Test timed out. - 
[task 2021-07-21T06:24:41.089Z] 06:24:41    ERROR - TEST-UNEXPECTED-FAIL | SimpleTest | this test already called finish!
[task 2021-07-21T06:24:41.095Z] 06:24:41     INFO - TEST-UNEXPECTED-ERROR | editor/spellchecker/tests/test_bug1602526.html | called finish() multiple times
[task 2021-07-21T06:24:41.095Z] 06:24:41     INFO - TEST-INFO took 361008ms
[task 2021-07-21T06:25:10.089Z] 06:25:10     INFO - Not taking screenshot here: see the one that was previously logged
[task 2021-07-21T06:25:10.089Z] 06:25:10     INFO - TEST-UNEXPECTED-FAIL | editor/spellchecker/tests/test_bug1602526.html | Test timed out. - 
[task 2021-07-21T06:25:11.089Z] 06:25:11    ERROR - TEST-UNEXPECTED-FAIL | SimpleTest | this test already called finish!
[task 2021-07-21T06:25:11.094Z] 06:25:11     INFO - TEST-UNEXPECTED-ERROR | editor/spellchecker/tests/test_bug1602526.html | called finish() multiple times
[task 2021-07-21T06:25:11.095Z] 06:25:11     INFO - TEST-INFO 
[task 2021-07-21T06:25:40.090Z] 06:25:40     INFO - Not taking screenshot here: see the one that was previously logged
[task 2021-07-21T06:25:40.090Z] 06:25:40     INFO - TEST-UNEXPECTED-FAIL | editor/spellchecker/tests/test_bug1602526.html | Test timed out. - 
[task 2021-07-21T06:25:40.091Z] 06:25:40     INFO - Not taking screenshot here: see the one that was previously logged
[task 2021-07-21T06:25:40.092Z] 06:25:40     INFO - TEST-UNEXPECTED-FAIL | (SimpleTest/TestRunner.js) | 4 test timeouts, giving up. - 
[task 2021-07-21T06:25:40.093Z] 06:25:40     INFO - Not taking screenshot here: see the one that was previously logged
[task 2021-07-21T06:25:40.093Z] 06:25:40     INFO - TEST-UNEXPECTED-FAIL | (SimpleTest/TestRunner.js) | Skipping 1 remaining tests. - 
[task 2021-07-21T06:25:41.091Z] 06:25:41    ERROR - TEST-UNEXPECTED-FAIL | SimpleTest | this test already called finish!
[task 2021-07-21T06:25:41.095Z] 06:25:41     INFO - TEST-UNEXPECTED-ERROR | (SimpleTest/TestRunner.js) | called finish() multiple times
[task 2021-07-21T06:25:41.095Z] 06:25:41     INFO - TEST-INFO 
[task 2021-07-21T06:26:59.819Z] 06:26:59     INFO - GECKO(3836) | 1626848819817	addons.xpi	ERROR	System addon update list error Error: got node name: html, expected: updates
[task 2021-07-21T06:33:09.836Z] 06:33:09     INFO - Buffered messages finished
[task 2021-07-21T06:33:09.836Z] 06:33:09    ERROR - TEST-UNEXPECTED-TIMEOUT | (SimpleTest/TestRunner.js) (finished) | application timed out after 370 seconds with no output
[task 2021-07-21T06:33:09.836Z] 06:33:09    ERROR - Force-terminating active process(es).
[task 2021-07-21T06:33:09.837Z] 06:33:09     INFO - Determining child pids from psutil...
[task 2021-07-21T06:33:09.842Z] 06:33:09     INFO - [3893, 3914, 3970, 4005]
[task 2021-07-21T06:33:09.843Z] 06:33:09     INFO - ==> process 3836 launched child process 3854
<...>

Set release status flags based on info from the regressing bug 1721323

Status: NEW → RESOLVED
Closed: 4 years ago
Resolution: --- → INCOMPLETE
Has Regression Range: --- → yes
You need to log in before you can comment on or make changes to this bug.