Added file to track login times, and moved functionality to boot_times_loader.

BUG=chromium-os:4727
TEST=None

Review URL: http://codereview.chromium.org/2858061

git-svn-id: svn://svn.chromium.org/chrome/trunk/src@53192 0039d316-1c4b-4281-b951-d872f2087c98

11 files changed, 139 insertions, 179 deletions

diff --git a/chrome/app/chrome_dll_main.cc b/chrome/app/chrome_dll_main.cc
index 57669a4..034b82d 100644
--- a/chrome/app/chrome_dll_main.cc
+++ b/chrome/app/chrome_dll_main.cc
@@ -443,7 +443,7 @@ DLLEXPORT int __cdecl ChromeMain(HINSTANCE instance,
 int ChromeMain(int argc, char** argv) {
 #endif
 #if defined(OS_CHROMEOS)
-  chromeos::BootTimesLoader::SaveChromeMainStats();
+  chromeos::BootTimesLoader::Get()->SaveChromeMainStats();
 #endif
 #if defined(OS_MACOSX)
   // TODO(mark): Some of these things ought to be handled in chrome_exe_main.mm.
diff --git a/chrome/browser/browser_init.cc b/chrome/browser/browser_init.cc
index e9c2087..1832960 100644
--- a/chrome/browser/browser_init.cc
+++ b/chrome/browser/browser_init.cc
@@ -69,7 +69,6 @@
 #endif
 
 #if defined(OS_CHROMEOS)
-#include "chrome/browser/chromeos/browser_notification_observers.h"
 #include "chrome/browser/chromeos/cros/cros_library.h"
 #include "chrome/browser/chromeos/cros/mount_library.h"
 #include "chrome/browser/chromeos/cros/network_library.h"
@@ -380,14 +379,6 @@ bool BrowserInit::LaunchBrowser(
   in_startup = process_startup;
   DCHECK(profile);
 
-  // This forces the creation of the initial tavb notification observer
-  // singleton.  It must be created before browser launch to catch first tab
-  // load.
-#if defined(OS_CHROMEOS)
-  if (process_startup)
-    chromeos::InitialTabNotificationObserver::Get();
-#endif
-
 #if defined(OS_WIN)
   // Disable the DPI-virtualization mode of Windows Vista or later because it
   // causes some problems when using system messages (such as WM_NCHITTEST and
diff --git a/chrome/browser/browser_main.cc b/chrome/browser/browser_main.cc
index 265fec1..8be27d2 100644
--- a/chrome/browser/browser_main.cc
+++ b/chrome/browser/browser_main.cc
@@ -907,7 +907,7 @@ int BrowserMain(const MainFunctionParams& parameters) {
 
 #if defined(OS_CHROMEOS)
   // Now that the file thread exists we can record our stats.
-  chromeos::BootTimesLoader::RecordChromeMainStats();
+  chromeos::BootTimesLoader::Get()->RecordChromeMainStats();
 #endif
 
   // Record last shutdown time into a histogram.
diff --git a/chrome/browser/chromeos/boot_times_loader.cc b/chrome/browser/chromeos/boot_times_loader.cc
index 8ae86d6..acdadce 100644
--- a/chrome/browser/chromeos/boot_times_loader.cc
+++ b/chrome/browser/chromeos/boot_times_loader.cc
@@ -12,23 +12,16 @@
 #include "base/histogram.h"
 #include "base/message_loop.h"
 #include "base/process_util.h"
+#include "base/singleton.h"
 #include "base/string_util.h"
 #include "base/thread.h"
 #include "base/time.h"
 #include "chrome/browser/browser_process.h"
 #include "chrome/browser/chrome_thread.h"
+#include "chrome/browser/chromeos/login/authentication_notification_details.h"
+#include "chrome/browser/chromeos/network_state_notifier.h"
 #include "chrome/common/chrome_switches.h"
-
-namespace {
-
-struct Stats {
-  std::string uptime;
-  std::string disk;
-
-  Stats() : uptime(std::string()), disk(std::string()) {}
-};
-
-}
+#include "chrome/common/notification_service.h"
 
 namespace chromeos {
 
@@ -43,7 +36,25 @@ static const char kChromeMain[] = "chrome-main";
 // Delay in milliseconds between file read attempts.
 static const int64 kReadAttemptDelayMs = 250;
 
-BootTimesLoader::BootTimesLoader() : backend_(new Backend()) {
+// Names of login stats files.
+static const char kLoginSuccess[] = "login-success";
+static const char kChromeFirstRender[] = "chrome-first-render";
+
+// Names of login UMA values.
+static const char kUmaAuthenticate[] = "BootTime.Authenticate";
+static const char kUmaLogin[] = "BootTime.Login";
+
+// Name of file collecting login times.
+static const char kLoginTimes[] = "login-times-sent";
+
+BootTimesLoader::BootTimesLoader()
+    : backend_(new Backend()),
+      have_registered_(false) {
+}
+
+// static
+BootTimesLoader* BootTimesLoader::Get() {
+  return Singleton<BootTimesLoader>::get();
 }
 
 BootTimesLoader::Handle BootTimesLoader::GetBootTimes(
@@ -202,14 +213,28 @@ static void RecordStatsDelayed(
     file_util::WriteFile(disk_output, disk.data(), disk.size());
 }
 
-static void RecordStats(
-    const std::string& name, const Stats& stats) {
+static void WriteLoginTimes(
+    base::Time login_attempt,
+    base::Time login_success,
+    base::Time chrome_first_render) {
+  const FilePath log_path(kLogPath);
+  std::string output =
+      StringPrintf("total: %.2f\nauth: %.2f\nlogin: %.2f\n",
+          (chrome_first_render - login_attempt).InSecondsF(),
+          (login_success - login_attempt).InSecondsF(),
+          (chrome_first_render - login_success).InSecondsF());
+  file_util::WriteFile(
+      log_path.Append(kLoginTimes), output.data(), output.size());
+}
+
+void BootTimesLoader::RecordStats(const std::string& name, const Stats& stats) {
   ChromeThread::PostTask(
       ChromeThread::FILE, FROM_HERE,
-      NewRunnableFunction(RecordStatsDelayed, name, stats.uptime, stats.disk));
+      NewRunnableFunction(
+          RecordStatsDelayed, name, stats.uptime, stats.disk));
 }
 
-static Stats GetCurrentStats() {
+BootTimesLoader::Stats BootTimesLoader::GetCurrentStats() {
   const FilePath kProcUptime("/proc/uptime");
   const FilePath kDiskStat("/sys/block/sda/stat");
   Stats stats;
@@ -219,15 +244,10 @@ static Stats GetCurrentStats() {
   return stats;
 }
 
-// static
 void BootTimesLoader::RecordCurrentStats(const std::string& name) {
-  Stats stats = GetCurrentStats();
-  RecordStats(name, stats);
+  RecordStats(name, GetCurrentStats());
 }
 
-// Used to hold the stats at main().
-static Stats chrome_main_stats_;
-
 void BootTimesLoader::SaveChromeMainStats() {
   chrome_main_stats_ = GetCurrentStats();
 }
@@ -236,4 +256,51 @@ void BootTimesLoader::RecordChromeMainStats() {
   RecordStats(kChromeMain, chrome_main_stats_);
 }
 
+void BootTimesLoader::RecordLoginAttempted() {
+  login_attempt_ = base::Time::NowFromSystemTime();
+  if (!have_registered_) {
+    have_registered_ = true;
+    registrar_.Add(this, NotificationType::LOAD_START,
+                   NotificationService::AllSources());
+    registrar_.Add(this, NotificationType::LOGIN_AUTHENTICATION,
+                   NotificationService::AllSources());
+  }
+}
+
+void BootTimesLoader::Observe(
+    NotificationType type,
+    const NotificationSource& source,
+    const NotificationDetails& details) {
+  if (type == NotificationType::LOGIN_AUTHENTICATION) {
+    Details<AuthenticationNotificationDetails> auth_details(details);
+    if (!login_attempt_.is_null() && auth_details->success()) {
+      login_success_ = base::Time::NowFromSystemTime();
+      RecordCurrentStats(kLoginSuccess);
+      UMA_HISTOGRAM_TIMES(kUmaAuthenticate, login_success_ - login_attempt_);
+      registrar_.Remove(this, NotificationType::LOGIN_AUTHENTICATION,
+                        NotificationService::AllSources());
+    }
+  } else if (type == NotificationType::LOAD_START) {
+    // Only log for first tab to render.  Make sure this is only done once.
+    // If the network isn't connected we'll get a second LOAD_START once it is
+    // and the page is reloaded.
+    if (!login_success_.is_null() &&
+        NetworkStateNotifier::Get()->is_connected()) {
+      // Post difference between first tab and login success time.
+      chrome_first_render_ = base::Time::NowFromSystemTime();
+      RecordCurrentStats(kChromeFirstRender);
+      UMA_HISTOGRAM_TIMES(kUmaLogin, chrome_first_render_ - login_success_);
+      // Post chrome first render stat.
+      registrar_.Remove(this, NotificationType::LOAD_START,
+                        NotificationService::AllSources());
+      ChromeThread::PostTask(
+          ChromeThread::FILE, FROM_HERE,
+          NewRunnableFunction(
+              WriteLoginTimes,
+              login_attempt_, login_success_, chrome_first_render_));
+      have_registered_ = false;
+    }
+  }
+}
+
 }  // namespace chromeos
diff --git a/chrome/browser/chromeos/boot_times_loader.h b/chrome/browser/chromeos/boot_times_loader.h
index 66a663d..143e425 100644
--- a/chrome/browser/chromeos/boot_times_loader.h
+++ b/chrome/browser/chromeos/boot_times_loader.h
@@ -7,8 +7,12 @@
 
 #include <string>
 
+#include "base/atomic_sequence_num.h"
 #include "base/callback.h"
+#include "base/time.h"
 #include "chrome/browser/cancelable_request.h"
+#include "chrome/common/notification_observer.h"
+#include "chrome/common/notification_registrar.h"
 
 namespace chromeos {
 
@@ -23,7 +27,9 @@ namespace chromeos {
 //   void OnBootTimesLoader(chromeos::BootTimesLoader::Handle,
 //                             BootTimesLoader::BootTimes boot_times);
 // . When you want the version invoke: loader.GetBootTimes(&consumer, callback);
-class BootTimesLoader : public CancelableRequestProvider {
+class BootTimesLoader
+    : public CancelableRequestProvider,
+      public NotificationObserver {
  public:
   BootTimesLoader();
 
@@ -55,6 +61,8 @@ class BootTimesLoader : public CancelableRequestProvider {
 
   typedef CancelableRequest<GetBootTimesCallback> GetBootTimesRequest;
 
+  static BootTimesLoader* Get();
+
   // Asynchronously requests the info.
   Handle GetBootTimes(
       CancelableRequestConsumerBase* consumer,
@@ -64,15 +72,24 @@ class BootTimesLoader : public CancelableRequestProvider {
   // Posts task to file thread.
   // name will be used as part of file names in /tmp.
   // Existing stats files will not be overwritten.
-  static void RecordCurrentStats(const std::string& name);
+  void RecordCurrentStats(const std::string& name);
 
   // Saves away the stats at main, so the can be recorded later. At main() time
   // the necessary threads don't exist yet for recording the data.
-  static void SaveChromeMainStats();
+  void SaveChromeMainStats();
 
   // Records the data previously saved by SaveChromeMainStats(), using the
   // file thread. Existing stats files will not be overwritten.
-  static void RecordChromeMainStats();
+  void RecordChromeMainStats();
+
+  // Records the time that a login was attempted. This will overwrite any
+  // previous login attempt times.
+  void RecordLoginAttempted();
+
+  // NotificationObserver implementation.
+  virtual void Observe(NotificationType type,
+                       const NotificationSource& source,
+                       const NotificationDetails& details);
 
  private:
   // BootTimesLoader calls into the Backend on the file thread to load
@@ -91,8 +108,31 @@ class BootTimesLoader : public CancelableRequestProvider {
     DISALLOW_COPY_AND_ASSIGN(Backend);
   };
 
+  struct Stats {
+    std::string uptime;
+    std::string disk;
+
+    Stats() : uptime(std::string()), disk(std::string()) {}
+  };
+
+  static void RecordStats(
+      const std::string& name, const Stats& stats);
+  static Stats GetCurrentStats();
+
+  // Used to hold the stats at main().
+  Stats chrome_main_stats_;
   scoped_refptr<Backend> backend_;
 
+  // Times for authentication and login metrics.
+  base::Time login_attempt_;
+  base::Time login_success_;
+  base::Time chrome_first_render_;
+
+  // Used to track notifications for login.
+  NotificationRegistrar registrar_;
+  base::AtomicSequenceNumber num_tabs_;
+  bool have_registered_;
+
   DISALLOW_COPY_AND_ASSIGN(BootTimesLoader);
 };
 
diff --git a/chrome/browser/chromeos/browser_notification_observers.cc b/chrome/browser/chromeos/browser_notification_observers.cc
deleted file mode 100644
index 3f06fb5..0000000
--- a/chrome/browser/chromeos/browser_notification_observers.cc
+++ /dev/null
@@ -1,63 +0,0 @@
-// Copyright (c) 2010 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 "chrome/browser/chromeos/browser_notification_observers.h"
-
-#include <string>
-
-#include "base/file_util.h"
-#include "base/histogram.h"
-#include "chrome/browser/chrome_thread.h"
-#include "chrome/browser/chromeos/boot_times_loader.h"
-#include "chrome/browser/chromeos/login/authentication_notification_details.h"
-#include "chrome/common/notification_service.h"
-
-namespace chromeos {
-
-InitialTabNotificationObserver::InitialTabNotificationObserver() {
-  registrar_.Add(this, NotificationType::LOAD_START,
-                 NotificationService::AllSources());
-}
-
-InitialTabNotificationObserver::~InitialTabNotificationObserver() {
-}
-
-void InitialTabNotificationObserver::Observe(
-    NotificationType type,
-    const NotificationSource& source,
-    const NotificationDetails& details) {
-  // Only log for first tab to render.  Make sure this is only done once.
-  if (type == NotificationType::LOAD_START && num_tabs_.GetNext() == 0) {
-    // Post difference between first tab and login succeess time as login time.
-    UMA_HISTOGRAM_TIMES("BootTime.Login",
-                        base::Time::NowFromSystemTime() - login_success_time_);
-    // Post chrome first render stat.
-    BootTimesLoader::RecordCurrentStats("chrome-first-render");
-    registrar_.Remove(this, NotificationType::LOAD_START,
-                      NotificationService::AllSources());
-  }
-}
-
-LogLoginSuccessObserver::LogLoginSuccessObserver() {
-  registrar_.Add(this, NotificationType::LOGIN_AUTHENTICATION,
-                 NotificationService::AllSources());
-}
-
-LogLoginSuccessObserver::~LogLoginSuccessObserver() {
-}
-
-void LogLoginSuccessObserver::Observe(NotificationType type,
-                                   const NotificationSource& source,
-                                   const NotificationDetails& details) {
-  DCHECK(type == NotificationType::LOGIN_AUTHENTICATION);
-  Details<AuthenticationNotificationDetails> auth_details(details);
-  if (auth_details->success()) {
-    InitialTabNotificationObserver::Get()->SetLoginSuccessTime();
-    BootTimesLoader::RecordCurrentStats("login-successful");
-    registrar_.Remove(this, NotificationType::LOGIN_AUTHENTICATION,
-                      NotificationService::AllSources());
-  }
-}
-
-}  // namespace chromeos
diff --git a/chrome/browser/chromeos/browser_notification_observers.h b/chrome/browser/chromeos/browser_notification_observers.h
deleted file mode 100644
index 13dacce..0000000
--- a/chrome/browser/chromeos/browser_notification_observers.h
+++ /dev/null
@@ -1,70 +0,0 @@
-// Copyright (c) 2010 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.
-
-#ifndef CHROME_BROWSER_CHROMEOS_BROWSER_NOTIFICATION_OBSERVERS_H_
-#define CHROME_BROWSER_CHROMEOS_BROWSER_NOTIFICATION_OBSERVERS_H_
-
-#include "base/atomic_sequence_num.h"
-#include "base/singleton.h"
-#include "base/time.h"
-#include "chrome/common/notification_observer.h"
-#include "chrome/common/notification_registrar.h"
-#include "chrome/common/notification_source.h"
-#include "chrome/common/notification_type.h"
-
-// Global notification observers for chrome os.
-namespace chromeos {
-
-// Notification observer to log the initial time of when the first tab
-// page is rendered for Chrome OS.
-class InitialTabNotificationObserver : public NotificationObserver {
- public:
-  InitialTabNotificationObserver();
-  virtual ~InitialTabNotificationObserver();
-
-  static InitialTabNotificationObserver* Get() {
-    return Singleton<InitialTabNotificationObserver>::get();
-  }
-
-  void SetLoginSuccessTime() {
-    login_success_time_ = base::Time::NowFromSystemTime();
-  }
-
-  // NotificationObserver implementation.
-  virtual void Observe(NotificationType type,
-                       const NotificationSource& source,
-                       const NotificationDetails& details);
-
- private:
-  NotificationRegistrar registrar_;
-  base::AtomicSequenceNumber num_tabs_;
-  base::Time login_success_time_;
-
-  DISALLOW_COPY_AND_ASSIGN(InitialTabNotificationObserver);
-};
-
-// Collects LOGIN_AUTHENTICATION notifications and logs uptime
-// when login was successful.
-class LogLoginSuccessObserver : public NotificationObserver {
- public:
-   LogLoginSuccessObserver();
-   virtual ~LogLoginSuccessObserver();
-
-   static LogLoginSuccessObserver* Get() {
-     return Singleton<LogLoginSuccessObserver>::get();
-   }
-
-  // NotificationObserver interface.
-  virtual void Observe(NotificationType type, const NotificationSource& source,
-                       const NotificationDetails& details);
-
- private:
-  NotificationRegistrar registrar_;
-
-  DISALLOW_COPY_AND_ASSIGN(LogLoginSuccessObserver);
-};
-
-}  // namespace chromeos
-
-#endif  // CHROME_BROWSER_CHROMEOS_BROWSER_NOTIFICATION_OBSERVERS_H_
diff --git a/chrome/browser/chromeos/login/existing_user_controller.cc b/chrome/browser/chromeos/login/existing_user_controller.cc
index 14eb9d8..5e6abeb 100644
--- a/chrome/browser/chromeos/login/existing_user_controller.cc
+++ b/chrome/browser/chromeos/login/existing_user_controller.cc
@@ -15,6 +15,7 @@
 #include "base/utf_string_conversions.h"
 #include "chrome/browser/browser_process.h"
 #include "chrome/browser/chrome_thread.h"
+#include "chrome/browser/chromeos/boot_times_loader.h"
 #include "chrome/browser/chromeos/cros/cros_library.h"
 #include "chrome/browser/chromeos/cros/login_library.h"
 #include "chrome/browser/chromeos/cros/network_library.h"
@@ -166,6 +167,7 @@ void ExistingUserController::SendSetLoginState(bool is_enabled) {
 
 void ExistingUserController::Login(UserController* source,
                                    const string16& password) {
+  BootTimesLoader::Get()->RecordLoginAttempted();
   std::vector<UserController*>::const_iterator i =
       std::find(controllers_.begin(), controllers_.end(), source);
   DCHECK(i != controllers_.end());
diff --git a/chrome/browser/chromeos/login/google_authenticator.cc b/chrome/browser/chromeos/login/google_authenticator.cc
index 0ec8815..94361be 100644
--- a/chrome/browser/chromeos/login/google_authenticator.cc
+++ b/chrome/browser/chromeos/login/google_authenticator.cc
@@ -18,7 +18,6 @@
 #include "base/third_party/nss/sha256.h"
 #include "chrome/browser/browser_process.h"
 #include "chrome/browser/chrome_thread.h"
-#include "chrome/browser/chromeos/browser_notification_observers.h"
 #include "chrome/browser/chromeos/cros/cryptohome_library.h"
 #include "chrome/browser/chromeos/login/auth_response_handler.h"
 #include "chrome/browser/chromeos/login/authentication_notification_details.h"
@@ -58,10 +57,6 @@ GoogleAuthenticator::GoogleAuthenticator(LoginStatusConsumer* consumer)
       try_again_(true),
       checked_for_localaccount_(false) {
   CHECK(chromeos::CrosLibrary::Get()->EnsureLoaded());
-
-  // This forces the creation of the login notification observer
-  // singleton.  It must be created to record login time.
-  chromeos::LogLoginSuccessObserver::Get();
 }
 
 GoogleAuthenticator::~GoogleAuthenticator() {}
diff --git a/chrome/browser/chromeos/login/login_screen.cc b/chrome/browser/chromeos/login/login_screen.cc
index 29ee360..9e1d886 100644
--- a/chrome/browser/chromeos/login/login_screen.cc
+++ b/chrome/browser/chromeos/login/login_screen.cc
@@ -13,7 +13,7 @@
 #include "base/utf_string_conversions.h"
 #include "chrome/browser/browser_process.h"
 #include "chrome/browser/chrome_thread.h"
-#include "chrome/browser/chromeos/browser_notification_observers.h"
+#include "chrome/browser/chromeos/boot_times_loader.h"
 #include "chrome/browser/chromeos/cros/cros_library.h"
 #include "chrome/browser/chromeos/cros/network_library.h"
 #include "chrome/browser/chromeos/login/authentication_notification_details.h"
@@ -31,8 +31,6 @@ LoginScreen::LoginScreen(WizardScreenDelegate* delegate)
     : ViewScreen<NewUserView>(delegate),
       bubble_(NULL),
       authenticator_(NULL) {
-  // Create login observer to record time of login when successful.
-  LogLoginSuccessObserver::Get();
   if (CrosLibrary::Get()->EnsureLoaded()) {
     authenticator_ = LoginUtils::Get()->CreateAuthenticator(this);
   }
@@ -48,6 +46,7 @@ NewUserView* LoginScreen::AllocateView() {
 
 void LoginScreen::OnLogin(const std::string& username,
                           const std::string& password) {
+  BootTimesLoader::Get()->RecordLoginAttempted();
   Profile* profile = g_browser_process->profile_manager()->GetDefaultProfile();
   ChromeThread::PostTask(
       ChromeThread::UI, FROM_HERE,
diff --git a/chrome/chrome_browser.gypi b/chrome/chrome_browser.gypi
index 7d0022a..ffa9db3 100644
--- a/chrome/chrome_browser.gypi
+++ b/chrome/chrome_browser.gypi
@@ -356,7 +356,6 @@
         'browser/chromeos/audio_handler.h',
         'browser/chromeos/boot_times_loader.cc',
         'browser/chromeos/boot_times_loader.h',
-        'browser/chromeos/browser_notification_observers.cc',
         'browser/chromeos/cros_settings.cc',
         'browser/chromeos/cros_settings.h',
         'browser/chromeos/cros_settings_names.cc',