[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);