Last Comment Bug 717349 - Telemetry to measure checkerboarding
: Telemetry to measure checkerboarding
Status: RESOLVED FIXED
[telemetry-needed]
:
Product: Firefox for Android
Classification: Client Software
Component: General (show other bugs)
: unspecified
: ARM Android
: P3 normal (vote)
: Firefox 13
Assigned To: Chris Lord [:cwiiis]
:
: Sebastian Kaspari (:sebastian)
Mentors:
Depends on:
Blocks:
  Show dependency treegraph
 
Reported: 2012-01-11 12:33 PST by Brad Lassey [:blassey] (use needinfo?)
Modified: 2012-02-28 11:03 PST (History)
14 users (show)
See Also:
Crash Signature:
(edit)
QA Whiteboard:
Iteration: ---
Points: ---
Has Regression Range: ---
Has STR: ---
affected
fixed
fixed
+


Attachments
Measure how much checkerboarding is happening (8.08 KB, patch)
2012-01-25 04:59 PST, Chris Lord [:cwiiis]
bugmail: feedback+
cpeterson: feedback+
Details | Diff | Splinter Review
Add metrics for checkerboarding (18.17 KB, patch)
2012-02-01 07:57 PST, Chris Lord [:cwiiis]
bugmail: review+
Details | Diff | Splinter Review
Add metrics for checkerboarding (18.19 KB, patch)
2012-02-01 10:36 PST, Chris Lord [:cwiiis]
chrislord.net: review+
Details | Diff | Splinter Review
Add support to Robotium for testing checkerboarding (4.10 KB, patch)
2012-02-01 10:44 PST, Chris Lord [:cwiiis]
jmaher: review+
Details | Diff | Splinter Review
Adapt the Robotium panning test to test checkerboarding (2.61 KB, patch)
2012-02-01 10:45 PST, Chris Lord [:cwiiis]
jmaher: review+
Details | Diff | Splinter Review

Description Brad Lassey [:blassey] (use needinfo?) 2012-01-11 12:33:16 PST
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.
Comment 1 Patrick Walton (:pcwalton) 2012-01-11 12:34:27 PST
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.
Comment 2 Chris Lord [:cwiiis] 2012-01-25 04:59:02 PST
Created attachment 591424 [details] [diff] [review]
Measure how much checkerboarding is happening

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.
Comment 3 Chris Peterson [:cpeterson] 2012-01-25 11:33:46 PST
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.
Comment 4 Kartikaya Gupta (email:kats@mozilla.com) 2012-01-25 13:26:36 PST
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.
Comment 5 Kartikaya Gupta (email:kats@mozilla.com) 2012-01-25 13:27:58 PST
Err I meant f+, not r+.
Comment 6 Chris Lord [:cwiiis] 2012-01-26 08:00:26 PST
(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.
Comment 7 William Lachance (:wlach) 2012-01-26 08:32:50 PST
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.
Comment 8 Chris Peterson [:cpeterson] 2012-01-26 10:27:52 PST
> > 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).
Comment 9 Chris Lord [:cwiiis] 2012-01-28 05:11:34 PST
(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.
Comment 10 Chris Lord [:cwiiis] 2012-01-28 05:21:46 PST
(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.
Comment 11 Chris Lord [:cwiiis] 2012-02-01 07:57:46 PST
Created attachment 593451 [details] [diff] [review]
Add metrics for checkerboarding

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.
Comment 12 Kartikaya Gupta (email:kats@mozilla.com) 2012-02-01 08:38:52 PST
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/
Comment 13 Chris Lord [:cwiiis] 2012-02-01 10:36:40 PST
Created attachment 593517 [details] [diff] [review]
Add metrics for checkerboarding

Review comment addressed, carrying over r+.
Comment 14 Chris Lord [:cwiiis] 2012-02-01 10:44:35 PST
Created attachment 593520 [details] [diff] [review]
Add support to Robotium for testing checkerboarding

Add Robotium functions for testing checkerboarding, similar to those that allow for testing panning.
Comment 15 Chris Lord [:cwiiis] 2012-02-01 10:45:37 PST
Created attachment 593521 [details] [diff] [review]
Adapt the Robotium panning test to test checkerboarding
Comment 16 Joel Maher ( :jmaher) 2012-02-01 11:40:37 PST
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!
Comment 17 Joel Maher ( :jmaher) 2012-02-01 11:42:12 PST
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.
Comment 18 Joel Maher ( :jmaher) 2012-02-01 11:49:06 PST
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?
Comment 19 Chris Lord [:cwiiis] 2012-02-01 11:52:40 PST
(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 20 Joel Maher ( :jmaher) 2012-02-01 11:56:34 PST
got it!
Comment 23 Mark Finkle (:mfinkle) (use needinfo?) 2012-02-06 13:29:52 PST
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
Comment 25 Brad Lassey [:blassey] (use needinfo?) 2012-02-06 19:26:26 PST
pushed to beta https://hg.mozilla.org/releases/mozilla-beta/rev/19d0e027d6fc and backed out https://hg.mozilla.org/releases/mozilla-beta/rev/ce224666955c
Comment 26 Justin Wood (:Callek) 2012-02-27 16:17:24 PST
(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 27 Matt Brubeck (:mbrubeck) 2012-02-28 10:49:45 PST
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.]

Note You need to log in before you can comment on or make changes to this bug.