diff --git a/es2panda/BUILD.gn b/es2panda/BUILD.gn index 1129c59f5a089cb817751f43f2b64f5b810f75fd..e81e9887e955fbf87b21e8ff6d637d22d1e0903c 100644 --- a/es2panda/BUILD.gn +++ b/es2panda/BUILD.gn @@ -257,6 +257,7 @@ es2panda_src = [ "util/patchFix.cpp", "util/moduleHelpers.cpp", "util/symbolTable.cpp", + "util/timers.cpp", "util/ustring.cpp", "util/workerQueue.cpp", "util/commonUtil.cpp", diff --git a/es2panda/aot/emitFiles.cpp b/es2panda/aot/emitFiles.cpp index f1f5a359792c7db875776d0b517eb6bf594a916f..1e4193bbdd11227f40b28a4569860d8933aa6995 100644 --- a/es2panda/aot/emitFiles.cpp +++ b/es2panda/aot/emitFiles.cpp @@ -21,6 +21,7 @@ #include #include #include +#include namespace panda::es2panda::aot { void EmitFileQueue::ScheduleEmitCacheJobs(EmitMergedAbcJob *emitMergedAbcJob) @@ -80,6 +81,7 @@ void EmitFileQueue::Schedule() void EmitSingleAbcJob::Run() { + es2panda::util::Timer::timerStart(util::EVENT_EMIT_SINGLE_PROGRAM, outputFileName_); if (!panda::pandasm::AsmEmitter::Emit(panda::os::file::File::GetExtendedFilePath(outputFileName_), *prog_, statp_, nullptr, true, nullptr, targetApiVersion_)) { throw Error(ErrorType::GENERIC, "Failed to emit " + outputFileName_ + ", error: " + @@ -88,10 +90,12 @@ void EmitSingleAbcJob::Run() for (auto *dependant : dependants_) { dependant->Signal(); } + es2panda::util::Timer::timerEnd(util::EVENT_EMIT_SINGLE_PROGRAM, outputFileName_); } void EmitMergedAbcJob::Run() { + es2panda::util::Timer::timerStart(util::EVENT_EMIT_MERGED_PROGRAM, ""); std::vector progs; progs.reserve(progsInfo_.size()); for (const auto &info: progsInfo_) { @@ -104,6 +108,7 @@ void EmitMergedAbcJob::Run() for (auto *dependant : dependants_) { dependant->Signal(); } + es2panda::util::Timer::timerEnd(util::EVENT_EMIT_MERGED_PROGRAM, ""); if (!success) { throw Error(ErrorType::GENERIC, "Failed to emit " + outputFileName_ + ", error: " + @@ -121,7 +126,9 @@ void EmitCacheJob::Run() { std::unique_lock lock(m_); cond_.wait(lock, [this] { return dependencies_ == 0; }); + es2panda::util::Timer::timerStart(util::EVENT_EMIT_CACHE_FILE, outputProtoName_); panda::proto::ProtobufSnapshotGenerator::UpdateCacheFile(progCache_, outputProtoName_); + es2panda::util::Timer::timerEnd(util::EVENT_EMIT_CACHE_FILE, outputProtoName_); } } // namespace panda::es2panda::util diff --git a/es2panda/aot/main.cpp b/es2panda/aot/main.cpp index efa30fbaa27ebddaad8832782b0cf160f1ae7a04..495a28f394ddd73798cf59e392834d1e5dfef6d0 100644 --- a/es2panda/aot/main.cpp +++ b/es2panda/aot/main.cpp @@ -28,6 +28,7 @@ #include #include #include +#include #include namespace panda::es2panda::aot { @@ -246,6 +247,7 @@ int Run(int argc, const char **argv) return 0; } + es2panda::util::Timer::timerStart(util::EVENT_TOTAL, ""); if (options->CompilerOptions().bcVersion || options->CompilerOptions().bcMinVersion) { std::string version = options->CompilerOptions().bcVersion ? panda::panda_file::GetVersion(panda::panda_file::version) : @@ -258,6 +260,7 @@ int Run(int argc, const char **argv) panda::ArenaAllocator allocator(panda::SpaceType::SPACE_TYPE_COMPILER, nullptr, true); Compiler::SetExpectedProgsCount(options->CompilerOptions().sourceFiles.size()); + es2panda::util::Timer::timerStart(util::EVENT_COMPILE, ""); int ret = Compiler::CompileFiles(options->CompilerOptions(), programsInfo, &allocator); if (options->ParseOnly()) { return ret; @@ -268,7 +271,9 @@ int Run(int argc, const char **argv) options->CompilerOptions(), programsInfo, &allocator); Compiler::SetExpectedProgsCount(Compiler::GetExpectedProgsCount() + 1); } + es2panda::util::Timer::timerEnd(util::EVENT_COMPILE, ""); + es2panda::util::Timer::timerStart(util::EVENT_EMIT_ABC, ""); // A mapping of program to its records which are resolved and collected as valid dependencies. std::map> resolvedDepsRelation {}; @@ -280,6 +285,12 @@ int Run(int argc, const char **argv) if (!GenerateAbcFiles(programsInfo, options, Compiler::GetExpectedProgsCount(), resolvedDepsRelation)) { return 1; } + es2panda::util::Timer::timerEnd(util::EVENT_EMIT_ABC, ""); + + es2panda::util::Timer::timerEnd(util::EVENT_TOTAL, ""); + if (!options->PerfFile().empty()) { + es2panda::util::Timer::PrintTimers(); + } return 0; } diff --git a/es2panda/aot/options.cpp b/es2panda/aot/options.cpp index 45ee9f75cb0de0df133a6eba1aee8a8eaff33b0a..0fbf139899b5056c9cc54ee07417df8f5a620f60 100644 --- a/es2panda/aot/options.cpp +++ b/es2panda/aot/options.cpp @@ -33,6 +33,7 @@ #include "mergeProgram.h" #include "util/helpers.h" +#include "util/timers.h" #include "utils/pandargs.h" namespace panda::es2panda::aot { @@ -336,6 +337,8 @@ bool Options::Parse(int argc, const char **argv) panda::PandArg opCacheFile("cache-file", "", "cache file for incremental compile"); panda::PandArg opNpmModuleEntryList("npm-module-entry-list", "", "entry list file for module compile"); panda::PandArg opMergeAbc("merge-abc", false, "Compile as merge abc"); + panda::PandArg opPerfFile("perf-file", "perf.txt", "Specify the file path to dump time consuming data"\ + " during compilation process, default to 'perf.txt' in the current directory"); panda::PandArg opuseDefineSemantic("use-define-semantic", false, "Compile ts class fields "\ "in accordance with ECMAScript2022"); @@ -413,6 +416,7 @@ bool Options::Parse(int argc, const char **argv) argparser_->Add(&opCacheFile); argparser_->Add(&opNpmModuleEntryList); argparser_->Add(&opMergeAbc); + argparser_->Add(&opPerfFile); argparser_->Add(&opuseDefineSemantic); argparser_->Add(&opBranchElimination); argparser_->Add(&opOptTryCatchFunc); @@ -593,6 +597,12 @@ bool Options::Parse(int argc, const char **argv) options_ |= OptionFlags::SIZE_PCT_STAT; } + perfFile_ = ""; + if (opPerfFile.WasSet()) { + perfFile_ = opPerfFile.GetValue().empty() ? opPerfFile.GetDefaultValue() : opPerfFile.GetValue(); + } + es2panda::util::Timer::InitializeTimer(perfFile_); + compilerOptions_.recordSource = opRecordSource.GetValue(); compilerOptions_.enableAbcInput = opEnableAbcInput.GetValue(); compilerOptions_.dumpAsmProgram = opDumpAsmProgram.GetValue(); diff --git a/es2panda/aot/options.h b/es2panda/aot/options.h index 65debf3b219de8edd696e393ac195c4d072c9cea..5d26ec2d7db2fe471f84fdb016e9b4f953877f2e 100644 --- a/es2panda/aot/options.h +++ b/es2panda/aot/options.h @@ -133,6 +133,11 @@ public: return outputFiles_; } + std::string PerfFile() const + { + return perfFile_; + } + bool CollectInputFilesFromFileList(const std::string &input, const std::string &inputExtension); bool CollectInputFilesFromFileDirectory(const std::string &input, const std::string &extension); void ParseCacheFileOption(const std::string &cacheInput); @@ -164,6 +169,7 @@ private: std::string npmModuleEntryList_; std::vector sourceFiles_; std::unordered_map outputFiles_; + std::string perfFile_; }; } // namespace panda::es2panda::aot diff --git a/es2panda/compiler/core/compileQueue.cpp b/es2panda/compiler/core/compileQueue.cpp index 9bda1c8bd9b866d0a3724a86481ef8e96c971423..a8c14128b7c758463399ec667fea266834c8a744 100644 --- a/es2panda/compiler/core/compileQueue.cpp +++ b/es2panda/compiler/core/compileQueue.cpp @@ -28,6 +28,7 @@ #include #include #include +#include namespace panda::es2panda::compiler { @@ -101,6 +102,7 @@ void CompileFileJob::Run() { std::stringstream ss; std::string buffer; + es2panda::util::Timer::timerStart(util::EVENT_READ_INPUT_AND_CACHE, src_->fileName); if (!src_->fileName.empty() && src_->isSourceMode) { if (!util::Helpers::ReadFileToBuffer(src_->fileName, ss)) { return; @@ -108,10 +110,13 @@ void CompileFileJob::Run() buffer = ss.str(); src_->source = buffer; if (RetrieveProgramFromCacheFiles(buffer)) { + es2panda::util::Timer::timerEnd(util::EVENT_READ_INPUT_AND_CACHE, src_->fileName); return; } } + es2panda::util::Timer::timerEnd(util::EVENT_READ_INPUT_AND_CACHE, src_->fileName); + es2panda::util::Timer::timerStart(util::EVENT_COMPILE_FILE, src_->fileName); es2panda::Compiler compiler(src_->scriptExtension, options_->functionThreadCount); if (!src_->isSourceMode) { compiler.AbcToAsmProgram(src_->fileName, *options_, progsInfo_, allocator_); @@ -121,7 +126,9 @@ void CompileFileJob::Run() if (prog == nullptr) { return; } + es2panda::util::Timer::timerEnd(util::EVENT_COMPILE_FILE, src_->fileName); + es2panda::util::Timer::timerStart(util::EVENT_OPTIMIZE_PROGRAM, src_->fileName); bool requireOptimizationAfterAnalysis = false; // When cross-program optimizations are required, skip program-local optimization at this stage // and perform it later after the analysis of all programs has been completed @@ -133,6 +140,7 @@ void CompileFileJob::Run() util::Helpers::OptimizeProgram(prog, src_->fileName); } } + es2panda::util::Timer::timerEnd(util::EVENT_OPTIMIZE_PROGRAM, src_->fileName); { std::unique_lock lock(global_m_); diff --git a/es2panda/compiler/core/emitter/emitter.cpp b/es2panda/compiler/core/emitter/emitter.cpp index 6304c14094641a1ae852c756ecf28b61a875023e..4fc70013d1cff05f84e36d8ef36f9a0420e21fc9 100644 --- a/es2panda/compiler/core/emitter/emitter.cpp +++ b/es2panda/compiler/core/emitter/emitter.cpp @@ -33,6 +33,7 @@ #include #include #include +#include #include #include @@ -69,9 +70,12 @@ void FunctionEmitter::Generate(util::PatchFix *patchFixHelper) GenLiteralBuffers(); GenFunctionSource(); GenConcurrentFunctionModuleRequests(); + + es2panda::util::Timer::timerStart(util::PATCH_FIX_DUMP_FUNCTION_INFO, std::string(pg_->Binder()->Program()->SourceFile())); if (patchFixHelper != nullptr) { patchFixHelper->ProcessFunction(pg_, func_, literalBuffers_); } + es2panda::util::Timer::timerEnd(util::PATCH_FIX_DUMP_FUNCTION_INFO, std::string(pg_->Binder()->Program()->SourceFile())); } const ArenaSet &FunctionEmitter::Strings() const diff --git a/es2panda/es2panda.cpp b/es2panda/es2panda.cpp index 18c1c24eb970e4309c241a5401d1a23fa1056044..ef4c1b4703267fecf779ba3df4a417bd6b2262eb 100644 --- a/es2panda/es2panda.cpp +++ b/es2panda/es2panda.cpp @@ -25,6 +25,7 @@ #include #include #include +#include #include @@ -125,6 +126,7 @@ panda::pandasm::Program *Compiler::Compile(const SourceFile &input, const Compil } try { + es2panda::util::Timer::timerStart(util::EVENT_PARSE, fname); auto ast = parser_->Parse(input, options); ast.Binder()->SetProgram(&ast); @@ -132,30 +134,18 @@ panda::pandasm::Program *Compiler::Compile(const SourceFile &input, const Compil std::cout << ast.Dump() << std::endl; } - if (ast.Extension() == ScriptExtension::TS && options.enableTypeCheck) { - ArenaAllocator localAllocator(SpaceType::SPACE_TYPE_COMPILER, nullptr, true); - auto checker = std::make_unique(&localAllocator, ast.Binder()); - checker->StartChecker(); - } - - if (ast.Extension() == ScriptExtension::TS) { - transformer_->Transform(&ast); - ast.Binder()->IdentifierAnalysis(binder::ResolveBindingFlags::TS_AFTER_TRANSFORM); - if (options.dumpTransformedAst) { - std::cout << ast.Dump() << std::endl; - } - if (options.checkTransformedAstStructure) { - transformer_->CheckTransformedAstStructure(&ast); - } - } + ProcessAstForTS(&ast, options); if (options.parseOnly) { return nullptr; } + es2panda::util::Timer::timerEnd(util::EVENT_PARSE, fname); + es2panda::util::Timer::timerStart(util::EVENT_COMPILE_TO_PROGRAM, fname); std::string debugInfoSourceFile = options.debugInfoSourceFile.empty() ? sourcefile : options.debugInfoSourceFile; auto *prog = compiler_->Compile(&ast, options, debugInfoSourceFile, pkgName); + es2panda::util::Timer::timerEnd(util::EVENT_COMPILE_TO_PROGRAM, fname); CleanPatchFixHelper(patchFixHelper); return prog; @@ -238,6 +228,10 @@ int Compiler::CompileFiles(CompilerOptions &options, queue = nullptr; if (symbolTable) { + // An optional optimization + // if (!options.patchFixOptions.dumpSymbolTable.empty()) { + // symbolTable->ActualWriteSymbolTable(); + // } delete symbolTable; symbolTable = nullptr; } @@ -277,4 +271,24 @@ panda::pandasm::Program *Compiler::CompileFile(const CompilerOptions &options, S return program; } +void Compiler::ProcessAstForTS(parser::Program *ast, const es2panda::CompilerOptions &options) +{ + if (ast->Extension() == ScriptExtension::TS && options.enableTypeCheck) { + ArenaAllocator localAllocator(SpaceType::SPACE_TYPE_COMPILER, nullptr, true); + auto checker = std::make_unique(&localAllocator, ast->Binder()); + checker->StartChecker(); + } + + if (ast->Extension() == ScriptExtension::TS) { + transformer_->Transform(ast); + ast->Binder()->IdentifierAnalysis(binder::ResolveBindingFlags::TS_AFTER_TRANSFORM); + if (options.dumpTransformedAst) { + std::cout << ast->Dump() << std::endl; + } + if (options.checkTransformedAstStructure) { + transformer_->CheckTransformedAstStructure(ast); + } + } +} + } // namespace panda::es2panda diff --git a/es2panda/es2panda.h b/es2panda/es2panda.h index 8cc78c0147c7fd8439fd64771fb1939ab33ed493..03bf315a2200d7ad112e4e47cd3bad8052f10725 100644 --- a/es2panda/es2panda.h +++ b/es2panda/es2panda.h @@ -36,6 +36,7 @@ struct PkgInfo; namespace parser { class ParserImpl; +class Program; class Transformer; enum class ScriptKind; } // namespace parser @@ -202,7 +203,7 @@ public: util::SymbolTable *symbolTable = nullptr); panda::pandasm::Program *CompileFile(const CompilerOptions &options, SourceFile *src, util::SymbolTable *symbolTable); - + void ProcessAstForTS(parser::Program *ast, const es2panda::CompilerOptions &options); static int CompileFiles(CompilerOptions &options, std::map &progsInfo, panda::ArenaAllocator *allocator); diff --git a/es2panda/util/patchFix.cpp b/es2panda/util/patchFix.cpp index 0940e77046ad03a05a0be4b3960ea996e90590c6..a18243a998ccc68bb8f8472234bc20ca7c523555 100644 --- a/es2panda/util/patchFix.cpp +++ b/es2panda/util/patchFix.cpp @@ -14,11 +14,13 @@ */ #include "patchFix.h" +#include "timers.h" #include #include #include #include #include +#include #include #include @@ -613,11 +615,18 @@ void PatchFix::HandleFunction(const compiler::PandaGen *pg, panda::pandasm::Func CollectFuncDefineIns(func); } -void PatchFix::DumpFunctionInfo(const compiler::PandaGen *pg, panda::pandasm::Function *func, - PatchFix::LiteralBuffers &literalBuffers) +static double collect_function_info_time = 0.0; +static double write_function_info_time = 0.0; + +void PatchFix::DumpFunctionInfo(const compiler::PandaGen *pg, [[maybe_unused]] panda::pandasm::Function *func, + [[maybe_unused]] PatchFix::LiteralBuffers &literalBuffers) { + es2panda::util::Timer::timerStart(util::PATCH_FIX_COLLECT_FUNCTION_INFO, std::string(pg->Binder()->Program()->SourceFile())); + std::stringstream ss; + auto start_time_1 = std::chrono::steady_clock::now(); + ss << pg->InternalName(); ss << SymbolTable::SECOND_LEVEL_SEPERATOR << pg->InternalName() << SymbolTable::SECOND_LEVEL_SEPERATOR; @@ -648,7 +657,20 @@ void PatchFix::DumpFunctionInfo(const compiler::PandaGen *pg, panda::pandasm::Fu } ss << SymbolTable::SECOND_LEVEL_SEPERATOR << std::endl; + auto start_time_2 = std::chrono::steady_clock::now(); + collect_function_info_time += std::chrono::duration_cast(start_time_2 - start_time_1).count(); + + es2panda::util::Timer::timerEnd(util::PATCH_FIX_COLLECT_FUNCTION_INFO, std::string(pg->Binder()->Program()->SourceFile())); + + es2panda::util::Timer::timerStart(util::PATCH_FIX_WRITE_FUNCTION_INFO, std::string(pg->Binder()->Program()->SourceFile())); symbolTable_->WriteSymbolTable(ss.str()); + + auto start_time_3 = std::chrono::steady_clock::now(); + write_function_info_time += std::chrono::duration_cast(start_time_3 - start_time_2).count(); + + std::cout << "collect_function_info_time: "<< collect_function_info_time << "write_function_info_time: " << write_function_info_time << std::endl; + + es2panda::util::Timer::timerEnd(util::PATCH_FIX_WRITE_FUNCTION_INFO, std::string(pg->Binder()->Program()->SourceFile())); } bool PatchFix::IsAdditionalVarInPatch(uint32_t slot) diff --git a/es2panda/util/symbolTable.cpp b/es2panda/util/symbolTable.cpp index 2b2cbc8837f226233cbf3dc2a0a7c5b1127c27a1..9ead4482c0876976d0d861747166a06c5c8141ad 100644 --- a/es2panda/util/symbolTable.cpp +++ b/es2panda/util/symbolTable.cpp @@ -14,6 +14,7 @@ */ #include "symbolTable.h" +#include "timers.h" #include #include @@ -130,16 +131,46 @@ bool SymbolTable::ReadSymbolTable(const std::string &symbolTable) void SymbolTable::WriteSymbolTable(const std::string &content) { + es2panda::util::Timer::timerStart(util::PATCH_FIX_AQUIRE_LOCK, ""); std::lock_guard lock(m_); + es2panda::util::Timer::timerEnd(util::PATCH_FIX_AQUIRE_LOCK, ""); + + es2panda::util::Timer::timerStart(util::PATCH_FIX_OPEN_FILE, ""); std::fstream fs; fs.open(panda::os::file::File::GetExtendedFilePath(dumpSymbolTable_), std::ios_base::app | std::ios_base::in); + + es2panda::util::Timer::timerEnd(util::PATCH_FIX_OPEN_FILE, ""); + + es2panda::util::Timer::timerStart(util::PATCH_FIX_WRITE_FILE, ""); if (fs.is_open()) { fs << content; fs.close(); } + es2panda::util::Timer::timerEnd(util::PATCH_FIX_WRITE_FILE, ""); + + // An optional optimization + // ss_ << content; +} + +void SymbolTable::ActualWriteSymbolTable() +{ + es2panda::util::Timer::timerStart(util::PATCH_FIX_OPEN_FILE, ""); + std::fstream fs; + fs.open(panda::os::file::File::GetExtendedFilePath(dumpSymbolTable_), + std::ios_base::app | std::ios_base::in); + + es2panda::util::Timer::timerEnd(util::PATCH_FIX_OPEN_FILE, ""); + + es2panda::util::Timer::timerStart(util::PATCH_FIX_WRITE_FILE, ""); + if (fs.is_open()) { + fs << ss_.str(); + fs.close(); + } + es2panda::util::Timer::timerEnd(util::PATCH_FIX_WRITE_FILE, ""); } + std::vector SymbolTable::GetStringItems(std::string_view input, const std::string &separator) { std::vector items; diff --git a/es2panda/util/symbolTable.h b/es2panda/util/symbolTable.h index cb829d18d164179282ede524ed151977980567a1..30d3619ab88b90c06c4bd982fad6012d63b68dce 100644 --- a/es2panda/util/symbolTable.h +++ b/es2panda/util/symbolTable.h @@ -46,6 +46,7 @@ public: bool Initialize(int targetApiVersion); void WriteSymbolTable(const std::string &content); + void ActualWriteSymbolTable(); ArenaUnorderedMap *GetOriginFunctionInfo() { return &originFunctionInfo_; @@ -81,6 +82,8 @@ private: ArenaUnorderedMap originModuleInfo_; // > ArenaUnorderedMap> originRecordHashFunctionNames_; + + std::stringstream ss_; }; } // namespace panda::es2panda::util diff --git a/es2panda/util/timers.cpp b/es2panda/util/timers.cpp new file mode 100644 index 0000000000000000000000000000000000000000..c99dc1492b45049ebf41228ee85c6c32a7e5e19e --- /dev/null +++ b/es2panda/util/timers.cpp @@ -0,0 +1,163 @@ +/* + * Copyright (c) 2024 Huawei Device Co., Ltd. + * Licensed under the Apache License, Version 2.0 (the "License"); + * you may not use this file except in compliance with the License. + * You may obtain a copy of the License at + * + * http://www.apache.org/licenses/LICENSE-2.0 + * + * Unless required by applicable law or agreed to in writing, software + * distributed under the License is distributed on an "AS IS" BASIS, + * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. + * See the License for the specific language governing permissions and + * limitations under the License. + */ + +#include "os/file.h" +#include "timers.h" + +#include +#include +#include +#include +#include +#include +#include + +namespace panda::es2panda::util { +TimeStartFunc Timer::timerStart; +TimeEndFunc Timer::timerEnd; +std::unordered_map Timer::timers_; +std::vector Timer::events_; +std::mutex Timer::mutex_; +std::string Timer::perfFile_; + +void Timer::InitializeTimer(std::string &perfFile) +{ + if (!perfFile.empty()) { + Timer::timerStart = Timer::TimerStartImpl; + Timer::timerEnd = Timer::TimerEndImpl; + perfFile_ = perfFile; + } else { + Timer::timerStart = Timer::TimerStartDoNothing; + Timer::timerEnd = Timer::TimerEndDoNothing; + } +} + +void WriteFile(std::stringstream &ss, std::string &perfFile) +{ + std::ofstream fs; + fs.open(panda::os::file::File::GetExtendedFilePath(perfFile)); + if (!fs.is_open()) { + std::cerr << "Failed to open perf file: " << perfFile << ". Errro: " << std::strerror(errno) << std::endl; + return; + } + fs << ss.str(); + fs.close(); +} + +bool DescentComparator(std::pair p1, std::pair p2) +{ + return p1.second > p2.second; +} + +void Timer::PrintTimers() +{ + std::stringstream ss; + ss << "------------- Compilation time consumption in milliseconds: -------------" << std::endl; + ss << "Note: When compiling multiple files in parallel, " << + "we will track the time consumption of each file individually. The output will aggregate these times, " << + "potentially resulting in a total time consumption greater than the sum of individual file times." << + std::endl << std::endl; + + std::vector summedUpTimeString; + ss << "------------- Compilation time consumption of each file: ----------------" << std::endl; + + for (auto &event: events_) { + auto &timeRecord = timers_.at(event); + auto formattedEvent = + std::string(timeRecord.level, ' ') + std::string(timeRecord.level, '#') + std::string(event); + + double eventTime = 0.0; + std::vector> eachFileTime; + + // ss << "****event: " << event << std::endl; + for (auto &[file, timePointRecord] : timeRecord.timePoints) { + auto t = std::chrono::duration_cast( + timePointRecord.endTime - timePointRecord.startTime).count(); + + // ss << "****file: " << file << " ,start: " << + // std::chrono::duration_cast(timePointRecord.startTime.time_since_epoch()).count() << + // " ,end: " << std::chrono::duration_cast(timePointRecord.endTime.time_since_epoch()).count() << std::endl; + eventTime += t; + if (!file.empty()) { + eachFileTime.push_back(std::pair(file, t)); + } + } + + // print each file time consumption in descending order + if (!eachFileTime.empty()) { + std::sort(eachFileTime.begin(), eachFileTime.end(), DescentComparator); + ss << formattedEvent << ", time consumption of each file:" << std::endl; + } + for (auto &pair : eachFileTime) { + if (!pair.first.empty()) { + ss << pair.first << ": " << pair.second << " ms" < lock(mutex_); + auto iter = timers_.find(event); + if (iter != timers_.end()) { + iter->second.timePoints.emplace(fileName, tpr); + } else { + TimeRecord tr; + tr.timePoints.emplace(fileName, tpr); + tr.event = event; + tr.level = level; + + timers_.emplace(event, tr); + events_.push_back(event); + } +} + +void Timer::TimerEndImpl(const std::string_view event, std::string fileName) +{ + auto endTime = std::chrono::steady_clock::now(); + + std::unique_lock lock(mutex_); + try { + auto &timeRecord = timers_.at(event); + auto &timePoint = timeRecord.timePoints.at(fileName); + timePoint.endTime = endTime; + } catch (std::exception &error) { + std::cerr << "Event " << event << " and file " << fileName << + " start timer not found in records, skip record end time!" << std::endl; + } +} + +} // namespace panda::es2panda::util diff --git a/es2panda/util/timers.h b/es2panda/util/timers.h new file mode 100644 index 0000000000000000000000000000000000000000..dcbf5e605c2810fa3b2809be0dcc2b175d550e38 --- /dev/null +++ b/es2panda/util/timers.h @@ -0,0 +1,117 @@ +/* + * Copyright (c) 2024 Huawei Device Co., Ltd. + * Licensed under the Apache License, Version 2.0 (the "License"); + * you may not use this file except in compliance with the License. + * You may obtain a copy of the License at + * + * http://www.apache.org/licenses/LICENSE-2.0 + * + * Unless required by applicable law or agreed to in writing, software + * distributed under the License is distributed on an "AS IS" BASIS, + * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. + * See the License for the specific language governing permissions and + * limitations under the License. + */ + +#ifndef ES2PANDA_UTIL_TIMERS_H +#define ES2PANDA_UTIL_TIMERS_H + +#include +#include +#include +#include +#include +#include + +namespace panda::es2panda::util { +// Event list +constexpr std::string_view EVENT_TOTAL = "Total"; +constexpr std::string_view EVENT_COMPILE = "Compile"; +constexpr std::string_view EVENT_EMIT_ABC = "Emit abc"; +constexpr std::string_view EVENT_READ_INPUT_AND_CACHE = "Read input and cache"; +constexpr std::string_view EVENT_COMPILE_FILE = "Compile file"; +constexpr std::string_view EVENT_OPTIMIZE_PROGRAM = "Optimize program"; +constexpr std::string_view EVENT_PARSE = "Parse"; +constexpr std::string_view EVENT_COMPILE_TO_PROGRAM = "Compile to program"; +constexpr std::string_view EVENT_EMIT_SINGLE_PROGRAM = "Emit single program"; +constexpr std::string_view EVENT_EMIT_MERGED_PROGRAM = "Emit merged program"; +constexpr std::string_view EVENT_EMIT_CACHE_FILE = "Emit cache file"; +constexpr std::string_view PATCH_FIX_DUMP_FUNCTION_INFO = "patch fix dump function info"; +constexpr std::string_view PATCH_FIX_COLLECT_FUNCTION_INFO = "patch fix collect function info"; +constexpr std::string_view PATCH_FIX_WRITE_FUNCTION_INFO = "patch fix write function info"; +constexpr std::string_view PATCH_FIX_AQUIRE_LOCK = "patch fix aquire lock"; +constexpr std::string_view PATCH_FIX_OPEN_FILE = "patch fix open file"; +constexpr std::string_view PATCH_FIX_WRITE_FILE = "patch fix write file"; + +// Event level, indicating the level of an event, where each event is a sub-event of the nearest preceding level event. +// The top-level event's level is 0 +enum EventLevel { + ZEROTH = 0, + FIRST, + SECOND, + THIRD, + FORTH, + FIFTH, + SIXTH +}; + +// Holds pairs of {event, level} according to the order during compilation process. +// When adding new events later, please add them in the compilation order for ease of reading and maintenance. +const std::unordered_map eventMap = { + { EVENT_TOTAL, EventLevel::ZEROTH }, + { EVENT_COMPILE, EventLevel::FIRST }, + { EVENT_READ_INPUT_AND_CACHE, EventLevel::SECOND }, + { EVENT_COMPILE_FILE, EventLevel::SECOND }, + { EVENT_PARSE, EventLevel::THIRD }, + { EVENT_COMPILE_TO_PROGRAM, EventLevel::THIRD }, + { PATCH_FIX_DUMP_FUNCTION_INFO, EventLevel::FORTH }, + { PATCH_FIX_COLLECT_FUNCTION_INFO, EventLevel::FIFTH }, + { PATCH_FIX_WRITE_FUNCTION_INFO, EventLevel::FIFTH }, + { PATCH_FIX_AQUIRE_LOCK, EventLevel::SIXTH }, + { PATCH_FIX_OPEN_FILE, EventLevel::SIXTH }, + { PATCH_FIX_WRITE_FILE, EventLevel::SIXTH }, + { EVENT_OPTIMIZE_PROGRAM, EventLevel::SECOND }, + { EVENT_EMIT_ABC, EventLevel::FIRST }, + { EVENT_EMIT_SINGLE_PROGRAM, EventLevel::SECOND }, + { EVENT_EMIT_MERGED_PROGRAM, EventLevel::SECOND }, + { EVENT_EMIT_CACHE_FILE, EventLevel::SECOND }, +}; + +typedef void (*TimeStartFunc)(const std::string_view event, std::string fileName); +typedef void (*TimeEndFunc)(const std::string_view event, std::string fileName); +typedef std::chrono::time_point TimePoint; + +struct TimePointRecord { + TimePoint startTime; + TimePoint endTime; +}; + +struct TimeRecord { + std::unordered_map timePoints; // pair of {fileName, TimePointRecord} + std::string event; + int level; +}; + +class Timer { +public: + static void InitializeTimer(std::string &perfFile); + static void PrintTimers(); + + static TimeStartFunc timerStart; + static TimeEndFunc timerEnd; + +private: + static void TimerStartImpl(const std::string_view event, std::string fileName = ""); + static void TimerEndImpl(const std::string_view event, std::string fileName = ""); + static void TimerStartDoNothing(const std::string_view event, std::string fileName = "") {} + static void TimerEndDoNothing(const std::string_view event, std::string fileName = "") {} + + static std::unordered_map timers_; // pair of {event, TimeRecord} + static std::vector events_; + static std::mutex mutex_; + static std::string perfFile_; +}; + +} // namespace panda::es2panda::util + +#endif // ES2PANDA_UTIL_TIMERS_H