Closed Bug 1494941 Opened Last year Closed 8 months ago

Intermittent devtools/client/webconsole/test/mochitest/browser_jsterm_await_helper_dollar_underscore.js | Test timed out -

Categories

(DevTools :: Console, defect, P5)

defect

Tracking

(firefox65 fixed, firefox66 fixed, firefox67 fixed)

RESOLVED FIXED
Firefox 66
Tracking Status
firefox65 --- fixed
firefox66 --- fixed
firefox67 --- fixed

People

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

Details

(Keywords: intermittent-failure)

Attachments

(2 files)

Filed by: apavel [at] mozilla.com

https://treeherder.mozilla.org/logviewer.html#?job_id=202159767&repo=mozilla-inbound

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

01:12:45     INFO - TEST-START | devtools/client/webconsole/test/mochitest/browser_jsterm_await_helper_dollar_underscore.js
01:12:45     INFO - GECKO(927) | ++DOCSHELL 0x10a822000 == 2 [pid = 930] [id = {586c9c9e-94c9-6d45-b210-9185d77b5f22}]
01:12:45     INFO - GECKO(927) | ++DOMWINDOW == 3 (0x11b87fc00) [pid = 930] [serial = 107] [outer = 0x0]
01:12:45     INFO - GECKO(927) | ++DOMWINDOW == 4 (0x112dc8c00) [pid = 930] [serial = 108] [outer = 0x11b87fc00]
01:12:45     INFO - GECKO(927) | ++DOMWINDOW == 5 (0x11a1d3c00) [pid = 930] [serial = 109] [outer = 0x11b87fc00]
01:12:46     INFO - GECKO(927) | ++DOCSHELL 0x11fe55800 == 7 [pid = 927] [id = {87054216-eec1-304b-a449-b3204b8a2224}]
01:12:46     INFO - GECKO(927) | ++DOMWINDOW == 25 (0x10dc62400) [pid = 927] [serial = 385] [outer = 0x0]
01:12:46     INFO - GECKO(927) | ++DOMWINDOW == 26 (0x11f4e7c00) [pid = 927] [serial = 386] [outer = 0x10dc62400]
01:12:46     INFO - GECKO(927) | ++DOMWINDOW == 27 (0x11f4f2c00) [pid = 927] [serial = 387] [outer = 0x10dc62400]
01:12:46     INFO - GECKO(927) | ++DOCSHELL 0x12c028000 == 8 [pid = 927] [id = {c0b0f4f1-2e15-5e4c-a7da-6e7879448afc}]
01:12:46     INFO - GECKO(927) | ++DOMWINDOW == 28 (0x11f42fc00) [pid = 927] [serial = 388] [outer = 0x0]
01:12:46     INFO - GECKO(927) | ++DOMWINDOW == 29 (0x12cbbac00) [pid = 927] [serial = 389] [outer = 0x11f42fc00]
01:12:49     INFO - GECKO(927) | --DOCSHELL 0x10ba20000 == 0 [pid = 932] [id = {77e557ad-9819-6c42-8256-1633952448c5}]
01:12:51     INFO - GECKO(927) | JavaScript error: , line 0: uncaught exception: await-rej
01:12:52     INFO - GECKO(927) | --DOMWINDOW == 4 (0x11bef0200) [pid = 931] [serial = 104] [outer = 0x0] [url = data:text/html;charset=utf-8,Web Console test failing top-level await]
01:12:52     INFO - GECKO(927) | --DOCSHELL 0x10c61d000 == 1 [pid = 931] [id = {25fcefb0-1397-5446-b6d2-737a2a21263f}]
01:12:52     INFO - GECKO(927) | --DOMWINDOW == 28 (0x10dc5fe00) [pid = 927] [serial = 373] [outer = 0x0] [url = about:blank]
01:12:52     INFO - GECKO(927) | --DOMWINDOW == 27 (0x122607a00) [pid = 927] [serial = 378] [outer = 0x0] [url = about:blank]
01:12:52     INFO - GECKO(927) | --DOMWINDOW == 26 (0x122609000) [pid = 927] [serial = 381] [outer = 0x0] [url = chrome://devtools/content/webconsole/index.html]
01:12:52     INFO - GECKO(927) | --DOMWINDOW == 25 (0x11f42ec00) [pid = 927] [serial = 376] [outer = 0x0] [url = chrome://devtools/content/webconsole/index.html]
01:12:53     INFO - GECKO(927) | --DOMWINDOW == 4 (0x11b880000) [pid = 930] [serial = 104] [outer = 0x0] [url = about:blank]
01:12:53     INFO - GECKO(927) | --DOCSHELL 0x11aa03800 == 1 [pid = 930] [id = {1948148b-cb23-754b-a64d-935310fbfa59}]
01:12:56     INFO - GECKO(927) | --DOMWINDOW == 24 (0x13040d000) [pid = 927] [serial = 380] [outer = 0x0] [url = about:devtools-toolbox]
01:12:56     INFO - GECKO(927) | --DOMWINDOW == 23 (0x12c552400) [pid = 927] [serial = 383] [outer = 0x0] [url = about:blank]
01:12:56     INFO - GECKO(927) | --DOMWINDOW == 22 (0x11f4ef000) [pid = 927] [serial = 384] [outer = 0x0] [url = about:blank]
01:12:56     INFO - GECKO(927) | --DOMWINDOW == 21 (0x11f4f2000) [pid = 927] [serial = 374] [outer = 0x0] [url = about:blank]
01:12:56     INFO - GECKO(927) | --DOMWINDOW == 20 (0x12c548400) [pid = 927] [serial = 377] [outer = 0x0] [url = about:blank]
01:12:56     INFO - GECKO(927) | --DOMWINDOW == 19 (0x11f4f0400) [pid = 927] [serial = 379] [outer = 0x0] [url = about:blank]
01:12:56     INFO - GECKO(927) | --DOMWINDOW == 18 (0x12bb81c00) [pid = 927] [serial = 375] [outer = 0x0] [url = about:devtools-toolbox]
01:12:56     INFO - GECKO(927) | --DOMWINDOW == 17 (0x134689800) [pid = 927] [serial = 382] [outer = 0x0] [url = about:blank]
01:12:56     INFO - GECKO(927) | --DOMWINDOW == 1 (0x11157ee00) [pid = 932] [serial = 95] [outer = 0x0] [url = data:text/html;charset=utf-8,Web Console test failing top-level await]
01:12:56     INFO - GECKO(927) | --DOMWINDOW == 3 (0x11becf000) [pid = 931] [serial = 106] [outer = 0x0] [url = data:text/html;charset=utf-8,Web Console test failing top-level await]
01:12:56     INFO - GECKO(927) | --DOMWINDOW == 2 (0x114ab5400) [pid = 931] [serial = 108] [outer = 0x0] [url = about:blank]
01:12:57     INFO - GECKO(927) | --DOMWINDOW == 3 (0x11a1d7000) [pid = 930] [serial = 106] [outer = 0x0] [url = about:blank]
01:12:57     INFO - GECKO(927) | --DOMWINDOW == 2 (0x112dc8c00) [pid = 930] [serial = 108] [outer = 0x0] [url = about:blank]
01:13:00     INFO - GECKO(927) | --DOMWINDOW == 0 (0x11b2d9800) [pid = 932] [serial = 97] [outer = 0x0] [url = data:text/html;charset=utf-8,Web Console test failing top-level await]
01:14:15     INFO - TEST-INFO | started process screencapture
01:14:16     INFO - TEST-INFO | screencapture: exit 0
01:14:16     INFO - Buffered messages logged at 01:12:45
01:14:16     INFO - Entering test bound 
01:14:16     INFO - Adding a new tab with URL: data:text/html;charset=utf-8,top-level await + $_
01:14:16     INFO - Buffered messages logged at 01:12:46
01:14:16     INFO - Tab added and finished loading
01:14:16     INFO - Opening the toolbox
01:14:16     INFO - Buffered messages logged at 01:12:47
01:14:16     INFO - Toolbox opened and focused
01:14:16     INFO - Evaluate a simple expression to populate $_
01:14:16     INFO - Matched a message with text: "2", all messages received.
01:14:16     INFO - Matched a message with text: "3", all messages received.
01:14:16     INFO - Buffered messages logged at 01:12:48
01:14:16     INFO - TEST-PASS | devtools/client/webconsole/test/mochitest/browser_jsterm_await_helper_dollar_underscore.js | $_ works as expected - 
01:14:16     INFO - Check that $_ does not get replaced until the top-level await is resolved
01:14:16     INFO - Matched a message with text: "4", all messages received.
01:14:16     INFO - TEST-PASS | devtools/client/webconsole/test/mochitest/browser_jsterm_await_helper_dollar_underscore.js | $_ was not impacted by the top-level await input - 
01:14:16     INFO - Buffered messages logged at 01:12:49
01:14:16     INFO - Matched a message with text: "Array(4) [ 1, 2, 3, 4 ]", all messages received.
01:14:16     INFO - TEST-PASS | devtools/client/webconsole/test/mochitest/browser_jsterm_await_helper_dollar_underscore.js | the top-level await result can use $_ in its returned value - 
01:14:16     INFO - Buffered messages logged at 01:12:50
01:14:16     INFO - Matched a message with text: "Array(5) [ 1, 2, 3, 4, 5 ]", all messages received.
01:14:16     INFO - TEST-PASS | devtools/client/webconsole/test/mochitest/browser_jsterm_await_helper_dollar_underscore.js | $_ is assigned with the result of the top-level await - 
01:14:16     INFO - Check that awaiting for a rejecting promise does not re-assign $_
01:14:16     INFO - Buffered messages logged at 01:12:51
01:14:16     INFO - Console message: [JavaScript Error: "uncaught exception: await-rej"]
01:14:16     INFO - Matched a message with text: "await-rej", all messages received.
01:14:16     INFO - Matched a message with text: "Array(5) [ 1, 2, 3, 4, 5 ]", all messages received.
01:14:16     INFO - TEST-PASS | devtools/client/webconsole/test/mochitest/browser_jsterm_await_helper_dollar_underscore.js | $_ wasn't re-assigned - 
01:14:16     INFO - Check that $_ gets the value of the last resolved await expression
01:14:16     INFO - Buffered messages logged at 01:12:54
01:14:16     INFO - Matched a message with text: "await-concurrent-2000", all messages received.
01:14:16     INFO - Buffered messages finished
01:14:16     INFO - TEST-UNEXPECTED-FAIL | devtools/client/webconsole/test/mochitest/browser_jsterm_await_helper_dollar_underscore.js | Test timed out - 
01:14:16     INFO - GECKO(927) | ++DOMWINDOW == 18 (0x11f4ef000) [pid = 927] [serial = 390] [outer = 0x10dc62400]
01:14:17     INFO - Removing tab.
01:14:17     INFO - Waiting for event: 'TabClose' on [object XULElement].
01:14:17     INFO - Got event: 'TabClose' on [object XULElement].
01:14:17     INFO - Tab removed and finished closing
01:14:17     INFO - GECKO(927) | --DOCSHELL 0x11fe55800 == 7 [pid = 927] [id = {87054216-eec1-304b-a449-b3204b8a2224}]
01:14:17     INFO - GECKO(927) | --DOCSHELL 0x12c028000 == 6 [pid = 927] [id = {c0b0f4f1-2e15-5e4c-a7da-6e7879448afc}]
01:14:17     INFO - GECKO(927) | MEMORY STAT | vsize 4459MB | residentFast 576MB | heapAllocated 147MB
01:14:17     INFO - TEST-OK | devtools/client/webconsole/test/mochitest/browser_jsterm_await_helper_dollar_underscore.js | took 91322ms
Pushed by nchevobbe@mozilla.com:
https://hg.mozilla.org/integration/autoland/rev/260b51e1a202
Fix browser_jsterm_await_helper_dollar_underscore.js intermittent; r=Honza.
Status: NEW → RESOLVED
Closed: 9 months ago
Resolution: --- → FIXED
Target Milestone: --- → Firefox 66
Assignee: nobody → nchevobbe
Status: RESOLVED → REOPENED
Flags: needinfo?(nchevobbe)
Resolution: FIXED → ---

looks like we might hit the timeout limit, I'll add a requestLongerTimeout

Flags: needinfo?(nchevobbe)
Pushed by nchevobbe@mozilla.com:
https://hg.mozilla.org/integration/autoland/rev/0cf4bfe64f61
Add requestLongerTimeout in browser_jsterm_await_helper_dollar_underscore.js; r=Honza.
Status: REOPENED → RESOLVED
Closed: 9 months ago8 months ago
Resolution: --- → FIXED

This appeared here: https://treeherder.mozilla.org/#/jobs?repo=mozilla-inbound&fromchange=a57aaf355b6411a93f8e815afc3415344df86f59&searchStr=windows%2C10%2Cx64%2Cpgo%2Cmochitests%2Cwith%2Ce10s%2Ctest-windows10-64-pgo%2Fopt-mochitest-devtools-chrome-e10s-1%2Cm-e10s%28dt1%29&selectedJob=231338115 on windows 10 x64 pgo.

Failure log: https://treeherder.mozilla.org/logviewer.html#/jobs?job_id=231338115&repo=mozilla-inbound&lineNumber=2050

21:10:55 INFO - TEST-PASS | devtools/client/webconsole/test/mochitest/browser_jsterm_await_helper_dollar_underscore.js | $_ wasn't re-assigned -
21:10:55 INFO - Check that $_ gets the value of the last resolved await expression
21:10:55 INFO - Buffered messages logged at 21:10:10
21:10:55 INFO - Longer timeout required, waiting longer... Remaining timeouts: 1
21:10:55 INFO - Buffered messages finished
21:10:55 INFO - TEST-UNEXPECTED-FAIL | devtools/client/webconsole/test/mochitest/browser_jsterm_await_helper_dollar_underscore.js | Test timed out -
21:10:55 INFO - GECKO(7448) | console.warn: "Error while detaching the thread front: 'detach' request packet to 'server1.conn94.child1/context22' can't be sent as the connection is closed."
21:10:55 INFO - Removing tab.
21:10:55 INFO - Waiting for event: 'TabClose' on [object XULElement].
21:10:55 INFO - Got event: 'TabClose' on [object XULElement].
21:10:55 INFO - Tab removed and finished closing
21:10:55 INFO - GECKO(7448) | console.warn: "Error while detaching the thread front: 'detach' request packet to 'server1.conn93.child1/context22' can't be sent as the connection is closed."
21:10:55 INFO - Removing tab.
21:10:55 INFO - Waiting for event: 'TabClose' on [object XULElement].
21:10:55 INFO - Got event: 'TabClose' on [object XULElement].
21:10:55 INFO - Tab removed and finished closing
21:10:55 INFO - GECKO(7448) | MEMORY STAT | vsize 2104016MB | vsizeMaxContiguous 65224398MB | residentFast 523MB | heapAllocated 91MB
21:10:55 INFO - TEST-OK | devtools/client/webconsole/test/mochitest/browser_jsterm_await_helper_dollar_underscore.js | took 90594ms
21:10:55 INFO - checking window state
21:10:55 INFO - TEST-START | devtools/client/webconsole/test/mochitest/browser_jsterm_await_paused.js

Flags: needinfo?(nchevobbe)

Not sure what happened there. Also, there was only 1 failure in 3 weeks, let's see if we have others in the next weeks.

Flags: needinfo?(nchevobbe)
You need to log in before you can comment on or make changes to this bug.