ServiceWorker: More traces for events dispatched to service workers

Bug: 852202, 669772, 806658
Change-Id: Ife9c41fbe08c1f414bb5459cba29d98d7e1fb892
Reviewed-on: https://chromium-review.googlesource.com/1098650
Commit-Queue: Makoto Shimazu <shimazu@chromium.org>
Reviewed-by: Matt Falkenhagen <falken@chromium.org>
Cr-Commit-Position: refs/heads/master@{#567205}

content/common/service_worker/service_worker_utils.cc

@@ -4,9 +4,6 @@
 
 #include "content/common/service_worker/service_worker_utils.h"
 
-#include <sstream>
-#include <string>
-
 #include "base/command_line.h"
 #include "base/feature_list.h"
 #include "base/logging.h"
@@ -147,22 +144,6 @@ bool ServiceWorkerUtils::IsServicificationEnabled() {
          base::FeatureList::IsEnabled(features::kServiceWorkerServicification);
 }
 
-// static
-std::string ServiceWorkerUtils::ErrorTypeToString(
-    blink::mojom::ServiceWorkerErrorType error) {
-  std::ostringstream oss;
-  oss << error;
-  return oss.str();
-}
-
-// static
-std::string ServiceWorkerUtils::ClientTypeToString(
-    blink::mojom::ServiceWorkerClientType type) {
-  std::ostringstream oss;
-  oss << type;
-  return oss.str();
-}
-
 bool ServiceWorkerUtils::ExtractSinglePartHttpRange(
     const net::HttpRequestHeaders& headers,
     bool* has_range_out,

content/common/service_worker/service_worker_utils.h

@@ -5,6 +5,9 @@
 #ifndef CONTENT_COMMON_SERVICE_WORKER_SERVICE_WORKER_UTILS_H_
 #define CONTENT_COMMON_SERVICE_WORKER_SERVICE_WORKER_UTILS_H_
 
+#include <sstream>
+#include <string>
+
 #include "base/command_line.h"
 #include "base/macros.h"
 #include "content/common/content_export.h"
@@ -13,7 +16,6 @@
 #include "content/public/common/content_switches.h"
 #include "content/public/common/resource_type.h"
 #include "net/http/http_request_headers.h"
-#include "third_party/blink/public/mojom/service_worker/service_worker_error_type.mojom.h"
 #include "url/gurl.h"
 
 namespace content {
@@ -56,11 +58,12 @@ class ServiceWorkerUtils {
     return provider_id < kInvalidServiceWorkerProviderId;
   }
 
-  static std::string ErrorTypeToString(
-      blink::mojom::ServiceWorkerErrorType error);
-
-  static std::string ClientTypeToString(
-      blink::mojom::ServiceWorkerClientType type);
+  template <typename T>
+  static std::string MojoEnumToString(T mojo_enum) {
+    std::ostringstream oss;
+    oss << mojo_enum;
+    return oss.str();
+  }
 
   // Sets |has_range| to true if |headers| specify a single range request, and
   // |offset| and |size| to the range. Returns true on valid input (regardless

content/renderer/service_worker/service_worker_context_client.cc

@@ -951,6 +951,10 @@ void ServiceWorkerContextClient::DidHandleActivateEvent(
     int request_id,
     blink::mojom::ServiceWorkerEventStatus status,
     double event_dispatch_time) {
+  TRACE_EVENT2("ServiceWorker",
+               "ServiceWorkerContextClient::DidHandleActivateEvent", "event_id",
+               request_id, "status",
+               ServiceWorkerUtils::MojoEnumToString(status));
   RunEventCallback(&context_->activate_event_callbacks,
                    context_->timeout_timer.get(), request_id, status,
                    base::Time::FromDoubleT(event_dispatch_time));
@@ -960,6 +964,10 @@ void ServiceWorkerContextClient::DidHandleBackgroundFetchAbortEvent(
     int request_id,
     blink::mojom::ServiceWorkerEventStatus status,
     double event_dispatch_time) {
+  TRACE_EVENT2("ServiceWorker",
+               "ServiceWorkerContextClient::DidHandleBackgroundFetchAbortEvent",
+               "event_id", request_id, "status",
+               ServiceWorkerUtils::MojoEnumToString(status));
   RunEventCallback(&context_->background_fetch_abort_event_callbacks,
                    context_->timeout_timer.get(), request_id, status,
                    base::Time::FromDoubleT(event_dispatch_time));
@@ -969,6 +977,10 @@ void ServiceWorkerContextClient::DidHandleBackgroundFetchClickEvent(
     int request_id,
     blink::mojom::ServiceWorkerEventStatus status,
     double event_dispatch_time) {
+  TRACE_EVENT2("ServiceWorker",
+               "ServiceWorkerContextClient::DidHandleBackgroundFetchClickEvent",
+               "event_id", request_id, "status",
+               ServiceWorkerUtils::MojoEnumToString(status));
   RunEventCallback(&context_->background_fetch_click_event_callbacks,
                    context_->timeout_timer.get(), request_id, status,
                    base::Time::FromDoubleT(event_dispatch_time));
@@ -978,6 +990,10 @@ void ServiceWorkerContextClient::DidHandleBackgroundFetchFailEvent(
     int request_id,
     blink::mojom::ServiceWorkerEventStatus status,
     double event_dispatch_time) {
+  TRACE_EVENT2("ServiceWorker",
+               "ServiceWorkerContextClient::DidHandleBackgroundFetchFailEvent",
+               "event_id", request_id, "status",
+               ServiceWorkerUtils::MojoEnumToString(status));
   RunEventCallback(&context_->background_fetch_fail_event_callbacks,
                    context_->timeout_timer.get(), request_id, status,
                    base::Time::FromDoubleT(event_dispatch_time));
@@ -987,6 +1003,10 @@ void ServiceWorkerContextClient::DidHandleBackgroundFetchedEvent(
     int request_id,
     blink::mojom::ServiceWorkerEventStatus status,
     double event_dispatch_time) {
+  TRACE_EVENT2("ServiceWorker",
+               "ServiceWorkerContextClient::DidHandleBackgroundFetchedEvent",
+               "event_id", request_id, "status",
+               ServiceWorkerUtils::MojoEnumToString(status));
   RunEventCallback(&context_->background_fetched_event_callbacks,
                    context_->timeout_timer.get(), request_id, status,
                    base::Time::FromDoubleT(event_dispatch_time));
@@ -996,6 +1016,10 @@ void ServiceWorkerContextClient::DidHandleCookieChangeEvent(
     int request_id,
     blink::mojom::ServiceWorkerEventStatus status,
     double event_dispatch_time) {
+  TRACE_EVENT2("ServiceWorker",
+               "ServiceWorkerContextClient::DidHandleCookieChangeEvent",
+               "event_id", request_id, "status",
+               ServiceWorkerUtils::MojoEnumToString(status));
   RunEventCallback(&context_->cookie_change_event_callbacks,
                    context_->timeout_timer.get(), request_id, status,
                    base::Time::FromDoubleT(event_dispatch_time));
@@ -1005,6 +1029,10 @@ void ServiceWorkerContextClient::DidHandleExtendableMessageEvent(
     int request_id,
     blink::mojom::ServiceWorkerEventStatus status,
     double event_dispatch_time) {
+  TRACE_EVENT2("ServiceWorker",
+               "ServiceWorkerContextClient::DidHandleExtendableMessageEvent",
+               "event_id", request_id, "status",
+               ServiceWorkerUtils::MojoEnumToString(status));
   RunEventCallback(&context_->message_event_callbacks,
                    context_->timeout_timer.get(), request_id, status,
                    base::Time::FromDoubleT(event_dispatch_time));
@@ -1014,6 +1042,10 @@ void ServiceWorkerContextClient::DidHandleInstallEvent(
     int event_id,
     blink::mojom::ServiceWorkerEventStatus status,
     double event_dispatch_time) {
+  TRACE_EVENT2("ServiceWorker",
+               "ServiceWorkerContextClient::DidHandleInstallEvent", "event_id",
+               event_id, "status",
+               ServiceWorkerUtils::MojoEnumToString(status));
   RunEventCallback(&context_->install_event_callbacks,
                    context_->timeout_timer.get(), event_id, status,
                    proxy_->HasFetchEventHandler(),
@@ -1023,6 +1055,9 @@ void ServiceWorkerContextClient::DidHandleInstallEvent(
 void ServiceWorkerContextClient::RespondToFetchEventWithNoResponse(
     int fetch_event_id,
     double event_dispatch_time) {
+  TRACE_EVENT1("ServiceWorker",
+               "ServiceWorkerContextClient::RespondToFetchEventWithNoResponse",
+               "event_id", fetch_event_id);
   DCHECK(base::ContainsKey(context_->fetch_response_callbacks, fetch_event_id));
   const mojom::ServiceWorkerFetchResponseCallbackPtr& response_callback =
       context_->fetch_response_callbacks[fetch_event_id];
@@ -1035,6 +1070,9 @@ void ServiceWorkerContextClient::RespondToFetchEvent(
     int fetch_event_id,
     const blink::WebServiceWorkerResponse& web_response,
     double event_dispatch_time) {
+  TRACE_EVENT1("ServiceWorker",
+               "ServiceWorkerContextClient::RespondToFetchEvent", "event_id",
+               fetch_event_id);
   DCHECK(base::ContainsKey(context_->fetch_response_callbacks, fetch_event_id));
   ServiceWorkerResponse response(
       GetServiceWorkerResponseFromWebResponse(web_response));
@@ -1063,6 +1101,10 @@ void ServiceWorkerContextClient::RespondToFetchEventWithResponseStream(
     const blink::WebServiceWorkerResponse& web_response,
     blink::WebServiceWorkerStreamHandle* web_body_as_stream,
     double event_dispatch_time) {
+  TRACE_EVENT1(
+      "ServiceWorker",
+      "ServiceWorkerContextClient::RespondToFetchEventWithResponseStream",
+      "event_id", fetch_event_id);
   DCHECK(base::ContainsKey(context_->fetch_response_callbacks, fetch_event_id));
   ServiceWorkerResponse response(
       GetServiceWorkerResponseFromWebResponse(web_response));
@@ -1090,9 +1132,10 @@ void ServiceWorkerContextClient::DidHandleFetchEvent(
     double event_dispatch_time) {
   // This TRACE_EVENT is used for perf benchmark to confirm if all of fetch
   // events have completed. (crbug.com/736697)
-  TRACE_EVENT1("ServiceWorker",
+  TRACE_EVENT2("ServiceWorker",
                "ServiceWorkerContextClient::DidHandleFetchEvent", "event_id",
-               event_id);
+               event_id, "status",
+               ServiceWorkerUtils::MojoEnumToString(status));
   if (RunEventCallback(&context_->fetch_event_callbacks,
                        context_->timeout_timer.get(), event_id, status,
                        base::Time::FromDoubleT(event_dispatch_time))) {
@@ -1104,6 +1147,10 @@ void ServiceWorkerContextClient::DidHandleNotificationClickEvent(
     int request_id,
     blink::mojom::ServiceWorkerEventStatus status,
     double event_dispatch_time) {
+  TRACE_EVENT2("ServiceWorker",
+               "ServiceWorkerContextClient::DidHandleNotificationClickEvent",
+               "event_id", request_id, "status",
+               ServiceWorkerUtils::MojoEnumToString(status));
   RunEventCallback(&context_->notification_click_event_callbacks,
                    context_->timeout_timer.get(), request_id, status,
                    base::Time::FromDoubleT(event_dispatch_time));
@@ -1113,6 +1160,10 @@ void ServiceWorkerContextClient::DidHandleNotificationCloseEvent(
     int request_id,
     blink::mojom::ServiceWorkerEventStatus status,
     double event_dispatch_time) {
+  TRACE_EVENT2("ServiceWorker",
+               "ServiceWorkerContextClient::DidHandleNotificationCloseEvent",
+               "event_id", request_id, "status",
+               ServiceWorkerUtils::MojoEnumToString(status));
   RunEventCallback(&context_->notification_close_event_callbacks,
                    context_->timeout_timer.get(), request_id, status,
                    base::Time::FromDoubleT(event_dispatch_time));
@@ -1122,6 +1173,10 @@ void ServiceWorkerContextClient::DidHandlePushEvent(
     int request_id,
     blink::mojom::ServiceWorkerEventStatus status,
     double event_dispatch_time) {
+  TRACE_EVENT2("ServiceWorker",
+               "ServiceWorkerContextClient::DidHandlePushEvent", "event_id",
+               request_id, "status",
+               ServiceWorkerUtils::MojoEnumToString(status));
   RunEventCallback(&context_->push_event_callbacks,
                    context_->timeout_timer.get(), request_id, status,
                    base::Time::FromDoubleT(event_dispatch_time));
@@ -1131,6 +1186,10 @@ void ServiceWorkerContextClient::DidHandleSyncEvent(
     int request_id,
     blink::mojom::ServiceWorkerEventStatus status,
     double event_dispatch_time) {
+  TRACE_EVENT2("ServiceWorker",
+               "ServiceWorkerContextClient::DidHandleSyncEvent", "event_id",
+               request_id, "status",
+               ServiceWorkerUtils::MojoEnumToString(status));
   RunEventCallback(&context_->sync_event_callbacks,
                    context_->timeout_timer.get(), request_id, status,
                    base::Time::FromDoubleT(event_dispatch_time));
@@ -1140,6 +1199,9 @@ void ServiceWorkerContextClient::RespondToAbortPaymentEvent(
     int event_id,
     bool payment_aborted,
     double dispatch_event_time) {
+  TRACE_EVENT1("ServiceWorker",
+               "ServiceWorkerContextClient::RespondToAbortPaymentEvent",
+               "event_id", event_id);
   DCHECK(base::ContainsKey(context_->abort_payment_result_callbacks, event_id));
   const payments::mojom::PaymentHandlerResponseCallbackPtr& result_callback =
       context_->abort_payment_result_callbacks[event_id];
@@ -1152,6 +1214,10 @@ void ServiceWorkerContextClient::DidHandleAbortPaymentEvent(
     int event_id,
     blink::mojom::ServiceWorkerEventStatus status,
     double dispatch_event_time) {
+  TRACE_EVENT2("ServiceWorker",
+               "ServiceWorkerContextClient::DidHandleAbortPaymentEvent",
+               "event_id", event_id, "status",
+               ServiceWorkerUtils::MojoEnumToString(status));
   if (RunEventCallback(&context_->abort_payment_event_callbacks,
                        context_->timeout_timer.get(), event_id, status,
                        base::Time::FromDoubleT(dispatch_event_time))) {
@@ -1163,6 +1229,9 @@ void ServiceWorkerContextClient::RespondToCanMakePaymentEvent(
     int event_id,
     bool can_make_payment,
     double dispatch_event_time) {
+  TRACE_EVENT1("ServiceWorker",
+               "ServiceWorkerContextClient::RespondToCanMakePaymentEvent",
+               "event_id", event_id);
   DCHECK(
       base::ContainsKey(context_->can_make_payment_result_callbacks, event_id));
   const payments::mojom::PaymentHandlerResponseCallbackPtr& result_callback =
@@ -1176,6 +1245,10 @@ void ServiceWorkerContextClient::DidHandleCanMakePaymentEvent(
     int event_id,
     blink::mojom::ServiceWorkerEventStatus status,
     double dispatch_event_time) {
+  TRACE_EVENT2("ServiceWorker",
+               "ServiceWorkerContextClient::DidHandleCanMakePaymentEvent",
+               "event_id", event_id, "status",
+               ServiceWorkerUtils::MojoEnumToString(status));
   if (RunEventCallback(&context_->can_make_payment_event_callbacks,
                        context_->timeout_timer.get(), event_id, status,
                        base::Time::FromDoubleT(dispatch_event_time))) {
@@ -1187,6 +1260,9 @@ void ServiceWorkerContextClient::RespondToPaymentRequestEvent(
     int payment_request_id,
     const blink::WebPaymentHandlerResponse& web_response,
     double dispatch_event_time) {
+  TRACE_EVENT1("ServiceWorker",
+               "ServiceWorkerContextClient::RespondToPaymentRequestEvent",
+               "event_id", payment_request_id);
   DCHECK(base::ContainsKey(context_->payment_response_callbacks,
                            payment_request_id));
   const payments::mojom::PaymentHandlerResponseCallbackPtr& response_callback =
@@ -1204,6 +1280,10 @@ void ServiceWorkerContextClient::DidHandlePaymentRequestEvent(
     int payment_request_id,
     blink::mojom::ServiceWorkerEventStatus status,
     double event_dispatch_time) {
+  TRACE_EVENT2("ServiceWorker",
+               "ServiceWorkerContextClient::DidHandlePaymentRequestEvent",
+               "event_id", payment_request_id, "status",
+               ServiceWorkerUtils::MojoEnumToString(status));
   if (RunEventCallback(&context_->payment_request_event_callbacks,
                        context_->timeout_timer.get(), payment_request_id,
                        status, base::Time::FromDoubleT(event_dispatch_time))) {
@@ -1303,6 +1383,10 @@ void ServiceWorkerContextClient::DispatchOrQueueFetchEvent(
     mojom::DispatchFetchEventParamsPtr params,
     mojom::ServiceWorkerFetchResponseCallbackPtr response_callback,
     DispatchFetchEventCallback callback) {
+  TRACE_EVENT2("ServiceWorker",
+               "ServiceWorkerContextClient::DispatchOrQueueFetchEvent", "url",
+               params->request.url.spec(), "queued",
+               RequestedTermination() ? "true" : "false");
   if (RequestedTermination()) {
     context_->timeout_timer->PushPendingTask(base::BindOnce(
         &ServiceWorkerContextClient::DispatchFetchEvent, GetWeakPtr(),
@@ -1318,11 +1402,11 @@ void ServiceWorkerContextClient::DispatchSyncEvent(
     bool last_chance,
     base::TimeDelta timeout,
     DispatchSyncEventCallback callback) {
-  TRACE_EVENT0("ServiceWorker",
-               "ServiceWorkerContextClient::DispatchSyncEvent");
   int request_id = context_->timeout_timer->StartEventWithCustomTimeout(
       CreateAbortCallback(&context_->sync_event_callbacks), timeout);
   context_->sync_event_callbacks.emplace(request_id, std::move(callback));
+  TRACE_EVENT1("ServiceWorker", "ServiceWorkerContextClient::DispatchSyncEvent",
+               "request_id", request_id);
 
   // TODO(jkarlin): Make this blink::WebString::FromUTF8Lenient once
   // https://crrev.com/1768063002/ lands.
@@ -1333,14 +1417,15 @@ void ServiceWorkerContextClient::DispatchSyncEvent(
 void ServiceWorkerContextClient::DispatchAbortPaymentEvent(
     payments::mojom::PaymentHandlerResponseCallbackPtr response_callback,
     DispatchAbortPaymentEventCallback callback) {
-  TRACE_EVENT0("ServiceWorker",
-               "ServiceWorkerContextClient::DispatchAbortPaymentEvent");
   int event_id = context_->timeout_timer->StartEvent(
       CreateAbortCallback(&context_->abort_payment_event_callbacks));
   context_->abort_payment_event_callbacks.emplace(event_id,
                                                   std::move(callback));
   context_->abort_payment_result_callbacks.emplace(
       event_id, std::move(response_callback));
+  TRACE_EVENT1("ServiceWorker",
+               "ServiceWorkerContextClient::DispatchAbortPaymentEvent",
+               "event_id", event_id);
   proxy_->DispatchAbortPaymentEvent(event_id);
 }
 
@@ -1348,14 +1433,15 @@ void ServiceWorkerContextClient::DispatchCanMakePaymentEvent(
     payments::mojom::CanMakePaymentEventDataPtr eventData,
     payments::mojom::PaymentHandlerResponseCallbackPtr response_callback,
     DispatchCanMakePaymentEventCallback callback) {
-  TRACE_EVENT0("ServiceWorker",
-               "ServiceWorkerContextClient::DispatchCanMakePaymentEvent");
   int event_id = context_->timeout_timer->StartEvent(
       CreateAbortCallback(&context_->can_make_payment_event_callbacks));
   context_->can_make_payment_event_callbacks.emplace(event_id,
                                                      std::move(callback));
   context_->can_make_payment_result_callbacks.emplace(
       event_id, std::move(response_callback));
+  TRACE_EVENT1("ServiceWorker",
+               "ServiceWorkerContextClient::DispatchCanMakePaymentEvent",
+               "event_id", event_id);
 
   blink::WebCanMakePaymentEventData webEventData =
       mojo::ConvertTo<blink::WebCanMakePaymentEventData>(std::move(eventData));
@@ -1366,14 +1452,15 @@ void ServiceWorkerContextClient::DispatchPaymentRequestEvent(
     payments::mojom::PaymentRequestEventDataPtr eventData,
     payments::mojom::PaymentHandlerResponseCallbackPtr response_callback,
     DispatchPaymentRequestEventCallback callback) {
-  TRACE_EVENT0("ServiceWorker",
-               "ServiceWorkerContextClient::DispatchPaymentRequestEvent");
   int event_id = context_->timeout_timer->StartEvent(
       CreateAbortCallback(&context_->payment_request_event_callbacks));
   context_->payment_request_event_callbacks.emplace(event_id,
                                                     std::move(callback));
   context_->payment_response_callbacks.emplace(event_id,
                                                std::move(response_callback));
+  TRACE_EVENT1("ServiceWorker",
+               "ServiceWorkerContextClient::DispatchPaymentRequestEvent",
+               "event_id", event_id);
 
   blink::WebPaymentRequestEventData webEventData =
       mojo::ConvertTo<blink::WebPaymentRequestEventData>(std::move(eventData));
@@ -1398,11 +1485,12 @@ void ServiceWorkerContextClient::SendWorkerStarted() {
 
 void ServiceWorkerContextClient::DispatchActivateEvent(
     DispatchActivateEventCallback callback) {
-  TRACE_EVENT0("ServiceWorker",
-               "ServiceWorkerContextClient::DispatchActivateEvent");
   int request_id = context_->timeout_timer->StartEvent(
       CreateAbortCallback(&context_->activate_event_callbacks));
   context_->activate_event_callbacks.emplace(request_id, std::move(callback));
+  TRACE_EVENT1("ServiceWorker",
+               "ServiceWorkerContextClient::DispatchActivateEvent",
+               "request_id", request_id);
   proxy_->DispatchActivateEvent(request_id);
 }
 
@@ -1411,12 +1499,13 @@ void ServiceWorkerContextClient::DispatchBackgroundFetchAbortEvent(
     const std::string& unique_id,
     const std::vector<BackgroundFetchSettledFetch>& fetches,
     DispatchBackgroundFetchAbortEventCallback callback) {
-  TRACE_EVENT0("ServiceWorker",
-               "ServiceWorkerContextClient::DispatchBackgroundFetchAbortEvent");
   int request_id = context_->timeout_timer->StartEvent(
       CreateAbortCallback(&context_->background_fetch_abort_event_callbacks));
   context_->background_fetch_abort_event_callbacks.emplace(request_id,
                                                            std::move(callback));
+  TRACE_EVENT1("ServiceWorker",
+               "ServiceWorkerContextClient::DispatchBackgroundFetchAbortEvent",
+               "request_id", request_id);
 
   blink::WebVector<blink::WebBackgroundFetchSettledFetch> web_fetches(
       fetches.size());
@@ -1434,12 +1523,13 @@ void ServiceWorkerContextClient::DispatchBackgroundFetchClickEvent(
     const std::string& developer_id,
     mojom::BackgroundFetchState state,
     DispatchBackgroundFetchClickEventCallback callback) {
-  TRACE_EVENT0("ServiceWorker",
-               "ServiceWorkerContextClient::DispatchBackgroundFetchClickEvent");
   int request_id = context_->timeout_timer->StartEvent(
       CreateAbortCallback(&context_->background_fetch_click_event_callbacks));
   context_->background_fetch_click_event_callbacks.emplace(request_id,
                                                            std::move(callback));
+  TRACE_EVENT1("ServiceWorker",
+               "ServiceWorkerContextClient::DispatchBackgroundFetchClickEvent",
+               "request_id", request_id);
 
   // TODO(peter): Use typemap when this is moved to blink-side.
   blink::WebServiceWorkerContextProxy::BackgroundFetchState web_state =
@@ -1454,12 +1544,13 @@ void ServiceWorkerContextClient::DispatchBackgroundFetchFailEvent(
     const std::string& unique_id,
     const std::vector<BackgroundFetchSettledFetch>& fetches,
     DispatchBackgroundFetchFailEventCallback callback) {
-  TRACE_EVENT0("ServiceWorker",
-               "ServiceWorkerContextClient::DispatchBackgroundFetchFailEvent");
   int request_id = context_->timeout_timer->StartEvent(
       CreateAbortCallback(&context_->background_fetch_fail_event_callbacks));
   context_->background_fetch_fail_event_callbacks.emplace(request_id,
                                                           std::move(callback));
+  TRACE_EVENT1("ServiceWorker",
+               "ServiceWorkerContextClient::DispatchBackgroundFetchFailEvent",
+               "request_id", request_id);
 
   blink::WebVector<blink::WebBackgroundFetchSettledFetch> web_fetches(
       fetches.size());
@@ -1478,12 +1569,13 @@ void ServiceWorkerContextClient::DispatchBackgroundFetchedEvent(
     const std::string& unique_id,
     const std::vector<BackgroundFetchSettledFetch>& fetches,
     DispatchBackgroundFetchedEventCallback callback) {
-  TRACE_EVENT0("ServiceWorker",
-               "ServiceWorkerContextClient::DispatchBackgroundFetchedEvent");
   int request_id = context_->timeout_timer->StartEvent(
       CreateAbortCallback(&context_->background_fetched_event_callbacks));
   context_->background_fetched_event_callbacks.emplace(request_id,
                                                        std::move(callback));
+  TRACE_EVENT1("ServiceWorker",
+               "ServiceWorkerContextClient::DispatchBackgroundFetchedEvent",
+               "request_id", request_id);
 
   blink::WebVector<blink::WebBackgroundFetchSettledFetch> web_fetches(
       fetches.size());
@@ -1518,23 +1610,25 @@ void ServiceWorkerContextClient::InitializeGlobalScope(
 
 void ServiceWorkerContextClient::DispatchInstallEvent(
     DispatchInstallEventCallback callback) {
-  TRACE_EVENT0("ServiceWorker",
-               "ServiceWorkerContextClient::DispatchInstallEvent");
-
   int event_id = context_->timeout_timer->StartEvent(CreateAbortCallback(
       &context_->install_event_callbacks, false /* has_fetch_handler */));
   context_->install_event_callbacks.emplace(event_id, std::move(callback));
+  TRACE_EVENT1("ServiceWorker",
+               "ServiceWorkerContextClient::DispatchInstallEvent", "event_id",
+               event_id);
+
   proxy_->DispatchInstallEvent(event_id);
 }
 
 void ServiceWorkerContextClient::DispatchExtendableMessageEvent(
     mojom::ExtendableMessageEventPtr event,
     DispatchExtendableMessageEventCallback callback) {
-  TRACE_EVENT0("ServiceWorker",
-               "ServiceWorkerContextClient::DispatchExtendableMessageEvent");
   int request_id = context_->timeout_timer->StartEvent(
       CreateAbortCallback(&context_->message_event_callbacks));
   context_->message_event_callbacks.emplace(request_id, std::move(callback));
+  TRACE_EVENT1("ServiceWorker",
+               "ServiceWorkerContextClient::DispatchExtendableMessageEvent",
+               "request_id", request_id);
 
   if (event->source_info_for_client) {
     blink::WebServiceWorkerClientInfo web_client =
@@ -1567,9 +1661,9 @@ void ServiceWorkerContextClient::DispatchFetchEvent(
 
   // This TRACE_EVENT is used for perf benchmark to confirm if all of fetch
   // events have completed. (crbug.com/736697)
-  TRACE_EVENT1("ServiceWorker",
+  TRACE_EVENT2("ServiceWorker",
                "ServiceWorkerContextClient::DispatchFetchEvent", "event_id",
-               event_id);
+               event_id, "url", params->request.url.spec());
 
   // Set up for navigation preload (FetchEvent#preloadResponse) if needed.
   const bool navigation_preload_sent = !!params->preload_handle;
@@ -1594,13 +1688,13 @@ void ServiceWorkerContextClient::DispatchNotificationClickEvent(
     int action_index,
     const base::Optional<base::string16>& reply,
     DispatchNotificationClickEventCallback callback) {
-  TRACE_EVENT0("ServiceWorker",
-               "ServiceWorkerContextClient::DispatchNotificationClickEvent");
-
   int request_id = context_->timeout_timer->StartEvent(
       CreateAbortCallback(&context_->notification_click_event_callbacks));
   context_->notification_click_event_callbacks.emplace(request_id,
                                                        std::move(callback));
+  TRACE_EVENT1("ServiceWorker",
+               "ServiceWorkerContextClient::DispatchNotificationClickEvent",
+               "request_id", request_id);
 
   blink::WebString web_reply;
   if (reply)
@@ -1615,13 +1709,13 @@ void ServiceWorkerContextClient::DispatchNotificationCloseEvent(
     const std::string& notification_id,
     const PlatformNotificationData& notification_data,
     DispatchNotificationCloseEventCallback callback) {
-  TRACE_EVENT0("ServiceWorker",
-               "ServiceWorkerContextClient::DispatchNotificationCloseEvent");
-
   int request_id = context_->timeout_timer->StartEvent(
       CreateAbortCallback(&context_->notification_close_event_callbacks));
   context_->notification_close_event_callbacks.emplace(request_id,
                                                        std::move(callback));
+  TRACE_EVENT1("ServiceWorker",
+               "ServiceWorkerContextClient::DispatchNotificationCloseEvent",
+               "request_id", request_id);
   proxy_->DispatchNotificationCloseEvent(
       request_id, blink::WebString::FromUTF8(notification_id),
       ToWebNotificationData(notification_data));
@@ -1630,13 +1724,12 @@ void ServiceWorkerContextClient::DispatchNotificationCloseEvent(
 void ServiceWorkerContextClient::DispatchPushEvent(
     const PushEventPayload& payload,
     DispatchPushEventCallback callback) {
-  TRACE_EVENT0("ServiceWorker",
-               "ServiceWorkerContextClient::DispatchPushEvent");
-
   int request_id = context_->timeout_timer->StartEventWithCustomTimeout(
       CreateAbortCallback(&context_->push_event_callbacks),
       base::TimeDelta::FromSeconds(mojom::kPushEventTimeoutSeconds));
   context_->push_event_callbacks.emplace(request_id, std::move(callback));
+  TRACE_EVENT1("ServiceWorker", "ServiceWorkerContextClient::DispatchPushEvent",
+               "request_id", request_id);
 
   // Only set data to be a valid string if the payload had decrypted data.
   blink::WebString data;
@@ -1649,13 +1742,13 @@ void ServiceWorkerContextClient::DispatchCookieChangeEvent(
     const net::CanonicalCookie& cookie,
     ::network::mojom::CookieChangeCause cause,
     DispatchCookieChangeEventCallback callback) {
-  TRACE_EVENT0("ServiceWorker",
-               "ServiceWorkerContextClient::DispatchCookieChangeEvent");
-
   int request_id = context_->timeout_timer->StartEvent(
       CreateAbortCallback(&context_->cookie_change_event_callbacks));
   context_->cookie_change_event_callbacks.emplace(request_id,
                                                   std::move(callback));
+  TRACE_EVENT1("ServiceWorker",
+               "ServiceWorkerContextClient::DispatchCookieChangeEvent",
+               "request_id", request_id);
 
   // TODO(pwnall): Map |cause| to a blink enum. Currently, a cookie overwrite
   //               shows up as delete + insert.
@@ -1681,6 +1774,9 @@ void ServiceWorkerContextClient::OnNavigationPreloadResponse(
     int fetch_event_id,
     std::unique_ptr<blink::WebURLResponse> response,
     std::unique_ptr<blink::WebDataConsumerHandle> data_consumer_handle) {
+  TRACE_EVENT1("ServiceWorker",
+               "ServiceWorkerContextClient::OnNavigationPreloadResponse",
+               "event_id", fetch_event_id);
   proxy_->OnNavigationPreloadResponse(fetch_event_id, std::move(response),
                                       std::move(data_consumer_handle));
 }
@@ -1688,6 +1784,9 @@ void ServiceWorkerContextClient::OnNavigationPreloadResponse(
 void ServiceWorkerContextClient::OnNavigationPreloadError(
     int fetch_event_id,
     std::unique_ptr<blink::WebServiceWorkerError> error) {
+  TRACE_EVENT1("ServiceWorker",
+               "ServiceWorkerContextClient::OnNavigationPreloadError",
+               "event_id", fetch_event_id);
   proxy_->OnNavigationPreloadError(fetch_event_id, std::move(error));
   context_->preload_requests.Remove(fetch_event_id);
 }
@@ -1698,6 +1797,9 @@ void ServiceWorkerContextClient::OnNavigationPreloadComplete(
     int64_t encoded_data_length,
     int64_t encoded_body_length,
     int64_t decoded_body_length) {
+  TRACE_EVENT1("ServiceWorker",
+               "ServiceWorkerContextClient::OnNavigationPreloadComplete",
+               "event_id", fetch_event_id);
   proxy_->OnNavigationPreloadComplete(fetch_event_id, completion_time,
                                       encoded_data_length, encoded_body_length,
                                       decoded_body_length);

content/renderer/service_worker/web_service_worker_provider_impl.cc

@@ -230,7 +230,7 @@ void WebServiceWorkerProviderImpl::OnRegistered(
     blink::mojom::ServiceWorkerRegistrationObjectInfoPtr registration) {
   TRACE_EVENT_ASYNC_END2(
       "ServiceWorker", "WebServiceWorkerProviderImpl::RegisterServiceWorker",
-      this, "Error", ServiceWorkerUtils::ErrorTypeToString(error), "Message",
+      this, "Error", ServiceWorkerUtils::MojoEnumToString(error), "Message",
       error_msg ? *error_msg : "Success");
   if (error != blink::mojom::ServiceWorkerErrorType::kNone) {
     DCHECK(error_msg);
@@ -256,7 +256,7 @@ void WebServiceWorkerProviderImpl::OnDidGetRegistration(
     blink::mojom::ServiceWorkerRegistrationObjectInfoPtr registration) {
   TRACE_EVENT_ASYNC_END2("ServiceWorker",
                          "WebServiceWorkerProviderImpl::GetRegistration", this,
-                         "Error", ServiceWorkerUtils::ErrorTypeToString(error),
+                         "Error", ServiceWorkerUtils::MojoEnumToString(error),
                          "Message", error_msg ? *error_msg : "Success");
   if (error != blink::mojom::ServiceWorkerErrorType::kNone) {
     DCHECK(error_msg);
@@ -292,7 +292,7 @@ void WebServiceWorkerProviderImpl::OnDidGetRegistrations(
         infos) {
   TRACE_EVENT_ASYNC_END2("ServiceWorker",
                          "WebServiceWorkerProviderImpl::GetRegistrations", this,
-                         "Error", ServiceWorkerUtils::ErrorTypeToString(error),
+                         "Error", ServiceWorkerUtils::MojoEnumToString(error),
                          "Message", error_msg ? *error_msg : "Success");
   if (error != blink::mojom::ServiceWorkerErrorType::kNone) {
     DCHECK(error_msg);