Skip to content

Revert "Add source file name for template instantiations in -ftime-trace" #99534

New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Merged
merged 1 commit into from
Jul 18, 2024
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
Empty file removed a-abfdec1d.o.tmp
Empty file.
3 changes: 0 additions & 3 deletions clang/docs/ReleaseNotes.rst
Original file line number Diff line number Diff line change
Expand Up @@ -736,9 +736,6 @@ Improvements to Clang's time-trace
- Clang now specifies that using ``auto`` in a lambda parameter is a C++14 extension when
appropriate. (`#46059: <https://github.com/llvm/llvm-project/issues/46059>`_).

- Clang now adds source file infomation for template instantiations as ``event["args"]["filename"]``. This
added behind an option ``-ftime-trace-verbose``. This is expected to increase the size of trace by 2-3 times.

Improvements to Coverage Mapping
--------------------------------

Expand Down
4 changes: 0 additions & 4 deletions clang/include/clang/Driver/Options.td
Original file line number Diff line number Diff line change
Expand Up @@ -3988,10 +3988,6 @@ def ftime_trace_granularity_EQ : Joined<["-"], "ftime-trace-granularity=">, Grou
HelpText<"Minimum time granularity (in microseconds) traced by time profiler">,
Visibility<[ClangOption, CC1Option, CLOption, DXCOption]>,
MarshallingInfoInt<FrontendOpts<"TimeTraceGranularity">, "500u">;
def ftime_trace_verbose : Joined<["-"], "ftime-trace-verbose">, Group<f_Group>,
HelpText<"Make time trace capture verbose event details (e.g. source filenames). This can increase the size of the output by 2-3 times">,
Visibility<[ClangOption, CC1Option, CLOption, DXCOption]>,
MarshallingInfoFlag<FrontendOpts<"TimeTraceVerbose">>;
def ftime_trace_EQ : Joined<["-"], "ftime-trace=">, Group<f_Group>,
HelpText<"Similar to -ftime-trace. Specify the JSON file or a directory which will contain the JSON file">,
Visibility<[ClangOption, CC1Option, CLOption, DXCOption]>,
Expand Down
8 changes: 1 addition & 7 deletions clang/include/clang/Frontend/FrontendOptions.h
Original file line number Diff line number Diff line change
Expand Up @@ -580,11 +580,6 @@ class FrontendOptions {
/// Minimum time granularity (in microseconds) traced by time profiler.
unsigned TimeTraceGranularity;

/// Make time trace capture verbose event details (e.g. source filenames).
/// This can increase the size of the output by 2-3 times.
LLVM_PREFERRED_TYPE(bool)
unsigned TimeTraceVerbose : 1;

/// Path which stores the output files for -ftime-trace
std::string TimeTracePath;

Expand All @@ -606,8 +601,7 @@ class FrontendOptions {
EmitSymbolGraph(false), EmitExtensionSymbolGraphs(false),
EmitSymbolGraphSymbolLabelsForTesting(false),
EmitPrettySymbolGraphs(false), GenReducedBMI(false),
UseClangIRPipeline(false), TimeTraceGranularity(500),
TimeTraceVerbose(false) {}
UseClangIRPipeline(false), TimeTraceGranularity(500) {}

/// getInputKindForExtension - Return the appropriate input kind for a file
/// extension. For example, "c" would return Language::C.
Expand Down
1 change: 0 additions & 1 deletion clang/lib/Driver/ToolChains/Clang.cpp
Original file line number Diff line number Diff line change
Expand Up @@ -6754,7 +6754,6 @@ void Clang::ConstructJob(Compilation &C, const JobAction &JA,
if (const char *Name = C.getTimeTraceFile(&JA)) {
CmdArgs.push_back(Args.MakeArgString("-ftime-trace=" + Twine(Name)));
Args.AddLastArg(CmdArgs, options::OPT_ftime_trace_granularity_EQ);
Args.AddLastArg(CmdArgs, options::OPT_ftime_trace_verbose);
}

if (Arg *A = Args.getLastArg(options::OPT_ftrapv_handler_EQ)) {
Expand Down
11 changes: 3 additions & 8 deletions clang/lib/Sema/SemaTemplateInstantiate.cpp
Original file line number Diff line number Diff line change
Expand Up @@ -3426,16 +3426,11 @@ Sema::InstantiateClass(SourceLocation PointOfInstantiation,
return true;

llvm::TimeTraceScope TimeScope("InstantiateClass", [&]() {
llvm::TimeTraceMetadata M;
llvm::raw_string_ostream OS(M.Detail);
std::string Name;
llvm::raw_string_ostream OS(Name);
Instantiation->getNameForDiagnostic(OS, getPrintingPolicy(),
/*Qualified=*/true);
if (llvm::isTimeTraceVerbose()) {
auto Loc = SourceMgr.getExpansionLoc(Instantiation->getLocation());
M.File = SourceMgr.getFilename(Loc);
M.Line = SourceMgr.getExpansionLineNumber(Loc);
}
return M;
return Name;
});

Pattern = PatternDef;
Expand Down
11 changes: 3 additions & 8 deletions clang/lib/Sema/SemaTemplateInstantiateDecl.cpp
Original file line number Diff line number Diff line change
Expand Up @@ -4966,16 +4966,11 @@ void Sema::InstantiateFunctionDefinition(SourceLocation PointOfInstantiation,
}

llvm::TimeTraceScope TimeScope("InstantiateFunction", [&]() {
llvm::TimeTraceMetadata M;
llvm::raw_string_ostream OS(M.Detail);
std::string Name;
llvm::raw_string_ostream OS(Name);
Function->getNameForDiagnostic(OS, getPrintingPolicy(),
/*Qualified=*/true);
if (llvm::isTimeTraceVerbose()) {
auto Loc = SourceMgr.getExpansionLoc(Function->getLocation());
M.File = SourceMgr.getFilename(Loc);
M.Line = SourceMgr.getExpansionLineNumber(Loc);
}
return M;
return Name;
});

// If we're performing recursive template instantiation, create our own
Expand Down
2 changes: 1 addition & 1 deletion clang/test/Driver/ftime-trace-sections.cpp
Original file line number Diff line number Diff line change
@@ -1,5 +1,5 @@
// RUN: rm -rf %t && mkdir %t && cd %t
// RUN: %clangxx -S -ftime-trace -ftime-trace-granularity=0 -ftime-trace-verbose -o out %s
// RUN: %clangxx -S -ftime-trace -ftime-trace-granularity=0 -o out %s
// RUN: %python %S/ftime-trace-sections.py < out.json

template <typename T>
Expand Down
39 changes: 19 additions & 20 deletions clang/test/Driver/ftime-trace.cpp
Original file line number Diff line number Diff line change
@@ -1,18 +1,18 @@
// RUN: rm -rf %t && mkdir -p %t && cd %t
// RUN: %clangxx -S -no-canonical-prefixes -ftime-trace -ftime-trace-granularity=0 -ftime-trace-verbose -o out %s
// RUN: %clangxx -S -no-canonical-prefixes -ftime-trace -ftime-trace-granularity=0 -o out %s
// RUN: cat out.json \
// RUN: | %python -c 'import json, sys; json.dump(json.loads(sys.stdin.read()), sys.stdout, sort_keys=True, indent=2)' \
// RUN: | FileCheck %s
// RUN: %clangxx -S -no-canonical-prefixes -ftime-trace=new-name.json -ftime-trace-granularity=0 -ftime-trace-verbose -o out %s
// RUN: %clangxx -S -no-canonical-prefixes -ftime-trace=new-name.json -ftime-trace-granularity=0 -o out %s
// RUN: cat new-name.json \
// RUN: | %python -c 'import json, sys; json.dump(json.loads(sys.stdin.read()), sys.stdout, sort_keys=True, indent=2)' \
// RUN: | FileCheck %s
// RUN: mkdir dir1 dir2
// RUN: %clangxx -S -no-canonical-prefixes -ftime-trace=dir1 -ftime-trace-granularity=0 -ftime-trace-verbose -o out %s
// RUN: %clangxx -S -no-canonical-prefixes -ftime-trace=dir1 -ftime-trace-granularity=0 -o out %s
// RUN: cat dir1/out.json \
// RUN: | %python -c 'import json, sys; json.dump(json.loads(sys.stdin.read()), sys.stdout, sort_keys=True, indent=2)' \
// RUN: | FileCheck %s
// RUN: %clangxx -S -no-canonical-prefixes -ftime-trace=dir2/ -ftime-trace-granularity=0 -ftime-trace-verbose -o out %s
// RUN: %clangxx -S -no-canonical-prefixes -ftime-trace=dir2/ -ftime-trace-granularity=0 -o out %s
// RUN: cat dir2/out.json \
// RUN: | %python -c 'import json, sys; json.dump(json.loads(sys.stdin.read()), sys.stdout, sort_keys=True, indent=2)' \
// RUN: | FileCheck %s
Expand All @@ -34,33 +34,32 @@
// RUN: mkdir d e f && cp %s d/a.cpp && touch d/b.c

/// TODO: Support -fno-integrated-as.
// RUN: %clang -### -c -ftime-trace -ftime-trace-granularity=0 -ftime-trace-verbose -fintegrated-as d/a.cpp -o e/a.o 2>&1 | FileCheck %s --check-prefix=COMPILE1
// COMPILE1: -cc1{{.*}} "-ftime-trace=e/a.json" "-ftime-trace-granularity=0" "-ftime-trace-verbose"
// RUN: %clang -### -c -ftime-trace -ftime-trace-granularity=0 -fintegrated-as d/a.cpp -o e/a.o 2>&1 | FileCheck %s --check-prefix=COMPILE1
// COMPILE1: -cc1{{.*}} "-ftime-trace=e/a.json" "-ftime-trace-granularity=0"

// RUN: %clang -### -c -ftime-trace -ftime-trace-granularity=0 -ftime-trace-verbose d/a.cpp d/b.c -dumpdir f/ 2>&1 | FileCheck %s --check-prefix=COMPILE2
// COMPILE2: -cc1{{.*}} "-ftime-trace=f/a.json" "-ftime-trace-granularity=0" "-ftime-trace-verbose"
// COMPILE2: -cc1{{.*}} "-ftime-trace=f/b.json" "-ftime-trace-granularity=0" "-ftime-trace-verbose"
// RUN: %clang -### -c -ftime-trace -ftime-trace-granularity=0 d/a.cpp d/b.c -dumpdir f/ 2>&1 | FileCheck %s --check-prefix=COMPILE2
// COMPILE2: -cc1{{.*}} "-ftime-trace=f/a.json" "-ftime-trace-granularity=0"
// COMPILE2: -cc1{{.*}} "-ftime-trace=f/b.json" "-ftime-trace-granularity=0"

/// -o specifies the link output. Create ${output}-${basename}.json.
// RUN: %clang -### -ftime-trace -ftime-trace-granularity=0 -ftime-trace-verbose d/a.cpp d/b.c -o e/x 2>&1 | FileCheck %s --check-prefix=LINK1
// LINK1: -cc1{{.*}} "-ftime-trace=e/x-a.json" "-ftime-trace-granularity=0" "-ftime-trace-verbose"
// LINK1: -cc1{{.*}} "-ftime-trace=e/x-b.json" "-ftime-trace-granularity=0" "-ftime-trace-verbose"
// RUN: %clang -### -ftime-trace -ftime-trace-granularity=0 d/a.cpp d/b.c -o e/x 2>&1 | FileCheck %s --check-prefix=LINK1
// LINK1: -cc1{{.*}} "-ftime-trace=e/x-a.json" "-ftime-trace-granularity=0"
// LINK1: -cc1{{.*}} "-ftime-trace=e/x-b.json" "-ftime-trace-granularity=0"

/// -dumpdir is f/g, not ending with a path separator. We create f/g${basename}.json.
// RUN: %clang -### -ftime-trace -ftime-trace-granularity=0 -ftime-trace-verbose d/a.cpp d/b.c -o e/x -dumpdir f/g 2>&1 | FileCheck %s --check-prefix=LINK2
// LINK2: -cc1{{.*}} "-ftime-trace=f/ga.json" "-ftime-trace-granularity=0" "-ftime-trace-verbose"
// LINK2: -cc1{{.*}} "-ftime-trace=f/gb.json" "-ftime-trace-granularity=0" "-ftime-trace-verbose"
// RUN: %clang -### -ftime-trace -ftime-trace-granularity=0 d/a.cpp d/b.c -o e/x -dumpdir f/g 2>&1 | FileCheck %s --check-prefix=LINK2
// LINK2: -cc1{{.*}} "-ftime-trace=f/ga.json" "-ftime-trace-granularity=0"
// LINK2: -cc1{{.*}} "-ftime-trace=f/gb.json" "-ftime-trace-granularity=0"

// RUN: %clang -### -ftime-trace=e -ftime-trace-granularity=0 -ftime-trace-verbose d/a.cpp d/b.c -o f/x -dumpdir f/ 2>&1 | FileCheck %s --check-prefix=LINK3
// LINK3: -cc1{{.*}} "-ftime-trace=e{{/|\\\\}}a-{{[^.]*}}.json" "-ftime-trace-granularity=0" "-ftime-trace-verbose"
// LINK3: -cc1{{.*}} "-ftime-trace=e{{/|\\\\}}b-{{[^.]*}}.json" "-ftime-trace-granularity=0" "-ftime-trace-verbose"
// RUN: %clang -### -ftime-trace=e -ftime-trace-granularity=0 d/a.cpp d/b.c -o f/x -dumpdir f/ 2>&1 | FileCheck %s --check-prefix=LINK3
// LINK3: -cc1{{.*}} "-ftime-trace=e{{/|\\\\}}a-{{[^.]*}}.json" "-ftime-trace-granularity=0"
// LINK3: -cc1{{.*}} "-ftime-trace=e{{/|\\\\}}b-{{[^.]*}}.json" "-ftime-trace-granularity=0"

// RUN: %clang -### -ftime-trace -ftime-trace=e -ftime-trace-granularity=1 -ftime-trace-verbose -xassembler d/a.cpp 2>&1 | \
// RUN: %clang -### -ftime-trace -ftime-trace=e -ftime-trace-granularity=1 -xassembler d/a.cpp 2>&1 | \
// RUN: FileCheck %s --check-prefix=UNUSED
// UNUSED: warning: argument unused during compilation: '-ftime-trace'
// UNUSED-NEXT: warning: argument unused during compilation: '-ftime-trace=e'
// UNUSED-NEXT: warning: argument unused during compilation: '-ftime-trace-granularity=1'
// UNUSED-NEXT: warning: argument unused during compilation: '-ftime-trace-verbose'
// UNUSED-NOT: warning:

template <typename T>
Expand Down
3 changes: 1 addition & 2 deletions clang/tools/driver/cc1_main.cpp
Original file line number Diff line number Diff line change
Expand Up @@ -241,8 +241,7 @@ int cc1_main(ArrayRef<const char *> Argv, const char *Argv0, void *MainAddr) {

if (!Clang->getFrontendOpts().TimeTracePath.empty()) {
llvm::timeTraceProfilerInitialize(
Clang->getFrontendOpts().TimeTraceGranularity, Argv0,
Clang->getFrontendOpts().TimeTraceVerbose);
Clang->getFrontendOpts().TimeTraceGranularity, Argv0);
}
// --print-supported-cpus takes priority over the actual compilation.
if (Clang->getFrontendOpts().PrintSupportedCPUs)
Expand Down
121 changes: 27 additions & 94 deletions clang/unittests/Support/TimeProfilerTest.cpp
Original file line number Diff line number Diff line change
Expand Up @@ -10,14 +10,11 @@
#include "clang/Frontend/FrontendActions.h"
#include "clang/Lex/PreprocessorOptions.h"

#include "llvm/ADT/StringMap.h"
#include "llvm/Support/JSON.h"
#include "llvm/Support/TimeProfiler.h"
#include "llvm/Support/VirtualFileSystem.h"
#include <stack>

#include "gtest/gtest.h"
#include <tuple>

using namespace clang;
using namespace llvm;
Expand All @@ -26,8 +23,7 @@ namespace {

// Should be called before testing.
void setupProfiler() {
timeTraceProfilerInitialize(/*TimeTraceGranularity=*/0, "test",
/*TimeTraceVerbose=*/true);
timeTraceProfilerInitialize(/*TimeTraceGranularity=*/0, "test");
}

// Should be called after `compileFromString()`.
Expand All @@ -42,24 +38,14 @@ std::string teardownProfiler() {

// Returns true if code compiles successfully.
// We only parse AST here. This is enough for constexpr evaluation.
bool compileFromString(StringRef Code, StringRef Standard, StringRef File,
llvm::StringMap<std::string> Headers = {}) {
bool compileFromString(StringRef Code, StringRef Standard, StringRef FileName) {
CompilerInstance Compiler;
Compiler.createDiagnostics();

llvm::IntrusiveRefCntPtr<llvm::vfs::InMemoryFileSystem> FS(
new llvm::vfs::InMemoryFileSystem());
FS->addFile(File, 0, MemoryBuffer::getMemBuffer(Code));
for (const auto &Header : Headers) {
FS->addFile(Header.getKey(), 0,
MemoryBuffer::getMemBuffer(Header.getValue()));
}
llvm::IntrusiveRefCntPtr<FileManager> Files(
new FileManager(FileSystemOptions(), FS));
Compiler.setFileManager(Files.get());

auto Invocation = std::make_shared<CompilerInvocation>();
std::vector<const char *> Args = {Standard.data(), File.data()};
Invocation->getPreprocessorOpts().addRemappedFile(
FileName, MemoryBuffer::getMemBuffer(Code).release());
const char *Args[] = {Standard.data(), FileName.data()};
CompilerInvocation::CreateFromArgs(*Invocation, Args,
Compiler.getDiagnostics());
Compiler.setInvocation(std::move(Invocation));
Expand All @@ -74,27 +60,13 @@ bool compileFromString(StringRef Code, StringRef Standard, StringRef File,
return Compiler.ExecuteAction(Action);
}

std::string GetMetadata(json::Object *Event) {
std::string Metadata;
llvm::raw_string_ostream OS(Metadata);
if (json::Object *Args = Event->getObject("args")) {
if (auto Detail = Args->getString("detail"))
OS << Detail->str();
if (auto File = Args->getString("file"))
OS << ", " << File->str();
if (auto Line = Args->getInteger("line"))
OS << ":" << *Line;
}
return Metadata;
}

// Returns pretty-printed trace graph.
std::string buildTraceGraph(StringRef Json) {
struct EventRecord {
int64_t TimestampBegin;
int64_t TimestampEnd;
std::string Name;
std::string Metadata;
StringRef Name;
StringRef Detail;
};
std::vector<EventRecord> Events;

Expand All @@ -109,21 +81,18 @@ std::string buildTraceGraph(StringRef Json) {
int64_t TimestampBegin = TraceEventObj->getInteger("ts").value_or(0);
int64_t TimestampEnd =
TimestampBegin + TraceEventObj->getInteger("dur").value_or(0);
std::string Name = TraceEventObj->getString("name").value_or("").str();
std::string Metadata = GetMetadata(TraceEventObj);

// Source events are asynchronous events and may not perfectly nest the
// synchronous events. Skip testing them.
if (Name == "Source")
continue;
StringRef Name = TraceEventObj->getString("name").value_or("");
StringRef Detail = "";
if (json::Object *Args = TraceEventObj->getObject("args"))
Detail = Args->getString("detail").value_or("");

// This is a "summary" event, like "Total PerformPendingInstantiations",
// skip it
if (TimestampBegin == 0)
continue;

Events.emplace_back(
EventRecord{TimestampBegin, TimestampEnd, Name, Metadata});
EventRecord{TimestampBegin, TimestampEnd, Name, Detail});
}

// There can be nested events that are very fast, for example:
Expand Down Expand Up @@ -163,9 +132,9 @@ std::string buildTraceGraph(StringRef Json) {
Stream << "| ";
}
Stream.write(Event.Name.data(), Event.Name.size());
if (!Event.Metadata.empty()) {
if (!Event.Detail.empty()) {
Stream << " (";
Stream.write(Event.Metadata.data(), Event.Metadata.size());
Stream.write(Event.Detail.data(), Event.Detail.size());
Stream << ")";
}
Stream << "\n";
Expand All @@ -176,7 +145,7 @@ std::string buildTraceGraph(StringRef Json) {
} // namespace

TEST(TimeProfilerTest, ConstantEvaluationCxx20) {
std::string Code = R"(
constexpr StringRef Code = R"(
void print(double value);

namespace slow_namespace {
Expand Down Expand Up @@ -206,7 +175,8 @@ constexpr int slow_init_list[] = {1, 1, 2, 3, 5, 8, 13, 21}; // 25th line
setupProfiler();
ASSERT_TRUE(compileFromString(Code, "-std=c++20", "test.cc"));
std::string Json = teardownProfiler();
ASSERT_EQ(R"(
std::string TraceGraph = buildTraceGraph(Json);
ASSERT_TRUE(TraceGraph == R"(
Frontend
| ParseDeclarationOrFunctionDefinition (test.cc:2:1)
| ParseDeclarationOrFunctionDefinition (test.cc:6:1)
Expand All @@ -232,54 +202,14 @@ Frontend
| ParseDeclarationOrFunctionDefinition (test.cc:25:1)
| | EvaluateAsInitializer (slow_init_list)
| PerformPendingInstantiations
)",
buildTraceGraph(Json));
}

TEST(TimeProfilerTest, TemplateInstantiations) {
std::string B_H = R"(
template <typename T>
T fooB(T t) {
return T();
}
)");

#define MacroTemp(x) template <typename T> void foo##x(T) { T(); }
)";

std::string A_H = R"(
#include "b.h"

MacroTemp(MTA)

template <typename T>
void fooA(T t) { fooB(t); fooMTA(t); }
)";
std::string Code = R"(
#include "a.h"
void user() { fooA(0); }
)";

setupProfiler();
ASSERT_TRUE(compileFromString(Code, "-std=c++20", "test.cc",
/*Headers=*/{{"a.h", A_H}, {"b.h", B_H}}));
std::string Json = teardownProfiler();
ASSERT_EQ(R"(
Frontend
| ParseFunctionDefinition (fooB)
| ParseFunctionDefinition (fooMTA)
| ParseFunctionDefinition (fooA)
| ParseDeclarationOrFunctionDefinition (test.cc:3:5)
| | ParseFunctionDefinition (user)
| PerformPendingInstantiations
| | InstantiateFunction (fooA<int>, ./a.h:7)
| | | InstantiateFunction (fooB<int>, ./b.h:3)
| | | InstantiateFunction (fooMTA<int>, ./a.h:4)
)",
buildTraceGraph(Json));
// NOTE: If this test is failing, run this test with
// `llvm::errs() << TraceGraph;` and change the assert above.
}

TEST(TimeProfilerTest, ConstantEvaluationC99) {
std::string Code = R"(
constexpr StringRef Code = R"(
struct {
short quantval[4]; // 3rd line
} value;
Expand All @@ -288,12 +218,15 @@ struct {
setupProfiler();
ASSERT_TRUE(compileFromString(Code, "-std=c99", "test.c"));
std::string Json = teardownProfiler();
ASSERT_EQ(R"(
std::string TraceGraph = buildTraceGraph(Json);
ASSERT_TRUE(TraceGraph == R"(
Frontend
| ParseDeclarationOrFunctionDefinition (test.c:2:1)
| | isIntegerConstantExpr (<test.c:3:18>)
| | EvaluateKnownConstIntCheckOverflow (<test.c:3:18>)
| PerformPendingInstantiations
)",
buildTraceGraph(Json));
)");

// NOTE: If this test is failing, run this test with
// `llvm::errs() << TraceGraph;` and change the assert above.
}
Loading
Loading