Record NTP.LogoShownTime for timely refreshs only

This CL corrects the load time metrics for Logos on the NTP.

The old behavior:
-----------------
If the doodle cache is empty, the LogoShownTime will be recorded when
the next DoodleService#Refresh triggers the observer who requested a
Refresh.
If the requested refresh is skipped, the observer records the time when
the next notification happens due to a refresh triggered by a different
caller. This can be timely but is much more likely to be 15 min or more
in the future. This delay blurs the metric.

The wanted/new behavior:
------------------------
This CL introduces a way to know that the refresh was skipped.
The observer that records LogoShownTime uses it to prevent recording
any metrics for this case.

BUG=713166

Review-Url: https://codereview.chromium.org/2833473002
Cr-Commit-Position: refs/heads/master@{#467989}

chrome/android/java/src/org/chromium/chrome/browser/ntp/LogoDelegateImpl.java

@@ -38,7 +38,7 @@ public class LogoDelegateImpl implements LogoView.Delegate {
     private String mOnLogoClickUrl;
     private String mAnimatedLogoUrl;
 
-    private boolean mHasRecordedLoadTime;
+    private boolean mShouldRecordLoadTime = true;
 
     private boolean mIsDestroyed;
 
@@ -94,13 +94,15 @@ public class LogoDelegateImpl implements LogoView.Delegate {
                 if (logo != null) {
                     RecordHistogram.recordSparseSlowlyHistogram(LOGO_SHOWN_UMA_NAME,
                             logo.animatedLogoUrl == null ? STATIC_LOGO_SHOWN : CTA_IMAGE_SHOWN);
-                    if (!mHasRecordedLoadTime) {
+                    if (mShouldRecordLoadTime) {
                         long loadTime = System.currentTimeMillis() - loadTimeStart;
                         RecordHistogram.recordMediumTimesHistogram(
                                 LOGO_SHOWN_TIME_UMA_NAME, loadTime, TimeUnit.MILLISECONDS);
-                        mHasRecordedLoadTime = true;
                     }
                 }
+                // If there currently is no Doodle, don't record the time if a refresh happens
+                // later.
+                mShouldRecordLoadTime = false;
                 logoObserver.onLogoAvailable(logo, fromCache);
             }
         };

chrome/browser/android/logo_bridge.cc

@@ -226,9 +226,13 @@ void LogoBridge::GetCurrentLogo(JNIEnv* env,
   if (doodle_service_) {
     j_logo_observer_.Reset(j_logo_observer);
 
-    // Immediately hand out any current cached config.
-    DoodleConfigReceived(doodle_service_->config(), /*from_cache=*/true);
-    // Also request a refresh, in case something changed.
+    // Hand out any current cached config.
+    if (doodle_service_->config().has_value()) {
+      FetchDoodleImage(doodle_service_->config().value(), /*from_cache=*/true);
+    }
+    // Also request a refresh, in case something changed. Depending on whether a
+    // newer config was available, either |OnDoodleConfigUpdated| or
+    // |OnDoodleConfigRevalidated| are called.
     doodle_service_->Refresh();
   } else {
     // |observer| is deleted in LogoObserverAndroid::OnObserverRemoved().
@@ -246,26 +250,40 @@ void LogoBridge::GetAnimatedLogo(JNIEnv* env,
   animated_logo_fetcher_->Start(env, url, j_callback);
 }
 
+void LogoBridge::OnDoodleConfigRevalidated(bool from_cache) {
+  if (j_logo_observer_.is_null()) {
+    return;
+  }
+  // If an existing config got re-validated, there's nothing to do - the UI is
+  // already in the correct state. However, we do tell the UI when we validate
+  // that there really isn't a Doodle. This is needed for metrics tracking.
+  if (!doodle_service_->config().has_value()) {
+    NotifyNoLogoAvailable(from_cache);
+  }
+}
+
 void LogoBridge::OnDoodleConfigUpdated(
     const base::Optional<doodle::DoodleConfig>& maybe_doodle_config) {
   if (j_logo_observer_.is_null()) {
     return;
   }
-  DoodleConfigReceived(maybe_doodle_config, /*from_cache=*/false);
+  if (!maybe_doodle_config.has_value()) {
+    NotifyNoLogoAvailable(/*from_cache=*/false);
+    return;
+  }
+  FetchDoodleImage(maybe_doodle_config.value(), /*from_cache=*/false);
+}
+
+void LogoBridge::NotifyNoLogoAvailable(bool from_cache) {
+  JNIEnv* env = base::android::AttachCurrentThread();
+  Java_LogoObserver_onLogoAvailable(env, j_logo_observer_,
+                                    ScopedJavaLocalRef<jobject>(), from_cache);
 }
 
-void LogoBridge::DoodleConfigReceived(
-    const base::Optional<doodle::DoodleConfig>& maybe_doodle_config,
-    bool from_cache) {
+void LogoBridge::FetchDoodleImage(const doodle::DoodleConfig& doodle_config,
+                                  bool from_cache) {
   DCHECK(!j_logo_observer_.is_null());
 
-  if (!maybe_doodle_config.has_value()) {
-    JNIEnv* env = base::android::AttachCurrentThread();
-    Java_LogoObserver_onLogoAvailable(
-        env, j_logo_observer_, ScopedJavaLocalRef<jobject>(), from_cache);
-    return;
-  }
-  const doodle::DoodleConfig& doodle_config = maybe_doodle_config.value();
   // If there is a CTA image, that means the main image is animated. Show the
   // non-animated CTA image first, and load the animated one only when the
   // user requests it.

chrome/browser/android/logo_bridge.h

@@ -38,8 +38,13 @@ class LogoBridge : public doodle::DoodleService::Observer {
   explicit LogoBridge(jobject j_profile);
   void Destroy(JNIEnv* env, const base::android::JavaParamRef<jobject>& obj);
 
+  // TODO(treib): Double-check the observer contract (esp. for LogoTracker).
   // Gets the current non-animated logo (downloading it if necessary) and passes
   // it to the observer.
+  // The observer's |onLogoAvailable| is guaranteed to be called at least once:
+  // a) A cached doodle is available.
+  // b) A new doodle is available.
+  // c) Not having a doodle was revalidated.
   void GetCurrentLogo(
       JNIEnv* env,
       const base::android::JavaParamRef<jobject>& obj,
@@ -60,13 +65,13 @@ class LogoBridge : public doodle::DoodleService::Observer {
   virtual ~LogoBridge();
 
   // doodle::DoodleService::Observer implementation.
+  void OnDoodleConfigRevalidated(bool from_cache) override;
   void OnDoodleConfigUpdated(
       const base::Optional<doodle::DoodleConfig>& maybe_doodle_config) override;
 
-  void DoodleConfigReceived(
-      const base::Optional<doodle::DoodleConfig>& maybe_doodle_config,
-      bool from_cache);
-
+  void NotifyNoLogoAvailable(bool from_cache);
+  void FetchDoodleImage(const doodle::DoodleConfig& doodle_config,
+                        bool from_cache);
   void DoodleImageFetched(bool config_from_cache,
                           const GURL& on_click_url,
                           const std::string& alt_text,

components/doodle/doodle_service.cc

@@ -87,6 +87,9 @@ void DoodleService::Refresh() {
   if (time_since_fetch < min_refresh_interval_) {
     RecordDownloadMetrics(OUTCOME_REFRESH_INTERVAL_NOT_PASSED,
                           base::TimeDelta());
+    for (auto& observer : observers_) {
+      observer.OnDoodleConfigRevalidated(/*from_cache=*/true);
+    }
     return;
   }
   fetcher_->FetchDoodle(base::BindOnce(&DoodleService::DoodleFetched,
@@ -192,7 +195,6 @@ DoodleService::DownloadOutcome DoodleService::HandleNewConfig(
   DownloadOutcome outcome =
       DetermineDownloadOutcome(cached_config_, new_config, state, expired);
 
-  // If the config changed, update our cache and notify observers.
   // Note that this checks both for existence changes as well as changes of the
   // configs themselves.
   if (cached_config_ != new_config) {
@@ -201,6 +203,10 @@ DoodleService::DownloadOutcome DoodleService::HandleNewConfig(
     for (auto& observer : observers_) {
       observer.OnDoodleConfigUpdated(cached_config_);
     }
+  } else {
+    for (auto& observer : observers_) {
+      observer.OnDoodleConfigRevalidated(/*from_cache=*/false);
+    }
   }
 
   // Even if the configs are identical, the time-to-live might have changed.

components/doodle/doodle_service.h

@@ -27,6 +27,7 @@ class DoodleService : public KeyedService {
  public:
   class Observer {
    public:
+    virtual void OnDoodleConfigRevalidated(bool from_cache) = 0;
     virtual void OnDoodleConfigUpdated(const base::Optional<DoodleConfig>&) = 0;
   };
 
@@ -57,8 +58,8 @@ class DoodleService : public KeyedService {
   void RemoveObserver(Observer* observer);
 
   // Requests an asynchronous refresh of the DoodleConfig from the network.
-  // After the update completes, the observers will be notified only if the
-  // config changed.
+  // After the update completes, the observers will be notified whether the
+  // config changed or active config remains valid.
   void Refresh();
 
  private:

components/doodle/doodle_service_unittest.cc

@@ -55,6 +55,7 @@ class MockDoodleObserver : public DoodleService::Observer {
  public:
   MOCK_METHOD1(OnDoodleConfigUpdated,
                void(const base::Optional<DoodleConfig>&));
+  MOCK_METHOD1(OnDoodleConfigRevalidated, void(bool));
 };
 
 DoodleConfig CreateConfig(DoodleType type) {
@@ -309,7 +310,7 @@ TEST_F(DoodleServiceTest, CallsObserverOnConfigUpdated) {
   service()->RemoveObserver(&observer);
 }
 
-TEST_F(DoodleServiceTest, DoesNotCallObserverIfConfigEquivalent) {
+TEST_F(DoodleServiceTest, CallsObserverIfConfigRevalidatedByNetworkRequest) {
   // Load some doodle config.
   service()->Refresh();
   DoodleConfig config = CreateConfig(DoodleType::SIMPLE);
@@ -317,14 +318,18 @@ TEST_F(DoodleServiceTest, DoesNotCallObserverIfConfigEquivalent) {
                                base::TimeDelta::FromHours(1), config);
   ASSERT_THAT(service()->config(), Eq(config));
 
-  // Register an observer and request a refresh.
+  // Let some time pass (more than the refresh interval).
+  task_runner()->FastForwardBy(base::TimeDelta::FromMinutes(16));
+
+  // Register an observer and request a refresh after refresh intervall passed.
   StrictMock<MockDoodleObserver> observer;
+  EXPECT_CALL(observer, OnDoodleConfigRevalidated(Eq(/*from_cache=*/false)));
   service()->AddObserver(&observer);
   service()->Refresh();
   ASSERT_THAT(fetcher()->num_pending_callbacks(), Eq(1u));
 
   // Serve the request with an equivalent doodle config. The observer should
-  // *not* get notified.
+  // get notified about a (non-cached) revalidation.
   DoodleConfig equivalent_config = CreateConfig(DoodleType::SIMPLE);
   DCHECK(config == equivalent_config);
   fetcher()->ServeAllCallbacks(
@@ -334,6 +339,28 @@ TEST_F(DoodleServiceTest, DoesNotCallObserverIfConfigEquivalent) {
   service()->RemoveObserver(&observer);
 }
 
+TEST_F(DoodleServiceTest, CallsObserverIfConfigRevalidatedByCache) {
+  // Create a service with the default refresh interval.
+  RecreateService(/*min_refresh_interval=*/base::nullopt);
+
+  // Load some doodle config.
+  service()->Refresh();
+  DoodleConfig config = CreateConfig(DoodleType::SIMPLE);
+  fetcher()->ServeAllCallbacks(DoodleState::AVAILABLE,
+                               base::TimeDelta::FromHours(1), config);
+  ASSERT_THAT(service()->config(), Eq(config));
+
+  // Register an observer and request a refresh within refresh intervall.
+  StrictMock<MockDoodleObserver> observer;
+  EXPECT_CALL(observer, OnDoodleConfigRevalidated(Eq(/*from_cache=*/true)));
+  service()->AddObserver(&observer);
+  service()->Refresh();
+  ASSERT_THAT(fetcher()->num_pending_callbacks(), Eq(0u));
+
+  // Remove the observer before the service gets destroyed.
+  service()->RemoveObserver(&observer);
+}
+
 TEST_F(DoodleServiceTest, CallsObserverWhenConfigExpires) {
   // Load some doodle config.
   service()->Refresh();
@@ -364,12 +391,14 @@ TEST_F(DoodleServiceTest, DisregardsAlreadyExpiredConfigs) {
   StrictMock<MockDoodleObserver> observer;
   service()->AddObserver(&observer);
 
+  // If there was no config and an expired config is loaded, not having a config
+  // must be revalidated.
   ASSERT_THAT(service()->config(), Eq(base::nullopt));
 
-  // Load an already-expired config. This should have no effect; in particular
-  // no call to the observer.
+  // Load an already-expired config.
   service()->Refresh();
   DoodleConfig config = CreateConfig(DoodleType::SIMPLE);
+  EXPECT_CALL(observer, OnDoodleConfigRevalidated(Eq(/*from_cache=*/false)));
   fetcher()->ServeAllCallbacks(DoodleState::AVAILABLE,
                                base::TimeDelta::FromSeconds(0), config);
   EXPECT_THAT(service()->config(), Eq(base::nullopt));