UKM that threads together multiple form interaction events.

components/autofill/core/browser/autofill_metrics.cc

Index: components/autofill/core/browser/autofill_metrics.cc
diff --git a/components/autofill/core/browser/autofill_metrics.cc b/components/autofill/core/browser/autofill_metrics.cc
index e813b1836f15f987cf2b02cadc879399f5e49b74..8505afadd79e6c06754537b790724f2ae9370437 100644
--- a/components/autofill/core/browser/autofill_metrics.cc
+++ b/components/autofill/core/browser/autofill_metrics.cc
@@ -5,6 +5,8 @@
 #include "components/autofill/core/browser/autofill_metrics.h"
 
 #include <algorithm>
+#include <utility>
+#include <vector>
 
 #include "base/logging.h"
 #include "base/metrics/histogram_macros.h"
@@ -22,6 +24,17 @@ const char kUKMCardUploadDecisionEntryName[] = "Autofill.CardUploadDecision";
 const char kUKMCardUploadDecisionMetricName[] = "UploadDecision";
 const char kUKMDeveloperEngagementEntryName[] = "Autofill.DeveloperEngagement";
 const char kUKMDeveloperEngagementMetricName[] = "DeveloperEngagement";
+const char kUKMFormInteractionsEntryName[] = "Autofill.FormInteractions";
+const char kUKMFormInteractionsAutofillFormSubmittedStateMetricName[] =
+    "AutofillFormSubmittedState";
+const char kUKMFormInteractionsUserHappinessMetricMetricName[] =
+    "UserHappinessMetric";
+const char kUKMFormInteractionsAddressFormEventMetricName[] =
+    "FormEvent.Address";
+const char kUKMFormInteractionsCreditCardFormEventMetricName[] =
+    "FormEvent.CreditCard";
+const char kUKMFormInteractionsUnmaskPromptEventMetricName[] =
+    "UnmaskPromptEvent";
 }  // namespace internal
 
 namespace autofill {
@@ -616,7 +629,8 @@ void AutofillMetrics::LogProfileActionOnFormSubmitted(
 
 // static
 void AutofillMetrics::LogAutofillFormSubmittedState(
-    AutofillFormSubmittedState state) {
+    AutofillFormSubmittedState state,
+    AutofillMetrics::FormInteractionsUkmLogger* form_interactions_ukm_logger) {
   UMA_HISTOGRAM_ENUMERATION("Autofill.FormSubmittedState", state,
                             AUTOFILL_FORM_SUBMITTED_STATE_ENUM_SIZE);
 
@@ -650,6 +664,7 @@ void AutofillMetrics::LogAutofillFormSubmittedState(
       NOTREACHED();
       break;
   }
+  form_interactions_ukm_logger->LogAutofillFormSubmittedState(state);
 }
 
 // static
@@ -706,7 +721,7 @@ void AutofillMetrics::LogCardUploadDecisionUkm(
   if (upload_decision >= AutofillMetrics::NUM_CARD_UPLOAD_DECISION_METRICS)
     return;
 
-  const std::map<std::string, int> metrics = {
+  const std::vector<std::pair<const char*, int>> metrics = {
       {internal::kUKMCardUploadDecisionMetricName,
        static_cast<int>(upload_decision)}};
   LogUkm(ukm_service, url, internal::kUKMCardUploadDecisionEntryName, metrics);
@@ -717,17 +732,18 @@ void AutofillMetrics::LogDeveloperEngagementUkm(
     ukm::UkmService* ukm_service,
     const GURL& url,
     AutofillMetrics::DeveloperEngagementMetric metric) {
-  const std::map<std::string, int> form_structure_metrics = {
+  const std::vector<std::pair<const char*, int>> form_structure_metrics = {
       {internal::kUKMDeveloperEngagementMetricName, static_cast<int>(metric)}};
   LogUkm(ukm_service, url, internal::kUKMDeveloperEngagementEntryName,
          form_structure_metrics);
 }
 
 // static
-bool AutofillMetrics::LogUkm(ukm::UkmService* ukm_service,
-                             const GURL& url,
-                             const std::string& ukm_entry_name,
-                             const std::map<std::string, int>& metrics) {
+bool AutofillMetrics::LogUkm(

[Steven Holte, 2017/04/10 22:42:32]

This appears to be logging a source for every entry, which you probably
shouldn't do.  Instead, you should log the source once and record multiple
entries to it.  Once we switch to having a global source id, we can just stop
adding the source and start using the global one.

[csashi, 2017/04/11 00:40:23]

FWIW, I was following the logging pattern that had been committed prior to my
change.  I can make this change, by keeping the source_id_ in the
FormInteractionsUkmLogger (similar to UkmPageLoadMetricsObserver). However, I
see 3 issues:

1. FormInteractions has a lifetime that is different from both the
CardUploadDecisionMetric and the DeveloperEngagement. CardUploadDecisionMetric
is logged after the user's form interaction is complete and the user has
submitted the form. DeveloperEngagement is logged when the form is parsed - i.e.
even before user has started interacting with the form.

2. DeveloperEngagement is logged for *all* forms, CardUploadDecisionMetric is
logged with URL key from form that is submitted, and FormInteractions is logged
for with URL key from form that user interacts with (usually same as submitted
form).

3. If we adopt this principle of logging the source only once, should we extend
it to UkmPageLoadMetricsObserver also?

I can make the change such that all logging from autofill_manager log the source
just once with some additional state in autofill_manager. Please confirm.

+    ukm::UkmService* ukm_service,
+    const GURL& url,
+    const std::string& ukm_entry_name,
+    const std::vector<std::pair<const char*, int>>& metrics) {
   if (!IsUkmLoggingEnabled() || !ukm_service || !url.is_valid() ||
       metrics.empty()) {
     return false;
@@ -739,13 +755,15 @@ bool AutofillMetrics::LogUkm(ukm::UkmService* ukm_service,
       ukm_service->GetEntryBuilder(source_id, ukm_entry_name.c_str());
 
   for (auto it = metrics.begin(); it != metrics.end(); ++it) {
-    builder->AddMetric(it->first.c_str(), it->second);
+    builder->AddMetric(it->first, it->second);
   }
 
   return true;
 }
 
-AutofillMetrics::FormEventLogger::FormEventLogger(bool is_for_credit_card)
+AutofillMetrics::FormEventLogger::FormEventLogger(
+    bool is_for_credit_card,
+    AutofillMetrics::FormInteractionsUkmLogger* form_interactions_ukm_logger)
     : is_for_credit_card_(is_for_credit_card),
       is_server_data_available_(false),
       is_local_data_available_(false),
@@ -757,12 +775,13 @@ AutofillMetrics::FormEventLogger::FormEventLogger(bool is_for_credit_card)
       has_logged_will_submit_(false),
       has_logged_submitted_(false),
       logged_suggestion_filled_was_server_data_(false),
-      logged_suggestion_filled_was_masked_server_card_(false) {}
+      logged_suggestion_filled_was_masked_server_card_(false),
+      form_interactions_ukm_logger_(form_interactions_ukm_logger) {}
 
 void AutofillMetrics::FormEventLogger::OnDidInteractWithAutofillableForm() {
   if (!has_logged_interacted_) {
     has_logged_interacted_ = true;
-    Log(AutofillMetrics::FORM_EVENT_INTERACTED_ONCE);
+    Log(AutofillMetrics::FORM_EVENT_INTERACTED_ONCE, false /* log_ukm */);
   }
 }
 
@@ -786,10 +805,11 @@ void AutofillMetrics::FormEventLogger::OnDidPollSuggestions(
 }
 
 void AutofillMetrics::FormEventLogger::OnDidShowSuggestions() {
-  Log(AutofillMetrics::FORM_EVENT_SUGGESTIONS_SHOWN);
+  Log(AutofillMetrics::FORM_EVENT_SUGGESTIONS_SHOWN, true /* log_ukm */);
   if (!has_logged_suggestions_shown_) {
     has_logged_suggestions_shown_ = true;
-    Log(AutofillMetrics::FORM_EVENT_SUGGESTIONS_SHOWN_ONCE);
+    Log(AutofillMetrics::FORM_EVENT_SUGGESTIONS_SHOWN_ONCE,
+        false /* log_ukm */);
   }
 
   if (is_for_credit_card_) {
@@ -803,11 +823,13 @@ void AutofillMetrics::FormEventLogger::OnDidShowSuggestions() {
 
 void AutofillMetrics::FormEventLogger::OnDidSelectMaskedServerCardSuggestion() {
   DCHECK(is_for_credit_card_);
-  Log(AutofillMetrics::FORM_EVENT_MASKED_SERVER_CARD_SUGGESTION_SELECTED);
+  Log(AutofillMetrics::FORM_EVENT_MASKED_SERVER_CARD_SUGGESTION_SELECTED,
+      true /* log_ukm */);
   if (!has_logged_masked_server_card_suggestion_selected_) {
     has_logged_masked_server_card_suggestion_selected_ = true;
-    Log(AutofillMetrics
-            ::FORM_EVENT_MASKED_SERVER_CARD_SUGGESTION_SELECTED_ONCE);
+    Log(AutofillMetrics ::
+            FORM_EVENT_MASKED_SERVER_CARD_SUGGESTION_SELECTED_ONCE,
+        false /* log_ukm */);
   }
 }
 
@@ -815,11 +837,14 @@ void AutofillMetrics::FormEventLogger::OnDidFillSuggestion(
     const CreditCard& credit_card) {
   DCHECK(is_for_credit_card_);
   if (credit_card.record_type() == CreditCard::MASKED_SERVER_CARD)
-    Log(AutofillMetrics::FORM_EVENT_MASKED_SERVER_CARD_SUGGESTION_FILLED);
+    Log(AutofillMetrics::FORM_EVENT_MASKED_SERVER_CARD_SUGGESTION_FILLED,
+        true /* log_ukm */);
   else if (credit_card.record_type() == CreditCard::FULL_SERVER_CARD)
-    Log(AutofillMetrics::FORM_EVENT_SERVER_SUGGESTION_FILLED);
+    Log(AutofillMetrics::FORM_EVENT_SERVER_SUGGESTION_FILLED,
+        true /* log_ukm */);
   else
-    Log(AutofillMetrics::FORM_EVENT_LOCAL_SUGGESTION_FILLED);
+    Log(AutofillMetrics::FORM_EVENT_LOCAL_SUGGESTION_FILLED,
+        true /* log_ukm */);
 
   if (!has_logged_suggestion_filled_) {
     has_logged_suggestion_filled_ = true;
@@ -829,12 +854,15 @@ void AutofillMetrics::FormEventLogger::OnDidFillSuggestion(
     logged_suggestion_filled_was_masked_server_card_ =
         credit_card.record_type() == CreditCard::MASKED_SERVER_CARD;
     if (credit_card.record_type() == CreditCard::MASKED_SERVER_CARD) {
-      Log(AutofillMetrics
-              ::FORM_EVENT_MASKED_SERVER_CARD_SUGGESTION_FILLED_ONCE);
+      Log(AutofillMetrics ::
+              FORM_EVENT_MASKED_SERVER_CARD_SUGGESTION_FILLED_ONCE,
+          false /* log_ukm */);
     } else if (credit_card.record_type() == CreditCard::FULL_SERVER_CARD) {
-      Log(AutofillMetrics::FORM_EVENT_SERVER_SUGGESTION_FILLED_ONCE);
+      Log(AutofillMetrics::FORM_EVENT_SERVER_SUGGESTION_FILLED_ONCE,
+          false /* log_ukm */);
     } else {
-      Log(AutofillMetrics::FORM_EVENT_LOCAL_SUGGESTION_FILLED_ONCE);
+      Log(AutofillMetrics::FORM_EVENT_LOCAL_SUGGESTION_FILLED_ONCE,
+          false /* log_ukm */);
     }
   }
 
@@ -846,17 +874,20 @@ void AutofillMetrics::FormEventLogger::OnDidFillSuggestion(
     const AutofillProfile& profile) {
   DCHECK(!is_for_credit_card_);
   if (profile.record_type() == AutofillProfile::SERVER_PROFILE)
-    Log(AutofillMetrics::FORM_EVENT_SERVER_SUGGESTION_FILLED);
+    Log(AutofillMetrics::FORM_EVENT_SERVER_SUGGESTION_FILLED,
+        true /* log_ukm */);
   else
-    Log(AutofillMetrics::FORM_EVENT_LOCAL_SUGGESTION_FILLED);
+    Log(AutofillMetrics::FORM_EVENT_LOCAL_SUGGESTION_FILLED,
+        true /* log_ukm */);
 
   if (!has_logged_suggestion_filled_) {
     has_logged_suggestion_filled_ = true;
     logged_suggestion_filled_was_server_data_ =
         profile.record_type() == AutofillProfile::SERVER_PROFILE;
     Log(profile.record_type() == AutofillProfile::SERVER_PROFILE
-        ? AutofillMetrics::FORM_EVENT_SERVER_SUGGESTION_FILLED_ONCE
-        : AutofillMetrics::FORM_EVENT_LOCAL_SUGGESTION_FILLED_ONCE);
+            ? AutofillMetrics::FORM_EVENT_SERVER_SUGGESTION_FILLED_ONCE
+            : AutofillMetrics::FORM_EVENT_LOCAL_SUGGESTION_FILLED_ONCE,
+        false /* log_ukm */);
   }
 
   base::RecordAction(
@@ -874,18 +905,23 @@ void AutofillMetrics::FormEventLogger::OnWillSubmitForm() {
   has_logged_will_submit_ = true;
 
   if (!has_logged_suggestion_filled_) {
-    Log(AutofillMetrics::FORM_EVENT_NO_SUGGESTION_WILL_SUBMIT_ONCE);
+    Log(AutofillMetrics::FORM_EVENT_NO_SUGGESTION_WILL_SUBMIT_ONCE,
+        false /* log_ukm */);
   } else if (logged_suggestion_filled_was_masked_server_card_) {
     Log(AutofillMetrics::
-            FORM_EVENT_MASKED_SERVER_CARD_SUGGESTION_WILL_SUBMIT_ONCE);
+            FORM_EVENT_MASKED_SERVER_CARD_SUGGESTION_WILL_SUBMIT_ONCE,
+        false /* log_ukm */);
   } else if (logged_suggestion_filled_was_server_data_) {
-    Log(AutofillMetrics::FORM_EVENT_SERVER_SUGGESTION_WILL_SUBMIT_ONCE);
+    Log(AutofillMetrics::FORM_EVENT_SERVER_SUGGESTION_WILL_SUBMIT_ONCE,
+        false /* log_ukm */);
   } else {
-    Log(AutofillMetrics::FORM_EVENT_LOCAL_SUGGESTION_WILL_SUBMIT_ONCE);
+    Log(AutofillMetrics::FORM_EVENT_LOCAL_SUGGESTION_WILL_SUBMIT_ONCE,
+        false /* log_ukm */);
   }
 
   if (has_logged_suggestions_shown_) {
-    Log(AutofillMetrics::FORM_EVENT_SUGGESTION_SHOWN_WILL_SUBMIT_ONCE);
+    Log(AutofillMetrics::FORM_EVENT_SUGGESTION_SHOWN_WILL_SUBMIT_ONCE,
+        false /* log_ukm */);
   }
 
   base::RecordAction(base::UserMetricsAction("Autofill_OnWillSubmitForm"));
@@ -902,22 +938,28 @@ void AutofillMetrics::FormEventLogger::OnFormSubmitted() {
   has_logged_submitted_ = true;
 
   if (!has_logged_suggestion_filled_) {
-    Log(AutofillMetrics::FORM_EVENT_NO_SUGGESTION_SUBMITTED_ONCE);
+    Log(AutofillMetrics::FORM_EVENT_NO_SUGGESTION_SUBMITTED_ONCE,
+        false /* log_ukm */);
   } else if (logged_suggestion_filled_was_masked_server_card_) {
-    Log(AutofillMetrics
-            ::FORM_EVENT_MASKED_SERVER_CARD_SUGGESTION_SUBMITTED_ONCE);
+    Log(AutofillMetrics ::
+            FORM_EVENT_MASKED_SERVER_CARD_SUGGESTION_SUBMITTED_ONCE,
+        false /* log_ukm */);
   } else if (logged_suggestion_filled_was_server_data_) {
-    Log(AutofillMetrics::FORM_EVENT_SERVER_SUGGESTION_SUBMITTED_ONCE);
+    Log(AutofillMetrics::FORM_EVENT_SERVER_SUGGESTION_SUBMITTED_ONCE,
+        false /* log_ukm */);
   } else {
-    Log(AutofillMetrics::FORM_EVENT_LOCAL_SUGGESTION_SUBMITTED_ONCE);
+    Log(AutofillMetrics::FORM_EVENT_LOCAL_SUGGESTION_SUBMITTED_ONCE,
+        false /* log_ukm */);
   }
 
   if (has_logged_suggestions_shown_) {
-    Log(AutofillMetrics::FORM_EVENT_SUGGESTION_SHOWN_SUBMITTED_ONCE);
+    Log(AutofillMetrics::FORM_EVENT_SUGGESTION_SHOWN_SUBMITTED_ONCE,
+        false /* log_ukm */);
   }
 }
 
-void AutofillMetrics::FormEventLogger::Log(FormEvent event) const {
+void AutofillMetrics::FormEventLogger::Log(FormEvent event,
+                                           bool log_ukm) const {
   DCHECK_LT(event, NUM_FORM_EVENTS);
   std::string name("Autofill.FormEvents.");
   if (is_for_credit_card_)
@@ -946,6 +988,90 @@ void AutofillMetrics::FormEventLogger::Log(FormEvent event) const {
   else
     name += ".WithBothServerAndLocalData";
   LogUMAHistogramEnumeration(name, event, NUM_FORM_EVENTS);
+
+  if (log_ukm) {
+    if (is_for_credit_card_)
+      form_interactions_ukm_logger_->LogCreditCardFormEvent(event);
+    else
+      form_interactions_ukm_logger_->LogAddressFormEvent(event);
+  }
+}
+
+AutofillMetrics::FormInteractionsUkmLogger::FormInteractionsUkmLogger(
+    ukm::UkmService* ukm_service)
+    : ukm_service_(ukm_service) {}
+
+AutofillMetrics::FormInteractionsUkmLogger::~FormInteractionsUkmLogger() {
+  // Submit pending events, if any. If the browser tab starts loading a new page
+  // when the user types a new URL prior to form submission,
+  // |LogAutofillFormSubmittedState| would not be invoked.
+  SubmitUkm();
+}
+
+void AutofillMetrics::FormInteractionsUkmLogger::LogAutofillFormSubmittedState(
+    AutofillFormSubmittedState state) {
+  metrics_.push_back(
+      std::make_pair(AUTOFILL_FORM_SUBMITTED_STATE, static_cast<int>(state)));
+  // User submitted form, we can submit the events for this form.
+  SubmitUkm();
+}
+
+void AutofillMetrics::FormInteractionsUkmLogger::LogUserHappinessMetric(
+    UserHappinessMetric metric) {
+  metrics_.push_back(
+      std::make_pair(USER_HAPPINESS_METRIC, static_cast<int>(metric)));
+}
+
+void AutofillMetrics::FormInteractionsUkmLogger::LogAddressFormEvent(
+    FormEvent event) {
+  metrics_.push_back(
+      std::make_pair(ADDRESS_FORM_EVENT, static_cast<int>(event)));
+}
+
+void AutofillMetrics::FormInteractionsUkmLogger::LogCreditCardFormEvent(
+    FormEvent event) {
+  metrics_.push_back(
+      std::make_pair(CREDIT_CARD_FORM_EVENT, static_cast<int>(event)));
+}
+
+void AutofillMetrics::FormInteractionsUkmLogger::LogUnmaskPromptEvent(
+    UnmaskPromptEvent event) {
+  metrics_.push_back(
+      std::make_pair(UNMASK_PROMPT_EVENT, static_cast<int>(event)));
+}
+
+void AutofillMetrics::FormInteractionsUkmLogger::SubmitUkm() {
+  std::vector<std::pair<const char*, int>> metrics;
+  for (const auto& it : metrics_) {
+    const char* metric_name = nullptr;
+    switch (it.first) {
+      case AutofillMetrics::FormInteractionsUkmLogger::
+          AUTOFILL_FORM_SUBMITTED_STATE:

[Steven Holte, 2017/04/10 22:42:31]

Why store all of this in multiple maps before putting it in UkmEntry?

It seems like it would be much simpler to just store this information in
UkmLogger members, and then just build the Entry from the members?

[csashi, 2017/04/11 00:40:23]

I am not using 'maps' - I have a vector of metrics. The same metric name could
be repeated. For example, we may show a suggestion, the user may edit, then we
show a suggestion again and so on. - we want to capture this 'session'.

In case you were referring to this switch statement as the 'map', I have removed
the switch.

[Steven Holte, 2017/04/11 17:37:57]

If I understand this right, you intending to infer the order of edits and fills
from the order of metrics within an entry?  I don't think we have an intention
to preserve that order during processing of this data.  It may make more sense
for you to send separate entries for each of your events and have something to
order them by, either a timestamp or a counter. (though you can still batch them
if they are only important for the context of the next event).

E.g. for some form, you might record
AutofillEvent {
  FormType: #CreditCard
  EventCounter: 0
  HadTypedData: 0
}
AutofillEvent {
  FormType: #CreditCard
  EventCounter: 1
  HadEdits: 1
}
AutofillSubmitEvent {
  FormType: #CreditCard
  EventCounter: 2
  HadEdits: 1
}

[csashi, 2017/04/12 00:13:53]

Done.

Your understanding is correct. I was intending to infer the order of events from
the order of the metrics. If we don't intend to preserve the order, it may be
worthwhile to document that explicitly because
https://developers.google.com/protocol-buffers/docs/encoding#optional says:
"""
The order of the elements with respect to each other is preserved when parsing,
though the ordering with respect to other fields is lost.
"""

+        metric_name =
+            internal::kUKMFormInteractionsAutofillFormSubmittedStateMetricName;
+        break;
+      case AutofillMetrics::FormInteractionsUkmLogger::USER_HAPPINESS_METRIC:
+        metric_name =
+            internal::kUKMFormInteractionsUserHappinessMetricMetricName;
+        break;
+      case AutofillMetrics::FormInteractionsUkmLogger::ADDRESS_FORM_EVENT:
+        metric_name = internal::kUKMFormInteractionsAddressFormEventMetricName;
+        break;
+      case AutofillMetrics::FormInteractionsUkmLogger::CREDIT_CARD_FORM_EVENT:
+        metric_name =
+            internal::kUKMFormInteractionsCreditCardFormEventMetricName;
+        break;
+      case AutofillMetrics::FormInteractionsUkmLogger::UNMASK_PROMPT_EVENT:
+        metric_name = internal::kUKMFormInteractionsUnmaskPromptEventMetricName;
+        break;
+      default:
+        NOTREACHED();
+    }
+    metrics.push_back(std::make_pair(metric_name, it.second));
+  }
+  AutofillMetrics::LogUkm(ukm_service_, url_,
+                          internal::kUKMFormInteractionsEntryName, metrics);
+  metrics_.clear();
 }
 
 }  // namespace autofill