Open Bug 1401741 Opened 2 years ago Updated 11 months ago

Some network loads show up incorrectly in devtools when RCWN enabled

Categories

(DevTools :: Netmonitor, defect, P2)

defect

Tracking

(Not tracked)

People

(Reporter: valentin, Unassigned)

References

(Blocks 1 open bug)

Details

Attachments

(1 file)

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/
Attached image res_load.png
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.
Blocks: RCWN
Priority: -- → P2
Summary: Some devtools network loads show up as pending when RCWN → Some network loads show up incorrecly in devtools when RCWN enabled
Summary: Some network loads show up incorrecly in devtools when RCWN enabled → Some network loads show up incorrectly in devtools when RCWN enabled
Thanks for the report I could reproduce the problem.

Honza
Has STR: --- → yes
Blocks: 1392841
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
Flags: needinfo?(valentin.gosu)
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.
Flags: needinfo?(valentin.gosu)
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
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?
Flags: needinfo?(odvarko)
Priority: P2 → P1
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
Flags: needinfo?(odvarko) → needinfo?(valentin.gosu)
(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.
Flags: needinfo?(valentin.gosu)
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)
Product: Firefox → DevTools

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

Priority: P1 → P2
You need to log in before you can comment on or make changes to this bug.