[tracing] Refine tracing of file writing and template execution

This disambiguates the writing of generated files and ninja files from
other write_file() commands, adds tracing of template invocations while
exec'ing files, and adds tracing of metadata walks.
diff --git a/src/gn/command_gen.cc b/src/gn/command_gen.cc
index 880fb20..d421888 100644
--- a/src/gn/command_gen.cc
+++ b/src/gn/command_gen.cc
@@ -706,10 +706,16 @@
         ItemResolvedAndGeneratedCallback(&write_info, record);
       });
 
+  OutputString("Starting Run @ " +
+               base::Int64ToString(timer.Elapsed().InMilliseconds()) + "ms\n");
+
   // Do the actual load. This will also write out the target ninja files.
   if (!setup->Run())
     return 1;
 
+  OutputString("Run complete @ " +
+               base::Int64ToString(timer.Elapsed().InMilliseconds()) + "ms\n");
+
   // Sort the targets in each toolchain according to their label. This makes
   // the ninja files have deterministic content.
   for (auto& cur_toolchain : write_info.rules) {
@@ -720,6 +726,9 @@
               });
   }
 
+  OutputString("RunAndWriteNinjaFiles starting @ " +
+               base::Int64ToString(timer.Elapsed().InMilliseconds()) + "ms\n");
+
   Err err;
   // Write the root ninja files.
   if (!NinjaWriter::RunAndWriteFiles(&setup->build_settings(), setup->builder(),
@@ -737,6 +746,9 @@
     return 1;
   }
 
+  OutputString("WriteRuntimeDepsFilesIfNeccessary starting @ " +
+               base::Int64ToString(timer.Elapsed().InMilliseconds()) + "ms\n");
+
   if (!WriteRuntimeDepsFilesIfNecessary(&setup->build_settings(),
                                         setup->builder(), &err)) {
     err.PrintToStdout();
diff --git a/src/gn/ninja_build_writer.cc b/src/gn/ninja_build_writer.cc
index e39e559..3c342ea 100644
--- a/src/gn/ninja_build_writer.cc
+++ b/src/gn/ninja_build_writer.cc
@@ -224,7 +224,7 @@
 bool NinjaBuildWriter::RunAndWriteFile(const BuildSettings* build_settings,
                                        const Builder& builder,
                                        Err* err) {
-  ScopedTrace trace(TraceItem::TRACE_FILE_WRITE, "build.ninja");
+  ScopedTrace trace(TraceItem::TRACE_FILE_WRITE_NINJA, "build.ninja");
 
   std::vector<const Target*> all_targets = builder.GetAllResolvedTargets();
   std::unordered_map<const Settings*, const Toolchain*> used_toolchains;
diff --git a/src/gn/ninja_generated_file_target_writer.cc b/src/gn/ninja_generated_file_target_writer.cc
index 994f322..3e07090 100644
--- a/src/gn/ninja_generated_file_target_writer.cc
+++ b/src/gn/ninja_generated_file_target_writer.cc
@@ -49,6 +49,16 @@
 void NinjaGeneratedFileTargetWriter::GenerateFile() {
   Err err;
 
+  std::vector<SourceFile> outputs_as_sources;
+  target_->action_values().GetOutputsAsSourceFiles(target_,
+                                                   &outputs_as_sources);
+  CHECK(outputs_as_sources.size() == 1);
+
+  base::FilePath output =
+      settings_->build_settings()->GetFullPath(outputs_as_sources[0]);
+  ScopedTrace trace(TraceItem::TRACE_FILE_WRITE_GENERATED, outputs_as_sources[0].value());
+  trace.SetToolchain(target_->settings()->toolchain_label());
+
   // If this is a metadata target, populate the write value with the appropriate
   // data.
   Value contents;
@@ -59,6 +69,8 @@
     contents = Value(target_->action_values().outputs().list()[0].origin(),
                      Value::LIST);
     TargetSet targets_walked;
+    ScopedTrace metadata_walk_trace(TraceItem::TRACE_WALK_METADATA, target_->label());
+    trace.SetToolchain(target_->settings()->toolchain_label());
     if (!target_->GetMetadata(target_->data_keys(), target_->walk_keys(),
                               target_->rebase(), /*deps_only = */ true,
                               &contents.list_value(), &targets_walked, &err)) {
@@ -69,15 +81,6 @@
     contents = target_->contents();
   }
 
-  std::vector<SourceFile> outputs_as_sources;
-  target_->action_values().GetOutputsAsSourceFiles(target_,
-                                                   &outputs_as_sources);
-  CHECK(outputs_as_sources.size() == 1);
-
-  base::FilePath output =
-      settings_->build_settings()->GetFullPath(outputs_as_sources[0]);
-  ScopedTrace trace(TraceItem::TRACE_FILE_WRITE, outputs_as_sources[0].value());
-
   // Compute output.
   StringOutputBuffer storage;
   std::ostream out(&storage);
diff --git a/src/gn/ninja_target_writer.cc b/src/gn/ninja_target_writer.cc
index 0f2514b..bd07f72 100644
--- a/src/gn/ninja_target_writer.cc
+++ b/src/gn/ninja_target_writer.cc
@@ -46,7 +46,7 @@
 std::string NinjaTargetWriter::RunAndWriteFile(const Target* target) {
   const Settings* settings = target->settings();
 
-  ScopedTrace trace(TraceItem::TRACE_FILE_WRITE,
+  ScopedTrace trace(TraceItem::TRACE_FILE_WRITE_NINJA,
                     target->label().GetUserVisibleName(false));
   trace.SetToolchain(settings->toolchain_label());
 
diff --git a/src/gn/ninja_toolchain_writer.cc b/src/gn/ninja_toolchain_writer.cc
index 2314bae..4ad17ca 100644
--- a/src/gn/ninja_toolchain_writer.cc
+++ b/src/gn/ninja_toolchain_writer.cc
@@ -63,7 +63,7 @@
     const std::vector<NinjaWriter::TargetRulePair>& rules) {
   base::FilePath ninja_file(settings->build_settings()->GetFullPath(
       GetNinjaFileForToolchain(settings)));
-  ScopedTrace trace(TraceItem::TRACE_FILE_WRITE, FilePathToUTF8(ninja_file));
+  ScopedTrace trace(TraceItem::TRACE_FILE_WRITE_NINJA, FilePathToUTF8(ninja_file));
 
   base::CreateDirectory(ninja_file.DirName());
 
diff --git a/src/gn/template.cc b/src/gn/template.cc
index d2c6fc6..029393c 100644
--- a/src/gn/template.cc
+++ b/src/gn/template.cc
@@ -12,6 +12,8 @@
 #include "gn/parse_tree.h"
 #include "gn/scope.h"
 #include "gn/scope_per_file_provider.h"
+#include "gn/settings.h"
+#include "gn/trace.h"
 #include "gn/value.h"
 #include "gn/variables.h"
 
@@ -34,6 +36,9 @@
   if (!EnsureNotProcessingImport(invocation, scope, err))
     return Value();
 
+  ScopedTrace trace(TraceItem::TRACE_FILE_EXECUTE_TEMPLATE, template_name);
+  trace.SetToolchain(scope->settings()->toolchain_label());
+
   // First run the invocation's block. Need to allocate the scope on the heap
   // so we can pass ownership to the template.
   std::unique_ptr<Scope> invocation_scope = std::make_unique<Scope>(scope);
diff --git a/src/gn/trace.cc b/src/gn/trace.cc
index bc3f50e..5f07353 100644
--- a/src/gn/trace.cc
+++ b/src/gn/trace.cc
@@ -211,10 +211,14 @@
       case TraceItem::TRACE_IMPORT_LOAD:
       case TraceItem::TRACE_IMPORT_BLOCK:
       case TraceItem::TRACE_SETUP:
+      case TraceItem::TRACE_FILE_EXECUTE_TEMPLATE:
       case TraceItem::TRACE_FILE_LOAD:
       case TraceItem::TRACE_FILE_WRITE:
+      case TraceItem::TRACE_FILE_WRITE_GENERATED:
+      case TraceItem::TRACE_FILE_WRITE_NINJA:
       case TraceItem::TRACE_DEFINE_TARGET:
       case TraceItem::TRACE_ON_RESOLVED:
+      case TraceItem::TRACE_WALK_METADATA:
         break;  // Ignore these for the summary.
     }
   }
@@ -293,9 +297,18 @@
       case TraceItem::TRACE_FILE_EXECUTE:
         out << "\"file_exec\"";
         break;
+      case TraceItem::TRACE_FILE_EXECUTE_TEMPLATE:
+        out << "\"file_exec_template\"";
+        break;
       case TraceItem::TRACE_FILE_WRITE:
         out << "\"file_write\"";
         break;
+      case TraceItem::TRACE_FILE_WRITE_GENERATED:
+        out << "\"file_write_generated\"";
+        break;
+      case TraceItem::TRACE_FILE_WRITE_NINJA:
+        out << "\"file_write_ninja\"";
+        break;
       case TraceItem::TRACE_IMPORT_LOAD:
         out << "\"import_load\"";
         break;
@@ -317,6 +330,9 @@
       case TraceItem::TRACE_CHECK_HEADERS:
         out << "\"header_check\"";
         break;
+      case TraceItem::TRACE_WALK_METADATA:
+        out << "\"walk_metadata\"";
+        break;
     }
 
     if (!item.toolchain().empty() || !item.cmdline().empty()) {
diff --git a/src/gn/trace.h b/src/gn/trace.h
index b59cd34..c57d99e 100644
--- a/src/gn/trace.h
+++ b/src/gn/trace.h
@@ -25,7 +25,10 @@
     TRACE_FILE_LOAD,
     TRACE_FILE_PARSE,
     TRACE_FILE_EXECUTE,
+    TRACE_FILE_EXECUTE_TEMPLATE,
     TRACE_FILE_WRITE,
+    TRACE_FILE_WRITE_GENERATED,
+    TRACE_FILE_WRITE_NINJA,
     TRACE_IMPORT_LOAD,
     TRACE_IMPORT_BLOCK,
     TRACE_SCRIPT_EXECUTE,
@@ -33,6 +36,7 @@
     TRACE_ON_RESOLVED,
     TRACE_CHECK_HEADER,   // One file.
     TRACE_CHECK_HEADERS,  // All files.
+    TRACE_WALK_METADATA,
   };
 
   TraceItem(Type type, const std::string& name, std::thread::id thread_id);