Closed Bug 1770119 Opened 2 years ago Closed 2 years ago

devtools/client/styleeditor/test/browser_toolbox_styleeditor.js | Test timed out -

Categories

(DevTools :: Style Editor, defect, P5)

defect

Tracking

(firefox-esr91 unaffected, firefox100 unaffected, firefox101 unaffected, firefox102 wontfix, firefox103 wontfix)

RESOLVED DUPLICATE of bug 1781504
Tracking Status
firefox-esr91 --- unaffected
firefox100 --- unaffected
firefox101 --- unaffected
firefox102 --- wontfix
firefox103 --- wontfix

People

(Reporter: intermittent-bug-filer, Unassigned)

References

(Regression)

Details

(Keywords: intermittent-failure, regression)

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


[task 2022-05-19T06:34:53.950Z] 06:34:53     INFO - TEST-PASS | devtools/client/styleeditor/test/browser_toolbox_styleeditor.js | Browser toolbox started - 
[task 2022-05-19T06:34:53.951Z] 06:34:53     INFO - TEST-PASS | devtools/client/styleeditor/test/browser_toolbox_styleeditor.js | Has session state - 
[task 2022-05-19T06:34:53.951Z] 06:34:53     INFO - Buffered messages logged at 06:29:41
[task 2022-05-19T06:34:53.951Z] 06:34:53     INFO - TEST-PASS | devtools/client/styleeditor/test/browser_toolbox_styleeditor.js | Got transport - 
[task 2022-05-19T06:34:53.952Z] 06:34:53     INFO - Buffered messages logged at 06:29:42
[task 2022-05-19T06:34:53.952Z] 06:34:53     INFO - TEST-PASS | devtools/client/styleeditor/test/browser_toolbox_styleeditor.js | Connected - 
[task 2022-05-19T06:34:53.953Z] 06:34:53     INFO - Buffered messages logged at 06:29:50
[task 2022-05-19T06:34:53.953Z] 06:34:53     INFO - Console message: [JavaScript Warning: "Use of nsIFile in content process is deprecated." {file: "resource://gre/modules/NetUtil.jsm" line: 253}]
[task 2022-05-19T06:34:53.954Z] 06:34:53     INFO - Buffered messages logged at 06:29:51
[task 2022-05-19T06:34:53.954Z] 06:34:53     INFO - Console message: [JavaScript Warning: "Use of nsIFile in content process is deprecated." {file: "resource://gre/modules/NetUtil.jsm" line: 253}]
[task 2022-05-19T06:34:53.955Z] 06:34:53     INFO - Console message: [JavaScript Warning: "Use of nsIFile in content process is deprecated." {file: "resource://gre/modules/NetUtil.jsm" line: 253}]
[task 2022-05-19T06:34:53.955Z] 06:34:53     INFO - Buffered messages logged at 06:30:23
[task 2022-05-19T06:34:53.955Z] 06:34:53     INFO - Longer timeout required, waiting longer...  Remaining timeouts: 3
[task 2022-05-19T06:34:53.956Z] 06:34:53     INFO - Buffered messages logged at 06:31:53
[task 2022-05-19T06:34:53.956Z] 06:34:53     INFO - Longer timeout required, waiting longer...  Remaining timeouts: 2
[task 2022-05-19T06:34:53.957Z] 06:34:53     INFO - Buffered messages logged at 06:33:23
[task 2022-05-19T06:34:53.957Z] 06:34:53     INFO - Longer timeout required, waiting longer...  Remaining timeouts: 1
[task 2022-05-19T06:34:53.957Z] 06:34:53     INFO - Buffered messages finished
[task 2022-05-19T06:34:53.958Z] 06:34:53     INFO - TEST-UNEXPECTED-FAIL | devtools/client/styleeditor/test/browser_toolbox_styleeditor.js | Test timed out - 
[task 2022-05-19T06:34:53.958Z] 06:34:53     INFO - Removing tab.
[task 2022-05-19T06:34:53.959Z] 06:34:53     INFO - Waiting for event: 'TabClose' on [object XULElement].
[task 2022-05-19T06:34:53.959Z] 06:34:53     INFO - Got event: 'TabClose' on [object XULElement].
[task 2022-05-19T06:34:53.960Z] 06:34:53     INFO - Tab removed and finished closing
[task 2022-05-19T06:34:54.069Z] 06:34:54     INFO - TEST-PASS | devtools/client/styleeditor/test/browser_toolbox_styleeditor.js | The main process DevToolsServer has no pending connection when the test ends - 
[task 2022-05-19T06:34:54.940Z] 06:34:54     INFO - GECKO(3830) | 4256> JavaScript error: resource://devtools/client/shared/theme.js, line 101: NS_ERROR_ILLEGAL_VALUE: Component returned failure code: 0x80070057 (NS_ERROR_ILLEGAL_VALUE) [nsIObserverService.removeObserver]
[task 2022-05-19T06:34:54.996Z] 06:34:54     INFO - GECKO(3830) | ### XPCOM_MEM_BLOAT_LOG defined -- logging bloat/leaks to /var/folders/6_/2fr28cdd7y77jbw9wg779c0r000014/T/tmpj5kwcjli.mozrunner/runtests_leaks_tab_pid4457.log
[task 2022-05-19T06:34:54.997Z] 06:34:54     INFO - GECKO(3830) | [4457, Main Thread] WARNING: XPCOM_MEM_BLOAT_LOG is set, disabling native allocations.: file /builds/worker/checkouts/gecko/tools/profiler/core/platform.cpp:339
[task 2022-05-19T06:34:55.077Z] 06:34:55     INFO - GECKO(3830) | ### XPCOM_MEM_BLOAT_LOG defined -- logging bloat/leaks to /var/folders/6_/2fr28cdd7y77jbw9wg779c0r000014/T/tmpj5kwcjli.mozrunner/runtests_leaks_tab_pid4458.log
[task 2022-05-19T06:34:55.077Z] 06:34:55     INFO - GECKO(3830) | [4458, Main Thread] WARNING: XPCOM_MEM_BLOAT_LOG is set, disabling native allocations.: file /builds/worker/checkouts/gecko/tools/profiler/core/platform.cpp:339
[task 2022-05-19T06:34:55.145Z] 06:34:55     INFO - GECKO(3830) | ### XPCOM_MEM_BLOAT_LOG defined -- logging bloat/leaks to /var/folders/6_/2fr28cdd7y77jbw9wg779c0r000014/T/tmpj5kwcjli.mozrunner/runtests_leaks_tab_pid4459.log
[task 2022-05-19T06:34:55.145Z] 06:34:55     INFO - GECKO(3830) | [4459, Main Thread] WARNING: XPCOM_MEM_BLOAT_LOG is set, disabling native allocations.: file /builds/worker/checkouts/gecko/tools/profiler/core/platform.cpp:339
[task 2022-05-19T06:34:55.262Z] 06:34:55     INFO - GECKO(3830) | JavaScript warning: resource://devtools/shared/loader/builtin-modules.js, line 207: debuggee 'resource://devtools/shared/loader/base-loader.js:289' would run
[task 2022-05-19T06:34:55.324Z] 06:34:55     INFO - Console message: [JavaScript Warning: "debuggee 'resource://devtools/shared/loader/base-loader.js:289' would run" {file: "resource://devtools/shared/loader/builtin-modules.js" line: 207}]
[task 2022-05-19T06:34:55.345Z] 06:34:55     INFO - GECKO(3830) | JavaScript warning: resource://devtools/shared/loader/builtin-modules.js, line 207: debuggee 'resource://devtools/shared/loader/base-loader.js:289' would run
[task 2022-05-19T06:34:55.408Z] 06:34:55     INFO - GECKO(3830) | JavaScript warning: resource://devtools/shared/loader/builtin-modules.js, line 207: debuggee 'resource://devtools/shared/loader/base-loader.js:289' would run
[task 2022-05-19T06:34:55.409Z] 06:34:55     INFO - Console message: [JavaScript Warning: "debuggee 'resource://devtools/shared/loader/base-loader.js:289' would run" {file: "resource://devtools/shared/loader/builtin-modules.js" line: 207}]
[task 2022-05-19T06:34:55.525Z] 06:34:55     INFO - Console message: [JavaScript Warning: "debuggee 'resource://devtools/shared/loader/base-loader.js:289' would run" {file: "resource://devtools/shared/loader/builtin-modules.js" line: 207}]
[task 2022-05-19T06:34:55.536Z] 06:34:55     INFO - GECKO(3830) | 4256> [Parent 4256, Main Thread] WARNING: '!sm', file /builds/worker/checkouts/gecko/widget/Theme.cpp:1055
[task 2022-05-19T06:34:55.536Z] 06:34:55     INFO - GECKO(3830) | 4256> [Parent 4256, Main Thread] WARNING: '!sm', file /builds/worker/checkouts/gecko/widget/Theme.cpp:1055
[task 2022-05-19T06:34:55.537Z] 06:34:55     INFO - GECKO(3830) | 4256> [Parent 4256, Main Thread] WARNING: '!sm', file /builds/worker/checkouts/gecko/widget/Theme.cpp:1055
[task 2022-05-19T06:34:56.390Z] 06:34:56     INFO - GECKO(3830) | 4256> [Parent 4256, Main Thread] WARNING: '!inner', file /builds/worker/checkouts/gecko/dom/ipc/jsactor/JSWindowActorProtocol.cpp:184
[task 2022-05-19T06:34:56.720Z] 06:34:56     INFO - GECKO(3830) | 4256> [Parent 4256, Socket Thread] WARNING: cannot post event if not initialized: file /builds/worker/checkouts/gecko/netwerk/protocol/http/nsHttpConnectionMgr.cpp:197
[task 2022-05-19T06:34:56.785Z] 06:34:56     INFO - Check that the edit done in the style editor were applied to the page
[task 2022-05-19T06:34:56.857Z] 06:34:56     INFO - GECKO(3830) | 4256> [Parent 4256, Main Thread] WARNING: unable to post continuation event: file /builds/worker/checkouts/gecko/xpcom/io/nsStreamUtils.cpp:467
[task 2022-05-19T06:34:56.857Z] 06:34:56     INFO - GECKO(3830) | 4256> [Parent 4256, Main Thread] WARNING: unable to post continuation event: file /builds/worker/checkouts/gecko/xpcom/io/nsStreamUtils.cpp:467
[task 2022-05-19T06:34:56.891Z] 06:34:56     INFO - Not taking screenshot here: see the one that was previously logged
[task 2022-05-19T06:34:56.892Z] 06:34:56     INFO - TEST-UNEXPECTED-FAIL | devtools/client/styleeditor/test/browser_toolbox_styleeditor.js | Changes made to simple.css were applied to the page - Got "rgb(0, 0, 0)", expected "rgb(255, 0, 0)"
[task 2022-05-19T06:34:56.892Z] 06:34:56     INFO - Stack trace:
[task 2022-05-19T06:34:56.892Z] 06:34:56     INFO - chrome://mochikit/content/browser-test.js:test_is:1422
[task 2022-05-19T06:34:56.892Z] 06:34:56     INFO - chrome://mochitests/content/browser/devtools/client/styleeditor/test/browser_toolbox_styleeditor.js:null:87
[task 2022-05-19T06:34:56.892Z] 06:34:56     INFO - chrome://mochikit/content/browser-test.js:handleTask:989
[task 2022-05-19T06:34:56.892Z] 06:34:56     INFO - chrome://mochikit/content/browser-test.js:_runTaskBasedTest:1061
[task 2022-05-19T06:34:56.892Z] 06:34:56     INFO - chrome://mochikit/content/browser-test.js:Tester_execTest:1189
[task 2022-05-19T06:34:56.892Z] 06:34:56     INFO - chrome://mochikit/content/browser-test.js:nextTest/<:972
[task 2022-05-19T06:34:56.892Z] 06:34:56     INFO - chrome://mochikit/content/tests/SimpleTest/SimpleTest.js:SimpleTest.waitForFocus/<:1041
<...>
[task 2022-05-19T06:34:59.399Z] 06:34:59     INFO - GECKO(3830) | 4256>  => mShareCount:          87910
[task 2022-05-19T06:34:59.400Z] 06:34:59     INFO - GECKO(3830) | 4256>  => mAdoptCount:           3186
[task 2022-05-19T06:34:59.400Z] 06:34:59     INFO - GECKO(3830) | 4256>  => mAdoptFreeCount:       3719
[task 2022-05-19T06:34:59.400Z] 06:34:59     INFO - GECKO(3830) | 4256>  => Process ID: 4256, Thread ID: 4643110336
[task 2022-05-19T06:34:59.452Z] 06:34:59     INFO - TEST-PASS | devtools/client/styleeditor/test/browser_toolbox_styleeditor.js | Browser toolbox process closed - 
[task 2022-05-19T06:34:59.452Z] 06:34:59     INFO - TEST-PASS | devtools/client/styleeditor/test/browser_toolbox_styleeditor.js | The remote debugger process died cleanly - 
[task 2022-05-19T06:34:59.453Z] 06:34:59     INFO - TEST-PASS | devtools/client/styleeditor/test/browser_toolbox_styleeditor.js | No session state after closing - 
[task 2022-05-19T06:34:59.453Z] 06:34:59     INFO - TEST-PASS | devtools/client/styleeditor/test/browser_toolbox_styleeditor.js | Browser toolbox process closed - 
[task 2022-05-19T06:34:59.454Z] 06:34:59     INFO - TEST-PASS | devtools/client/styleeditor/test/browser_toolbox_styleeditor.js | The remote debugger process died cleanly - 
[task 2022-05-19T06:34:59.454Z] 06:34:59     INFO - TEST-PASS | devtools/client/styleeditor/test/browser_toolbox_styleeditor.js | No session state after closing - 
[task 2022-05-19T06:34:59.458Z] 06:34:59     INFO - Not taking screenshot here: see the one that was previously logged
[task 2022-05-19T06:34:59.460Z] 06:34:59     INFO - TEST-UNEXPECTED-FAIL | devtools/client/styleeditor/test/browser_toolbox_styleeditor.js | A promise chain failed to handle a rejection: Can not send request 'evaluateJSAsync' because front 'console' is already destroyed. - stack: generateRequestMethods/</frontProto[name]@resource://devtools/shared/protocol/Front/FrontClassWithSpec.js:28:15
[task 2022-05-19T06:34:59.460Z] 06:34:59     INFO - evaluateExpression@chrome://mochitests/content/browser/devtools/client/framework/browser-toolbox/test/helpers-browser-toolbox.js:157:24
[task 2022-05-19T06:34:59.460Z] 06:34:59     INFO - destroy@chrome://mochitests/content/browser/devtools/client/framework/browser-toolbox/test/helpers-browser-toolbox.js:200:23
[task 2022-05-19T06:34:59.460Z] 06:34:59     INFO - @chrome://mochitests/content/browser/devtools/client/styleeditor/test/browser_toolbox_styleeditor.js:93:21
[task 2022-05-19T06:34:59.460Z] 06:34:59     INFO - Async*handleTask@chrome://mochikit/content/browser-test.js:989:26
[task 2022-05-19T06:34:59.460Z] 06:34:59     INFO - _runTaskBasedTest@chrome://mochikit/content/browser-test.js:1061:18
[task 2022-05-19T06:34:59.460Z] 06:34:59     INFO - Tester_execTest@chrome://mochikit/content/browser-test.js:1189:14
[task 2022-05-19T06:34:59.460Z] 06:34:59     INFO - nextTest/<@chrome://mochikit/content/browser-test.js:972:14
[task 2022-05-19T06:34:59.460Z] 06:34:59     INFO - SimpleTest.waitForFocus/<@chrome://mochikit/content/tests/SimpleTest/SimpleTest.js:1041:13
[task 2022-05-19T06:34:59.460Z] 06:34:59     INFO - Rejection date: Thu May 19 2022 06:34:56 GMT+0000 (Greenwich Mean Time) - false == true - JS frame :: resource://testing-common/PromiseTestUtils.jsm :: assertNoUncaughtRejections :: line 271
[task 2022-05-19T06:34:59.460Z] 06:34:59     INFO - Stack trace:
[task 2022-05-19T06:34:59.460Z] 06:34:59     INFO - resource://testing-common/PromiseTestUtils.jsm:assertNoUncaughtRejections:271
[task 2022-05-19T06:34:59.460Z] 06:34:59     INFO - chrome://mochikit/content/browser-test.js:handleTask:1017
[task 2022-05-19T06:34:59.460Z] 06:34:59     INFO - chrome://mochikit/content/browser-test.js:_runTaskBasedTest:1061
[task 2022-05-19T06:34:59.460Z] 06:34:59     INFO - chrome://mochikit/content/browser-test.js:Tester_execTest:1189
[task 2022-05-19T06:34:59.460Z] 06:34:59     INFO - chrome://mochikit/content/browser-test.js:nextTest/<:972
[task 2022-05-19T06:34:59.460Z] 06:34:59     INFO - chrome://mochikit/content/tests/SimpleTest/SimpleTest.js:SimpleTest.waitForFocus/<:1041
[task 2022-05-19T06:34:59.461Z] 06:34:59     INFO - Leaving test bound 
[task 2022-05-19T06:34:59.544Z] 06:34:59     INFO - GECKO(3830) | MEMORY STAT | vsize 7961MB | residentFast 386MB | heapAllocated 186MB
[task 2022-05-19T06:34:59.545Z] 06:34:59     INFO - TEST-OK | devtools/client/styleeditor/test/browser_toolbox_styleeditor.js | took 366245ms

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

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

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

There don't seem to be anything in the logs that would explain this
Looking at the failure screenshot, we might not wait enough before trying to write in the editor? Let's see if we get more occurrences of this.

Flags: needinfo?(nchevobbe)

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

Summary: Intermittent TV devtools/client/styleeditor/test/browser_toolbox_styleeditor.js | Test timed out - → devtools/client/styleeditor/test/browser_toolbox_styleeditor.js | Test timed out -
Status: NEW → RESOLVED
Closed: 2 years ago
Resolution: --- → INCOMPLETE
Status: RESOLVED → REOPENED
Resolution: INCOMPLETE → ---
Status: REOPENED → RESOLVED
Closed: 2 years ago2 years ago
Resolution: --- → DUPLICATE
You need to log in before you can comment on or make changes to this bug.