1540803 - Intermittent devtools/client/debugger/new/test/mochitest/browser_dbg-pretty-print-paused.js | top frame's source is selected -

Status: RESOLVED FIXED

(DevTools :: Debugger, defect, P5)

Description

[Treeherder Bug Filer]

#[markdown(off)]
Filed by: nerli [at] mozilla.com

https://treeherder.mozilla.org/logviewer.html#?job_id=237372553&repo=autoland

https://queue.taskcluster.net/v1/task/eo6CvhLwQIGJe19EUaljSg/runs/0/artifacts/public/logs/live_backing.log

17:47:40 INFO - TEST-PASS | devtools/client/debugger/new/test/mochitest/browser_dbg-pretty-print-paused.js | top frame's source is selected -
17:47:40 INFO - TEST-PASS | devtools/client/debugger/new/test/mochitest/browser_dbg-pretty-print-paused.js | Line is highlighted as paused -
17:47:40 INFO - TEST-PASS | devtools/client/debugger/new/test/mochitest/browser_dbg-pretty-print-paused.js | There is only one line -
17:47:40 INFO - TEST-PASS | devtools/client/debugger/new/test/mochitest/browser_dbg-pretty-print-paused.js | debug line is visible -
17:47:40 INFO - TEST-PASS | devtools/client/debugger/new/test/mochitest/browser_dbg-pretty-print-paused.js | expression is highlighted as paused -
17:47:40 INFO - TEST-PASS | devtools/client/debugger/new/test/mochitest/browser_dbg-pretty-print-paused.js | gutter is visible -
17:47:40 INFO - Waiting for state change: selected source
17:47:40 INFO - Buffered messages logged at 17:47:39
17:47:40 INFO - Finished waiting for state change: selected source
17:47:40 INFO - Buffered messages finished
17:47:40 INFO - TEST-UNEXPECTED-FAIL | devtools/client/debugger/new/test/mochitest/browser_dbg-pretty-print-paused.js | top frame's source is selected -
17:47:40 INFO - Stack trace:
17:47:40 INFO - chrome://mochikit/content/browser-test.js:test_ok:1304
17:47:40 INFO - chrome://mochitests/content/browser/devtools/client/debugger/new/test/mochitest/helpers.js:assertPausedLocation:305
17:47:40 INFO - chrome://mochitests/content/browser/devtools/client/debugger/new/test/mochitest/browser_dbg-pretty-print-paused.js:null:18
17:47:40 INFO - chrome://mochikit/content/browser-test.js:Tester_execTest/<:1106
17:47:40 INFO - chrome://mochikit/content/browser-test.js:Tester_execTest:1134
17:47:40 INFO - chrome://mochikit/content/browser-test.js:nextTest/<:995
17:47:40 INFO - chrome://mochikit/content/tests/SimpleTest/SimpleTest.js:SimpleTest.waitForFocus/waitForFocusInner/focusedOrLoaded/<:803
17:47:40 INFO - Not taking screenshot here: see the one that was previously logged
17:47:40 INFO - TEST-UNEXPECTED-FAIL | devtools/client/debugger/new/test/mochitest/browser_dbg-pretty-print-paused.js | Expected pause line on line 2, it is on 2 -
17:47:40 INFO - Stack trace:
17:47:40 INFO - chrome://mochikit/content/browser-test.js:test_ok:1304
17:47:40 INFO - chrome://mochitests/content/browser/devtools/client/debugger/new/test/mochitest/helpers.js:assertDebugLine:332
17:47:40 INFO - chrome://mochitests/content/browser/devtools/client/debugger/new/test/mochitest/helpers.js:assertPausedLocation:312
17:47:40 INFO - chrome://mochitests/content/browser/devtools/client/debugger/new/test/mochitest/browser_dbg-pretty-print-paused.js:null:18
17:47:40 INFO - chrome://mochikit/content/browser-test.js:Tester_execTest/<:1106
17:47:40 INFO - chrome://mochikit/content/browser-test.js:Tester_execTest:1134
17:47:40 INFO - chrome://mochikit/content/browser-test.js:nextTest/<:995
17:47:40 INFO - chrome://mochikit/content/tests/SimpleTest/SimpleTest.js:SimpleTest.waitForFocus/waitForFocusInner/focusedOrLoaded/<:803
17:47:40 INFO - TEST-PASS | devtools/client/debugger/new/test/mochitest/browser_dbg-pretty-print-paused.js | gutter is visible -
17:47:40 INFO - Resuming from 2
17:47:40 INFO - GECKO(5504) | [ACTION] COMMAND [start] - {"type":"COMMAND","command":"resume","thread":"server1.conn55.child1/context18","seqId":"7","status":"start"}
17:47:40 INFO - GECKO(5504) | [ACTION] REMOVE_BREAKPOINT - {}
17:47:40 INFO - GECKO(5504) | [ACTION] SET_BREAKPOINT - {"type":"SET_BREAKPOINT","breakpoint":{"id":"sourceURL-http://example.com/browser/devtools/client/debugger/new/test/mochitest/examples/math.min.js/originalSource-d096ee6b9228104ac049e96c5926c143:18:","disabled":false,"options":{},"location":{"sourceId":"sourceURL-http://example.com/browser/devtools/client/debugger/new/test/mochitest/examples/math.min.js/originalSource-d096ee6b9228104ac049e96c5926c143","sourceUrl":"http://example.com/browser/devtools/client/debugger/new/test/mochitest/examples/math.min.js:formatted","line":18,"column":0},"astLocation":{"name":"arithmetic","offset":{"line":1},"index":0},"generatedLocation":{"line":2,"column":2,"sourceId":"sourceURL-http://example.com/browser/devtools/client/debugger/new/test/mochitest/examples/math.min.js","sourceUrl":"http://example.com/browser/devtools/client/debugger/new/test/mochitest/examples/math.min.js"},"text":"add(4,4,function(a){","originalText":"add(4, 4, function (a) {"}}
17:47:40 INFO - GECKO(5504) | [ACTION] MAP_FRAMES - {}
17:47:40 INFO - GECKO(5504) | [ACTION] RESUME - {"type":"RESUME","thread":"server1.conn55.child1/context18","wasStepping":false}
17:47:40 INFO - GECKO(5504) | [ACTION] EVALUATE_EXPRESSIONS - {"type":"EVALUATE_EXPRESSIONS","inputs":[],"results":[]}
17:47:40 INFO - GECKO(5504) | [ACTION] COMMAND [done] - {"type":"COMMAND","command":"resume","thread":"server1.conn55.child1/context18","seqId":"7","status":"done","value":{"from":"server1.conn55.child1/context18","type":"resumed"}}
17:47:40 INFO - Leaving test bound
17:47:40 INFO - GECKO(5504) | [ACTION] SET_SELECTED_LOCATION - {"type":"SET_SELECTED_LOCATION","source":{"url":"http://example.com/browser/devtools/client/debugger/new/test/mochitest/examples/math.min.js:formatted","relativeUrl":"http://example.com/browser/devtools/client/debugger/new/test/mochitest/examples/math.min.js:formatted","id":"sourceURL-http://example.com/browser/devtools/client/debugger/new/test/mochitest/examples/math.min.js/originalSource-d096ee6b9228104ac049e96c5926c143","isBlackBoxed":false,"isPrettyPrinted":true,"isWasm":false,"contentType":"text/javascript","loadedState":"loaded","introductionUrl":null,"isExtension":false,"actors":[],"text":""},"location":{"sourceId":"sourceURL-http://example.com/browser/devtools/client/debugger/new/test/mochitest/examples/math.min.js/originalSource-d096ee6b9228104ac049e96c5926c143","line":2,"column":2}}
17:47:40 INFO - GECKO(5504) | ++DOMWINDOW == 30 (0EC27800) [pid = 4784] [serial = 398] [outer = 009DE4C0]
17:47:40 INFO - GECKO(5504) | console.warn: "Error while detaching the thread front: 'detach' request packet to 'server1.conn55.child1/context18' can't be sent as the connection is closed."
17:47:41 INFO - GECKO(5504) | --DOMWINDOW == 3 (01368800) [pid = 4584] [serial = 65] [outer = 00000000] [url = about:blank]
17:47:41 INFO - GECKO(5504) | --DOMWINDOW == 2 (089AD000) [pid = 4584] [serial = 67] [outer = 00000000] [url = about:blank]
17:47:41 INFO - GECKO(5504) | --DOMWINDOW == 29 (0EB35C00) [pid = 4784] [serial = 380] [outer = 00000000] [url = about:blank]
17:47:41 INFO - GECKO(5504) | --DOMWINDOW == 28 (11187400) [pid = 4784] [serial = 381] [outer = 00000000] [url = about:devtools-toolbox]
17:47:41 INFO - GECKO(5504) | --DOMWINDOW == 27 (13E19800) [pid = 4784] [serial = 383] [outer = 00000000] [url = about:blank]
17:47:41 INFO - GECKO(5504) | --DOMWINDOW == 26 (13E1B800) [pid = 4784] [serial = 384] [outer = 00000000] [url = about:blank]
17:47:42 INFO - GECKO(5504) | [Parent 4784, Main Thread] WARNING: NS_ENSURE_TRUE(!mHasOrHasHadOwnerWindow || mOwnerWindow) failed: file z:/build/build/src/obj-firefox/dist/include\mozilla/DOMEventTargetHelper.h, line 135
17:47:42 INFO - GECKO(5504) | [Parent 4784, Main Thread] WARNING: NS_ENSURE_TRUE(!mHasOrHasHadOwnerWindow || mOwnerWindow) failed: file z:/build/build/src/obj-firefox/dist/include\mozilla/DOMEventTargetHelper.h, line 135
17:47:42 INFO - GECKO(5504) | [Parent 4784, Main Thread] WARNING: NS_ENSURE_TRUE(!mHasOrHasHadOwnerWindow || mOwnerWindow) failed: file z:/build/build/src/obj-firefox/dist/include\mozilla/DOMEventTargetHelper.h, line 135
17:47:42 INFO - GECKO(5504) | [Parent 4784, Main Thread] WARNING: NS_ENSURE_TRUE(!mHasOrHasHadOwnerWindow || mOwnerWindow) failed: file z:/build/build/src/obj-firefox/dist/include\mozilla/DOMEventTargetHelper.h, line 135
17:47:42 INFO - Removing tab.
17:47:42 INFO - Waiting for event: 'TabClose' on [object XULElement].
17:47:42 INFO - Got event: 'TabClose' on [object XULElement].
17:47:42 INFO - Tab removed and finished closing

Comment 1

[Intermittent Failures Robot]

25 failures in 398 pushes (0.063 failures/push) were associated with this bug yesterday.

Repository breakdown:

• autoland: 21
• mozilla-central: 4

Platform breakdown:

• windows7-32: 1
• linux64-shippable: 7
• linux32-shippable: 5
• linux64: 11
• windows10-64-ccov: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1540803&startday=2019-04-01&endday=2019-04-01&tree=all

Comment 2

[Intermittent Failures Robot]

46 failures in 461 pushes (0.1 failures/push) were associated with this bug yesterday.

Repository breakdown:

• autoland: 22
• mozilla-central: 16
• try: 4
• mozilla-inbound: 4

Platform breakdown:

• linux64-shippable: 9
• linux64: 21
• linux32-shippable: 12
• osx-10-10-shippable: 1
• linux64-devedition: 1
• windows10-64-ccov: 1
• windows10-64-shippable: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1540803&startday=2019-04-02&endday=2019-04-02&tree=all

Comment 3

[Andreea Pavel [:apavel]]

This appears to be from Bug 1539493, Jason can you take a look?

There are 69 total failures in the last 7 days on linux32-shippable opt, linux64 debug and opt, linux64-shippable opt

Comment 4

[Andreea Pavel [:apavel]]

Retriigers: https://treeherder.mozilla.org/#/jobs?repo=autoland&searchStr=windows%2C7%2Cdebug%2Cmochitests%2Cwith%2Ce10s%2Ctest-windows7-32%2Fdebug-mochitest-devtools-chrome-e10s-4%2Cm-e10s%28dt4%29&tochange=cfbec1b8ef406a89ab04452861b883800cc0e393&fromchange=7de6e431f1ae32cacc2b5d4aea1c47bf7900c4c4&group_state=expanded&selectedJob=237773918

Comment 5

[Jason Laster [:jlast]]

I'm on PTO. Perhaps Logan can take a look. The error looks timing related.

Comment 6

[Logan Smyth [:loganfsmyth]]

Attachment: Bug 1540803 - Fix flakey test by waiting for source to fully load.

Comment 7

[Logan Smyth [:loganfsmyth]]

Here's a patch that is a guess that may stabilize it.

Try run here: https://treeherder.mozilla.org/#/jobs?repo=try&revision=0ace139cab4292959b8223fda537a7f03b33e5ea

Comment 8

[Intermittent Failures Robot]

75 failures in 2843 pushes (0.026 failures/push) were associated with this bug in the last 7 days.

This is the #27 most frequent failure this week.

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

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

Repository breakdown:

• autoland: 43
• mozilla-central: 21
• try: 5
• mozilla-inbound: 6

Platform breakdown:

• linux64: 35
• windows7-32: 1
• linux32-shippable: 18
• linux64-shippable: 16
• windows10-64-ccov: 2
• osx-10-10-shippable: 1
• linux64-devedition: 1
• windows10-64-shippable: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1540803&startday=2019-04-01&endday=2019-04-07&tree=all

Comment 9

[Pulsebot]

Pushed by [e-mail]:
https://hg.mozilla.org/integration/autoland/rev/6d5dcdf3f56b
Fix flakey test by waiting for source to fully load. r=davidwalsh

Comment 10

[Dorel Luca [:dluca]]

https://hg.mozilla.org/mozilla-central/rev/6d5dcdf3f56b