1761074 - Intermittent TV editor/spellchecker/tests/test_bug1497480.html | Test timed out. | [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

Status: RESOLVED INCOMPLETE

(Core :: Spelling checker, defect, P5)

Description

[Treeherder Bug Filer]

Filed by: mlaza [at] mozilla.com
Parsed log: https://treeherder.mozilla.org/logviewer?job_id=372067018&repo=autoland
Full log: https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/RRHZvAI6QpyUKaHGKkf05Q/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/RRHZvAI6QpyUKaHGKkf05Q/runs/0/artifacts/public/logs/live_backing.log&only_show_unexpected=1

---

[task 2022-03-23T14:17:42.113Z] 14:17:42     INFO - TEST-START | editor/spellchecker/tests/test_bug1497480.html
[task 2022-03-23T14:17:42.682Z] 14:17:42     INFO - GECKO(3650) | 2022-03-23 14:17:42.681 firefox[3650:51416] Persistent UI failed to open file file:///Users/cltbld/Library/Saved%20Application%20State/org.mozilla.nightlydebug.savedState/window_1.data: No such file or directory (2)
[task 2022-03-23T14:17:42.916Z] 14:17:42     INFO - GECKO(3650) | ### XPCOM_MEM_BLOAT_LOG defined -- logging bloat/leaks to /var/folders/40/r3s4v7650l5_ctg0b7p2x2_r000014/T/tmpzzs4qvdx.mozrunner/runtests_leaks_tab_pid3675.log
[task 2022-03-23T14:17:42.916Z] 14:17:42     INFO - GECKO(3650) | [3675, Main Thread] WARNING: XPCOM_MEM_BLOAT_LOG is set, disabling native allocations.: file /builds/worker/checkouts/gecko/tools/profiler/core/platform.cpp:283
[task 2022-03-23T14:17:44.273Z] 14:17:44     INFO - GECKO(3650) | [Child 3658, Main Thread] WARNING: nsAppShell::Exit() called redundantly: file /builds/worker/checkouts/gecko/widget/cocoa/nsAppShell.mm:823
[task 2022-03-23T14:17:44.291Z] 14:17:44     INFO - GECKO(3650) | ###!!! [Parent][PCompositorManagerParent] Error: RunMessage(msgname=PCompositorBridge::Msg___delete__) Channel closing: too late to send/recv, messages will be lost
[task 2022-03-23T14:17:44.292Z] 14:17:44     INFO - GECKO(3650) | [Child 3658, Main Thread] WARNING: IPC message 'PIdleScheduler::Msg_StartedGC' discarded: actor cannot send: file /builds/worker/checkouts/gecko/ipc/glue/ProtocolUtils.cpp:506
[task 2022-03-23T14:17:44.296Z] 14:17:44     INFO - GECKO(3650) | [Child 3658, Main Thread] WARNING: IPC message 'PIdleScheduler::Msg_DoneGC' discarded: actor cannot send: file /builds/worker/checkouts/gecko/ipc/glue/ProtocolUtils.cpp:506
[task 2022-03-23T14:17:44.297Z] 14:17:44     INFO - GECKO(3650) | ###!!! [Parent][PImageBridgeParent] Error: RunMessage(msgname=PImageBridge::Msg_WillClose) Channel closing: too late to send/recv, messages will be lost
[task 2022-03-23T14:17:44.300Z] 14:17:44     INFO - GECKO(3650) | [Child 3658, Main Thread] WARNING: IPC message 'PIdleScheduler::Msg_StartedGC' discarded: actor cannot send: file /builds/worker/checkouts/gecko/ipc/glue/ProtocolUtils.cpp:506
[task 2022-03-23T14:17:44.302Z] 14:17:44     INFO - GECKO(3650) | [Child 3658, Main Thread] WARNING: IPC message 'PIdleScheduler::Msg_DoneGC' discarded: actor cannot send: file /builds/worker/checkouts/gecko/ipc/glue/ProtocolUtils.cpp:506
[task 2022-03-23T14:17:44.304Z] 14:17:44     INFO - GECKO(3650) | [Child 3658, Main Thread] WARNING: Extra shutdown CC: 'i < NORMAL_SHUTDOWN_COLLECTIONS', file /builds/worker/checkouts/gecko/xpcom/base/nsCycleCollector.cpp:3359
[task 2022-03-23T14:17:44.305Z] 14:17:44     INFO - GECKO(3650) | [Child 3658, Main Thread] WARNING: NS_ENSURE_TRUE(InitStaticMembers()) failed: file /builds/worker/workspace/obj-build/dist/include/mozilla/Preferences.h:128
[task 2022-03-23T14:17:44.306Z] 14:17:44     INFO - GECKO(3650) | [Child 3658, Main Thread] WARNING: IPC message 'PIdleScheduler::Msg_StartedGC' discarded: actor cannot send: file /builds/worker/checkouts/gecko/ipc/glue/ProtocolUtils.cpp:506
[task 2022-03-23T14:17:44.307Z] 14:17:44     INFO - GECKO(3650) | [Child 3658, Main Thread] WARNING: IPC message 'PIdleScheduler::Msg_DoneGC' discarded: actor cannot send: file /builds/worker/checkouts/gecko/ipc/glue/ProtocolUtils.cpp:506
[task 2022-03-23T14:17:44.307Z] 14:17:44     INFO - GECKO(3650) | [Child 3658, Main Thread] WARNING: IPC message 'PIdleScheduler::Msg_StartedGC' discarded: actor cannot send: file /builds/worker/checkouts/gecko/ipc/glue/ProtocolUtils.cpp:506
[task 2022-03-23T14:17:44.308Z] 14:17:44     INFO - GECKO(3650) | [Child 3658, Main Thread] WARNING: IPC message 'PIdleScheduler::Msg_DoneGC' discarded: actor cannot send: file /builds/worker/checkouts/gecko/ipc/glue/ProtocolUtils.cpp:506
[task 2022-03-23T14:17:44.310Z] 14:17:44     INFO - GECKO(3650) | [Child 3658, Main Thread] WARNING: NS_ENSURE_TRUE(Preferences::InitStaticMembers()) failed: file /builds/worker/checkouts/gecko/modules/libpref/Preferences.cpp:4465
[task 2022-03-23T14:17:49.550Z] 14:17:49     INFO - GECKO(3650) | [Child 3668, Main Thread] WARNING: early callback, or time went backwards: '!aAllowIdleDispatch', file /builds/worker/checkouts/gecko/xpcom/threads/IdleTaskRunner.cpp:197
[task 2022-03-23T14:22:42.187Z] 14:22:42     INFO - TEST-INFO | started process screencapture
[task 2022-03-23T14:22:42.308Z] 14:22:42     INFO - TEST-INFO | screencapture: exit 0
[task 2022-03-23T14:22:42.308Z] 14:22:42     INFO - Buffered messages logged at 14:17:45
[task 2022-03-23T14:22:42.308Z] 14:22:42     INFO - add_task | Entering test 
[task 2022-03-23T14:22:42.309Z] 14:22:42     INFO - Buffered messages finished
[task 2022-03-23T14:22:42.309Z] 14:22:42     INFO - TEST-UNEXPECTED-FAIL | editor/spellchecker/tests/test_bug1497480.html | Test timed out. - 
[task 2022-03-23T14:22:43.192Z] 14:22:43     INFO - Not taking screenshot here: see the one that was previously logged
[task 2022-03-23T14:22:43.192Z] 14:22:43     INFO - TEST-UNEXPECTED-FAIL | editor/spellchecker/tests/test_bug1497480.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 2022-03-23T14:22:43.192Z] 14:22:43     INFO -     SimpleTest.ok@SimpleTest/SimpleTest.js:417:16
[task 2022-03-23T14:22:43.192Z] 14:22:43     INFO -     afterCleanup@SimpleTest/SimpleTest.js:1416:18
[task 2022-03-23T14:22:43.192Z] 14:22:43     INFO -     executeCleanupFunction@SimpleTest/SimpleTest.js:1481:7
[task 2022-03-23T14:22:43.193Z] 14:22:43     INFO -     SimpleTest.finish@SimpleTest/SimpleTest.js:1501:3
[task 2022-03-23T14:22:43.193Z] 14:22:43     INFO -     killTest@SimpleTest/TestRunner.js:194:22
[task 2022-03-23T14:22:43.200Z] 14:22:43     INFO - GECKO(3650) | MEMORY STAT vsizeMaxContiguous not supported in this build configuration.
[task 2022-03-23T14:22:43.201Z] 14:22:43     INFO - GECKO(3650) | MEMORY STAT | vsize 8248MB | residentFast 1698MB | heapAllocated 1612MB
[task 2022-03-23T14:25:38.080Z] 14:25:38     INFO - GECKO(3650) | 1648045538079	addons.xpi	ERROR	System addon update list error Error: got node name: html, expected: updates
[task 2022-03-23T14:31:48.099Z] 14:31:48     INFO - Buffered messages finished
[task 2022-03-23T14:31:48.100Z] 14:31:48    ERROR - TEST-UNEXPECTED-TIMEOUT | editor/spellchecker/tests/test_bug1497480.html | application timed out after 370 seconds with no output
[task 2022-03-23T14:31:48.100Z] 14:31:48    ERROR - Force-terminating active process(es).
[task 2022-03-23T14:31:48.100Z] 14:31:48     INFO - Determining child pids from psutil...
[task 2022-03-23T14:31:48.102Z] 14:31:48     INFO - [3657, 3667, 3668, 3669, 3670, 3675]
[task 2022-03-23T14:31:48.102Z] 14:31:48     INFO - ==> process 3650 launched child process 3657
[task 2022-03-23T14:31:48.103Z] 14:31:48     INFO - ==> process 3650 launched child process 3658
[task 2022-03-23T14:31:48.103Z] 14:31:48     INFO - ==> process 3650 launched child process 3667
[task 2022-03-23T14:31:48.103Z] 14:31:48     INFO - ==> process 3650 launched child process 3668
[task 2022-03-23T14:31:48.104Z] 14:31:48     INFO - ==> process 3650 launched child process 3669
[task 2022-03-23T14:31:48.104Z] 14:31:48     INFO - ==> process 3650 launched child process 3670
[task 2022-03-23T14:31:48.104Z] 14:31:48     INFO - ==> process 3650 launched child process 3675
[task 2022-03-23T14:31:48.104Z] 14:31:48     INFO - Found child pids: {3657, 3658, 3667, 3668, 3669, 3670, 3675}
[task 2022-03-23T14:31:48.105Z] 14:31:48     INFO - Failed to get child procs
[task 2022-03-23T14:31:48.105Z] 14:31:48     INFO - Killing process: 3657[task 2022-03-23T14:31:48.105Z] 14:31:48     INFO - Not taking screenshot here: see the one that was previously logged
[task 2022-03-23T14:31:48.105Z] 14:31:48     INFO - Killing process: 3658
[task 2022-03-23T14:31:48.106Z] 14:31:48     INFO - Not taking screenshot here: see the one that was previously logged
[task 2022-03-23T14:31:48.106Z] 14:31:48     INFO - Can't trigger Breakpad, process no longer exists
[task 2022-03-23T14:31:48.106Z] 14:31:48     INFO - Killing process: 3667
[task 2022-03-23T14:31:48.106Z] 14:31:48     INFO - Not taking screenshot here: see the one that was previously logged
[task 2022-03-23T14:31:48.107Z] 14:31:48     INFO - Killing process: 3668
[task 2022-03-23T14:31:48.107Z] 14:31:48     INFO - Not taking screenshot here: see the one that was previously logged
[task 2022-03-23T14:31:48.107Z] 14:31:48     INFO - Killing process: 3669
[task 2022-03-23T14:31:48.107Z] 14:31:48     INFO - Not taking screenshot here: see the one that was previously logged
[task 2022-03-23T14:31:48.108Z] 14:31:48     INFO - Killing process: 3670
[task 2022-03-23T14:31:48.108Z] 14:31:48     INFO - Not taking screenshot here: see the one that was previously logged
[task 2022-03-23T14:31:48.108Z] 14:31:48     INFO - Killing process: 3675
[task 2022-03-23T14:31:48.108Z] 14:31:48     INFO - Not taking screenshot here: see the one that was previously logged
[task 2022-03-23T14:31:48.109Z] 14:31:48     INFO - Killing process: 3650
[task 2022-03-23T14:31:48.109Z] 14:31:48     INFO - Not taking screenshot here: see the one that was previously logged
[task 2022-03-23T14:31:48.382Z] 14:31:48     INFO - psutil found pid 3650 dead
[task 2022-03-23T14:31:49.624Z] 14:31:49     INFO - TEST-INFO | Main app process: exit 0

Comment 1

[BugBot [:suhaib / :marco/ :calixte]]

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

Comment 2

[BugBot [:suhaib / :marco/ :calixte]]

:dminor, since you are the author of the regressor, bug 1402822, could you take a look?
For more information, please visit auto_nag documentation.

Comment 3

[Dan Minor [:dminor]]

These tests were flaky on test verification prior to the changes in Bug 1402822.

Comment 4

[Intermittent Failures Robot]

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

Repository breakdown:

• autoland: 1

Platform and build breakdown:

• macosx1015-64-qr: 1
  • debug: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1761074&startday=2022-03-21&endday=2022-03-27&tree=all

Comment 5

[BugBot [:suhaib / :marco/ :calixte]]

https://wiki.mozilla.org/Bug_Triage#Intermittent_Test_Failure_Cleanup
For more information, please visit auto_nag documentation.