ServiceWorker: More accurate StartWorker result and UMA

This adds SERVICE_WORKER_ERROR_DISK_CACHE to indicate
failure to read from the disk cache. It also re-enables
logging of StartWorker for redundant workers. This was
previously disabled because we got a lot of "failed" spam
for updates that get aborted when there is no script change,
so I've changed StartWorker to fail with SW_ERROR_EXISTS in
that case.

This patch is a step in the direction of evicting a SW
that can't be read from disk cache.

BUG=448003

Review URL: https://codereview.chromium.org/1054033004

Cr-Commit-Position: refs/heads/master@{#326923}

content/browser/notifications/notification_event_dispatcher_impl.cc

@@ -51,6 +51,7 @@ void NotificationClickEventFinished(
     case SERVICE_WORKER_ERROR_STATE:
     case SERVICE_WORKER_ERROR_TIMEOUT:
     case SERVICE_WORKER_ERROR_SCRIPT_EVALUATE_FAILED:
+    case SERVICE_WORKER_ERROR_DISK_CACHE:
     case SERVICE_WORKER_ERROR_MAX_VALUE:
       status = PERSISTENT_NOTIFICATION_STATUS_SERVICE_WORKER_ERROR;
       break;
@@ -103,6 +104,7 @@ void DispatchNotificationClickEventOnRegistration(
     case SERVICE_WORKER_ERROR_STATE:
     case SERVICE_WORKER_ERROR_TIMEOUT:
     case SERVICE_WORKER_ERROR_SCRIPT_EVALUATE_FAILED:
+    case SERVICE_WORKER_ERROR_DISK_CACHE:
     case SERVICE_WORKER_ERROR_MAX_VALUE:
       status = PERSISTENT_NOTIFICATION_STATUS_SERVICE_WORKER_ERROR;
       break;

content/browser/push_messaging/push_messaging_message_filter.cc

@@ -559,6 +559,7 @@ void PushMessagingMessageFilter::UnregisterHavingGottenSenderId(
     case SERVICE_WORKER_ERROR_STATE:
     case SERVICE_WORKER_ERROR_TIMEOUT:
     case SERVICE_WORKER_ERROR_SCRIPT_EVALUATE_FAILED:
+    case SERVICE_WORKER_ERROR_DISK_CACHE:
     case SERVICE_WORKER_ERROR_MAX_VALUE:
       NOTREACHED() << "Got unexpected error code: " << service_worker_status
                    << " " << ServiceWorkerStatusToString(service_worker_status);
@@ -734,6 +735,7 @@ void PushMessagingMessageFilter::DidGetRegistration(
     case SERVICE_WORKER_ERROR_STATE:
     case SERVICE_WORKER_ERROR_TIMEOUT:
     case SERVICE_WORKER_ERROR_SCRIPT_EVALUATE_FAILED:
+    case SERVICE_WORKER_ERROR_DISK_CACHE:
     case SERVICE_WORKER_ERROR_MAX_VALUE:
       NOTREACHED() << "Got unexpected error code: " << service_worker_status
                    << " " << ServiceWorkerStatusToString(service_worker_status);

content/browser/push_messaging/push_messaging_router.cc

@@ -109,6 +109,7 @@ void PushMessagingRouter::DeliverMessageEnd(
     case SERVICE_WORKER_ERROR_IPC_FAILED:
     case SERVICE_WORKER_ERROR_TIMEOUT:
     case SERVICE_WORKER_ERROR_SCRIPT_EVALUATE_FAILED:
+    case SERVICE_WORKER_ERROR_DISK_CACHE:
       delivery_status = PUSH_DELIVERY_STATUS_SERVICE_WORKER_ERROR;
       break;
     case SERVICE_WORKER_ERROR_EXISTS:

content/browser/service_worker/service_worker_read_from_cache_job.cc

@@ -151,7 +151,7 @@ void ServiceWorkerReadFromCacheJob::OnReadInfoComplete(int result) {
     DCHECK_LT(result, 0);
     ServiceWorkerMetrics::CountReadResponseResult(
         ServiceWorkerMetrics::READ_HEADERS_ERROR);
-    NotifyDone(net::URLRequestStatus(net::URLRequestStatus::FAILED, result));
+    Done(net::URLRequestStatus(net::URLRequestStatus::FAILED, result));
     return;
   }
   DCHECK_GE(result, 0);
@@ -192,14 +192,22 @@ void ServiceWorkerReadFromCacheJob::SetupRangeResponse(int resource_size) {
       range_requested_, resource_size, true /* replace status line */);
 }
 
+void ServiceWorkerReadFromCacheJob::Done(const net::URLRequestStatus& status) {
+  if (!status.is_success()) {
+    version_->SetStartWorkerStatusCode(SERVICE_WORKER_ERROR_DISK_CACHE);
+    // TODO(falken): Retry and evict the SW if it fails again.
+  }
+  NotifyDone(status);
+}
+
 void ServiceWorkerReadFromCacheJob::OnReadComplete(int result) {
   ServiceWorkerMetrics::ReadResponseResult check_result;
   if (result == 0) {
     check_result = ServiceWorkerMetrics::READ_OK;
-    NotifyDone(net::URLRequestStatus());
+    Done(net::URLRequestStatus());
   } else if (result < 0) {
     check_result = ServiceWorkerMetrics::READ_DATA_ERROR;
-    NotifyDone(net::URLRequestStatus(net::URLRequestStatus::FAILED, result));
+    Done(net::URLRequestStatus(net::URLRequestStatus::FAILED, result));
   } else {
     check_result = ServiceWorkerMetrics::READ_OK;
     SetStatus(net::URLRequestStatus());  // Clear the IO_PENDING status

content/browser/service_worker/service_worker_read_from_cache_job.h

@@ -55,6 +55,7 @@ class CONTENT_EXPORT ServiceWorkerReadFromCacheJob
   const net::HttpResponseInfo* http_info() const;
   bool is_range_request() const { return range_requested_.IsValid(); }
   void SetupRangeResponse(int response_data_size);
+  void Done(const net::URLRequestStatus& status);
 
   base::WeakPtr<ServiceWorkerContextCore> context_;
   scoped_refptr<ServiceWorkerVersion> version_;

content/browser/service_worker/service_worker_register_job.cc

@@ -450,7 +450,9 @@ void ServiceWorkerRegisterJob::CompleteInternal(
       if (should_uninstall_on_failure_)
         registration()->ClearWhenReady();
       if (new_version()) {
-        if (status != SERVICE_WORKER_ERROR_EXISTS)
+        if (status == SERVICE_WORKER_ERROR_EXISTS)
+          new_version()->SetStartWorkerStatusCode(SERVICE_WORKER_ERROR_EXISTS);
+        else
           new_version()->ReportError(status, status_message);
         registration()->UnsetVersion(new_version());
         new_version()->Doom();

content/browser/service_worker/service_worker_registration_status.cc

@@ -59,6 +59,7 @@ void GetServiceWorkerRegistrationStatusResponse(
     case SERVICE_WORKER_ERROR_EXISTS:
     case SERVICE_WORKER_ERROR_EVENT_WAITUNTIL_REJECTED:
     case SERVICE_WORKER_ERROR_STATE:
+    case SERVICE_WORKER_ERROR_DISK_CACHE:
     case SERVICE_WORKER_ERROR_MAX_VALUE:
       // Unexpected, or should have bailed out before calling this, or we don't
       // have a corresponding blink error code yet.

content/browser/service_worker/service_worker_version.cc

@@ -348,12 +348,14 @@ bool IsInstalled(ServiceWorkerVersion::Status status) {
   switch (status) {
     case ServiceWorkerVersion::NEW:
     case ServiceWorkerVersion::INSTALLING:
-    case ServiceWorkerVersion::REDUNDANT:
       return false;
     case ServiceWorkerVersion::INSTALLED:
     case ServiceWorkerVersion::ACTIVATING:
     case ServiceWorkerVersion::ACTIVATED:
       return true;
+    case ServiceWorkerVersion::REDUNDANT:
+      NOTREACHED() << "Cannot use REDUNDANT here.";
+      return false;
   }
   NOTREACHED() << "Unexpected status: " << status;
   return false;
@@ -452,6 +454,11 @@ void ServiceWorkerVersion::StartWorker(
     RunSoon(base::Bind(callback, SERVICE_WORKER_ERROR_ABORT));
     return;
   }
+  if (status_ == REDUNDANT) {
+    RunSoon(base::Bind(callback, SERVICE_WORKER_ERROR_START_WORKER_FAILED));
+    return;
+  }
+  prestart_status_ = status_;
 
   // Ensure the live registration during starting worker so that the worker can
   // get associated with it in SWDispatcherHost::OnSetHostedVersionId().
@@ -837,6 +844,11 @@ void ServiceWorkerVersion::ReportError(ServiceWorkerStatusCode status,
   }
 }
 
+void ServiceWorkerVersion::SetStartWorkerStatusCode(
+    ServiceWorkerStatusCode status) {
+  start_worker_status_ = status;
+}
+
 void ServiceWorkerVersion::Doom() {
   DCHECK(!HasControllee());
   SetStatus(REDUNDANT);
@@ -1514,11 +1526,16 @@ void ServiceWorkerVersion::DidEnsureLiveRegistrationForStartWorker(
     const StatusCallback& callback,
     ServiceWorkerStatusCode status,
     const scoped_refptr<ServiceWorkerRegistration>& protect) {
-  if (status != SERVICE_WORKER_OK || is_redundant()) {
+  if (status != SERVICE_WORKER_OK) {
     RecordStartWorkerResult(status);
     RunSoon(base::Bind(callback, SERVICE_WORKER_ERROR_START_WORKER_FAILED));
     return;
   }
+  if (is_redundant()) {
+    RecordStartWorkerResult(SERVICE_WORKER_ERROR_NOT_FOUND);
+    RunSoon(base::Bind(callback, SERVICE_WORKER_ERROR_START_WORKER_FAILED));
+    return;
+  }
 
   switch (running_status()) {
     case RUNNING:
@@ -1742,17 +1759,13 @@ void ServiceWorkerVersion::RecordStartWorkerResult(
   base::TimeTicks start_time = start_time_;
   ClearTick(&start_time_);
 
-  // Failing to start a redundant worker isn't interesting and very common when
-  // update dooms because the script is byte-to-byte identical.
-  if (is_redundant())
-    return;
-
-  ServiceWorkerMetrics::RecordStartWorkerStatus(status, IsInstalled(status_));
+  ServiceWorkerMetrics::RecordStartWorkerStatus(status,
+                                                IsInstalled(prestart_status_));
 
   if (status == SERVICE_WORKER_OK && !start_time.is_null() &&
       !skip_recording_startup_time_) {
     ServiceWorkerMetrics::RecordStartWorkerTime(GetTickDuration(start_time),
-                                                IsInstalled(status_));
+                                                IsInstalled(prestart_status_));
   }
 
   if (status != SERVICE_WORKER_ERROR_TIMEOUT)
@@ -1851,6 +1864,9 @@ ServiceWorkerStatusCode ServiceWorkerVersion::DeduceStartWorkerFailureReason(
   if (ping_state_ == PING_TIMED_OUT)
     return SERVICE_WORKER_ERROR_TIMEOUT;
 
+  if (start_worker_status_ != SERVICE_WORKER_OK)
+    return start_worker_status_;
+
   const net::URLRequestStatus& main_script_status =
       script_cache_map()->main_script_status();
   if (main_script_status.status() != net::URLRequestStatus::SUCCESS) {

content/browser/service_worker/service_worker_version.h

@@ -286,6 +286,9 @@ class CONTENT_EXPORT ServiceWorkerVersion
   void ReportError(ServiceWorkerStatusCode status,
                    const std::string& status_message);
 
+  // Sets the status code to pass to StartWorker callbacks if start fails.
+  void SetStartWorkerStatusCode(ServiceWorkerStatusCode status);
+
   // Sets this version's status to REDUNDANT and deletes its resources.
   // The version must not have controllees.
   void Doom();
@@ -543,6 +546,12 @@ class CONTENT_EXPORT ServiceWorkerVersion
   std::vector<int> pending_skip_waiting_requests_;
   scoped_ptr<net::HttpResponseInfo> main_script_http_info_;
 
+  // The status when StartWorker was invoked. Used for UMA.
+  Status prestart_status_ = NEW;
+  // If not OK, the reason that StartWorker failed. Used for
+  // running |start_callbacks_|.
+  ServiceWorkerStatusCode start_worker_status_ = SERVICE_WORKER_OK;
+
   base::WeakPtrFactory<ServiceWorkerVersion> weak_factory_;
 
   DISALLOW_COPY_AND_ASSIGN(ServiceWorkerVersion);

content/common/service_worker/service_worker_status_code.cc

@@ -43,6 +43,8 @@ const char* ServiceWorkerStatusToString(ServiceWorkerStatusCode status) {
       return "The ServiceWorker timed out";
     case SERVICE_WORKER_ERROR_SCRIPT_EVALUATE_FAILED:
       return "ServiceWorker script evaluation failed";
+    case SERVICE_WORKER_ERROR_DISK_CACHE:
+      return "Disk cache error";
     case SERVICE_WORKER_ERROR_MAX_VALUE:
       NOTREACHED();
   }

content/common/service_worker/service_worker_status_code.h

@@ -63,6 +63,9 @@ enum ServiceWorkerStatusCode {
   // An error occurred during initial script evaluation.
   SERVICE_WORKER_ERROR_SCRIPT_EVALUATE_FAILED,
 
+  // Generic error to indicate failure to read/write the disk cache.
+  SERVICE_WORKER_ERROR_DISK_CACHE,
+
   SERVICE_WORKER_ERROR_MAX_VALUE
 };
 

tools/metrics/histograms/histograms.xml

@@ -61370,6 +61370,7 @@ To add a new entry, add it with any value and run test to compute valid value.
   <int value="13" label="SERVICE_WORKER_ERROR_STATE"/>
   <int value="14" label="SERVICE_WORKER_ERROR_TIMEOUT"/>
   <int value="15" label="SERVICE_WORKER_ERROR_SCRIPT_EVALUATE_FAILED"/>
+  <int value="16" label="SERVICE_WORKER_ERROR_DISK_CACHE"/>
 </enum>
 
 <enum name="ServiceWorkerWriteResponseResult" type="int">