Adds tracing to MHTML generation call chain.

content/browser/download/mhtml_generation_manager.cc

 // Copyright (c) 2012 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/download/mhtml_generation_manager.h"
 
 #include <map>
 #include <queue>
 #include <utility>
 
 #include "base/bind.h"
 #include "base/files/file.h"
 #include "base/guid.h"
 #include "base/macros.h"
 #include "base/scoped_observer.h"
 #include "base/stl_util.h"
 #include "base/strings/stringprintf.h"
+#include "base/trace_event/trace_event.h"
 #include "content/browser/bad_message.h"
 #include "content/browser/frame_host/frame_tree_node.h"
 #include "content/browser/frame_host/render_frame_host_impl.h"
 #include "content/common/frame_messages.h"
 #include "content/public/browser/browser_thread.h"
 #include "content/public/browser/render_frame_host.h"
 #include "content/public/browser/render_process_host.h"
 #include "content/public/browser/render_process_host_observer.h"
 #include "content/public/browser/web_contents.h"
 #include "content/public/common/mhtml_generation_params.h"
@@ skipping 187 matching lines @@
 
   ipc_params.destination_file = IPC::GetPlatformFileForTransit(
       browser_file_.GetPlatformFile(), false);  // |close_source_handle|.
   ipc_params.frame_routing_id_to_content_id =
       CreateFrameRoutingIdToContentId(rfh->GetSiteInstance());
 
   // Send the IPC asking the renderer to serialize the frame.
   DCHECK_EQ(FrameTreeNode::kFrameTreeNodeInvalidId,
             frame_tree_node_id_of_busy_frame_);
   frame_tree_node_id_of_busy_frame_ = frame_tree_node_id;
   rfh->Send(new FrameMsg_SerializeAsMHTML(rfh->GetRoutingID(), ipc_params));

[esprehn, 2016/09/21 00:14:57]

we really need to rewrite this with mojo and move it into blink

[carlosk, 2016/09/21 16:47:19]

Acknowledged.

+  TRACE_EVENT_NESTABLE_ASYNC_BEGIN1("page-serialization", "WaitingOnRenderer",
+                                    this, "tree node id", frame_tree_node_id);

[Łukasz Anforowicz, 2016/09/20 22:44:59]

nit: Would it be worth spelling out "frame tree node id" to avoid any confusion?

[carlosk, 2016/09/21 16:47:20]

Done.

   return true;
 }
 
 void MHTMLGenerationManager::Job::RenderProcessExited(
     RenderProcessHost* host,
     base::TerminationStatus status,
     int exit_code) {
   DCHECK_CURRENTLY_ON(BrowserThread::UI);
   MHTMLGenerationManager::GetInstance()->RenderProcessExited(this);
 }
 
 void MHTMLGenerationManager::Job::MarkAsFinished() {
   DCHECK(!is_finished_);
   is_finished_ = true;
+  TRACE_EVENT_NESTABLE_ASYNC_INSTANT0("page-serialization", "JobFinished",
+                                      this);
 
   // Stopping RenderProcessExited notifications is needed to avoid calling
   // JobFinished twice.  See also https://crbug.com/612098.
   observed_renderer_process_host_.RemoveAll();
 }
 
 void MHTMLGenerationManager::Job::AddFrame(RenderFrameHost* render_frame_host) {
   auto* rfhi = static_cast<RenderFrameHostImpl*>(render_frame_host);
   int frame_tree_node_id = rfhi->frame_tree_node()->frame_tree_node_id();
   pending_frame_tree_node_ids_.push(frame_tree_node_id);
@@ skipping 73 matching lines @@
 MHTMLGenerationManager::~MHTMLGenerationManager() {
   base::STLDeleteValues(&id_to_job_);
 }
 
 void MHTMLGenerationManager::SaveMHTML(WebContents* web_contents,
                                        const MHTMLGenerationParams& params,
                                        const GenerateMHTMLCallback& callback) {
   DCHECK_CURRENTLY_ON(BrowserThread::UI);
 
   int job_id = NewJob(web_contents, params, callback);
+  TRACE_EVENT_NESTABLE_ASYNC_BEGIN2(
+      "page-serialization", "SavingMhtmlJob", FindJob(job_id), "url",

[Łukasz Anforowicz, 2016/09/20 22:44:59]

FindJob above looks weird (maybe just to me :-).  Would it be possible to change
NewJob to return a Job pointer and then replace |FindJob(...)| with |job->id()|?

[carlosk, 2016/09/21 16:47:19]

Sounds better to me too. Done.

This mapping should also be updated to use smart pointers. I wlill try to do
that eventually as I should visit this file a few more times.

+      web_contents->GetLastCommittedURL().spec().c_str(), "file",

[Łukasz Anforowicz, 2016/09/20 22:44:59]

I don't know if GetLastCommittedURL is guaranteed to always return a valid URL. 
Maybe change this to  possibly_invalid_spec?

[carlosk, 2016/09/21 16:47:19]

If the URL was committed it must be valid otherwise the navigation leading to it
would have been stopped early on.

BUT as there's no significant difference and the returned value is what's
referred to as a "virtual URL" (it can contain some extra snippets) I will make
that change anyway. 

So done!

+      params.file_path.value().c_str());
 
   BrowserThread::PostTaskAndReplyWithResult(
       BrowserThread::FILE, FROM_HERE,
       base::Bind(&MHTMLGenerationManager::CreateFile, params.file_path),
       base::Bind(&MHTMLGenerationManager::OnFileAvailable,
                  base::Unretained(this),  // Safe b/c |this| is a singleton.
                  job_id));
 }
 
 void MHTMLGenerationManager::OnSerializeAsMHTMLResponse(
     RenderFrameHostImpl* sender,
     int job_id,
     bool mhtml_generation_in_renderer_succeeded,
     const std::set<std::string>& digests_of_uris_of_serialized_resources) {
   DCHECK_CURRENTLY_ON(BrowserThread::UI);
 
   Job* job = FindJob(job_id);
   if (!job || !job->IsMessageFromFrameExpected(sender)) {
     NOTREACHED();
     ReceivedBadMessage(sender->GetProcess(),
                        bad_message::DWNLD_INVALID_SERIALIZE_AS_MHTML_RESPONSE);
     return;
   }
 
+  TRACE_EVENT_NESTABLE_ASYNC_END0("page-serialization", "WaitingOnRenderer",
+                                  job);
+
   if (!mhtml_generation_in_renderer_succeeded) {
     JobFinished(job, JobStatus::FAILURE);
     return;
   }
 
   if (!job->OnSerializeAsMHTMLResponse(
           digests_of_uris_of_serialized_resources)) {
     JobFinished(job, JobStatus::FAILURE);
     return;
   }
@@ skipping 52 matching lines @@
                  base::Unretained(this),  // Safe b/c |this| is a singleton.
                  job->id(), job_status));
 }
 
 void MHTMLGenerationManager::OnFileClosed(int job_id,
                                           JobStatus job_status,
                                           int64_t file_size) {
   DCHECK_CURRENTLY_ON(BrowserThread::UI);
 
   Job* job = FindJob(job_id);
+  TRACE_EVENT_NESTABLE_ASYNC_END2(
+      "page-serialization", "SavingMhtmlJob", job, "job result",
+      job_status == JobStatus::SUCCESS ? "success" : "failure", "file size",
+      file_size);
   job->callback().Run(job_status == JobStatus::SUCCESS ? file_size : -1);
   id_to_job_.erase(job_id);
   delete job;
 }
 
 int MHTMLGenerationManager::NewJob(WebContents* web_contents,
                                    const MHTMLGenerationParams& params,
                                    const GenerateMHTMLCallback& callback) {
   DCHECK_CURRENTLY_ON(BrowserThread::UI);
 
@@ skipping 13 matching lines @@
   return iter->second;
 }
 
 void MHTMLGenerationManager::RenderProcessExited(Job* job) {
   DCHECK_CURRENTLY_ON(BrowserThread::UI);
   DCHECK(job);
   JobFinished(job, JobStatus::FAILURE);
 }
 
 }  // namespace content