[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.
A "before" trace can be found here, for a very large build that heavily
uses templates:
https://ui.perfetto.dev/#!/?s=ff7918ffc237b25bfafa04e0188cdd732be49d788aa65beb072fc16446e33468
and the "after" trace is:
https://ui.perfetto.dev/#!/?s=adeb4aba68882f380e7f88b3a45f15528722343ee3932d8dfc82e4120856a8a9
Change-Id: Ie7a445ff334e28dca97dfcd00c6398149c5b6b8a
Reviewed-on: https://gn-review.googlesource.com/c/gn/+/15280
Reviewed-by: Takuto Ikuta <tikuta@google.com>
Commit-Queue: Aaron Wood <aaronwood@google.com>
diff --git a/src/gn/command_gen.cc b/src/gn/command_gen.cc
index 880fb20..6216269 100644
--- a/src/gn/command_gen.cc
+++ b/src/gn/command_gen.cc
@@ -710,6 +710,11 @@
if (!setup->Run())
return 1;
+ if (command_line->HasSwitch(switches::kVerbose))
+ OutputString("Build graph constructed in " +
+ 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) {
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);
