1469191 - Intermittent devtools/client/netmonitor/test/browser_net_filter-autocomplete.js | Autocomplete Popup Created -

Status: RESOLVED FIXED

(DevTools :: Netmonitor, defect, P2)

Description

[Treeherder Bug Filer]

Filed by: dvarga [at] mozilla.com

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

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

01:13:01     INFO - TEST-PASS | devtools/client/netmonitor/test/browser_net_filter-autocomplete.js | Request to reconfigure the tab was recorded. - 
01:13:01     INFO - Clearing requests in the console client.
01:13:01     INFO - Clearing requests in the UI.
01:13:01     INFO - Starting test... 
01:13:01     INFO - Loading the helper frame script chrome://mochitests/content/browser/devtools/client/shared/test/frame-script-utils.js
01:13:01     INFO - Performing requests in the context of the content.
01:13:01     INFO - > Network event progress: NetworkEvent: 1/10, PayloadReady: 0/10, got NetMonitor:NetworkEvent for server1.conn35.child1/netEvent45
01:13:01     INFO - > Network event progress: NetworkEvent: 1/10, PayloadReady: 1/10, got NetMonitor:PayloadReady for server1.conn35.child1/netEvent45
01:13:01     INFO - > Network event progress: NetworkEvent: 2/10, PayloadReady: 1/10, got NetMonitor:NetworkEvent for server1.conn35.child1/netEvent65
01:13:01     INFO - > Network event progress: NetworkEvent: 2/10, PayloadReady: 2/10, got NetMonitor:PayloadReady for server1.conn35.child1/netEvent65
01:13:01     INFO - Buffered messages logged at 01:13:01
01:13:01     INFO - > Network event progress: NetworkEvent: 3/10, PayloadReady: 2/10, got NetMonitor:NetworkEvent for server1.conn35.child1/netEvent89
01:13:01     INFO - > Network event progress: NetworkEvent: 3/10, PayloadReady: 3/10, got NetMonitor:PayloadReady for server1.conn35.child1/netEvent89
01:13:01     INFO - > Network event progress: NetworkEvent: 4/10, PayloadReady: 3/10, got NetMonitor:NetworkEvent for server1.conn35.child1/netEvent111
01:13:01     INFO - > Network event progress: NetworkEvent: 4/10, PayloadReady: 4/10, got NetMonitor:PayloadReady for server1.conn35.child1/netEvent111
01:13:01     INFO - > Network event progress: NetworkEvent: 5/10, PayloadReady: 4/10, got NetMonitor:NetworkEvent for server1.conn35.child1/netEvent133
01:13:01     INFO - > Network event progress: NetworkEvent: 5/10, PayloadReady: 5/10, got NetMonitor:PayloadReady for server1.conn35.child1/netEvent133
01:13:01     INFO - > Network event progress: NetworkEvent: 6/10, PayloadReady: 5/10, got NetMonitor:NetworkEvent for server1.conn35.child1/netEvent155
01:13:01     INFO - > Network event progress: NetworkEvent: 6/10, PayloadReady: 6/10, got NetMonitor:PayloadReady for server1.conn35.child1/netEvent155
01:13:01     INFO - > Network event progress: NetworkEvent: 7/10, PayloadReady: 6/10, got NetMonitor:NetworkEvent for server1.conn35.child1/netEvent177
01:13:01     INFO - > Network event progress: NetworkEvent: 7/10, PayloadReady: 7/10, got NetMonitor:PayloadReady for server1.conn35.child1/netEvent177
01:13:01     INFO - > Network event progress: NetworkEvent: 8/10, PayloadReady: 7/10, got NetMonitor:NetworkEvent for server1.conn35.child1/netEvent199
01:13:01     INFO - > Network event progress: NetworkEvent: 8/10, PayloadReady: 8/10, got NetMonitor:PayloadReady for server1.conn35.child1/netEvent199
01:13:01     INFO - > Network event progress: NetworkEvent: 9/10, PayloadReady: 8/10, got NetMonitor:NetworkEvent for server1.conn35.child1/netEvent221
01:13:01     INFO - > Network event progress: NetworkEvent: 9/10, PayloadReady: 9/10, got NetMonitor:PayloadReady for server1.conn35.child1/netEvent221
01:13:01     INFO - > Network event progress: NetworkEvent: 10/10, PayloadReady: 9/10, got NetMonitor:NetworkEvent for server1.conn35.child1/netEvent245
01:13:01     INFO - > Network event progress: NetworkEvent: 10/10, PayloadReady: 10/10, got NetMonitor:PayloadReady for server1.conn35.child1/netEvent245
01:13:01     INFO - TEST-PASS | devtools/client/netmonitor/test/browser_net_filter-autocomplete.js | Autocomplete Popup still hidden - 
01:13:01     INFO - Buffered messages finished
01:13:01     INFO - TEST-UNEXPECTED-FAIL | devtools/client/netmonitor/test/browser_net_filter-autocomplete.js | Autocomplete Popup Created - 
01:13:01     INFO - Stack trace:
01:13:01     INFO - chrome://mochitests/content/browser/devtools/client/netmonitor/test/browser_net_filter-autocomplete.js:null:62
01:13:01     INFO - chrome://mochikit/content/browser-test.js:Tester_execTest/<:1098
01:13:01     INFO - chrome://mochikit/content/browser-test.js:Tester_execTest:1089
01:13:01     INFO - chrome://mochikit/content/browser-test.js:nextTest/<:991
01:13:01     INFO - chrome://mochikit/content/tests/SimpleTest/SimpleTest.js:SimpleTest.waitForFocus/waitForFocusInner/focusedOrLoaded/<:795
01:13:01     INFO - Not taking screenshot here: see the one that was previously logged
01:13:01     INFO - TEST-UNEXPECTED-FAIL | devtools/client/netmonitor/test/browser_net_filter-autocomplete.js | Uncaught exception - at chrome://mochitests/content/browser/devtools/client/netmonitor/test/browser_net_filter-autocomplete.js:26 - TypeError: document.querySelector(...) is null
01:13:01     INFO - Stack trace:
01:13:01     INFO - testAutocompleteContents/<@chrome://mochitests/content/browser/devtools/client/netmonitor/test/browser_net_filter-autocomplete.js:26:7
01:13:01     INFO - testAutocompleteContents@chrome://mochitests/content/browser/devtools/client/netmonitor/test/browser_net_filter-autocomplete.js:24:3
01:13:01     INFO - @chrome://mochitests/content/browser/devtools/client/netmonitor/test/browser_net_filter-autocomplete.js:64:3
01:13:01     INFO - Async*Tester_execTest/<@chrome://mochikit/content/browser-test.js:1098:34
01:13:01     INFO - async*Tester_execTest@chrome://mochikit/content/browser-test.js:1089:16
01:13:01     INFO - nextTest/<@chrome://mochikit/content/browser-test.js:991:9
01:13:01     INFO - SimpleTest.waitForFocus/waitForFocusInner/focusedOrLoaded/<@chrome://mochikit/content/tests/SimpleTest/SimpleTest.js:795:59
01:13:01     INFO - Leaving test bound 
01:13:01     INFO - Removing tab.
01:13:01     INFO - Waiting for event: 'TabClose' on [object XULElement].
01:13:01     INFO - Got event: 'TabClose' on [object XULElement].
01:13:01     INFO - Tab removed and finished closing
01:13:01     INFO - finish() was called, cleaning up...
01:13:01     INFO - GECKO(2053) | MEMORY STAT | vsize 4649MB | residentFast 624MB | heapAllocated 163MB
01:13:01     INFO - TEST-OK | devtools/client/netmonitor/test/browser_net_filter-autocomplete.js | took 2236ms

Comment 1

[Intermittent Failures Robot]

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

Repository breakdown:
* autoland: 1

Platform breakdown:
* osx-10-10: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1469191&startday=2018-06-11&endday=2018-06-17&tree=trunk

Comment 2

[Firefox Bug Husbandry Bot]

https://wiki.mozilla.org/Bug_Triage#Intermittent_Test_Failure_Cleanup

Comment 3

[Bogdan Tara[:bogdan_tara | bogdant]]

This is still happening.

Recent failure: https://treeherder.mozilla.org/logviewer.html#?job_id=189885382&repo=autoland&lineNumber=1870

Comment 4

[Julian Descottes [:jdescottes]]

Looks like this is permafailing on OSX since https://hg.mozilla.org/mozilla-central/pushloghtml?changeset=dd386b5b9fa7f5cd6dc4bbbfa0503b3eb2969af5

Comment 5

[Julian Descottes [:jdescottes]]

Bisect points to Bug 1442582 https://hg.mozilla.org/mozilla-central/rev/6b30047d863c

Comment 6

[Julian Descottes [:jdescottes]]

When the test attempts to click on the netmonitor filter input [1], the tab switches to the first blank tab.

Brian, any idea what could trigger that?

Comment 7

[Julian Descottes [:jdescottes]]

(In reply to Julian Descottes [:jdescottes][:julian] from comment #6)
> When the test attempts to click on the netmonitor filter input [1], the tab
> switches to the first blank tab.
> 
> Brian, any idea what could trigger that?

[1] https://searchfox.org/mozilla-central/rev/bdfd20ef30d521b57d5b6feeda71325e8b4cad66/devtools/client/netmonitor/test/browser_net_filter-autocomplete.js#53-54

Comment 8

[Brian Grinstead [:bgrins]]

Looking into it

Comment 9

[Brian Grinstead [:bgrins]]

Somehow the `EventUtils.synthesizeMouseAtCenter(document.querySelector(".devtools-filterinput"), {}, window);` triggers "onmousedown" in the "tab" xbl binding:

console.trace() tabbrowser.js:4183
_setupEventListeners/<
chrome://browser/content/tabbrowser.js:4183
set_selectedIndex
chrome://global/content/bindings/tabbox.xml:607
set_selectedPanel
chrome://global/content/bindings/tabbox.xml:635
set_selectedIndex
chrome://global/content/bindings/tabbox.xml:386
set_selectedItem
chrome://global/content/bindings/tabbox.xml:411
_selectNewTab
chrome://global/content/bindings/tabbox.xml:456
onxblmousedown
chrome://global/content/bindings/tabbox.xml:727
synthesizeMouseAtPoint
chrome://mochikit/content/tests/SimpleTest/EventUtils.js:468
synthesizeMouse
chrome://mochikit/content/tests/SimpleTest/EventUtils.js:405
synthesizeMouseAtCenter
chrome://mochikit/content/tests/SimpleTest/EventUtils.js:506
<anonymous>
chrome://mochitests/content/browser/devtools/client/netmonitor/test/browser_net_filter-autocomplete.js:54

Comment 10

[Brian Grinstead [:bgrins]]

Attachment: Bug 1469191 - Use the proper window for synthesizeMouseAtCenter in netmonitor test;

It was using `window` which refers to the browser window, but we actually want to synthesize
the click in the devtools window.

Review commit: https://reviewboard.mozilla.org/r/259424/diff/#index_header
See other reviews: https://reviewboard.mozilla.org/r/259424/

Comment 11

[Brian Grinstead [:bgrins]]

I'm not sure if this will fix the original intermittent, but it should fix the perma orange which is triggered by synthesizing the mouse event in the wrong window (the browser window instead of netmonitor window that has the DOM node).

Comment 12

[Julian Descottes [:jdescottes]]

Comment on attachment 8994902 [details]
Bug 1469191 - Use the proper window for synthesizeMouseAtCenter in netmonitor test;

https://reviewboard.mozilla.org/r/259424/#review266438

Fixes the issue! Thanks

Comment 13

[Pulsebot]

Pushed by [e-mail]:
https://hg.mozilla.org/integration/autoland/rev/429bdd36f4a7
Use the proper window for synthesizeMouseAtCenter in netmonitor test;r=jdescottes

Comment 14

[Intermittent Failures Robot]

86 failures in 138 pushes (0.623 failures/push) were associated with this bug yesterday.    

Repository breakdown:
* autoland: 35
* mozilla-inbound: 25
* mozilla-central: 21
* try: 5

Platform breakdown:
* osx-10-10: 84
* macosx64-nightly: 2

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1469191&startday=2018-07-25&endday=2018-07-25&tree=trunk

Comment 15

[Stefan Hindli [:stefan_hindli]]

https://hg.mozilla.org/mozilla-central/rev/429bdd36f4a7

Comment 16

[Intermittent Failures Robot]

18 failures in 142 pushes (0.127 failures/push) were associated with this bug yesterday.    

Repository breakdown:
* mozilla-inbound: 13
* try: 3
* mozilla-central: 2

Platform breakdown:
* osx-10-10: 16
* macosx64-nightly: 2

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1469191&startday=2018-07-26&endday=2018-07-26&tree=trunk

Comment 17

[Intermittent Failures Robot]

166 failures in 760 pushes (0.218 failures/push) were associated with this bug in the last 7 days. 

This is the #10 most frequent failure this week.   

** This test has failed more than 150 times in the last 21 days. It should be disabled until it can be fixed. ** 

Repository breakdown:
* try: 49
* autoland: 49
* mozilla-inbound: 43
* mozilla-central: 25

Platform breakdown:
* osx-10-10: 161
* macosx64-nightly: 5

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1469191&startday=2018-07-23&endday=2018-07-29&tree=trunk

Comment 18

[meck93]

We are trying to build a tool to automatically classify intermittent failures, which would provide a starting point for fixing the bug, reducing the manual work for the developers.
We are collecting some feedback on the results, to see if they’re good enough and where we need to improve.
    
For this bug, the tool says that the intermittent failure is most likely a:
Concurrency Issue: This includes tests in which failures occur due to thread management issues (different threads or their outcomes depending on an implicit ordering), race conditions and/or deadlocks, and issues related to an asynchronous waits (e.g. a process trying to access an external resource or continuing before the external resource is available).


Once you’re done investigating and/or fixing the bug, could you tell me:
- Did the tool correctly recognize the type of intermittent failure?
- Did the information from the tool help your analysis, the bug fixing process, or anything in the process? (please also let us know how the tool was useful and/or what would improve the tool's usefulness for you)