Closed Bug 1396856 Opened 7 years ago Closed 7 years ago

Lots of HTTP connections result in poor performance caused by WebRequest.jsm and MessageChannel.jsm

Categories

(WebExtensions :: Request Handling, enhancement)

enhancement
Not set
normal

Tracking

(Performance Impact:?, firefox57 fixed)

RESOLVED FIXED
mozilla57
Performance Impact ?
Tracking Status
firefox57 --- fixed

People

(Reporter: ehsan.akhgari, Assigned: kmag)

References

(Blocks 1 open bug)

Details

Attachments

(4 files)

A user has submitted feedback on my blog about poor performance they're getting caused by a lot of expensive stuff we run on the UI thread in the face of too many ongoing HTTP requests.  See this profile for example: https://perfht.ml/2eyktgz.  The blog post: https://ehsanakhgari.org/blog/2017-08-25/quantum-flow-engineering-newsletter-21

Their use case is setting browser.sessionstore.restore_on_demand to false with the uMatrix extension installed, restoring a large session with 50 tabs and trying to scroll on the active tab.  While I think it's unreasonable to expect us to deliver good performance with that pref change, the performance problem is probably worth looking into.

Kris, do you mind taking a look please?  Thanks.
Flags: needinfo?(kmaglione+bmo)
Hm. I'm not sure how much we can do about this on a short timescale.

It looks like the biggest chunks of overhead are structured cloning the request data, and cloning an arrow function, for each request, which I don't think we can avoid.

Aside from that, the biggest issue seems to be a bunch of scattered XPConnect overhead, mainly from dealing with channels, but also from the message manager classes. I could solve that by rewriting some key parts of WebRequest.jsm in C++, but I'm not sure how long that would take or how soon I'll have the time to do it. I'll look into it this week, though.
Component: WebExtensions: General → WebExtensions: Request Handling
Flags: needinfo?(kmaglione+bmo)
Blocks: webext-perf
There's also a huge amount of proxy overhead contributing to the problems here. Bug 1186409 should hopefully cut down on a lot of that.
Depends on: 1186409
Hello, everyone! I am the guy who left a comment in Ehsan Akhgari's blog about performance regression with restore_on_demand false. Thank you very much for taking your time and looking at my profiles! 

I tried to improve the STR so I've just reproduced a similar performance regression with just two tabs open! STR is simple: turn off Kaspersky, create new profile, install uMatrix and forbid everything except for .css and images, open a long web page in the active tab, open the web page with big number of thumbnails in the background tab and hold Arrow down key.

Result: constant scrolling fps drops, as far as I can tell, CPU utilization never reached 100%. Here is the profile: 
https://perfht.ml/2wCpwmn

I hope it'll help.
Depends on: 888600
Thanks a lot Kris, and also ajfhajf.  Knowing that the same issue can happen with only two tabs makes this a bit more worrying.  :-(
(In reply to ajfhajf from comment #3)
> I hope it'll help.

Yes, it helps. Thanks!

(In reply to :Ehsan Akhgari (needinfo please, extremely long backlog) from comment #4)
> Thanks a lot Kris, and also ajfhajf.  Knowing that the same issue can happen
> with only two tabs makes this a bit more worrying.  :-(

Don't thank me yet. You're probably going to wind up having to review the WebIDL channel wrapper I'm going to have to write to fix this. :P
(In reply to :Ehsan Akhgari (needinfo please, extremely long backlog) from comment #4)
> Thanks a lot Kris, and also ajfhajf.  Knowing that the same issue can happen
> with only two tabs makes this a bit more worrying.  :-(

I forgot to add I didn't modify any about:config entries or settings in Tools - Options in STR from comment 3.
There's probably still more to do here, but so far this seems to remove at least the bulk of the WebRequest.jsm side of the overhead.
Comment on attachment 8904869 [details]
Bug 1396856: Part 2 - Add top outer window ID to LoadInfo.

https://reviewboard.mozilla.org/r/176648/#review181798

::: netwerk/base/LoadInfo.cpp:33
(Diff revision 1)
>  
>  namespace mozilla {
>  namespace net {
>  
> +uint64_t
> +FindTopOuterWindowID(nsPIDOMWindowOuter* aOuter)

Nit: please make this static.

::: netwerk/base/nsILoadInfo.idl:503
(Diff revision 1)
>     * These are the window IDs of the window in which the element being
>     * loaded lives. parentOuterWindowID is the window ID of this window's
>     * parent.
>     *
>     * Note that these window IDs can be 0 if the window is not
>     * available. parentOuterWindowID will be the same as outerWindowID if the

Nit: s/parentOuterWindowID/parentOuterWindowID and topOuterWindowID/
Attachment #8904869 - Flags: review?(ehsan) → review+
Comment on attachment 8904870 [details]
Bug 1396856: Part 3 - Add a WebIDL wrapper class for necko channels.

https://reviewboard.mozilla.org/r/176650/#review181802

Thanks, this is really great!  I'd appreciate if Shane can go over the logic of the methods in ChannelWrapper.cpp, as I mostly reviewed the correctness of the bindings part.

::: dom/webidl/ChannelWrapper.webidl:10
(Diff revision 1)
> +interface LoadInfo;
> +interface MozChannel;
> +interface URI;
> +interface nsISupports;
> +
> +enum MozContentPolicyType {

Do you mind adding a comment here to note that changes to this enum would need to update the constants in nsIContentPolicy.idl, and also update https://searchfox.org/mozilla-central/rev/4d8e389498a08668cce9ebf6232cc96be178c3e4/dom/base/nsIContentPolicy.idl#340 please?

::: toolkit/components/extensions/webrequest/ChannelWrapper.cpp:209
(Diff revision 1)
> +    return --mRefCnt;
> +  }
> +
> +  virtual ~HeaderVisitor()
> +  {
> +    MOZ_ASSERT(mRefCnt == 0);

Nit: it may be a good idea to make this a diagnostic assert.  If this fails, we really want to catch it...

::: toolkit/components/extensions/webrequest/ChannelWrapper.cpp:235
(Diff revision 1)
> +  }
> +
> +  JSContext* mCx;
> +  RootedObject mMap;
> +
> +  uint32_t mRefCnt = 0;

Nit: please use nsrefcnt for refcount variables.

::: toolkit/components/extensions/webrequest/ChannelWrapper.cpp:266
(Diff revision 1)
> +void
> +ChannelWrapper::GetRequestHeaders(JSContext* cx, JS::MutableHandle<JSObject*> aRetVal, ErrorResult& aRv) const
> +{
> +  if (nsCOMPtr<nsIHttpChannel> chan = MaybeHttpChannel()) {
> +    HeaderVisitor visitor(cx);
> +    aRetVal.set(visitor.VisitRequestHeaders(chan, aRv));

I think the rooting here is correct, since the map remains rooted when the assignment to aRetVal is happening.  That being said, it may be a good idea to add a comment as to why returning a bare `JSObject*` from VisitRequestHeaders/VisitResponseHeaders is OK before the declaration of those methods...

::: toolkit/components/extensions/webrequest/ChannelWrapper.cpp:328
(Diff revision 1)
> +
> +already_AddRefed<nsILoadContext>
> +ChannelWrapper::GetLoadContext() const
> +{
> +  if (nsCOMPtr<nsIChannel> chan = MaybeChannel()) {
> +    nsCOMPtr<nsILoadContext> ctxt = FindLoadContext(chan);

I may be missing something here, but couldn't you use NS_QueryNotificationCallbacks() instead of rolling your own logic here?

::: toolkit/components/extensions/webrequest/ChannelWrapper.cpp:352
(Diff revision 1)
> +    }
> +  }
> +  return nullptr;
> +}
> +
> +bool

Nit: static

::: toolkit/components/extensions/webrequest/ChannelWrapper.cpp:494
(Diff revision 1)
> + *****************************************************************************/
> +
> +MozContentPolicyType
> +GetContentPolicyType(uint32_t aType)
> +{
> +  switch (aType) {

Same comment about linking to nsIContentPolicy.idl as the header...
Attachment #8904870 - Flags: review?(ehsan) → review+
Comment on attachment 8904868 [details]
Bug 1396856: Part 1 - Remove spread call fallback overhead in event dispatch.

https://reviewboard.mozilla.org/r/176646/#review181860
Attachment #8904868 - Flags: review?(tomica) → review+
Comment on attachment 8904871 [details]
Bug 1396856: Part 4 - Update WebRequest.jsm to use ChannelWrapper bindings.

https://reviewboard.mozilla.org/r/176652/#review182022

wow.  nice.
Attachment #8904871 - Flags: review?(mixedpuppy) → review+
Comment on attachment 8904870 [details]
Bug 1396856: Part 3 - Add a WebIDL wrapper class for necko channels.

https://reviewboard.mozilla.org/r/176650/#review182012

::: toolkit/components/extensions/webrequest/ChannelWrapper.cpp:459
(Diff revision 1)
> +    auto frameID = loadInfo->GetFrameOuterWindowID();
> +    if (!frameID) {
> +      frameID = loadInfo->GetOuterWindowID();
> +    }

frame ID logic here is unecessary.
Attachment #8904870 - Flags: review?(mixedpuppy) → review+
Assignee: nobody → kmaglione+bmo
Comment on attachment 8904870 [details]
Bug 1396856: Part 3 - Add a WebIDL wrapper class for necko channels.

https://reviewboard.mozilla.org/r/176650/#review182012

> frame ID logic here is unecessary.

Urgh. Good catch.
Blocks: 1397448
Comment on attachment 8904870 [details]
Bug 1396856: Part 3 - Add a WebIDL wrapper class for necko channels.

https://reviewboard.mozilla.org/r/176650/#review181802

> Nit: it may be a good idea to make this a diagnostic assert.  If this fails, we really want to catch it...

Yeah, I was actually considering that too...

> I think the rooting here is correct, since the map remains rooted when the assignment to aRetVal is happening.  That being said, it may be a good idea to add a comment as to why returning a bare `JSObject*` from VisitRequestHeaders/VisitResponseHeaders is OK before the declaration of those methods...

Returning a bare `JSObject*` is always safe as long as it's rooted before any calls that could trigger a GC. And the rooting hazard analysis job will throw errors if that happens.

> I may be missing something here, but couldn't you use NS_QueryNotificationCallbacks() instead of rolling your own logic here?

Ohhhh yes. I copied this logic from the JS implementation without thinking. But the JS implementation was initially copied from NS_QueryNotificationCallbacks
Depends on: 1397536
(In reply to Kris Maglione [:kmag] (long backlog; ping on IRC if you're blocked) from comment #18)
> > I think the rooting here is correct, since the map remains rooted when the assignment to aRetVal is happening.  That being said, it may be a good idea to add a comment as to why returning a bare `JSObject*` from VisitRequestHeaders/VisitResponseHeaders is OK before the declaration of those methods...
> 
> Returning a bare `JSObject*` is always safe as long as it's rooted before
> any calls that could trigger a GC. And the rooting hazard analysis job will
> throw errors if that happens.

Yes, fair enough.  Nevermind that part then.  :-)
https://hg.mozilla.org/integration/mozilla-inbound/rev/1e4b5ec2904fcf7641a322480c45a4efd6da40da
Bug 1396856: Part 1 - Remove spread call fallback overhead in event dispatch. r=zombie

https://hg.mozilla.org/integration/mozilla-inbound/rev/3b496e60f978d3ca2792c90ba01207cd7427aaf6
Bug 1396856: Part 2 - Add top outer window ID to LoadInfo. r=ehsan

https://hg.mozilla.org/integration/mozilla-inbound/rev/223a7c5a7c471f5fbf319029da2dcc5a093b8548
Bug 1396856: Part 3 - Add a WebIDL wrapper class for necko channels. r=ehsan,mixedpuppy

https://hg.mozilla.org/integration/mozilla-inbound/rev/30fe3c84b60ee8ae1ab865733041173902892e8f
Bug 1396856: Part 4 - Update WebRequest.jsm to use ChannelWrapper bindings. r=mixedpuppy
Depends on: 1397785
Blocks: 1386895
Depends on: 1398045
ajfhajf, any chance you could test things again on the latest Nightly and capture a new profile please?  Please see if you can notice any improvements.  If possible, it would be ideal if you can keep all of the testing conditions as similar as possible to the ones you were using last week for the profiles in comment 0.

Thanks so much!
Flags: needinfo?(ajfhajf)
Hello!
Unfortunately, I don't notice any performance improvements in both my regular Nightly profile and a new profile. I've recorded a new profile in Nightly 14-09-17-2 using STR from comment 0. 

STR:
Create new profile, install uMatrix, forbid everything except for .css and images, open the long web page in the 1st tab, start recording the profile, open the page with lots of thumbnails in the 2nd tab in the background and press Arrow down in order to start scrolling the long web page in the 1st tab. In other words, no about:config tweaks, no Tools - Options modified.

Profile: https://perfht.ml/2x3q833
Constant fps drops every couple of seconds from the very beginning.

I also sent you profiles that I recorded with 50 tabs and browser.sessionstore.restore_on_demand set to false but this use case is not officially supported so I guess it doesn't make sense to record the profile with these settings. Also, I have a couple of ideas:

Should I record a profile with GPU process priority set to High in Windows Task Manager?
Should I record a profile with uMatrix and uBlock installed and 1 content process? It should simulate the situation when the active tab shares the content process with "heavy" tab loading in the background.
Flags: needinfo?(ajfhajf)
Also, [Bug 1398895] "JSM sharing pref not used when manually set" has just landed. Maybe it'll improve performance with jsloader.shareGlobal set to true.
(In reply to ajfhajf from comment #24)
> Also, [Bug 1398895] "JSM sharing pref not used when manually set" has just
> landed. Maybe it'll improve performance with jsloader.shareGlobal set to
> true.

Yes, from your last profile, it looks like that should help considerably. Can you try flipping that pref and capturing a new profile?
(In reply to Kris Maglione [:kmag] (long backlog; ping on IRC if you're blocked) from comment #25)
> Yes, from your last profile, it looks like that should help considerably.
> Can you try flipping that pref and capturing a new profile?

I've set jsloader.shareGlobal set to true, cleared cache and used STR from comment 23. No difference, same frequent drops of scrolling fps. The first profile I recorded is one big jankfest - it's over 60 seconds long but there are constant fps drops all the time except for small ~20 second interval somewhere in the middle. 
Link: https://perfht.ml/2h72lHX

I tried to record the second profile - it's not as long as the first one but there are frequent fps drops as well. Also, I would like to pay your attention to the second half of this profile: scrolling fps drops were still present despite very low CPU usage in the second half(around 10-20% according to the tray indicator).
Link: https://perfht.ml/2h8qjm2
(In reply to ajfhajf from comment #26)
> (In reply to Kris Maglione [:kmag] (long backlog; ping on IRC if you're
> blocked) from comment #25)
> > Yes, from your last profile, it looks like that should help considerably.
> > Can you try flipping that pref and capturing a new profile?
> 
> I've set jsloader.shareGlobal set to true, cleared cache and used STR from
> comment 23. No difference, same frequent drops of scrolling fps. The first
> profile I recorded is one big jankfest - it's over 60 seconds long but there
> are constant fps drops all the time except for small ~20 second interval
> somewhere in the middle. 
> Link: https://perfht.ml/2h72lHX

This profile looks quite good, in terms of WebRequest overhead. There are still a couple of areas that could use some work (mainly XPC overhead in maybeError and StartStopListener), but nothing especially concerning.

In one content process, there's a bit of overhead from remote WebProgress, RemoteAddonsChild, SessionStore, and telemetry. But, again, nothing especially concerning.

It is possible that the WebRequest operations in the main process happen in big enough chunks to decrease responsiveness. It's also possible that the additional request processing lag affects the image loader or layout code in some way that leads to decreased frame rates.

We can look at those possibilities in a follow-up bug, but from this profile, it looks like the WebRequest.jsm overhead portion of the problem is mostly fixed.

> I tried to record the second profile - it's not as long as the first one but
> there are frequent fps drops as well. Also, I would like to pay your
> attention to the second half of this profile: scrolling fps drops were still
> present despite very low CPU usage in the second half(around 10-20%
> according to the tray indicator).
> Link: https://perfht.ml/2h8qjm2

This profile, unfortunately, fails to load...
(In reply to Kris Maglione [:kmag] (long backlog; ping on IRC if you're blocked) from comment #27)
> We can look at those possibilities in a follow-up bug, but from this
> profile, it looks like the WebRequest.jsm overhead portion of the problem is
> mostly fixed.
Thank you very much! The follow-up bug means it will be listed in "Depends on" graph? I would like to keep track of all bugs that might improve performance when using my STR.

> This profile, unfortunately, fails to load...
My bad, I closed the browser before the profile was uploaded. Here is a new one: https://perfht.ml/2h8HjIX
Scrolling fps drops multiple times not long before the end of the profile when CPU utilization is ~20%.
(In reply to ajfhajf from comment #28)
> Thank you very much! The follow-up bug means it will be listed in "Depends
> on" graph? I would like to keep track of all bugs that might improve
> performance when using my STR.

Correct. If you could file one, that would help.

> > This profile, unfortunately, fails to load...
> My bad, I closed the browser before the profile was uploaded. Here is a new
> one: https://perfht.ml/2h8HjIX
> Scrolling fps drops multiple times not long before the end of the profile
> when CPU utilization is ~20%.

Ah. This is closer to your other profiles, but at least with a lot of the proxy overhead gone.

In the follow-up bug, can you provide more detailed steps to reproduce, including the exact pages you loaded. And instructions, preferably with screenshots, on how to configure uMatrix? I couldn't make head or tail of its user interface, so I just went with the first configuration that seemed to generate a bunch of WebRequest overhead and worked based on that.
(In reply to Kris Maglione [:kmag] (long backlog; ping on IRC if you're blocked) from comment #29)
> Correct. If you could file one, that would help.
OK but English is not my first language so there are might be grammatical mistakes. I will post a link to the bug in this thread once I file it.

>In the follow-up bug, can you provide more detailed steps to reproduce, including the exact pages you loaded. And instructions, preferably with screenshots, on how to configure uMatrix?
Yes, of course. STR is very simple, I load just one page, the problem is that the site I used for STR is NSFW. To say honestly, I don't even know if it doesn't contain malware or spyware or some unknown 0-day exploit. I tried to find an alternative to no avail. Since the site is NSFW and might damage computer or user data, I'll post a link to it in pastebin. Is that ok?
(In reply to ajfhajf from comment #30)
> >In the follow-up bug, can you provide more detailed steps to reproduce, including the exact pages you loaded. And instructions, preferably with screenshots, on how to configure uMatrix?
> Yes, of course. STR is very simple, I load just one page, the problem is
> that the site I used for STR is NSFW. To say honestly, I don't even know if
> it doesn't contain malware or spyware or some unknown 0-day exploit. I tried
> to find an alternative to no avail. Since the site is NSFW and might damage
> computer or user data, I'll post a link to it in pastebin. Is that ok?

Yes, if it's that difficult to find a site that produces the same problem, that would definitely be helpful.
(In reply to Kris Maglione [:kmag] (long backlog; ping on IRC if you're blocked) from comment #31)
> Yes, if it's that difficult to find a site that produces the same problem,
> that would definitely be helpful.

I filed a bug: https://bugzilla.mozilla.org/show_bug.cgi?id=1400534
See Also: → 1400534
Is manual testing required on this bug? If Yes, please provide some STR and the proper webextension(if required), if No set the “qe-verify-“ flag.
Flags: needinfo?(kmaglione+bmo)
Flags: needinfo?(kmaglione+bmo) → qe-verify-
Product: Toolkit → WebExtensions
Performance Impact: --- → ?
Whiteboard: [qf]
You need to log in before you can comment on or make changes to this bug.