1667086 - Intermittent devtools/client/inspector/changes/test/browser_changes_declaration_remove_ahead.js | Added declaration has updated property value - Got "grid", expected "flex"

Status: RESOLVED FIXED

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

Description

[Treeherder Bug Filer]

Filed by: malexandru [at] mozilla.com
Parsed log: https://treeherder.mozilla.org/logviewer.html#?job_id=316575189&repo=autoland
Full log: https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/L_p-KuJ3SmaF8iaRvtJySg/runs/0/artifacts/public/logs/live_backing.log

---

[task 2020-09-24T12:03:58.586Z] 12:03:58 INFO - TEST-START | devtools/client/inspector/changes/test/browser_changes_declaration_remove_ahead.js
[task 2020-09-24T12:03:59.527Z] 12:03:59 INFO - GECKO(1529) | console.log: "[DISPATCH] action type:" "UPDATE_GRIDS"
[task 2020-09-24T12:03:59.605Z] 12:03:59 INFO - GECKO(1529) | console.log: "[DISPATCH] action type:" "CLEAR_FLEXBOX"
[task 2020-09-24T12:03:59.641Z] 12:03:59 INFO - GECKO(1529) | console.log: "[DISPATCH] action type:" "UPDATE_GRIDS"
[task 2020-09-24T12:03:59.642Z] 12:03:59 INFO - GECKO(1529) | console.log: "[DISPATCH] action type:" "CLEAR_FLEXBOX"
[task 2020-09-24T12:03:59.649Z] 12:03:59 INFO - GECKO(1529) | console.log: "[DISPATCH] action type:" "UPDATE_OFFSET_PARENT"
[task 2020-09-24T12:03:59.653Z] 12:03:59 INFO - GECKO(1529) | console.log: "[DISPATCH] action type:" "UPDATE_LAYOUT"
[task 2020-09-24T12:03:59.909Z] 12:03:59 INFO - GECKO(1529) | console.log: "[DISPATCH] action type:" "TRACK_CHANGE"
[task 2020-09-24T12:04:00.031Z] 12:04:00 INFO - GECKO(1529) | console.log: "[DISPATCH] action type:" "TRACK_CHANGE"
[task 2020-09-24T12:04:00.161Z] 12:04:00 INFO - GECKO(1529) | console.log: "[DISPATCH] action type:" "TRACK_CHANGE"
[task 2020-09-24T12:04:00.249Z] 12:04:00 INFO - TEST-INFO | started process screentopng
[task 2020-09-24T12:04:00.439Z] 12:04:00 INFO - TEST-INFO | screentopng: exit 0
[task 2020-09-24T12:04:00.439Z] 12:04:00 INFO - Buffered messages logged at 12:03:58
[task 2020-09-24T12:04:00.440Z] 12:04:00 INFO - Entering test bound
[task 2020-09-24T12:04:00.440Z] 12:04:00 INFO - Adding a new tab with URL: data:text/html;charset=utf-8,%0A%20%20%3Cstyle%20type%3D'text%2Fcss'%3E%0A%20%20%20%20div%20%7B%0A%20%20%20%20%20%20color%3A%20red%3B%0A%20%20%20%20%20%20display%3A%20block%3B%0A%20%20%20%20%7D%0A%20%20%3C%2Fstyle%3E%0A%20%20%3Cdiv%3E%3C%2Fdiv%3E%0A
[task 2020-09-24T12:04:00.440Z] 12:04:00 INFO - Tab added and finished loading
[task 2020-09-24T12:04:00.441Z] 12:04:00 INFO - Opening the inspector
[task 2020-09-24T12:04:00.441Z] 12:04:00 INFO - Opening the toolbox
[task 2020-09-24T12:04:00.441Z] 12:04:00 INFO - Buffered messages logged at 12:03:59
[task 2020-09-24T12:04:00.441Z] 12:04:00 INFO - Toolbox opened and focused
[task 2020-09-24T12:04:00.441Z] 12:04:00 INFO - Selecting the node for 'div'
[task 2020-09-24T12:04:00.441Z] 12:04:00 INFO - Waiting for action "TRACK_CHANGE"
[task 2020-09-24T12:04:00.441Z] 12:04:00 INFO - Change the second declaration
[task 2020-09-24T12:04:00.441Z] 12:04:00 INFO - Waiting for event: 'focus' on [object HTMLSpanElement].
[task 2020-09-24T12:04:00.441Z] 12:04:00 INFO - Clicking on editable field to turn to edit mode
[task 2020-09-24T12:04:00.442Z] 12:04:00 INFO - Got event: 'focus' on [object HTMLSpanElement].
[task 2020-09-24T12:04:00.442Z] 12:04:00 INFO - Editable field gained focus, returning the input field now
[task 2020-09-24T12:04:00.444Z] 12:04:00 INFO - Found action "TRACK_CHANGE"
[task 2020-09-24T12:04:00.444Z] 12:04:00 INFO - Waiting for action "TRACK_CHANGE"
[task 2020-09-24T12:04:00.444Z] 12:04:00 INFO - Remove the first declaration
[task 2020-09-24T12:04:00.444Z] 12:04:00 INFO - Waiting for event: 'focus' on [object HTMLSpanElement].
[task 2020-09-24T12:04:00.444Z] 12:04:00 INFO - Clicking on editable field to turn to edit mode
[task 2020-09-24T12:04:00.444Z] 12:04:00 INFO - Got event: 'focus' on [object HTMLSpanElement].
[task 2020-09-24T12:04:00.444Z] 12:04:00 INFO - Editable field gained focus, returning the input field now
[task 2020-09-24T12:04:00.444Z] 12:04:00 INFO - Deleting the property name now
[task 2020-09-24T12:04:00.445Z] 12:04:00 INFO - Buffered messages logged at 12:04:00
[task 2020-09-24T12:04:00.446Z] 12:04:00 INFO - Found action "TRACK_CHANGE"
[task 2020-09-24T12:04:00.446Z] 12:04:00 INFO - Console message: [JavaScript Warning: "Empty string passed to getElementById()." {file: "chrome://global/content/elements/browser-custom-element.js" line: 370}]
[task 2020-09-24T12:04:00.446Z] 12:04:00 INFO - Console message: [JavaScript Warning: "Empty string passed to getElementById()." {file: "chrome://global/content/elements/browser-custom-element.js" line: 370}]
[task 2020-09-24T12:04:00.446Z] 12:04:00 INFO - Waiting for action "TRACK_CHANGE"
[task 2020-09-24T12:04:00.446Z] 12:04:00 INFO - Change the second declaration again
[task 2020-09-24T12:04:00.447Z] 12:04:00 INFO - Waiting for event: 'focus' on [object HTMLSpanElement].
[task 2020-09-24T12:04:00.447Z] 12:04:00 INFO - Clicking on editable field to turn to edit mode
[task 2020-09-24T12:04:00.447Z] 12:04:00 INFO - Got event: 'focus' on [object HTMLSpanElement].
[task 2020-09-24T12:04:00.448Z] 12:04:00 INFO - Editable field gained focus, returning the input field now
[task 2020-09-24T12:04:00.448Z] 12:04:00 INFO - Console message: [JavaScript Warning: "Empty string passed to getElementById()." {file: "chrome://global/content/elements/browser-custom-element.js" line: 370}]
[task 2020-09-24T12:04:00.448Z] 12:04:00 INFO - Found action "TRACK_CHANGE"
[task 2020-09-24T12:04:00.449Z] 12:04:00 INFO - Wait for change to be tracked
[task 2020-09-24T12:04:00.449Z] 12:04:00 INFO - TEST-PASS | devtools/client/inspector/changes/test/browser_changes_declaration_remove_ahead.js | Two declarations tracked as removed -
[task 2020-09-24T12:04:00.450Z] 12:04:00 INFO - TEST-PASS | devtools/client/inspector/changes/test/browser_changes_declaration_remove_ahead.js | One declaration tracked as added -
[task 2020-09-24T12:04:00.450Z] 12:04:00 INFO - TEST-PASS | devtools/client/inspector/changes/test/browser_changes_declaration_remove_ahead.js | Added declaration has updated property name -
[task 2020-09-24T12:04:00.451Z] 12:04:00 INFO - Buffered messages finished
[task 2020-09-24T12:04:00.453Z] 12:04:00 INFO - TEST-UNEXPECTED-FAIL | devtools/client/inspector/changes/test/browser_changes_declaration_remove_ahead.js | Added declaration has updated property value - Got "grid", expected "flex"
[task 2020-09-24T12:04:00.453Z] 12:04:00 INFO - Stack trace:
[task 2020-09-24T12:04:00.453Z] 12:04:00 INFO - chrome://mochikit/content/browser-test.js:test_is:1332
[task 2020-09-24T12:04:00.453Z] 12:04:00 INFO - chrome://mochitests/content/browser/devtools/client/inspector/changes/test/browser_changes_declaration_remove_ahead.js:null:55
[task 2020-09-24T12:04:00.453Z] 12:04:00 INFO - chrome://mochikit/content/browser-test.js:Tester_execTest/<:1069
[task 2020-09-24T12:04:00.453Z] 12:04:00 INFO - chrome://mochikit/content/browser-test.js:Tester_execTest:1109
[task 2020-09-24T12:04:00.453Z] 12:04:00 INFO - chrome://mochikit/content/browser-test.js:nextTest/<:932
[task 2020-09-24T12:04:00.453Z] 12:04:00 INFO - chrome://mochikit/content/tests/SimpleTest/SimpleTest.js:SimpleTest.waitForFocus/waitForFocusInner/focusedOrLoaded/<:1037
[task 2020-09-24T12:04:00.453Z] 12:04:00 INFO - Leaving test bound
[task 2020-09-24T12:04:00.453Z] 12:04:00 INFO - GECKO(1529) | console.log: "[DISPATCH] action type:" "RESET_CHANGES"
[task 2020-09-24T12:04:00.640Z] 12:04:00 INFO - Removing tab.
[task 2020-09-24T12:04:00.641Z] 12:04:00 INFO - Waiting for event: 'TabClose' on [object XULElement].
[task 2020-09-24T12:04:00.656Z] 12:04:00 INFO - Got event: 'TabClose' on [object XULElement].
[task 2020-09-24T12:04:00.671Z] 12:04:00 INFO - Tab removed and finished closing
[task 2020-09-24T12:04:00.687Z] 12:04:00 INFO - Console message: [JavaScript Warning: "Empty string passed to getElementById()." {file: "chrome://global/content/elements/browser-custom-element.js" line: 370}]
[task 2020-09-24T12:04:00.707Z] 12:04:00 INFO - TEST-PASS | devtools/client/inspector/changes/test/browser_changes_declaration_remove_ahead.js | The main process DevToolsServer has no pending connection when the test ends -
[task 2020-09-24T12:04:00.710Z] 12:04:00 INFO - GECKO(1529) | MEMORY STAT | vsize 20975508MB | residentFast 1236MB
[task 2020-09-24T12:04:00.711Z] 12:04:00 INFO - TEST-OK | devtools/client/inspector/changes/test/browser_changes_declaration_remove_ahead.js | took 2127ms
[task 2020-09-24T12:04:00.746Z] 12:04:00 INFO - checking window state
[task 2020-09-24T12:04:00.774Z] 12:04:00 INFO - TEST-START | devtools/client/inspector/changes/test/browser_changes_declaration_remove_disabled.js

Comment 1

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

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

Comment 2

[Intermittent Failures Robot]

21 failures in 656 pushes (0.032 failures/push) were associated with this bug yesterday.

Repository breakdown:

• autoland: 14
• mozilla-central: 6
• try: 1

Platform breakdown:

• windows10-64: 8
• macosx1014-64: 4
• linux1804-64-asan: 7
• windows10-64-ccov: 2

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1667086&startday=2020-09-25&endday=2020-09-25&tree=all

Comment 3

[Natalia Csoregi [:nataliaCs]]

Update:

There have been 43 failures since the bug was created:

• 15 failures on Linux 18.04 x64 asan opt
• 9 failures on OS X 10.14 debug
• 3 failures on Windows 10 x64 CCov opt
• 16 failures on Windows 10 x64 asan/debug

Recent failure log: https://treeherder.mozilla.org/logviewer.html#/jobs?job_id=316853434&repo=autoland&lineNumber=2937

Comment 4

[Intermittent Failures Robot]

46 failures in 4019 pushes (0.011 failures/push) were associated with this bug in the last 7 days.

This is the #16 most frequent failure this week.

** This failure happened more than 30 times this week! Resolving this bug is a high priority. **

** Try to resolve this bug as soon as possible. If unresolved for 2 weeks, the affected test(s) may be disabled. **

Repository breakdown:

• autoland: 33
• mozilla-central: 11
• try: 2

Platform breakdown:

• linux1804-64-asan: 17
• macosx1014-64: 9
• windows10-64: 17
• windows10-64-ccov: 3

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1667086&startday=2020-09-21&endday=2020-09-27&tree=all

Comment 5

[Alexandre Poirot [:ochameau]]

Attachment: Bug 1667086 - [devtools] Wait for state instead of TRACK_CHANGE events in browser_changes_declaration_remove_ahead.js.

This is because of bug 1596093, introducing throttling around TRACK_CHANGE
and making its listening less reliable.

Comment 6

[Intermittent Failures Robot]

16 failures in 845 pushes (0.019 failures/push) were associated with this bug yesterday.

Repository breakdown:

• autoland: 11
• mozilla-central: 4
• try: 1

Platform breakdown:

• windows10-64: 4
• macosx1014-64: 4
• linux1804-64-asan: 7
• windows10-64-qr: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1667086&startday=2020-09-29&endday=2020-09-29&tree=all

Comment 7

[Alexandre Poirot [:ochameau]]

try run with many retries:
https://treeherder.mozilla.org/#/jobs?repo=try&selectedTaskRun=QGlTaaOzSUiT4AhxBlfyHA.0&revision=45c4eba2ae62a350e438b4e399b8b6f8335cb81d

Comment 8

[Chris Peterson [:cpeterson]]

Tracking for Fission Beta milestone (M7).

Comment 9

[Pulsebot]

Pushed by [e-mail]:
https://hg.mozilla.org/integration/autoland/rev/ae40917b2a2b
[devtools] Wait for state instead of TRACK_CHANGE events in browser_changes_declaration_remove_ahead.js. r=rcaliman

Comment 10

[Atila Butkovits]

https://hg.mozilla.org/mozilla-central/rev/ae40917b2a2b

Comment 11

[Intermittent Failures Robot]

53 failures in 4195 pushes (0.013 failures/push) were associated with this bug in the last 7 days.

This is the #15 most frequent failure this week.

** This failure happened more than 30 times this week! Resolving this bug is a high priority. **

** Try to resolve this bug as soon as possible. If unresolved for 2 weeks, the affected test(s) may be disabled. **

Repository breakdown:

• autoland: 36
• mozilla-central: 8
• try: 9

Platform breakdown:

• linux1804-64-asan: 13
• windows10-64: 26
• macosx1014-64: 12
• windows10-64-qr: 1
• linux1804-64-ccov: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1667086&startday=2020-09-28&endday=2020-10-04&tree=all