937375 - [1.2] Regression in SMS App Scroll FPS (compared to an earlier 1.2 build)

Status: RESOLVED WORKSFORME

(Firefox OS Graveyard :: Gaia::SMS, defect, P1)

Description

[Mandyam Vikram]

While measuring FPS on the following build with a high speed camera, it was measured to be 48 fps. 

Gecko:
 964f7c844f2793092bab72612d5da2f5bcfd6c2e
Gaia:
 be4ea00a50236b10eb0a03232a28ffd0048e0cb8

On the earlier build,the FPS was measured to be on par with v1.1 (as a result, bug 915123 was closed):
Gaia version: 
845801e0c74badf0b96657a864935ef1a983cf47
Gecko version:
bbb4c0a8fa65cf1546a6cedc4c20fea16cd63ef

Comment 1

[Julien Wajsberg [:julienw]]

As I understand from bug 937350, this is probably more a Gecko issue than a Gaia issue.

Unless this is a Building Blocks issue...

Comment 2

[Mandyam Vikram]

On profiling this build during SMS Scroll, these are my observations:
- frames are taking about 22-24 ms to render 
- Compositor rendering (CompositorOGL->BeginFrame/CompositorOGL->EndFrame) or (LayerManagerComposite::Render) is taking about 8-10 ms

Will attach screenshot

Comment 3

[Mandyam Vikram]

Attachment: sms.jpg

Comment 4

[Mandyam Vikram]

The scroll fps measured on the following build was 54 fps:
Gecko:
d5ccbecb3abd3c760dcef7b5f7195cbeea667cc1
Gaia:
2ef9bc3c7a6de228b63e6ba3613eb0c0dd639c59

Comment 5

[Mason Chang [Inactive] [:mchang]]

Here are some profiles:

Good Revision - http://people.mozilla.org/~bgirard/cleopatra/#report=c16c71123f3d8a1543d0f431544b5942a1c86c6e

Bad Revision - http://people.mozilla.org/~bgirard/cleopatra/#report=d90fc9da8c07b6e07ea41a24f2fee4518007ad2e

I'm not particularly seeing lots of reflows, still needs more investigation.

Comment 6

[Mason Chang [Inactive] [:mchang]]

Just to clarify:

Gaia: 2ef9bc3c7a6de228b63e6ba3613eb0c0dd639c59
Gecko: d5ccbecb3abd3c760dcef7b5f7195cbeea667cc1
Good Revision - http://people.mozilla.org/~bgirard/cleopatra/#report=c16c71123f3d8a1543d0f431544b5942a1c86c6e

Gaia: be4ea00a50236b10eb0a03232a28ffd0048e0cb8
Gecko: 964f7c844f2793092bab72612d5da2f5bcfd6c2e
Bad Revision - http://people.mozilla.org/~bgirard/cleopatra/#report=d90fc9da8c07b6e07ea41a24f2fee4518007ad2e

Comment 7

[Mason Chang [Inactive] [:mchang]]

Attachment: Bad Revision - Compositing

Bad Synced Frames - http://people.mozilla.org/~bgirard/cleopatra/#report=f888783332477f484ef637e86b8ed8e750d619b7
Good Asynced Frames - http://people.mozilla.org/~bgirard/cleopatra/#report=d337105814c002b17f4b3955d377f7f7126ea641

Looks like a systemic issue that's related to async compositing, bug 936535.

Comment 8

[Mason Chang [Inactive] [:mchang]]

Attachment: Good Revision - Compositing

Comment 9

[Mandyam Vikram]

New measurements on the following build using a high speed camera show a result of 51 fps:
Gecko:
8926376583fdd3711aaf75594fd4084306c5f02a
Gaia:
3cc5e6ddec0656b3a6a197e989dabebee536c982

Comment 10

[Mason Chang [Inactive] [:mchang]]

Spoke with Benwa and Bkelly, it's a difficult bug to measure because we don't have high speed cameras. It also seems to come and go even during our bisection as stated in bug 936535. I looked at the changeset between bad gecko 964f7c844f2793092bab72612d5da2f5bcfd6c2e and good gecko bbb4c0a8fa65cf1546a6cedc4c20fea16cd63ef. I noticed a changeset in a smaller Skia cache and a change in sGfxScrollFrameInner::BuildDisplayList, both of which BenWa shouldn't have changed the FPS. Investigating how we actually do layout to see if something stands out.

Comment 11

[Mandyam Vikram]

Can Eideticker be used at least to track relative measurements (I understand that it not working on a more representative device).

Comment 12

[Mason Chang [Inactive] [:mchang]]

Automation is working on using Eideticker to track Gaia apps, but at the moment the numbers are unreliable.

I also tried using enabling COMPOSITOR_PERFORMANCE_WARNING, and saw a few Composites taking 30-50ms every couple of seconds while scrolling. After discussion with Benwa, this should be ok. I don't see any big divergences in the messages app either, and not a large amount of reflows other than the expected reflow when we hit a new message date. 

Vikram: Are you scrolling the messages list or a specific single message? I'm noticing lots of painting if I show a single message. I'm using the gaia reference-workload-medium

Comment 13

[Mason Chang [Inactive] [:mchang]]

Attachment: fpsLog.patch

Patch that prints the FPS counter logic from the "Show FPS" option into adb logcat rather than on screen.

Comment 14

[Mason Chang [Inactive] [:mchang]]

Attachment: fpsLog.txt

Log showing Compositor calculated FPS with the good / bad gecko revision, both using the good gaia revision, running the messages app with the reference workload-medium, a single scroll from the top down. 

Shows that the good gecko has roughly a higher FPS, with the average FPS being 51 FPS, and the slower FPS roughly 49 FPS, which is roughly in line with Vikram's measurements (48 FPS on bad gecko, 52 FPS with good Gecko, and 51 in Comment 9)

Comment 15

[Mason Chang [Inactive] [:mchang]]

Been digging through the compositor FPS, and essentially after a certain amount of time and everything is in the cache, we get a consistent 55+ FPS in the compositor. I'm going to start looking at Ben Kelly's idea of seeing a timeline of FPS and see how the FPS slowdown occurs during loading. But after reference-workload-medium has been loaded, FPS plateaus.

Comment 16

[Mason Chang [Inactive] [:mchang]]

I rummaged the SMS workload from Vikram in https://bugzilla.mozilla.org/show_bug.cgi?id=915088#c4. Using the two geckos, I found that the bad gecko revision actually has higher FPS. It has an average mean of 48.02867384 FPS whereas the "good" gecko revision has 47.3794 mean FPS. Geomeans are closer respectively, with Good (46.24023383) and Bad (46.64150724). I'm going to try using a histogram and see if we get something cleaner. 

Vikram, can you please detail how you measure SMS App Scroll FPS and if the workload in https://bugzilla.mozilla.org/show_bug.cgi?id=915088#c4 is still valid?

Thanks!

Comment 17

[Alex Keybl [:akeybl]]

Can somebody please update the title of this bug to reflect the number of frames per second we need to gain back? My read is that 1.1 was 52 FPS (https://bugzilla.mozilla.org/show_bug.cgi?id=915123#c5), so based on some of these comments (comment 9 for instance) we're only off by a couple.

We need good perf data and hard targets at this point. Too close to release to have an amorphous goal.

Comment 18

[Mason Chang [Inactive] [:mchang]]

Running the SMS workload in https://bugzilla.mozilla.org/show_bug.cgi?id=915088#c4, I could find no discernible difference between the Good Gecko Revision - d5ccbecb3abd3c760dcef7b5f7195cbeea667cc1, and the bad Gecko Revision - 964f7c844f2793092bab72612d5da2f5bcfd6c2e. I gathered the Compositor FPS data for 5000 samples and got the following numbers:

Bad Gecko (200 Frames means the FPS average after we've called CompositrOGL::DrawFPS 200 times)
200: 54.958 average, w/ 7.04 frames std deviation.
400: 53.84 FPS, w/ 6.3176 std deviation.
800: 54.302 FPS w/ 6.5578 std deviation.
5000: 51.177 FPS w/ 7.134 std deviation.

Good Gecko:
200: 51.729 FPS w/ 7.535 std deviation
400: 52.153 FPS w/ 6.994 std deviation
800: 51.588 FPS w/ 7.044 std deviation
5000: 51.607 FPS w/ 7.194 std deviation

What we see is that initially, there is a dip in FPS as the app loads the SMS message, but both the good and bad revisions are within the targeted 51 FPS average. What is surprising is that the "bad" revision is actually performing better. In addition, the regression is within the standard deviation, so the regression could be noise. Finally, as we continue scrolling through the SMS app, we see both gecko revisions converge to ~51 FPS with ~7 frame std deviation. 

Unless we can get a better idea how we're measuring the regression, at the moment, it seems unreproducible.

Comment 19

[Mason Chang [Inactive] [:mchang]]

Based on Comment 2, instrumented CompositorOGL::BeginFrame -> CompositorOGL::EndFrame:

Good Gecko: 8.8269 ms average time, w/ 2.44204 std deviation
Bad Gecko: 8.78052 ms average time w/ 2.0445 ms std deviation.

Comment 20

[Mason Chang [Inactive] [:mchang]]

Vikram, based on Comment #60 on Bug 936535 and our phone call, can we close this bug?

Comment 21

[Mandyam Vikram]

On the following build, using measurements on a high speed camera, the scroll latency was measured as 52 fps:
Gecko:
14432474328e7558902329c3fc2a8238c3222a7f
Gaia:
7a23f8c53ba97da9c63a7275b36d155b4526a639

We saw results of 54 fps on earlier builds. This seems close enough for now.

We'll continue to monitor it.