Closed Bug 1784159 Opened 2 years ago Closed 1 year ago

Intermittent devtools/client/inspector/changes/test/browser_changes_declaration_add_special_character.js | single tracking bug

Categories

(DevTools :: Inspector: Changes, defect, P5)

defect

Tracking

(firefox-esr91 unaffected, firefox-esr102 unaffected, firefox103 unaffected, firefox104 unaffected, firefox105 wontfix, firefox106 wontfix, firefox108 wontfix, firefox109 wontfix, firefox110 fixed)

RESOLVED FIXED
110 Branch
Tracking Status
firefox-esr91 --- unaffected
firefox-esr102 --- unaffected
firefox103 --- unaffected
firefox104 --- unaffected
firefox105 --- wontfix
firefox106 --- wontfix
firefox108 --- wontfix
firefox109 --- wontfix
firefox110 --- fixed

People

(Reporter: intermittent-bug-filer, Assigned: jdescottes)

References

(Regression)

Details

(Keywords: intermittent-failure, intermittent-testcase, regression)

Attachments

(1 file)

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


task 2022-08-10T22:00:56.861Z] 22:00:56     INFO - TEST-PASS | devtools/client/inspector/changes/test/browser_changes_declaration_add_special_character.js | The main process DevToolsServer has no pending connection when the test ends - 
[task 2022-08-10T22:00:56.865Z] 22:00:56     INFO - Console message: [JavaScript Error: "Error: Connection closed, pending request to server0.conn0.windowGlobal4294967301/domstylerule34, type setRuleText failed
[task 2022-08-10T22:00:56.865Z] 22:00:56     INFO - 
[task 2022-08-10T22:00:56.865Z] 22:00:56     INFO - Request stack:
[task 2022-08-10T22:00:56.866Z] 22:00:56     INFO - request@resource://devtools/shared/protocol/Front.js:301:14
[task 2022-08-10T22:00:56.866Z] 22:00:56     INFO - generateRequestMethods/</frontProto[name]@resource://devtools/shared/protocol/Front/FrontClassWithSpec.js:49:19
[task 2022-08-10T22:00:56.867Z] 22:00:56     INFO - setRuleText@resource://devtools/client/fronts/style-rule.js:155:18
[task 2022-08-10T22:00:56.867Z] 22:00:56     INFO - apply/<@resource://devtools/client/fronts/inspector/rule-rewriter.js:719:24
[task 2022-08-10T22:00:56.868Z] 22:00:56     INFO - promise callback*apply@resource://devtools/client/fronts/inspector/rule-rewriter.js:718:46
[task 2022-08-10T22:00:56.868Z] 22:00:56     INFO - _applyPropertiesAuthored@resource://devtools/client/inspector/rules/models/rule.js:389:26
[task 2022-08-10T22:00:56.868Z] 22:00:56     INFO - applyProperties/resultPromise<@resource://devtools/client/inspector/rules/models/rule.js:429:23
[task 2022-08-10T22:00:56.869Z] 22:00:56     INFO - promise callback*applyProperties@resource://devtools/client/inspector/rules/models/rule.js:423:8
[task 2022-08-10T22:00:56.869Z] 22:00:56     INFO - setPropertyValue@resource://devtools/client/inspector/rules/models/rule.js:489:17
[task 2022-08-10T22:00:56.869Z] 22:00:56     INFO - setValue@resource://devtools/client/inspector/rules/models/text-property.js:190:22
[task 2022-08-10T22:00:56.870Z] 22:00:56     INFO - _onValueDone@resource://devtools/client/inspector/rules/views/text-property-editor.js:1217:15
[task 2022-08-10T22:00:56.870Z] 22:00:56     INFO - _apply@resource://devtools/client/shared/inplace-editor.js:1058:19
[task 2022-08-10T22:00:56.871Z] 22:00:56     INFO - _onKeyPress@resource://devtools/client/shared/inplace-editor.js:1287:12
[task 2022-08-10T22:00:56.871Z] 22:00:56     INFO - synthesizeKey@chrome://mochikit/content/tests/SimpleTest/EventUtils.js:1360:11
[task 2022-08-10T22:00:56.872Z] 22:00:56     INFO - setProperty@chrome://mochitests/content/browser/devtools/client/inspector/rules/test/head.js:399:14
[task 2022-08-10T22:00:56.872Z] 22:00:56     INFO - async*addWithSpecialCharacter@chrome://mochitests/content/browser/devtools/client/inspector/changes/test/browser_changes_declaration_add_special_character.js:56:9
[task 2022-08-10T22:00:56.872Z] 22:00:56     INFO - Async*handleTask@chrome://mochikit/content/browser-test.js:1028:26
[task 2022-08-10T22:00:56.873Z] 22:00:56     INFO - _runTaskBasedTest@chrome://mochikit/content/browser-test.js:1100:18
[task 2022-08-10T22:00:56.873Z] 22:00:56     INFO - Tester_execTest@chrome://mochikit/content/browser-test.js:1235:14
[task 2022-08-10T22:00:56.873Z] 22:00:56     INFO - nextTest/<@chrome://mochikit/content/browser-test.js:1017:14
[task 2022-08-10T22:00:56.874Z] 22:00:56     INFO - SimpleTest.waitForFocus/<@chrome://mochikit/content/tests/SimpleTest/SimpleTest.js:1038:13
[task 2022-08-10T22:00:56.874Z] 22:00:56     INFO - " {file: "resource://devtools/shared/protocol/Front.js" line: 107}]
[task 2022-08-10T22:00:56.875Z] 22:00:56     INFO - Buffered messages finished
[task 2022-08-10T22:00:56.879Z] 22:00:56     INFO - TEST-UNEXPECTED-FAIL | devtools/client/inspector/changes/test/browser_changes_declaration_add_special_character.js | A promise chain failed to handle a rejection: Connection closed, pending request to server0.conn0.windowGlobal4294967301/domstylerule34, type setRuleText failed
[task 2022-08-10T22:00:56.880Z] 22:00:56     INFO - 
[task 2022-08-10T22:00:56.881Z] 22:00:56     INFO - Request stack:
[task 2022-08-10T22:00:56.881Z] 22:00:56     INFO - request@resource://devtools/shared/protocol/Front.js:301:14
[task 2022-08-10T22:00:56.881Z] 22:00:56     INFO - generateRequestMethods/</frontProto[name]@resource://devtools/shared/protocol/Front/FrontClassWithSpec.js:49:19
[task 2022-08-10T22:00:56.882Z] 22:00:56     INFO - setRuleText@resource://devtools/client/fronts/style-rule.js:155:18
[task 2022-08-10T22:00:56.882Z] 22:00:56     INFO - apply/<@resource://devtools/client/fronts/inspector/rule-rewriter.js:719:24
[task 2022-08-10T22:00:56.883Z] 22:00:56     INFO - promise callback*apply@resource://devtools/client/fronts/inspector/rule-rewriter.js:718:46
[task 2022-08-10T22:00:56.883Z] 22:00:56     INFO - _applyPropertiesAuthored@resource://devtools/client/inspector/rules/models/rule.js:389:26
[task 2022-08-10T22:00:56.883Z] 22:00:56     INFO - applyProperties/resultPromise<@resource://devtools/client/inspector/rules/models/rule.js:429:23
[task 2022-08-10T22:00:56.883Z] 22:00:56     INFO - promise callback*applyProperties@resource://devtools/client/inspector/rules/models/rule.js:423:8
[task 2022-08-10T22:00:56.884Z] 22:00:56     INFO - setPropertyValue@resource://devtools/client/inspector/rules/models/rule.js:489:17
[task 2022-08-10T22:00:56.884Z] 22:00:56     INFO - setValue@resource://devtools/client/inspector/rules/models/text-property.js:190:22
[task 2022-08-10T22:00:56.884Z] 22:00:56     INFO - _onValueDone@resource://devtools/client/inspector/rules/views/text-property-editor.js:1217:15
[task 2022-08-10T22:00:56.885Z] 22:00:56     INFO - _apply@resource://devtools/client/shared/inplace-editor.js:1058:19
[task 2022-08-10T22:00:56.885Z] 22:00:56     INFO - _onKeyPress@resource://devtools/client/shared/inplace-editor.js:1287:12
[task 2022-08-10T22:00:56.885Z] 22:00:56     INFO - synthesizeKey@chrome://mochikit/content/tests/SimpleTest/EventUtils.js:1360:11
[task 2022-08-10T22:00:56.886Z] 22:00:56     INFO - setProperty@chrome://mochitests/content/browser/devtools/client/inspector/rules/test/head.js:399:14
[task 2022-08-10T22:00:56.886Z] 22:00:56     INFO - async*addWithSpecialCharacter@chrome://mochitests/content/browser/devtools/client/inspector/changes/test/browser_changes_declaration_add_special_character.js:56:9
[task 2022-08-10T22:00:56.886Z] 22:00:56     INFO - Async*handleTask@chrome://mochikit/content/browser-test.js:1028:26
[task 2022-08-10T22:00:56.887Z] 22:00:56     INFO - _runTaskBasedTest@chrome://mochikit/content/browser-test.js:1100:18
[task 2022-08-10T22:00:56.887Z] 22:00:56     INFO - Tester_execTest@chrome://mochikit/content/browser-test.js:1235:14
[task 2022-08-10T22:00:56.887Z] 22:00:56     INFO - nextTest/<@chrome://mochikit/content/browser-test.js:1017:14
[task 2022-08-10T22:00:56.887Z] 22:00:56     INFO - SimpleTest.waitForFocus/<@chrome://mochikit/content/tests/SimpleTest/SimpleTest.js:1038:13
[task 2022-08-10T22:00:56.888Z] 22:00:56     INFO -  - stack: baseFrontClassDestroy@resource://devtools/shared/protocol/Front.js:107:23
[task 2022-08-10T22:00:56.888Z] 22:00:56     INFO - destroy@resource://devtools/shared/protocol/Front.js:75:10
[task 2022-08-10T22:00:56.889Z] 22:00:56     INFO - destroy@resource://devtools/shared/protocol/Pool.js:211:17
[task 2022-08-10T22:00:56.890Z] 22:00:56     INFO - baseFrontClassDestroy@resource://devtools/shared/protocol/Front.js:111:13
[task 2022-08-10T22:00:56.890Z] 22:00:56     INFO - destroy@resource://devtools/shared/protocol/Front.js:75:10
[task 2022-08-10T22:00:56.890Z] 22:00:56     INFO - destroy@resource://devtools/shared/protocol/Pool.js:211:17
[task 2022-08-10T22:00:56.890Z] 22:00:56     INFO - baseFrontClassDestroy@resource://devtools/shared/protocol/Front.js:111:13
[task 2022-08-10T22:00:56.891Z] 22:00:56     INFO - destroy@resource://devtools/shared/protocol/Front.js:75:10
[task 2022-08-10T22:00:56.891Z] 22:00:56     INFO - destroy@resource://devtools/client/fronts/inspector.js:137:11
[task 2022-08-10T22:00:56.892Z] 22:00:56     INFO - _destroyTarget@resource://devtools/client/fronts/targets/target-mixin.js:615:17
[task 2022-08-10T22:00:56.892Z] 22:00:56     INFO - Rejection date: Wed Aug 10 2022 22:00:56 GMT+0000 (Coordinated Universal Time) - false == true - JS frame :: resource://testing-common/PromiseTestUtils.jsm :: assertNoUncaughtRejections :: line 270
[task 2022-08-10T22:00:56.892Z] 22:00:56     INFO - Stack trace:
[task 2022-08-10T22:00:56.892Z] 22:00:56     INFO - resource://testing-common/PromiseTestUtils.jsm:assertNoUncaughtRejections:270
[task 2022-08-10T22:00:56.892Z] 22:00:56     INFO - chrome://mochikit/content/browser-test.js:nextTest:663
[task 2022-08-10T22:00:56.893Z] 22:00:56     INFO - chrome://mochikit/content/browser-test.js:testScope/test_finish/<:1659
[task 2022-08-10T22:00:56.894Z] 22:00:56     INFO - chrome://mochikit/content/browser-test.js:run:1574
[task 2022-08-10T22:00:56.895Z] 22:00:56     INFO - GECKO(6131) | ### XPCOM_MEM_BLOAT_LOG defined -- logging bloat/leaks to /tmp/tmplqdca1kt.mozrunner/runtests_leaks_tab_pid6568.log
[task 2022-08-10T22:00:56.896Z] 22:00:56     INFO - GECKO(6131) | [6568, 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-08-10T22:00:56.897Z] 22:00:56     INFO - GECKO(6131) | [Child 6568, Main Thread] WARNING: could not set real-time limit in CubebUtils::InitLibrary: file /builds/worker/checkouts/gecko/dom/media/CubebUtils.cpp:707
[task 2022-08-10T22:00:56.898Z] 22:00:56     INFO - GECKO(6131) | ### XPCOM_MEM_BLOAT_LOG defined -- logging bloat/leaks to /tmp/tmplqdca1kt.mozrunner/runtests_leaks_tab_pid6571.log
[task 2022-08-10T22:00:56.899Z] 22:00:56     INFO - GECKO(6131) | [6571, 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-08-10T22:00:56.900Z] 22:00:56     INFO - GECKO(6131) | MEMORY STAT | vsize 11648MB | residentFast 517MB | heapAllocated 241MB
[task 2022-08-10T22:00:56.901Z] 22:00:56     INFO - TEST-OK | devtools/client/inspector/changes/test/browser_changes_declaration_add_special_character.js | took 4613ms
[task 2022-08-10T22:00:56.902Z] 22:00:56     INFO - GECKO(6131) | [Child 6283: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 3 (7f6f3fe37c00) [pid = 6283] [serial = 9] [outer = 0] [url = about:blank]
[task 2022-08-10T22:00:56.903Z] 22:00:56     INFO - GECKO(6131) | [Child 6283: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 2 (7f6f3fe3e000) [pid = 6283] [serial = 10] [outer = 0] [url = data:text/html;charset=utf-8,%0A%20%20%3Cstyle%20type%3D'text%2Fcss'%3E%0A%20%20div%20%7B%0A%20%20%20%20color%3A%20red%3B%0A%20%20%20%20margin%3A%200%3B%0A%20%20%7D%0A%20%20%3C%2Fstyle%3E%0A%20%20%3Cdiv%3E%3C%2Fdiv%3E%0A]
[task 2022-08-10T22:00:56.904Z] 22:00:56     INFO - GECKO(6131) | [Child 6224: Main Thread]: I/DocShellAndDOMWindowLeak ++DOCSHELL 7f2bdb01ec00 == 2 [pid = 6224] [id = 6]
[task 2022-08-10T22:00:56.910Z] 22:00:56     INFO - GECKO(6131) | [Child 6224: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 5 (7f2bf62919f0) [pid = 6224] [serial = 18] [outer = 0]
[task 2022-08-10T22:00:56.912Z] 22:00:56     INFO - GECKO(6131) | [Child 6224: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 6 (7f2bdb020000) [pid = 6224] [serial = 19] [outer = 7f2bf62919f0]
[task 2022-08-10T22:00:56.924Z] 22:00:56     INFO - GECKO(6131) | ### XPCOM_MEM_BLOAT_LOG defined -- logging bloat/leaks to /tmp/tmplqdca1kt.mozrunner/runtests_leaks_tab_pid6576.log
[task 2022-08-10T22:00:56.926Z] 22:00:56     INFO - GECKO(6131) | [6576, 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-08-10T22:00:56.934Z] 22:00:56     INFO - GECKO(6131) | [Child 6571, Main Thread] WARNING: could not set real-time limit in CubebUtils::InitLibrary: file /builds/worker/checkouts/gecko/dom/media/CubebUtils.cpp:707
[task 2022-08-10T22:00:56.936Z] 22:00:56     INFO - GECKO(6131) | [Child 6283, Main Thread] WARNING: '!CanHandleWith(aPresContext)', file /builds/worker/checkouts/gecko/dom/events/IMEStateManager.cpp:498
[task 2022-08-10T22:00:56.937Z] 22:00:56     INFO - GECKO(6131) | [Child 6576, Main Thread] WARNING: could not set real-time limit in CubebUtils::InitLibrary: file /builds/worker/checkouts/gecko/dom/media/CubebUtils.cpp:707
[task 2022-08-10T22:00:56.938Z] 22:00:56     INFO - checking window state

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

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

Flags: needinfo?(jdescottes)

Let's monitor the frequency for now. It's odd to have this intermittent only for this test as I don't think the pattern is much different from eg browser_changes_declaration_edit_value.js

As far as the failure goes, it seems that the last request initiated by the test does not have time to complete before we shutdown the test, even though the UI was updated with the expected information. The events required to update the UI are normally only emitted at the very end of that request, so it sounds unlikely that we had time to receive the events and update the UI but the request didn't manage to fully come back. Is there potentially another request started?

I will take a deeper look is the frequency increases, otherwise if I have no way to reproduce it will be hard to investigate.

Flags: needinfo?(jdescottes)

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

Regular failures, should fix it.

Flags: needinfo?(jdescottes)
Assignee: nobody → jdescottes
Status: NEW → ASSIGNED
Flags: needinfo?(jdescottes)
Pushed by jdescottes@mozilla.com:
https://hg.mozilla.org/integration/autoland/rev/4b8d690cc23f
[devtools] Wait for previews to be applied in browser_changes_declaration_add_special_character.js r=nchevobbe

Sorry about that, testing for a strict equality between the two counters we introduced in the patch is fragile for all the consumers which don't provide the correct "flushCount". Switching to "greater or equal" should be a better fit here.

Status: ASSIGNED → RESOLVED
Closed: 1 year ago
Flags: needinfo?(jdescottes)
Resolution: --- → FIXED
Status: RESOLVED → REOPENED
Resolution: FIXED → ---
Status: REOPENED → NEW
Status: NEW → ASSIGNED
Pushed by jdescottes@mozilla.com:
https://hg.mozilla.org/integration/autoland/rev/d57d744b3fec
[devtools] Wait for previews to be applied in browser_changes_declaration_add_special_character.js r=nchevobbe
Status: ASSIGNED → RESOLVED
Closed: 1 year ago1 year ago
Resolution: --- → FIXED
Target Milestone: --- → 110 Branch
You need to log in before you can comment on or make changes to this bug.

Attachment

General

Created:
Updated:
Size: