Index: lld/COFF/Config.h =================================================================== --- lld/COFF/Config.h +++ lld/COFF/Config.h @@ -13,6 +13,7 @@ #include "llvm/ADT/StringRef.h" #include "llvm/Object/COFF.h" #include "llvm/Support/CachePruning.h" +#include #include #include #include @@ -92,6 +93,24 @@ bool DebugGHashes = false; unsigned DebugTypes = static_cast(DebugType::None); llvm::SmallString<128> PDBPath; + + enum { + TotalLinkTime, + + CodeLayoutTime, + CodeDiskCommitTime, + PdbLinkTime, + PdbPublicsConstructionTime, + PdbTpiConstructionTime, + PdbTypeMergingTime, + PdbSymbolMergingTime, + PdbDiskCommitTime, + + MaxMetric + }; + + std::array Timings; + std::vector Argv; // Symbols in this set are considered as live by the garbage collector. Index: lld/COFF/PDB.cpp =================================================================== --- lld/COFF/PDB.cpp +++ lld/COFF/PDB.cpp @@ -15,6 +15,7 @@ #include "Symbols.h" #include "Writer.h" #include "lld/Common/ErrorHandler.h" +#include "lld/Common/LinkTimer.h" #include "llvm/DebugInfo/CodeView/CVDebugRecord.h" #include "llvm/DebugInfo/CodeView/DebugSubsectionRecord.h" #include "llvm/DebugInfo/CodeView/GlobalTypeTableBuilder.h" @@ -233,6 +234,10 @@ const CVIndexMap &PDBLinker::mergeDebugT(ObjFile *File, CVIndexMap &ObjectIndexMap) { + LinkTimer TypeMergingTimer; + if (Config->Verbose) + TypeMergingTimer.start(Config->Timings[Configuration::PdbTypeMergingTime]); + ArrayRef Data = getDebugSection(File, ".debug$T"); if (Data.empty()) return ObjectIndexMap; @@ -747,6 +752,11 @@ CVIndexMap ObjectIndexMap; const CVIndexMap &IndexMap = mergeDebugT(File, ObjectIndexMap); + LinkTimer SymbolTimer; + + if (Config->Verbose) + SymbolTimer.start(Config->Timings[Configuration::PdbSymbolMergingTime]); + // Now do all live .debug$S sections. DebugStringTableSubsectionRef CVStrTab; DebugChecksumsSubsectionRef Checksums; @@ -864,11 +874,16 @@ // Add all object files to the PDB. Merge .debug$T sections into IpiData and // TpiData. void PDBLinker::addObjectsToPDB() { + LinkTimer PublicsTimer; + LinkTimer TpiTimer; + for (ObjFile *File : ObjFile::Instances) addObjFile(File); Builder.getStringTableBuilder().setStrings(PDBStrTab); + if (Config->Verbose) + TpiTimer.start(Config->Timings[Configuration::PdbTpiConstructionTime]); // Construct TPI and IPI stream contents. if (Config->DebugGHashes) { addTypeInfo(Builder.getTpiBuilder(), GlobalTypeTable); @@ -877,6 +892,11 @@ addTypeInfo(Builder.getTpiBuilder(), TypeTable); addTypeInfo(Builder.getIpiBuilder(), IDTable); } + TpiTimer.end(); + + if (Config->Verbose) + PublicsTimer.start( + Config->Timings[Configuration::PdbPublicsConstructionTime]); // Compute the public and global symbols. auto &GsiBuilder = Builder.getGsiBuilder(); @@ -897,6 +917,8 @@ for (const PublicSym32 &Pub : Publics) GsiBuilder.addPublicSymbol(Pub); } + + PublicsTimer.end(); } static void addCommonLinkerModuleSymbols(StringRef Path, @@ -974,11 +996,23 @@ ArrayRef OutputSections, ArrayRef SectionTable, const llvm::codeview::DebugInfo &BuildId) { + LinkTimer FullPdbLinkTimer; + LinkTimer PdbCommitTimer; + if (Config->Verbose) + FullPdbLinkTimer.start(Config->Timings[Configuration::PdbLinkTime]); + PDBLinker PDB(Symtab); PDB.initialize(BuildId); PDB.addObjectsToPDB(); PDB.addSections(OutputSections, SectionTable); + + if (Config->Verbose) + PdbCommitTimer.start(Config->Timings[Configuration::PdbDiskCommitTime]); + PDB.commit(); + + PdbCommitTimer.end(); + FullPdbLinkTimer.end(); } void PDBLinker::initialize(const llvm::codeview::DebugInfo &BuildId) { Index: lld/COFF/Writer.cpp =================================================================== --- lld/COFF/Writer.cpp +++ lld/COFF/Writer.cpp @@ -16,6 +16,7 @@ #include "SymbolTable.h" #include "Symbols.h" #include "lld/Common/ErrorHandler.h" +#include "lld/Common/LinkTimer.h" #include "lld/Common/Memory.h" #include "llvm/ADT/DenseMap.h" #include "llvm/ADT/STLExtras.h" @@ -24,12 +25,15 @@ #include "llvm/Support/Debug.h" #include "llvm/Support/Endian.h" #include "llvm/Support/FileOutputBuffer.h" +#include "llvm/Support/FormatAdapters.h" +#include "llvm/Support/FormatVariadic.h" #include "llvm/Support/Parallel.h" #include "llvm/Support/RandomNumberGenerator.h" #include #include #include #include +#include #include using namespace llvm; @@ -282,8 +286,59 @@ return None; } +static void outputTimingInformation() { + using C = Configuration; + + using namespace std::chrono_literals; + std::chrono::milliseconds TotalDuration = 0ms; + auto MaxDuration = + std::max_element(Config->Timings.begin(), Config->Timings.end()); + TotalDuration = Config->Timings[C::TotalLinkTime]; + int Digits = std::ceil(std::log10(MaxDuration->count())); + int MaxLength = 10 + Digits + 3; // ( AB.CD%) ms + + auto Format = [Digits, TotalDuration](int N) { + float P = 100.0f * (float)Config->Timings[N].count() / + (float)TotalDuration.count(); + std::string Result = + formatv("({0,+6}%) {1:ms}", P, + fmt_align(Config->Timings[N], AlignStyle::Right, Digits + 3)); + return Result; + }; + + message("Timing:"); + message( + formatv(" Code Layout Time: {0}", Format(C::CodeLayoutTime))); + message(formatv(" Commit Output File: {0}", + Format(C::CodeDiskCommitTime))); + message(formatv(" PDB Emission (Cumulative): {0}", Format(C::PdbLinkTime))); + message(formatv(" Globals Stream Layout: {0}", + Format(C::PdbPublicsConstructionTime))); + message(formatv(" Symbol Merging: {0}", + Format(C::PdbSymbolMergingTime))); + message(formatv(" Type Merging: {0}", + Format(C::PdbTypeMergingTime))); + message(formatv(" TPI Stream Layout: {0}", + Format(C::PdbTpiConstructionTime))); + message(formatv(" Commit to Disk: {0}", + Format(C::PdbDiskCommitTime))); + message( + formatv("-----------------------------{0}", fmt_repeat("-", MaxLength))); + message( + formatv(" Total Link Time: {0}", Format(C::TotalLinkTime))); +} + // The main function of the writer. void Writer::run() { + LinkTimer TotalLinkTimer; + LinkTimer CodeLayoutTimer; + LinkTimer CodeDiskCommitTimer; + + if (Config->Verbose) { + TotalLinkTimer.start(Config->Timings[Configuration::TotalLinkTime]); + CodeLayoutTimer.start(Config->Timings[Configuration::CodeLayoutTime]); + } + createSections(); createMiscChunks(); createImportTables(); @@ -308,16 +363,25 @@ sortExceptionTable(); writeBuildId(); - if (!Config->PDBPath.empty() && Config->Debug) { + CodeLayoutTimer.end(); + if (!Config->PDBPath.empty() && Config->Debug) { assert(BuildId); createPDB(Symtab, OutputSections, SectionTable, *BuildId->BuildId); } writeMapFile(OutputSections); + if (Config->Verbose) + CodeDiskCommitTimer.start( + Config->Timings[Configuration::CodeDiskCommitTime]); if (auto E = Buffer->commit()) fatal("failed to write the output file: " + toString(std::move(E))); + CodeDiskCommitTimer.end(); + TotalLinkTimer.end(); + + if (Config->Verbose) + outputTimingInformation(); } static StringRef getOutputSection(StringRef Name) { Index: lld/include/lld/Common/LinkTimer.h =================================================================== --- /dev/null +++ lld/include/lld/Common/LinkTimer.h @@ -0,0 +1,40 @@ +//===- LinkTimer.h ----------------------------------------------*- C++ -*-===// +// +// The LLVM Linker +// +// This file is distributed under the University of Illinois Open Source +// License. See LICENSE.TXT for details. +// +//===----------------------------------------------------------------------===// + +#ifndef LLD_LINKTIMER_H +#define LLD_LINKTIMER_H + +#include +#include + +namespace lld { + +struct LinkTimer { + ~LinkTimer() { end(); } + + void start(std::chrono::milliseconds &DurationToUpdate) { + assert(!this->DurationToUpdate); + this->DurationToUpdate = &DurationToUpdate; + StartTime = std::chrono::system_clock::now(); + } + + void end() { + if (!DurationToUpdate) + return; + auto EndTime = std::chrono::system_clock::now(); + *DurationToUpdate += std::chrono::duration_cast( + EndTime - StartTime); + DurationToUpdate = nullptr; + } + std::chrono::time_point StartTime; + std::chrono::milliseconds *DurationToUpdate = nullptr; +}; +} // namespace lld + +#endif