510110 - Extend MozAfterPaint with more features for testability of Gecko and Web applications

Status: RESOLVED FIXED

(Core :: Layout, defect)

Description

[Robert O'Callahan (:roc) (email my personal email if necessary)]

What I'd like to do for testability is to add to MozAfterPaint a log of all invalidates. Each entry in this log would contain
-- the region invalidated
-- a timestamp of when the invalidation happened
-- a reason string, which would default to null (meaning "unknown"), but which we would set in certain cases:
* "unsupress painting" when we invalidate due to exiting paint suppression
* "scroll repaint" when we invalidate an area due to scrolling
* "scroll copy" when we update part of the window using a copy operation

Comment 1

[Robert O'Callahan (:roc) (email my personal email if necessary)]

We'd only maintain this log while there's a MozAfterPaint listener registered, of course, and we'd lazily create DOM objects when the log is queried. We'd expose the log as a regular DOM array of objects.

Comment 2

[Kyle Scholz]

The presence of a natively determined timestamp is key. In the present model, contention between the handler for the MozAferPaint event and other script activity make collecting a timestamp in the handler undependable.

I think this feature may be incredibly useful in live latency measurement, where we really want an indication of user perceived latency.

Comment 3

[Robert O'Callahan (:roc) (email my personal email if necessary)]

Attachment: Part 1: Implement paintRequest API for MozAfterPaint event

Adds paintRequest attribute to MozAfterPaint events. This is a regular JS/DOM list; each element supports three attributes:
-- clientRect
-- time (in JS Date() compatible milliseconds-since-UNIX-epoch format)
-- reason (a string; currently support "", "scroll copy", "scroll repaint")

I'm not sure whether doing PR_Now on every Invalidate will be a measurable perf hit on mobile which uses MozAfterPaint extensively. I hope not. If it is, we can pref it off.

Comment 4

[Robert O'Callahan (:roc) (email my personal email if necessary)]

(In reply to comment #2)
> The presence of a natively determined timestamp is key. In the present model,
> contention between the handler for the MozAferPaint event and other script
> activity make collecting a timestamp in the handler undependable.
> 
> I think this feature may be incredibly useful in live latency measurement,
> where we really want an indication of user perceived latency.

The time returned in the 'time' attribute in this patch is the time of invalidation, i.e. the time of whatever triggered the painting. So that's not actually what you want for user-perceived latency. The actual painting would happen some time after that time, and currently might even happen after MozAfterPaint fires.

My plan is that during an upcoming rework of paint logic ("compositor phase 2") I will make MozAfterPaint fire synchronously immediately after painting. Then the current time in the event handler should be a reasonable proxy for user-perceived paint time.

Comment 5

[Robert O'Callahan (:roc) (email my personal email if necessary)]

The test suite in bug 510856 uses this code.

Comment 6

[David Baron :dbaron: (⌚️UTC-4, no longer working on Mozilla)]

Comment on attachment 397576 [details] [diff] [review]
Part 1: Implement paintRequest API for MozAfterPaint event

nsIPrivateDOMEvent.h:

> /*
>  * Event listener manager interface.
>  */

While you're here, mind removing these three lines too?  (clearly copied
from elsewhere)

>-                          const nsRegion* aSameOriginRegion = nsnull,
>-                          const nsRegion* aCrossDocRegion = nsnull);
>+                          nsInvalidateRequestList* aSameDoc = nsnull,
>+                          nsInvalidateRequestList* aCrossDoc = nsnull);

Maybe call them aSameDocInvalidates and aCrossDocInvalidates?

Also comment that it empties the request lists?


nsDOMNotifyPaintEvent.cpp:

In nsDOMNotifyPaintEvent::GetPaintRequests, is it a problem that the
same-doc and cross-doc lists are just getting concatenated together
rather than preserving the original order?  I suspect the order may be
meaningful.

+  *aResult = requests.forget().get();

Use requests.forget(aResult) instead.

nsDOMNotifyPaintEvent.h:

-  nsDOMNotifyPaintEvent(nsPresContext*  aPresContext,
-                        nsEvent*        aEvent,
-                        PRUint32        aEventType,
-                        const nsRegion* aSameOriginRegion,
-                        const nsRegion* aCrossDocRegion);
+  nsDOMNotifyPaintEvent(nsPresContext*           aPresContext,
+                        nsEvent*                 aEvent,
+                        PRUint32                 aEventType,
+                        nsInvalidateRequestList* aSameOriginRegion,
+                        nsInvalidateRequestList* aCrossDocRegion);

Fix the names of the two new parameters whose types you changed (and whose
names you changed in the .cpp), perhaps according to the comment I made on
NS_NewDOMNotifyPaintEvent?  And also add the same comment about stealing the
requests that I mentioned there?

Same for the .h file too.

>+  void AppendRequests(nsPaintRequestList* aList,
>+                      const nsTArray<nsInvalidateRequestList::Request>& aRequests);

Maybe the parameters make more sense in the other order?
 
nsPaintRequest.cpp:

I think you should get nsPaintRequest.{cpp,h} reviewed by somebody with
more DOM code knowledge than I have.

>+NS_IMETHODIMP
>+nsPaintRequest::GetTime(double* aResult)
>+{
>+  *aResult = mRequest.mTime;
>+  return NS_OK;
>+}

I don't think this matches your interface documentation, which says
milliseconds since the epoch.  PRTime is in microseconds, according to
prtime.h.


>+  *aResult = clientRect.forget().get();

clientRect.forget(aResult);

Given that nsPaintRequest owns an nsPresContext, I think you should add
nsPaintRequest and nsPaintRequestList to cycle collection.

nsPaintRequest.h:

+  nsPaintRequest() { mRequest.mFlags = 0; mRequest.mTime = 0; }

Does this constructor help anything?  It seems like you'd either be better
off:
 (1) leaving it empty and letting valgrind catch failure to initialize
 (2) putting the initializing constructor on nsInvalidateRequestList::Request,
     perhaps not as a constructor but as an optional Initialize method.

>+  virtual ~nsPaintRequest() {}

>+  virtual ~nsPaintRequestList() {}

How about private and non-virtual for both of these?

>+#ifdef DEBUG
>+    {
>+      nsCOMPtr<nsIDOMPaintRequestList> list_qi = do_QueryInterface(aSupports);
>+
>+      // If this assertion fires the QI implementation for the object in
>+      // question doesn't use the nsIDOMClientRectList pointer as the nsISupports
>+      // pointer. That must be fixed, or we'll crash...
>+      NS_ASSERTION(list_qi == static_cast<nsIDOMPaintRequestList*>(aSupports),
>+                   "Uh, fix QI!");
>+    }
>+#endif

You could shorten this a bit using a temporary nsCOMPtr:

NS_ASSERTION(nsCOMPtr<nsIDOMPaintRequestList>(do_QueryInterface(aSupports) ==
               static_cast<...

nsDOMClassInfo.cpp:

This also needs review from somebody with more DOM knowledge.

Also, given that Canvas3D is off by default, I think you should add
right before the Canvas3D ifdefs rather than right after (in 3 places: 2
in nsDOMClassInfo.cpp and one in nsDOMClassInfo.h).

I'm not in a position to comment on nsPaintRequestListSH.

nsIFrame.h (from jumping around, not my full read through):

>    * @param aFlags INVALIDATE_NOTIFY_ONLY: set when this invalidation should
>    * cause MozAfterPaint listeners to be notified, but should not actually
>    * invalidate anything. This is used to notify about scrolling, where the
>    * screen has already been updated.

You should remove this documentation if you're removing the flag.


I'm up to nsPresContext.cpp at this point.  But I'm posting the comments
so far since they include requests to get additional review on parts of
the patch.  (Except now that I'm posting them I notice you've already requested sr from jst, so that probably counts.  But I'm posting them anyway because I'm here.)

Comment 7

[Robert O'Callahan (:roc) (email my personal email if necessary)]

(In reply to comment #6)
> (From update of attachment 397576 [details] [diff] [review])
> nsIPrivateDOMEvent.h:
> 
> > /*
> >  * Event listener manager interface.
> >  */
> 
> While you're here, mind removing these three lines too?  (clearly copied
> from elsewhere)

Sure

> >-                          const nsRegion* aSameOriginRegion = nsnull,
> >-                          const nsRegion* aCrossDocRegion = nsnull);
> >+                          nsInvalidateRequestList* aSameDoc = nsnull,
> >+                          nsInvalidateRequestList* aCrossDoc = nsnull);
> 
> Maybe call them aSameDocInvalidates and aCrossDocInvalidates?
> 
> Also comment that it empties the request lists?

Sure

> nsDOMNotifyPaintEvent.cpp:
> 
> In nsDOMNotifyPaintEvent::GetPaintRequests, is it a problem that the
> same-doc and cross-doc lists are just getting concatenated together
> rather than preserving the original order?  I suspect the order may be
> meaningful.

Hmm, there is a timestamp, but you're right, I should just have one list with a flag in each record saying if it's crossdoc or not.

> +  *aResult = requests.forget().get();
> 
> Use requests.forget(aResult) instead.

I learn something every day!

> nsDOMNotifyPaintEvent.h:
> 
> -  nsDOMNotifyPaintEvent(nsPresContext*  aPresContext,
> -                        nsEvent*        aEvent,
> -                        PRUint32        aEventType,
> -                        const nsRegion* aSameOriginRegion,
> -                        const nsRegion* aCrossDocRegion);
> +  nsDOMNotifyPaintEvent(nsPresContext*           aPresContext,
> +                        nsEvent*                 aEvent,
> +                        PRUint32                 aEventType,
> +                        nsInvalidateRequestList* aSameOriginRegion,
> +                        nsInvalidateRequestList* aCrossDocRegion);
> 
> Fix the names of the two new parameters whose types you changed (and whose
> names you changed in the .cpp), perhaps according to the comment I made on
> NS_NewDOMNotifyPaintEvent?  And also add the same comment about stealing the
> requests that I mentioned there?

Yes

> Maybe the parameters make more sense in the other order?

Yep

> nsPaintRequest.cpp:
> 
> I think you should get nsPaintRequest.{cpp,h} reviewed by somebody with
> more DOM code knowledge than I have.
> 
> >+NS_IMETHODIMP
> >+nsPaintRequest::GetTime(double* aResult)
> >+{
> >+  *aResult = mRequest.mTime;
> >+  return NS_OK;
> >+}
> 
> I don't think this matches your interface documentation, which says
> milliseconds since the epoch.  PRTime is in microseconds, according to
> prtime.h.

You're right! I need a test for that. Although actually I'm considering getting rid of the times since I don't have an immediate use for them. What do you think?

> Given that nsPaintRequest owns an nsPresContext, I think you should add
> nsPaintRequest and nsPaintRequestList to cycle collection.

I actually don't need the prescontext, nsClientRect::SetLayoutRect doesn't need its aPresContext parameter since the appunits-per-CSS-pixel value is global. So I'll just remove that stuff.

> nsPaintRequest.h:
> 
> +  nsPaintRequest() { mRequest.mFlags = 0; mRequest.mTime = 0; }
> 
> Does this constructor help anything?  It seems like you'd either be better
> off:
>  (1) leaving it empty and letting valgrind catch failure to initialize
>  (2) putting the initializing constructor on nsInvalidateRequestList::Request,
>      perhaps not as a constructor but as an optional Initialize method.

I'm afraid that there might be a way to create an nsPaintRequest via DOMClassInfo or something.

> >+  virtual ~nsPaintRequest() {}
> 
> >+  virtual ~nsPaintRequestList() {}
> 
> How about private and non-virtual for both of these?

OK

> >+#ifdef DEBUG
> >+    {
> >+      nsCOMPtr<nsIDOMPaintRequestList> list_qi = do_QueryInterface(aSupports);
> >+
> >+      // If this assertion fires the QI implementation for the object in
> >+      // question doesn't use the nsIDOMClientRectList pointer as the nsISupports
> >+      // pointer. That must be fixed, or we'll crash...
> >+      NS_ASSERTION(list_qi == static_cast<nsIDOMPaintRequestList*>(aSupports),
> >+                   "Uh, fix QI!");
> >+    }
> >+#endif
> 
> You could shorten this a bit using a temporary nsCOMPtr:
> 
> NS_ASSERTION(nsCOMPtr<nsIDOMPaintRequestList>(do_QueryInterface(aSupports) ==
>                static_cast<...

OK

> nsDOMClassInfo.cpp:
> 
> This also needs review from somebody with more DOM knowledge.
> 
> Also, given that Canvas3D is off by default, I think you should add
> right before the Canvas3D ifdefs rather than right after (in 3 places: 2
> in nsDOMClassInfo.cpp and one in nsDOMClassInfo.h).

OK

> I'm not in a position to comment on nsPaintRequestListSH.
> 
> nsIFrame.h (from jumping around, not my full read through):
> 
> >    * @param aFlags INVALIDATE_NOTIFY_ONLY: set when this invalidation should
> >    * cause MozAfterPaint listeners to be notified, but should not actually
> >    * invalidate anything. This is used to notify about scrolling, where the
> >    * screen has already been updated.
> 
> You should remove this documentation if you're removing the flag.

Indeed

Comment 8

[David Baron :dbaron: (⌚️UTC-4, no longer working on Mozilla)]

(In reply to comment #7)
> (In reply to comment #6)
> > I don't think this matches your interface documentation, which says
> > milliseconds since the epoch.  PRTime is in microseconds, according to
> > prtime.h.
> 
> You're right! I need a test for that. Although actually I'm considering getting
> rid of the times since I don't have an immediate use for them. What do you
> think?

No idea; I don't yet have a sense of what users this API would have.

Comment 9

[Robert O'Callahan (:roc) (email my personal email if necessary)]

> You could shorten this a bit using a temporary nsCOMPtr:

Actually this code pattern is all over the place. If we want to shorten them I think we should do that all at once.

Comment 10

[Robert O'Callahan (:roc) (email my personal email if necessary)]

Attachment: fix v2

Addresses comments.

Comment 11

[David Baron :dbaron: (⌚️UTC-4, no longer working on Mozilla)]

Comment on attachment 399007 [details] [diff] [review]
fix v2

Continued from comment 6, except now I'm reviewing attachment 399007 [details] [diff] [review],
starting with nsPresContext.cpp.

+  // This will empty our regions in case dispatching the event causes more damage

It's now emptying a list of requests, not a pair of regions.

nsPresContext.h:

+  PRBool MayHavePaintEventListener();

Shouldn't this be private?

nsPresShell.cpp:

> /* Just hook this call into InvalidateOverflowRect */

This comment isn't true anymore and should probably be removed.

>+  nsPresContext* p = GetPresContext();

It feels odd to call a pres context "p".  Maybe pc?

>+    flags |= nsIFrame::INVALIDATE_CROSS_DOC;    

If you want, this could just be = rather than |=, especially if the
variable were called crossDocFlags.

Also, this line has a bunch of trailing whitespace at the end.

nsIFrame.h:

+    INVALIDATE_REASON_MASK = 0x0C,

maybe better to write this as INVALIDATE_REASON_SCROLL_BLIT |
INVALIDATE_REASON_SCROLL_REPAINT (and put it after them)?

nsViewManager.cpp:

Why are you no longer checking !aUpdateRegion.IsEmpty() ?  Maybe worth
adding a comment explaining why you shouldn't?

r=dbaron with that

Comment 12

[David Baron :dbaron: (⌚️UTC-4, no longer working on Mozilla)]

Comment on attachment 397576 [details] [diff] [review]
Part 1: Implement paintRequest API for MozAfterPaint event

Canceling review requests on old patch (already duplicated on new one).

Comment 13

[Robert O'Callahan (:roc) (email my personal email if necessary)]

(In reply to comment #11)
> nsPresContext.h:
> 
> +  PRBool MayHavePaintEventListener();
> 
> Shouldn't this be private?

PresShell::NotifyInvalidateForScrolledView needs it.

> nsViewManager.cpp:
> 
> Why are you no longer checking !aUpdateRegion.IsEmpty() ?  Maybe worth
> adding a comment explaining why you shouldn't?

It's basically a short-circuit for a very rare case and with this patch, we still need to do most of the work in UpdateViewAfterScroll even if aUpdateRegion is empty, because we'd still need to send NotifyInvalidateForScrolledView with the correctly computed regions.

Comment 14

[Robert O'Callahan (:roc) (email my personal email if necessary)]

http://hg.mozilla.org/mozilla-central/rev/7494a97275dc

Tests in bug 510856 use this.

Comment 15

[Robert O'Callahan (:roc) (email my personal email if necessary)]

Comment on attachment 399007 [details] [diff] [review]
fix v2

I want to take this on the 1.9.2 branch so we can have scrolling test coverage there.

Comment 16

[David Baron :dbaron: (⌚️UTC-4, no longer working on Mozilla)]

Comment on attachment 399007 [details] [diff] [review]
fix v2

a1.9.2=dbaron

Comment 17

[Robert O'Callahan (:roc) (email my personal email if necessary)]

http://hg.mozilla.org/releases/mozilla-1.9.2/rev/44b98dceddb7

Comment 18

[Bryan McQuade]

Thanks for this change. I just tried it out and indeed I get a list of rects.

As I can tell, though, there isn't a timestamp for each of the rects. Kyle and I both see a lot of value in getting a timestamp per rect, or at least some way to measure the time that the various bits of content were rendered to the screen that is more accurate than taking a timestamp in the MozAfterPaint event handler.

I also see that you fill out the "reason" field for a few cases related to scrolling but other reasons are left empty. One reason we'd like to get populated is "unsupress painting" since this event seems to do a full window repaint but doesn't necessarily paint anything to the screen (seems to just paint an empty white buffer as far as I can tell but perhaps it sometimes also paints actual page content?).

Generally, we'd like to filter out things like scroll paints and unsuppress paints, and only record paint events related to painting as a result of rendering page content.

I appreciate that you implemented the core of this change already. If you have the cycles to add timestamps and a reason for "unsuppress painting" that'd be very helpful for us.

Thanks!
-bryan

Comment 19

[Robert O'Callahan (:roc) (email my personal email if necessary)]

(In reply to comment #18)
> I also see that you fill out the "reason" field for a few cases related to
> scrolling but other reasons are left empty. One reason we'd like to get
> populated is "unsupress painting" since this event seems to do a full window
> repaint but doesn't necessarily paint anything to the screen (seems to just
> paint an empty white buffer as far as I can tell but perhaps it sometimes also
> paints actual page content?).

It'll paint whatever we've got. Sometimes that's "nothing" (or stuff that renders as nothing). Yes, "unsuppress" would be a good reason to add. Can you file a bug for that?

I think the right thing to do for timestamps is just to make MozAfterPaint actually fire just after painting, so the current time in that event is close enough to what you want. Right now MozAfterPaint can fire before painting in some cases so there is no way to provide accurate timestamps in those cases. The changes required to fix the event timing are very high priority for me once my Firefox 3.6 issues are out of the way.

Comment 20

[:Ms2ger (he/him; ⌚ UTC+1/+2)]

Looks like bug 568392 removed all tests for event.paintRequests.