1401741 - Some network loads show up incorrectly in devtools when RCWN enabled

Status: NEW

(DevTools :: Netmonitor, defect, P2)

Description

[Valentin Gosu [:valentin] (he/him)]

When RCWN is on, and testing on [1] some of the resources in the devtools show up as pending (no status code, transfer size 0GB). This seems to happen only when RCWN is on, but when clicking on the response tab, the content seems to be there.

The HTTP logs don't show anything odd for those resources. One theory would be that racing is triggering something in the devtools. Not sure exactly what is going on. We would love some help debugging this, or at least a summary of how the netmonitor gets and displays this info.


[1] https://mozilla.github.io/arewefastyet-speedometer/2.0/

Comment 1

[Valentin Gosu [:valentin] (he/him)]

Attachment: res_load.png

Comment 2

[Valentin Gosu [:valentin] (he/him)]

To reproduce this:
1. set network.http.rcwn.enabled to true
2. go to https://mozilla.github.io/arewefastyet-speedometer/2.0/
3. open devtools netmonitor
4. click start
5. watch loading resources until you see one that doesn't load.

Comment 3

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

Thanks for the report I could reproduce the problem.

Honza

Comment 4

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

I tried to reproduce this bug on my machine (using STR from comment #2, waiting to see at least 400-500 requests in the panel) and I can't see any failed requests. Testing on Win10 machine.

Anyone can still reproduce it using latest Nightly?

Honza

Comment 5

[Valentin Gosu [:valentin] (he/him)]

Hi Honza,

I can actually reproduce it quite easily.
I tried it using yesterday's Nightly first. The test runs ok for a while, while it doesn't have any of the resources in the cache. After it starts finding resources in the cache, it's quite easy to notice the misbehaving requests as they are the only ones showing in sharp black test, instead of the cached grey (see attachment).
After I rebooted to update to today's nightly and started the test again, it started reproducing immediately (the resources were in the cache).
Note that as this is inherently racy, it may depend on having a fast internet connection.

PS. Make sure the network.http.rcwn.enabled pref is set to true.

Comment 6

[Valentin Gosu [:valentin] (he/him)]

So, I've been looking at this a bit.
One of the weird things in the netmonitor is that the transferredSize is shown as 0 Gb (see screenshot)
I've looked at the code that formats it [1]. From what I can tell, the function is called with the argument `bytes` as undefined. This allows it to fall through until the last part, gb will be NaN, which will be turned into 0 by formatDecimals.

The question is where is this undefined coming from?
I see there's a TODO at [2]. Not sure if it's relevant or not.

Anyway, I really want to get to the bottom of it, to see if it's just a bug in devtools, or if necko is sending some incorrect info that way, but my devtools debugging skills are not good enough :)

[1] http://searchfox.org/mozilla-central/rev/1285ae3e810e2dbf2652c49ee539e3199fcfe820/devtools/client/netmonitor/src/utils/format-utils.js#58
[2] http://searchfox.org/mozilla-central/rev/1285ae3e810e2dbf2652c49ee539e3199fcfe820/devtools/client/netmonitor/src/connector/chrome/response.js#33

Comment 7

[Jason Duell]

Honza: we're hoping to ship RCWN in 59, so I'm bumping this to P1.  Is it likely you can fix it before then?  Would you consider this a blocker for shipping RCWN?

Comment 8

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

I've been testing this and I can see the issue only on OSX and Ubuntu (it work just fine on Win10)

I am seeing this error in the Console:

NS_ERROR_INVALID_CONTENT_ENCODING: Component returned failure code: 0x804b001b (NS_ERROR_INVALID_CONTENT_ENCODING) [nsIStreamListener.onDataAvailable] network-monitor.js:658

Do you see it too?

I am not sure if this is related to this report since I can see the error even with network.http.rcwn.enabled pref is set to false.


(In reply to Valentin Gosu [:valentin] from comment #6)
> [1]
> http://searchfox.org/mozilla-central/rev/
> 1285ae3e810e2dbf2652c49ee539e3199fcfe820/devtools/client/netmonitor/src/
> utils/format-utils.js#58
Yep, the conversion could convert NaN to 0. It looks like the zero transferred size is rather consequence not the culprit.

> [2]
> http://searchfox.org/mozilla-central/rev/
> 1285ae3e810e2dbf2652c49ee539e3199fcfe820/devtools/client/netmonitor/src/
> connector/chrome/response.js#33
This code is only used when connecting to Chrome browser
(and the feature isn't available in the UI)

Honza

Comment 9

[Valentin Gosu [:valentin] (he/him)]

(In reply to Jan Honza Odvarko [:Honza] from comment #8)
> I've been testing this and I can see the issue only on OSX and Ubuntu (it
> work just fine on Win10)
> 
> I am seeing this error in the Console:
> 
> NS_ERROR_INVALID_CONTENT_ENCODING: Component returned failure code:
> 0x804b001b (NS_ERROR_INVALID_CONTENT_ENCODING)
> [nsIStreamListener.onDataAvailable] network-monitor.js:658
> 
> Do you see it too?
> 
> I am not sure if this is related to this report since I can see the error
> even with network.http.rcwn.enabled pref is set to false.

I don't see that error, and it only happens to me with the pref enabled.

> (In reply to Valentin Gosu [:valentin] from comment #6)
> > [1]
> > http://searchfox.org/mozilla-central/rev/
> > 1285ae3e810e2dbf2652c49ee539e3199fcfe820/devtools/client/netmonitor/src/
> > utils/format-utils.js#58
> Yep, the conversion could convert NaN to 0. It looks like the zero
> transferred size is rather consequence not the culprit.

I agree. I was just thinking that finding out where that value originates from could lead us to the bug.

Comment 10

[atlanto]

Although I'm not sure it is not answered yet,
getFormattedSize(NaN) is called from
https://searchfox.org/mozilla-central/rev/8f06c1b9a080b84435a2906e420fe102e1ed780b/devtools/client/netmonitor/src/components/RequestListColumnTransferredSize.js#44
>text = getFormattedSize(transferredSize);
and transferredSize comes from
https://searchfox.org/mozilla-central/rev/8f06c1b9a080b84435a2906e420fe102e1ed780b/devtools/shared/webconsole/network-monitor.js#625
>response.transferredSize = this.transferredSize + this.httpActivity.headersSize;
response.transferredSize is NaN because this.httpActivity.headersSize is undefined.
this.httpActivity.headersSize is set on
https://searchfox.org/mozilla-central/rev/8f06c1b9a080b84435a2906e420fe102e1ed780b/devtools/shared/webconsole/network-monitor.js#1374
(in case of network-response)
https://searchfox.org/mozilla-central/rev/8f06c1b9a080b84435a2906e420fe102e1ed780b/devtools/shared/webconsole/network-monitor.js#945
(in case of cached-response)
It is not defined in the initial object,
https://searchfox.org/mozilla-central/rev/8f06c1b9a080b84435a2906e420fe102e1ed780b/devtools/shared/webconsole/network-monitor.js#1232
and it is kept undefined since "http-on-examine-cached-response" is not notified when "First response from cache"(nsHttpChannel). (fromCache(RequestListColumnTransferredSize.js#39/network-monitor.js#936) or response header or status or ... are not set also)

"0GB" will be resolved(?) if 'headersSize' is defined in the initial object, but it does not make sense. It should be displayed as "cached", and that may depend on bug 1358038(?)...

(sorry if I'm wrong)

Comment 11

[BugBot [:suhaib / :marco/ :calixte]]

Moving to p2 because no activity for at least 24 weeks.
See How Do You Triage for more information