Add positive event logs to chrome://interventions-internals.

Design doc:
https://docs.google.com/document/d/1i7_1VkjJ2x86BXWocK4ZuEVq_DzdYRslt2ihJ2UdlZk

Screenshot: https://drive.google.com/a/chromium.org/file/d/1qGcgcNF3vCjb0cjkkrO_Sox9OEOSQtXo

Bug: 788872
Change-Id: Ib09a31a3914aa9b244e9e6117e1cc501a102e82c
Reviewed-on: https://chromium-review.googlesource.com/791910
Commit-Queue: Thanh Le <thanhdle@chromium.org>
Reviewed-by: Tarun Bansal <tbansal@chromium.org>
Reviewed-by: Ryan Sturm <ryansturm@chromium.org>
Cr-Commit-Position: refs/heads/master@{#521440}

components/previews/content/previews_io_data.cc

@@ -153,14 +153,17 @@ void PreviewsIOData::LogPreviewNavigation(const GURL& url,
                             previews_ui_service_, url, type, opt_out, time));
 }
 
-void PreviewsIOData::LogPreviewDecisionMade(PreviewsEligibilityReason reason,
-                                            const GURL& url,
-                                            base::Time time,
-                                            PreviewsType type) const {
+void PreviewsIOData::LogPreviewDecisionMade(
+    PreviewsEligibilityReason reason,
+    const GURL& url,
+    base::Time time,
+    PreviewsType type,
+    std::vector<PreviewsEligibilityReason>&& passed_reasons) const {
   LogPreviewsEligibilityReason(reason, type);
   ui_task_runner_->PostTask(
       FROM_HERE, base::Bind(&PreviewsUIService::LogPreviewDecisionMade,
-                            previews_ui_service_, reason, url, time, type));
+                            previews_ui_service_, reason, url, time, type,
+                            base::Passed(std::move(passed_reasons))));
 }
 
 void PreviewsIOData::AddPreviewNavigation(const GURL& url,
@@ -204,21 +207,27 @@ bool PreviewsIOData::ShouldAllowPreviewAtECT(
     // when navigating to files on disk, etc.
     return false;
   }
+
+  std::vector<PreviewsEligibilityReason> passed_reasons;
   if (is_enabled_callback_.is_null() || !previews_black_list_) {
     LogPreviewDecisionMade(PreviewsEligibilityReason::BLACKLIST_UNAVAILABLE,
-                           request.url(), base::Time::Now(), type);
+                           request.url(), base::Time::Now(), type,
+                           std::move(passed_reasons));
     return false;
   }
+  passed_reasons.push_back(PreviewsEligibilityReason::BLACKLIST_UNAVAILABLE);
+
   if (!is_enabled_callback_.Run(type))
     return false;
 
   if (!blacklist_ignored_) {
     // The blacklist will disallow certain hosts for periods of time based on
     // user's opting out of the preview.
-    PreviewsEligibilityReason status =
-        previews_black_list_->IsLoadedAndAllowed(request.url(), type);
+    PreviewsEligibilityReason status = previews_black_list_->IsLoadedAndAllowed(
+        request.url(), type, &passed_reasons);
     if (status != PreviewsEligibilityReason::ALLOWED) {
-      LogPreviewDecisionMade(status, request.url(), base::Time::Now(), type);
+      LogPreviewDecisionMade(status, request.url(), base::Time::Now(), type,
+                             std::move(passed_reasons));
       return false;
     }
   }
@@ -232,16 +241,20 @@ bool PreviewsIOData::ShouldAllowPreviewAtECT(
             net::EFFECTIVE_CONNECTION_TYPE_OFFLINE) {
       LogPreviewDecisionMade(
           PreviewsEligibilityReason::NETWORK_QUALITY_UNAVAILABLE, request.url(),
-          base::Time::Now(), type);
+          base::Time::Now(), type, std::move(passed_reasons));
       return false;
     }
+    passed_reasons.push_back(
+        PreviewsEligibilityReason::NETWORK_QUALITY_UNAVAILABLE);
 
     if (network_quality_estimator->GetEffectiveConnectionType() >
         effective_connection_type_threshold) {
       LogPreviewDecisionMade(PreviewsEligibilityReason::NETWORK_NOT_SLOW,
-                             request.url(), base::Time::Now(), type);
+                             request.url(), base::Time::Now(), type,
+                             std::move(passed_reasons));
       return false;
     }
+    passed_reasons.push_back(PreviewsEligibilityReason::NETWORK_NOT_SLOW);
   }
 
   // LOAD_VALIDATE_CACHE or LOAD_BYPASS_CACHE mean the user reloaded the page.
@@ -250,9 +263,11 @@ bool PreviewsIOData::ShouldAllowPreviewAtECT(
       request.load_flags() &
           (net::LOAD_VALIDATE_CACHE | net::LOAD_BYPASS_CACHE)) {
     LogPreviewDecisionMade(PreviewsEligibilityReason::RELOAD_DISALLOWED,
-                           request.url(), base::Time::Now(), type);
+                           request.url(), base::Time::Now(), type,
+                           std::move(passed_reasons));
     return false;
   }
+  passed_reasons.push_back(PreviewsEligibilityReason::RELOAD_DISALLOWED);
 
   // Check provided blacklist, if any. This type of blacklist was added for
   // Finch provided blacklist for Client LoFi.
@@ -261,9 +276,11 @@ bool PreviewsIOData::ShouldAllowPreviewAtECT(
       host_blacklist_from_server.end()) {
     LogPreviewDecisionMade(
         PreviewsEligibilityReason::HOST_BLACKLISTED_BY_SERVER, request.url(),
-        base::Time::Now(), type);
+        base::Time::Now(), type, std::move(passed_reasons));
     return false;
   }
+  passed_reasons.push_back(
+      PreviewsEligibilityReason::HOST_BLACKLISTED_BY_SERVER);
 
   // Check whitelist from the server, if provided.
   if (IsServerWhitelistedType(type)) {
@@ -273,21 +290,23 @@ bool PreviewsIOData::ShouldAllowPreviewAtECT(
           !previews_opt_guide_->IsWhitelisted(request, type)) {
         LogPreviewDecisionMade(
             PreviewsEligibilityReason::HOST_NOT_WHITELISTED_BY_SERVER,
-            request.url(), base::Time::Now(), type);
+            request.url(), base::Time::Now(), type, std::move(passed_reasons));
         return false;
       }
+      passed_reasons.push_back(
+          PreviewsEligibilityReason::HOST_NOT_WHITELISTED_BY_SERVER);
     } else {
       // Since server optimization guidance not configure, allow the preview
       // but with qualified eligibility reason.
       LogPreviewDecisionMade(
           PreviewsEligibilityReason::ALLOWED_WITHOUT_OPTIMIZATION_HINTS,
-          request.url(), base::Time::Now(), type);
+          request.url(), base::Time::Now(), type, std::move(passed_reasons));
       return true;
     }
   }
 
   LogPreviewDecisionMade(PreviewsEligibilityReason::ALLOWED, request.url(),
-                         base::Time::Now(), type);
+                         base::Time::Now(), type, std::move(passed_reasons));
   return true;
 }
 

components/previews/content/previews_io_data.h

@@ -67,11 +67,15 @@ class PreviewsIOData : public PreviewsDecider,
                             PreviewsType type,
                             base::Time time) const;
 
-  // Adds log message of preview decision made asynchronously.
-  void LogPreviewDecisionMade(PreviewsEligibilityReason reason,
-                              const GURL& url,
-                              base::Time time,
-                              PreviewsType type) const;
+  // Adds log message of preview decision made asynchronously. |passed_reasons|
+  // are PreviewsEligibilityReasons that got passed the decision before
+  // |reason|. The method takes ownership of |passed_reasons|.
+  void LogPreviewDecisionMade(
+      PreviewsEligibilityReason reason,
+      const GURL& url,
+      base::Time time,
+      PreviewsType type,
+      std::vector<PreviewsEligibilityReason>&& passed_reasons) const;
 
   // Adds a navigation to |url| to the black list with result |opt_out|.
   void AddPreviewNavigation(const GURL& url, bool opt_out, PreviewsType type);

components/previews/content/previews_ui_service.cc

@@ -52,12 +52,15 @@ void PreviewsUIService::LogPreviewNavigation(const GURL& url,
   logger_->LogPreviewNavigation(url, type, opt_out, time);
 }
 
-void PreviewsUIService::LogPreviewDecisionMade(PreviewsEligibilityReason reason,
-                                               const GURL& url,
-                                               base::Time time,
-                                               PreviewsType type) {
+void PreviewsUIService::LogPreviewDecisionMade(
+    PreviewsEligibilityReason reason,
+    const GURL& url,
+    base::Time time,
+    PreviewsType type,
+    std::vector<PreviewsEligibilityReason>&& passed_reasons) {
   DCHECK(thread_checker_.CalledOnValidThread());
-  logger_->LogPreviewDecisionMade(reason, url, time, type);
+  logger_->LogPreviewDecisionMade(reason, url, time, type,
+                                  std::move(passed_reasons));
 }
 
 void PreviewsUIService::OnNewBlacklistedHost(const std::string& host,

components/previews/content/previews_ui_service.h

@@ -81,12 +81,15 @@ class PreviewsUIService {
                                     bool opt_out,
                                     base::Time time);
 
-  // Log the made decision of previews to PreviewsLogger. Virtualized in
-  // testing.
-  virtual void LogPreviewDecisionMade(PreviewsEligibilityReason reason,
-                                      const GURL& url,
-                                      base::Time time,
-                                      PreviewsType type);
+  // Log the made decision of previews to PreviewsLogger. |passed_reasons| is a
+  // collection of PreviewsEligibilityReasons passed the checks before |reason|.
+  // The method takes ownership of |passed_reasons|. Virtualized in testing.
+  virtual void LogPreviewDecisionMade(
+      PreviewsEligibilityReason reason,
+      const GURL& url,
+      base::Time time,
+      PreviewsType type,
+      std::vector<PreviewsEligibilityReason>&& passed_reasons);
 
   // Expose the pointer to PreviewsLogger to extract logging messages. This
   // pointer's life time is the same as of |this|, and it is guaranteed to not

components/previews/content/previews_ui_service_unittest.cc

@@ -71,14 +71,17 @@ class TestPreviewsLogger : public PreviewsLogger {
     navigation_time_ = base::Time(time);
   }
 
-  void LogPreviewDecisionMade(PreviewsEligibilityReason reason,
-                              const GURL& url,
-                              base::Time time,
-                              PreviewsType type) override {
+  void LogPreviewDecisionMade(
+      PreviewsEligibilityReason reason,
+      const GURL& url,
+      base::Time time,
+      PreviewsType type,
+      std::vector<PreviewsEligibilityReason>&& passed_reasons) override {
     decision_reason_ = reason;
     decision_url_ = GURL(url);
     decision_time_ = time;
     decision_type_ = type;
+    decision_passed_reasons_ = std::move(passed_reasons);
   }
 
   void OnNewBlacklistedHost(const std::string& host, base::Time time) override {
@@ -103,6 +106,10 @@ class TestPreviewsLogger : public PreviewsLogger {
   GURL decision_url() const { return decision_url_; }
   PreviewsType decision_type() const { return decision_type_; }
   base::Time decision_time() const { return decision_time_; }
+  const std::vector<PreviewsEligibilityReason>& decision_passed_reasons()
+      const {
+    return decision_passed_reasons_;
+  }
 
   // Return the passed in LogPreviewNavigation parameters.
   GURL navigation_url() const { return navigation_url_; }
@@ -125,6 +132,7 @@ class TestPreviewsLogger : public PreviewsLogger {
   GURL decision_url_;
   PreviewsType decision_type_;
   base::Time decision_time_;
+  std::vector<PreviewsEligibilityReason> decision_passed_reasons_;
 
   // Passed in LogPreviewsNavigation parameters.
   GURL navigation_url_;
@@ -238,26 +246,53 @@ TEST_F(PreviewsUIServiceTest, TestLogPreviewDecisionMadePassesCorrectParams) {
   const GURL url_a("http://www.url_a.com/url_a");
   const base::Time time_a = base::Time::Now();
   PreviewsType type_a = PreviewsType::OFFLINE;
+  std::vector<PreviewsEligibilityReason> passed_reasons_a = {
+      PreviewsEligibilityReason::NETWORK_NOT_SLOW,
+      PreviewsEligibilityReason::USER_RECENTLY_OPTED_OUT,
+      PreviewsEligibilityReason::RELOAD_DISALLOWED,
+  };
+  const std::vector<PreviewsEligibilityReason> expected_passed_reasons_a(
+      passed_reasons_a);
 
-  ui_service()->LogPreviewDecisionMade(reason_a, url_a, time_a, type_a);
+  ui_service()->LogPreviewDecisionMade(reason_a, url_a, time_a, type_a,
+                                       std::move(passed_reasons_a));
 
   EXPECT_EQ(reason_a, logger_ptr_->decision_reason());
   EXPECT_EQ(url_a, logger_ptr_->decision_url());
   EXPECT_EQ(time_a, logger_ptr_->decision_time());
   EXPECT_EQ(type_a, logger_ptr_->decision_type());
 
+  auto actual_passed_reasons_a = logger_ptr_->decision_passed_reasons();
+  EXPECT_EQ(3UL, actual_passed_reasons_a.size());
+  for (size_t i = 0; i < actual_passed_reasons_a.size(); i++) {
+    EXPECT_EQ(expected_passed_reasons_a[i], actual_passed_reasons_a[i]);
+  }
+
   PreviewsEligibilityReason reason_b =
       PreviewsEligibilityReason::NETWORK_NOT_SLOW;
   const GURL url_b("http://www.url_b.com/url_b");
   const base::Time time_b = base::Time::Now();
   PreviewsType type_b = PreviewsType::LOFI;
+  std::vector<PreviewsEligibilityReason> passed_reasons_b = {
+      PreviewsEligibilityReason::HOST_NOT_WHITELISTED_BY_SERVER,
+      PreviewsEligibilityReason::NETWORK_QUALITY_UNAVAILABLE,
+  };
+  const std::vector<PreviewsEligibilityReason> expected_passed_reasons_b(
+      passed_reasons_b);
 
-  ui_service()->LogPreviewDecisionMade(reason_b, url_b, time_b, type_b);
+  ui_service()->LogPreviewDecisionMade(reason_b, url_b, time_b, type_b,
+                                       std::move(passed_reasons_b));
 
   EXPECT_EQ(reason_b, logger_ptr_->decision_reason());
   EXPECT_EQ(url_b, logger_ptr_->decision_url());
   EXPECT_EQ(type_b, logger_ptr_->decision_type());
   EXPECT_EQ(time_b, logger_ptr_->decision_time());
+
+  auto actual_passed_reasons_b = logger_ptr_->decision_passed_reasons();
+  EXPECT_EQ(2UL, actual_passed_reasons_b.size());
+  for (size_t i = 0; i < actual_passed_reasons_b.size(); i++) {
+    EXPECT_EQ(expected_passed_reasons_b[i], actual_passed_reasons_b[i]);
+  }
 }
 
 TEST_F(PreviewsUIServiceTest, TestOnNewBlacklistedHostPassesCorrectParams) {

components/previews/core/previews_black_list.cc

@@ -29,9 +29,8 @@ void EvictOldestOptOut(BlackListItemMap* black_list_item_map) {
       item_to_delete = iter;
       break;
     }
-    if (!oldest_opt_out ||
-        iter->second->most_recent_opt_out_time().value() <
-            oldest_opt_out.value()) {
+    if (!oldest_opt_out || iter->second->most_recent_opt_out_time().value() <
+                               oldest_opt_out.value()) {
       oldest_opt_out = iter->second->most_recent_opt_out_time().value();
       item_to_delete = iter;
     }
@@ -147,23 +146,29 @@ void PreviewsBlackList::AddPreviewNavigationSync(const GURL& url,
 
 PreviewsEligibilityReason PreviewsBlackList::IsLoadedAndAllowed(
     const GURL& url,
-    PreviewsType type) const {
+    PreviewsType type,
+    std::vector<PreviewsEligibilityReason>* passed_reasons) const {
   DCHECK(thread_checker_.CalledOnValidThread());
   DCHECK(url.has_host());
   if (!loaded_)
     return PreviewsEligibilityReason::BLACKLIST_DATA_NOT_LOADED;
+  passed_reasons->push_back(
+      PreviewsEligibilityReason::BLACKLIST_DATA_NOT_LOADED);
   DCHECK(black_list_item_map_);
   if (last_opt_out_time_ &&
       clock_->Now() <
           last_opt_out_time_.value() + params::SingleOptOutDuration()) {
     return PreviewsEligibilityReason::USER_RECENTLY_OPTED_OUT;
   }
+  passed_reasons->push_back(PreviewsEligibilityReason::USER_RECENTLY_OPTED_OUT);
   if (host_indifferent_black_list_item_->IsBlackListed(clock_->Now()))
     return PreviewsEligibilityReason::USER_BLACKLISTED;
+  passed_reasons->push_back(PreviewsEligibilityReason::USER_BLACKLISTED);
   PreviewsBlackListItem* black_list_item =
       GetBlackListItemFromMap(*black_list_item_map_, url.host());
   if (black_list_item && black_list_item->IsBlackListed(clock_->Now()))
     return PreviewsEligibilityReason::HOST_BLACKLISTED;
+  passed_reasons->push_back(PreviewsEligibilityReason::HOST_BLACKLISTED);
   return PreviewsEligibilityReason::ALLOWED;
 }
 

components/previews/core/previews_black_list.h

@@ -99,10 +99,12 @@ class PreviewsBlackList {
 
   // Synchronously determines if |host_name| should be allowed to show previews.
   // Returns the reason the blacklist disallowed the preview, or
-  // PreviewsEligibilityReason::ALLOWED if the preview is allowed. Virtualized
-  // in testing.
-  virtual PreviewsEligibilityReason IsLoadedAndAllowed(const GURL& url,
-                                                       PreviewsType type) const;
+  // PreviewsEligibilityReason::ALLOWED if the preview is allowed. Record
+  // checked reasons in |passed_reasons|. Virtualized in testing.
+  virtual PreviewsEligibilityReason IsLoadedAndAllowed(
+      const GURL& url,
+      PreviewsType type,
+      std::vector<PreviewsEligibilityReason>* passed_reasons) const;
 
   // Asynchronously deletes all entries in the in-memory black list. Informs
   // the backing store to delete entries between |begin_time| and |end_time|,

components/previews/core/previews_logger.cc

@@ -29,42 +29,56 @@ std::string GetDescriptionForPreviewsNavigation(PreviewsType type,
                             opt_out ? "True" : "False");
 }
 
-std::string GetReasonDescription(PreviewsEligibilityReason reason) {
+std::string GetReasonDescription(PreviewsEligibilityReason reason,
+                                 bool final_reason) {
   switch (reason) {
     case PreviewsEligibilityReason::ALLOWED:
+      DCHECK(final_reason);
       return "Allowed";
     case PreviewsEligibilityReason::BLACKLIST_UNAVAILABLE:
-      return "Blacklist failed to be created";
+      return final_reason ? "Blacklist failed to be created"
+                          : "Blacklist not null";
     case PreviewsEligibilityReason::BLACKLIST_DATA_NOT_LOADED:
-      return "Blacklist not loaded from disk yet";
+      return final_reason ? "Blacklist not loaded from disk yet"
+                          : "Blacklist loaded from disk";
     case PreviewsEligibilityReason::USER_RECENTLY_OPTED_OUT:
-      return "User recently opted out";
+      return final_reason ? "User recently opted out"
+                          : "User did not opt out recently";
     case PreviewsEligibilityReason::USER_BLACKLISTED:
-      return "All previews are blacklisted";
+      return final_reason ? "All previews are blacklisted"
+                          : "Not all previews are blacklisted";
     case PreviewsEligibilityReason::HOST_BLACKLISTED:
-      return "All previews on this host are blacklisted";
+      return final_reason ? "All previews on this host are blacklisted"
+                          : "Host is not blacklisted on all previews";
     case PreviewsEligibilityReason::NETWORK_QUALITY_UNAVAILABLE:
-      return "Network quality unavailable";
+      return final_reason ? "Network quality unavailable"
+                          : "Network quality available";
     case PreviewsEligibilityReason::NETWORK_NOT_SLOW:
-      return "Network not slow";
+      return final_reason ? "Network not slow" : "Network is slow";
     case PreviewsEligibilityReason::RELOAD_DISALLOWED:
-      return "Page reloads do not show previews for this preview type";
+      return final_reason
+                 ? "Page reloads do not show previews for this preview type"
+                 : "Page reloads allowed";
     case PreviewsEligibilityReason::HOST_BLACKLISTED_BY_SERVER:
-      return "Host blacklisted by server rules";
+      return final_reason ? "Host blacklisted by server rules"
+                          : "Host not blacklisted by server rules";
     case PreviewsEligibilityReason::HOST_NOT_WHITELISTED_BY_SERVER:
-      return "Host not whitelisted by server rules";
+      return final_reason ? "Host not whitelisted by server rules"
+                          : "Host whitelisted by server rules";
     case PreviewsEligibilityReason::ALLOWED_WITHOUT_OPTIMIZATION_HINTS:
-      return "Allowed (but without server rule check)";
+      return final_reason ? "Allowed (but without server rule check)"
+                          : "Not allowed (without server rule check)";
   }
   NOTREACHED();
   return "";
 }
 
 std::string GetDescriptionForPreviewsDecision(PreviewsEligibilityReason reason,
-                                              PreviewsType type) {
+                                              PreviewsType type,
+                                              bool final_reason) {
   return base::StringPrintf("%s preview - %s",
                             GetStringNameForType(type).c_str(),
-                            GetReasonDescription(reason).c_str());
+                            GetReasonDescription(reason, final_reason).c_str());
 }
 
 }  // namespace
@@ -167,18 +181,30 @@ void PreviewsLogger::LogPreviewNavigation(const GURL& url,
                                  time);
 }
 
-void PreviewsLogger::LogPreviewDecisionMade(PreviewsEligibilityReason reason,
-                                            const GURL& url,
-                                            base::Time time,
-                                            PreviewsType type) {
+void PreviewsLogger::LogPreviewDecisionMade(
+    PreviewsEligibilityReason reason,
+    const GURL& url,
+    base::Time time,
+    PreviewsType type,
+    std::vector<PreviewsEligibilityReason>&& passed_reasons) {
   DCHECK_CALLED_ON_VALID_SEQUENCE(sequence_checker_);
   DCHECK_GE(kMaximumDecisionLogs, decisions_logs_.size());
 
-  std::string description = GetDescriptionForPreviewsDecision(reason, type);
+  // Logs all passed decisions messages.
+  for (auto decision : passed_reasons) {
+    std::string decision_description = GetDescriptionForPreviewsDecision(
+        decision, type, false /* final_reason */);
+    LogMessage(kPreviewDecisionMadeEventType, decision_description, url, time);
+    decisions_logs_.emplace_back(kPreviewDecisionMadeEventType,
+                                 decision_description, url, time);
+  }
+
+  std::string description =
+      GetDescriptionForPreviewsDecision(reason, type, true /* final_reason */);
   LogMessage(kPreviewDecisionMadeEventType, description, url, time);
 
-  // Pop out the oldest message when the list is full.
-  if (decisions_logs_.size() >= kMaximumDecisionLogs) {
+  // Pop out the older messages when the list is full.
+  while (decisions_logs_.size() >= kMaximumDecisionLogs) {
     decisions_logs_.pop_front();
   }
 

components/previews/core/previews_logger.h

@@ -10,6 +10,7 @@
 #include <unordered_map>
 
 #include "base/macros.h"
+#include "base/memory/ptr_util.h"
 #include "base/observer_list.h"
 #include "base/sequence_checker.h"
 #include "base/time/time.h"
@@ -81,11 +82,15 @@ class PreviewsLogger {
                                     base::Time time);
 
   // Add a MessageLog for the a decision that was made about the state of
-  // previews and blacklist. Virtualized in testing.
-  virtual void LogPreviewDecisionMade(PreviewsEligibilityReason reason,
-                                      const GURL& url,
-                                      base::Time time,
-                                      PreviewsType type);
+  // previews and blacklist. |passed_reasons| is an ordered list of
+  // PreviewsEligibilityReasons that got pass the decision. The method takes
+  // ownership of |passed_reasons|. Virtualized in testing.
+  virtual void LogPreviewDecisionMade(
+      PreviewsEligibilityReason reason,
+      const GURL& url,
+      base::Time time,
+      PreviewsType type,
+      std::vector<PreviewsEligibilityReason>&& passed_reasons);
 
   // Notify observers that |host| is blacklisted at |time|. Virtualized in
   // testing.