WebFonts: measure network loading time

third_party/WebKit/Source/core/css/RemoteFontFaceSource.cpp

Index: third_party/WebKit/Source/core/css/RemoteFontFaceSource.cpp
diff --git a/third_party/WebKit/Source/core/css/RemoteFontFaceSource.cpp b/third_party/WebKit/Source/core/css/RemoteFontFaceSource.cpp
index bd49325ebda38e603bd5f7ffd78f72c79f1429b2..4e6da51f5fdc3ea3bc8175b6ba467f1ba3c39a91 100644
--- a/third_party/WebKit/Source/core/css/RemoteFontFaceSource.cpp
+++ b/third_party/WebKit/Source/core/css/RemoteFontFaceSource.cpp
@@ -24,6 +24,35 @@ namespace blink {
 
 namespace {
 
+// Should not change following enum order to be used for metrics values.
+enum CacheHitMetrics {
+    Miss,
+    DiskHit,
+    DataUrl,
+    MemoryHit,
+    CacheHitEnumMax
+};
+
+CacheHitMetrics getMetricsValue(RemoteFontFaceSource::DataSource dataSource)
+{
+    switch (dataSource) {
+    case RemoteFontFaceSource::FromDataURL:
+        return DataUrl;
+    case RemoteFontFaceSource::FromMemoryCache:
+        return MemoryHit;
+    case RemoteFontFaceSource::FromDiskCache:
+        return DiskHit;
+    case RemoteFontFaceSource::FromNetwork:
+        return Miss;
+    case RemoteFontFaceSource::FromUnknown:
+        // Still loading implies coming from network.

[Kunihiko Sakamoto, 2016/09/06 18:04:53]

Having this logic in this conversion function feels a bit weird...
Can we just call NOTREACHED() here?

[Takashi Toyoshima, 2016/09/07 08:49:08]

Done.

+        return Miss;
+    default:
+        NOTREACHED();
+    }
+    return Miss;
+}
+
 bool isEffectiveConnectionTypeSlowFor(Document* document)
 {
     WebEffectiveConnectionType type = document->frame()->loader().client()->getEffectiveConnectionType();
@@ -40,11 +69,11 @@ bool isConnectionTypeSlow()
     return networkStateNotifier().connectionType() == WebConnectionTypeCellular2G;
 }
 
-bool shouldTriggerWebFontsIntervention(Document* document, FontDisplay display, bool isLoadedFromMemoryCache, bool isLoadedFromDataURL)
+bool shouldTriggerWebFontsIntervention(Document* document, FontDisplay display, RemoteFontFaceSource::DataSource dataSource)

[Kunihiko Sakamoto, 2016/09/06 18:04:53]

Maybe make this a private member function of RemoteFonTaceSource, so
m_dataSource can be accessed directly.

[Takashi Toyoshima, 2016/09/07 08:49:08]

Hum... I'm neutral on this, but I'd rather consider to have dataSource inside
FontLoadHistograms since this is a state used for metrics. I didn't do so
because dataSource is used outside the inner class, here. But probably I can
write it in a reasonable way.

[Kunihiko Sakamoto, 2016/09/07 16:25:42]

ok, sgtm.

 {
     if (RuntimeEnabledFeatures::webFontsInterventionTriggerEnabled())
         return true;
-    if (isLoadedFromMemoryCache || isLoadedFromDataURL)
+    if (dataSource == RemoteFontFaceSource::FromMemoryCache || dataSource == RemoteFontFaceSource::FromDataURL)
         return false;
 
     bool isV2Enabled = RuntimeEnabledFeatures::webFontsInterventionV2With2GEnabled() || RuntimeEnabledFeatures::webFontsInterventionV2WithSlow2GEnabled();
@@ -62,13 +91,12 @@ RemoteFontFaceSource::RemoteFontFaceSource(FontResource* font, CSSFontSelector*
     , m_display(display)
     , m_period(display == FontDisplaySwap ? SwapPeriod : BlockPeriod)
     , m_isInterventionTriggered(false)
-    , m_isLoadedFromMemoryCache(font->isLoaded())
+    , m_dataSource(font->url().protocolIsData() ? FromDataURL : font->isLoaded() ? FromMemoryCache : FromUnknown)
 {
     ThreadState::current()->registerPreFinalizer(this);
     m_font->addClient(this);
 
-    if (shouldTriggerWebFontsIntervention(m_fontSelector->document(), display, m_isLoadedFromMemoryCache, m_font->url().protocolIsData())) {
-
+    if (shouldTriggerWebFontsIntervention(m_fontSelector->document(), display, m_dataSource)) {
         m_isInterventionTriggered = true;
         m_period = SwapPeriod;
         m_fontSelector->document()->addConsoleMessage(ConsoleMessage::create(OtherMessageSource, InfoMessageLevel, "Slow network is detected. Fallback font will be used while loading: " + m_font->url().elidedString()));
@@ -116,8 +144,10 @@ bool RemoteFontFaceSource::isValid() const
 
 void RemoteFontFaceSource::notifyFinished(Resource*)
 {
-    m_histograms.recordRemoteFont(m_font.get(), m_isLoadedFromMemoryCache);
-    m_histograms.fontLoaded(m_isInterventionTriggered, !m_isLoadedFromMemoryCache && !m_font->url().protocolIsData() && !m_font->response().wasCached());
+    if (m_dataSource == FromUnknown)
+        m_dataSource = m_font->response().wasCached() ? FromDiskCache : FromNetwork;
+    m_histograms.recordRemoteFont(m_font.get(), m_dataSource);
+    m_histograms.fontLoaded(m_isInterventionTriggered, m_dataSource);
 
     m_font->ensureCustomFontData();
     // FIXME: Provide more useful message such as OTS rejection reason.
@@ -152,7 +182,7 @@ void RemoteFontFaceSource::fontLoadLongLimitExceeded(FontResource*)
     else if (m_display == FontDisplayFallback)
         switchToFailurePeriod();
 
-    m_histograms.longLimitExceeded(m_isInterventionTriggered);
+    m_histograms.longLimitExceeded(m_isInterventionTriggered, m_dataSource);
 }
 
 void RemoteFontFaceSource::switchToSwapPeriod()
@@ -238,16 +268,16 @@ void RemoteFontFaceSource::FontLoadHistograms::fallbackFontPainted(DisplayPeriod
         m_blankPaintTime = currentTimeMS();
 }
 
-void RemoteFontFaceSource::FontLoadHistograms::fontLoaded(bool isInterventionTriggered, bool isLoadedFromNetwork)
+void RemoteFontFaceSource::FontLoadHistograms::fontLoaded(bool isInterventionTriggered, DataSource dataSource)
 {
     if (!m_isLongLimitExceeded)
-        recordInterventionResult(isInterventionTriggered, isLoadedFromNetwork);
+        recordInterventionResult(isInterventionTriggered, dataSource);
 }
 
-void RemoteFontFaceSource::FontLoadHistograms::longLimitExceeded(bool isInterventionTriggered)
+void RemoteFontFaceSource::FontLoadHistograms::longLimitExceeded(bool isInterventionTriggered, DataSource dataSource)
 {
     m_isLongLimitExceeded = true;
-    recordInterventionResult(isInterventionTriggered, true);
+    recordInterventionResult(isInterventionTriggered, dataSource);
 }
 
 void RemoteFontFaceSource::FontLoadHistograms::recordFallbackTime(const FontResource* font)
@@ -260,20 +290,17 @@ void RemoteFontFaceSource::FontLoadHistograms::recordFallbackTime(const FontReso
     m_blankPaintTime = -1;
 }
 
-void RemoteFontFaceSource::FontLoadHistograms::recordRemoteFont(const FontResource* font, bool isLoadedFromMemoryCache)
+void RemoteFontFaceSource::FontLoadHistograms::recordRemoteFont(const FontResource* font, DataSource dataSource)
 {
     if (m_loadStartTime > 0 && font && !font->isLoading()) {
-        int duration = static_cast<int>(currentTimeMS() - m_loadStartTime);
-        recordLoadTimeHistogram(font, duration);
-        m_loadStartTime = -1;
-
         enum { Miss, DiskHit, DataUrl, MemoryHit, CacheHitEnumMax };
-        int histogramValue = font->url().protocolIsData() ? DataUrl
-            : isLoadedFromMemoryCache ? MemoryHit
-            : font->response().wasCached() ? DiskHit
-            : Miss;
+        int cacheHitValue = getMetricsValue(dataSource);
         DEFINE_STATIC_LOCAL(EnumerationHistogram, cacheHitHistogram, ("WebFont.CacheHit", CacheHitEnumMax));
-        cacheHitHistogram.count(histogramValue);
+        cacheHitHistogram.count(cacheHitValue);

[Kunihiko Sakamoto, 2016/09/06 18:04:53]

Call getMetricsValue() here and remove cacheHitValue variable?

[Takashi Toyoshima, 2016/09/07 08:49:09]

Done.

+
+        int duration = static_cast<int>(currentTimeMS() - m_loadStartTime);
+        recordLoadTimeHistogram(font, duration, dataSource);
+        m_loadStartTime = -1;
 
         enum { CORSFail, CORSSuccess, CORSEnumMax };
         int corsValue = font->isCORSFailed() ? CORSFail : CORSSuccess;
@@ -282,40 +309,58 @@ void RemoteFontFaceSource::FontLoadHistograms::recordRemoteFont(const FontResour
     }
 }
 
-void RemoteFontFaceSource::FontLoadHistograms::recordLoadTimeHistogram(const FontResource* font, int duration)
+void RemoteFontFaceSource::FontLoadHistograms::recordLoadTimeHistogram(const FontResource* font, int duration, DataSource dataSource)
 {
     if (font->errorOccurred()) {
         DEFINE_STATIC_LOCAL(CustomCountHistogram, loadErrorHistogram, ("WebFont.DownloadTime.LoadError", 0, 10000, 50));
+        DEFINE_STATIC_LOCAL(CustomCountHistogram, missedCacheLoadErrorHistogram, ("WebFont.MissedCache.DownloadTime.LoadError", 0, 10000, 50));

[Takashi Toyoshima, 2016/09/07 08:49:08]

Also, I'd say there is another requirement to have another variant,
HitDiskCache. sakamoto-san, could you follow mail thread I forwarded?

[Kunihiko Sakamoto, 2016/09/07 16:25:42]

Yeah I'm following the thread, and I agree we need cache-hit variant. I have
some questions:

- Should we add separate histogram(s) for DiskCacheHit and MemoryCacheHit?
- Breakdown by font size is needed?
- Can we deprecate existing cache-unaware histogram in favor of new ones?

[Takashi Toyoshima, 2016/09/09 06:25:24]

Good point.
If data comes from memory cache or data URL, we can have data on constructor.
That means load time is always 0. So, I think we don't need separate one for
MemoryCacheHit.

- Breakdown by font size is needed?

Probably yes for disk cache. Our current result implies it may have a wide
distribution.


- Can we deprecate existing cache-unaware histogram in favor of new ones?

Agreed. At some point, when we understand cache hit rate and loadtime for each
correctly, we won't need this (we can calculate it indirectly)

         loadErrorHistogram.count(duration);
+        if (dataSource == FromNetwork)
+            missedCacheLoadErrorHistogram.count(duration);
         return;
     }
 
     unsigned size = font->encodedSize();
     if (size < 10 * 1024) {
         DEFINE_STATIC_LOCAL(CustomCountHistogram, under10kHistogram, ("WebFont.DownloadTime.0.Under10KB", 0, 10000, 50));
+        DEFINE_STATIC_LOCAL(CustomCountHistogram, missedCacheUnder10kHistogram, ("WebFont.MissedCache.DownloadTime.0.Under10KB", 0, 10000, 50));
         under10kHistogram.count(duration);
+        if (dataSource == FromNetwork)
+            missedCacheUnder10kHistogram.count(duration);
         return;
     }
     if (size < 50 * 1024) {
         DEFINE_STATIC_LOCAL(CustomCountHistogram, under50kHistogram, ("WebFont.DownloadTime.1.10KBTo50KB", 0, 10000, 50));
+        DEFINE_STATIC_LOCAL(CustomCountHistogram, missedCacheUnder50kHistogram, ("WebFont.MissedCache.DownloadTime.1.10KBTo50KB", 0, 10000, 50));
         under50kHistogram.count(duration);
+        if (dataSource == FromNetwork)
+            missedCacheUnder50kHistogram.count(duration);
         return;
     }
     if (size < 100 * 1024) {
         DEFINE_STATIC_LOCAL(CustomCountHistogram, under100kHistogram, ("WebFont.DownloadTime.2.50KBTo100KB", 0, 10000, 50));
+        DEFINE_STATIC_LOCAL(CustomCountHistogram, missedCacheUnder100kHistogram, ("WebFont.MissedCache.DownloadTime.2.50KBTo100KB", 0, 10000, 50));
         under100kHistogram.count(duration);
+        if (dataSource == FromNetwork)
+            missedCacheUnder100kHistogram.count(duration);
         return;
     }
     if (size < 1024 * 1024) {
         DEFINE_STATIC_LOCAL(CustomCountHistogram, under1mbHistogram, ("WebFont.DownloadTime.3.100KBTo1MB", 0, 10000, 50));
+        DEFINE_STATIC_LOCAL(CustomCountHistogram, missedCacheUnder1mbHistogram, ("WebFont.MissedCache.DownloadTime.3.100KBTo1MB", 0, 10000, 50));
         under1mbHistogram.count(duration);
+        if (dataSource == FromNetwork)
+            missedCacheUnder1mbHistogram.count(duration);
         return;
     }
     DEFINE_STATIC_LOCAL(CustomCountHistogram, over1mbHistogram, ("WebFont.DownloadTime.4.Over1MB", 0, 10000, 50));
+    DEFINE_STATIC_LOCAL(CustomCountHistogram, missedCacheOver1mbHistogram, ("WebFont.MissedCache.DownloadTime.4.Over1MB", 0, 10000, 50));
     over1mbHistogram.count(duration);
+    if (dataSource == FromNetwork)
+        missedCacheOver1mbHistogram.count(duration);
 }
 
-void RemoteFontFaceSource::FontLoadHistograms::recordInterventionResult(bool isTriggered, bool isLoadedFromNetwork)
+void RemoteFontFaceSource::FontLoadHistograms::recordInterventionResult(bool isTriggered, DataSource dataSource)
 {
     // interventionResult takes 0-3 values.
     int interventionResult = 0;
@@ -328,7 +373,7 @@ void RemoteFontFaceSource::FontLoadHistograms::recordInterventionResult(bool isT
     DEFINE_STATIC_LOCAL(EnumerationHistogram, interventionHistogram, ("WebFont.InterventionResult", boundary));
     DEFINE_STATIC_LOCAL(EnumerationHistogram, missedCacheInterventionHistogram, ("WebFont.InterventionResult.MissedCache", boundary));
     interventionHistogram.count(interventionResult);
-    if (isLoadedFromNetwork)
+    if (dataSource == FromNetwork || dataSource == FromUnknown)
         missedCacheInterventionHistogram.count(interventionResult);
 }