Closed Bug 1761074 Opened 3 years ago Closed 3 years ago

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

Categories

(Core :: Spelling checker, defect, P5)

Product:
Core
Component:
Spelling checker
Type:
defect

Tracking

()

Status:
RESOLVED INCOMPLETE
Tracking Flags:
Tracking Status
firefox-esr91 --- unaffected
firefox98 --- unaffected
firefox99 --- unaffected
firefox100 --- affected

People

(Reporter: intermittent-bug-filer, Unassigned)

References

(Regression)

Details

(Keywords: intermittent-failure, regression)

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
Regressed by: 1402822

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

status-firefox100: --- → affected
status-firefox98: --- → unaffected
status-firefox99: --- → unaffected
status-firefox-esr91: --- → unaffected

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

Flags: needinfo?(dminor)
Has Regression Range: --- → yes

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

Flags: needinfo?(dminor)
Component: DOM: Editor → Spelling checker

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

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