Move some Autofill processing logic on form submit to a background thread.

chrome/browser/autofill/autofill_metrics_unittest.cc

 // Copyright (c) 2011 The Chromium Authors. All rights reserved.
 // Use of this source code is governed by a BSD-style license that can be
 // found in the LICENSE file.
 
 #include <vector>
 
 #include "base/memory/scoped_ptr.h"
 #include "base/string16.h"
 #include "base/time.h"
 #include "base/utf_string_conversions.h"
@@ skipping 160 matching lines @@
  private:
   std::string server_experiment_id_;
   DISALLOW_COPY_AND_ASSIGN(TestFormStructure);
 };
 
 class TestAutofillManager : public AutofillManager {
  public:
   TestAutofillManager(TabContentsWrapper* tab_contents,
                       TestPersonalDataManager* personal_manager)
       : AutofillManager(tab_contents, personal_manager),
-        autofill_enabled_(true) {
+        autofill_enabled_(true),
+        did_finish_async_form_submit_(false),
+        message_loop_is_running_(false) {
     set_metric_logger(new MockAutofillMetrics);
   }
-  virtual ~TestAutofillManager() {}
 
   virtual bool IsAutofillEnabled() const { return autofill_enabled_; }
 
   void set_autofill_enabled(bool autofill_enabled) {
     autofill_enabled_ = autofill_enabled;
   }
 
   MockAutofillMetrics* metric_logger() {
     return static_cast<MockAutofillMetrics*>(const_cast<AutofillMetrics*>(
         AutofillManager::metric_logger()));
   }
 
   void AddSeenForm(const FormData& form,
                    const std::vector<AutofillFieldType>& heuristic_types,
                    const std::vector<AutofillFieldType>& server_types,
                    const std::string& experiment_id) {
     FormData empty_form = form;
     for (size_t i = 0; i < empty_form.fields.size(); ++i) {
       empty_form.fields[i].value = string16();
     }
 
     // |form_structure| will be owned by |form_structures()|.
     TestFormStructure* form_structure = new TestFormStructure(empty_form);
     form_structure->SetFieldTypes(heuristic_types, server_types);
     form_structure->set_server_experiment_id(experiment_id);
     form_structures()->push_back(form_structure);
   }
 
+  void FormSubmitted(const FormData& form, const TimeTicks& timestamp) {
+    if (!OnFormSubmitted(form, timestamp))
+      return;
+
+    // Wait for the asynchronous FormSubmitted() call to complete.
+    if (!did_finish_async_form_submit_) {
+      // TODO(isherman): It seems silly to need this variable.  Is there some
+      // way I can just query the message loop's state?
+      message_loop_is_running_ = true;
+      MessageLoop::current()->Run();
+    } else {
+      did_finish_async_form_submit_ = false;
+    }
+  }
+
+  virtual void UploadFormDataAsyncCallback(
+      const FormStructure* submitted_form,
+      const base::TimeTicks& load_time,
+      const base::TimeTicks& interaction_time,
+      const base::TimeTicks& submission_time) OVERRIDE {
+    if (message_loop_is_running_) {
+      MessageLoop::current()->Quit();
+      message_loop_is_running_ = false;
+    } else {
+      did_finish_async_form_submit_ = true;
+    }
+
+    AutofillManager::UploadFormDataAsyncCallback(submitted_form,
+                                                 load_time,
+                                                 interaction_time,
+                                                 submission_time);
+  }
+
  private:
+  // AutofillManager is ref counted.
+  virtual ~TestAutofillManager() {}
+
   bool autofill_enabled_;
+  bool did_finish_async_form_submit_;
+  bool message_loop_is_running_;
 
   DISALLOW_COPY_AND_ASSIGN(TestAutofillManager);
 };
 
 }  // namespace
 
 class AutofillMetricsTest : public TabContentsWrapperTestHarness {
  public:
   AutofillMetricsTest();
   virtual ~AutofillMetricsTest();
 
-  virtual void SetUp();
+  virtual void SetUp() OVERRIDE;
+  virtual void TearDown() OVERRIDE;
 
  protected:
   AutofillCCInfoBarDelegate* CreateDelegate(MockAutofillMetrics* metric_logger,
                                             CreditCard** created_card);
 
-  scoped_ptr<TestAutofillManager> autofill_manager_;
+  content::TestBrowserThread ui_thread_;
+  content::TestBrowserThread file_thread_;
+
+  scoped_refptr<TestAutofillManager> autofill_manager_;
   TestPersonalDataManager personal_data_;
 
  private:
-  content::TestBrowserThread browser_thread_;
-
   DISALLOW_COPY_AND_ASSIGN(AutofillMetricsTest);
 };
 
 AutofillMetricsTest::AutofillMetricsTest()
   : TabContentsWrapperTestHarness(),
-    browser_thread_(BrowserThread::UI, &message_loop_) {
+    ui_thread_(BrowserThread::UI, &message_loop_),
+    file_thread_(BrowserThread::FILE) {
 }
 
 AutofillMetricsTest::~AutofillMetricsTest() {
   // Order of destruction is important as AutofillManager relies on
   // PersonalDataManager to be around when it gets destroyed.
-  autofill_manager_.reset(NULL);
+  autofill_manager_ = NULL;
 }
 
 void AutofillMetricsTest::SetUp() {
   Profile* profile = new TestingProfile();
   browser_context_.reset(profile);
   PersonalDataManagerFactory::GetInstance()->SetTestingFactory(
       profile, TestPersonalDataManager::Build);
 
   TabContentsWrapperTestHarness::SetUp();
-  autofill_manager_.reset(new TestAutofillManager(contents_wrapper(),
-                                                  &personal_data_));
+  autofill_manager_ = new TestAutofillManager(contents_wrapper(),
+                                              &personal_data_);
+
+  file_thread_.Start();
+}
+
+void AutofillMetricsTest::TearDown() {
+  file_thread_.Stop();
+  TabContentsWrapperTestHarness::TearDown();
 }
 
 AutofillCCInfoBarDelegate* AutofillMetricsTest::CreateDelegate(
     MockAutofillMetrics* metric_logger,
     CreditCard** created_card) {
   EXPECT_CALL(*metric_logger,
               LogCreditCardInfoBarMetric(AutofillMetrics::INFOBAR_SHOWN));
   // The delegate created below will take ownership of this object.
   CreditCard* credit_card = new CreditCard();
   if (created_card)
@@ skipping 142 matching lines @@
               LogOverallTypePrediction(AutofillMetrics::TYPE_MATCH,
                   PHONE_HOME_WHOLE_NUMBER, std::string()));
   EXPECT_CALL(*autofill_manager_->metric_logger(),
               LogQualityMetric(AutofillMetrics::FIELD_AUTOFILLED,
                                std::string()));
   EXPECT_CALL(*autofill_manager_->metric_logger(),
               LogUserHappinessMetric(
                   AutofillMetrics::SUBMITTED_FILLABLE_FORM_AUTOFILLED_SOME));
 
   // Simulate form submission.
-  EXPECT_NO_FATAL_FAILURE(autofill_manager_->OnFormSubmitted(form,
-                                                             TimeTicks::Now()));
+  EXPECT_NO_FATAL_FAILURE(autofill_manager_->FormSubmitted(form,
+                                                           TimeTicks::Now()));
 }
 
 // Test that we log the appropriate additional metrics when Autofill failed.
 TEST_F(AutofillMetricsTest, QualityMetricsForFailure) {
   // Set up our form data.
   FormData form;
   form.name = ASCIIToUTF16("TestForm");
   form.method = ASCIIToUTF16("POST");
   form.origin = GURL("http://example.com/form.html");
   form.action = GURL("http://example.com/submit.html");
@@ skipping 96 matching lines @@
                                  std::string()));
     EXPECT_CALL(*autofill_manager_->metric_logger(),
                 LogQualityMetric(failure_cases[i].heuristic_metric,
                                  std::string()));
     EXPECT_CALL(*autofill_manager_->metric_logger(),
                 LogQualityMetric(failure_cases[i].server_metric,
                                  std::string()));
   }
 
   // Simulate form submission.
-  EXPECT_NO_FATAL_FAILURE(autofill_manager_->OnFormSubmitted(form,
-                                                             TimeTicks::Now()));
+  EXPECT_NO_FATAL_FAILURE(autofill_manager_->FormSubmitted(form,
+                                                           TimeTicks::Now()));
 }
 
 // Test that we behave sanely when the cached form differs from the submitted
 // one.
 TEST_F(AutofillMetricsTest, SaneMetricsWithCacheMismatch) {
   // Set up our form data.
   FormData form;
   form.name = ASCIIToUTF16("TestForm");
   form.method = ASCIIToUTF16("POST");
   form.origin = GURL("http://example.com/form.html");
@@ skipping 136 matching lines @@
               LogServerTypePrediction(AutofillMetrics::TYPE_MATCH,
                   NAME_FULL, std::string()));
   EXPECT_CALL(*autofill_manager_->metric_logger(),
               LogOverallTypePrediction(AutofillMetrics::TYPE_MATCH,
                   NAME_FULL, std::string()));
   EXPECT_CALL(*autofill_manager_->metric_logger(),
               LogQualityMetric(AutofillMetrics::FIELD_AUTOFILLED,
                                std::string()));
 
   // Simulate form submission.
-  EXPECT_NO_FATAL_FAILURE(autofill_manager_->OnFormSubmitted(form,
-                                                             TimeTicks::Now()));
+  EXPECT_NO_FATAL_FAILURE(autofill_manager_->FormSubmitted(form,
+                                                           TimeTicks::Now()));
 }
 
 // Test that we don't log quality metrics for non-autofillable forms.
 TEST_F(AutofillMetricsTest, NoQualityMetricsForNonAutofillableForms) {
   // Forms must include at least three fields to be auto-fillable.
   FormData form;
   form.name = ASCIIToUTF16("TestForm");
   form.method = ASCIIToUTF16("POST");
   form.origin = GURL("http://example.com/form.html");
   form.action = GURL("http://example.com/submit.html");
   form.user_submitted = true;
 
   FormField field;
   autofill_test::CreateTestFormField(
       "Autofilled", "autofilled", "Elvis Presley", "text", &field);
   field.is_autofilled = true;
   form.fields.push_back(field);
   autofill_test::CreateTestFormField(
       "Autofill Failed", "autofillfailed", "buddy@gmail.com", "text", &field);
   form.fields.push_back(field);
 
   // Simulate form submission.
   EXPECT_CALL(*autofill_manager_->metric_logger(),
               LogQualityMetric(AutofillMetrics::FIELD_SUBMITTED,
                                std::string())).Times(0);
-  EXPECT_NO_FATAL_FAILURE(autofill_manager_->OnFormSubmitted(form,
-                                                             TimeTicks::Now()));
+  EXPECT_NO_FATAL_FAILURE(autofill_manager_->FormSubmitted(form,
+                                                           TimeTicks::Now()));
 
   // Search forms are not auto-fillable.
   form.action = GURL("http://example.com/search?q=Elvis%20Presley");
   autofill_test::CreateTestFormField(
       "Empty", "empty", "", "text", &field);
   form.fields.push_back(field);
 
   // Simulate form submission.
   EXPECT_CALL(*autofill_manager_->metric_logger(),
               LogQualityMetric(AutofillMetrics::FIELD_SUBMITTED,
                                std::string())).Times(0);
-  EXPECT_NO_FATAL_FAILURE(autofill_manager_->OnFormSubmitted(form,
-                                                             TimeTicks::Now()));
+  EXPECT_NO_FATAL_FAILURE(autofill_manager_->FormSubmitted(form,
+                                                           TimeTicks::Now()));
 }
 
 // Test that we recored the experiment id appropriately.
 TEST_F(AutofillMetricsTest, QualityMetricsWithExperimentId) {
   // Set up our form data.
   FormData form;
   form.name = ASCIIToUTF16("TestForm");
   form.method = ASCIIToUTF16("POST");
   form.origin = GURL("http://example.com/form.html");
   form.action = GURL("http://example.com/submit.html");
@@ skipping 104 matching lines @@
               LogHeuristicTypePrediction(AutofillMetrics::TYPE_UNKNOWN,
                                          ADDRESS_HOME_COUNTRY, experiment_id));
   EXPECT_CALL(*autofill_manager_->metric_logger(),
               LogServerTypePrediction(AutofillMetrics::TYPE_UNKNOWN,
                                       ADDRESS_HOME_COUNTRY, experiment_id));
   EXPECT_CALL(*autofill_manager_->metric_logger(),
               LogOverallTypePrediction(AutofillMetrics::TYPE_UNKNOWN,
                                        ADDRESS_HOME_COUNTRY, experiment_id));
 
   // Simulate form submission.
-  EXPECT_NO_FATAL_FAILURE(autofill_manager_->OnFormSubmitted(form,
-                                                             TimeTicks::Now()));
+  EXPECT_NO_FATAL_FAILURE(autofill_manager_->FormSubmitted(form,
+                                                           TimeTicks::Now()));
 }
 
 // Test that the profile count is logged correctly.
 TEST_F(AutofillMetricsTest, StoredProfileCount) {
   // The metric should be logged when the profiles are first loaded.
   EXPECT_CALL(*personal_data_.metric_logger(),
               LogStoredProfileCount(2)).Times(1);
   personal_data_.LoadProfiles();
 
   // The metric should only be logged once.
@@ skipping 222 matching lines @@
         LogUserHappinessMetric(
             AutofillMetrics::SUBMITTED_FILLABLE_FORM_AUTOFILLED_SOME)).Times(0);
     EXPECT_CALL(
         *autofill_manager_->metric_logger(),
         LogUserHappinessMetric(
             AutofillMetrics::SUBMITTED_FILLABLE_FORM_AUTOFILLED_NONE)).Times(0);
     EXPECT_CALL(
         *autofill_manager_->metric_logger(),
         LogUserHappinessMetric(
             AutofillMetrics::SUBMITTED_NON_FILLABLE_FORM)).Times(0);
-    autofill_manager_->OnFormSubmitted(form, TimeTicks::Now());
+    autofill_manager_->FormSubmitted(form, TimeTicks::Now());
   }
 
   // Add more fields to the form.
   autofill_test::CreateTestFormField("Phone", "phone", "", "text", &field);
   form.fields.push_back(field);
   autofill_test::CreateTestFormField("Unknown", "unknown", "", "text", &field);
   form.fields.push_back(field);
   forms.front() = form;
 
   // Expect a notification when the form is first seen.
   {
     EXPECT_CALL(*autofill_manager_->metric_logger(),
                 LogUserHappinessMetric(AutofillMetrics::FORMS_LOADED));
     autofill_manager_->OnFormsSeen(forms, TimeTicks());
   }
 
   // Expect a notification when the form is submitted.
   {
     EXPECT_CALL(*autofill_manager_->metric_logger(),
                 LogUserHappinessMetric(
                     AutofillMetrics::SUBMITTED_NON_FILLABLE_FORM));
-    autofill_manager_->OnFormSubmitted(form, TimeTicks::Now());
+    autofill_manager_->FormSubmitted(form, TimeTicks::Now());
   }
 
   // Fill in two of the fields.
   form.fields[0].value = ASCIIToUTF16("Elvis Aaron Presley");
   form.fields[1].value = ASCIIToUTF16("theking@gmail.com");
   forms.front() = form;
 
   // Expect a notification when the form is submitted.
   {
     EXPECT_CALL(*autofill_manager_->metric_logger(),
                 LogUserHappinessMetric(
                     AutofillMetrics::SUBMITTED_NON_FILLABLE_FORM));
-    autofill_manager_->OnFormSubmitted(form, TimeTicks::Now());
+    autofill_manager_->FormSubmitted(form, TimeTicks::Now());
   }
 
   // Fill in the third field.
   form.fields[2].value = ASCIIToUTF16("12345678901");
   forms.front() = form;
 
   // Expect notifications when the form is submitted.
   {
     EXPECT_CALL(*autofill_manager_->metric_logger(),
                 LogUserHappinessMetric(
                     AutofillMetrics::SUBMITTED_FILLABLE_FORM_AUTOFILLED_NONE));
-    autofill_manager_->OnFormSubmitted(form, TimeTicks::Now());
+    autofill_manager_->FormSubmitted(form, TimeTicks::Now());
   }
 
 
   // Mark one of the fields as autofilled.
   form.fields[1].is_autofilled = true;
   forms.front() = form;
 
   // Expect notifications when the form is submitted.
   {
     EXPECT_CALL(*autofill_manager_->metric_logger(),
                 LogUserHappinessMetric(
                     AutofillMetrics::SUBMITTED_FILLABLE_FORM_AUTOFILLED_SOME));
-    autofill_manager_->OnFormSubmitted(form, TimeTicks::Now());
+    autofill_manager_->FormSubmitted(form, TimeTicks::Now());
   }
 
   // Mark all of the fillable fields as autofilled.
   form.fields[0].is_autofilled = true;
   form.fields[2].is_autofilled = true;
   forms.front() = form;
 
   // Expect notifications when the form is submitted.
   {
     EXPECT_CALL(*autofill_manager_->metric_logger(),
                 LogUserHappinessMetric(
                     AutofillMetrics::SUBMITTED_FILLABLE_FORM_AUTOFILLED_ALL));
-    autofill_manager_->OnFormSubmitted(form, TimeTicks::Now());
+    autofill_manager_->FormSubmitted(form, TimeTicks::Now());
   }
 
   // Clear out the third field's value.
   form.fields[2].value = string16();
   forms.front() = form;
 
   // Expect notifications when the form is submitted.
   {
     EXPECT_CALL(*autofill_manager_->metric_logger(),
                 LogUserHappinessMetric(
                     AutofillMetrics::SUBMITTED_NON_FILLABLE_FORM));
-    autofill_manager_->OnFormSubmitted(form, TimeTicks::Now());
+    autofill_manager_->FormSubmitted(form, TimeTicks::Now());
   }
 }
 
 // Verify that we correctly log user happiness metrics dealing with form
 // interaction.
 TEST_F(AutofillMetricsTest, UserHappinessFormInteraction) {
   // Load a fillable form.
   FormData form;
   form.name = ASCIIToUTF16("TestForm");
   form.method = ASCIIToUTF16("POST");
@@ skipping 132 matching lines @@
     EXPECT_CALL(*autofill_manager_->metric_logger(),
                 LogFormFillDurationFromLoadWithAutofill(_)).Times(0);
     EXPECT_CALL(*autofill_manager_->metric_logger(),
                 LogFormFillDurationFromLoadWithoutAutofill(
                     TimeDelta::FromInternalValue(16)));
     EXPECT_CALL(*autofill_manager_->metric_logger(),
                 LogFormFillDurationFromInteractionWithAutofill(_)).Times(0);
     EXPECT_CALL(*autofill_manager_->metric_logger(),
                 LogFormFillDurationFromInteractionWithoutAutofill(_)).Times(0);
     autofill_manager_->OnFormsSeen(forms, TimeTicks::FromInternalValue(1));
-    autofill_manager_->OnFormSubmitted(form, TimeTicks::FromInternalValue(17));
+    autofill_manager_->FormSubmitted(form, TimeTicks::FromInternalValue(17));
     autofill_manager_->Reset();
     Mock::VerifyAndClearExpectations(autofill_manager_->metric_logger());
   }
 
   // Expect metric to be logged if the user manually edited a form field.
   {
     EXPECT_CALL(*autofill_manager_->metric_logger(),
                 LogFormFillDurationFromLoadWithAutofill(_)).Times(0);
     EXPECT_CALL(*autofill_manager_->metric_logger(),
                 LogFormFillDurationFromLoadWithoutAutofill(
                     TimeDelta::FromInternalValue(16)));
     EXPECT_CALL(*autofill_manager_->metric_logger(),
                 LogFormFillDurationFromInteractionWithAutofill(_)).Times(0);
     EXPECT_CALL(*autofill_manager_->metric_logger(),
                 LogFormFillDurationFromInteractionWithoutAutofill(
                     TimeDelta::FromInternalValue(14)));
     autofill_manager_->OnFormsSeen(forms, TimeTicks::FromInternalValue(1));
     autofill_manager_->OnTextFieldDidChange(form, form.fields.front(),
                                             TimeTicks::FromInternalValue(3));
-    autofill_manager_->OnFormSubmitted(form, TimeTicks::FromInternalValue(17));
+    autofill_manager_->FormSubmitted(form, TimeTicks::FromInternalValue(17));
     autofill_manager_->Reset();
     Mock::VerifyAndClearExpectations(autofill_manager_->metric_logger());
   }
 
   // Expect metric to be logged if the user autofilled the form.
   form.fields[0].is_autofilled = true;
   {
     EXPECT_CALL(*autofill_manager_->metric_logger(),
                 LogFormFillDurationFromLoadWithAutofill(
                     TimeDelta::FromInternalValue(16)));
     EXPECT_CALL(*autofill_manager_->metric_logger(),
                 LogFormFillDurationFromLoadWithoutAutofill(_)).Times(0);
     EXPECT_CALL(*autofill_manager_->metric_logger(),
                 LogFormFillDurationFromInteractionWithAutofill(
                     TimeDelta::FromInternalValue(12)));
     EXPECT_CALL(*autofill_manager_->metric_logger(),
                 LogFormFillDurationFromInteractionWithoutAutofill(_)).Times(0);
     autofill_manager_->OnFormsSeen(forms, TimeTicks::FromInternalValue(1));
     autofill_manager_->OnDidFillAutofillFormData(
         TimeTicks::FromInternalValue(5));
-    autofill_manager_->OnFormSubmitted(form, TimeTicks::FromInternalValue(17));
+    autofill_manager_->FormSubmitted(form, TimeTicks::FromInternalValue(17));
     autofill_manager_->Reset();
     Mock::VerifyAndClearExpectations(autofill_manager_->metric_logger());
   }
 
   // Expect metric to be logged if the user both manually filled some fields
   // and autofilled others.  Messages can arrive out of order, so make sure they
   // take precedence appropriately.
   {
     EXPECT_CALL(*autofill_manager_->metric_logger(),
                 LogFormFillDurationFromLoadWithAutofill(
                     TimeDelta::FromInternalValue(16)));
     EXPECT_CALL(*autofill_manager_->metric_logger(),
                 LogFormFillDurationFromLoadWithoutAutofill(_)).Times(0);
     EXPECT_CALL(*autofill_manager_->metric_logger(),
                 LogFormFillDurationFromInteractionWithAutofill(
                     TimeDelta::FromInternalValue(14)));
     EXPECT_CALL(*autofill_manager_->metric_logger(),
                 LogFormFillDurationFromInteractionWithoutAutofill(_)).Times(0);
     autofill_manager_->OnFormsSeen(forms, TimeTicks::FromInternalValue(1));
     autofill_manager_->OnDidFillAutofillFormData(
         TimeTicks::FromInternalValue(5));
     autofill_manager_->OnTextFieldDidChange(form, form.fields.front(),
                                             TimeTicks::FromInternalValue(3));
-    autofill_manager_->OnFormSubmitted(form, TimeTicks::FromInternalValue(17));
+    autofill_manager_->FormSubmitted(form, TimeTicks::FromInternalValue(17));
     autofill_manager_->Reset();
     Mock::VerifyAndClearExpectations(autofill_manager_->metric_logger());
   }
 
   // Restore the global Gmock verbosity level to its default value.
   ::testing::FLAGS_gmock_verbose = "warning";
 }