ServiceWorker: Insert TRACE_EVENT to watch a breakdown of the ServiceWorker's...

ServiceWorker: Insert TRACE_EVENT to watch a breakdown of the ServiceWorker's performance on chome://tracing

Add TRACE_EVENT into each IPC message receiver and some important procedure (register, unregister and fetch).

BUG=401389
TEST=N/A

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

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

content/browser/service_worker/embedded_worker_instance.cc

@@ -8,6 +8,7 @@
 #include <utility>
 
 #include "base/bind_helpers.h"
+#include "base/debug/trace_event.h"
 #include "content/browser/devtools/embedded_worker_devtools_manager.h"
 #include "content/browser/service_worker/embedded_worker_registry.h"
 #include "content/browser/service_worker/service_worker_context_core.h"
@@ -136,6 +137,11 @@ void EmbeddedWorkerInstance::Start(int64 service_worker_version_id,
   status_ = STARTING;
   scoped_ptr<EmbeddedWorkerMsg_StartWorker_Params> params(
       new EmbeddedWorkerMsg_StartWorker_Params());
+  TRACE_EVENT_ASYNC_BEGIN2("ServiceWorker",
+                           "EmbeddedWorkerInstance::ProcessAllocate",
+                           params.get(),
+                           "Scope", scope.spec(),
+                           "Script URL", script_url.spec());
   params->embedded_worker_id = embedded_worker_id_;
   params->service_worker_version_id = service_worker_version_id;
   params->scope = scope;
@@ -248,6 +254,10 @@ void EmbeddedWorkerInstance::ProcessAllocated(
   const int64 service_worker_version_id = params->service_worker_version_id;
   process_id_ = process_id;
   GURL script_url(params->script_url);
+  TRACE_EVENT_ASYNC_END1("ServiceWorker",
+                         "EmbeddedWorkerInstance::ProcessAllocate",
+                         params.get(),
+                         "Status", status);
   RegisterToWorkerDevToolsManager(
       process_id,
       context_.get(),

content/browser/service_worker/service_worker_cache_listener.cc

@@ -5,6 +5,7 @@
 #include "content/browser/service_worker/service_worker_cache_listener.h"
 
 #include "base/bind.h"
+#include "base/debug/trace_event.h"
 #include "base/strings/utf_string_conversions.h"
 #include "content/browser/service_worker/service_worker_cache_storage_manager.h"
 #include "content/browser/service_worker/service_worker_context_core.h"
@@ -77,6 +78,8 @@ bool ServiceWorkerCacheListener::OnMessageReceived(
 void ServiceWorkerCacheListener::OnCacheStorageGet(
     int request_id,
     const base::string16& cache_name) {
+  TRACE_EVENT0("ServiceWorker",
+               "ServiceWorkerCacheListener::OnCacheStorageGet");
   context_->cache_manager()->GetCache(
       version_->scope().GetOrigin(),
       base::UTF16ToUTF8(cache_name),
@@ -88,6 +91,8 @@ void ServiceWorkerCacheListener::OnCacheStorageGet(
 void ServiceWorkerCacheListener::OnCacheStorageHas(
     int request_id,
     const base::string16& cache_name) {
+  TRACE_EVENT0("ServiceWorker",
+               "ServiceWorkerCacheListener::OnCacheStorageHas");
   context_->cache_manager()->HasCache(
       version_->scope().GetOrigin(),
       base::UTF16ToUTF8(cache_name),
@@ -99,6 +104,8 @@ void ServiceWorkerCacheListener::OnCacheStorageHas(
 void ServiceWorkerCacheListener::OnCacheStorageCreate(
     int request_id,
     const base::string16& cache_name) {
+  TRACE_EVENT0("ServiceWorker",
+               "ServiceWorkerCacheListener::OnCacheStorageCreate");
   context_->cache_manager()->CreateCache(
       version_->scope().GetOrigin(),
       base::UTF16ToUTF8(cache_name),
@@ -110,6 +117,8 @@ void ServiceWorkerCacheListener::OnCacheStorageCreate(
 void ServiceWorkerCacheListener::OnCacheStorageDelete(
     int request_id,
     const base::string16& cache_name) {
+  TRACE_EVENT0("ServiceWorker",
+               "ServiceWorkerCacheListener::OnCacheStorageDelete");
   context_->cache_manager()->DeleteCache(
       version_->scope().GetOrigin(),
       base::UTF16ToUTF8(cache_name),
@@ -119,6 +128,8 @@ void ServiceWorkerCacheListener::OnCacheStorageDelete(
 }
 
 void ServiceWorkerCacheListener::OnCacheStorageKeys(int request_id) {
+  TRACE_EVENT0("ServiceWorker",
+               "ServiceWorkerCacheListener::OnCacheStorageKeys");
   context_->cache_manager()->EnumerateCaches(
       version_->scope().GetOrigin(),
       base::Bind(&ServiceWorkerCacheListener::OnCacheStorageKeysCallback,

content/browser/service_worker/service_worker_controllee_request_handler.cc

@@ -4,6 +4,7 @@
 
 #include "content/browser/service_worker/service_worker_controllee_request_handler.h"
 
+#include "base/debug/trace_event.h"
 #include "content/browser/service_worker/service_worker_context_core.h"
 #include "content/browser/service_worker/service_worker_metrics.h"
 #include "content/browser/service_worker/service_worker_provider_host.h"
@@ -106,6 +107,11 @@ void ServiceWorkerControlleeRequestHandler::PrepareForMainResource(
     const GURL& url) {
   DCHECK(job_.get());
   DCHECK(context_);
+  TRACE_EVENT_ASYNC_BEGIN1(
+      "ServiceWorker",
+      "ServiceWorkerControlleeRequestHandler::PrepareForMainResource",
+      job_.get(),
+      "URL", url.spec());
   // The corresponding provider_host may already have associated a registration
   // in redirect case, unassociate it now.
   provider_host_->UnassociateRegistration();
@@ -125,6 +131,11 @@ ServiceWorkerControlleeRequestHandler::DidLookupRegistrationForMainResource(
   DCHECK(job_.get());
   if (status != SERVICE_WORKER_OK) {
     job_->FallbackToNetwork();
+    TRACE_EVENT_ASYNC_END1(
+        "ServiceWorker",
+        "ServiceWorkerControlleeRequestHandler::PrepareForMainResource",
+        job_.get(),
+        "Status", status);
     return;
   }
   DCHECK(registration.get());
@@ -149,17 +160,37 @@ ServiceWorkerControlleeRequestHandler::DidLookupRegistrationForMainResource(
                    weak_factory_.GetWeakPtr(),
                    registration,
                    active_version));
+    TRACE_EVENT_ASYNC_END2(
+        "ServiceWorker",
+        "ServiceWorkerControlleeRequestHandler::PrepareForMainResource",
+        job_.get(),
+        "Status", status,
+        "Info", "Wait until finished SW activation");
     return;
   }
 
   if (!active_version.get() ||
       active_version->status() != ServiceWorkerVersion::ACTIVATED) {
     job_->FallbackToNetwork();
+    TRACE_EVENT_ASYNC_END2(
+        "ServiceWorker",
+        "ServiceWorkerControlleeRequestHandler::PrepareForMainResource",
+        job_.get(),
+        "Status", status,
+        "Info",
+        "ServiceWorkerVersion is not available, so falling back to network");
     return;
   }
 
   provider_host_->AssociateRegistration(registration.get());
   job_->ForwardToServiceWorker();
+  TRACE_EVENT_ASYNC_END2(
+      "ServiceWorker",
+      "ServiceWorkerControlleeRequestHandler::PrepareForMainResource",
+      job_.get(),
+      "Status", status,
+      "Info",
+      "Forwarded to the ServiceWorker");
 }
 
 void ServiceWorkerControlleeRequestHandler::OnVersionStatusChanged(

content/browser/service_worker/service_worker_dispatcher_host.cc

@@ -4,6 +4,7 @@
 
 #include "content/browser/service_worker/service_worker_dispatcher_host.h"
 
+#include "base/debug/trace_event.h"
 #include "base/logging.h"
 #include "base/strings/utf_string_conversions.h"
 #include "content/browser/message_port_message_filter.h"
@@ -89,6 +90,8 @@ void ServiceWorkerDispatcherHost::Init(
 }
 
 void ServiceWorkerDispatcherHost::OnFilterAdded(IPC::Sender* sender) {
+  TRACE_EVENT0("ServiceWorker",
+               "ServiceWorkerDispatcherHost::OnFilterAdded");
   BrowserMessageFilter::OnFilterAdded(sender);
   channel_ready_ = true;
   std::vector<IPC::Message*> messages;
@@ -184,6 +187,8 @@ void ServiceWorkerDispatcherHost::OnRegisterServiceWorker(
     int provider_id,
     const GURL& pattern,
     const GURL& script_url) {
+  TRACE_EVENT0("ServiceWorker",
+               "ServiceWorkerDispatcherHost::OnRegisterServiceWorker");
   if (!GetContext()) {
     Send(new ServiceWorkerMsg_ServiceWorkerRegistrationError(
         thread_id,
@@ -213,6 +218,11 @@ void ServiceWorkerDispatcherHost::OnRegisterServiceWorker(
     BadMessageReceived();
     return;
   }
+  TRACE_EVENT_ASYNC_BEGIN2("ServiceWorker",
+                           "ServiceWorkerDispatcherHost::RegisterServiceWorker",
+                           request_id,
+                           "Pattern", pattern.spec(),
+                           "Script URL", script_url.spec());
   GetContext()->RegisterServiceWorker(
       pattern,
       script_url,
@@ -230,6 +240,8 @@ void ServiceWorkerDispatcherHost::OnUnregisterServiceWorker(
     int request_id,
     int provider_id,
     const GURL& pattern) {
+  TRACE_EVENT0("ServiceWorker",
+               "ServiceWorkerDispatcherHost::OnUnregisterServiceWorker");
   if (!GetContext()) {
     Send(new ServiceWorkerMsg_ServiceWorkerUnregistrationError(
         thread_id,
@@ -259,6 +271,11 @@ void ServiceWorkerDispatcherHost::OnUnregisterServiceWorker(
     return;
   }
 
+  TRACE_EVENT_ASYNC_BEGIN1(
+      "ServiceWorker",
+      "ServiceWorkerDispatcherHost::UnregisterServiceWorker",
+      request_id,
+      "Pattern", pattern.spec());
   GetContext()->UnregisterServiceWorker(
       pattern,
       base::Bind(&ServiceWorkerDispatcherHost::UnregistrationComplete,
@@ -271,6 +288,8 @@ void ServiceWorkerDispatcherHost::OnPostMessageToWorker(
     int handle_id,
     const base::string16& message,
     const std::vector<int>& sent_message_port_ids) {
+  TRACE_EVENT0("ServiceWorker",
+               "ServiceWorkerDispatcherHost::OnPostMessageToWorker");
   if (!GetContext())
     return;
 
@@ -291,6 +310,8 @@ void ServiceWorkerDispatcherHost::OnPostMessageToWorker(
 }
 
 void ServiceWorkerDispatcherHost::OnProviderCreated(int provider_id) {
+  TRACE_EVENT0("ServiceWorker",
+               "ServiceWorkerDispatcherHost::OnProviderCreated");
   if (!GetContext())
     return;
   if (GetContext()->GetProviderHost(render_process_id_, provider_id)) {
@@ -304,6 +325,8 @@ void ServiceWorkerDispatcherHost::OnProviderCreated(int provider_id) {
 }
 
 void ServiceWorkerDispatcherHost::OnProviderDestroyed(int provider_id) {
+  TRACE_EVENT0("ServiceWorker",
+               "ServiceWorkerDispatcherHost::OnProviderDestroyed");
   if (!GetContext())
     return;
   if (!GetContext()->GetProviderHost(render_process_id_, provider_id)) {
@@ -315,6 +338,8 @@ void ServiceWorkerDispatcherHost::OnProviderDestroyed(int provider_id) {
 
 void ServiceWorkerDispatcherHost::OnSetHostedVersionId(
     int provider_id, int64 version_id) {
+  TRACE_EVENT0("ServiceWorker",
+               "ServiceWorkerDispatcherHost::OnSetHostedVersionId");
   if (!GetContext())
     return;
   ServiceWorkerProviderHost* provider_host =
@@ -390,10 +415,17 @@ void ServiceWorkerDispatcherHost::RegistrationComplete(
 
   Send(new ServiceWorkerMsg_ServiceWorkerRegistered(
       thread_id, request_id, info, attrs));
+  TRACE_EVENT_ASYNC_END2("ServiceWorker",
+                         "ServiceWorkerDispatcherHost::RegisterServiceWorker",
+                         request_id,
+                         "Registration ID", registration_id,
+                         "Version ID", version_id);
 }
 
 void ServiceWorkerDispatcherHost::OnWorkerReadyForInspection(
     int embedded_worker_id) {
+  TRACE_EVENT0("ServiceWorker",
+               "ServiceWorkerDispatcherHost::OnWorkerReadyForInspection");
   if (!GetContext())
     return;
   EmbeddedWorkerRegistry* registry = GetContext()->embedded_worker_registry();
@@ -405,6 +437,8 @@ void ServiceWorkerDispatcherHost::OnWorkerReadyForInspection(
 void ServiceWorkerDispatcherHost::OnWorkerScriptLoaded(
     int embedded_worker_id,
     int thread_id) {
+  TRACE_EVENT0("ServiceWorker",
+               "ServiceWorkerDispatcherHost::OnWorkerScriptLoaded");
   if (!GetContext())
     return;
   EmbeddedWorkerRegistry* registry = GetContext()->embedded_worker_registry();
@@ -416,6 +450,8 @@ void ServiceWorkerDispatcherHost::OnWorkerScriptLoaded(
 
 void ServiceWorkerDispatcherHost::OnWorkerScriptLoadFailed(
     int embedded_worker_id) {
+  TRACE_EVENT0("ServiceWorker",
+               "ServiceWorkerDispatcherHost::OnWorkerScriptLoadFailed");
   if (!GetContext())
     return;
   EmbeddedWorkerRegistry* registry = GetContext()->embedded_worker_registry();
@@ -425,6 +461,8 @@ void ServiceWorkerDispatcherHost::OnWorkerScriptLoadFailed(
 }
 
 void ServiceWorkerDispatcherHost::OnWorkerStarted(int embedded_worker_id) {
+  TRACE_EVENT0("ServiceWorker",
+               "ServiceWorkerDispatcherHost::OnWorkerStarted");
   if (!GetContext())
     return;
   EmbeddedWorkerRegistry* registry = GetContext()->embedded_worker_registry();
@@ -434,6 +472,8 @@ void ServiceWorkerDispatcherHost::OnWorkerStarted(int embedded_worker_id) {
 }
 
 void ServiceWorkerDispatcherHost::OnWorkerStopped(int embedded_worker_id) {
+  TRACE_EVENT0("ServiceWorker",
+               "ServiceWorkerDispatcherHost::OnWorkerStopped");
   if (!GetContext())
     return;
   EmbeddedWorkerRegistry* registry = GetContext()->embedded_worker_registry();
@@ -444,6 +484,8 @@ void ServiceWorkerDispatcherHost::OnWorkerStopped(int embedded_worker_id) {
 
 void ServiceWorkerDispatcherHost::OnPausedAfterDownload(
     int embedded_worker_id) {
+  TRACE_EVENT0("ServiceWorker",
+               "ServiceWorkerDispatcherHost::OnPausedAfterDownload");
   if (!GetContext())
     return;
   GetContext()->embedded_worker_registry()->OnPausedAfterDownload(
@@ -456,6 +498,8 @@ void ServiceWorkerDispatcherHost::OnReportException(
     int line_number,
     int column_number,
     const GURL& source_url) {
+  TRACE_EVENT0("ServiceWorker",
+               "ServiceWorkerDispatcherHost::OnReportException");
   if (!GetContext())
     return;
   EmbeddedWorkerRegistry* registry = GetContext()->embedded_worker_registry();
@@ -471,6 +515,8 @@ void ServiceWorkerDispatcherHost::OnReportException(
 void ServiceWorkerDispatcherHost::OnReportConsoleMessage(
     int embedded_worker_id,
     const EmbeddedWorkerHostMsg_ReportConsoleMessage_Params& params) {
+  TRACE_EVENT0("ServiceWorker",
+               "ServiceWorkerDispatcherHost::OnReportConsoleMessage");
   if (!GetContext())
     return;
   EmbeddedWorkerRegistry* registry = GetContext()->embedded_worker_registry();
@@ -486,6 +532,8 @@ void ServiceWorkerDispatcherHost::OnReportConsoleMessage(
 
 void ServiceWorkerDispatcherHost::OnIncrementServiceWorkerRefCount(
     int handle_id) {
+  TRACE_EVENT0("ServiceWorker",
+               "ServiceWorkerDispatcherHost::OnIncrementServiceWorkerRefCount");
   ServiceWorkerHandle* handle = handles_.Lookup(handle_id);
   if (!handle) {
     BadMessageReceived();
@@ -496,6 +544,8 @@ void ServiceWorkerDispatcherHost::OnIncrementServiceWorkerRefCount(
 
 void ServiceWorkerDispatcherHost::OnDecrementServiceWorkerRefCount(
     int handle_id) {
+  TRACE_EVENT0("ServiceWorker",
+               "ServiceWorkerDispatcherHost::OnDecrementServiceWorkerRefCount");
   ServiceWorkerHandle* handle = handles_.Lookup(handle_id);
   if (!handle) {
     BadMessageReceived();
@@ -508,6 +558,8 @@ void ServiceWorkerDispatcherHost::OnDecrementServiceWorkerRefCount(
 
 void ServiceWorkerDispatcherHost::OnIncrementRegistrationRefCount(
     int registration_handle_id) {
+  TRACE_EVENT0("ServiceWorker",
+               "ServiceWorkerDispatcherHost::OnIncrementRegistrationRefCount");
   ServiceWorkerRegistrationHandle* handle =
       registration_handles_.Lookup(registration_handle_id);
   if (!handle) {
@@ -519,6 +571,8 @@ void ServiceWorkerDispatcherHost::OnIncrementRegistrationRefCount(
 
 void ServiceWorkerDispatcherHost::OnDecrementRegistrationRefCount(
     int registration_handle_id) {
+  TRACE_EVENT0("ServiceWorker",
+               "ServiceWorkerDispatcherHost::OnDecrementRegistrationRefCount");
   ServiceWorkerRegistrationHandle* handle =
       registration_handles_.Lookup(registration_handle_id);
   if (!handle) {
@@ -540,6 +594,11 @@ void ServiceWorkerDispatcherHost::UnregistrationComplete(
   }
 
   Send(new ServiceWorkerMsg_ServiceWorkerUnregistered(thread_id, request_id));
+  TRACE_EVENT_ASYNC_END1(
+      "ServiceWorker",
+      "ServiceWorkerDispatcherHost::UnregisterServiceWorker",
+      request_id,
+      "Status", status);
 }
 
 void ServiceWorkerDispatcherHost::SendRegistrationError(

content/browser/service_worker/service_worker_fetch_dispatcher.cc

@@ -5,6 +5,7 @@
 #include "content/browser/service_worker/service_worker_fetch_dispatcher.h"
 
 #include "base/bind.h"
+#include "base/debug/trace_event.h"
 #include "content/browser/service_worker/service_worker_version.h"
 
 namespace content {
@@ -57,6 +58,10 @@ void ServiceWorkerFetchDispatcher::DidFailActivation() {
 }
 
 void ServiceWorkerFetchDispatcher::DispatchFetchEvent() {
+  TRACE_EVENT_ASYNC_BEGIN0(
+      "ServiceWorker",
+      "ServiceWorkerFetchDispatcher::DispatchFetchEvent",
+      request_.get());
   version_->DispatchFetchEvent(
       *request_.get(),
       base::Bind(&ServiceWorkerFetchDispatcher::DidPrepare,
@@ -75,6 +80,10 @@ void ServiceWorkerFetchDispatcher::DidFinish(
     ServiceWorkerStatusCode status,
     ServiceWorkerFetchEventResult fetch_result,
     const ServiceWorkerResponse& response) {
+  TRACE_EVENT_ASYNC_END0(
+      "ServiceWorker",
+      "ServiceWorkerFetchDispatcher::DispatchFetchEvent",
+      request_.get());
   DCHECK(!fetch_callback_.is_null());
   FetchCallback fetch_callback = fetch_callback_;
   fetch_callback.Run(status, fetch_result, response);

content/browser/service_worker/service_worker_read_from_cache_job.cc

@@ -7,6 +7,7 @@
 #include <string>
 #include <vector>
 
+#include "base/debug/trace_event.h"
 #include "content/browser/service_worker/service_worker_context_core.h"
 #include "content/browser/service_worker/service_worker_disk_cache.h"
 #include "content/browser/service_worker/service_worker_metrics.h"
@@ -36,6 +37,10 @@ ServiceWorkerReadFromCacheJob::~ServiceWorkerReadFromCacheJob() {
 }
 
 void ServiceWorkerReadFromCacheJob::Start() {
+  TRACE_EVENT_ASYNC_BEGIN1("ServiceWorker",
+                           "ServiceWorkerReadFromCacheJob::ReadInfo",
+                           this,
+                           "URL", request_->url().spec());
   if (!context_) {
     NotifyStartError(net::URLRequestStatus(
         net::URLRequestStatus::FAILED, net::ERR_FAILED));
@@ -119,6 +124,10 @@ bool ServiceWorkerReadFromCacheJob::ReadRawData(
   DCHECK_NE(buf_size, 0);
   DCHECK(bytes_read);
   DCHECK(!reader_->IsReadPending());
+  TRACE_EVENT_ASYNC_BEGIN1("ServiceWorker",
+                           "ServiceWorkerReadFromCacheJob::ReadRawData",
+                           this,
+                           "URL", request_->url().spec());
   reader_->ReadData(
       buf, buf_size, base::Bind(&ServiceWorkerReadFromCacheJob::OnReadComplete,
                                 weak_factory_.GetWeakPtr()));
@@ -149,6 +158,10 @@ void ServiceWorkerReadFromCacheJob::OnReadInfoComplete(int result) {
   if (is_range_request())
     SetupRangeResponse(http_info_io_buffer_->response_data_size);
   http_info_io_buffer_ = NULL;
+  TRACE_EVENT_ASYNC_END1("ServiceWorker",
+                         "ServiceWorkerReadFromCacheJob::ReadInfo",
+                         this,
+                         "Result", result);
   NotifyHeadersComplete();
 }
 
@@ -189,6 +202,10 @@ void ServiceWorkerReadFromCacheJob::OnReadComplete(int result) {
   }
   ServiceWorkerMetrics::CountReadResponseResult(check_result);
   NotifyReadComplete(result);
+  TRACE_EVENT_ASYNC_END1("ServiceWorker",
+                         "ServiceWorkerReadFromCacheJob::ReadRawData",
+                         this,
+                         "Result", result);
 }
 
 }  // namespace content

content/browser/service_worker/service_worker_storage.cc

@@ -7,7 +7,9 @@
 #include <string>
 
 #include "base/bind_helpers.h"
+#include "base/debug/trace_event.h"
 #include "base/files/file_util.h"
+#include "base/hash.h"
 #include "base/message_loop/message_loop.h"
 #include "base/sequenced_task_runner.h"
 #include "base/single_thread_task_runner.h"
@@ -250,6 +252,11 @@ void ServiceWorkerStorage::FindRegistrationForDocument(
     const GURL& document_url,
     const FindRegistrationCallback& callback) {
   DCHECK(!document_url.has_ref());
+  TRACE_EVENT_ASYNC_BEGIN1(
+      "ServiceWorker",
+      "ServiceWorkerStorage::FindRegistrationForDocument",
+      base::Hash(document_url.spec()),
+      "URL", document_url.spec());
   if (!LazyInitialize(base::Bind(
           &ServiceWorkerStorage::FindRegistrationForDocument,
           weak_factory_.GetWeakPtr(), document_url, callback))) {
@@ -767,6 +774,11 @@ void ServiceWorkerStorage::DidFindRegistrationForDocument(
     ServiceWorkerDatabase::Status status) {
   if (status == ServiceWorkerDatabase::STATUS_OK) {
     ReturnFoundRegistration(callback, data, resources);
+    TRACE_EVENT_ASYNC_END1(
+        "ServiceWorker",
+        "ServiceWorkerStorage::FindRegistrationForDocument",
+        base::Hash(document_url.spec()),
+        "Status", "OK");
     return;
   }
 
@@ -777,12 +789,22 @@ void ServiceWorkerStorage::DidFindRegistrationForDocument(
     callback.Run(installing_registration.get() ? SERVICE_WORKER_OK
                                                : SERVICE_WORKER_ERROR_NOT_FOUND,
                  installing_registration);
+    TRACE_EVENT_ASYNC_END1(
+        "ServiceWorker",
+        "ServiceWorkerStorage::FindRegistrationForDocument",
+        base::Hash(document_url.spec()),
+        "Status", status);
     return;
   }
 
   ScheduleDeleteAndStartOver();
   callback.Run(DatabaseStatusToStatusCode(status),
                scoped_refptr<ServiceWorkerRegistration>());
+  TRACE_EVENT_ASYNC_END1(
+      "ServiceWorker",
+      "ServiceWorkerStorage::FindRegistrationForDocument",
+      base::Hash(document_url.spec()),
+      "Status", status);
 }
 
 void ServiceWorkerStorage::DidFindRegistrationForPattern(

content/browser/service_worker/service_worker_version.cc

@@ -572,6 +572,8 @@ void ServiceWorkerVersion::DispatchActivateEventAfterStartWorker(
 void ServiceWorkerVersion::OnGetClientDocuments(int request_id) {
   std::vector<int> client_ids;
   ControlleeByIDMap::iterator it(&controllee_by_id_);
+  TRACE_EVENT0("ServiceWorker",
+               "ServiceWorkerVersion::OnGetClientDocuments");
   while (!it.IsAtEnd()) {
     client_ids.push_back(it.GetCurrentKey());
     it.Advance();
@@ -588,6 +590,8 @@ void ServiceWorkerVersion::OnActivateEventFinished(
     blink::WebServiceWorkerEventResult result) {
   DCHECK(ACTIVATING == status() ||
          REDUNDANT == status()) << status();
+  TRACE_EVENT0("ServiceWorker",
+               "ServiceWorkerVersion::OnActivateEventFinished");
 
   StatusCallback* callback = activate_callbacks_.Lookup(request_id);
   if (!callback) {
@@ -609,6 +613,8 @@ void ServiceWorkerVersion::OnInstallEventFinished(
     int request_id,
     blink::WebServiceWorkerEventResult result) {
   DCHECK_EQ(INSTALLING, status()) << status();
+  TRACE_EVENT0("ServiceWorker",
+               "ServiceWorkerVersion::OnInstallEventFinished");
 
   StatusCallback* callback = install_callbacks_.Lookup(request_id);
   if (!callback) {
@@ -628,6 +634,9 @@ void ServiceWorkerVersion::OnFetchEventFinished(
     int request_id,
     ServiceWorkerFetchEventResult result,
     const ServiceWorkerResponse& response) {
+  TRACE_EVENT1("ServiceWorker",
+               "ServiceWorkerVersion::OnFetchEventFinished",
+               "Request id", request_id);
   FetchCallback* callback = fetch_callbacks_.Lookup(request_id);
   if (!callback) {
     NOTREACHED() << "Got unexpected message: " << request_id;
@@ -641,6 +650,9 @@ void ServiceWorkerVersion::OnFetchEventFinished(
 
 void ServiceWorkerVersion::OnSyncEventFinished(
     int request_id) {
+  TRACE_EVENT1("ServiceWorker",
+               "ServiceWorkerVersion::OnSyncEventFinished",
+               "Request id", request_id);
   StatusCallback* callback = sync_callbacks_.Lookup(request_id);
   if (!callback) {
     NOTREACHED() << "Got unexpected message: " << request_id;
@@ -654,6 +666,9 @@ void ServiceWorkerVersion::OnSyncEventFinished(
 
 void ServiceWorkerVersion::OnPushEventFinished(
     int request_id) {
+  TRACE_EVENT1("ServiceWorker",
+               "ServiceWorkerVersion::OnPushEventFinished",
+               "Request id", request_id);
   StatusCallback* callback = push_callbacks_.Lookup(request_id);
   if (!callback) {
     NOTREACHED() << "Got unexpected message: " << request_id;
@@ -669,6 +684,9 @@ void ServiceWorkerVersion::OnPostMessageToDocument(
     int client_id,
     const base::string16& message,
     const std::vector<int>& sent_message_port_ids) {
+  TRACE_EVENT1("ServiceWorker",
+               "ServiceWorkerVersion::OnPostMessageToDocument",
+               "Client id", client_id);
   ServiceWorkerProviderHost* provider_host =
       controllee_by_id_.Lookup(client_id);
   if (!provider_host) {

content/browser/service_worker/service_worker_write_to_cache_job.cc

@@ -4,6 +4,7 @@
 
 #include "content/browser/service_worker/service_worker_write_to_cache_job.h"
 
+#include "base/debug/trace_event.h"
 #include "content/browser/service_worker/service_worker_context_core.h"
 #include "content/browser/service_worker/service_worker_disk_cache.h"
 #include "content/browser/service_worker/service_worker_metrics.h"
@@ -44,6 +45,10 @@ ServiceWorkerWriteToCacheJob::~ServiceWorkerWriteToCacheJob() {
 }
 
 void ServiceWorkerWriteToCacheJob::Start() {
+  TRACE_EVENT_ASYNC_BEGIN1("ServiceWorker",
+                           "ServiceWorkerWriteToCacheJob::ExecutingJob",
+                           this,
+                           "URL", request_->url().spec());
   if (!context_) {
     NotifyStartError(net::URLRequestStatus(
         net::URLRequestStatus::FAILED, net::ERR_FAILED));
@@ -154,6 +159,10 @@ void ServiceWorkerWriteToCacheJob::InitNetRequest(
 }
 
 void ServiceWorkerWriteToCacheJob::StartNetRequest() {
+  TRACE_EVENT_ASYNC_STEP_INTO0("ServiceWorker",
+                               "ServiceWorkerWriteToCacheJob::ExecutingJob",
+                               this,
+                               "NetRequest");
   net_request_->Start();  // We'll continue in OnResponseStarted.
 }
 
@@ -190,6 +199,10 @@ void ServiceWorkerWriteToCacheJob::WriteHeadersToCache() {
         net::URLRequestStatus::FAILED, net::ERR_FAILED));
     return;
   }
+  TRACE_EVENT_ASYNC_STEP_INTO0("ServiceWorker",
+                               "ServiceWorkerWriteToCacheJob::ExecutingJob",
+                               this,
+                               "WriteHeadersToCache");
   writer_ = context_->storage()->CreateResponseWriter(response_id_);
   info_buffer_ = new HttpResponseInfoIOBuffer(
       new net::HttpResponseInfo(net_request_->response_info()));
@@ -211,11 +224,20 @@ void ServiceWorkerWriteToCacheJob::OnWriteHeadersComplete(int result) {
   }
   http_info_.reset(info_buffer_->http_info.release());
   info_buffer_ = NULL;
+  TRACE_EVENT_ASYNC_STEP_INTO0("ServiceWorker",
+                               "ServiceWorkerWriteToCacheJob::ExecutingJob",
+                               this,
+                               "WriteHeadersToCacheCompleted");
   NotifyHeadersComplete();
 }
 
 void ServiceWorkerWriteToCacheJob::WriteDataToCache(int amount_to_write) {
   DCHECK_NE(0, amount_to_write);
+  TRACE_EVENT_ASYNC_STEP_INTO1("ServiceWorker",
+                               "ServiceWorkerWriteToCacheJob::ExecutingJob",
+                               this,
+                               "WriteDataToCache",
+                               "Amount to write", amount_to_write);
   SetStatus(net::URLRequestStatus(net::URLRequestStatus::IO_PENDING, 0));
   writer_->WriteData(
       io_buffer_.get(),
@@ -243,6 +265,9 @@ void ServiceWorkerWriteToCacheJob::OnWriteDataComplete(int result) {
       ServiceWorkerMetrics::WRITE_OK);
   SetStatus(net::URLRequestStatus());  // Clear the IO_PENDING status
   NotifyReadComplete(result);
+  TRACE_EVENT_ASYNC_END0("ServiceWorker",
+                         "ServiceWorkerWriteToCacheJob::ExecutingJob",
+                         this);
 }
 
 void ServiceWorkerWriteToCacheJob::OnReceivedRedirect(
@@ -250,6 +275,8 @@ void ServiceWorkerWriteToCacheJob::OnReceivedRedirect(
     const net::RedirectInfo& redirect_info,
     bool* defer_redirect) {
   DCHECK_EQ(net_request_, request);
+  TRACE_EVENT0("ServiceWorker",
+               "ServiceWorkerWriteToCacheJob::OnReceivedRedirect");
   // Script resources can't redirect.
   AsyncNotifyDoneHelper(net::URLRequestStatus(
       net::URLRequestStatus::FAILED, net::ERR_FAILED));
@@ -259,6 +286,8 @@ void ServiceWorkerWriteToCacheJob::OnAuthRequired(
     net::URLRequest* request,
     net::AuthChallengeInfo* auth_info) {
   DCHECK_EQ(net_request_, request);
+  TRACE_EVENT0("ServiceWorker",
+               "ServiceWorkerWriteToCacheJob::OnAuthRequired");
   // TODO(michaeln): Pass this thru to our jobs client.
   AsyncNotifyDoneHelper(net::URLRequestStatus(
       net::URLRequestStatus::FAILED, net::ERR_FAILED));
@@ -268,6 +297,8 @@ void ServiceWorkerWriteToCacheJob::OnCertificateRequested(
     net::URLRequest* request,
     net::SSLCertRequestInfo* cert_request_info) {
   DCHECK_EQ(net_request_, request);
+  TRACE_EVENT0("ServiceWorker",
+               "ServiceWorkerWriteToCacheJob::OnCertificateRequested");
   // TODO(michaeln): Pass this thru to our jobs client.
   // see NotifyCertificateRequested.
   AsyncNotifyDoneHelper(net::URLRequestStatus(
@@ -279,6 +310,8 @@ void ServiceWorkerWriteToCacheJob:: OnSSLCertificateError(
     const net::SSLInfo& ssl_info,
     bool fatal) {
   DCHECK_EQ(net_request_, request);
+  TRACE_EVENT0("ServiceWorker",
+               "ServiceWorkerWriteToCacheJob::OnSSLCertificateError");
   // TODO(michaeln): Pass this thru to our jobs client,
   // see NotifySSLCertificateError.
   AsyncNotifyDoneHelper(net::URLRequestStatus(
@@ -289,6 +322,8 @@ void ServiceWorkerWriteToCacheJob::OnBeforeNetworkStart(
     net::URLRequest* request,
     bool* defer) {
   DCHECK_EQ(net_request_, request);
+  TRACE_EVENT0("ServiceWorker",
+               "ServiceWorkerWriteToCacheJob::OnBeforeNetworkStart");
   NotifyBeforeNetworkStart(defer);
 }
 
@@ -333,6 +368,10 @@ void ServiceWorkerWriteToCacheJob::OnReadCompleted(
     WriteDataToCache(bytes_read);
     return;
   }
+  TRACE_EVENT_ASYNC_STEP_INTO0("ServiceWorker",
+                               "ServiceWorkerWriteToCacheJob::ExecutingJob",
+                               this,
+                               "WriteHeadersToCache");
   // We're done with all.
   AsyncNotifyDoneHelper(request->status());
   return;

content/child/service_worker/service_worker_dispatcher.cc

@@ -4,6 +4,7 @@
 
 #include "content/child/service_worker/service_worker_dispatcher.h"
 
+#include "base/debug/trace_event.h"
 #include "base/lazy_instance.h"
 #include "base/stl_util.h"
 #include "base/threading/thread_local.h"
@@ -97,6 +98,11 @@ void ServiceWorkerDispatcher::RegisterServiceWorker(
   }
 
   int request_id = pending_registration_callbacks_.Add(callbacks);
+  TRACE_EVENT_ASYNC_BEGIN2("ServiceWorker",
+                           "ServiceWorkerDispatcher::RegisterServiceWorker",
+                           request_id,
+                           "Pettern", pattern.spec(),
+                           "Script URL", script_url.spec());
   thread_safe_sender_->Send(new ServiceWorkerHostMsg_RegisterServiceWorker(
       CurrentWorkerId(), request_id, provider_id, pattern, script_url));
 }
@@ -117,6 +123,10 @@ void ServiceWorkerDispatcher::UnregisterServiceWorker(
   }
 
   int request_id = pending_unregistration_callbacks_.Add(callbacks);
+  TRACE_EVENT_ASYNC_BEGIN1("ServiceWorker",
+                           "ServiceWorkerDispatcher::UnregisterServiceWorker",
+                           request_id,
+                           "Pettern", pattern.spec());
   thread_safe_sender_->Send(new ServiceWorkerHostMsg_UnregisterServiceWorker(
       CurrentWorkerId(), request_id, provider_id, pattern));
 }
@@ -244,6 +254,10 @@ void ServiceWorkerDispatcher::OnRegistered(
     int request_id,
     const ServiceWorkerRegistrationObjectInfo& info,
     const ServiceWorkerVersionAttributes& attrs) {
+  TRACE_EVENT_ASYNC_STEP_INTO0("ServiceWorker",
+                               "ServiceWorkerDispatcher::RegisterServiceWorker",
+                               request_id,
+                               "OnRegistered");
   WebServiceWorkerRegistrationCallbacks* callbacks =
       pending_registration_callbacks_.Lookup(request_id);
   DCHECK(callbacks);
@@ -258,6 +272,9 @@ void ServiceWorkerDispatcher::OnRegistered(
 
   callbacks->onSuccess(registration);
   pending_registration_callbacks_.Remove(request_id);
+  TRACE_EVENT_ASYNC_END0("ServiceWorker",
+                         "ServiceWorkerDispatcher::RegisterServiceWorker",
+                         request_id);
 }
 
 void ServiceWorkerDispatcher::OnUnregistered(
@@ -265,12 +282,20 @@ void ServiceWorkerDispatcher::OnUnregistered(
     int request_id) {
   WebServiceWorkerUnregistrationCallbacks* callbacks =
       pending_unregistration_callbacks_.Lookup(request_id);
+  TRACE_EVENT_ASYNC_STEP_INTO0(
+      "ServiceWorker",
+      "ServiceWorkerDispatcher::UnregisterServiceWorker",
+      request_id,
+      "OnUnregistered");
   DCHECK(callbacks);
   if (!callbacks)
     return;
   bool is_success = true;
   callbacks->onSuccess(&is_success);
   pending_unregistration_callbacks_.Remove(request_id);
+  TRACE_EVENT_ASYNC_END0("ServiceWorker",
+                         "ServiceWorkerDispatcher::UnregisterServiceWorker",
+                         request_id);
 }
 
 void ServiceWorkerDispatcher::OnRegistrationError(
@@ -278,6 +303,10 @@ void ServiceWorkerDispatcher::OnRegistrationError(
     int request_id,
     WebServiceWorkerError::ErrorType error_type,
     const base::string16& message) {
+  TRACE_EVENT_ASYNC_STEP_INTO0("ServiceWorker",
+                               "ServiceWorkerDispatcher::RegisterServiceWorker",
+                               request_id,
+                               "OnRegistrationError");
   WebServiceWorkerRegistrationCallbacks* callbacks =
       pending_registration_callbacks_.Lookup(request_id);
   DCHECK(callbacks);
@@ -288,6 +317,9 @@ void ServiceWorkerDispatcher::OnRegistrationError(
       new WebServiceWorkerError(error_type, message));
   callbacks->onError(error.release());
   pending_registration_callbacks_.Remove(request_id);
+  TRACE_EVENT_ASYNC_END0("ServiceWorker",
+                         "ServiceWorkerDispatcher::RegisterServiceWorker",
+                         request_id);
 }
 
 void ServiceWorkerDispatcher::OnUnregistrationError(
@@ -295,6 +327,11 @@ void ServiceWorkerDispatcher::OnUnregistrationError(
     int request_id,
     WebServiceWorkerError::ErrorType error_type,
     const base::string16& message) {
+  TRACE_EVENT_ASYNC_STEP_INTO0(
+      "ServiceWorker",
+      "ServiceWorkerDispatcher::UnregisterServiceWorker",
+      request_id,
+      "OnUnregistrationError");
   WebServiceWorkerUnregistrationCallbacks* callbacks =
       pending_unregistration_callbacks_.Lookup(request_id);
   DCHECK(callbacks);
@@ -305,12 +342,19 @@ void ServiceWorkerDispatcher::OnUnregistrationError(
       new WebServiceWorkerError(error_type, message));
   callbacks->onError(error.release());
   pending_unregistration_callbacks_.Remove(request_id);
+  TRACE_EVENT_ASYNC_END0("ServiceWorker",
+                         "ServiceWorkerDispatcher::UnregisterServiceWorker",
+                         request_id);
 }
 
 void ServiceWorkerDispatcher::OnServiceWorkerStateChanged(
     int thread_id,
     int handle_id,
     blink::WebServiceWorkerState state) {
+  TRACE_EVENT2("ServiceWorker",
+               "ServiceWorkerDispatcher::OnServiceWorkerStateChanged",
+               "Thread ID", thread_id,
+               "State", state);
   WorkerObjectMap::iterator worker = service_workers_.find(handle_id);
   if (worker != service_workers_.end())
     worker->second->OnStateChanged(state);
@@ -326,6 +370,9 @@ void ServiceWorkerDispatcher::OnSetVersionAttributes(
     int registration_handle_id,
     int changed_mask,
     const ServiceWorkerVersionAttributes& attributes) {
+  TRACE_EVENT1("ServiceWorker",
+               "ServiceWorkerDispatcher::OnSetVersionAttributes",
+               "Thread ID", thread_id);
   ChangedVersionAttributesMask mask(changed_mask);
   if (mask.installing_changed()) {
     SetInstallingServiceWorker(provider_id,
@@ -347,6 +394,8 @@ void ServiceWorkerDispatcher::OnSetVersionAttributes(
 void ServiceWorkerDispatcher::OnUpdateFound(
     int thread_id,
     const ServiceWorkerRegistrationObjectInfo& info) {
+  TRACE_EVENT0("ServiceWorker",
+               "ServiceWorkerDispatcher::OnUpdateFound");
   RegistrationObjectMap::iterator found = registrations_.find(info.handle_id);
   if (found != registrations_.end())
     found->second->OnUpdateFound();
@@ -440,6 +489,10 @@ void ServiceWorkerDispatcher::OnSetControllerServiceWorker(
     int thread_id,
     int provider_id,
     const ServiceWorkerObjectInfo& info) {
+  TRACE_EVENT2("ServiceWorker",
+               "ServiceWorkerDispatcher::OnSetControllerServiceWorker",
+               "Thread ID", thread_id,
+               "Provider ID", provider_id);
   ProviderContextMap::iterator provider = provider_contexts_.find(provider_id);
   if (provider != provider_contexts_.end()) {
     provider->second->OnSetControllerServiceWorker(provider_id, info);
@@ -462,6 +515,9 @@ void ServiceWorkerDispatcher::OnPostMessage(
   // Make sure we're on the main document thread. (That must be the only
   // thread we get this message)
   DCHECK(ChildThread::current());
+  TRACE_EVENT1("ServiceWorker",
+               "ServiceWorkerDispatcher::OnPostMessage",
+               "Thread ID", thread_id);
 
   ScriptClientMap::iterator found = script_clients_.find(provider_id);
   if (found == script_clients_.end()) {

content/renderer/service_worker/embedded_worker_context_client.cc

@@ -7,6 +7,7 @@
 #include <map>
 #include <string>
 
+#include "base/debug/trace_event.h"
 #include "base/lazy_instance.h"
 #include "base/message_loop/message_loop_proxy.h"
 #include "base/pickle.h"
@@ -99,6 +100,14 @@ EmbeddedWorkerContextClient::EmbeddedWorkerContextClient(
       sender_(ChildThread::current()->thread_safe_sender()),
       main_thread_proxy_(base::MessageLoopProxy::current()),
       weak_factory_(this) {
+  TRACE_EVENT_ASYNC_BEGIN0("ServiceWorker",
+                           "EmbeddedWorkerContextClient::StartingWorkerContext",
+                           this);
+  TRACE_EVENT_ASYNC_STEP_INTO0(
+      "ServiceWorker",
+      "EmbeddedWorkerContextClient::StartingWorkerContext",
+      this,
+      "PrepareWorker");
 }
 
 EmbeddedWorkerContextClient::~EmbeddedWorkerContextClient() {
@@ -176,6 +185,11 @@ void EmbeddedWorkerContextClient::workerContextStarted(
       FROM_HERE,
       base::Bind(&EmbeddedWorkerContextClient::SendWorkerStarted,
                  weak_factory_.GetWeakPtr()));
+  TRACE_EVENT_ASYNC_STEP_INTO0(
+      "ServiceWorker",
+      "EmbeddedWorkerContextClient::StartingWorkerContext",
+      this,
+      "ExecuteScript");
 }
 
 void EmbeddedWorkerContextClient::willDestroyWorkerContext() {
@@ -330,6 +344,9 @@ void EmbeddedWorkerContextClient::OnMessageToWorker(
 
 void EmbeddedWorkerContextClient::SendWorkerStarted() {
   DCHECK(worker_task_runner_->RunsTasksOnCurrentThread());
+  TRACE_EVENT_ASYNC_END0("ServiceWorker",
+                         "EmbeddedWorkerContextClient::StartingWorkerContext",
+                         this);
   Send(new EmbeddedWorkerHostMsg_WorkerStarted(embedded_worker_id_));
 }
 

content/renderer/service_worker/embedded_worker_dispatcher.cc

@@ -69,6 +69,7 @@ void EmbeddedWorkerDispatcher::WorkerContextDestroyed(
 void EmbeddedWorkerDispatcher::OnStartWorker(
     const EmbeddedWorkerMsg_StartWorker_Params& params) {
   DCHECK(!workers_.Lookup(params.embedded_worker_id));
+  TRACE_EVENT0("ServiceWorker", "EmbeddedWorkerDispatcher::OnStartWorker");
   RenderThread::Get()->EnsureWebKitInitialized();
   scoped_ptr<WorkerWrapper> wrapper(
       new WorkerWrapper(blink::WebEmbeddedWorker::create(
@@ -105,6 +106,7 @@ void EmbeddedWorkerDispatcher::OnStartWorker(
 }
 
 void EmbeddedWorkerDispatcher::OnStopWorker(int embedded_worker_id) {
+  TRACE_EVENT0("ServiceWorker", "EmbeddedWorkerDispatcher::OnStopWorker");
   WorkerWrapper* wrapper = workers_.Lookup(embedded_worker_id);
   if (!wrapper) {
     LOG(WARNING) << "Got OnStopWorker for nonexistent worker";
@@ -118,6 +120,8 @@ void EmbeddedWorkerDispatcher::OnStopWorker(int embedded_worker_id) {
 }
 
 void EmbeddedWorkerDispatcher::OnResumeAfterDownload(int embedded_worker_id) {
+  TRACE_EVENT0("ServiceWorker",
+               "EmbeddedWorkerDispatcher::OnResumeAfterDownload");
   WorkerWrapper* wrapper = workers_.Lookup(embedded_worker_id);
   if (!wrapper) {
     LOG(WARNING) << "Got OnResumeAfterDownload for nonexistent worker";

content/renderer/service_worker/service_worker_script_context.cc

@@ -6,6 +6,7 @@
 
 #include <map>
 
+#include "base/debug/trace_event.h"
 #include "base/logging.h"
 #include "content/child/thread_safe_sender.h"
 #include "content/child/webmessageportchannel_impl.h"
@@ -128,11 +129,15 @@ int ServiceWorkerScriptContext::GetRoutingID() const {
 }
 
 void ServiceWorkerScriptContext::OnActivateEvent(int request_id) {
+  TRACE_EVENT0("ServiceWorker",
+               "ServiceWorkerScriptContext::OnActivateEvent");
   proxy_->dispatchActivateEvent(request_id);
 }
 
 void ServiceWorkerScriptContext::OnInstallEvent(int request_id,
                                                 int active_version_id) {
+  TRACE_EVENT0("ServiceWorker",
+               "ServiceWorkerScriptContext::OnInstallEvent");
   proxy_->dispatchInstallEvent(request_id);
 }
 
@@ -140,6 +145,8 @@ void ServiceWorkerScriptContext::OnFetchEvent(
     int request_id,
     const ServiceWorkerFetchRequest& request) {
   blink::WebServiceWorkerRequest webRequest;
+  TRACE_EVENT0("ServiceWorker",
+               "ServiceWorkerScriptContext::OnFetchEvent");
   webRequest.setURL(blink::WebURL(request.url));
   webRequest.setMethod(blink::WebString::fromUTF8(request.method));
   for (std::map<std::string, std::string>::const_iterator it =
@@ -160,11 +167,15 @@ void ServiceWorkerScriptContext::OnFetchEvent(
 }
 
 void ServiceWorkerScriptContext::OnSyncEvent(int request_id) {
+  TRACE_EVENT0("ServiceWorker",
+               "ServiceWorkerScriptContext::OnSyncEvent");
   proxy_->dispatchSyncEvent(request_id);
 }
 
 void ServiceWorkerScriptContext::OnPushEvent(int request_id,
                                              const std::string& data) {
+  TRACE_EVENT0("ServiceWorker",
+               "ServiceWorkerScriptContext::OnPushEvent");
   proxy_->dispatchPushEvent(request_id, blink::WebString::fromUTF8(data));
   Send(new ServiceWorkerHostMsg_PushEventFinished(
       GetRoutingID(), request_id));
@@ -174,6 +185,8 @@ void ServiceWorkerScriptContext::OnPostMessage(
     const base::string16& message,
     const std::vector<int>& sent_message_port_ids,
     const std::vector<int>& new_routing_ids) {
+  TRACE_EVENT0("ServiceWorker",
+               "ServiceWorkerScriptContext::OnPostEvent");
   std::vector<WebMessagePortChannelImpl*> ports;
   if (!sent_message_port_ids.empty()) {
     base::MessageLoopProxy* loop_proxy = embedded_context_->main_thread_proxy();
@@ -189,6 +202,8 @@ void ServiceWorkerScriptContext::OnPostMessage(
 
 void ServiceWorkerScriptContext::OnDidGetClientDocuments(
     int request_id, const std::vector<int>& client_ids) {
+  TRACE_EVENT0("ServiceWorker",
+               "ServiceWorkerScriptContext::OnDidGetClientDocuments");
   blink::WebServiceWorkerClientsCallbacks* callbacks =
       pending_clients_callbacks_.Lookup(request_id);
   if (!callbacks) {