Added asynchronous notification of readiness to the StatisticsProvider, and

chrome/browser/metrics/metrics_service.cc

Index: chrome/browser/metrics/metrics_service.cc
diff --git a/chrome/browser/metrics/metrics_service.cc b/chrome/browser/metrics/metrics_service.cc
index 0b692aaa9b0bf4cfe2dd9abc12ecbe7cdc37b7ca..1edcd3498e8c224ad844621acf91afcbcc32d224 100644
--- a/chrome/browser/metrics/metrics_service.cc
+++ b/chrome/browser/metrics/metrics_service.cc
@@ -89,11 +89,10 @@
 // initial log.
 //
 //    INIT_TASK_SCHEDULED,    // Waiting for deferred init tasks to complete.
-// Typically about 30 seconds after startup, a task is sent to a second thread
-// (the file thread) to perform deferred (lower priority and slower)
-// initialization steps such as getting the list of plugins.  That task will
-// (when complete) make an async callback (via a Task) to indicate the
-// completion.
+// Typically about 30 seconds after startup, a task is posted to perform
+// deferred (lower priority and slower) initialization steps such as getting the
+// list of plugins.  That task will (when complete) make an async callback (via
+// a Task) to indicate the completion.
 //
 //    INIT_TASK_DONE,         // Waiting for timer to send initial log.
 // The callback has arrived, and it is now possible for an initial log to be
@@ -153,6 +152,7 @@
 #include "base/threading/platform_thread.h"
 #include "base/threading/thread.h"
 #include "base/threading/thread_restrictions.h"
+#include "base/time.h"
 #include "base/tracked_objects.h"
 #include "base/utf_string_conversions.h"
 #include "base/values.h"
@@ -229,6 +229,10 @@ const char kServerUrlProto[] = "https://clients4.google.com/uma/v2";
 // initialization work.
 const int kInitializationDelaySeconds = 30;
 
+// The timeout, in seconds, to resume initialization of the MetricsService if
+// the initialization of the StatisticsProvider hasn't completed yet.
+const int kStatisticsProviderTimeoutSeconds = 300;
+
 // This specifies the amount of time to wait for all renderers to send their
 // data.
 const int kMaxHistogramGatheringWaitDuration = 60000;  // 60 seconds.
@@ -250,6 +254,11 @@ const int kSaveStateIntervalMinutes = 5;
 // e.g., the server is down.
 const int kNoResponseCode = content::URLFetcher::RESPONSE_CODE_INVALID - 1;
 
+// Used to indicate that a report was generated before the hardware_class
+// property was available from the StatisticsProvider. This is used to identify
+// faulty reports from Chrome OS clients.
+const char kHardwareClassNotReady[] = "(not ready)";
+
 }
 
 // static
@@ -400,6 +409,7 @@ MetricsService::MetricsService()
       next_window_id_(0),
       ALLOW_THIS_IN_INITIALIZER_LIST(self_ptr_factory_(this)),
       ALLOW_THIS_IN_INITIALIZER_LIST(state_saver_factory_(this)),
+      ALLOW_THIS_IN_INITIALIZER_LIST(timeout_task_factory_(this)),
       waiting_for_asynchronus_reporting_step_(false) {
   DCHECK(IsSingleThreaded());
   InitializeMetricsState();
@@ -757,32 +767,72 @@ void MetricsService::InitializeMetricsState() {
   ScheduleNextStateSave();
 }
 
-// static
-void MetricsService::InitTaskGetHardwareClass(
-    base::WeakPtr<MetricsService> self,
-    base::MessageLoopProxy* target_loop) {
-  DCHECK(BrowserThread::CurrentlyOn(BrowserThread::FILE));
+void MetricsService::InitTaskGetHardwareClass() {
+  DCHECK(BrowserThread::CurrentlyOn(BrowserThread::UI));
+  DCHECK_EQ(INIT_TASK_SCHEDULED, state_);
 
-  std::string hardware_class;
 #if defined(OS_CHROMEOS)
+  // The hardware class can only be retrieved once the StatisticsProvider is
+  // ready. This usually happens early enough, but can take longer on some
+  // faulty hardware.
+  chromeos::system::StatisticsProvider::GetInstance()->WhenReady(
+      base::Bind(&MetricsService::OnStatisticsProviderReady,
+                 self_ptr_factory_.GetWeakPtr(),
+                 base::Time::Now()));
+
+  // Set up a timeout task in case the StatisticsProvider takes too long to
+  // initialize. Only one of these tasks will execute; invoking either
+  // invalidates the WeakPtr of the other. In both cases, hardware_class_ is
+  // updated once OnStatisticsProviderReady is invoked.
+
+  // Invoke the next init task if the StatisticsProvider becomes ready.
+  // This will be invoked immediately after OnStatisticsProviderReady.
+  chromeos::system::StatisticsProvider::GetInstance()->WhenReady(
+      base::Bind(&MetricsService::InitTaskGetPluginInfo,
+                 timeout_task_factory_.GetWeakPtr()));
+
+  // Invoke OnStatisticsProviderTimeout if it times out instead.
+  MessageLoop::current()->PostDelayedTask(
+      FROM_HERE,
+      base::Bind(&MetricsService::OnStatisticsProviderTimeout,
+                 timeout_task_factory_.GetWeakPtr()),
+      base::TimeDelta::FromSeconds(kStatisticsProviderTimeoutSeconds));
+#else
+  InitTaskGetPluginInfo();
+#endif
+}
+
+void MetricsService::OnStatisticsProviderReady(const base::Time& start_time) {
+#if defined(OS_CHROMEOS)
+  DCHECK(BrowserThread::CurrentlyOn(BrowserThread::UI));
+  base::TimeDelta elapsed = base::Time::Now() - start_time;
+  UMA_HISTOGRAM_LONG_TIMES("UMA.StatisticsProviderReadyDelay", elapsed);
   chromeos::system::StatisticsProvider::GetInstance()->GetMachineStatistic(
-      "hardware_class", &hardware_class);
-#endif  // OS_CHROMEOS
+      "hardware_class", &hardware_class_);
+#endif
+}
 
-  target_loop->PostTask(FROM_HERE,
-      base::Bind(&MetricsService::OnInitTaskGotHardwareClass,
-          self, hardware_class));
+void MetricsService::OnStatisticsProviderTimeout() {

[Ilya Sherman, 2012/04/30 07:36:41]

nit: Perhaps log a histogram/event for the timeout case as well?

[Joao da Silva, 2012/05/15 13:52:47]

Good idea. I've moved these histograms to the StatisticsProvider code and added
this one there as well.

+#if defined(OS_CHROMEOS)
+  // Use an invalid hardware_class temporarily until the StatisticsProvider is
+  // ready.

[Ilya Sherman, 2012/04/30 07:36:41]

It looks like, with this setup, we'll never record the hardware class if we
reach the timeout, even for ongoing uploads.  Am I misreading the code?  If not,
it would be nice to still listen for the "ready" event from the
StatisticsProvider, just not have it block the init path, in the case of a
timeout.

[Joao da Silva, 2012/05/15 13:52:47]

The WhenReady() callback is still pending in this case, and will update
hardware_class_ once it executes. This code has changed meanwhile.

+  hardware_class_ = kHardwareClassNotReady;
+  InitTaskGetPluginInfo();
+#endif
 }
 
-void MetricsService::OnInitTaskGotHardwareClass(
-    const std::string& hardware_class) {
+void MetricsService::InitTaskGetPluginInfo() {
+  DCHECK(BrowserThread::CurrentlyOn(BrowserThread::UI));
   DCHECK_EQ(INIT_TASK_SCHEDULED, state_);
-  hardware_class_ = hardware_class;
+
+  // Invalidate tasks related to waiting for the StatisticsProvider to
+  // initialize, if any are still scheduled.
+  timeout_task_factory_.InvalidateWeakPtrs();
 
   // Start the next part of the init task: loading plugin information.
   PluginService::GetInstance()->GetPlugins(
       base::Bind(&MetricsService::OnInitTaskGotPluginInfo,
-          self_ptr_factory_.GetWeakPtr()));
+                 self_ptr_factory_.GetWeakPtr()));
 }
 
 void MetricsService::OnInitTaskGotPluginInfo(
@@ -857,16 +907,12 @@ void MetricsService::StartRecording() {
     // We only need to schedule that run once.
     state_ = INIT_TASK_SCHEDULED;
 
-    // Schedules a task on the file thread for execution of slower
-    // initialization steps (such as plugin list generation) necessary
-    // for sending the initial log.  This avoids blocking the main UI
-    // thread.
-    BrowserThread::PostDelayedTask(
-        BrowserThread::FILE,
+    // Schedules a delayed task for execution of slower initialization steps
+    // (such as plugin list generation) necessary for sending the initial log.
+    MessageLoop::current()->PostDelayedTask(
         FROM_HERE,
         base::Bind(&MetricsService::InitTaskGetHardwareClass,
-            self_ptr_factory_.GetWeakPtr(),
-            MessageLoop::current()->message_loop_proxy()),
+                   self_ptr_factory_.GetWeakPtr()),
         base::TimeDelta::FromSeconds(kInitializationDelaySeconds));
   }
 }