1465594 - Intermittent devtools/client/netmonitor/test/browser_net_copy_params.js | Timed out while polling clipboard for pasted data, got: a -

Reporter

Description

•

6 years ago

treeherder

Filed by: aiakab [at] mozilla.com

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

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

task 2018-05-30T16:12:46.907Z] 16:12:46     INFO - Starting test... 
[task 2018-05-30T16:12:46.908Z] 16:12:46     INFO - > Network event progress: NetworkEvent: 1/7, PayloadReady: 0/7, got NetMonitor:NetworkEvent for server1.conn3.child1/netEvent45
[task 2018-05-30T16:12:46.909Z] 16:12:46     INFO - > Network event progress: NetworkEvent: 1/7, PayloadReady: 1/7, got NetMonitor:PayloadReady for server1.conn3.child1/netEvent45
[task 2018-05-30T16:12:46.909Z] 16:12:46     INFO - > Network event progress: NetworkEvent: 2/7, PayloadReady: 1/7, got NetMonitor:NetworkEvent for server1.conn3.child1/netEvent66
[task 2018-05-30T16:12:46.910Z] 16:12:46     INFO - > Network event progress: NetworkEvent: 3/7, PayloadReady: 1/7, got NetMonitor:NetworkEvent for server1.conn3.child1/netEvent86
[task 2018-05-30T16:12:46.910Z] 16:12:46     INFO - > Network event progress: NetworkEvent: 4/7, PayloadReady: 1/7, got NetMonitor:NetworkEvent for server1.conn3.child1/netEvent100
[task 2018-05-30T16:12:46.911Z] 16:12:46     INFO - > Network event progress: NetworkEvent: 5/7, PayloadReady: 1/7, got NetMonitor:NetworkEvent for server1.conn3.child1/netEvent114
[task 2018-05-30T16:12:46.911Z] 16:12:46     INFO - > Network event progress: NetworkEvent: 6/7, PayloadReady: 1/7, got NetMonitor:NetworkEvent for server1.conn3.child1/netEvent128
[task 2018-05-30T16:12:46.912Z] 16:12:46     INFO - > Network event progress: NetworkEvent: 7/7, PayloadReady: 1/7, got NetMonitor:NetworkEvent for server1.conn3.child1/netEvent142
[task 2018-05-30T16:12:46.912Z] 16:12:46     INFO - > Network event progress: NetworkEvent: 7/7, PayloadReady: 2/7, got NetMonitor:PayloadReady for server1.conn3.child1/netEvent66
[task 2018-05-30T16:12:46.913Z] 16:12:46     INFO - > Network event progress: NetworkEvent: 7/7, PayloadReady: 3/7, got NetMonitor:PayloadReady for server1.conn3.child1/netEvent86
[task 2018-05-30T16:12:46.913Z] 16:12:46     INFO - > Network event progress: NetworkEvent: 7/7, PayloadReady: 4/7, got NetMonitor:PayloadReady for server1.conn3.child1/netEvent100
[task 2018-05-30T16:12:46.914Z] 16:12:46     INFO - > Network event progress: NetworkEvent: 7/7, PayloadReady: 5/7, got NetMonitor:PayloadReady for server1.conn3.child1/netEvent114
[task 2018-05-30T16:12:46.914Z] 16:12:46     INFO - > Network event progress: NetworkEvent: 7/7, PayloadReady: 6/7, got NetMonitor:PayloadReady for server1.conn3.child1/netEvent128
[task 2018-05-30T16:12:46.915Z] 16:12:46     INFO - > Network event progress: NetworkEvent: 7/7, PayloadReady: 7/7, got NetMonitor:PayloadReady for server1.conn3.child1/netEvent142
[task 2018-05-30T16:12:46.916Z] 16:12:46     INFO - TEST-PASS | devtools/client/netmonitor/test/browser_net_copy_params.js | The "Copy URL Parameters" context menu item should not be hidden. - 
[task 2018-05-30T16:12:46.916Z] 16:12:46     INFO - TEST-PASS | devtools/client/netmonitor/test/browser_net_copy_params.js | Clipboard has the given value: 'a' - 
[task 2018-05-30T16:12:46.917Z] 16:12:46     INFO - TEST-PASS | devtools/client/netmonitor/test/browser_net_copy_params.js | The url query string copied from the selected item is correct. - 
[task 2018-05-30T16:12:46.917Z] 16:12:46     INFO - TEST-PASS | devtools/client/netmonitor/test/browser_net_copy_params.js | The "Copy POST Data" context menu item should not be hidden. - 
[task 2018-05-30T16:12:46.918Z] 16:12:46     INFO - Buffered messages logged at 16:12:41
[task 2018-05-30T16:12:46.918Z] 16:12:46     INFO - TEST-PASS | devtools/client/netmonitor/test/browser_net_copy_params.js | Clipboard has the given value: '{ "foo": "bar" }' - 
[task 2018-05-30T16:12:46.919Z] 16:12:46     INFO - TEST-PASS | devtools/client/netmonitor/test/browser_net_copy_params.js | The post data string copied from the selected item is correct. - 
[task 2018-05-30T16:12:46.920Z] 16:12:46     INFO - TEST-PASS | devtools/client/netmonitor/test/browser_net_copy_params.js | The "Copy URL Parameters" context menu item should not be hidden. - 
[task 2018-05-30T16:12:46.920Z] 16:12:46     INFO - TEST-PASS | devtools/client/netmonitor/test/browser_net_copy_params.js | Clipboard has the given value: 'a=b' - 
[task 2018-05-30T16:12:46.921Z] 16:12:46     INFO - TEST-PASS | devtools/client/netmonitor/test/browser_net_copy_params.js | The url query string copied from the selected item is correct. - 
[task 2018-05-30T16:12:46.921Z] 16:12:46     INFO - TEST-PASS | devtools/client/netmonitor/test/browser_net_copy_params.js | The "Copy POST Data" context menu item should not be hidden. - 
[task 2018-05-30T16:12:46.922Z] 16:12:46     INFO - TEST-PASS | devtools/client/netmonitor/test/browser_net_copy_params.js | Clipboard has the given value: '{ "foo": "bar" }' - 
[task 2018-05-30T16:12:46.922Z] 16:12:46     INFO - TEST-PASS | devtools/client/netmonitor/test/browser_net_copy_params.js | The post data string copied from the selected item is correct. - 
[task 2018-05-30T16:12:46.924Z] 16:12:46     INFO - TEST-PASS | devtools/client/netmonitor/test/browser_net_copy_params.js | The "Copy URL Parameters" context menu item should not be hidden. - 
[task 2018-05-30T16:12:46.924Z] 16:12:46     INFO - Buffered messages finished
[task 2018-05-30T16:12:46.925Z] 16:12:46     INFO - TEST-UNEXPECTED-FAIL | devtools/client/netmonitor/test/browser_net_copy_params.js | Timed out while polling clipboard for pasted data, got: a - 
[task 2018-05-30T16:12:46.925Z] 16:12:46     INFO - Stack trace:
[task 2018-05-30T16:12:46.926Z] 16:12:46     INFO - chrome://mochikit/content/tests/SimpleTest/SimpleTest.js:putAndVerify:1025
[task 2018-05-30T16:12:46.926Z] 16:12:46     INFO - chrome://mochikit/content/tests/SimpleTest/SimpleTest.js:SimpleTest.promiseClipboardChange:1036
[task 2018-05-30T16:12:46.926Z] 16:12:46     INFO - chrome://mochikit/content/tests/SimpleTest/SimpleTest.js:SimpleTest.waitForClipboard:969
[task 2018-05-30T16:12:46.926Z] 16:12:46     INFO - chrome://mochitests/content/browser/devtools/client/shared/test/shared-head.js:waitForClipboardPromise/<:561
[task 2018-05-30T16:12:46.926Z] 16:12:46     INFO - chrome://mochitests/content/browser/devtools/client/shared/test/shared-head.js:waitForClipboardPromise:560
[task 2018-05-30T16:12:46.927Z] 16:12:46     INFO - chrome://mochitests/content/browser/devtools/client/netmonitor/test/browser_net_copy_params.js:testCopyUrlParams:74
[task 2018-05-30T16:12:46.927Z] 16:12:46     INFO - chrome://mochitests/content/browser/devtools/client/netmonitor/test/browser_net_copy_params.js:null:33
[task 2018-05-30T16:12:46.927Z] 16:12:46     INFO - chrome://mochikit/content/browser-test.js:Tester_execTest/<:1083
[task 2018-05-30T16:12:46.927Z] 16:12:46     INFO - chrome://mochikit/content/browser-test.js:Tester_execTest:1074
[task 2018-05-30T16:12:46.928Z] 16:12:46     INFO - chrome://mochikit/content/browser-test.js:nextTest/<:976
[task 2018-05-30T16:12:46.928Z] 16:12:46     INFO - chrome://mochikit/content/tests/SimpleTest/SimpleTest.js:SimpleTest.waitForFocus/waitForFocusInner/focusedOrLoaded/<:795
[task 2018-05-30T16:12:46.928Z] 16:12:46     INFO - Not taking screenshot here: see the one that was previously logged
[task 2018-05-30T16:12:46.928Z] 16:12:46     INFO - TEST-UNEXPECTED-FAIL | devtools/client/netmonitor/test/browser_net_copy_params.js | Uncaught exception - failed
[task 2018-05-30T16:12:46.929Z] 16:12:46     INFO - Leaving test bound 
[task 2018-05-30T16:12:46.945Z] 16:12:46     INFO - Removing tab.
[task 2018-05-30T16:12:46.945Z] 16:12:46     INFO - Waiting for event: 'TabClose' on [object XULElement].
[task 2018-05-30T16:12:46.966Z] 16:12:46     INFO - Got event: 'TabClose' on [object XULElement].
[task 2018-05-30T16:12:46.966Z] 16:12:46     INFO - Tab removed and finished closing
[task 2018-05-30T16:12:46.967Z] 16:12:46     INFO - finish() was called, cleaning up...
[task 2018-05-30T16:12:46.983Z] 16:12:46     INFO - GECKO(5202) | MEMORY STAT | vsize 2336MB | residentFast 324MB | heapAllocated 119MB
[task 2018-05-30T16:12:46.983Z] 16:12:46     INFO - TEST-OK | devtools/client/netmonitor/test/browser_net_copy_params.js | took 7469ms

Comment hidden (Intermittent Failures Robot)

30 failures in 655 pushes (0.046 failures/push) were associated with this bug in the last 7 days.   

** 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:
* mozilla-central: 10
* autoland: 10
* mozilla-inbound: 8
* try: 2

Platform breakdown:
* windows7-32: 21
* windows7-32-nightly: 3
* osx-10-10: 2
* linux64: 2
* windows10-64-nightly: 1
* linux64-devedition: 1

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

Cristina Coroiu [:ccoroiu]

Comment 2

•

6 years ago

In the last 7 days, there have been 31 failures.

Most of the failures are on windows7-32, but a few of them on windows7-32-nightly and linux64.
Affected build types: pgo and opt.

An example of a recent log file:
https://treeherder.mozilla.org/logviewer.html#?job_id=181812872&repo=autoland&lineNumber=3714

And the relevant part of the log:
23:52:55     INFO -  424 INFO TEST-PASS | devtools/client/netmonitor/test/browser_net_copy_params.js | The "Copy URL Parameters" context menu item should not be hidden. -
23:52:55     INFO -  Buffered messages finished
23:52:55    ERROR -  425 INFO TEST-UNEXPECTED-FAIL | devtools/client/netmonitor/test/browser_net_copy_params.js | Timed out while polling clipboard for pasted data, got: a -
23:52:55     INFO -  Stack trace:
23:52:55     INFO -  chrome://mochikit/content/tests/SimpleTest/SimpleTest.js:putAndVerify:1025
23:52:55     INFO -  chrome://mochikit/content/tests/SimpleTest/SimpleTest.js:SimpleTest.promiseClipboardChange:1036
23:52:55     INFO -  chrome://mochikit/content/tests/SimpleTest/SimpleTest.js:SimpleTest.waitForClipboard:969
23:52:55     INFO -  chrome://mochitests/content/browser/devtools/client/shared/test/shared-head.js:waitForClipboardPromise/<:564
23:52:55     INFO -  chrome://mochitests/content/browser/devtools/client/shared/test/shared-head.js:waitForClipboardPromise:563
23:52:55     INFO -  chrome://mochitests/content/browser/devtools/client/netmonitor/test/browser_net_copy_params.js:testCopyUrlParams:74
23:52:55     INFO -  chrome://mochitests/content/browser/devtools/client/netmonitor/test/browser_net_copy_params.js:null:33
23:52:55     INFO -  chrome://mochikit/content/browser-test.js:Tester_execTest/<:1083
23:52:55     INFO -  chrome://mochikit/content/browser-test.js:Tester_execTest:1074
23:52:55     INFO -  chrome://mochikit/content/browser-test.js:nextTest/<:976
23:52:55     INFO -  chrome://mochikit/content/tests/SimpleTest/SimpleTest.js:SimpleTest.waitForFocus/waitForFocusInner/focusedOrLoaded/<:795
23:52:55     INFO -  Not taking screenshot here: see the one that was previously logged
23:52:55    ERROR -  426 INFO TEST-UNEXPECTED-FAIL | devtools/client/netmonitor/test/browser_net_copy_params.js | Uncaught exception - failed
23:52:55     INFO -  427 INFO Leaving test bound
23:52:56     INFO -  428 INFO Removing tab.
23:52:56     INFO -  429 INFO Waiting for event: 'TabClose' on [object XULElement].
23:52:56     INFO -  430 INFO Got event: 'TabClose' on [object XULElement].
23:52:56     INFO -  431 INFO Tab removed and finished closing
23:52:56     INFO -  432 INFO finish() was called, cleaning up...

:Honza As you are the triage owner of this component, could you please take a look at this?
Thank you!

Flags: needinfo?(odvarko)

Whiteboard: [stockwell needswork]

Comment hidden (mozreview-request)

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

Jan Honza Odvarko [:Honza] (always need-info? me)

Assignee

Comment 4

•

6 years ago

Patch attached.

Let's see how the try push looks like:
https://treeherder.mozilla.org/#/jobs?repo=try&revision=7186035ab2546414e083c3802be41cb988620956

Honza

Assignee: nobody → odvarko

Status: NEW → ASSIGNED

Comment hidden (mozreview-request)

Comment on attachment 8983516 [details]
Bug 1465594 - Ensure proper order of XHRs;

Review request updated; see interdiff: https://reviewboard.mozilla.org/r/249372/diff/1-2/

Jan Honza Odvarko [:Honza] (always need-info? me)

Assignee

Comment 6

•

6 years ago

@jryans: I changed the way XHRs are executed to ensure the same order in every run. I think that the order was different sometimes, which caused the intermittent failure.

Honza

Flags: needinfo?(odvarko)

J. Ryan Stinnett [:jryans] (Use needinfo, replies may be slow)

Comment 7

•

6 years ago

mozreview-review

Comment on attachment 8983516 [details]
Bug 1465594 - Ensure proper order of XHRs;

https://reviewboard.mozilla.org/r/249372/#review255974

Thanks, seems reasonable to me! :)

::: devtools/client/netmonitor/test/html_params-test-page.html:48
(Diff revision 2)
>  
>        function performRequests() {
>          const urlencoded = "application/x-www-form-urlencoded";
>  
>          /* eslint-disable max-nested-callbacks */
> -        setTimeout(function() {
> +        post("baz", "?a", urlencoded, '{ "foo": "bar" }', function() {

Could we resolve a promise when done and use async / await here instead of these nested callbacks?

Not required, but seems like it would be much nicer to read!

Attachment #8983516 - Flags: review?(jryans) → review+

Comment hidden (mozreview-request)

Comment on attachment 8983516 [details]
Bug 1465594 - Ensure proper order of XHRs;

Review request updated; see interdiff: https://reviewboard.mozilla.org/r/249372/diff/2-3/

Jan Honza Odvarko [:Honza] (always need-info? me)

Assignee

Comment 9

•

6 years ago

(In reply to J. Ryan Stinnett [:jryans] (use ni?) from comment #7)
> Could we resolve a promise when done and use async / await here instead of
> these nested callbacks?
> Not required, but seems like it would be much nicer to read!
You are right, done.

Thanks for the review Ryan!

Honza

Pulsebot

Comment 10

•

6 years ago

Pushed by jodvarko@mozilla.com:
https://hg.mozilla.org/integration/autoland/rev/4fdaaf004dc5
Ensure proper order of XHRs; r=jryans

Andrei Ciure[:aciure]

Comment 11

•

6 years ago

bugherder

https://hg.mozilla.org/mozilla-central/rev/4fdaaf004dc5

Status: ASSIGNED → RESOLVED

Closed: 6 years ago

status-firefox62: --- → fixed

Resolution: --- → FIXED

Target Milestone: --- → Firefox 62

Comment hidden (Intermittent Failures Robot)

24 failures in 669 pushes (0.036 failures/push) were associated with this bug in the last 7 days.    

Repository breakdown:
* mozilla-inbound: 10
* autoland: 6
* mozilla-central: 5
* try: 3

Platform breakdown:
* windows7-32: 15
* windows7-32-nightly: 3
* osx-10-10: 3
* windows10-64: 2
* linux64: 1

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

BMO Automation

Updated

•

6 years ago

Product: Firefox → DevTools

Joel Maher ( :jmaher ) (UTC -8)

Updated

•

6 years ago

Whiteboard: [stockwell needswork] → [stockwell fixed:other]

Bugzilla

Quick Search

Intermittent devtools/client/netmonitor/test/browser_net_copy_params.js | Timed out while polling clipboard for pasted data, got: a -

Categories

(DevTools :: Netmonitor, defect, P5)

Tracking

(firefox62 fixed)

People

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

References

Details

(Keywords: intermittent-failure, Whiteboard: [stockwell fixed:other])

Crash Data

Security

(public)

User Story

Attachments

(1 file)

Description

Comment 1

Comment 2

Comment 3

Comment 4

Comment 5

Comment 6

Comment 7

Comment 8

Comment 9

Comment 10

Comment 11

Comment 12

Updated

Updated

Attachment

General

Description

File Name

Content Type