Password manager: introduce logging for the internals page

components/password_manager/core/browser/password_manager.cc

Index: components/password_manager/core/browser/password_manager.cc
diff --git a/components/password_manager/core/browser/password_manager.cc b/components/password_manager/core/browser/password_manager.cc
index ebb3e38f6a464f29de1afc8f5af389ad6c7b60f4..89a940b1653b75dd7631537ddb7fad1c30f9a64b 100644
--- a/components/password_manager/core/browser/password_manager.cc
+++ b/components/password_manager/core/browser/password_manager.cc
@@ -12,6 +12,7 @@
 #include "base/strings/utf_string_conversions.h"
 #include "base/threading/platform_thread.h"
 #include "components/autofill/core/common/password_autofill_util.h"
+#include "components/password_manager/core/browser/browser_save_password_progress_logger.h"
 #include "components/password_manager/core/browser/password_form_manager.h"
 #include "components/password_manager/core/browser/password_manager_client.h"
 #include "components/password_manager/core/browser/password_manager_driver.h"
@@ -28,6 +29,10 @@ namespace {
 
 const char kSpdyProxyRealm[] = "/SpdyProxy";
 
+// Shorten the name to spare line breaks. The code provides enough context
+// already.
+typedef autofill::SavePasswordProgressLogger Logger;
+
 // This routine is called when PasswordManagers are constructed.
 //
 // Currently we report metrics only once at startup. We require
@@ -108,14 +113,25 @@ bool PasswordManager::IsSavingEnabled() const {
 }
 
 void PasswordManager::ProvisionallySavePassword(const PasswordForm& form) {
-  if (!IsSavingEnabled()) {
-    RecordFailure(SAVING_DISABLED, form.origin.host());
+  bool is_saving_enabled = IsSavingEnabled();
+
+  scoped_ptr<BrowserSavePasswordProgressLogger> logger;
+  if (client_->IsLoggingActive()) {
+    logger.reset(new BrowserSavePasswordProgressLogger(client_));
+    logger->LogMessage(Logger::STRING_PROVISIONALLY_SAVE_PASSWORD_METHOD);
+    logger->LogPasswordForm(Logger::STRING_PROVISIONALLY_SAVE_PASSWORD_FORM,
+                            form);
+    logger->LogBoolean(Logger::STRING_IS_SAVING_ENABLED, is_saving_enabled);
+  }
+
+  if (!is_saving_enabled) {
+    RecordFailure(SAVING_DISABLED, form.origin.host(), logger.get());
     return;
   }
 
   // No password to save? Then don't.
   if (form.password_value.empty()) {
-    RecordFailure(EMPTY_PASSWORD, form.origin.host());
+    RecordFailure(EMPTY_PASSWORD, form.origin.host(), logger.get());
     return;
   }
 
@@ -129,6 +145,8 @@ void PasswordManager::ProvisionallySavePassword(const PasswordForm& form) {
     if ((*iter)->DoesManage(form, PasswordFormManager::ACTION_MATCH_REQUIRED)) {
       // If we find a manager that exactly matches the submitted form including
       // the action URL, exit the loop.
+      if (logger)
+        logger->LogMessage(Logger::STRING_EXACT_MATCH);
       matched_manager_it = iter;
       break;
     } else if ((*iter)->DoesManage(
@@ -136,6 +154,8 @@ void PasswordManager::ProvisionallySavePassword(const PasswordForm& form) {
       // If the current manager matches the submitted form excluding the action
       // URL, remember it as a candidate and continue searching for an exact
       // match.
+      if (logger)
+        logger->LogMessage(Logger::STRING_MATCH_WITHOUT_ACTION);
       matched_manager_it = iter;
     }
   }
@@ -148,7 +168,7 @@ void PasswordManager::ProvisionallySavePassword(const PasswordForm& form) {
     manager.reset(*matched_manager_it);
     pending_login_managers_.weak_erase(matched_manager_it);
   } else {
-    RecordFailure(NO_MATCHING_FORM, form.origin.host());
+    RecordFailure(NO_MATCHING_FORM, form.origin.host(), logger.get());
     return;
   }
 
@@ -157,20 +177,20 @@ void PasswordManager::ProvisionallySavePassword(const PasswordForm& form) {
   // results for the given form and autofill. If this is the case, we just
   // give up.
   if (!manager->HasCompletedMatching()) {
-    RecordFailure(MATCHING_NOT_COMPLETE, form.origin.host());
+    RecordFailure(MATCHING_NOT_COMPLETE, form.origin.host(), logger.get());
     return;
   }
 
   // Also get out of here if the user told us to 'never remember' passwords for
   // this form.
   if (manager->IsBlacklisted()) {
-    RecordFailure(FORM_BLACKLISTED, form.origin.host());
+    RecordFailure(FORM_BLACKLISTED, form.origin.host(), logger.get());
     return;
   }
 
   // Bail if we're missing any of the necessary form components.
   if (!manager->HasValidPasswordForm()) {
-    RecordFailure(INVALID_FORM, form.origin.host());
+    RecordFailure(INVALID_FORM, form.origin.host(), logger.get());
     return;
   }
 
@@ -179,7 +199,7 @@ void PasswordManager::ProvisionallySavePassword(const PasswordForm& form) {
   // autocomplete attribute if autocomplete='off' is not ignored.
   if (!autofill::ShouldIgnoreAutocompleteOffForPasswordFields() &&
       !manager->HasGeneratedPassword() && !form.password_autocomplete_set) {
-    RecordFailure(AUTOCOMPLETE_OFF, form.origin.host());
+    RecordFailure(AUTOCOMPLETE_OFF, form.origin.host(), logger.get());
     return;
   }
 
@@ -188,16 +208,26 @@ void PasswordManager::ProvisionallySavePassword(const PasswordForm& form) {
       form.origin.SchemeIsSecure() &&
       !driver_->DidLastPageLoadEncounterSSLErrors();
   provisionally_saved_form.preferred = true;
+  if (logger) {
+    logger->LogPasswordForm(Logger::STRING_PROVISIONALLY_SAVED_FORM,
+                            provisionally_saved_form);
+  }
   PasswordFormManager::OtherPossibleUsernamesAction action =
       PasswordFormManager::IGNORE_OTHER_POSSIBLE_USERNAMES;
   if (OtherPossibleUsernamesEnabled())
     action = PasswordFormManager::ALLOW_OTHER_POSSIBLE_USERNAMES;
+  if (logger) {
+    logger->LogBoolean(
+        Logger::STRING_IGNORE_POSSIBLE_USERNAMES,
+        action == PasswordFormManager::IGNORE_OTHER_POSSIBLE_USERNAMES);
+  }
   manager->ProvisionallySave(provisionally_saved_form, action);
   provisional_save_manager_.swap(manager);
 }
 
 void PasswordManager::RecordFailure(ProvisionalSaveFailure failure,
-                                    const std::string& form_origin) {
+                                    const std::string& form_origin,
+                                    BrowserSavePasswordProgressLogger* logger) {
   UMA_HISTOGRAM_ENUMERATION(
       "PasswordManager.ProvisionalSaveFailure", failure, MAX_FAILURE_VALUE);
 
@@ -209,6 +239,35 @@ void PasswordManager::RecordFailure(ProvisionalSaveFailure failure,
         failure,
         MAX_FAILURE_VALUE);
   }
+
+  if (logger) {
+    bool log_decision_drop = true;
+    switch (failure) {
+      case SAVING_DISABLED:
+        logger->LogMessage(Logger::STRING_SAVING_DISABLED);
+        break;
+      case EMPTY_PASSWORD:
+        logger->LogMessage(Logger::STRING_EMPTY_PASSWORD);
+        break;
+      case MATCHING_NOT_COMPLETE:
+        logger->LogMessage(Logger::STRING_NO_FORM_MANAGER);
+        break;
+      case FORM_BLACKLISTED:
+        logger->LogMessage(Logger::STRING_FORM_BLACKLISTED);
+        break;
+      case INVALID_FORM:
+        logger->LogMessage(Logger::STRING_INVALID_FORM);
+        break;
+      case AUTOCOMPLETE_OFF:
+        logger->LogMessage(Logger::STRING_AUTOCOMPLETE_OFF);
+        break;
+      default:

[Ilya Sherman, 2014/04/25 00:48:45]

I'd prefer if you directly listed NO_MATCHING_FORM and MAX_FAILURE_VALUE as
explicit cases.  That way, if any new provisional save failure reasons are added
in the future, the compiler will remind the code author to update this code. 
(For MAX_FAILURE_VALUE, I would have a NOTREACHED().)

[vabr (Chromium), 2014/04/25 09:38:47]

Good idea.
Reminded me that I actually also need to log a message for NO_MATCHING_FORM,
thanks! :)
Done.

+        log_decision_drop = false;
+        break;
+    }
+    if (log_decision_drop)
+      logger->LogMessage(Logger::STRING_DECISION_DROP);
+  }
 }
 
 void PasswordManager::AddSubmissionCallback(
@@ -277,11 +336,27 @@ bool PasswordManager::ShouldPromptUserToSavePassword() const {
 
 void PasswordManager::OnPasswordFormsRendered(
     const std::vector<PasswordForm>& visible_forms) {
-  if (!provisional_save_manager_.get())
+  scoped_ptr<BrowserSavePasswordProgressLogger> logger;
+  if (client_->IsLoggingActive()) {
+    logger.reset(new BrowserSavePasswordProgressLogger(client_));
+    logger->LogMessage(Logger::STRING_ON_PASSWORD_FORMS_RENDERED_METHOD);
+  }
+
+  if (!provisional_save_manager_.get()) {
+    if (logger) {
+      logger->LogMessage(Logger::STRING_NO_PROVISIONAL_SAVE_MANAGER);
+      logger->LogMessage(Logger::STRING_DECISION_DROP);
+    }
     return;
+  }
 
   DCHECK(IsSavingEnabled());
 
+  if (logger) {
+    logger->LogNumber(Logger::STRING_NUMBER_OF_VISIBLE_FORMS,
+                      visible_forms.size());
+  }
+
   // If we see the login form again, then the login failed.
   for (size_t i = 0; i < visible_forms.size(); ++i) {
     // TODO(vabr): The similarity check is just action equality for now. If it
@@ -290,6 +365,11 @@ void PasswordManager::OnPasswordFormsRendered(
     if (visible_forms[i].action.is_valid() &&
         provisional_save_manager_->pending_credentials().action ==
             visible_forms[i].action) {
+      if (logger) {
+        logger->LogPasswordForm(Logger::STRING_PASSWORD_FORM_REAPPEARED,
+                                visible_forms[i]);
+        logger->LogMessage(Logger::STRING_DECISION_DROP);
+      }
       provisional_save_manager_->SubmitFailed();
       provisional_save_manager_.reset();
       return;
@@ -303,8 +383,12 @@ void PasswordManager::OnPasswordFormsRendered(
   provisional_save_manager_->SubmitPassed();
 
   if (ShouldPromptUserToSavePassword()) {
+    if (logger)
+      logger->LogMessage(Logger::STRING_DECISION_ASK);
     client_->PromptUserToSavePassword(provisional_save_manager_.release());
   } else {
+    if (logger)
+      logger->LogMessage(Logger::STRING_DECISION_SAVE);
     provisional_save_manager_->Save();
     provisional_save_manager_.reset();
   }