diff options
author | Anton Afanasyev <anton.a.afanasyev@gmail.com> | 2019-03-30 08:42:48 +0000 |
---|---|---|
committer | Anton Afanasyev <anton.a.afanasyev@gmail.com> | 2019-03-30 08:42:48 +0000 |
commit | d880de2d19d46f7cfea7aa593602458440bc1e8d (patch) | |
tree | 462bf94e899135c45aae23c3cf79251f521003e7 | |
parent | 98b8ecde64d89cca944d9a975b12319dd0376cc0 (diff) | |
download | bcm5719-llvm-d880de2d19d46f7cfea7aa593602458440bc1e8d.tar.gz bcm5719-llvm-d880de2d19d46f7cfea7aa593602458440bc1e8d.zip |
Adds `-ftime-trace` option to clang that produces Chrome `chrome://tracing` compatible JSON profiling output dumps.
This change adds hierarchical "time trace" profiling blocks that can be visualized in Chrome, in a "flame chart" style. Each profiling block can have a "detail" string that for example indicates the file being processed, template name being instantiated, function being optimized etc.
This is taken from GitHub PR: https://github.com/aras-p/llvm-project-20170507/pull/2
Patch by Aras Pranckevičius.
Differential Revision: https://reviews.llvm.org/D58675
llvm-svn: 357340
-rw-r--r-- | clang/include/clang/Basic/CodeGenOptions.def | 1 | ||||
-rw-r--r-- | clang/include/clang/Driver/Options.td | 1 | ||||
-rw-r--r-- | clang/include/clang/Frontend/FrontendOptions.h | 18 | ||||
-rw-r--r-- | clang/lib/CodeGen/BackendUtil.cpp | 4 | ||||
-rw-r--r-- | clang/lib/CodeGen/CodeGenModule.cpp | 4 | ||||
-rw-r--r-- | clang/lib/Driver/ToolChains/Clang.cpp | 1 | ||||
-rw-r--r-- | clang/lib/Frontend/CompilerInstance.cpp | 4 | ||||
-rw-r--r-- | clang/lib/Frontend/CompilerInvocation.cpp | 1 | ||||
-rw-r--r-- | clang/lib/Parse/ParseAST.cpp | 2 | ||||
-rw-r--r-- | clang/lib/Parse/ParseDeclCXX.cpp | 7 | ||||
-rw-r--r-- | clang/lib/Parse/ParseTemplate.cpp | 7 | ||||
-rw-r--r-- | clang/lib/Sema/Sema.cpp | 20 | ||||
-rw-r--r-- | clang/lib/Sema/SemaTemplateInstantiate.cpp | 6 | ||||
-rw-r--r-- | clang/lib/Sema/SemaTemplateInstantiateDecl.cpp | 5 | ||||
-rw-r--r-- | clang/lib/Serialization/GlobalModuleIndex.cpp | 4 | ||||
-rw-r--r-- | clang/tools/driver/cc1_main.cpp | 24 | ||||
-rw-r--r-- | llvm/include/llvm/Support/TimeProfiler.h | 70 | ||||
-rw-r--r-- | llvm/lib/IR/LegacyPassManager.cpp | 12 | ||||
-rw-r--r-- | llvm/lib/Support/CMakeLists.txt | 1 | ||||
-rw-r--r-- | llvm/lib/Support/TimeProfiler.cpp | 184 |
20 files changed, 366 insertions, 10 deletions
diff --git a/clang/include/clang/Basic/CodeGenOptions.def b/clang/include/clang/Basic/CodeGenOptions.def index a7aafcf2f4d..8e8a064f844 100644 --- a/clang/include/clang/Basic/CodeGenOptions.def +++ b/clang/include/clang/Basic/CodeGenOptions.def @@ -224,6 +224,7 @@ CODEGENOPT(FineGrainedBitfieldAccesses, 1, 0) ///< Enable fine-grained bitfield CODEGENOPT(StrictEnums , 1, 0) ///< Optimize based on strict enum definition. CODEGENOPT(StrictVTablePointers, 1, 0) ///< Optimize based on the strict vtable pointers CODEGENOPT(TimePasses , 1, 0) ///< Set when -ftime-report is enabled. +CODEGENOPT(TimeTrace , 1, 0) ///< Set when -ftime-trace is enabled. CODEGENOPT(UnrollLoops , 1, 0) ///< Control whether loops are unrolled. CODEGENOPT(RerollLoops , 1, 0) ///< Control whether loops are rerolled. CODEGENOPT(NoUseJumpTables , 1, 0) ///< Set when -fno-jump-tables is enabled. diff --git a/clang/include/clang/Driver/Options.td b/clang/include/clang/Driver/Options.td index abff15311a9..6d4aa1bf42c 100644 --- a/clang/include/clang/Driver/Options.td +++ b/clang/include/clang/Driver/Options.td @@ -1745,6 +1745,7 @@ def Wframe_larger_than_EQ : Joined<["-"], "Wframe-larger-than=">, Group<f_Group> def : Flag<["-"], "fterminated-vtables">, Alias<fapple_kext>; def fthreadsafe_statics : Flag<["-"], "fthreadsafe-statics">, Group<f_Group>; def ftime_report : Flag<["-"], "ftime-report">, Group<f_Group>, Flags<[CC1Option]>; +def ftime_trace : Flag<["-"], "ftime-trace">, Group<f_Group>, Flags<[CC1Option]>; def ftlsmodel_EQ : Joined<["-"], "ftls-model=">, Group<f_Group>, Flags<[CC1Option]>; def ftrapv : Flag<["-"], "ftrapv">, Group<f_Group>, Flags<[CC1Option]>, HelpText<"Trap on integer overflow">; diff --git a/clang/include/clang/Frontend/FrontendOptions.h b/clang/include/clang/Frontend/FrontendOptions.h index 4c4ed96d1ca..8cbba55da4d 100644 --- a/clang/include/clang/Frontend/FrontendOptions.h +++ b/clang/include/clang/Frontend/FrontendOptions.h @@ -256,6 +256,9 @@ public: /// Show timers for individual actions. unsigned ShowTimers : 1; + /// Output time trace profile. + unsigned TimeTrace : 1; + /// Show the -version text. unsigned ShowVersion : 1; @@ -437,13 +440,14 @@ public: public: FrontendOptions() : DisableFree(false), RelocatablePCH(false), ShowHelp(false), - ShowStats(false), ShowTimers(false), ShowVersion(false), - FixWhatYouCan(false), FixOnlyWarnings(false), FixAndRecompile(false), - FixToTemporaries(false), ARCMTMigrateEmitARCErrors(false), - SkipFunctionBodies(false), UseGlobalModuleIndex(true), - GenerateGlobalModuleIndex(true), ASTDumpDecls(false), - ASTDumpLookups(false), BuildingImplicitModule(false), - ModulesEmbedAllFiles(false), IncludeTimestamps(true) {} + ShowStats(false), ShowTimers(false), TimeTrace(false), + ShowVersion(false), FixWhatYouCan(false), FixOnlyWarnings(false), + FixAndRecompile(false), FixToTemporaries(false), + ARCMTMigrateEmitARCErrors(false), SkipFunctionBodies(false), + UseGlobalModuleIndex(true), GenerateGlobalModuleIndex(true), + ASTDumpDecls(false), ASTDumpLookups(false), + BuildingImplicitModule(false), ModulesEmbedAllFiles(false), + IncludeTimestamps(true) {} /// getInputKindForExtension - Return the appropriate input kind for a file /// extension. For example, "c" would return InputKind::C. diff --git a/clang/lib/CodeGen/BackendUtil.cpp b/clang/lib/CodeGen/BackendUtil.cpp index 540cc6f6bc5..e22a62d3777 100644 --- a/clang/lib/CodeGen/BackendUtil.cpp +++ b/clang/lib/CodeGen/BackendUtil.cpp @@ -42,6 +42,7 @@ #include "llvm/Support/MemoryBuffer.h" #include "llvm/Support/PrettyStackTrace.h" #include "llvm/Support/TargetRegistry.h" +#include "llvm/Support/TimeProfiler.h" #include "llvm/Support/Timer.h" #include "llvm/Support/raw_ostream.h" #include "llvm/Target/TargetMachine.h" @@ -1382,6 +1383,9 @@ void clang::EmitBackendOutput(DiagnosticsEngine &Diags, const llvm::DataLayout &TDesc, Module *M, BackendAction Action, std::unique_ptr<raw_pwrite_stream> OS) { + + llvm::TimeTraceScope TimeScope("Backend", StringRef("")); + std::unique_ptr<llvm::Module> EmptyModule; if (!CGOpts.ThinLTOIndexFile.empty()) { // If we are performing a ThinLTO importing compile, load the function index diff --git a/clang/lib/CodeGen/CodeGenModule.cpp b/clang/lib/CodeGen/CodeGenModule.cpp index 91f162820cb..1a2e420233e 100644 --- a/clang/lib/CodeGen/CodeGenModule.cpp +++ b/clang/lib/CodeGen/CodeGenModule.cpp @@ -58,6 +58,7 @@ #include "llvm/Support/ConvertUTF.h" #include "llvm/Support/ErrorHandling.h" #include "llvm/Support/MD5.h" +#include "llvm/Support/TimeProfiler.h" using namespace clang; using namespace CodeGen; @@ -2482,6 +2483,9 @@ void CodeGenModule::EmitGlobalDefinition(GlobalDecl GD, llvm::GlobalValue *GV) { if (!shouldEmitFunction(GD)) return; + llvm::TimeTraceScope TimeScope( + "CodeGen Function", [&]() { return FD->getQualifiedNameAsString(); }); + if (const auto *Method = dyn_cast<CXXMethodDecl>(D)) { // Make sure to emit the definition(s) before we emit the thunks. // This is necessary for the generation of certain thunks. diff --git a/clang/lib/Driver/ToolChains/Clang.cpp b/clang/lib/Driver/ToolChains/Clang.cpp index 1f1d80057ec..a638fc5e870 100644 --- a/clang/lib/Driver/ToolChains/Clang.cpp +++ b/clang/lib/Driver/ToolChains/Clang.cpp @@ -4548,6 +4548,7 @@ void Clang::ConstructJob(Compilation &C, const JobAction &JA, Args.AddLastArg(CmdArgs, options::OPT_fdiagnostics_print_source_range_info); Args.AddLastArg(CmdArgs, options::OPT_fdiagnostics_parseable_fixits); Args.AddLastArg(CmdArgs, options::OPT_ftime_report); + Args.AddLastArg(CmdArgs, options::OPT_ftime_trace); Args.AddLastArg(CmdArgs, options::OPT_ftrapv); Args.AddLastArg(CmdArgs, options::OPT_malign_double); diff --git a/clang/lib/Frontend/CompilerInstance.cpp b/clang/lib/Frontend/CompilerInstance.cpp index 559bdb3c0e5..c5afe2a47b5 100644 --- a/clang/lib/Frontend/CompilerInstance.cpp +++ b/clang/lib/Frontend/CompilerInstance.cpp @@ -46,6 +46,7 @@ #include "llvm/Support/Path.h" #include "llvm/Support/Program.h" #include "llvm/Support/Signals.h" +#include "llvm/Support/TimeProfiler.h" #include "llvm/Support/Timer.h" #include "llvm/Support/raw_ostream.h" #include <sys/stat.h> @@ -1025,6 +1026,8 @@ compileModuleImpl(CompilerInstance &ImportingInstance, SourceLocation ImportLoc, [](CompilerInstance &) {}, llvm::function_ref<void(CompilerInstance &)> PostBuildStep = [](CompilerInstance &) {}) { + llvm::TimeTraceScope TimeScope("Module Compile", ModuleName); + // Construct a compiler invocation for creating this module. auto Invocation = std::make_shared<CompilerInvocation>(ImportingInstance.getInvocation()); @@ -1701,6 +1704,7 @@ CompilerInstance::loadModule(SourceLocation ImportLoc, Timer.init("loading." + ModuleFileName, "Loading " + ModuleFileName, *FrontendTimerGroup); llvm::TimeRegion TimeLoading(FrontendTimerGroup ? &Timer : nullptr); + llvm::TimeTraceScope TimeScope("Module Load", ModuleName); // Try to load the module file. If we are not trying to load from the // module cache, we don't know how to rebuild modules. diff --git a/clang/lib/Frontend/CompilerInvocation.cpp b/clang/lib/Frontend/CompilerInvocation.cpp index b5872b961cc..7f1fb90ee11 100644 --- a/clang/lib/Frontend/CompilerInvocation.cpp +++ b/clang/lib/Frontend/CompilerInvocation.cpp @@ -1717,6 +1717,7 @@ static InputKind ParseFrontendArgs(FrontendOptions &Opts, ArgList &Args, Opts.ShowHelp = Args.hasArg(OPT_help); Opts.ShowStats = Args.hasArg(OPT_print_stats); Opts.ShowTimers = Args.hasArg(OPT_ftime_report); + Opts.TimeTrace = Args.hasArg(OPT_ftime_trace); Opts.ShowVersion = Args.hasArg(OPT_version); Opts.ASTMergeFiles = Args.getAllArgValues(OPT_ast_merge); Opts.LLVMArgs = Args.getAllArgValues(OPT_mllvm); diff --git a/clang/lib/Parse/ParseAST.cpp b/clang/lib/Parse/ParseAST.cpp index 5ecfc7d66fd..3efd893e499 100644 --- a/clang/lib/Parse/ParseAST.cpp +++ b/clang/lib/Parse/ParseAST.cpp @@ -22,6 +22,7 @@ #include "clang/Sema/SemaConsumer.h" #include "clang/Sema/TemplateInstCallback.h" #include "llvm/Support/CrashRecoveryContext.h" +#include "llvm/Support/TimeProfiler.h" #include <cstdio> #include <memory> @@ -150,6 +151,7 @@ void clang::ParseAST(Sema &S, bool PrintStats, bool SkipFunctionBodies) { bool HaveLexer = S.getPreprocessor().getCurrentLexer(); if (HaveLexer) { + llvm::TimeTraceScope TimeScope("Frontend", StringRef("")); P.Initialize(); Parser::DeclGroupPtrTy ADecl; for (bool AtEOF = P.ParseFirstTopLevelDecl(ADecl); !AtEOF; diff --git a/clang/lib/Parse/ParseDeclCXX.cpp b/clang/lib/Parse/ParseDeclCXX.cpp index fe9fa1059a6..de481e88793 100644 --- a/clang/lib/Parse/ParseDeclCXX.cpp +++ b/clang/lib/Parse/ParseDeclCXX.cpp @@ -24,6 +24,7 @@ #include "clang/Sema/ParsedTemplate.h" #include "clang/Sema/Scope.h" #include "llvm/ADT/SmallString.h" +#include "llvm/Support/TimeProfiler.h" using namespace clang; @@ -3114,6 +3115,12 @@ void Parser::ParseCXXMemberSpecification(SourceLocation RecordLoc, TagType == DeclSpec::TST_union || TagType == DeclSpec::TST_class) && "Invalid TagType!"); + llvm::TimeTraceScope TimeScope("ParseClass", [&]() { + if (auto *TD = dyn_cast_or_null<NamedDecl>(TagDecl)) + return TD->getQualifiedNameAsString(); + return std::string("<anonymous>"); + }); + PrettyDeclStackTraceEntry CrashInfo(Actions.Context, TagDecl, RecordLoc, "parsing struct/union/class body"); diff --git a/clang/lib/Parse/ParseTemplate.cpp b/clang/lib/Parse/ParseTemplate.cpp index 97826695e2b..d028c8f4c39 100644 --- a/clang/lib/Parse/ParseTemplate.cpp +++ b/clang/lib/Parse/ParseTemplate.cpp @@ -18,6 +18,7 @@ #include "clang/Sema/DeclSpec.h" #include "clang/Sema/ParsedTemplate.h" #include "clang/Sema/Scope.h" +#include "llvm/Support/TimeProfiler.h" using namespace clang; /// Parse a template declaration, explicit instantiation, or @@ -231,6 +232,12 @@ Decl *Parser::ParseSingleDeclarationAfterTemplate( return nullptr; } + llvm::TimeTraceScope TimeScope("ParseTemplate", [&]() { + return DeclaratorInfo.getIdentifier() != nullptr + ? DeclaratorInfo.getIdentifier()->getName() + : "<unknown>"; + }); + LateParsedAttrList LateParsedAttrs(true); if (DeclaratorInfo.isFunctionDeclarator()) MaybeParseGNUAttributes(DeclaratorInfo, &LateParsedAttrs); diff --git a/clang/lib/Sema/Sema.cpp b/clang/lib/Sema/Sema.cpp index da87e156835..bc4fdfbe58e 100644 --- a/clang/lib/Sema/Sema.cpp +++ b/clang/lib/Sema/Sema.cpp @@ -39,6 +39,8 @@ #include "clang/Sema/TemplateInstCallback.h" #include "llvm/ADT/DenseMap.h" #include "llvm/ADT/SmallSet.h" +#include "llvm/Support/TimeProfiler.h" + using namespace clang; using namespace sema; @@ -92,6 +94,12 @@ public: SourceManager &SM = S->getSourceManager(); SourceLocation IncludeLoc = SM.getIncludeLoc(SM.getFileID(Loc)); if (IncludeLoc.isValid()) { + if (llvm::timeTraceProfilerEnabled()) { + const FileEntry *FE = SM.getFileEntryForID(SM.getFileID(Loc)); + llvm::timeTraceProfilerBegin( + "Source", FE != nullptr ? FE->getName() : StringRef("<unknown>")); + } + IncludeStack.push_back(IncludeLoc); S->DiagnoseNonDefaultPragmaPack( Sema::PragmaPackDiagnoseKind::NonDefaultStateAtInclude, IncludeLoc); @@ -99,10 +107,14 @@ public: break; } case ExitFile: - if (!IncludeStack.empty()) + if (!IncludeStack.empty()) { + if (llvm::timeTraceProfilerEnabled()) + llvm::timeTraceProfilerEnd(); + S->DiagnoseNonDefaultPragmaPack( Sema::PragmaPackDiagnoseKind::ChangedStateAtExit, IncludeStack.pop_back_val()); + } break; default: break; @@ -914,7 +926,11 @@ void Sema::ActOnEndOfTranslationUnit() { Pending.begin(), Pending.end()); } - PerformPendingInstantiations(); + { + llvm::TimeTraceScope TimeScope("PerformPendingInstantiations", + StringRef("")); + PerformPendingInstantiations(); + } assert(LateParsedInstantiations.empty() && "end of TU template instantiation should not create more " diff --git a/clang/lib/Sema/SemaTemplateInstantiate.cpp b/clang/lib/Sema/SemaTemplateInstantiate.cpp index bc4d9e08451..a7d03ddff36 100644 --- a/clang/lib/Sema/SemaTemplateInstantiate.cpp +++ b/clang/lib/Sema/SemaTemplateInstantiate.cpp @@ -25,6 +25,7 @@ #include "clang/Sema/Template.h" #include "clang/Sema/TemplateDeduction.h" #include "clang/Sema/TemplateInstCallback.h" +#include "llvm/Support/TimeProfiler.h" using namespace clang; using namespace sema; @@ -2008,6 +2009,11 @@ Sema::InstantiateClass(SourceLocation PointOfInstantiation, Instantiation->getInstantiatedFromMemberClass(), Pattern, PatternDef, TSK, Complain)) return true; + + llvm::TimeTraceScope TimeScope("InstantiateClass", [&]() { + return Instantiation->getQualifiedNameAsString(); + }); + Pattern = PatternDef; // Record the point of instantiation. diff --git a/clang/lib/Sema/SemaTemplateInstantiateDecl.cpp b/clang/lib/Sema/SemaTemplateInstantiateDecl.cpp index 4615fbc9749..531defdf232 100644 --- a/clang/lib/Sema/SemaTemplateInstantiateDecl.cpp +++ b/clang/lib/Sema/SemaTemplateInstantiateDecl.cpp @@ -23,6 +23,7 @@ #include "clang/Sema/Lookup.h" #include "clang/Sema/Template.h" #include "clang/Sema/TemplateInstCallback.h" +#include "llvm/Support/TimeProfiler.h" using namespace clang; @@ -4124,6 +4125,10 @@ void Sema::InstantiateFunctionDefinition(SourceLocation PointOfInstantiation, return; } + llvm::TimeTraceScope TimeScope("InstantiateFunction", [&]() { + return Function->getQualifiedNameAsString(); + }); + // If we're performing recursive template instantiation, create our own // queue of pending implicit instantiations that we will instantiate later, // while we're still within our own instantiation context. diff --git a/clang/lib/Serialization/GlobalModuleIndex.cpp b/clang/lib/Serialization/GlobalModuleIndex.cpp index c5091bbbe49..ebcfa9f5067 100644 --- a/clang/lib/Serialization/GlobalModuleIndex.cpp +++ b/clang/lib/Serialization/GlobalModuleIndex.cpp @@ -10,6 +10,7 @@ // //===----------------------------------------------------------------------===// + #include "ASTReaderInternals.h" #include "clang/Basic/FileManager.h" #include "clang/Lex/HeaderSearch.h" @@ -28,6 +29,7 @@ #include "llvm/Support/MemoryBuffer.h" #include "llvm/Support/OnDiskHashTable.h" #include "llvm/Support/Path.h" +#include "llvm/Support/TimeProfiler.h" #include <cstdio> using namespace clang; using namespace serialization; @@ -126,6 +128,7 @@ GlobalModuleIndex::GlobalModuleIndex(std::unique_ptr<llvm::MemoryBuffer> Buffer, llvm::BitstreamCursor Cursor) : Buffer(std::move(Buffer)), IdentifierIndex(), NumIdentifierLookups(), NumIdentifierLookupHits() { + llvm::TimeTraceScope TimeScope("Module LoadIndex", StringRef("")); // Read the global index. bool InGlobalIndexBlock = false; bool Done = false; @@ -739,6 +742,7 @@ bool GlobalModuleIndexBuilder::writeIndex(llvm::BitstreamWriter &Stream) { } using namespace llvm; + llvm::TimeTraceScope TimeScope("Module WriteIndex", StringRef("")); // Emit the file header. Stream.Emit((unsigned)'B', 8); diff --git a/clang/tools/driver/cc1_main.cpp b/clang/tools/driver/cc1_main.cpp index be5818e5804..337c7d77ab0 100644 --- a/clang/tools/driver/cc1_main.cpp +++ b/clang/tools/driver/cc1_main.cpp @@ -34,8 +34,10 @@ #include "llvm/Support/Compiler.h" #include "llvm/Support/ErrorHandling.h" #include "llvm/Support/ManagedStatic.h" +#include "llvm/Support/Path.h" #include "llvm/Support/Signals.h" #include "llvm/Support/TargetSelect.h" +#include "llvm/Support/TimeProfiler.h" #include "llvm/Support/Timer.h" #include "llvm/Support/raw_ostream.h" #include <cstdio> @@ -194,6 +196,9 @@ int cc1_main(ArrayRef<const char *> Argv, const char *Argv0, void *MainAddr) { bool Success = CompilerInvocation::CreateFromArgs( Clang->getInvocation(), Argv.begin(), Argv.end(), Diags); + if (Clang->getFrontendOpts().TimeTrace) + llvm::timeTraceProfilerInitialize(); + // Infer the builtin include path if unspecified. if (Clang->getHeaderSearchOpts().UseBuiltinIncludes && Clang->getHeaderSearchOpts().ResourceDir.empty()) @@ -215,12 +220,29 @@ int cc1_main(ArrayRef<const char *> Argv, const char *Argv0, void *MainAddr) { return 1; // Execute the frontend actions. - Success = ExecuteCompilerInvocation(Clang.get()); + { + llvm::TimeTraceScope TimeScope("ExecuteCompiler", StringRef("")); + Success = ExecuteCompilerInvocation(Clang.get()); + } // If any timers were active but haven't been destroyed yet, print their // results now. This happens in -disable-free mode. llvm::TimerGroup::printAll(llvm::errs()); + if (llvm::timeTraceProfilerEnabled()) { + SmallString<128> Path(Clang->getFrontendOpts().OutputFile); + llvm::sys::path::replace_extension(Path, "json"); + auto profilerOutput = + Clang->createOutputFile(Path.str(), + /*Binary=*/false, + /*RemoveFileOnSignal=*/false, "", + /*Extension=*/"json", + /*useTemporary=*/false); + + llvm::timeTraceProfilerWrite(profilerOutput); + llvm::timeTraceProfilerCleanup(); + } + // Our error handler depends on the Diagnostics object, which we're // potentially about to delete. Uninstall the handler now so that any // later errors use the default handling behavior instead. diff --git a/llvm/include/llvm/Support/TimeProfiler.h b/llvm/include/llvm/Support/TimeProfiler.h new file mode 100644 index 00000000000..ae6703e2169 --- /dev/null +++ b/llvm/include/llvm/Support/TimeProfiler.h @@ -0,0 +1,70 @@ +//===- llvm/Support/TimeProfiler.h - Hierarchical Time Profiler -*- C++ -*-===// +// +// The LLVM Compiler Infrastructure +// +// This file is distributed under the University of Illinois Open Source +// License. See LICENSE.TXT for details. +// +//===----------------------------------------------------------------------===// + +#ifndef LLVM_SUPPORT_TIME_PROFILER_H +#define LLVM_SUPPORT_TIME_PROFILER_H + +#include "llvm/Support/raw_ostream.h" + +namespace llvm { + +struct TimeTraceProfiler; +extern TimeTraceProfiler *TimeTraceProfilerInstance; + +/// Initialize the time trace profiler. +/// This sets up the global \p TimeTraceProfilerInstance +/// variable to be the profiler instance. +void timeTraceProfilerInitialize(); + +/// Cleanup the time trace profiler, if it was initialized. +void timeTraceProfilerCleanup(); + +/// Is the time trace profiler enabled, i.e. initialized? +inline bool timeTraceProfilerEnabled() { + return TimeTraceProfilerInstance != nullptr; +} + +/// Write profiling data to output file. +/// Data produced is JSON, in Chrome "Trace Event" format, see +/// https://docs.google.com/document/d/1CvAClvFfyA5R-PhYUmn5OOQtYMH4h6I0nSsKchNAySU/preview +void timeTraceProfilerWrite(std::unique_ptr<raw_pwrite_stream> &OS); + +/// Manually begin a time section, with the given \p Name and \p Detail. +/// Profiler copies the string data, so the pointers can be given into +/// temporaries. Time sections can be hierarchical; every Begin must have a +/// matching End pair but they can nest. +void timeTraceProfilerBegin(StringRef Name, StringRef Detail); +void timeTraceProfilerBegin(StringRef Name, + llvm::function_ref<std::string()> Detail); + +/// Manually end the last time section. +void timeTraceProfilerEnd(); + +/// The TimeTraceScope is a helper class to call the begin and end functions +/// of the time trace profiler. When the object is constructed, it begins +/// the section; and when it is destroyed, it stops it. If the time profiler +/// is not initialized, the overhead is a single branch. +struct TimeTraceScope { + TimeTraceScope(StringRef Name, StringRef Detail) { + if (TimeTraceProfilerInstance != nullptr) + timeTraceProfilerBegin(Name, Detail); + } + TimeTraceScope(StringRef Name, llvm::function_ref<std::string()> Detail) { + if (TimeTraceProfilerInstance != nullptr) + timeTraceProfilerBegin(Name, Detail); + } + ~TimeTraceScope() { + if (TimeTraceProfilerInstance != nullptr) + timeTraceProfilerEnd(); + } +}; + +} // end namespace llvm + +#endif diff --git a/llvm/lib/IR/LegacyPassManager.cpp b/llvm/lib/IR/LegacyPassManager.cpp index 98b7d9b76aa..e2717f7887e 100644 --- a/llvm/lib/IR/LegacyPassManager.cpp +++ b/llvm/lib/IR/LegacyPassManager.cpp @@ -27,6 +27,7 @@ #include "llvm/Support/ErrorHandling.h" #include "llvm/Support/ManagedStatic.h" #include "llvm/Support/Mutex.h" +#include "llvm/Support/TimeProfiler.h" #include "llvm/Support/Timer.h" #include "llvm/Support/raw_ostream.h" #include <algorithm> @@ -1628,6 +1629,10 @@ bool FPPassManager::runOnFunction(Function &F) { FunctionSize = F.getInstructionCount(); } + bool ProfileTime = llvm::timeTraceProfilerEnabled(); + if (ProfileTime) + llvm::timeTraceProfilerBegin("OptFunction", F.getName()); + for (unsigned Index = 0; Index < getNumContainedPasses(); ++Index) { FunctionPass *FP = getContainedPass(Index); bool LocalChanged = false; @@ -1668,12 +1673,17 @@ bool FPPassManager::runOnFunction(Function &F) { recordAvailableAnalysis(FP); removeDeadPasses(FP, F.getName(), ON_FUNCTION_MSG); } + + if (ProfileTime) + llvm::timeTraceProfilerEnd(); + return Changed; } bool FPPassManager::runOnModule(Module &M) { bool Changed = false; + llvm::TimeTraceScope TimeScope("OptModule", M.getName()); for (Function &F : M) Changed |= runOnFunction(F); @@ -1706,6 +1716,8 @@ bool FPPassManager::doFinalization(Module &M) { /// the module, and if so, return true. bool MPPassManager::runOnModule(Module &M) { + llvm::TimeTraceScope TimeScope("OptModule", M.getName()); + bool Changed = false; // Initialize on-the-fly passes diff --git a/llvm/lib/Support/CMakeLists.txt b/llvm/lib/Support/CMakeLists.txt index b5246b27ca1..c5846ad6c81 100644 --- a/llvm/lib/Support/CMakeLists.txt +++ b/llvm/lib/Support/CMakeLists.txt @@ -139,6 +139,7 @@ add_llvm_library(LLVMSupport TarWriter.cpp TargetParser.cpp ThreadPool.cpp + TimeProfiler.cpp Timer.cpp ToolOutputFile.cpp TrigramIndex.cpp diff --git a/llvm/lib/Support/TimeProfiler.cpp b/llvm/lib/Support/TimeProfiler.cpp new file mode 100644 index 00000000000..6b999cad71a --- /dev/null +++ b/llvm/lib/Support/TimeProfiler.cpp @@ -0,0 +1,184 @@ +//===-- TimeProfiler.cpp - Hierarchical Time Profiler ---------------------===// +// +// The LLVM Compiler Infrastructure +// +// This file is distributed under the University of Illinois Open Source +// License. See LICENSE.TXT for details. +// +//===----------------------------------------------------------------------===// +// +/// \file Hierarchical time profiler implementation. +// +//===----------------------------------------------------------------------===// + +#include "llvm/Support/TimeProfiler.h" +#include "llvm/ADT/StringExtras.h" +#include "llvm/Support/FileSystem.h" +#include <cassert> +#include <chrono> +#include <string> +#include <unordered_map> +#include <vector> + +using namespace std::chrono; + +namespace llvm { + +TimeTraceProfiler *TimeTraceProfilerInstance = nullptr; + +static std::string escapeString(StringRef Src) { + std::string OS; + for (const unsigned char &C : Src) { + switch (C) { + case '"': + case '/': + case '\\': + case '\b': + case '\f': + case '\n': + case '\r': + case '\t': + OS += '\\'; + OS += C; + break; + default: + if (isPrint(C)) { + OS += C; + } + } + } + return OS; +} + +typedef duration<steady_clock::rep, steady_clock::period> DurationType; +typedef std::pair<std::string, DurationType> NameAndDuration; + +struct Entry { + time_point<steady_clock> Start; + DurationType Duration; + std::string Name; + std::string Detail; +}; + +struct TimeTraceProfiler { + TimeTraceProfiler() { + Stack.reserve(8); + Entries.reserve(128); + StartTime = steady_clock::now(); + } + + void begin(std::string Name, llvm::function_ref<std::string()> Detail) { + Entry E = {steady_clock::now(), {}, Name, Detail()}; + Stack.push_back(std::move(E)); + } + + void end() { + assert(!Stack.empty() && "Must call begin() first"); + auto &E = Stack.back(); + E.Duration = steady_clock::now() - E.Start; + + // Only include sections longer than 500us. + if (duration_cast<microseconds>(E.Duration).count() > 500) + Entries.emplace_back(E); + + // Track total time taken by each "name", but only the topmost levels of + // them; e.g. if there's a template instantiation that instantiates other + // templates from within, we only want to add the topmost one. "topmost" + // happens to be the ones that don't have any currently open entries above + // itself. + if (std::find_if(++Stack.rbegin(), Stack.rend(), [&](const Entry &Val) { + return Val.Name == E.Name; + }) == Stack.rend()) { + TotalPerName[E.Name] += E.Duration; + CountPerName[E.Name]++; + } + + Stack.pop_back(); + } + + void Write(std::unique_ptr<raw_pwrite_stream> &OS) { + assert(Stack.empty() && + "All profiler sections should be ended when calling Write"); + + *OS << "{ \"traceEvents\": [\n"; + + // Emit all events for the main flame graph. + for (const auto &E : Entries) { + auto StartUs = duration_cast<microseconds>(E.Start - StartTime).count(); + auto DurUs = duration_cast<microseconds>(E.Duration).count(); + *OS << "{ \"pid\":1, \"tid\":0, \"ph\":\"X\", \"ts\":" << StartUs + << ", \"dur\":" << DurUs << ", \"name\":\"" << escapeString(E.Name) + << "\", \"args\":{ \"detail\":\"" << escapeString(E.Detail) + << "\"} },\n"; + } + + // Emit totals by section name as additional "thread" events, sorted from + // longest one. + int Tid = 1; + std::vector<NameAndDuration> SortedTotals; + SortedTotals.reserve(TotalPerName.size()); + for (const auto &E : TotalPerName) { + SortedTotals.push_back(E); + } + std::sort(SortedTotals.begin(), SortedTotals.end(), + [](const NameAndDuration &A, const NameAndDuration &B) { + return A.second > B.second; + }); + for (const auto &E : SortedTotals) { + auto DurUs = duration_cast<microseconds>(E.second).count(); + *OS << "{ \"pid\":1, \"tid\":" << Tid << ", \"ph\":\"X\", \"ts\":" << 0 + << ", \"dur\":" << DurUs << ", \"name\":\"Total " + << escapeString(E.first) + << "\", \"args\":{ \"count\":" << CountPerName[E.first] + << ", \"avg ms\":" << (DurUs / CountPerName[E.first] / 1000) + << "} },\n"; + ++Tid; + } + + // Emit metadata event with process name. + *OS << "{ \"cat\":\"\", \"pid\":1, \"tid\":0, \"ts\":0, \"ph\":\"M\", " + "\"name\":\"process_name\", \"args\":{ \"name\":\"clang\" } }\n"; + *OS << "] }\n"; + } + + std::vector<Entry> Stack; + std::vector<Entry> Entries; + std::unordered_map<std::string, DurationType> TotalPerName; + std::unordered_map<std::string, size_t> CountPerName; + time_point<steady_clock> StartTime; +}; + +void timeTraceProfilerInitialize() { + assert(TimeTraceProfilerInstance == nullptr && + "Profiler should not be initialized"); + TimeTraceProfilerInstance = new TimeTraceProfiler(); +} + +void timeTraceProfilerCleanup() { + delete TimeTraceProfilerInstance; + TimeTraceProfilerInstance = nullptr; +} + +void timeTraceProfilerWrite(std::unique_ptr<raw_pwrite_stream> &OS) { + assert(TimeTraceProfilerInstance != nullptr && + "Profiler object can't be null"); + TimeTraceProfilerInstance->Write(OS); +} + +void timeTraceProfilerBegin(StringRef Name, StringRef Detail) { + if (TimeTraceProfilerInstance != nullptr) + TimeTraceProfilerInstance->begin(Name, [&]() { return Detail; }); +} + +void timeTraceProfilerBegin(StringRef Name, + llvm::function_ref<std::string()> Detail) { + if (TimeTraceProfilerInstance != nullptr) + TimeTraceProfilerInstance->begin(Name, Detail); +} + +void timeTraceProfilerEnd() { + if (TimeTraceProfilerInstance != nullptr) + TimeTraceProfilerInstance->end(); +} + +} // namespace llvm |