1620638 - Intermittent TEST-UNEXPECTED-TIMEOUT | devtools/client/webconsole/test/browser/browser_jsterm_autocomplete_arrow_keys.js | application timed out after 370 seconds with no output

Status: NEW

(DevTools :: Console, defect, P5)

Description

[Treeherder Bug Filer]

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

---

[task 2020-03-06T15:53:39.483Z] 15:53:39 INFO - TEST-START | devtools/client/webconsole/test/browser/browser_jsterm_autocomplete_arrow_keys.js
[task 2020-03-06T15:53:39.959Z] 15:53:39 INFO - GECKO(3220) | ### XPCOM_MEM_BLOAT_LOG defined -- logging bloat/leaks to c:\users\task_1583507479\appdata\local\temp\tmpu_kvvs.mozrunner\runtests_leaks_tab_pid3164.log
[task 2020-03-06T15:53:39.983Z] 15:53:39 INFO - GECKO(3220) | [Child 3164, Main Thread] WARNING: No CID found when attempting to map contract ID: file z:/build/build/src/xpcom/components/nsComponentManager.cpp, line 721
[task 2020-03-06T15:53:40.123Z] 15:53:40 INFO - GECKO(3220) | [Child 3164: Main Thread]: I/DocShellAndDOMWindowLeak ++DOCSHELL 00CB5800 == 1 [pid = 3164] [id = {8ff6e130-635d-4d0b-bd9d-e68193e3777d}]
[task 2020-03-06T15:53:40.123Z] 15:53:40 INFO - GECKO(3220) | [Child 3164, Main Thread] WARNING: 'NS_FAILED(rv)', file z:/build/build/src/widget/windows/nsLookAndFeel.cpp, line 853
[task 2020-03-06T15:53:40.123Z] 15:53:40 INFO - GECKO(3220) | [Child 3164: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 1 (00C0CAB0) [pid = 3164] [serial = 1] [outer = 00000000]
[task 2020-03-06T15:53:40.126Z] 15:53:40 INFO - GECKO(3220) | [Child 3164, Main Thread] WARNING: NS_ENSURE_TRUE(mPresShell) failed: file z:/build/build/src/layout/base/nsPresContext.cpp, line 845
[task 2020-03-06T15:53:40.126Z] 15:53:40 INFO - GECKO(3220) | [Child 3164: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 2 (00CBAC00) [pid = 3164] [serial = 2] [outer = 00C0CAB0]
[task 2020-03-06T15:53:40.165Z] 15:53:40 INFO - GECKO(3220) | [Child 3164, Main Thread] WARNING: 'NS_FAILED(GetAccentColor(unused))', file z:/build/build/src/widget/windows/nsLookAndFeel.cpp, line 481
[task 2020-03-06T15:53:40.246Z] 15:53:40 INFO - GECKO(3220) | [Child 3164: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 3 (00CBB800) [pid = 3164] [serial = 3] [outer = 00C0CAB0]
[task 2020-03-06T15:53:40.281Z] 15:53:40 INFO - GECKO(3220) | [Child 3164, Main Thread] WARNING: '!aWin', file z:/build/build/src/dom/base/Document.cpp, line 1395
[task 2020-03-06T15:53:40.281Z] 15:53:40 INFO - GECKO(3220) | [Child 3164, Main Thread] WARNING: '!aWin', file z:/build/build/src/dom/base/Document.cpp, line 1395

[task 2020-03-06T16:00:03.582Z] 16:00:03 INFO - TEST-PASS | devtools/client/webconsole/test/browser/browser_jsterm_autocomplete_arrow_keys.js | completeNode is empty -
[task 2020-03-06T16:00:03.582Z] 16:00:03 INFO - Trigger autocomplete popup opening
[task 2020-03-06T16:00:03.582Z] 16:00:03 INFO - Buffered messages finished
[task 2020-03-06T16:00:03.583Z] 16:00:03 ERROR - TEST-UNEXPECTED-TIMEOUT | devtools/client/webconsole/test/browser/browser_jsterm_autocomplete_arrow_keys.js | application timed out after 370 seconds with no output
[task 2020-03-06T16:00:03.583Z] 16:00:03 ERROR - Force-terminating active process(es).
[task 2020-03-06T16:00:03.583Z] 16:00:03 INFO - Determining child pids from psutil...
[task 2020-03-06T16:00:03.583Z] 16:00:03 INFO - [5012]
[task 2020-03-06T16:00:03.584Z] 16:00:03 INFO - ==> process 5012 launched child process 5616 ("Z:\task_1583507479\build\application\firefox\firefox.exe" -contentproc --channel="5012.0.215754821\1372648441" -childID 1 -isForBrowser -prefsHandle 2188 -prefMapHandle 2180 -prefsLen 1 -prefMapSize 231022 -parentBuildID 20200306134956 -appdir "Z:\task_1583507479\build\application\firefox\browser" - 5012 "\.\pipe\gecko-crash-server-pipe.5012" 2232 tab)
[task 2020-03-06T16:00:03.584Z] 16:00:03 INFO - ==> process 5012 launched child process 3428 ("Z:\task_1583507479\build\application\firefox\firefox.exe" -contentproc --channel="5012.6.868665937\1030029168" -childID 2 -isForBrowser -prefsHandle 2444 -prefMapHandle 2440 -prefsLen 463 -prefMapSize 231022 -parentBuildID 20200306134956 -appdir "Z:\task_1583507479\build\application\firefox\browser" - 5012 "\.\pipe\gecko-crash-server-pipe.5012" 2456 tab)
[task 2020-03-06T16:00:03.584Z] 16:00:03 INFO - ==> process 5012 launched child process 5460 ("Z:\task_1583507479\build\application\firefox\firefox.exe" -contentproc --channel="5012.12.998346997\16703994" -childID 3 -isForBrowser -prefsHandle 4396 -prefMapHandle 4384 -prefsLen 524 -prefMapSize 231022 -parentBuildID 20200306134956 -appdir "Z:\task_1583507479\build\application\firefox\browser" - 5012 "\.\pipe\gecko-crash-server-pipe.5012" 4408 tab)
[task 2020-03-06T16:00:03.584Z] 16:00:03 INFO - ==> process 5012 launched child process 3164 ("Z:\task_1583507479\build\application\firefox\firefox.exe" -contentproc --channel="5012.18.1692526542\2031943916" -childID 4 -isForBrowser -prefsHandle 3768 -prefMapHandle 3652 -prefsLen 10840 -prefMapSize 231022 -parentBuildID 20200306134956 -appdir "Z:\task_1583507479\build\application\firefox\browser" - 5012 "\.\pipe\gecko-crash-server-pipe.5012" 4160 tab)
[task 2020-03-06T16:00:03.584Z] 16:00:03 INFO - ==> process 5012 launched child process 3520 ("Z:\task_1583507479\build\application\firefox\firefox.exe" -contentproc --channel="5012.24.1819243625\2022682874" -childID 5 -isForBrowser -prefsHandle 3700 -prefMapHandle 2964 -prefsLen 10940 -prefMapSize 231022 -parentBuildID 20200306134956 -appdir "Z:\task_1583507479\build\application\firefox\browser" - 5012 "\.\pipe\gecko-crash-server-pipe.5012" 2860 tab)
[task 2020-03-06T16:00:03.585Z] 16:00:03 INFO - Found child pids: set([3520, 3428, 5616, 5012, 5460, 3164])
[task 2020-03-06T16:00:03.585Z] 16:00:03 INFO - Killing process: 3520

Comment 1

[Intermittent Failures Robot]

5 failures in 5483 pushes (0.001 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• autoland: 4
• mozilla-central: 1

Platform breakdown:

• windows7-32: 5

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1620638&startday=2020-03-02&endday=2020-03-08&tree=all

Comment 2

[Intermittent Failures Robot]

10 failures in 5336 pushes (0.002 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• autoland: 10

Platform breakdown:

• windows7-32: 10

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

Comment 3

[Intermittent Failures Robot]

15 failures in 4955 pushes (0.003 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• mozilla-central: 2
• autoland: 13

Platform breakdown:

• windows7-32: 15

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1620638&startday=2020-03-16&endday=2020-03-22&tree=all

Comment 4

[Intermittent Failures Robot]

16 failures in 789 pushes (0.02 failures/push) were associated with this bug yesterday.

Repository breakdown:

• autoland: 15
• mozilla-central: 1

Platform breakdown:

• windows7-32: 16

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

Comment 5

[Cristina Coroiu [:ccoroiu]]

Started to fail with this push: https://treeherder.mozilla.org/#/jobs?repo=autoland&searchStr=Windows%2C7%2Cdebug%2CMochitests%2Ctest-windows7-32%2Fdebug-mochitest-devtools-chrome-e10s-3%2CM%28dt3%29&tochange=6d7fafa57a83a61ea4b4ffa5a6db338738918b35&fromchange=cc2aadaf59239d480105ecc5e409cd1c5f9861ea&selectedJob=294746273 from https://hg.mozilla.org/integration/autoland/rev/a2ebc0c68234d99bb4e598b9f1e3f4902df9ad54.

Nicolas, can you please take a look?

Comment 6

[Intermittent Failures Robot]

48 failures in 4773 pushes (0.01 failures/push) were associated with this bug in the last 7 days.

This is the #18 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: 47
• mozilla-central: 1

Platform breakdown:

• windows7-32: 48

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

Comment 7

[Andrei Ciure[:aciure]]

There are 36 failures associated to this bug in the last 7 days. These are occurring on windows7-32 debug builds.

recent log: https://treeherder.mozilla.org/logviewer.html#/jobs?job_id=295783040&repo=autoland&lineNumber=28019

Any updates on this?

Comment 8

[Nicolas Chevobbe [:nchevobbe]]

That's the same issue than in Bug 1620622. What I found is that somehow, on windows7, a setTimeout callback isn't called (devtools/client/shared/widgets/tooltip/HTMLTooltip.js#521-534), which makes the test wait for ever.

That's quite mysterious to me, and I'm not sure how I can debug that in a better way alone. I'll ask some people who might know.

Comment 9

[Intermittent Failures Robot]

33 failures in 5015 pushes (0.007 failures/push) were associated with this bug in the last 7 days.

This is the #37 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: 29
• mozilla-central: 3
• mozilla-release: 1

Platform breakdown:

• windows7-32: 33

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1620638&startday=2020-03-30&endday=2020-04-05&tree=all

Comment 10

[Daniel Varga [:dvarga]]

There are 53 failures associated with this bug in the last 7 days https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?startday=2020-04-02&endday=2020-04-09&tree=trunk&bug=1620638
Recent failure log: https://treeherder.mozilla.org/logviewer.html#/jobs?job_id=297050069&repo=autoland&lineNumber=28004
This has failed on windows7-32 - debug, pgo build type.

Comment 11

[Intermittent Failures Robot]

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

This is the #23 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: 53

Platform breakdown:

• windows7-32: 53

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

Comment 12

[Andreea Pavel [:apavel]]

Nicolas are there any updates here?

Comment 13

[Intermittent Failures Robot]

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

This is the #21 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: 45
• mozilla-central: 3
• try: 4

Platform breakdown:

• windows7-32: 52

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

Comment 14

[Nicolas Chevobbe [:nchevobbe]]

let's disable this.
This is part of a more global failures in the console autocomplete, only on windows 7 builds that I still didn't figure out as it's outside of my knowledge, and the people I asked for help so far were clueless as well :/

Comment 15

[Andreea Pavel [:apavel]]

Attachment: Bug 1620638 - disable browser_jsterm_autocomplete_arrow_keys.js on win7 32bits debug r=nchevobbe

Comment 16

[Pulsebot]

Pushed by [e-mail]:
https://hg.mozilla.org/integration/autoland/rev/f5883b24b3fe
disable browser_jsterm_autocomplete_arrow_keys.js on win7 32bits debug r=nchevobbe

Comment 17

[Pulsebot]

Pushed by [e-mail]:
https://hg.mozilla.org/integration/autoland/rev/5705b1e471ba
fix disabling typo on a CLOSED TREE

Comment 18

[Natalia Csoregi [:nataliaCs]]

https://hg.mozilla.org/mozilla-central/rev/f5883b24b3fe
https://hg.mozilla.org/mozilla-central/rev/5705b1e471ba

Comment 19

[Intermittent Failures Robot]

11 failures in 5582 pushes (0.002 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• autoland: 8
• mozilla-central: 1
• mozilla-beta: 1
• try: 1

Platform breakdown:

• windows7-32: 9
• windows7-32-shippable: 1
• windows7-32-devedition: 1

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