Add DocumentTiming metrics for "time to first text paint"

Add DocumentTiming metrics for "time to first text paint"

This patch adds two DocumentTiming metrics, FirstNonBlankText and
FirstCustomFontText.

See https://codereview.chromium.org/1325593003/ for the chromium side of
this change, which records UMA for these timings.

BUG=520410

[Kunihiko Sakamoto, 2015-09-03 06:44:27]

Patchset #1 (id:1) has been deleted

[Kunihiko Sakamoto, 2015-09-14 06:13:29]

Patchset #1 (id:20001) has been deleted

[Kunihiko Sakamoto, 2015-09-14 06:13:37]

Patchset #1 (id:40001) has been deleted

[Kunihiko Sakamoto, 2015-09-14 06:13:52]

Patchset #1 (id:60001) has been deleted

[Kunihiko Sakamoto, 2015-09-14 07:44:56]

ksakamoto@chromium.org changed reviewers:
+ eae@chromium.org, kinuko@chromium.org

[kinuko, 2015-09-14 14:14:34]

https://codereview.chromium.org/1314843009/diff/80001/Source/core/css/CSSFont...
File Source/core/css/CSSFontSelector.cpp (right):

https://codereview.chromium.org/1314843009/diff/80001/Source/core/css/CSSFont...
Source/core/css/CSSFontSelector.cpp:136: if (m_firstCustomFontTextReported)
Looks like common pattern is doing something like following, should we follow?

if (!documentTiming.firstFooTiming())
  documentTiming.markFirstFooTiming();

Also I wonder if we should report these via document class, so that it's easier
to track all document related timings.

https://codereview.chromium.org/1314843009/diff/80001/public/web/WebPerforman...
File public/web/WebPerformance.h (right):

https://codereview.chromium.org/1314843009/diff/80001/public/web/WebPerforman...
public/web/WebPerformance.h:89: BLINK_EXPORT double firstCustomFontText() const;
Um... some of these are from spec but others are not, for non-spec related ones
could we add comments somewhere, either on Performance or WebPerformance?

Esp. these two would be hard to distinguish without documentation.

[Kunihiko Sakamoto, 2015-09-15 05:11:02]

https://codereview.chromium.org/1314843009/diff/80001/Source/core/css/CSSFont...
File Source/core/css/CSSFontSelector.cpp (right):

https://codereview.chromium.org/1314843009/diff/80001/Source/core/css/CSSFont...
Source/core/css/CSSFontSelector.cpp:136: if (m_firstCustomFontTextReported)
On 2015/09/14 14:14:33, kinuko wrote:
> Looks like common pattern is doing something like following, should we follow?
> 
> if (!documentTiming.firstFooTiming())
>   documentTiming.markFirstFooTiming();
> 
> Also I wonder if we should report these via document class, so that it's
easier
> to track all document related timings.

Done.

https://codereview.chromium.org/1314843009/diff/80001/public/web/WebPerforman...
File public/web/WebPerformance.h (right):

https://codereview.chromium.org/1314843009/diff/80001/public/web/WebPerforman...
public/web/WebPerformance.h:89: BLINK_EXPORT double firstCustomFontText() const;
On 2015/09/14 14:14:33, kinuko wrote:
> Um... some of these are from spec but others are not, for non-spec related
ones
> could we add comments somewhere, either on Performance or WebPerformance?
> 
> Esp. these two would be hard to distinguish without documentation.

Added some comments in PerformanceTiming.h.

[kinuko, 2015-09-15 05:25:08]

lgtm, I think

https://codereview.chromium.org/1314843009/diff/100001/Source/core/dom/Docume...
File Source/core/dom/Document.cpp (right):

https://codereview.chromium.org/1314843009/diff/100001/Source/core/dom/Docume...
Source/core/dom/Document.cpp:1928: }
(If we start to feel these are too annoying let's consider moving these out of
Document class as you did in the first patch... for now this looks ok to me)

https://codereview.chromium.org/1314843009/diff/100001/Source/core/timing/Per...
File Source/core/timing/PerformanceTiming.h (right):

https://codereview.chromium.org/1314843009/diff/100001/Source/core/timing/Per...
Source/core/timing/PerformanceTiming.h:86: // Similar to firstNonBlankText, but
only for text with custom fonts.
nit: could we also comment that this may not be recorded if no custom font is
used?

Could we also note what fonts are considered 'custom' here?

[kinuko, 2015-09-15 05:43:17]

Also before we actually start wiring this change could we think about how to
avoid logging this when the tab's background?
(Will we want to handle the status in browser side, say, within
https://codereview.chromium.org/1312213010/ ?)

[Kunihiko Sakamoto, 2015-09-15 06:22:42]

On 2015/09/15 05:43:17, kinuko wrote:
> Also before we actually start wiring this change could we think about how to
> avoid logging this when the tab's background?
> (Will we want to handle the status in browser side, say, within
> https://codereview.chromium.org/1312213010/ ?)

Yeah unless we filter out data from backgrounded tabs, these metrics wouldn't be
so useful.
Marked crbug.com/509676 as a blocking bug of this. Let's figure out how to
detect that (probably in browser side).

https://codereview.chromium.org/1314843009/diff/100001/Source/core/timing/Per...
File Source/core/timing/PerformanceTiming.h (right):

https://codereview.chromium.org/1314843009/diff/100001/Source/core/timing/Per...
Source/core/timing/PerformanceTiming.h:86: // Similar to firstNonBlankText, but
only for text with custom fonts.
On 2015/09/15 05:25:08, kinuko wrote:
> nit: could we also comment that this may not be recorded if no custom font is
> used?
> 
> Could we also note what fonts are considered 'custom' here?

Done.

[Bryan McQuade, 2015-09-15 17:24:17]

bmcquade@chromium.org changed reviewers:
+ bmcquade@chromium.org

[Bryan McQuade, 2015-09-15 17:24:17]

Really glad to see this change, thanks! One question from me.

https://codereview.chromium.org/1314843009/diff/120001/Source/platform/fonts/...
File Source/platform/fonts/FontFallbackList.cpp (right):

https://codereview.chromium.org/1314843009/diff/120001/Source/platform/fonts/...
Source/platform/fonts/FontFallbackList.cpp:104:
m_fontSelector->reportFirstNonBlankText(m_hasCustomFont);
I'm still learning this code so I may be misunderstanding, but given that
shouldSkipDrawing is a const method, which from its method signature appears to
not have side effects, I worry a little bit about depending on when/where such a
method gets called to record the first non-blank text. Would it make sense to
move this to the code that is actually responsible for drawing text, perhaps
somewhere in the Font class?

[Kunihiko Sakamoto, 2015-09-16 05:37:03]

eae@, could you take a look for platform/fonts?

https://codereview.chromium.org/1314843009/diff/120001/Source/platform/fonts/...
File Source/platform/fonts/FontFallbackList.cpp (right):

https://codereview.chromium.org/1314843009/diff/120001/Source/platform/fonts/...
Source/platform/fonts/FontFallbackList.cpp:104:
m_fontSelector->reportFirstNonBlankText(m_hasCustomFont);
On 2015/09/15 17:24:17, Bryan McQuade wrote:
> I'm still learning this code so I may be misunderstanding, but given that
> shouldSkipDrawing is a const method, which from its method signature appears
to
> not have side effects, I worry a little bit about depending on when/where such
a
> method gets called to record the first non-blank text. Would it make sense to
> move this to the code that is actually responsible for drawing text, perhaps
> somewhere in the Font class?

Agreed that reporting from shouldXXX is confusing. Moved this to the caller side
(Font::drawText is also a const method, but it having side effects may be less
counter-intuitive).

[Kunihiko Sakamoto, 2015-09-16 05:41:42]

ksakamoto@chromium.org changed reviewers:
+ drott@chromium.org

[Kunihiko Sakamoto, 2015-09-16 05:41:42]

+drott@, would you mind reviewing fonts part?

[drott, 2015-09-16 07:26:20]

Thanks for the patch and working on getting better metrics. While I agree that
having better metrics for "first meaningful paint" is needed, I am not sure this
approach helps us get there. I'm also afraid that your CL is not exactly
recording the intended event, see below.

From the bug it seems like the discussion on the definition and exact metrics
for "first meaningful paint" is not concluded. It'd be great if a sharper
definition could be found, but in the meantime I am okay reviewing this again if
we can find solutions for the issues below.

https://codereview.chromium.org/1314843009/diff/140001/Source/platform/fonts/...
File Source/platform/fonts/Font.cpp (right):

https://codereview.chromium.org/1314843009/diff/140001/Source/platform/fonts/...
Source/platform/fonts/Font.cpp:146: if (fontSelector())
If I am not mistaken, this keeps calling reportFirstNonBlankText reporting, and
calling up to m_document of CSSFontSelector for every draw call. The
Font::drawText is a highly performance sensitive function - I would prefer not
to introduce additional callback hooks into it.

https://codereview.chromium.org/1314843009/diff/140001/Source/platform/fonts/...
Source/platform/fonts/Font.cpp:169: if (fontSelector())
Dito.

https://codereview.chromium.org/1314843009/diff/140001/Source/platform/fonts/...
File Source/platform/fonts/FontFallbackList.cpp (right):

https://codereview.chromium.org/1314843009/diff/140001/Source/platform/fonts/...
Source/platform/fonts/FontFallbackList.cpp:216: if (result->isCustomFont())
Note that recording the m_hasCustomFont flag here, when fontDataAt(a) is called
with an index that points to a custom font, is not 100% equivalent to the
accessed font getting used for drawing. This might make the intended UMA data
you're trying to record inaccurate.

Instead, you might want to check whether SimpleFontData->isCustomFont() in
drawGlyphBuffer() - however, as I mentioned before, somehow it needs to be
ensure that we do this really only once per pageload and avoid introducing
additional cycles into drawGlyphBuffer.

https://codereview.chromium.org/1314843009/diff/140001/Source/platform/fonts/...
File Source/platform/fonts/FontSelector.h (right):

https://codereview.chromium.org/1314843009/diff/140001/Source/platform/fonts/...
Source/platform/fonts/FontSelector.h:45: virtual void
reportFirstNonBlankText(bool isCustomFont) { }
I would prefer to have both reportFirstNonBlankText &
reportFirstCustomFontText() here instead of a magic boolean. That said - could
you think of a better way to get the timestamps recorded in UMA other than using
FontSelector as a bridge to access the document? The method does not fit so well
into the purpose of FontSelector.

[Kunihiko Sakamoto, 2015-09-17 08:36:10]

Thank you for the comments.

We're still trying to figure out a good definition of first 'meaningful' paint,
but I think metrics in this patch are still useful.

https://codereview.chromium.org/1314843009/diff/140001/Source/platform/fonts/...
File Source/platform/fonts/Font.cpp (right):

https://codereview.chromium.org/1314843009/diff/140001/Source/platform/fonts/...
Source/platform/fonts/Font.cpp:146: if (fontSelector())
On 2015/09/16 07:26:20, drott wrote:
> If I am not mistaken, this keeps calling reportFirstNonBlankText reporting,
and
> calling up to m_document of CSSFontSelector for every draw call. The
> Font::drawText is a highly performance sensitive function - I would prefer not
> to introduce additional callback hooks into it.

That's right - I optimistically assumed the function call cost would be small
compared to actual font drawing.
Added a flag so that calling up to Document occurs at most once per Font
instance.

https://codereview.chromium.org/1314843009/diff/140001/Source/platform/fonts/...
File Source/platform/fonts/FontFallbackList.cpp (right):

https://codereview.chromium.org/1314843009/diff/140001/Source/platform/fonts/...
Source/platform/fonts/FontFallbackList.cpp:216: if (result->isCustomFont())
On 2015/09/16 07:26:20, drott wrote:
> Note that recording the m_hasCustomFont flag here, when fontDataAt(a) is
called
> with an index that points to a custom font, is not 100% equivalent to the
> accessed font getting used for drawing. This might make the intended UMA data
> you're trying to record inaccurate.
> 
> Instead, you might want to check whether SimpleFontData->isCustomFont() in
> drawGlyphBuffer() - however, as I mentioned before, somehow it needs to be
> ensure that we do this really only once per pageload and avoid introducing
> additional cycles into drawGlyphBuffer.
> 

I see your point, but I think this condition is appropriate for our purpose.

Rather than actual font used for drawing, I'm interested in distinguishing if
the text paint is blocked by font load or not. If a webfont is loaded and then
fallbacked to local font (e.g. because loaded font did not have a glyph), we'd
like to count it as "custom font text".

https://codereview.chromium.org/1314843009/diff/140001/Source/platform/fonts/...
File Source/platform/fonts/FontSelector.h (right):

https://codereview.chromium.org/1314843009/diff/140001/Source/platform/fonts/...
Source/platform/fonts/FontSelector.h:45: virtual void
reportFirstNonBlankText(bool isCustomFont) { }
On 2015/09/16 07:26:20, drott wrote:
> I would prefer to have both reportFirstNonBlankText &
> reportFirstCustomFontText() here instead of a magic boolean. That said - could
> you think of a better way to get the timestamps recorded in UMA other than
using
> FontSelector as a bridge to access the document? The method does not fit so
well
> into the purpose of FontSelector.

Changed it to two methods.

Unfortunately, relation between Font class and Document is pretty weak so I
couldn't come up with a better way to route this. We might be able to make this
look less weird, by introducing a new interface. For example:

class TextTiming {
  virtual void reportFirstCustomFontText();
  virtual void reportFirstNonBlankText();
};

class FontSelector {
  TextTiming* textTiming();
};

What do you think?

[kinuko, 2015-09-18 04:05:18]

On 2015/09/17 08:36:10, ksakamoto (ooo Sep 19-27) wrote:
>
https://codereview.chromium.org/1314843009/diff/140001/Source/platform/fonts/...
> File Source/platform/fonts/Font.cpp (right):
> 
>
https://codereview.chromium.org/1314843009/diff/140001/Source/platform/fonts/...
> Source/platform/fonts/Font.cpp:146: if (fontSelector())
> On 2015/09/16 07:26:20, drott wrote:
> > If I am not mistaken, this keeps calling reportFirstNonBlankText reporting,
> and
> > calling up to m_document of CSSFontSelector for every draw call. The
> > Font::drawText is a highly performance sensitive function - I would prefer
not
> > to introduce additional callback hooks into it.
> 
> That's right - I optimistically assumed the function call cost would be small
> compared to actual font drawing.
> Added a flag so that calling up to Document occurs at most once per Font
> instance.

(As we chatted offline) could we try running some of our perf benchmarks to see
if any impact shows up with this change?
(Not sure if we have good benchmark set for drawing texts though)

[Kunihiko Sakamoto, 2015-09-18 05:16:36]

On 2015/09/18 04:05:18, kinuko wrote:
> On 2015/09/17 08:36:10, ksakamoto (ooo Sep 19-27) wrote:
> >
>
https://codereview.chromium.org/1314843009/diff/140001/Source/platform/fonts/...
> > File Source/platform/fonts/Font.cpp (right):
> > 
> >
>
https://codereview.chromium.org/1314843009/diff/140001/Source/platform/fonts/...
> > Source/platform/fonts/Font.cpp:146: if (fontSelector())
> > On 2015/09/16 07:26:20, drott wrote:
> > > If I am not mistaken, this keeps calling reportFirstNonBlankText
reporting,
> > and
> > > calling up to m_document of CSSFontSelector for every draw call. The
> > > Font::drawText is a highly performance sensitive function - I would prefer
> not
> > > to introduce additional callback hooks into it.
> > 
> > That's right - I optimistically assumed the function call cost would be
small
> > compared to actual font drawing.
> > Added a flag so that calling up to Document occurs at most once per Font
> > instance.
> 
> (As we chatted offline) could we try running some of our perf benchmarks to
see
> if any impact shows up with this change?
> (Not sure if we have good benchmark set for drawing texts though)

I'm not quite sure which perf benchmark I should run...
drott@: Any suggestions?

[esprehn, 2015-09-18 05:44:39]

esprehn@chromium.org changed reviewers:
+ esprehn@chromium.org

[esprehn, 2015-09-18 05:44:39]

I don't think this is the right layer of the system to report this. Drawing text
to a canvas will also cause you to report the first text metric even though the
page has no text yet. I think you want this in the paint/ system, not in the
font.

[Kunihiko Sakamoto, 2015-09-18 08:03:59]

Yeah, we should explore that way (thanks Bryan for forwarding the email thread).

I'm closing this codereview and will create new one once it's ready.
Thanks for the reviews!

[Bryan McQuade, 2015-09-18 14:03:23]

Thanks for digging into this! Agree that we should approach this from the
paint side of things.

On Fri, Sep 18, 2015 at 4:04 AM <ksakamoto@chromium.org> wrote:

> Yeah, we should explore that way (thanks Bryan for forwarding the email
> thread).
>
> I'm closing this codereview and will create new one once it's ready.
> Thanks for the reviews!
>
>
> https://codereview.chromium.org/1314843009/
>

To unsubscribe from this group and stop receiving emails from it, send an email
to blink-reviews+unsubscribe@chromium.org.