1366960 - [Input Latency] Firefox is 76% (172 ms) slower than Chrome in case Facebook - click to open chat tab

Status: RESOLVED WORKSFORME

(Core :: General, defect)

Comment 1

[Olli Pettay [:smaug][[e-mail]]]

(Commenting on User Story)
> STR:
> 0. Login with Facebook White Hat account.
> 1. Click on a name in the chat panel on the right side.
> 2. Wait for the chat window to open.
> 
> Gecko Profiles:
> 1: https://perfht.ml/2pVkRFD
This doesn't seem to be too useful. Child process is just waiting for input.

> 2: https://perfht.ml/2pV9GwT
Here the time is really spent in JS


> 3: https://perfht.ml/2pV2WPm
And this too, though there is also once-only slow localization related call to load properties data.

Comment 2

[Olli Pettay [:smaug][[e-mail]]]

Based on the two latter profiles, most of the time is JS. There is also some graphics, but I think that is expected, we need to render the chat.

It is a bit unclear from the profile what is the start and end points.
And there is a long gap between two busy times and nothing is happening at that time.
Talking about the time 21s-24s.
Bobby, could you perhaps clarify what is being tested.

Comment 3

[Olli Pettay [:smaug][[e-mail]]]

Filed bug 1367878, since I'm not sure if there are qf bugs about regexp performance.

Comment 4

[Bobby Chien]

(In reply to Olli Pettay [:smaug] from comment #2)
> Based on the two latter profiles, most of the time is JS. There is also some
> graphics, but I think that is expected, we need to render the chat.
> 
> It is a bit unclear from the profile what is the start and end points.
> And there is a long gap between two busy times and nothing is happening at
> that time.
> Talking about the time 21s-24s.
> Bobby, could you perhaps clarify what is being tested.

Mike, could you help to clarify Olli's question? Thanks.

Comment 5

[Mike Lien[:mlien]]

(In reply to Bobby Chien [:bchien] from comment #4)
> (In reply to Olli Pettay [:smaug] from comment #2)
> > Based on the two latter profiles, most of the time is JS. There is also some
> > graphics, but I think that is expected, we need to render the chat.
> > 
> > It is a bit unclear from the profile what is the start and end points.
> > And there is a long gap between two busy times and nothing is happening at
> > that time.
> > Talking about the time 21s-24s.
> > Bobby, could you perhaps clarify what is being tested.
> 
> Mike, could you help to clarify Olli's question? Thanks.

The detailed steps are as below
1. Typing url into url bar and link to Facebook homepage (Whitehat account is already logged in)
2. Wait homepage loaded finished
3. Mouse click friend's name from right side panel to open chat tab
4. Wait chat tab show up

From these steps, the long gap is between homepage loaded and chat tab show up

Comment 6

[Kan-Ru Chen [:kanru] (UTC+9)]

(In reply to Mike Lien[:mlien] from comment #5)
> (In reply to Bobby Chien [:bchien] from comment #4)
> > (In reply to Olli Pettay [:smaug] from comment #2)
> > > Based on the two latter profiles, most of the time is JS. There is also some
> > > graphics, but I think that is expected, we need to render the chat.
> > > 
> > > It is a bit unclear from the profile what is the start and end points.
> > > And there is a long gap between two busy times and nothing is happening at
> > > that time.
> > > Talking about the time 21s-24s.
> > > Bobby, could you perhaps clarify what is being tested.
> > 
> > Mike, could you help to clarify Olli's question? Thanks.
> 
> The detailed steps are as below
> 1. Typing url into url bar and link to Facebook homepage (Whitehat account
> is already logged in)
> 2. Wait homepage loaded finished
> 3. Mouse click friend's name from right side panel to open chat tab
> 4. Wait chat tab show up
> 
> From these steps, the long gap is between homepage loaded and chat tab show
> up

If I remember correctly the input latency case does not include the time to load the page right?

Would it be possible to only profile the input case?

Comment 7

[Mike Lien[:mlien]]

(In reply to Kan-Ru Chen [:kanru] (UTC+8) from comment #6)
> (In reply to Mike Lien[:mlien] from comment #5)
> > (In reply to Bobby Chien [:bchien] from comment #4)
> > > (In reply to Olli Pettay [:smaug] from comment #2)
> > > > Based on the two latter profiles, most of the time is JS. There is also some
> > > > graphics, but I think that is expected, we need to render the chat.
> > > > 
> > > > It is a bit unclear from the profile what is the start and end points.
> > > > And there is a long gap between two busy times and nothing is happening at
> > > > that time.
> > > > Talking about the time 21s-24s.
> > > > Bobby, could you perhaps clarify what is being tested.
> > > 
> > > Mike, could you help to clarify Olli's question? Thanks.
> > 
> > The detailed steps are as below
> > 1. Typing url into url bar and link to Facebook homepage (Whitehat account
> > is already logged in)
> > 2. Wait homepage loaded finished
> > 3. Mouse click friend's name from right side panel to open chat tab
> > 4. Wait chat tab show up
> > 
> > From these steps, the long gap is between homepage loaded and chat tab show
> > up
> 
> If I remember correctly the input latency case does not include the time to
> load the page right?
> 
> Would it be possible to only profile the input case?

Below is the profile start before clicking friend's name in right panel until chat tab show up
https://perfht.ml/2ra8Yjb

Comment 8

[Mike Lien[:mlien]]

Hi Olli, do you think the profile from action of input latency is much useful than whole original (from open page until click action completed)?

Comment 9

[Olli Pettay [:smaug][[e-mail]]]

Bug 1349255 at least shows up, and bug 1331680.

Also some once-per-child-process initialization related to spellchecker.

GC is also running, but nothing unusual there, and some style and layout flushes.
Stylo will hopefully help with style flushes.

Comment 10

[Ting-Yu Chou [:ting] (away)]

(In reply to Mike Lien[:mlien] from comment #7)
> Below is the profile start before clicking friend's name in right panel
> until chat tab show up
> https://perfht.ml/2ra8Yjb

I saw 44ms in mozInlineSpellChecker::DoSpellCheck and 70ms in js::irregexp::NativeRegExpMacroAssembler::BindBacktrack.

:smaug has filed bug 1367878 for the regexp one. He also mentioned spellchecker intialization in comment 9, but it doesn't seem like the DoSpellCheck which does real check. Per comment 7, the STR doesn't input anything, why is there a DoSpellCheck call?

:mlien, where can I find the latest profile? I assume Hasal keeps test result history and profiles.

Comment 11

[Mike Lien[:mlien]]

Ting, unfortunately we don't regularly generate profile from hasal test. Although hasal supports to generate profile automatically but all profiles here are generated manually.

Comment 12

[Kan-Ru Chen [:kanru] (UTC+9)]

(In reply to Ting-Yu Chou [:ting] from comment #10)
> (In reply to Mike Lien[:mlien] from comment #7)
> > Below is the profile start before clicking friend's name in right panel
> > until chat tab show up
> > https://perfht.ml/2ra8Yjb
> 
> I saw 44ms in mozInlineSpellChecker::DoSpellCheck and 70ms in
> js::irregexp::NativeRegExpMacroAssembler::BindBacktrack.
> 
> :smaug has filed bug 1367878 for the regexp one. He also mentioned
> spellchecker intialization in comment 9, but it doesn't seem like the
> DoSpellCheck which does real check. Per comment 7, the STR doesn't input
> anything, why is there a DoSpellCheck call?
> 
> :mlien, where can I find the latest profile? I assume Hasal keeps test
> result history and profiles.

Because spellcheck is triggered automatically when there is a new input field focused. And the old spellchecker does dumb things checking non-editable nodes. It should be gone after bug 1362858 was fixed.

Comment 13

[Mike Lien[:mlien]]

(In reply to Mike Lien[:mlien] from comment #11)
> Ting, unfortunately we don't regularly generate profile from hasal test.
> Although hasal supports to generate profile automatically but all profiles
> here are generated manually.

Here is the history data from perfherder for your reference.

Comment 14

[Mike Lien[:mlien]]

Sorry for missing url.

Here is the history data from perfherder for your reference.
https://treeherder.mozilla.org/perf.html#/graphs?series=%5Bmozilla-central,7b287bc993dcd5a2a9e8d2d369740dd1c88fef25,1,9%5D&series=%5Bmozilla-central,85b7300002195cbb74be4117ddb4fdb5434749d5,1,9%5D

Comment 15

[Ting-Yu Chou [:ting] (away)]

(In reply to Kan-Ru Chen [:kanru] (UTC+8) from comment #12)
> Because spellcheck is triggered automatically when there is a new input
> field focused. And the old spellchecker does dumb things checking
> non-editable nodes. It should be gone after bug 1362858 was fixed.

Yeah, I don't see it from the profile I just captured on Nightly 20170710100245. But it's odd that Hasal [1] doesn't show a drop after bug 1362858 landed...

Where can I find the test code?

[1] https://treeherder.mozilla.org/perf.html#/graphs?timerange=5184000&series=%5Bmozilla-central,85b7300002195cbb74be4117ddb4fdb5434749d5,1,9%5D&series=%5Bmozilla-central,7b287bc993dcd5a2a9e8d2d369740dd1c88fef25,0,9%5D

Comment 16

[Bobby Chien]

As latest number[1], Firefox is still behind. I think it's time to create new bug and profile data for latest firefox build.

[1] https://treeherder.mozilla.org/perf.html#/dashboard?topic=hasal&repo=mozilla-central&timerange=604800

Comment 17

[Bobby Chien]

There's a 200ms-300ms improvement; a possible fix is bug 1331680. Please refer to https://bugzilla.mozilla.org/show_bug.cgi?id=1331680#c326 for the detail.

Comment 18

[Bobby Chien]

Current result is 57.24ms (Chrome) vs 50.74ms (Firefox) on Win10. I think we could close the bug for now. Please reopen if you think something we could dig more.