1358038 - Add "Race Cache With Network" status to netmonitor

Status: RESOLVED FIXED

(DevTools :: Netmonitor, enhancement, P2)

Description

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

The RCWN feature in Necko adds the ability to race the cache with the network when the cache is slow. So if reading from the disk is slow, we will send a network request, and return the channel from the network, even though we have the entry in the cache. This way we provide the content to consumers faster.

We want to enable this on Nighty for a few days in order to get some telemetry, but it might confuse people if the resource was actually loaded from the network instead from the cache. So we would like to add this information to the netmonitor before we land it.
From what I understand, there are the parts of doing this:
1. Add the platform code to signal that the channel is racing
2. Add devtools server code to get the state from the channel
3. Add devtools client frontend code to show this information
   - our suggestion for the UI is that we instead cached/Transfer size we show raced/cached, or raced/Transfer, and maybe pick a different icon for the status as well.

Comment 1

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

(In reply to Valentin Gosu [:valentin] from comment #0)
> From what I understand, there are the parts of doing this:
> 1. Add the platform code to signal that the channel is racing
> 2. Add devtools server code to get the state from the channel
Yes, make sense.

> 3. Add devtools client frontend code to show this information
>    - our suggestion for the UI is that we instead cached/Transfer size we
> show raced/cached, or raced/Transfer, and maybe pick a different icon for
> the status as well.
One option is also keeping the "cached/Transfer size" column as is and introduce a new column for those new values (the new column might be hidden by default). The user who is interested in the racing info/stats can right click on Network panel header to show menu with list of all available columns and display it.

The ability to show/hide columns has been introduced recently and is available in Firefox Nightly.

Honza

Comment 2

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

(In reply to Jan Honza Odvarko [:Honza] from comment #1)
> One option is also keeping the "cached/Transfer size" column as is and
> introduce a new column for those new values (the new column might be hidden
> by default). The user who is interested in the racing info/stats can right
> click on Network panel header to show menu with list of all available
> columns and display it.

Our concern is that requests that load from the network instead of the cache will confuse users, and they will think there is a problem with their caching headers, or with Firefox's caching. We want to avoid that by showing them why it loaded from the network instead (because we raced).

I will start working on the platform code immediately, but I don't know how the netmonitor is determining if the channel is returning a cached response or not.
Would adding a method nsICacheInfoChannel.isRacing() be OK? Similar to nsICacheInfoChannel.isFromCache().

Also, it might be necessary for web developers to have a checkbox in the devtools settings to turn racing off, so they have deterministic caching behaviour when they are building their website. We probably need a different bug for this.

Comment 3

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

(In reply to Valentin Gosu [:valentin] from comment #2)
> Our concern is that requests that load from the network instead of the cache
> will confuse users, and they will think there is a problem with their
> caching headers, or with Firefox's caching. We want to avoid that by showing
> them why it loaded from the network instead (because we raced).
I see, agree, it should be clear for web developers why the request
didn't come from the browser cache.

> I will start working on the platform code immediately, but I don't know how
> the netmonitor is determining if the channel is returning a cached response
> or not.
> Would adding a method nsICacheInfoChannel.isRacing() be OK? Similar to
> nsICacheInfoChannel.isFromCache().
Yes

Btw. the current Net monitor server code is not using `isFromCache` API, but observes "http-on-examine-cached-response" notifications. Every request for which is this notification fired is marked as 'fromCache'. Is that safe?

> Also, it might be necessary for web developers to have a checkbox in the
> devtools settings to turn racing off, so they have deterministic caching
> behaviour when they are building their website. We probably need a different
> bug for this.
I see, yes sounds useful.

Honza

Comment 4

[Michal Novotny [:michal]]

(In reply to Jan Honza Odvarko [:Honza] from comment #3)
> Btw. the current Net monitor server code is not using `isFromCache` API, but
> observes "http-on-examine-cached-response" notifications. Every request for
> which is this notification fired is marked as 'fromCache'. Is that safe?

After a quick look at the code I think it is safe now, but this is going to change once we enable racing. So the code should be changed to use isFromCache method.

Comment 5

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

(In reply to Michal Novotny (:michal) from comment #4)
> (In reply to Jan Honza Odvarko [:Honza] from comment #3)
> > Btw. the current Net monitor server code is not using `isFromCache` API, but
> > observes "http-on-examine-cached-response" notifications. Every request for
> > which is this notification fired is marked as 'fromCache'. Is that safe?
> 
> After a quick look at the code I think it is safe now, but this is going to
> change once we enable racing. So the code should be changed to use
> isFromCache method.
OK, thanks!

One more question. The related code, see here:
http://searchfox.org/mozilla-central/source/devtools/shared/webconsole/network-monitor.js#909 

... is also doing:
`fromCache: !fromServiceWorker,`

This indicates that requests coming from a service worker can't be cached. Is that correct?

Honza

Comment 6

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

(In reply to Jan Honza Odvarko [:Honza] from comment #5)
> ... is also doing:
> `fromCache: !fromServiceWorker,`
> 
> This indicates that requests coming from a service worker can't be cached.
> Is that correct?

Short answer: yes.
The ServiceWorker may return the response from either the network, or its local cache, but it's not the HTTP cache.
The ServiceWorker acts as a proxy to the real server, so I think it's correct to always say that if it's coming from the ServiceWorker then the response is not cached.

Comment 7

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

Attachment: Add isRacing() to nsICacheInfoChannel

MozReview-Commit-ID: 4uH5kJIguI3

Comment 8

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

Honza, do you think we could get someone to work on the netmonitor bits?
We were thinking of turning on the racing on nightly for a few days, and it would really help to have this information in the netmonitor so no one is surprised by the change.

Comment 9

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

@Locke: do you have time to look at this?

Honza

Comment 10

[Locke Chen]

Yes, sure.

Comment 11

[[e-mail]]

Do we have the base UI spec about what should be shown for the Race Cache condition?

Comment 12

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

(In reply to Fred Lin [:gasolin] from comment #11)
> Do we have the base UI spec about what should be shown for the Race Cache
> condition?

The first comment #0 says the following:

> 3. Add devtools client frontend code to show this information
>   - our suggestion for the UI is that we instead cached/Transfer size we show raced/cached, or raced/Transfer, and maybe
> pick a different icon for the status as well.

The goal here is reusing the existing "Transferred" column since this columns shows information about whether the request came from the cache. It should be adopted, so it also shows whether "Race Cache With Network" were involved.

The columns has following possible values:

1) `cache` - a labels saying that the request came from the cache
2) `13.2 KB` - a number saying how much data were transferred over the wire (perhaps compressed)

We need to add a flag saying that the request came from the network, but it happened because of "Race Cache With Network" feature.

So, one more additional possible value:

3) `13.2 KB (raced)` - a number indicating amount of data transferred + a label that explains why it didn't came from the cache.

Honza

Comment 13

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

(In reply to Jan Honza Odvarko [:Honza] from comment #12)
> So, one more additional possible value:
> 
> 3) `13.2 KB (raced)` - a number indicating amount of data transferred + a
> label that explains why it didn't came from the cache.

Just to make this a bit more clear.

The column should just append a flag saying that a request has been 'raced'.
So, there are two additional possible values:

3) `13.2 KB (raced)`
4) `cached (raced)`

Honza

Comment 14

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

Any chance we could get someone to actively work on this? Thanks!

Comment 15

[Patrick Brosset <:pbro>]

Planning for DevTools for Firefox 61 has already been done and the whole team is pretty packed as one might expect.
Maybe we'll have more room during the 62 nightly timeframe.
Can you help me fit that in by answering the following questions:

- Valentin: comment 0 said RCWN would be enabled in nightly and that this was blocked on this devtools feature, is that still the case?
- Honza: what is the complexity for the change in devtools? From what I can read, we already have access to the data in devtools, we just need to change what is displayed in one of the columns, is that correct?

Basically, I'm trying to assess the priority compared to the other things the devtools team is currently working on, to see if that is something we can take on quickly or not.

Comment 16

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

(In reply to Patrick Brosset <:pbro> from comment #15)
> Planning for DevTools for Firefox 61 has already been done and the whole
> team is pretty packed as one might expect.
> Maybe we'll have more room during the 62 nightly timeframe.
> Can you help me fit that in by answering the following questions:
> 
> - Valentin: comment 0 said RCWN would be enabled in nightly and that this
> was blocked on this devtools feature, is that still the case?

This feature has already shipped in release.
No one has yet to complain about the non-deterministic caching behaviour, but I think it's best we provide developers with this information.

Comment 17

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

(In reply to Patrick Brosset <:pbro> from comment #15)
> - Honza: what is the complexity for the change in devtools? From what I can
> read, we already have access to the data in devtools, we just need to change
> what is displayed in one of the columns, is that correct?
Yes, this doesn't feel as complex feature and should
be rather relatively simple.

Honza

Comment 18

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

Here are detailed instructions for anyone interested in this bug.

First of all, this bug is marked as "first-good-bug", but it's rather "second-good-bug", so not for anyone who's trying to fix  a bug in DevTools for the first time. Some experience needed.

=== Goal ===

The goal here is to display new label for racing HTTP requests in the Network panel. 

From comment #0:
"The RCWN feature in Necko adds the ability to race the cache with the network when the cache is slow. So if reading from the disk is slow, we will send a network request, and return the channel from the network, even though we have the entry in the cache. This way we provide the content to consumers faster."

There is new platform API allowing to figure out whether a request is raced or not:
`nsICacheInfoChannel.isRacing();`
See the attached patch.


=== UI ===

The new flag should be displayed in the existing "Transferred" column. This columns already shows information about whether the request came from the cache or not.

There will be four possible values for the column:
1) `13.2 KB` - a number saying how much data were transferred over the wire (perhaps compressed)
2) `cache` - a labels saying that the request came from the cache
3) `13.2 KB (raced)` - request is racing. The response was fetched from the server even if it's available in the cache. It was faster to get it from the server.
4) `cached (raced)` - request is racing. The response was fetched from the cache, but a request has been also sent to the server. The cache was faster in this case.

#1 and #2 is what we have now, #3 and #4 is new.

If there is not enough space in the column we might think about the following syntax (for #3 and #4):

`13.2 KB/raced` 
`cache/raced` 

... to save a few characters.


=== Implementation ===

1) The Transferred column is represented by `RequestListColumnTransferredSize`
devtools/client/netmonitor/src/components/RequestListColumnTransferredSize.js

The render method calculates `text` value, which represents the label. Here is the place where we need to check a new `isRacing` property (doesn't exist now) and calculate new values (#3 and #4)

The 'race' label should be localized here in this file:
devtools/client/locales/en-US/netmonitor.properties

2) The column is used here:
https://searchfox.org/mozilla-central/rev/028cd8342899357d80fafba2d528a0fd5819e316/devtools/client/netmonitor/src/components/RequestListItem.js#233

This is also the place where props are passed in. Only one props is passed in `item`, so `isRacing` should be part of it. The `item` represents the request object with all data. Data in this object are calculated here:

https://searchfox.org/mozilla-central/rev/028cd8342899357d80fafba2d528a0fd5819e316/devtools/client/netmonitor/src/connector/firefox-data-provider.js#328

This is the place where we handle update packet types send from the backend and read data from it. See more about the backend below. You might notice "securityInfo" packet type as it's mentioned below as well.


3) The `isRacing` flag needs to be sent to the UI from the backend. The backend has direct access to the HTTP channel (nsICacheInfoChannel).

The method can only be called after the channel fires its OnStartRequest notification, so we need to call `isRacing` in this method:

https://searchfox.org/mozilla-central/rev/028cd8342899357d80fafba2d528a0fd5819e316/devtools/shared/webconsole/network-monitor.js#432

Something like:
if (channel instanceof Ci.nsICacheInfoChannel) {
  this.request.isRacing();
}

4) You might get `this._getSecurityInfo();` call as an example how to report data to the client.
https://searchfox.org/mozilla-central/rev/028cd8342899357d80fafba2d528a0fd5819e316/devtools/shared/webconsole/network-monitor.js#503

See how new data are appended into the owner, look for 
this.httpActivity.owner.addSecurityInfo
this.httpActivity.owner.addResponseHeaders
this.httpActivity.owner.addResponseCookies
etc.

See all requestTypes packets here:
https://searchfox.org/mozilla-central/rev/028cd8342899357d80fafba2d528a0fd5819e316/devtools/server/actors/webconsole.js#2449

We might add the `isRacing` flag to one of the request packet type sent to the clint, which I think is better than introducing entire new packet for one flag. E.g. security info?

5) Compatibility with backends that are not supporting this new flag:

If the backend is sending the flag it should be true/false. If it's undefined, it means that the backend is not supporting this new feature

`RequestListColumnTransferredSize` render method should check against `undefined`.


Honza

Comment 19

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

@Ryan: what do you think about the #4 (section === Implementation ===)?
Can we utilize existing packet type? 

Honza

Comment 20

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

(In reply to Jan Honza Odvarko [:Honza] from comment #19)
> @Ryan: what do you think about the #4 (section === Implementation ===)?
> Can we utilize existing packet type?

Yes, your plan sounds good to me.  Since it's a purely additive change to the packet, it is straightforward for the client to handle both old and new versions.

Comment 21

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

@Mayank: any progress on this bug? Can I help with something?

Honza

Comment 22

[mayank9856]

Attachment: Bug1358038 : Add 'Race Cache With Network' status to netmonitor.

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

Comment 23

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

@valentin: We are finally trying to make a progress on this bug, but the platform patch implementing `isRacing()` method needs rebasing on top of m-c. Can you please take a look at that, thanks!

Honza

Comment 24

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

Comment on attachment 8975370 [details]
Bug1358038 : Add 'Race Cache With Network' status to netmonitor.

https://reviewboard.mozilla.org/r/243654/#review250196

Thanks for working on this Mayank!

Please see my inline comments.

Also, how do you  test this patch? Did you rebase the platform patch from Valentin?

Honza

::: .gitignore:56
(Diff revision 1)
>  js/src/tests/results-*.html
>  js/src/tests/results-*.txt
>  
>  # Java HTML5 parser classes
>  parser/html/java/htmlparser/
>  parser/html/java/javaparser/

I don't think we need this file in m-c?

::: devtools/client/netmonitor/src/components/RequestListColumnTransferredSize.js:39
(Diff revision 1)
>  
>    render() {
> -    let { fromCache, fromServiceWorker, status, transferredSize } = this.props.item;
> +    let {
> +      fromCache, fromServiceWorker, status,
> +      transferredSize, isRacing
> +    } = this.props.item;

Please put every prop into its own line. Something like as follow:

let {
  fromCache,
  fromServiceWorker,
  ...
} = this.props.item;

::: devtools/client/netmonitor/src/components/RequestListColumnTransferredSize.js:53
(Diff revision 1)
>      } else if (transferredSize === null) {
>        text = SIZE_UNAVAILABLE;
>      }
>  
> +    if (isRacing) {
> +      text += " (raced)";

I think this string should be localized (in netmonitor.properties) file

::: devtools/server/actors/webconsole.js:2282
(Diff revision 1)
> +   * Add connection Racing information.
> +   *
> +   * @param object info
> +   *        The object containing Racing Information
> +   */
> +  addRacingInfo: function(info) {

This code is sending entire new packet with just one field 'isRacing'.

Instead of introducing entire new packet that sends just one boolean property (not good for performance) we can add the prop into an existing packet.

We've been talking about the `responseCache` packet type (introduced in bug 859051). Or as an alternative there is also `securityInfo` I mentioned in comment #18 (at that time the `responseCache` packet didn't exist yet).

The `responseCache` packet type seems to be a bit more suitable for this.

Comment 25

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

Attachment: Add isRacing() to nsICacheInfoChannel

MozReview-Commit-ID: 4uH5kJIguI3

Comment 26

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

Ooops, bzexport changed the asignee :)

I rebased the patch on m-c. It should be fine now.

Comment 27

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

@Mayank, does the patch from Valentin work for you?

Honza

Comment 28

[Hengyeow (:tanhengyeow)]

:Honza

Would love to be assigned this bug! :)

Comment 29

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

Great, assigned to you!

Note that you need to apply the patch `Add isRacing() to nsICacheInfoChannel` that implements new platform API. The patch makes changes in .cpp/h/idl code and so you can't use `ac_add_options --enable-artifact-builds` in your .mozconfig file.

Honza

Comment 30

[Hengyeow (:tanhengyeow)]

Updates on the progress of this bug:
- Managed to apply the patch that implements the new platform API. I was able to build the project successfully after that. Have yet to test whether the API is working but will do so.
- I have been working on Bug 1437435 but will look into updating the frontend code for this patch now as I'm awaiting review for Bug 1437435 :)

Comment 31

[Hengyeow (:tanhengyeow)]

Hi Honza

It seem like the `devtools/shared/webconsole/network-monitor.js` file is not present in the latest build.

I searched for similar files, and they include `devtools/shared/specs/network-monitor.js`, `devtools/server/actors/network-monitor.js`.

I’m guessing that the code has been migrated over to `devtools/server/actors/network-monitor.js`, is that right? 

If so, the comment's guidelines (step 3 & 4) to send the flag to the UI from the backend would be out of context. Any other suggestions?

Comment 32

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

(In reply to Heng Yeow (:tanhengyeow) from comment #30)
> - I have been working on Bug 1437435 but will look into updating the
> frontend code for this patch now as I'm awaiting review for Bug 1437435 :)
I saw it, great job, review coming tomorrow.

(In reply to Heng Yeow (:tanhengyeow) from comment #31)
> It seem like the `devtools/shared/webconsole/network-monitor.js` file is not
> present in the latest build.
devtools\server\actors\network-monitor\network-response-listener.js:

You should looking around this place:
https://searchfox.org/mozilla-central/rev/3c85ea2f8700ab17e38b82d77cd44644b4dae703/devtools/server/actors/network-monitor/network-response-listener.js#224

Honza

Comment 33

[Hengyeow (:tanhengyeow)]

Attachment: Bug 1358038 - Add "Race Cache With Network" status. r=Honza

Comment 34

[Hengyeow (:tanhengyeow)]

:Honza

I have an initial patch ready for review in Phabricator, would like to know if I am heading in the right direction :) 

Also, how would you advice on a manual test plan to simulate race conditions?

Comment 35

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

@Valentin: how can we implement a mochitest for this? Are there any platform API we can use to ensure that specific request in a test has isRacing set?

Also, for user testing, are there any pages we could use?

Honza

Comment 36

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

Right now we only have an xpcshell-test for the feature:
netwerk/test/unit/test_race_cache_with_network.js where we synthetically add a delay to the cache loads to test for specific corner cases.
But from my experience the cache is usually slower than a local webserver... so what we can do to test this is to load some resources from the webserver repeteadly... and add a delay in the handler before sending back a response. Increasing the delay from 0 to ~50 ms should ensure that there is a decent spread of network wins and cache wins responses.

Comment 37

[Hengyeow (:tanhengyeow)]

Attachment: Bug 1358038 - Add Platform API for race conditions. r=Honza

Bug 1358038 - Add Platform API for race conditions. r=Honza

Comment 38

[Hengyeow (:tanhengyeow)]

Attachment: Bug 1358038 - Add "Race Cache With Network" status. r=Honza

Bug 1358038 - Add "Race Cache With Network" status. r=Honza

Comment 39

[Hengyeow (:tanhengyeow)]

Hi :valentin

I have setup a local web server to return a resource upon loading (tried image files of ~10KB and executable files of ~10MB).

However, it seems like the cache always wins in my case after the first request (first request was a normal full transfer as expected). 

Do you have recommendations to circumvent this?

Comment 40

[Michal Novotny [:michal]]

Try to set preference network.http.rcwn.max_wait_before_racing_ms to 0. If this doesn't help, try to stress your HDD.

Comment 41

[Hengyeow (:tanhengyeow)]

Hi :michal

Setting the preference doesn't seem to work for me. Also I'm using a SSD so it might be difficult to replicate this scenario compared to stress testing a HDD. Do you have other recommendations for a more deterministic test plan? Thank you :D

Comment 42

[Michal Novotny [:michal]]

Attachment: force_random_rcwn.patch

(In reply to Heng Yeow (:tanhengyeow) from comment #41)
> Hi :michal
> 
> Setting the preference doesn't seem to work for me. Also I'm using a SSD so
> it might be difficult to replicate this scenario compared to stress testing
> a HDD. Do you have other recommendations for a more deterministic test plan?
> Thank you :D

Try this patch. It delays randomly opening the cache entry by 100ms.

Comment 43

[Hengyeow (:tanhengyeow)]

Thanks for the patch! I've tried running a for loop in my client javascript to repeatedly load resources from the web server. 

As a result, I got both cache and network wins. However, it didn't show the (raced) label that we are expecting.

I tried debugging through the toolbox and deliberately setting `isRacing` as true and the text does displays the desired results correctly. I feel the issue lies with `isRacing` being always interpreted as `undefined` or `null`.

I would need some help in verifying if the platform API patch is applied correctly (same for the front-end files), thank you! :D

Comment 44

[Michal Novotny [:michal]]

Attachment: force_random_rcwn.patch

Try this new patch. The problem with the old one was that delaying opening the entry delayed also setting mRaceCacheWithNetwork flag.

Comment 45

[Hengyeow (:tanhengyeow)]

Hi :michal

Thanks for helping, appreciate it :) I've applied the patch on top of Attachment 9014788 [details] but it still isn't working. 

Can I trouble you to check if Attachment 9014788 [details] requires any updates? The attachment is created based on Attachment 8976256 [details] [diff] which was created sometime ago so I'm not sure if it requires further updates since then.

Once again thanks a lot for your prompt response :D

Comment 46

[Michal Novotny [:michal]]

(In reply to Heng Yeow (:tanhengyeow) from comment #45)
> Thanks for helping, appreciate it :) I've applied the patch on top of
> Attachment 9014788 [details] but it still isn't working. 

Do you mean that network doesn't win the race or that HttpChannelChild::IsRacing never returns true?

> Can I trouble you to check if Attachment 9014788 [details] requires any
> updates? The attachment is created based on Attachment 8976256 [details] [diff]
> [diff] which was created sometime ago so I'm not sure if it requires further
> updates since then.

At the first look it seems the patch should work. You can add few LOGs to see what's propagated to HttpChannelChild and what HttpChannelChild::IsRacing returns.

Comment 47

[Hengyeow (:tanhengyeow)]

Hi :Honza

I've updated the patch to update more necessary files that work with transporting the isRacing flag from the backend to the frontend(updated in Phabricator).

However, it seems like the isRacing flag still isn't being interpreted properly (e.g. still undefined) when I debug the files. In a separate experiment, I deliberately set isRacing to be true when it is being added in the `_getSecurityInfo` function and the results are the same.

I suspect that the flag isn't read properly because it is embedded in the securityInfo object and not extracted out properly. Would like some advice on this :)

Comment 48

[Hengyeow (:tanhengyeow)]

Hi :michal

> Do you mean that network doesn't win the race or that HttpChannelChild::IsRacing never returns true?

The network does win the race now. Here is how I query interface the channel:

```
    let isRacing = false;
    const channel = this.httpActivity.channel;
    if (channel instanceof Ci.nsICacheInfoChannel) {
      isRacing = channel.isRacing();
    }
```

Am I doing it correctly? I've inserted `court` statements in `HttpChannelChild::IsRacing` and the statement didn't print out in the console, so I'm suspecting either I'm doing it wrong or the platform API never gets called somehow. Please advice on this, thank you :)

Comment 49

[Michal Novotny [:michal]]

Sorry, I can't help you with the JS part. You can use LOG((...)) which you would then see in HTTP log https://developer.mozilla.org/en-US/docs/Mozilla/Debugging/HTTP_logging.

Ideally, use a debugger to find out whether the method is called or not. If you disabled e10s, then nsHttpChannel::IsRacing will be called. I'm not sure when exactly InterceptedHttpChannel::IsRacing would be called.

Comment 50

[Hengyeow (:tanhengyeow)]

Hi :michal

Thanks for the reply! I need help with understanding the platform API patch (haven't dealt with C++ files before, more of a Java person). 

Here's my current understanding of the relationship of .idl/.h/.cpp files (please correct me if I'm wrong):
1. .idl files describe an interface of methods and attributes. Any class implementing it needs to implement the methods specified in this "contract".
2. .h files are generated from idl files to be used during compilation (specific to C++).
3. .cpp files are the source files that contain the actual logic of the methods implemented.

Here's my progress experimenting with the patch:
1. `nsHttpChannel::IsRacing` always gets called and the value of `*aIsRacing` is always false. Results are the same even if I did not query interface it from the JS side.
2. `InterceptedHttpChannel::IsRacing` and `HttpChannelChild::IsRacing` never gets called at all. Results are the same even if I did not query interface it from the JS side.

Here are some questions I have:
1. What are `nsHttpChannel::IsRacing`, `InterceptedHttpChannel::IsRacing` and `HttpChannelChild::IsRacing` doing? Why does `nsHttpChannel::IsRacing` always gets called? There is a comment for `InterceptedHttpChannel` which says: "We transfer parameters to the saved nsICacheInfoChannel(mSynthesizedCacheInfo)". How about the other two?

2. All the methods mentioned in point 1 seems to take in a value, e.g. `...(bool *aIsRacing)`. Who is supplying this value?

3. There is an example that query interface the backend and the `alternativeDataType` can be directly accessed just by  `channel.alternativeDataType`. `alternativeDataType` is defined in `nsICacheInfoChannel.idl`. Should the `isRacing` flag be declared something like this?

Sincerely appreciate your patience in guidance in this patch!

Comment 51

[Michal Novotny [:michal]]

(In reply to Heng Yeow (:tanhengyeow) from comment #50)
> 2. `InterceptedHttpChannel::IsRacing` and `HttpChannelChild::IsRacing` never
> gets called at all. Results are the same even if I did not query interface
> it from the JS side.

Are you looking at the correct log file? This will be in the log file from the child process.

> Here are some questions I have:
> 1. What are `nsHttpChannel::IsRacing`, `InterceptedHttpChannel::IsRacing`
> and `HttpChannelChild::IsRacing` doing? Why does `nsHttpChannel::IsRacing`
> always gets called?

nsHttpChannel::IsRacing is called from HttpChannelParent::OnStartRequest where it gets the value and sends it to the child process.

> 2. All the methods mentioned in point 1 seems to take in a value, e.g.
> `...(bool *aIsRacing)`. Who is supplying this value?

It's an output parameter, the value is stored there.

> 3. There is an example that query interface the backend and the
> `alternativeDataType` can be directly accessed just by 
> `channel.alternativeDataType`. `alternativeDataType` is defined in
> `nsICacheInfoChannel.idl`. Should the `isRacing` flag be declared something
> like this?

alternativeDataType is an attribute whereas isRacing is a method.

Comment 52

[Hengyeow (:tanhengyeow)]

> Are you looking at the correct log file? This will be in the log file from the child process.

Yup I've checked it again and the results are still the same. Only `nsHttpChannel::IsRacing` gets called every time and even so the LOG entry is only found in the main log.txt (all of them can't be found in log.text.child files).

Would need help in verifying if the platform API works as intended, thanks! :)

Comment 53

[Hengyeow (:tanhengyeow)]

Hi :Honza

Further updates on the front-end portion:

1. Since the information can't be read from `devtools/server/actors/network-monitor/network-observer.js` anymore, the value isn't available when it reaches `devtools/client/netmonitor/src/connector/firefox-data-provider.js`, unlike before.

2. I tried manually setting `isRacing` to be true in the _getSecurityInfo() call, e.g.:

```
    const isRacing = true;
    this.httpActivity.owner.addSecurityInfo({
      info: info,
      isRacing: isRacing
    });
```

but the value of `isRacing` isn't available when it reaches this method of `devtools/server/actors/network-event.js`:

```
  /**
   * Set the properties of this actor based on it's corresponding
   * network event.
   *
   * @param object networkEvent
   *        The network event associated with this actor.
   */
  init(networkEvent) {
    this._startedDateTime = networkEvent.startedDateTime;
    this._isXHR = networkEvent.isXHR;
    this._cause = networkEvent.cause;
    this._fromCache = networkEvent.fromCache;
    this._isRacing = networkEvent.isRacing; <--------- (isRacing isn't a property of the networkEvent at all)
    this._fromServiceWorker = networkEvent.fromServiceWorker;
    this._isThirdPartyTrackingResource = networkEvent.isThirdPartyTrackingResource;
    this._referrerPolicy = networkEvent.referrerPolicy;
    this._channelId = networkEvent.channelId;
.......
```

Any tips on resolving the following?

1. Finding a way to pass value of isRacing to `devtools/client/netmonitor/src/connector/firefox-data-provider.js` and also ``devtools/server/actors/network-event.js` given that we don't have the value in `devtools/server/actors/network-monitor/network-observer.js`

2. Making sure the value added (isRacing) in the security packet is transferred to the respective files which needs to read it.

Comment 54

[Michal Novotny [:michal]]

(In reply to Heng Yeow (:tanhengyeow) from comment #52)
> Would need help in verifying if the platform API works as intended, thanks!

I verified that isRacing flag is passed from nsHttpChannel to HttpChannelChild correctly.

While inspecting the logs I found a special case when it doesn't work correctly. If LOAD_ONLY_IF_MODIFIED flag is used, we don't read the data, nsHttpChannel::OnStartRequest isn't called and mAfterOnStartRequestBegun is false. I think it's a bug because although nsHttpChannel::OnStartRequest was omitted, according to meaning of mAfterOnStartRequestBegun it should be IMO true. We could set it to true in HttpBaseChannel::DoNotifyListener if it's false there. Valentin, what do you think?

Comment 55

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

(In reply to Michal Novotny [:michal] from comment #54)
> We could set it to true in HttpBaseChannel::DoNotifyListener if it's
> false there. Valentin, what do you think?

That sounds good. I filed bug 1507467 for it.
Is that what was causing the issue here? Does the netmonitor set LOAD_ONLY_IF_MODIFIED on channels?

Comment 56

[Michal Novotny [:michal]]

(In reply to Valentin Gosu [:valentin] from comment #55)
> Is that what was causing the issue here? Does the netmonitor set
> LOAD_ONLY_IF_MODIFIED on channels?

No, the flag is used only by appcache and prefetch service. The problem here is somewhere in the JS code, because HttpChannelChild receives the flag correctly except this rare case.

Comment 57

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

@Valentin, could you please rebase the platform patch on the latest head?
Thanks!

Honza

Comment 58

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

Attachment: Bug 1358038 - Add isRacing() to nsICacheInfoChannel r=michal!

Comment 59

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

Comment on attachment 8976256 [details] [diff] [review]
Add isRacing() to nsICacheInfoChannel

I rebased the patch on top of m-c: see attachment 9036216 [details]
I also added an info line to the test to make sure that it works, at least in non-e10s mode, and it does.

Comment 60

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

Attachment: force_random_rcwn.patch

Rebasing

Honza

Comment 61

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

Thanks Valentin for the rebase!
(I also rebased the additional patch from Michal)

---

Similarly to (:tanhengyeow, comment #52), I can't get any request that would have set isRacing flag to true.

I applied:

1. Bug 1358038 - Add isRacing() to nsICacheInfoChannel r=michal!
   The platform API implementation

2. force_random_rcwn.patch
   Helper from Michal

3. Bug 1358038 - Add "Race Cache With Network" status. r=Honza
   The UI changes in DevTools

I tried to set the following prefs:

network.http.rcwn.enabled = true
network.http.rcwn.max_wait_before_racing_ms

It looks like nsHTTPChannel.OnCacheEntryCheck is only called 3 times at the beginning (Firefox start), but never when opening DevTools and loading a page.

channel.isRacing() returns false all the time for me.

This is what I am doing:

1. Apply all the patches above, set prefs above
2. Add the following log into network-response-listeners.js, in _getSecurityInfo method:
   dump("Racing: " + isRacing);
3. Start Firefox, open DevTools, load google.com
4. Select the Network panel, reload the page
5. Observe the system console and look for the log from step #2 => It always prints false

@Valentin, could you please check these steps?
Is there anything I am doing wrong?
Does that work for you?

Honza

Comment 62

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

@Valentin: do you have time to look at this or should I ask someone else?
Thanks!
Honza

Comment 63

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

(In reply to Jan Honza Odvarko [:Honza] (need-info? me) from comment #62)

@Valentin: do you have time to look at this or should I ask someone else?

Sorry, I've been caught up with other things and I don't know if I can get to it this week.

Comment 64

[Michal Novotny [:michal]]

I'll test it.

Comment 65

[Michal Novotny [:michal]]

I followed the steps in comment #61 and I see false as well as true in the console.

Comment 66

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

@Valentin, any chance you could look at this?
Honza

Comment 67

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

(In reply to Jan Honza Odvarko [:Honza] (always need-info? me) from comment #61)

Similarly to (:tanhengyeow, comment #52), I can't get any request that would have set isRacing flag to true.

I applied:

1. Bug 1358038 - Add isRacing() to nsICacheInfoChannel r=michal!
   The platform API implementation

2. force_random_rcwn.patch
   Helper from Michal

3. Bug 1358038 - Add "Race Cache With Network" status. r=Honza
   The UI changes in DevTools

Hi Honza,

I applied both D7636 and D8018 (needed a rebase), and I can see both false and a few true results. I tried it on suggested pages in the new tab (wiki, reddit, twitter, etc) and refreshed. The racing=true requests happen in 5-10% of the cases, so the patches seem to work.

Comment 68

[Hengyeow (:tanhengyeow)]

Hi Valentin

I'm helping to test this patch. I pulled code from this revision, rebased the patch on top of m-c's latest changes but failed to build the code.

These are some errors I'm seeing which might aid in investigating the issue:

/Applications/Xcode.app/Contents/Developer/Toolchains/XcodeDefault.xctoolchain/usr/lib/clang/10.0.0/include/stdarg.h:43:9: note: macro 'va_copy' defined here
10:47.43 #define va_copy(dest, src)  __builtin_va_copy(dest, src)
10:47.43         ^
10:47.43 1 warning and 2 errors generated.
10:47.43 make[4]: *** [Unified_cpp_protocol_http1.o] Error 1

11:00.38 make[3]: *** [netwerk/protocol/http/target] Error 2
11:00.38 make[3]: *** Waiting for unfinished jobs....
11:00.52 /Users/seed/Development/mozilla-central/netwerk/sctp/src/netinet/sctp_usrreq.c:1088:11: warning: 'return' will never be executed [-Wunreachable-code-return]
11:00.52                 return (0);
11:00.52                         ^
11:00.52 /Users/seed/Development/mozilla-central/netwerk/sctp/src/netinet/sctp_usrreq.c:6879:3: warning: code will never be executed [-Wunreachable-code]
11:00.52                 sctp_bindx_delete_address(inp, addrs->addr,
11:00.52                 ^~~~~~~~~~~~~~~~~~~~~~~~~
11:00.52 /Users/seed/Development/mozilla-central/netwerk/sctp/src/netinet/sctp_usrreq.c:6828:3: warning: code will never be executed [-Wunreachable-code]
11:00.52                 sctp_bindx_add_address(so, inp, addrs->addr,
11:00.52                 ^~~~~~~~~~~~~~~~~~~~~~
11:00.53 3 warnings generated.
11:00.87 /Users/seed/Development/mozilla-central/netwerk/sctp/src/user_socket.c:2651:37: warning: code will never be executed [-Wunreachable-code]
11:00.87                 sa = (struct sockaddr *)((caddr_t)sa + sa->sa_len);
11:00.87                                                   ^~
11:00.87 1 warning generated.
12:12.39    Compiling cert_storage v0.0.1 (/Users/seed/Development/mozilla-central/security/manager/ssl/cert_storage)
12:12.39    Compiling geckoservo v0.0.1 (/Users/seed/Development/mozilla-central/servo/ports/geckolib)
12:31.03    Compiling gkrust v0.1.0 (/Users/seed/Development/mozilla-central/toolkit/library/rust)
12:33.38     Finished release [optimized] target(s) in 10m 56s
12:33.53     Finished release [optimized] target(s) in 10m 56s
12:33.76    Compiling jsrust v0.1.0 (/Users/seed/Development/mozilla-central/js/src/rust)
12:34.16     Finished release [optimized] target(s) in 10m 56s
12:34.21 make[2]: *** [compile] Error 2
12:34.21 make[1]: *** [default] Error 2
12:34.22 make: *** [build] Error 2
12:34.24 155 compiler warnings present.
12:34.37 /usr/local/bin/terminal-notifier -title Mozilla Build System -group mozbuild -message Build failed

Would appreciate some help here!

Comment 69

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

Can you try to compile it again and look for error: in the output?
I only see warning: in what you pasted.
Not sure how va_copy is related to the failure.

Comment 70

[Hengyeow (:tanhengyeow)]

Hi :valentin

Thanks for the help! It turned out to be some rebasing problem that caused the issue faced above so everything's cool now :) Was able to reproduce some racing requests through sites like Reddit/Stack Overflow so the platform side is working correctly. I'm working on updating the DevTools side to show the race status.

:Honza, I've updated D8018 and it successfully shows the race status in the Transferred column. My test sites were Reddit/Stack Overflow.

Comment 71

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

@tanhengyeow:, thanks for the update! (the patch needs rebase)

@valentin: the Network panel UI works for us and we can start landing.
The platform patch needs to be rebased on top of the latest m-c
(conflict with new function arguments).

Can you please rebase, thanks!

Honza

Comment 72

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

@Michal, can you please rebase the platform patch? Valentin is on PTO for next 3 weeks.
(it's ready to land)

Honza

Comment 73

[Michal Novotny [:michal]]

Attachment: Add isRacing() to nsICacheInfoChannel, rebased patch

Comment 74

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

@tanhengyeow: there are some ESlint failures on try:
https://treeherder.mozilla.org/#/jobs?repo=try&revision=d7450cf50f3ad8c379f2d8d7324e769e0fd755fd&selectedJob=240406584

Honza

Comment 75

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

@Michal: Failed to land, https://lando.services.mozilla.com/D16417/

We're sorry, Autoland could not rebase your commits for you automatically. Please manually rebase your commits and try again. (255, 'applying /tmp/tmpdHz6on\npatching file netwerk/protocol/http/HttpChannelParent.cpp\nHunk #3 FAILED at 1454\n1 out of 3 hunks FAILED -- saving rejects to file netwerk/protocol/http/HttpChannelParent.cpp.rej\npatching file netwerk/protocol/http/HttpChannelChild.cpp\nHunk #4 succeeded at 438 with fuzz 2 (offset 1 lines).\nHunk #6 FAILED at 467\nHunk #7 succeeded at 496 with fuzz 2 (offset 3 lines).\nHunk #8 succeeded at 526 with fuzz 2 (offset 3 lines).\n1 out of 10 hunks FAILED -- saving rejects to file netwerk/protocol/http/HttpChannelChild.cpp.rej\nabort: patch failed to apply', '')

Honza

Comment 76

[Hengyeow (:tanhengyeow)]

Attachment: Support "Race Cache With Network" in DevTools

Attaching the latest patch that is in sync with the Phabricator patch.

Comment 77

[Hengyeow (:tanhengyeow)]

This is the latest try results for the attached patch above:
https://treeherder.mozilla.org/#/jobs?repo=try&revision=5e005666b61dc36b81c20d1e5b36c4b3e665c444

Haven't look too much into it but the failing tests were mostly related to security tests.

Comment 78

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

Thanks!

My try looks better:
https://treeherder.mozilla.org/#/jobs?repo=try&revision=d7450cf50f3ad8c379f2d8d7324e769e0fd755fd&selectedJob=240406584

(ESlint failures unrelated)

Honza

Comment 79

[Pulsebot]

Pushed by [e-mail]:
https://hg.mozilla.org/integration/mozilla-inbound/rev/17f5cadc3b29
Add "Race Cache With Network" status. r=Honza
https://hg.mozilla.org/integration/mozilla-inbound/rev/f1455cdc78ed
"Add "Race Cache With Network" status to netmonitor" r=Honza

Comment 80

[Raul Gurzau (:RaulG)]

https://hg.mozilla.org/mozilla-central/rev/17f5cadc3b29
https://hg.mozilla.org/mozilla-central/rev/f1455cdc78ed

Comment 81

[vaindil]

I'm a web developer and started seeing (raced) in my network requests as of today, 68.0b13. I'm confused as to what's actually happening though, it seems unclear. I attached an example. Some of the raced requests have status codes, some don't, nothing is grayed out like normal cached requests are. I ran this by a few other people and none of us could figure out exactly what this is supposed to mean.

Don't know if the current UI is final, just putting my two cents out that this is very unclear.

Comment 82

[vaindil]

Actually, I guess I can't add an attachment, sorry for the double comment. It's here: https://i.imgur.com/mA6K80Q.png

Comment 83

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

Thanks, I filled a new bug 1561532 (to introduce better UI)

Please comment in that new bug if you have suggestions about how to improve the user experience.

Honza