From 01b409c35e08e4972bf0a23210a9c1690507148a Mon Sep 17 00:00:00 2001 From: Marc Auberer Date: Sat, 19 Nov 2022 00:01:11 +0100 Subject: [PATCH] Measure time for all compile stages --- .run/spice.run.xml | 2 +- src/SourceFile.cpp | 90 +++++++++++++++++-------- src/SourceFile.h | 4 +- src/cli/CLIInterface.cpp | 6 -- src/importcollector/ImportCollector.cpp | 4 ++ src/iroptimizer/IROptimizer.cpp | 2 +- src/objectemitter/ObjectEmitter.cpp | 4 +- src/util/Timer.h | 18 +++-- 8 files changed, 83 insertions(+), 47 deletions(-) diff --git a/.run/spice.run.xml b/.run/spice.run.xml index c7ab197bc..cfc787993 100644 --- a/.run/spice.run.xml +++ b/.run/spice.run.xml @@ -1,5 +1,5 @@ - + diff --git a/src/SourceFile.cpp b/src/SourceFile.cpp index 607d0b1ce..9cc9de824 100644 --- a/src/SourceFile.cpp +++ b/src/SourceFile.cpp @@ -34,7 +34,8 @@ SourceFile::SourceFile(GlobalResourceManager &resourceManager, SourceFile *paren } void SourceFile::runLexer() { - Timer timer; // Start timer, which runs until the end of the current scope + Timer timer; + timer.start(); // Read from file std::ifstream fileInputStream(filePath); @@ -61,7 +62,8 @@ void SourceFile::runLexer() { if (!resourceManager.cliOptions.ignoreCache) restoredFromCache = resourceManager.cacheManager.lookupSourceFile(this); - printStatusMessage("Lexer", IO_CODE, IO_TOKENS); + timer.stop(); + printStatusMessage("Lexer", IO_CODE, IO_TOKENS, &timer); } void SourceFile::runParser() { @@ -69,7 +71,8 @@ void SourceFile::runParser() { if (restoredFromCache) return; - Timer timer; // Start timer, which runs until the end of the current scope + Timer timer; + timer.start(); // Parse input antlrCtx.parser = std::make_unique(antlrCtx.tokenStream.get()); // Check for syntax errors @@ -77,7 +80,8 @@ void SourceFile::runParser() { antlrCtx.parser->addErrorListener(antlrCtx.parserErrorHandler.get()); antlrCtx.parser->removeParseListeners(); - printStatusMessage("Parser", IO_TOKENS, IO_CST); + timer.stop(); + printStatusMessage("Parser", IO_TOKENS, IO_CST, &timer); } void SourceFile::runCSTVisualizer() { @@ -85,7 +89,8 @@ void SourceFile::runCSTVisualizer() { if (restoredFromCache || (!resourceManager.cliOptions.dumpCST && !resourceManager.cliOptions.testMode)) return; - Timer timer; // Start timer, which runs until the end of the current scope + Timer timer; + timer.start(); // Generate dot code for this source file std::stringstream dotCode; @@ -101,7 +106,8 @@ void SourceFile::runCSTVisualizer() { visualizerOutput("CST", compilerOutput.cstString); } - printStatusMessage("CST Visualizer", IO_CST, IO_CST); + timer.stop(); + printStatusMessage("CST Visualizer", IO_CST, IO_CST, &timer); } void SourceFile::runASTBuilder() { @@ -109,7 +115,8 @@ void SourceFile::runASTBuilder() { if (restoredFromCache) return; - Timer timer; // Start timer, which runs until the end of the current scope + Timer timer; + timer.start(); // Create AST ast = std::make_unique(nullptr, CodeLoc(1, 1, filePath)); @@ -122,7 +129,8 @@ void SourceFile::runASTBuilder() { // Create global scope globalScope = std::make_unique(nullptr, SCOPE_GLOBAL); - printStatusMessage("AST Builder", IO_CST, IO_AST); + timer.stop(); + printStatusMessage("AST Builder", IO_CST, IO_AST, &timer); } void SourceFile::runASTOptimizer() { @@ -130,12 +138,14 @@ void SourceFile::runASTOptimizer() { if (restoredFromCache) return; - Timer timer; // Start timer, which runs until the end of the current scope + Timer timer; + timer.start(); ASTOptimizer astOptimizer(resourceManager, this); astOptimizer.visit(static_cast(ast.get())); - printStatusMessage("AST Optimizer", IO_AST, IO_AST); + timer.stop(); + printStatusMessage("AST Optimizer", IO_AST, IO_AST, &timer); } void SourceFile::runASTVisualizer() { @@ -143,7 +153,8 @@ void SourceFile::runASTVisualizer() { if (restoredFromCache || (!resourceManager.cliOptions.dumpAST && !resourceManager.cliOptions.testMode)) return; - Timer timer; // Start timer, which runs until the end of the current scope + Timer timer; + timer.start(); // Generate dot code for this source file std::stringstream dotCode; @@ -158,7 +169,8 @@ void SourceFile::runASTVisualizer() { visualizerOutput("AST", compilerOutput.astString); } - printStatusMessage("AST Visualizer", IO_AST, IO_AST); + timer.stop(); + printStatusMessage("AST Visualizer", IO_AST, IO_AST, &timer); } void SourceFile::runImportCollector() { // NOLINT(misc-no-recursion) @@ -166,7 +178,8 @@ void SourceFile::runImportCollector() { // NOLINT(misc-no-recursion) if (restoredFromCache) return; - Timer timer; // Start timer, which runs until the end of the current scope + Timer timer; + timer.start(); // Collect the imports for this source file ImportCollector importCollector(resourceManager, this); @@ -176,7 +189,8 @@ void SourceFile::runImportCollector() { // NOLINT(misc-no-recursion) for (const auto &dependency : dependencies) dependency.second.first->runFrontEnd(); - printStatusMessage("Import Collector", IO_AST, IO_AST); + timer.stop(); + printStatusMessage("Import Collector", IO_AST, IO_AST, &timer); } void SourceFile::runSymbolTableBuilder() { // NOLINT(misc-no-recursion) @@ -184,7 +198,8 @@ void SourceFile::runSymbolTableBuilder() { // NOLINT(misc-no-recursion) if (restoredFromCache) return; - Timer timer; // Start timer, which runs until the end of the current scope + Timer timer; + timer.start(); // Build symbol table of dependencies first for (const auto &[importName, sourceFile] : dependencies) @@ -193,10 +208,14 @@ void SourceFile::runSymbolTableBuilder() { // NOLINT(misc-no-recursion) // Then build symbol table of the current file SymbolTableBuilder symbolTableBuilder(resourceManager, this); symbolTableBuilder.visit(static_cast(ast.get())); + + timer.stop(); + printStatusMessage("Symbol Table Builder", IO_AST, IO_AST, &timer); } void SourceFile::runTypeChecker() { // NOLINT(misc-no-recursion) - Timer timer; // Start timer, which runs until the end of the current scope + Timer timer; + timer.start(); // We need two runs here due to generics. // The first run to determine all concrete substantiations of potentially generic elements @@ -204,7 +223,8 @@ void SourceFile::runTypeChecker() { // NOLINT(misc-no-recursion) // The second run to ensure, also generic scopes are type-checked properly runTypeCheckerSecond(); // Visit dependency tree from top to bottom - printStatusMessage("Type Checker", IO_AST, IO_AST); + timer.stop(); + printStatusMessage("Type Checker", IO_AST, IO_AST, &timer); } void SourceFile::runTypeCheckerFirst() { // NOLINT(misc-no-recursion) @@ -256,7 +276,8 @@ void SourceFile::runBorrowChecker() { // NOLINT(misc-no-recursion) if (restoredFromCache) return; - Timer timer; // Start timer, which runs until the end of the current scope + Timer timer; + timer.start(); // Borrow-check all dependencies first for (const auto &[importName, sourceFile] : dependencies) @@ -266,7 +287,8 @@ void SourceFile::runBorrowChecker() { // NOLINT(misc-no-recursion) BorrowChecker borrowChecker(resourceManager, this); borrowChecker.visit(static_cast(ast.get())); - printStatusMessage("Borrow Checker", IO_AST, IO_AST); + timer.stop(); + printStatusMessage("Borrow Checker", IO_AST, IO_AST, &timer); } void SourceFile::runEscapeAnalyzer() { // NOLINT(misc-no-recursion) @@ -274,7 +296,8 @@ void SourceFile::runEscapeAnalyzer() { // NOLINT(misc-no-recursion) if (restoredFromCache) return; - Timer timer; // Start timer, which runs until the end of the current scope + Timer timer; + timer.start(); // Escape-analyze all dependencies first for (const auto &[importName, sourceFile] : dependencies) @@ -284,7 +307,8 @@ void SourceFile::runEscapeAnalyzer() { // NOLINT(misc-no-recursion) EscapeAnalyzer escapeAnalyzer(resourceManager, this); escapeAnalyzer.visit(static_cast(ast.get())); - printStatusMessage("Escape Analyzer", IO_AST, IO_AST); + timer.stop(); + printStatusMessage("Escape Analyzer", IO_AST, IO_AST, &timer); } void SourceFile::runIRGenerator() { // NOLINT(misc-no-recursion) @@ -292,7 +316,8 @@ void SourceFile::runIRGenerator() { // NOLINT(misc-no-recursion) if (restoredFromCache) return; - Timer timer; // Start timer, which runs until the end of the current scope + Timer timer; + timer.start(); // Generate the imported source files for (const auto &sourceFile : dependencies) @@ -315,7 +340,8 @@ void SourceFile::runIRGenerator() { // NOLINT(misc-no-recursion) std::cout << "\n"; } // GCOV_EXCL_STOP - printStatusMessage("IR Generator", IO_AST, IO_IR); + timer.stop(); + printStatusMessage("IR Generator", IO_AST, IO_IR, &timer); } void SourceFile::runIROptimizer() { // NOLINT(misc-no-recursion) @@ -323,7 +349,8 @@ void SourceFile::runIROptimizer() { // NOLINT(misc-no-recursion) if (restoredFromCache) return; - Timer timer; // Start timer, which runs until the end of the current scope + Timer timer; + timer.start(); // Skip this stage if optimization is disabled if (resourceManager.cliOptions.optLevel < 1 || resourceManager.cliOptions.optLevel > 5) @@ -347,7 +374,8 @@ void SourceFile::runIROptimizer() { // NOLINT(misc-no-recursion) std::cout << "\n"; } // GCOV_EXCL_STOP - printStatusMessage("IR Optimizer", IO_IR, IO_IR); + timer.stop(); + printStatusMessage("IR Optimizer", IO_IR, IO_IR, &timer); } void SourceFile::runObjectEmitter() { // NOLINT(misc-no-recursion) @@ -355,7 +383,8 @@ void SourceFile::runObjectEmitter() { // NOLINT(misc-no-recursion) if (restoredFromCache) return; - Timer timer; // Start timer, which runs until the end of the current scope + Timer timer; + timer.start(); // Emit objects for the imported source files for (const auto &sourceFile : dependencies) @@ -371,7 +400,8 @@ void SourceFile::runObjectEmitter() { // NOLINT(misc-no-recursion) objectEmitter.dumpAsm(); } // GCOV_EXCL_STOP - printStatusMessage("IR Optimizer", IO_IR, IO_OBJECT_FILE); + timer.stop(); + printStatusMessage("Object Emitter", IO_IR, IO_OBJECT_FILE, &timer); } void SourceFile::concludeCompilation() { // NOLINT(misc-no-recursion) @@ -499,11 +529,13 @@ void SourceFile::visualizerOutput(std::string outputName, const std::string &out std::cout << "done.\nSVG file can be found at: " << fileBasePath << ".svg\n"; } -void SourceFile::printStatusMessage(const std::string &stage, const CompilerStageIOType &in, - const CompilerStageIOType &out) const { +void SourceFile::printStatusMessage(const std::string &stage, const CompilerStageIOType &in, const CompilerStageIOType &out, + const Timer *timer) const { if (resourceManager.cliOptions.printDebugOutput) { const char *compilerStageIoTypeName[] = {"Code", "Tokens", "CST", "AST", "IR", "OBJECT_FILE"}; std::cout << "[" << stage << "] for " << fileName << ": "; std::cout << compilerStageIoTypeName[in] << " --> " << compilerStageIoTypeName[out]; + if (timer != nullptr) + std::cout << " (" << std::to_string(timer->getDurationMilliseconds()) << " ms)\n"; } } \ No newline at end of file diff --git a/src/SourceFile.h b/src/SourceFile.h index d4c55f2e6..ff566d069 100644 --- a/src/SourceFile.h +++ b/src/SourceFile.h @@ -22,6 +22,7 @@ class GlobalResourceManager; class EntryNode; class ASTNode; +class Timer; enum CompilerStageIOType { IO_CODE = 0, @@ -130,5 +131,6 @@ class SourceFile { // Private methods void visualizerPreamble(std::stringstream &output) const; void visualizerOutput(std::string outputName, const std::string &output) const; - void printStatusMessage(const std::string &stage, const CompilerStageIOType &in, const CompilerStageIOType &out) const; + void printStatusMessage(const std::string &stage, const CompilerStageIOType &in, const CompilerStageIOType &out, + const Timer *timer) const; }; \ No newline at end of file diff --git a/src/cli/CLIInterface.cpp b/src/cli/CLIInterface.cpp index 62ef794ea..87b99cc5a 100644 --- a/src/cli/CLIInterface.cpp +++ b/src/cli/CLIInterface.cpp @@ -127,12 +127,6 @@ void CLIInterface::enrich() { cliOptions.targetOs = triple.getOSName(); cliOptions.isNativeTarget = triple == defaultTriple; } - // Dump AST, IR and symbol table if all debug output is enabled - if (cliOptions.printDebugOutput) { - cliOptions.dumpAST = true; - cliOptions.dumpIR = true; - cliOptions.dumpSymbolTables = true; - } } /** diff --git a/src/importcollector/ImportCollector.cpp b/src/importcollector/ImportCollector.cpp index 9eb7e60a0..e48cd44bc 100644 --- a/src/importcollector/ImportCollector.cpp +++ b/src/importcollector/ImportCollector.cpp @@ -15,6 +15,8 @@ std::any ImportCollector::visitEntry(EntryNode *node) { // Reset the AST node->reset(); + + return nullptr; } std::any ImportCollector::visitImportStmt(ImportStmtNode *node) { @@ -60,6 +62,8 @@ std::any ImportCollector::visitImportStmt(ImportStmtNode *node) { sourceFile->addDependency(importedSourceFile, node, node->importName, importPath); // Register all external names of the imported source file to the current one registerExternalGlobalNames(importedSourceFile.get(), node->importName); + + return nullptr; } /** diff --git a/src/iroptimizer/IROptimizer.cpp b/src/iroptimizer/IROptimizer.cpp index 772553cc8..1aa486adb 100644 --- a/src/iroptimizer/IROptimizer.cpp +++ b/src/iroptimizer/IROptimizer.cpp @@ -9,7 +9,7 @@ #include void IROptimizer::optimize() { - if (cliOptions.printDebugOutput) + if (cliOptions.printDebugOutput && cliOptions.dumpIR) std::cout << "\nOptimizing on level " + std::to_string(cliOptions.optLevel) << " ...\n"; // GCOV_EXCL_LINE llvm::LoopAnalysisManager loopAnalysisMgr; diff --git a/src/objectemitter/ObjectEmitter.cpp b/src/objectemitter/ObjectEmitter.cpp index 2397a2d44..08ca05c83 100644 --- a/src/objectemitter/ObjectEmitter.cpp +++ b/src/objectemitter/ObjectEmitter.cpp @@ -11,7 +11,7 @@ void ObjectEmitter::emit() const { const std::string &objectFile = sourceFile->objectFilePath; // GCOV_EXCL_START - if (cliOptions.printDebugOutput) + if (cliOptions.printDebugOutput && cliOptions.dumpAssembly) std::cout << "\nEmitting object file for triplet '" << cliOptions.targetTriple << "' to path: " << objectFile << "\n"; // GCOV_EXCL_STOP @@ -38,4 +38,4 @@ void ObjectEmitter::dumpAsm() const { // Emit object file passManager.run(*module); llvm::outs().flush(); -} +} \ No newline at end of file diff --git a/src/util/Timer.h b/src/util/Timer.h index cabf916eb..6908b5bd0 100644 --- a/src/util/Timer.h +++ b/src/util/Timer.h @@ -7,14 +7,18 @@ struct Timer { public: - Timer() { start = std::chrono::high_resolution_clock::now(); } - ~Timer() { - std::chrono::time_point end = std::chrono::high_resolution_clock::now(); - std::chrono::duration duration = end - start; - double durationSeconds = duration.count() * 1000000; - std::cout << durationSeconds << std::endl; + // Constructors + Timer() = default; + + // Public methods + void start() { timeStart = std::chrono::high_resolution_clock::now(); } + void stop() { timeStop = std::chrono::high_resolution_clock::now(); } + [[nodiscard]] long long getDurationMilliseconds() const { + std::chrono::duration duration = timeStop - timeStart; + return std::chrono::duration_cast(duration).count(); } private: - std::chrono::time_point start; + std::chrono::time_point timeStart; + std::chrono::time_point timeStop; }; \ No newline at end of file