Closed Bug 1341308 Opened 3 years ago Closed 2 years ago

Intermittent browser_webconsole_check_stubs_network_event.js | The networkEvent stubs file needs to be updated by running `mach test devtools/client/webconsole/new-console-outp

Categories

(DevTools :: Console, defect, P3)

defect

Tracking

(firefox-esr52 unaffected, firefox54 unaffected, firefox55 fixed, firefox56 fixed)

RESOLVED FIXED
Firefox 56
Tracking Status
firefox-esr52 --- unaffected
firefox54 --- unaffected
firefox55 --- fixed
firefox56 --- fixed

People

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

Details

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

Attachments

(1 file)

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.
Summary: Intermittent 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-outp → Intermittent browser_webconsole_check_stubs_network_event.js | The networkEvent stubs file needs to be updated by running `mach test devtools/client/webconsole/new-console-outp
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?
Flags: needinfo?(bgrinstead)
Whiteboard: [stockwell needswork]
Assignee: nobody → nchevobbe
Status: NEW → ASSIGNED
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)
Flags: needinfo?(bgrinstead)
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?
Attachment #8876596 - Flags: review?(bgrinstead) → review?(odvarko)
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"
Attachment #8876596 - Flags: review?(odvarko) → review+
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
Attachment #8876596 - Flags: review?(bgrinstead) → review+
Pushed by nchevobbe@mozilla.com:
https://hg.mozilla.org/integration/autoland/rev/6bf02efb9d13
Fix network stub check test intermittent. r=bgrins,Honza
https://hg.mozilla.org/mozilla-central/rev/6bf02efb9d13
Status: ASSIGNED → RESOLVED
Closed: 2 years ago
Resolution: --- → FIXED
Target Milestone: --- → Firefox 56
https://hg.mozilla.org/releases/mozilla-beta/rev/bb9de44b0906
Whiteboard: [stockwell needswork] → [stockwell fixed]
Product: Firefox → DevTools
You need to log in before you can comment on or make changes to this bug.