Move NavigationRequest tracing to use to use navigation id.

The NavigationThrottleRunner is tracing events related to the
NavigationRequest, however using the delegate pointer does not work to
associate the two logs together. This CL changes both NavigationRequest
and NavigationThrottleRunner to use the navigation id as the common
identifier to tie the tracing events together.

Bug: 1043616
Change-Id: I84594851724f1026fa9c9a5409705a127347a251
Reviewed-on: https://chromium-review.googlesource.com/c/chromium/src/+/2343564
Commit-Queue: Nasko Oskov <nasko@chromium.org>
Reviewed-by: Aaron Colwell <acolwell@chromium.org>
Cr-Commit-Position: refs/heads/master@{#796169}

content/browser/frame_host/navigation_request.cc

@@ -631,8 +631,9 @@ class ScopedNavigationRequestCrashKeys {
 void EnterChildTraceEvent(const char* name, NavigationRequest* request) {
   // Tracing no longer outputs the end event name, so we can simply pass an
   // empty string here.
-  TRACE_EVENT_NESTABLE_ASYNC_END0("navigation", "", request);
-  TRACE_EVENT_NESTABLE_ASYNC_BEGIN0("navigation", name, request);
+  TRACE_EVENT_NESTABLE_ASYNC_END0("navigation", "", request->GetNavigationId());
+  TRACE_EVENT_NESTABLE_ASYNC_BEGIN0("navigation", name,
+                                    request->GetNavigationId());
 }
 
 // Start a new nested async event with the given name and args.
@@ -643,9 +644,9 @@ void EnterChildTraceEvent(const char* name,
                           ArgType arg_value) {
   // Tracing no longer outputs the end event name, so we can simply pass an
   // empty string here.
-  TRACE_EVENT_NESTABLE_ASYNC_END0("navigation", "", request);
-  TRACE_EVENT_NESTABLE_ASYNC_BEGIN1("navigation", name, request, arg_name,
-                                    arg_value);
+  TRACE_EVENT_NESTABLE_ASYNC_END0("navigation", "", request->GetNavigationId());
+  TRACE_EVENT_NESTABLE_ASYNC_BEGIN1(
+      "navigation", name, request->GetNavigationId(), arg_name, arg_value);
 }
 
 network::mojom::RequestDestination GetDestinationFromFrameTreeNode(
@@ -1119,10 +1120,11 @@ NavigationRequest::NavigationRequest(
          commit_params_->frame_policy.has_value());
 
   TRACE_EVENT_NESTABLE_ASYNC_BEGIN2(
-      "navigation", "NavigationRequest", this, "frame_tree_node",
+      "navigation", "NavigationRequest", navigation_id_, "frame_tree_node",
       frame_tree_node_->frame_tree_node_id(), "url",
       common_params_->url.possibly_invalid_spec());
-  TRACE_EVENT_NESTABLE_ASYNC_BEGIN0("navigation", "Initializing", this);
+  TRACE_EVENT_NESTABLE_ASYNC_BEGIN0("navigation", "Initializing",
+                                    navigation_id_);
   NavigationControllerImpl* controller = GetNavigationController();
 
   if (frame_entry) {
@@ -1284,8 +1286,9 @@ NavigationRequest::~NavigationRequest() {
 
   // Close the last child event. Tracing no longer outputs the end event name,
   // so we can simply pass an empty string here.
-  TRACE_EVENT_NESTABLE_ASYNC_END0("navigation", "", this);
-  TRACE_EVENT_NESTABLE_ASYNC_END0("navigation", "NavigationRequest", this);
+  TRACE_EVENT_NESTABLE_ASYNC_END0("navigation", "", navigation_id_);
+  TRACE_EVENT_NESTABLE_ASYNC_END0("navigation", "NavigationRequest",
+                                  navigation_id_);
   if (loading_mem_tracker_)
     loading_mem_tracker_->Cancel();
   ResetExpectedProcess();
@@ -1551,7 +1554,8 @@ void NavigationRequest::StartNavigation(bool is_for_commit) {
   modified_request_headers_.Clear();
   removed_request_headers_.clear();
 
-  throttle_runner_ = base::WrapUnique(new NavigationThrottleRunner(this));
+  throttle_runner_ =
+      base::WrapUnique(new NavigationThrottleRunner(this, navigation_id_));
 
 #if defined(OS_ANDROID)
   navigation_handle_proxy_ = std::make_unique<NavigationHandleProxy>(this);

content/browser/frame_host/navigation_throttle_runner.cc

@@ -56,8 +56,9 @@ const char* GetEventName(NavigationThrottleRunner::Event event) {
 
 }  // namespace
 
-NavigationThrottleRunner::NavigationThrottleRunner(Delegate* delegate)
-    : delegate_(delegate) {}
+NavigationThrottleRunner::NavigationThrottleRunner(Delegate* delegate,
+                                                   int64_t navigation_id)
+    : delegate_(delegate), navigation_id_(navigation_id) {}
 
 NavigationThrottleRunner::~NavigationThrottleRunner() = default;
 
@@ -145,21 +146,30 @@ void NavigationThrottleRunner::AddThrottle(
 void NavigationThrottleRunner::ProcessInternal() {
   DCHECK_NE(Event::NoEvent, current_event_);
   base::WeakPtr<NavigationThrottleRunner> weak_ref = weak_factory_.GetWeakPtr();
+
+  // Capture into a local variable the |navigation_id_| value, since this
+  // object can be freed by any of the throttles being invoked and the trace
+  // events need to be able to use the navigation id safely in such a case.
+  int64_t local_navigation_id = navigation_id_;
+
   for (size_t i = next_index_; i < throttles_.size(); ++i) {
-    TRACE_EVENT1("navigation", GetEventName(current_event_), "throttle",
-                 throttles_[i]->GetNameForLogging());
+    TRACE_EVENT_NESTABLE_ASYNC_BEGIN1(
+        "navigation", GetEventName(current_event_), local_navigation_id,
+        "throttle", throttles_[i]->GetNameForLogging());
+
     NavigationThrottle::ThrottleCheckResult result =
         ExecuteNavigationEvent(throttles_[i].get(), current_event_);
     if (!weak_ref) {
       // The NavigationThrottle execution has destroyed this
       // NavigationThrottleRunner. Return immediately.
+      TRACE_EVENT_NESTABLE_ASYNC_END1("navigation", "", local_navigation_id,
+                                      "result", "deleted");
       return;
     }
-    TRACE_EVENT_ASYNC_STEP_INTO0(
-        "navigation", "NavigationHandle", delegate_,
-        base::StringPrintf("%s: %s: %d", GetEventName(current_event_),
-                           throttles_[i]->GetNameForLogging(),
-                           result.action()));
+    TRACE_EVENT_NESTABLE_ASYNC_END1("navigation", GetEventName(current_event_),
+                                    local_navigation_id, "result",
+                                    result.action());
+
     switch (result.action()) {
       case NavigationThrottle::PROCEED:
         continue;

content/browser/frame_host/navigation_throttle_runner.h

@@ -36,7 +36,7 @@ class CONTENT_EXPORT NavigationThrottleRunner {
         NavigationThrottle::ThrottleCheckResult result) = 0;
   };
 
-  NavigationThrottleRunner(Delegate* delegate);
+  NavigationThrottleRunner(Delegate* delegate, int64_t navigation_id);
   ~NavigationThrottleRunner();
 
   // Will call the appropriate NavigationThrottle function based on |event| on
@@ -68,7 +68,7 @@ class CONTENT_EXPORT NavigationThrottleRunner {
   void ProcessInternal();
   void InformDelegate(const NavigationThrottle::ThrottleCheckResult& result);
 
-  Delegate* delegate_;
+  Delegate* const delegate_;
 
   // A list of Throttles registered for this navigation.
   std::vector<std::unique_ptr<NavigationThrottle>> throttles_;
@@ -76,6 +76,10 @@ class CONTENT_EXPORT NavigationThrottleRunner {
   // The index of the next throttle to check.
   size_t next_index_;
 
+  // The unique id of the navigation which this throttle runner is associated
+  // with.
+  const int64_t navigation_id_;
+
   // The event currently being processed.
   Event current_event_ = Event::NoEvent;
   base::WeakPtrFactory<NavigationThrottleRunner> weak_factory_{this};

content/browser/frame_host/navigation_throttle_runner_unittest.cc

@@ -60,7 +60,7 @@ class NavigationThrottleRunnerTest : public RenderViewHostTestHarness,
 
   void SetUp() override {
     RenderViewHostTestHarness::SetUp();
-    runner_ = std::make_unique<NavigationThrottleRunner>(this);
+    runner_ = std::make_unique<NavigationThrottleRunner>(this, 1);
   }
 
   void Resume() { runner_->CallResumeForTesting(); }