[Background Sync] Gather UMA data for Background Sync

content/browser/background_sync/background_sync_manager.cc

Index: content/browser/background_sync/background_sync_manager.cc
diff --git a/content/browser/background_sync/background_sync_manager.cc b/content/browser/background_sync/background_sync_manager.cc
index e056d23979b9c02ebcaacccacd1ca21856b3b14c..e3f018b1a6fa38905283677e8e72a7be9c11c9c5 100644
--- a/content/browser/background_sync/background_sync_manager.cc
+++ b/content/browser/background_sync/background_sync_manager.cc
@@ -9,6 +9,7 @@
 #include "base/location.h"
 #include "base/single_thread_task_runner.h"
 #include "base/thread_task_runner_handle.h"
+#include "content/browser/background_sync/background_sync_metrics.h"
 #include "content/browser/background_sync/background_sync_network_observer.h"
 #include "content/browser/background_sync/background_sync_power_observer.h"
 #include "content/browser/background_sync/background_sync_registration_options.h"
@@ -76,6 +77,9 @@ void BackgroundSyncManager::Register(
   DCHECK_CURRENTLY_ON(BrowserThread::IO);
 
   if (disabled_) {
+    BackgroundSyncMetrics::CountRegistration(
+        options.periodicity, false,

[jkarlin, 2015/07/13 16:51:12]

Prefer an enum to a bool.

[iclelland, 2015/07/13 19:34:31]

Yes, generally. I hate to have to define the enum here, though, and import it in
background_sync_metrics.h. But it's worse to define it there, when I'd really
want it to be the return value for WouldFireRegistrationWithOptions.

+        BackgroundSyncMetrics::REGISTRATION_RESULT_FAILED);

[jkarlin, 2015/07/13 16:51:13]

RESULT_DISABLED instead of RESULT_FAILED. 

[iclelland, 2015/07/13 19:34:31]

I'll switch to ERROR_TYPE_STORAGE, to mirror ErrorType, as discussed in a later
comment.

     base::ThreadTaskRunnerHandle::Get()->PostTask(
         FROM_HERE,
         base::Bind(callback, ERROR_TYPE_STORAGE, BackgroundSyncRegistration()));
@@ -97,6 +101,7 @@ void BackgroundSyncManager::Unregister(
   DCHECK_CURRENTLY_ON(BrowserThread::IO);
 
   if (disabled_) {
+    BackgroundSyncMetrics::CountUnregistration(periodicity, false);

[jkarlin, 2015/07/13 16:51:12]

Why a bool? Why not use the same enum as registration? That would tell us more
about what's going on.

[iclelland, 2015/07/13 19:34:31]

They both started as bool, but registration has different possibilities
(duplicate registration, e.g.), so I switched it. I'll switch unregister as
well, if that makes sense.

     base::ThreadTaskRunnerHandle::Get()->PostTask(
         FROM_HERE, base::Bind(callback, ERROR_TYPE_STORAGE));
     return;
@@ -106,7 +111,7 @@ void BackgroundSyncManager::Unregister(
 
   op_scheduler_.ScheduleOperation(base::Bind(
       &BackgroundSyncManager::UnregisterImpl, weak_ptr_factory_.GetWeakPtr(),
-      sw_registration_id, registration_key, sync_registration_id,
+      sw_registration_id, registration_key, sync_registration_id, periodicity,
       MakeStatusCompletion(callback)));
 }
 
@@ -292,16 +297,27 @@ void BackgroundSyncManager::RegisterImpl(
   DCHECK_CURRENTLY_ON(BrowserThread::IO);
 
   if (disabled_) {
+    BackgroundSyncMetrics::CountRegistration(
+        options.periodicity, false,
+        BackgroundSyncMetrics::REGISTRATION_RESULT_FAILED);
     base::ThreadTaskRunnerHandle::Get()->PostTask(
         FROM_HERE,
         base::Bind(callback, ERROR_TYPE_STORAGE, BackgroundSyncRegistration()));
     return;
   }
 
+  // For UMA, determine here whether the sync could fire immediately
+  bool registrationCouldFire = WouldFireRegistrationWithOptions(options);

[jkarlin, 2015/07/13 16:51:13]

registration_could_fire

[iclelland, 2015/07/13 19:34:31]

Done.

+
   const BackgroundSyncRegistration* existing_registration =
       LookupRegistration(sw_registration_id, RegistrationKey(options));
   if (existing_registration &&
       existing_registration->options()->Equals(options)) {
+    // Record the duplicated registration
+    BackgroundSyncMetrics::CountRegistration(
+        existing_registration->options()->periodicity, registrationCouldFire,
+        BackgroundSyncMetrics::REGISTRATION_RESULT_DUPLICATE);
+
     base::ThreadTaskRunnerHandle::Get()->PostTask(
         FROM_HERE, base::Bind(callback, ERROR_TYPE_OK, *existing_registration));
     return;
@@ -317,6 +333,9 @@ void BackgroundSyncManager::RegisterImpl(
   ServiceWorkerRegistration* sw_registration =
       service_worker_context_->GetLiveRegistration(sw_registration_id);
   if (!sw_registration || !sw_registration->active_version()) {
+    BackgroundSyncMetrics::CountRegistration(
+        options.periodicity, registrationCouldFire,
+        BackgroundSyncMetrics::REGISTRATION_RESULT_FAILED);
     base::ThreadTaskRunnerHandle::Get()->PostTask(
         FROM_HERE, base::Bind(callback, ERROR_TYPE_NO_SERVICE_WORKER,
                               BackgroundSyncRegistration()));
@@ -452,8 +471,15 @@ void BackgroundSyncManager::RegisterDidStore(
     ServiceWorkerStatusCode status) {
   DCHECK_CURRENTLY_ON(BrowserThread::IO);
 
+  // For UMA, determine here whether the sync could fire immediately
+  bool registrationCouldFire =

[jkarlin, 2015/07/13 16:51:13]

registration_could_fire

[iclelland, 2015/07/13 19:34:31]

Done.

+      WouldFireRegistrationWithOptions(*new_registration.options());
+
   if (status == SERVICE_WORKER_ERROR_NOT_FOUND) {
-    // The registration is gone.
+    // The service worker registration is gone.
+    BackgroundSyncMetrics::CountRegistration(
+        new_registration.options()->periodicity, registrationCouldFire,
+        BackgroundSyncMetrics::REGISTRATION_RESULT_FAILED);
     sw_to_registrations_map_.erase(sw_registration_id);
     base::ThreadTaskRunnerHandle::Get()->PostTask(
         FROM_HERE,
@@ -464,11 +490,17 @@ void BackgroundSyncManager::RegisterDidStore(
   if (status != SERVICE_WORKER_OK) {
     LOG(ERROR) << "BackgroundSync failed to store registration due to backend "
                   "failure.";
+    BackgroundSyncMetrics::CountRegistration(
+        new_registration.options()->periodicity, registrationCouldFire,
+        BackgroundSyncMetrics::REGISTRATION_RESULT_FAILED);
     DisableAndClearManager(
         base::Bind(callback, ERROR_TYPE_STORAGE, BackgroundSyncRegistration()));
     return;
   }
 
+  BackgroundSyncMetrics::CountRegistration(
+      new_registration.options()->periodicity, registrationCouldFire,
+      BackgroundSyncMetrics::REGISTRATION_RESULT_SUCCEEDED);
   FireReadyEvents();
   base::ThreadTaskRunnerHandle::Get()->PostTask(
       FROM_HERE, base::Bind(callback, ERROR_TYPE_OK, new_registration));
@@ -535,10 +567,12 @@ void BackgroundSyncManager::UnregisterImpl(
     int64 sw_registration_id,
     const RegistrationKey& registration_key,
     BackgroundSyncRegistration::RegistrationId sync_registration_id,
+    SyncPeriodicity periodicity,
     const StatusCallback& callback) {
   DCHECK_CURRENTLY_ON(BrowserThread::IO);
 
   if (disabled_) {
+    BackgroundSyncMetrics::CountUnregistration(periodicity, false);
     base::ThreadTaskRunnerHandle::Get()->PostTask(
         FROM_HERE, base::Bind(callback, ERROR_TYPE_STORAGE));
     return;
@@ -548,6 +582,7 @@ void BackgroundSyncManager::UnregisterImpl(
       LookupRegistration(sw_registration_id, registration_key);
   if (!existing_registration ||
       existing_registration->id() != sync_registration_id) {
+    BackgroundSyncMetrics::CountUnregistration(periodicity, false);
     base::ThreadTaskRunnerHandle::Get()->PostTask(
         FROM_HERE, base::Bind(callback, ERROR_TYPE_NOT_FOUND));
     return;
@@ -555,20 +590,21 @@ void BackgroundSyncManager::UnregisterImpl(
 
   RemoveRegistrationFromMap(sw_registration_id, registration_key);
 
-  StoreRegistrations(
-      sw_registration_id,
-      base::Bind(&BackgroundSyncManager::UnregisterDidStore,
-                 weak_ptr_factory_.GetWeakPtr(), sw_registration_id, callback));
+  StoreRegistrations(sw_registration_id,
+                     base::Bind(&BackgroundSyncManager::UnregisterDidStore,
+                                weak_ptr_factory_.GetWeakPtr(),
+                                sw_registration_id, periodicity, callback));
 }
 
-void BackgroundSyncManager::UnregisterDidStore(
-    int64 sw_registration_id,
-    const StatusCallback& callback,
-    ServiceWorkerStatusCode status) {
+void BackgroundSyncManager::UnregisterDidStore(int64 sw_registration_id,
+                                               SyncPeriodicity periodicity,
+                                               const StatusCallback& callback,
+                                               ServiceWorkerStatusCode status) {
   DCHECK_CURRENTLY_ON(BrowserThread::IO);
 
   if (status == SERVICE_WORKER_ERROR_NOT_FOUND) {
     // ServiceWorker was unregistered.
+    BackgroundSyncMetrics::CountUnregistration(periodicity, false);
     sw_to_registrations_map_.erase(sw_registration_id);
     base::ThreadTaskRunnerHandle::Get()->PostTask(
         FROM_HERE, base::Bind(callback, ERROR_TYPE_STORAGE));
@@ -577,10 +613,12 @@ void BackgroundSyncManager::UnregisterDidStore(
 
   if (status != SERVICE_WORKER_OK) {
     LOG(ERROR) << "BackgroundSync failed to unregister due to backend failure.";
+    BackgroundSyncMetrics::CountUnregistration(periodicity, false);
     DisableAndClearManager(base::Bind(callback, ERROR_TYPE_STORAGE));
     return;
   }
 
+  BackgroundSyncMetrics::CountUnregistration(periodicity, true);
   base::ThreadTaskRunnerHandle::Get()->PostTask(
       FROM_HERE, base::Bind(callback, ERROR_TYPE_OK));
 }
@@ -642,6 +680,13 @@ void BackgroundSyncManager::GetRegistrationsImpl(
       FROM_HERE, base::Bind(callback, ERROR_TYPE_OK, out_registrations));
 }
 
+bool BackgroundSyncManager::WouldFireRegistrationWithOptions(

[jkarlin, 2015/07/13 16:51:12]

Why this function? Why not just call IsRegistrationReadyToFire for the UMA
check?

[iclelland, 2015/07/13 19:34:31]

IsRegistrationReadyToFire takes a Registration object, and I wanted to call this
early in the Register() method, when all we have is an options object. That way,
even if we bail early, we can still report whether the registration *could* have
fired, as far as the developer was concerned.
I thought it made sense to factor out the "are these options satisfied right
now" check, and leave the sync-lifecycle (PENDING vs FIRING, etc) checks to the
method that is actually checking registered syncs.

[jkarlin, 2015/07/14 15:54:10]

Okay. Can you rename to AreOptionConditionsMet?

[iclelland, 2015/07/15 14:22:25]

Done.

+    const BackgroundSyncRegistrationOptions& options) {
+  DCHECK_CURRENTLY_ON(BrowserThread::IO);
+  return network_observer_->NetworkSufficient(options.network_state) &&
+         power_observer_->PowerSufficient(options.power_state);
+}
+
 bool BackgroundSyncManager::IsRegistrationReadyToFire(
     const BackgroundSyncRegistration& registration) {
   DCHECK_CURRENTLY_ON(BrowserThread::IO);
@@ -655,9 +700,7 @@ bool BackgroundSyncManager::IsRegistrationReadyToFire(
 
   DCHECK_EQ(SYNC_ONE_SHOT, registration.options()->periodicity);
 
-  return network_observer_->NetworkSufficient(
-             registration.options()->network_state) &&
-         power_observer_->PowerSufficient(registration.options()->power_state);
+  return WouldFireRegistrationWithOptions(*registration.options());
 }
 
 void BackgroundSyncManager::SchedulePendingRegistrations() {
@@ -730,10 +773,13 @@ void BackgroundSyncManager::FireReadyEventsImpl(const base::Closure& callback) {
     }
   }
 
+  base::TimeTicks start_time = base::TimeTicks::Now();
+
   // Fire the sync event of the ready registrations and run |callback| once
   // they're all done.
-  base::Closure barrier_closure =
-      base::BarrierClosure(sw_id_and_keys_to_fire.size(), base::Bind(callback));
+  base::Closure barrier_closure = base::BarrierClosure(
+      sw_id_and_keys_to_fire.size(),
+      base::Bind(&OnAllSyncEventsCompleted, start_time, callback));

[jkarlin, 2015/07/13 16:51:13]

OnAllSyncEventsCompleted doesn't get called when you think it does. This barrier
is complete once all of the service worker versions have called DispatchSync. It
doesn't wait for them to complete.

[iclelland, 2015/07/15 14:22:24]

Thanks for catching that -- I've added a second barrier now, so one is called
when all events have fired, and the other when all events have completed. That
second one now calls OnAllSyncEventsCompleted, as intended.

 
   for (const auto& sw_id_and_key : sw_id_and_keys_to_fire) {
     int64 service_worker_id = sw_id_and_key.first;
@@ -817,6 +863,11 @@ void BackgroundSyncManager::EventCompleteImpl(
     return;
   }
 
+  // The event ran to completion, we should count it, no matter what happens
+  // from here.
+  BackgroundSyncMetrics::RecordEventResult(registration->options()->periodicity,
+                                           status_code == SERVICE_WORKER_OK);
+
   if (registration->options()->periodicity == SYNC_ONE_SHOT) {
     if (status_code != SERVICE_WORKER_OK) {
       // TODO(jkarlin) Fire the sync event on the next page load controlled by
@@ -862,6 +913,16 @@ void BackgroundSyncManager::EventCompleteDidStore(
                                                 base::Bind(callback));
 }
 
+// static
+void BackgroundSyncManager::OnAllSyncEventsCompleted(
+    const base::TimeTicks& start_time,
+    const base::Closure& callback) {
+  // Record the combined time taken by all sync events and run |callback|.
+  BackgroundSyncMetrics::RecordSyncEventHandlingTime(base::TimeTicks::Now() -
+                                                     start_time);
+  callback.Run();
+}
+
 void BackgroundSyncManager::OnRegistrationDeletedImpl(
     int64 registration_id,
     const base::Closure& callback) {