Filed by: philringnalda [at] gmail.com https://treeherder.mozilla.org/logviewer.html#?job_id=79023723&repo=autoland https://queue.taskcluster.net/v1/task/MDDPzusCQIKNwdQdYky3EQ/runs/0/artifacts/public/logs/live_backing.log

this will increase in frequency as we are going to be running the devtools tests on ubuntu 16.04 today- I don't think it will be outrageous, but probably <50/week.

this test case has increased in failures in the last week or so, 44 failures looking at the past week (orange factor will post tomorrow night the official number). this is primarily on linux 32/64 opt/pgo and e10s (with a few non-e10s failures mixed in). here is a log file: https://treeherder.mozilla.org/logviewer.html#?repo=try&job_id=106005790&lineNumber=3022 and a related screenshot: https://public-artifacts.taskcluster.net/U17-cNtpQKSX2FTr8FBmkQ/0/public/test_info//mozilla-test-fail-screenshot_ra8FXY.png this is what I see in the log: task 2017-06-10T01:01:58.031994Z] 01:01:58 INFO - TEST-START | devtools/client/webconsole/new-console-output/test/fixtures/stub-generators/browser_webconsole_check_stubs_network_event.js [task 2017-06-10T01:01:59.278889Z] 01:01:59 INFO - TEST-INFO | started process screentopng [task 2017-06-10T01:01:59.782362Z] 01:01:59 INFO - TEST-INFO | screentopng: exit 0 [task 2017-06-10T01:01:59.782637Z] 01:01:59 INFO - Buffered messages logged at 01:01:58 [task 2017-06-10T01:01:59.782819Z] 01:01:59 INFO - Entering test bound [task 2017-06-10T01:01:59.783626Z] 01:01:59 INFO - Adding a new tab with URL: http://example.com/browser/devtools/client/webconsole/new-console-output/test/fixtures/stub-generators/test-network-event.html [task 2017-06-10T01:01:59.783708Z] 01:01:59 INFO - Tab added and finished loading [task 2017-06-10T01:01:59.784487Z] 01:01:59 INFO - Opening the toolbox [task 2017-06-10T01:01:59.784660Z] 01:01:59 INFO - Toolbox opened and focused [task 2017-06-10T01:01:59.785429Z] 01:01:59 INFO - Buffered messages logged at 01:01:59 [task 2017-06-10T01:01:59.786146Z] 01:01:59 INFO - Removing tab. [task 2017-06-10T01:01:59.789221Z] 01:01:59 INFO - Waiting for event: 'TabClose' on [object XULElement]. [task 2017-06-10T01:01:59.791322Z] 01:01:59 INFO - Got event: 'TabClose' on [object XULElement]. [task 2017-06-10T01:01:59.793120Z] 01:01:59 INFO - Tab removed and finished closing [task 2017-06-10T01:01:59.795076Z] 01:01:59 INFO - Buffered messages finished [task 2017-06-10T01:01:59.797105Z] 01:01:59 INFO - TEST-UNEXPECTED-FAIL | devtools/client/webconsole/new-console-output/test/fixtures/stub-generators/browser_webconsole_check_stubs_network_event.js | The networkEvent stubs file needs to be updated by running `mach test devtools/client/webconsole/new-console-output/test/fixtures/stub-generators/browser_webconsole_update_stubs_network_event.js` - [task 2017-06-10T01:01:59.798774Z] 01:01:59 INFO - Stack trace: [task 2017-06-10T01:01:59.800389Z] 01:01:59 INFO - chrome://mochitests/content/browser/devtools/client/webconsole/new-console-output/test/fixtures/stub-generators/browser_webconsole_check_stubs_network_event.js:null:17 [task 2017-06-10T01:01:59.803034Z] 01:01:59 INFO - Tester_execTest@chrome://mochikit/content/browser-test.js:801:9 [task 2017-06-10T01:01:59.804911Z] 01:01:59 INFO - Tester.prototype.nextTest</<@chrome://mochikit/content/browser-test.js:714:7 [task 2017-06-10T01:01:59.806076Z] 01:01:59 INFO - SimpleTest.waitForFocus/waitForFocusInner/focusedOrLoaded/<@chrome://mochikit/content/tests/SimpleTest/SimpleTest.js:795:59 [task 2017-06-10T01:01:59.807314Z] 01:01:59 INFO - Leaving test bound [task 2017-06-10T01:01:59.808449Z] 01:01:59 INFO - GECKO(2105) | MEMORY STAT | vsize 2165MB | residentFast 344MB | heapAllocated 141MB [task 2017-06-10T01:01:59.809662Z] 01:01:59 INFO - TEST-OK | devtools/client/webconsole/new-console-output/test/fixtures/stub-generators/browser_webconsole_check_stubs_network_event.js | took 1266ms is it possible we are not generating the stubs file during the build or maybe not seeing it in the uploaded package? :bgrins, could you take a look at this sometime in the next 2 weeks?

This is due to network update not being fired everytime in the same order. In the test we assume that the network update "eventTiming" is the last one but it might not be the case. This is a bit tricky here, my only idea would be to not add stubs for those network updates, or at least, maybe not converting them to messages and only hand pick what we need (httpVersion, totalTime, responseStatusText, responseStatusCode)

The last patch should fix the intermittent. Here's a TRY patch of the previous one (there was only an eslint error I had to fix) : https://treeherder.mozilla.org/#/jobs?repo=try&revision=14b56d0ecdfd97b412c8663b1f65f8e9b23cf8bf&selectedJob=107018177

Comment on attachment 8876596 [details] Bug 1341308 - Fix network stub check test intermittent. https://reviewboard.mozilla.org/r/147926/#review153558 I'm going to forward this to Honza since he knows the network stuff better than me ::: devtools/client/webconsole/new-console-output/test/fixtures/stubs/networkEvent.js (Diff revision 7) > "url": "http://example.com/browser/devtools/client/webconsole/new-console-output/test/fixtures/stub-generators/inexistent.html", > "method": "GET", > "headersSize": 489 > }, > - "isXHR": false, > - "cause": { What did `cause` get removed here?

Comment on attachment 8876596 [details] Bug 1341308 - Fix network stub check test intermittent. https://reviewboard.mozilla.org/r/147926/#review153558 > What did `cause` get removed here? it's because we now only get what we actually use in the messages for the network update packet. Doing that we're safe with property ordering and things like that. I think this isn't much of a big deal, because if the stub change in a way that would break the console, this would be caught here. Do you think of anything that could go wrong that I haven't thought of ?

Comment on attachment 8876596 [details] Bug 1341308 - Fix network stub check test intermittent. https://reviewboard.mozilla.org/r/147926/#review153964 Couple of inline questions, but I think this is ready. R+ Thanks Nicolas! Honza ::: devtools/client/webconsole/new-console-output/new-console-output-wrapper.js:190 (Diff revision 7) > > dispatchMessageUpdate: function (message, res) { > - // network-message-updated will emit when eventTimings message arrives > - // which is the last one of 8 updates happening on network message update. > - if (res.packet.updateType === "eventTimings") { > + // network-message-updated will emit when all the update message arrives. > + // Since we can't ensure the order of the network update, we check > + // that networkInfo.updates has all we need. > + const NUMBER_OF_NETWORK_UPDATE = 8; Counting number of updates feels risky. At least, it should happen on the backend and perhaps the backend should be responsible for sending an update like "done". But, I am not going to block on this. Also, does this also mean that in case of long response body download the UI is updated only when the download is finished? I.e. the user can't observe how the response bar in the timeline column is nicely growing, right? (I guess it's the same behavior as before) ::: devtools/client/webconsole/new-console-output/test/fixtures/stubs/networkEvent.js:83 (Diff revision 7) > -stubPreparedMessages.set("XHR GET request eventTimings", new NetworkEventMessage({ > +stubPreparedMessages.set("XHR GET request update", new NetworkEventMessage({ > "id": "1", > - "actor": "server1.conn1.child1/netEvent30", > + "actor": "server1.conn0.child1/netEvent31", > "level": "log", > - "isXHR": true, > "request": { How come we don't need the 'isXHR' field? Note that the key (title) still says "XHR GET request update"

Comment on attachment 8876596 [details] Bug 1341308 - Fix network stub check test intermittent. https://reviewboard.mozilla.org/r/147926/#review153964 > Counting number of updates feels risky. At least, it should happen on the backend and perhaps the backend should be responsible for sending an update like "done". But, I am not going to block on this. > > Also, does this also mean that in case of long response body download the UI is updated only when the download is finished? I.e. the user can't observe how the response bar in the timeline column is nicely growing, right? > > (I guess it's the same behavior as before) Yes, we don't have this kind of things in the console at the moment. The only thing we do is: - show the original information we get from the initial network packet - show the totalTime, statusText, statusCode and httpVersion when we get them. I think we discussed integration some network inspector component in the future to have the kind of feature you're describing

(In reply to Nicolas Chevobbe [:nchevobbe] from comment #26) > Comment on attachment 8876596 [details] > Bug 1341308 - Fix network stub check test intermittent. > > https://reviewboard.mozilla.org/r/147926/#review153558 > > > What did `cause` get removed here? > > it's because we now only get what we actually use in the messages for the > network update packet. > Doing that we're safe with property ordering and things like that. > I think this isn't much of a big deal, because if the stub change in a way > that would break the console, this would be caught here. > > Do you think of anything that could go wrong that I haven't thought of ? Thanks - I don't have any particular concerns with it, just wanted to understand why it went away

Comment on attachment 8876596 [details] Bug 1341308 - Fix network stub check test intermittent. https://reviewboard.mozilla.org/r/147926/#review154038

Pushed by nchevobbe@mozilla.com: https://hg.mozilla.org/integration/autoland/rev/6bf02efb9d13 Fix network stub check test intermittent. r=bgrins,Honza