Adds tracing to MHTML generation call chain.

content/browser/download/mhtml_generation_manager.cc

Index: content/browser/download/mhtml_generation_manager.cc
diff --git a/content/browser/download/mhtml_generation_manager.cc b/content/browser/download/mhtml_generation_manager.cc
index f28c86f1c01d55630d372754c63943186a21551c..268ea9819542fb50a728ad5bd08d71686a15b7fb 100644
--- a/content/browser/download/mhtml_generation_manager.cc
+++ b/content/browser/download/mhtml_generation_manager.cc
@@ -15,6 +15,7 @@
 #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"
@@ -223,6 +224,8 @@ bool MHTMLGenerationManager::Job::SendToNextRenderFrame() {
             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;
 }
 
@@ -237,6 +240,8 @@ void MHTMLGenerationManager::Job::RenderProcessExited(
 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.
@@ -330,6 +335,10 @@ void MHTMLGenerationManager::SaveMHTML(WebContents* web_contents,
   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,
@@ -354,6 +363,9 @@ void MHTMLGenerationManager::OnSerializeAsMHTMLResponse(
     return;
   }
 
+  TRACE_EVENT_NESTABLE_ASYNC_END0("page-serialization", "WaitingOnRenderer",
+                                  job);
+
   if (!mhtml_generation_in_renderer_succeeded) {
     JobFinished(job, JobStatus::FAILURE);
     return;
@@ -426,6 +438,10 @@ void MHTMLGenerationManager::OnFileClosed(int job_id,
   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;