Skip to content

Commit

Permalink
Revert "Add source file name for template instantiations in -ftime-tr…
Browse files Browse the repository at this point in the history
…ace (#98…"

This reverts commit cd495d2.
  • Loading branch information
usx95 authored Jul 18, 2024
1 parent b2dcf62 commit 532a2f4
Show file tree
Hide file tree
Showing 13 changed files with 64 additions and 223 deletions.
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

0 comments on commit 532a2f4

Please sign in to comment.