Telemetry to measure checkerboarding

RESOLVED FIXED in Firefox 12

Status

()

defect
P3
normal
RESOLVED FIXED
8 years ago
7 years ago

People

(Reporter: blassey, Assigned: cwiiis)

Tracking

unspecified
Firefox 13
ARM
Android
Points:
---

Firefox Tracking Flags

(firefox11 affected, firefox12 fixed, firefox13 fixed, fennec+)

Details

(Whiteboard: [telemetry-needed])

Attachments

(3 attachments, 2 obsolete attachments)

I really thought there was already a bug filed for this. Hopefully there is and someone on this CC bomb will dupe this one.

We want to be able to measure checkerboarding both in the wild and in our test infrastructure.
One thing I would love to measure is "how much retained layers would help". That is, when we're checkerboarding, how much of the previous page was displayed and how much we drew. I'd like to write the code for this soon.
Assignee: nobody → cpeterson
tracking-fennec: --- → +
Priority: -- → P3
Assignee

Comment 2

8 years ago
Sorry, I didn't realise this was assigned already and needed it for another patch I want to write.

The attached patch measures how much checkerboarding is going on, and any frame that has checkerboarding, it outputs, as a percentage, how much of the screen is checkerboarding.

This should probably be reported more nicely, and depend on a SharedPreference - could do with ideas/feedback.
Attachment #591424 - Flags: feedback?(pwalton)
Attachment #591424 - Flags: feedback?(cpeterson)
Attachment #591424 - Flags: feedback?(bugmail.mozilla)
Assignee: cpeterson → chrislord.net
Comment on attachment 591424 [details] [diff] [review]
Measure how much checkerboarding is happening

If you think the checkerboard region would be expensive to calculate on every onDrawFrame() on release builds, you could guard that code path with android.util.Log.isLoggable(DEBUG). isLoggable() itself is not cheap, so you would probably want to query and cache the isLoggable(DEBUG) value on start.
Attachment #591424 - Flags: feedback?(cpeterson) → feedback+
Comment on attachment 591424 [details] [diff] [review]
Measure how much checkerboarding is happening

Review of attachment 591424 [details] [diff] [review]:
-----------------------------------------------------------------

Overall looks fine. r+ with comments addressed

::: mobile/android/base/gfx/LayerRenderer.java
@@ +233,5 @@
> +            if (rootLayer != null) {
> +                Rect viewport = RectUtils.roundOut(pageContext.viewport);
> +                Region validRegion = rootLayer.getValidRegion(pageContext);
> +                validRegion.op(viewport, Region.Op.INTERSECT);
> +                if (!validRegion.isRect() || !validRegion.getBounds().equals(viewport)) {

This condition is hard to read. I'd prefer factoring out the negation:
if (! (validRegion.isRect() && validRegion.getBounds().equals(viewport)) {

@@ +240,5 @@
> +                    Rect r = new Rect();
> +                    int checkerboardArea = 0;
> +                    for (RegionIterator i = new RegionIterator(validRegion); i.next(r);) {
> +                        checkerboardArea += r.width() * r.height();
> +                    }

This assumes the rects that you get from the region are non-overlapping. Do you know if that will always be the case? If that's not enforced by the Region class (and I didn't see that anywhere in Region javadoc) then a comment here stating the assumption would be good in case the getValidRegion() code changes.

::: mobile/android/base/gfx/TileLayer.java
@@ +163,5 @@
> +        float width = mValidTextureRect.width() * scaleFactor;
> +        float height = mValidTextureRect.height() * scaleFactor;
> +
> +        RectF validRect = new RectF(x, y, x + width, y + height);
> +        return new Region(RectUtils.roundOut(validRect));

I think you should either (A) not multiply the individual components by the scaleFactor and use RectUtils.scale, or (B) also round the individual components and not use roundOut. It seems inconsistent to do half of the operations here and use RectUtils for the other half.
Attachment #591424 - Flags: feedback?(bugmail.mozilla) → feedback+
Err I meant f+, not r+.
Assignee

Comment 6

8 years ago
(In reply to Chris Peterson (:cpeterson) from comment #3)
> Comment on attachment 591424 [details] [diff] [review]
> Measure how much checkerboarding is happening
> 
> If you think the checkerboard region would be expensive to calculate on
> every onDrawFrame() on release builds, you could guard that code path with
> android.util.Log.isLoggable(DEBUG). isLoggable() itself is not cheap, so you
> would probably want to query and cache the isLoggable(DEBUG) value on start.

Good idea - though it shouldn't be expensive, and we may want to use the metric to control other features... Until those features exist though, I'll add this, thanks!

(In reply to Kartikaya Gupta (:kats) from comment #4)
> Comment on attachment 591424 [details] [diff] [review]
> Measure how much checkerboarding is happening
> 
> Review of attachment 591424 [details] [diff] [review]:
> -----------------------------------------------------------------
> 
> Overall looks fine. r+ with comments addressed
> 
> ::: mobile/android/base/gfx/LayerRenderer.java
> @@ +233,5 @@
> > +            if (rootLayer != null) {
> > +                Rect viewport = RectUtils.roundOut(pageContext.viewport);
> > +                Region validRegion = rootLayer.getValidRegion(pageContext);
> > +                validRegion.op(viewport, Region.Op.INTERSECT);
> > +                if (!validRegion.isRect() || !validRegion.getBounds().equals(viewport)) {
> 
> This condition is hard to read. I'd prefer factoring out the negation:
> if (! (validRegion.isRect() && validRegion.getBounds().equals(viewport)) {

Agreed.

> @@ +240,5 @@
> > +                    Rect r = new Rect();
> > +                    int checkerboardArea = 0;
> > +                    for (RegionIterator i = new RegionIterator(validRegion); i.next(r);) {
> > +                        checkerboardArea += r.width() * r.height();
> > +                    }
> 
> This assumes the rects that you get from the region are non-overlapping. Do
> you know if that will always be the case? If that's not enforced by the
> Region class (and I didn't see that anywhere in Region javadoc) then a
> comment here stating the assumption would be good in case the
> getValidRegion() code changes.

I had to read the source-code to find out, but this assumption is correct. Region is a thin wrapper over SkRegion, which is a pretty complicated and fast Region implementation that works with spans (and thus guarantees non-overlapping). That said, you're right that this ought to be documented, will do so.

> ::: mobile/android/base/gfx/TileLayer.java
> @@ +163,5 @@
> > +        float width = mValidTextureRect.width() * scaleFactor;
> > +        float height = mValidTextureRect.height() * scaleFactor;
> > +
> > +        RectF validRect = new RectF(x, y, x + width, y + height);
> > +        return new Region(RectUtils.roundOut(validRect));
> 
> I think you should either (A) not multiply the individual components by the
> scaleFactor and use RectUtils.scale, or (B) also round the individual
> components and not use roundOut. It seems inconsistent to do half of the
> operations here and use RectUtils for the other half.

Agreed here too.
Status: NEW → ASSIGNED
So I assume this is mostly a proof of concept. Some thoughts from the perspective of using this to test checkerboarding for automation:

* To really measure how often/much this is checkerboarding, we need timestamps associated with the checkerboarding percentages so we know when checkerboarding starts/ends
* For talos, I'm thinking it would be useful if this variable were accessible via browser chrome somehow so we could write this out to the file log we use via the pageloader extension (http://hg.mozilla.org/build/pageloader/file/beca399c3a16/chrome/MozillaFileLogger.js). We don't currently have code to parse the adb log in devicemanager. jmaher can probably give guidance on this (or tell us if I'm way off base). ;)

BTW, this latter comment applies to any other performance metrics we want to measure in automation. We could certainly try to just parse out the adb log, but I think it'd be much easier just to add some hooks into browser chrome.
> > If you think the checkerboard region would be expensive to calculate on
> > every onDrawFrame() on release builds, you could guard that code path with
> > android.util.Log.isLoggable(DEBUG). isLoggable() itself is not cheap, so you
> > would probably want to query and cache the isLoggable(DEBUG) value on start.
> 
> Good idea - though it shouldn't be expensive, and we may want to use the metric to 
> control other features... Until those features exist though, I'll add this, thanks!

Log.isLoggable() is more expensive than it seems. It calls out to JNI, mallocs some strings, and does an O(n) search of system properties flags. We probably don't want to do that on every frame! :)

https://github.com/android/platform_frameworks_base/blob/master/core/jni/android_util_Log.cpp#L59

Adding a global LOGD flag that is initialized on launch might be nice (for another day).
Assignee

Comment 9

8 years ago
(In reply to Chris Peterson (:cpeterson) from comment #8)
> > > If you think the checkerboard region would be expensive to calculate on
> > > every onDrawFrame() on release builds, you could guard that code path with
> > > android.util.Log.isLoggable(DEBUG). isLoggable() itself is not cheap, so you
> > > would probably want to query and cache the isLoggable(DEBUG) value on start.
> > 
> > Good idea - though it shouldn't be expensive, and we may want to use the metric to 
> > control other features... Until those features exist though, I'll add this, thanks!
> 
> Log.isLoggable() is more expensive than it seems. It calls out to JNI,
> mallocs some strings, and does an O(n) search of system properties flags. We
> probably don't want to do that on every frame! :)

When I was saying "it shouldn't be expensive", I meant the checkerboard measuring rather than Log.isLoggable() :) We already check the FPS meter pref in a thread, we can stick isLoggable in there if need be.
Assignee

Comment 10

8 years ago
(In reply to William Lachance (:wlach) from comment #7)
> So I assume this is mostly a proof of concept. Some thoughts from the
> perspective of using this to test checkerboarding for automation:
> 
> * To really measure how often/much this is checkerboarding, we need
> timestamps associated with the checkerboarding percentages so we know when
> checkerboarding starts/ends

Right now it just outputs on every frame that checkerboarded how much it checkerboarded - I'm not sure start/end really makes sense for this, any measurements ought to be frame-based.

Perhaps this should be part of a frame-rendering measurement that outputs on *every* frame - you could derive better information from that, rather than basing things on time.

> * For talos, I'm thinking it would be useful if this variable were
> accessible via browser chrome somehow so we could write this out to the file
> log we use via the pageloader extension
> (http://hg.mozilla.org/build/pageloader/file/beca399c3a16/chrome/
> MozillaFileLogger.js). We don't currently have code to parse the adb log in
> devicemanager. jmaher can probably give guidance on this (or tell us if I'm
> way off base). ;)

How would this work? This information is purely on the Java side, sending it back to browser.js would be expensive. In a best-case scenario, these messages would be generated at 60fps, but Gecko will be busy rendering the page - we could send it in back in batches I suppose, but it seems like a lot of trouble. Suggestions?

> BTW, this latter comment applies to any other performance metrics we want to
> measure in automation. We could certainly try to just parse out the adb log,
> but I think it'd be much easier just to add some hooks into browser chrome.

Given the concurrency/storage/performance issues related to sending things from Java back to Gecko, it makes a lot more sense to me to have this information read from logcat, or written to wherever it needs to be written to from Java. Sending messages back from Java to Gecko at high frequency is likely to be a considerable performance hit, as well as perhaps being unreliable.
Assignee

Comment 11

8 years ago
This patch adds metrics for checkerboarding (and addresses previous feedback comments).

There are two ways of enabling it,

1- Setting log.tag.GeckoLayerRendererProf to DEBUG via adb or /data/local.prop
2- Using PanningPerfAPI via reflection

Both ways will cause an output message on logcat that will get printed at a frequency of ~every second (depending on whether rendering is happening), showing how many of the last few frames were complete (as in rendered without checkerboard).

Handy for debugging, and this should enable a possible Talos test for checkerboarding.
Attachment #591424 - Attachment is obsolete: true
Attachment #591424 - Flags: feedback?(pwalton)
Attachment #593451 - Flags: review?(bugmail.mozilla)
Comment on attachment 593451 [details] [diff] [review]
Add metrics for checkerboarding

Review of attachment 593451 [details] [diff] [review]:
-----------------------------------------------------------------

Looks good. r+ with the one change below.

::: mobile/android/base/gfx/PanningPerfAPI.java
@@ +55,5 @@
>      private static List<Long> mFrameTimes;
> +    private static long mFrameStartTime;
> +
> +    private static boolean mRecordingCheckerboard = false;
> +    private static List<Float> mCheckerboardTimes;

s/mCheckerboardTimes/mCheckerboardAmounts/
Attachment #593451 - Flags: review?(bugmail.mozilla) → review+
Assignee

Comment 13

8 years ago
Review comment addressed, carrying over r+.
Attachment #593451 - Attachment is obsolete: true
Attachment #593517 - Flags: review+
Assignee

Comment 14

8 years ago
Add Robotium functions for testing checkerboarding, similar to those that allow for testing panning.
Attachment #593520 - Flags: review?(jmaher)
Comment on attachment 593520 [details] [diff] [review]
Add support to Robotium for testing checkerboarding

Review of attachment 593520 [details] [diff] [review]:
-----------------------------------------------------------------

this looks too easy, but simple!
Attachment #593520 - Flags: review?(jmaher) → review+
Comment on attachment 593521 [details] [diff] [review]
Adapt the Robotium panning test to test checkerboarding

Review of attachment 593521 [details] [diff] [review]:
-----------------------------------------------------------------

great!  I can clean this up as needed as we get testPan turned on inside the talos framework.
Attachment #593521 - Flags: review?(jmaher) → review+
Comment on attachment 593521 [details] [diff] [review]
Adapt the Robotium panning test to test checkerboarding

Review of attachment 593521 [details] [diff] [review]:
-----------------------------------------------------------------

I think you are just modifying testPan.java.in, not creating a new testCheck.java.in.  Was this intended?
Assignee

Comment 19

8 years ago
(In reply to Joel Maher (:jmaher) from comment #18)
> Comment on attachment 593521 [details] [diff] [review]
> Adapt the Robotium panning test to test checkerboarding
> 
> Review of attachment 593521 [details] [diff] [review]:
> -----------------------------------------------------------------
> 
> I think you are just modifying testPan.java.in, not creating a new
> testCheck.java.in.  Was this intended?

This is just splinter messing up - if you look at the raw patch, you can see this isn't the case.
Comment on attachment 593517 [details] [diff] [review]
Add metrics for checkerboarding

[Approval Request Comment]
I had to move this patch to aurora for other dependencies

Do not land the test patches
Attachment #593517 - Flags: approval-mozilla-beta+
Attachment #593517 - Flags: approval-mozilla-aurora+
(In reply to Brad Lassey [:blassey] from comment #25)
> pushed to beta https://hg.mozilla.org/releases/mozilla-beta/rev/19d0e027d6fc
> and backed out https://hg.mozilla.org/releases/mozilla-beta/rev/ce224666955c

Whats the status here, shall we still plan on a landing on beta, or is it inherently a-?
Comment on attachment 593517 [details] [diff] [review]
Add metrics for checkerboarding

Clearing approval for Aurora 12 and Beta 11 because we are not currently planning a Native Fennec release of these versions.  If this changes in the future, we will likely do a mass uplift of all native fennec changes.  For now, let's get these bugs off the channel triage radar.

[Filter on the string "mbrubeck-bugspam" if you want to delete all of these emails at once.]
Attachment #593517 - Flags: approval-mozilla-beta+
Attachment #593517 - Flags: approval-mozilla-aurora+
Whiteboard: [telemetry-needed]
You need to log in before you can comment on or make changes to this bug.