Add async tracing to SWVersion::AddRequest.

content/browser/service_worker/service_worker_version.cc

 // Copyright 2013 The Chromium Authors. All rights reserved.
 // Use of this source code is governed by a BSD-style license that can be
 // found in the LICENSE file.
 
 #include "content/browser/service_worker/service_worker_version.h"
 
 #include <stddef.h>
 
 #include <map>
 #include <string>
@@ skipping 76 matching lines @@
   CallbackArray callbacks;
   callbacks.swap(*callbacks_ptr);
   for (const auto& callback : callbacks)
     callback.Run(arg);
 }
 
 template <typename IDMAP, typename... Params>
 void RunIDMapCallbacks(IDMAP* requests, const Params&... params) {
   typename IDMAP::iterator iter(requests);
   while (!iter.IsAtEnd()) {
+    TRACE_EVENT_ASYNC_END0("ServiceWorker", "ServiceWorkerVersion::Request",
+                           iter.GetCurrentValue());
     iter.GetCurrentValue()->callback.Run(params...);
     iter.Advance();
   }
   requests->Clear();
 }
 
 template <typename CallbackType, typename... Params>
 bool RunIDMapCallback(IDMap<CallbackType, IDMapOwnPointer>* requests,
                       int request_id,
                       const Params&... params) {
   CallbackType* request = requests->Lookup(request_id);
   if (!request)
     return false;
 
+  TRACE_EVENT_ASYNC_END0("ServiceWorker", "ServiceWorkerVersion::Request",
+                         request);
   request->callback.Run(params...);
   requests->Remove(request_id);
   return true;
 }
 
 void RunStartWorkerCallback(
     const StatusCallback& callback,
     scoped_refptr<ServiceWorkerRegistration> protect,
     ServiceWorkerStatusCode status) {
   callback.Run(status);
@@ skipping 769 matching lines @@
     ServiceWorkerVersion* worker,
     const char* service_name)
     : worker_(worker), service_name_(service_name) {}
 
 ServiceWorkerVersion::BaseMojoServiceWrapper::~BaseMojoServiceWrapper() {
   IDMap<PendingRequest<StatusCallback>, IDMapOwnPointer>::iterator iter(
       &worker_->custom_requests_);
   while (!iter.IsAtEnd()) {
     PendingRequest<StatusCallback>* request = iter.GetCurrentValue();
     if (request->mojo_service == service_name_) {
+      TRACE_EVENT_ASYNC_END0("ServiceWorker", "ServiceWorkerVersion::Request",
+                             request);
       request->callback.Run(SERVICE_WORKER_ERROR_FAILED);
       worker_->custom_requests_.Remove(iter.GetCurrentKey());
     }
     iter.Advance();
   }
 }
 
 void ServiceWorkerVersion::OnThreadStarted() {
   if (running_status() == STOPPING)
     return;
@@ skipping 895 matching lines @@
   DVLOG(1) << message;
   UMA_HISTOGRAM_ENUMERATION("ServiceWorker.StartWorker.TimeoutPhase",
                             phase,
                             EmbeddedWorkerInstance::STARTING_PHASE_MAX_VALUE);
 }
 
 template <typename IDMAP>
 void ServiceWorkerVersion::RemoveCallbackAndStopIfRedundant(IDMAP* callbacks,
                                                             int request_id) {
   RestartTick(&idle_time_);
+  auto* request = callbacks->Lookup(request_id);
+  if (request) {
+    TRACE_EVENT_ASYNC_END0("ServiceWorker", "ServiceWorkerVersion::Request",
+                           request);
+  }
   callbacks->Remove(request_id);
   if (is_redundant()) {
     // The stop should be already scheduled, but try to stop immediately, in
     // order to release worker resources soon.
     StopWorkerIfIdle();
   }
 }
 
 template <typename CallbackType>
 int ServiceWorkerVersion::AddRequest(
     const CallbackType& callback,
     IDMap<PendingRequest<CallbackType>, IDMapOwnPointer>* callback_map,
     RequestType request_type,
     ServiceWorkerMetrics::EventType event_type) {
   base::TimeTicks expiration_time =
       base::TimeTicks::Now() +
       base::TimeDelta::FromMinutes(kRequestTimeoutMinutes);
   return AddRequestWithExpiration(callback, callback_map, request_type,
                                   event_type, expiration_time, KILL_ON_TIMEOUT);
 }
 
 template <typename CallbackType>
 int ServiceWorkerVersion::AddRequestWithExpiration(
     const CallbackType& callback,
     IDMap<PendingRequest<CallbackType>, IDMapOwnPointer>* callback_map,
     RequestType request_type,
     ServiceWorkerMetrics::EventType event_type,
     base::TimeTicks expiration,
     TimeoutBehavior timeout_behavior) {
-  int request_id = callback_map->Add(new PendingRequest<CallbackType>(
-      callback, base::TimeTicks::Now(), event_type));
+  PendingRequest<CallbackType>* request = new PendingRequest<CallbackType>(
+      callback, base::TimeTicks::Now(), event_type);
+  int request_id = callback_map->Add(request);
+  TRACE_EVENT_ASYNC_BEGIN2("ServiceWorker", "ServiceWorkerVersion::Request",
+                           request, "Request id", request_id, "Event type",
+                           ServiceWorkerMetrics::EventTypeToString(event_type));
   requests_.push(RequestInfo(request_id, request_type, event_type, expiration,
                              timeout_behavior));
   return request_id;
 }
 
 bool ServiceWorkerVersion::MaybeTimeOutRequest(const RequestInfo& info) {
   switch (info.type) {
     case REQUEST_ACTIVATE:
       return RunIDMapCallback(&activate_requests_, info.id,
                               SERVICE_WORKER_ERROR_TIMEOUT);
@@ skipping 155 matching lines @@
 void ServiceWorkerVersion::OnBeginEvent() {
   if (should_exclude_from_uma_ || running_status() != RUNNING ||
       idle_time_.is_null()) {
     return;
   }
   ServiceWorkerMetrics::RecordTimeBetweenEvents(base::TimeTicks::Now() -
                                                 idle_time_);
 }
 
 }  // namespace content