diff --git a/llvm/docs/CommandGuide/tblgen.rst b/llvm/docs/CommandGuide/tblgen.rst --- a/llvm/docs/CommandGuide/tblgen.rst +++ b/llvm/docs/CommandGuide/tblgen.rst @@ -43,7 +43,7 @@ Specify the name of the dependency filename. -.. option:: --debug +.. option:: -debug Enable debug output. @@ -58,6 +58,11 @@ ``directory`` value should be a full or partial path to a directory that contains target description files. +.. option:: -null-backend + + Parse the source files and build the records, but do not run any + backend. This is useful for timing the frontend. + .. option:: -o filename Specify the output file name. If ``filename`` is ``-``, then @@ -65,21 +70,24 @@ .. option:: -print-records - Print all classes and records to standard output (default option). + Print all classes and records to standard output (default backend option). .. option:: -print-detailed-records Print a detailed report of all global variables, classes, and records to standard output. -.. option:: --stats +.. option:: -stats Enable statistics output. +.. option:: -time-phases + + Time the parser and backend phases and print a report. + .. option:: -write-if-changed - Write the output file only if it is new or has changed. The default - is true. + Write the output file only if it is new or has changed. llvm-tblgen Options ~~~~~~~~~~~~~~~~~~~ diff --git a/llvm/docs/TableGen/BackGuide.rst b/llvm/docs/TableGen/BackGuide.rst --- a/llvm/docs/TableGen/BackGuide.rst +++ b/llvm/docs/TableGen/BackGuide.rst @@ -824,3 +824,55 @@ which it was set. The ``defm`` sequence gives the locations of the ``defm`` statements that were involved in generating the record, in the order they were invoked. + +Timing TableGen Phases +---------------------- + +TableGen provides a phase timing feature that produces a report of the time +used by the various phases of parsing the source files and running the +selected backend. This feature is enabled with the ``--time-phases`` option +of the TableGen command. + +If the backend is *not* instrumented for timing, then a report such as the +following is produced. This is the timing for the +``--print-detailed-records`` backend run on the AMDGPU target. + +.. code-block:: text + + ===-------------------------------------------------------------------------=== + TableGen Phase Timing + ===-------------------------------------------------------------------------=== + Total Execution Time: 101.0106 seconds (102.4819 wall clock) + + ---User Time--- --System Time-- --User+System-- ---Wall Time--- --- Name --- + 85.5197 ( 84.9%) 0.1560 ( 50.0%) 85.6757 ( 84.8%) 85.7009 ( 83.6%) Backend overall + 15.1789 ( 15.1%) 0.0000 ( 0.0%) 15.1789 ( 15.0%) 15.1829 ( 14.8%) Parse, build records + 0.0000 ( 0.0%) 0.1560 ( 50.0%) 0.1560 ( 0.2%) 1.5981 ( 1.6%) Write output + 100.6986 (100.0%) 0.3120 (100.0%) 101.0106 (100.0%) 102.4819 (100.0%) Total + +Note that all the time for the backend is lumped under "Backend overall". + +If the backend is instrumented for timing, then its processing is +divided into phases and each one timed separately. This is the timing for +the ``--emit-dag-isel`` backend run on the AMDGPU target. + +.. code-block:: text + + ===-------------------------------------------------------------------------=== + TableGen Phase Timing + ===-------------------------------------------------------------------------=== + Total Execution Time: 746.3868 seconds (747.1447 wall clock) + + ---User Time--- --System Time-- --User+System-- ---Wall Time--- --- Name --- + 657.7938 ( 88.1%) 0.1404 ( 90.0%) 657.9342 ( 88.1%) 658.6497 ( 88.2%) Emit matcher table + 70.2317 ( 9.4%) 0.0000 ( 0.0%) 70.2317 ( 9.4%) 70.2700 ( 9.4%) Convert to matchers + 14.8825 ( 2.0%) 0.0156 ( 10.0%) 14.8981 ( 2.0%) 14.9009 ( 2.0%) Parse, build records + 2.1840 ( 0.3%) 0.0000 ( 0.0%) 2.1840 ( 0.3%) 2.1791 ( 0.3%) Sort patterns + 1.1388 ( 0.2%) 0.0000 ( 0.0%) 1.1388 ( 0.2%) 1.1401 ( 0.2%) Optimize matchers + 0.0000 ( 0.0%) 0.0000 ( 0.0%) 0.0000 ( 0.0%) 0.0050 ( 0.0%) Write output + 746.2308 (100.0%) 0.1560 (100.0%) 746.3868 (100.0%) 747.1447 (100.0%) Total + +The backend has been divided into four phases and timed separately. + +If you want to instrument a backend, refer to the backend ``DAGISelEmitter.cpp`` +and search for ``Records.startTimer``. \ No newline at end of file diff --git a/llvm/include/llvm/TableGen/Record.h b/llvm/include/llvm/TableGen/Record.h --- a/llvm/include/llvm/TableGen/Record.h +++ b/llvm/include/llvm/TableGen/Record.h @@ -26,6 +26,7 @@ #include "llvm/Support/SMLoc.h" #include "llvm/Support/TrailingObjects.h" #include "llvm/Support/raw_ostream.h" +#include "llvm/Support/timer.h" #include #include #include @@ -1743,6 +1744,13 @@ std::map> ExtraGlobals; unsigned AnonCounter = 0; + // These members are for the phase timing feature. We need a timer group, + // the last timer started, and a flag to say whether the last timer + // is the special "backend overall timer." + TimerGroup *TimingGroup = nullptr; + Timer *LastTimer = nullptr; + bool BackendTimer = false; + public: /// Get the main TableGen input file's name. const std::string getInputFilename() const { return InputFilename; } @@ -1803,6 +1811,30 @@ Init *getNewAnonymousName(); + /// Start phase timing; called if the --time-phases option is specified. + void startPhaseTiming() { + TimingGroup = new TimerGroup("TableGen", "TableGen Phase Timing"); + } + + /// Start timing a phase. Automatically stops any previous phase timer. + void startTimer(StringRef Name); + + /// Stop timing a phase. + void stopTimer(); + + /// Start timing the overall backend. If the backend starts a timer, + /// then this timer is cleared. + void startBackendTimer(StringRef Name); + + /// Stop timing the overall backend. + void stopBackendTimer(); + + /// Stop phase timing and print the report. + void stopPhaseTiming() { + if (TimingGroup) + delete TimingGroup; + } + //===--------------------------------------------------------------------===// // High-level helper methods, useful for tablegen backends. diff --git a/llvm/lib/TableGen/Main.cpp b/llvm/lib/TableGen/Main.cpp --- a/llvm/lib/TableGen/Main.cpp +++ b/llvm/lib/TableGen/Main.cpp @@ -52,6 +52,9 @@ static cl::opt WriteIfChanged("write-if-changed", cl::desc("Only write output if it changed")); +static cl::opt +TimePhases("time-phases", cl::desc("Time phases of parser and backend")); + static int reportError(const char *ProgName, Twine Msg) { errs() << ProgName << ": " << Msg; errs().flush(); @@ -83,7 +86,12 @@ int llvm::TableGenMain(const char *argv0, TableGenMainFn *MainFn) { RecordKeeper Records; + if (TimePhases) + Records.startPhaseTiming(); + // Parse the input file. + + Records.startTimer("Parse, build records"); ErrorOr> FileOrErr = MemoryBuffer::getFileOrSTDIN(InputFilename); if (std::error_code EC = FileOrErr.getError()) @@ -103,11 +111,15 @@ if (Parser.ParseFile()) return 1; + Records.stopTimer(); // Write output to memory. + Records.startBackendTimer("Backend overall"); std::string OutString; raw_string_ostream Out(OutString); - if (MainFn(Out, Records)) + unsigned status = MainFn(Out, Records); + Records.stopBackendTimer(); + if (status) return 1; // Always write the depfile, even if the main output hasn't changed. @@ -119,26 +131,31 @@ return Ret; } + Records.startTimer("Write output"); + bool WriteFile = true; if (WriteIfChanged) { // Only updates the real output file if there are any differences. // This prevents recompilation of all the files depending on it if there // aren't any. if (auto ExistingOrErr = MemoryBuffer::getFile(OutputFilename)) if (std::move(ExistingOrErr.get())->getBuffer() == Out.str()) - return 0; + WriteFile = false; } - - std::error_code EC; - ToolOutputFile OutFile(OutputFilename, EC, sys::fs::OF_None); - if (EC) - return reportError(argv0, "error opening " + OutputFilename + ":" + - EC.message() + "\n"); - OutFile.os() << Out.str(); + if (WriteFile) { + std::error_code EC; + ToolOutputFile OutFile(OutputFilename, EC, sys::fs::OF_None); + if (EC) + return reportError(argv0, "error opening " + OutputFilename + ": " + + EC.message() + "\n"); + OutFile.os() << Out.str(); + if (ErrorsPrinted == 0) + OutFile.keep(); + } + + Records.stopTimer(); + Records.stopPhaseTiming(); if (ErrorsPrinted > 0) return reportError(argv0, Twine(ErrorsPrinted) + " errors.\n"); - - // Declare success. - OutFile.keep(); return 0; } diff --git a/llvm/lib/TableGen/Record.cpp b/llvm/lib/TableGen/Record.cpp --- a/llvm/lib/TableGen/Record.cpp +++ b/llvm/lib/TableGen/Record.cpp @@ -27,6 +27,7 @@ #include "llvm/Support/ErrorHandling.h" #include "llvm/Support/SMLoc.h" #include "llvm/Support/raw_ostream.h" +#include "llvm/Support/timer.h" #include "llvm/TableGen/Error.h" #include "llvm/TableGen/Record.h" #include @@ -2574,6 +2575,46 @@ return StringInit::get("anonymous_" + utostr(AnonCounter++)); } +// These functions implement the phase timing facility. Starting a timer +// when one is already running stops the running one. + +void RecordKeeper::startTimer(StringRef Name) { + if (TimingGroup) { + if (LastTimer && LastTimer->isRunning()) { + LastTimer->stopTimer(); + if (BackendTimer) { + LastTimer->clear(); + BackendTimer = false; + } + } + + LastTimer = new Timer("", Name, *TimingGroup); + LastTimer->startTimer(); + } +} + +void RecordKeeper::stopTimer() { + if (TimingGroup) { + assert(LastTimer && "No phase timer was started"); + LastTimer->stopTimer(); + } +} + +void RecordKeeper::startBackendTimer(StringRef Name) { + if (TimingGroup) { + startTimer(Name); + BackendTimer = true; + } +} + +void RecordKeeper::stopBackendTimer() { + if (TimingGroup) { + if (BackendTimer) + stopTimer(); + BackendTimer = false; + } +} + std::vector RecordKeeper::getAllDerivedDefinitions( const ArrayRef ClassNames) const { SmallVector ClassRecs; diff --git a/llvm/utils/TableGen/CallingConvEmitter.cpp b/llvm/utils/TableGen/CallingConvEmitter.cpp --- a/llvm/utils/TableGen/CallingConvEmitter.cpp +++ b/llvm/utils/TableGen/CallingConvEmitter.cpp @@ -38,6 +38,7 @@ // Emit prototypes for all of the non-custom CC's so that they can forward ref // each other. + Records.startTimer("Emit prototypes"); for (Record *CC : CCs) { if (!CC->getValueAsBit("Custom")) { unsigned Pad = CC->getName().size(); @@ -56,6 +57,7 @@ } // Emit each non-custom calling convention description in full. + Records.startTimer("Emit full descriptions"); for (Record *CC : CCs) { if (!CC->getValueAsBit("Custom")) EmitCallingConv(CC, O); diff --git a/llvm/utils/TableGen/CodeGenTarget.cpp b/llvm/utils/TableGen/CodeGenTarget.cpp --- a/llvm/utils/TableGen/CodeGenTarget.cpp +++ b/llvm/utils/TableGen/CodeGenTarget.cpp @@ -433,8 +433,6 @@ } void CodeGenTarget::ReadInstructions() const { - NamedRegionTimer T("Read Instructions", "Time spent reading instructions", - "CodeGenTarget", "CodeGenTarget", TimeRegions); std::vector Insts = Records.getAllDerivedDefinitions("Instruction"); if (Insts.size() <= 2) PrintFatalError("No 'Instruction' subclasses defined!"); diff --git a/llvm/utils/TableGen/DAGISelEmitter.cpp b/llvm/utils/TableGen/DAGISelEmitter.cpp --- a/llvm/utils/TableGen/DAGISelEmitter.cpp +++ b/llvm/utils/TableGen/DAGISelEmitter.cpp @@ -23,9 +23,10 @@ /// DAGISelEmitter - The top-level class which coordinates construction /// and emission of the instruction selector. class DAGISelEmitter { + RecordKeeper &Records; // Just so we can get at the timing functions. CodeGenDAGPatterns CGP; public: - explicit DAGISelEmitter(RecordKeeper &R) : CGP(R) {} + explicit DAGISelEmitter(RecordKeeper &R) : Records(R), CGP(R) {} void run(raw_ostream &OS); }; } // End anonymous namespace @@ -150,6 +151,7 @@ }); // Add all the patterns to a temporary list so we can sort them. + Records.startTimer("Sort patterns"); std::vector Patterns; for (CodeGenDAGPatterns::ptm_iterator I = CGP.ptm_begin(), E = CGP.ptm_end(); I != E; ++I) @@ -160,8 +162,8 @@ std::stable_sort(Patterns.begin(), Patterns.end(), PatternSortingPredicate(CGP)); - // Convert each variant of each pattern into a Matcher. + Records.startTimer("Convert to matchers"); std::vector PatternMatchers; for (unsigned i = 0, e = Patterns.size(); i != e; ++i) { for (unsigned Variant = 0; ; ++Variant) { @@ -175,8 +177,12 @@ std::unique_ptr TheMatcher = std::make_unique(PatternMatchers); + Records.startTimer("Optimize matchers"); OptimizeMatcher(TheMatcher, CGP); + //Matcher->dump(); + + Records.startTimer("Emit matcher table"); EmitMatcherTable(TheMatcher.get(), CGP, OS); } diff --git a/llvm/utils/TableGen/GICombinerEmitter.cpp b/llvm/utils/TableGen/GICombinerEmitter.cpp --- a/llvm/utils/TableGen/GICombinerEmitter.cpp +++ b/llvm/utils/TableGen/GICombinerEmitter.cpp @@ -346,8 +346,6 @@ } bool CombineRule::parseDefs() { - NamedRegionTimer T("parseDefs", "Time spent parsing the defs", "Rule Parsing", - "Time spent on rule parsing", TimeRegions); DagInit *Defs = TheDef.getValueAsDag("Defs"); if (Defs->getOperatorAsDef(TheDef.getLoc())->getName() != "defs") { @@ -488,8 +486,6 @@ return false; } bool CombineRule::parseMatcher(const CodeGenTarget &Target) { - NamedRegionTimer T("parseMatcher", "Time spent parsing the matcher", - "Rule Parsing", "Time spent on rule parsing", TimeRegions); StringMap> NamedEdgeDefs; StringMap> NamedEdgeUses; DagInit *Matchers = TheDef.getValueAsDag("Match"); @@ -593,6 +589,7 @@ } class GICombinerEmitter { + RecordKeeper &Records; StringRef Name; const CodeGenTarget &Target; Record *Combiner; @@ -626,7 +623,7 @@ GICombinerEmitter::GICombinerEmitter(RecordKeeper &RK, const CodeGenTarget &Target, StringRef Name, Record *Combiner) - : Name(Name), Target(Target), Combiner(Combiner) {} + : Records(RK), Name(Name), Target(Target), Combiner(Combiner) {} void GICombinerEmitter::emitNameMatcher(raw_ostream &OS) const { std::vector> Cases; @@ -850,6 +847,7 @@ } void GICombinerEmitter::run(raw_ostream &OS) { + Records.startTimer("Gather rules"); gatherRules(Rules, Combiner->getValueAsListOfDefs("Rules")); if (StopAfterParse) { MatchDagCtx.print(errs()); @@ -861,11 +859,8 @@ PrintFatalError(Combiner->getLoc(), "Failed to parse one or more rules"); LLVM_DEBUG(dbgs() << "Optimizing tree for " << Rules.size() << " rules\n"); std::unique_ptr Tree; + Records.startTimer("Optimize combiner"); { - NamedRegionTimer T("Optimize", "Time spent optimizing the combiner", - "Code Generation", "Time spent generating code", - TimeRegions); - GIMatchTreeBuilder TreeBuilder(0); for (const auto &Rule : Rules) { bool HadARoot = false; @@ -887,9 +882,7 @@ return; } - NamedRegionTimer T("Emit", "Time spent emitting the combiner", - "Code Generation", "Time spent generating code", - TimeRegions); + Records.startTimer("Emit combiner"); OS << "#ifdef " << Name.upper() << "_GENCOMBINERHELPER_DEPS\n" << "#include \"llvm/ADT/SparseBitVector.h\"\n" << "namespace llvm {\n" diff --git a/llvm/utils/TableGen/PseudoLoweringEmitter.cpp b/llvm/utils/TableGen/PseudoLoweringEmitter.cpp --- a/llvm/utils/TableGen/PseudoLoweringEmitter.cpp +++ b/llvm/utils/TableGen/PseudoLoweringEmitter.cpp @@ -298,11 +298,13 @@ Records.getAllDerivedDefinitions(makeArrayRef(Classes)); // Process the pseudo expansion definitions, validating them as we do so. + Records.startTimer("Process definitions"); for (unsigned i = 0, e = Insts.size(); i != e; ++i) evaluateExpansion(Insts[i]); // Generate expansion code to lower the pseudo to an MCInst of the real // instruction. + Records.startTimer("Emit expansion code"); emitLoweringEmitter(o); } diff --git a/llvm/utils/TableGen/RegisterBankEmitter.cpp b/llvm/utils/TableGen/RegisterBankEmitter.cpp --- a/llvm/utils/TableGen/RegisterBankEmitter.cpp +++ b/llvm/utils/TableGen/RegisterBankEmitter.cpp @@ -282,6 +282,7 @@ StringRef TargetName = Target.getName(); const CodeGenRegBank &RegisterClassHierarchy = Target.getRegBank(); + Records.startTimer("Analyze records"); std::vector Banks; for (const auto &V : Records.getAllDerivedDefinitions("RegisterBank")) { SmallPtrSet VisitedRCs; @@ -303,6 +304,7 @@ } // Warn about ambiguous MIR caused by register bank/class name clashes. + Records.startTimer("Warn ambiguous"); for (const auto &Class : RegisterClassHierarchy.getRegClasses()) { for (const auto &Bank : Banks) { if (Bank.getName().lower() == StringRef(Class.getName()).lower()) { @@ -315,6 +317,7 @@ } } + Records.startTimer("Emit output"); emitSourceFileHeader("Register Bank Source Fragments", OS); OS << "#ifdef GET_REGBANK_DECLARATIONS\n" << "#undef GET_REGBANK_DECLARATIONS\n"; diff --git a/llvm/utils/TableGen/RegisterInfoEmitter.cpp b/llvm/utils/TableGen/RegisterInfoEmitter.cpp --- a/llvm/utils/TableGen/RegisterInfoEmitter.cpp +++ b/llvm/utils/TableGen/RegisterInfoEmitter.cpp @@ -1616,9 +1616,16 @@ void RegisterInfoEmitter::run(raw_ostream &OS) { CodeGenRegBank &RegBank = Target.getRegBank(); + Records.startTimer("Print enums"); runEnums(OS, Target, RegBank); + + Records.startTimer("Print MC registers"); runMCDesc(OS, Target, RegBank); + + Records.startTimer("Print header fragment"); runTargetHeader(OS, Target, RegBank); + + Records.startTimer("Print target registers"); runTargetDesc(OS, Target, RegBank); if (RegisterInfoDebug) diff --git a/llvm/utils/TableGen/TableGen.cpp b/llvm/utils/TableGen/TableGen.cpp --- a/llvm/utils/TableGen/TableGen.cpp +++ b/llvm/utils/TableGen/TableGen.cpp @@ -22,6 +22,7 @@ enum ActionType { PrintRecords, PrintDetailedRecords, + NullBackend, DumpJSON, GenEmitter, GenRegisterInfo, @@ -59,9 +60,6 @@ }; namespace llvm { -/// Storage for TimeRegionsOpt as a global so that backends aren't required to -/// include CommandLine.h -bool TimeRegions = false; cl::opt EmitLongStrLiterals( "long-string-literals", cl::desc("when emitting large string tables, prefer string literals over " @@ -78,6 +76,8 @@ "Print all records to stdout (default)"), clEnumValN(PrintDetailedRecords, "print-detailed-records", "Print full details of all records to stdout"), + clEnumValN(NullBackend, "null-backend", + "Do nothing after parsing (useful for timing)"), clEnumValN(DumpJSON, "dump-json", "Dump all records as machine-readable JSON"), clEnumValN(GenEmitter, "gen-emitter", "Generate machine code emitter"), @@ -145,19 +145,16 @@ cl::value_desc("class name"), cl::cat(PrintEnumsCat)); -cl::opt - TimeRegionsOpt("time-regions", - cl::desc("Time regions of tablegens execution"), - cl::location(TimeRegions)); - bool LLVMTableGenMain(raw_ostream &OS, RecordKeeper &Records) { switch (Action) { case PrintRecords: - OS << Records; // No argument, dump all contents + OS << Records; // No argument, dump all contents break; case PrintDetailedRecords: EmitDetailedRecords(Records, OS); break; + case NullBackend: // No backend at all. + break; case DumpJSON: EmitJSON(Records, OS); break;