[lld] r322736 - [coff] Print detailed timing information with /TIME.
Zachary Turner via llvm-commits
llvm-commits at lists.llvm.org
Wed Jan 17 11:16:26 PST 2018
Author: zturner
Date: Wed Jan 17 11:16:26 2018
New Revision: 322736
URL: http://llvm.org/viewvc/llvm-project?rev=322736&view=rev
Log:
[coff] Print detailed timing information with /TIME.
The classes used to print and update time information are in
common, so other linkers could use this as well if desired.
Differential Revision: https://reviews.llvm.org/D41915
Added:
lld/trunk/Common/Timer.cpp
lld/trunk/include/lld/Common/Timer.h
Modified:
lld/trunk/COFF/Config.h
lld/trunk/COFF/Driver.cpp
lld/trunk/COFF/ICF.cpp
lld/trunk/COFF/MarkLive.cpp
lld/trunk/COFF/Options.td
lld/trunk/COFF/PDB.cpp
lld/trunk/COFF/SymbolTable.cpp
lld/trunk/COFF/Writer.cpp
lld/trunk/COFF/Writer.h
lld/trunk/Common/CMakeLists.txt
Modified: lld/trunk/COFF/Config.h
URL: http://llvm.org/viewvc/llvm-project/lld/trunk/COFF/Config.h?rev=322736&r1=322735&r2=322736&view=diff
==============================================================================
--- lld/trunk/COFF/Config.h (original)
+++ lld/trunk/COFF/Config.h Wed Jan 17 11:16:26 2018
@@ -90,6 +90,7 @@ struct Configuration {
bool Debug = false;
bool DebugDwarf = false;
bool DebugGHashes = false;
+ bool ShowTiming = false;
unsigned DebugTypes = static_cast<unsigned>(DebugType::None);
llvm::SmallString<128> PDBPath;
std::vector<llvm::StringRef> Argv;
Modified: lld/trunk/COFF/Driver.cpp
URL: http://llvm.org/viewvc/llvm-project/lld/trunk/COFF/Driver.cpp?rev=322736&r1=322735&r2=322736&view=diff
==============================================================================
--- lld/trunk/COFF/Driver.cpp (original)
+++ lld/trunk/COFF/Driver.cpp Wed Jan 17 11:16:26 2018
@@ -17,6 +17,7 @@
#include "lld/Common/Driver.h"
#include "lld/Common/ErrorHandler.h"
#include "lld/Common/Memory.h"
+#include "lld/Common/Timer.h"
#include "lld/Common/Version.h"
#include "llvm/ADT/Optional.h"
#include "llvm/ADT/StringSwitch.h"
@@ -47,6 +48,8 @@ using llvm::sys::Process;
namespace lld {
namespace coff {
+static Timer InputFileTimer("Input File Reading", Timer::root());
+
Configuration *Config;
LinkerDriver *Driver;
@@ -714,6 +717,8 @@ void LinkerDriver::enqueueTask(std::func
}
bool LinkerDriver::run() {
+ ScopedTimer T(InputFileTimer);
+
bool DidWork = !TaskQueue.empty();
while (!TaskQueue.empty()) {
TaskQueue.front()();
@@ -765,6 +770,10 @@ void LinkerDriver::link(ArrayRef<const c
return;
}
+ if (Args.hasArg(OPT_show_timing))
+ Config->ShowTiming = true;
+
+ ScopedTimer T(Timer::root());
// Handle --version, which is an lld extension. This option is a bit odd
// because it doesn't start with "/", but we deliberately chose "--" to
// avoid conflict with /version and for compatibility with clang-cl.
@@ -1295,7 +1304,7 @@ void LinkerDriver::link(ArrayRef<const c
// Handle /output-def (MinGW specific).
if (auto *Arg = Args.getLastArg(OPT_output_def))
writeDefFile(Arg->getValue());
-
+
// Set extra alignment for .comm symbols
for (auto Pair : Config->AlignComm) {
StringRef Name = Pair.first;
@@ -1331,6 +1340,11 @@ void LinkerDriver::link(ArrayRef<const c
// Write the result.
writeResult();
+
+ // Stop early so we can print the results.
+ Timer::root().stop();
+ if (Config->ShowTiming)
+ Timer::root().print();
}
} // namespace coff
Modified: lld/trunk/COFF/ICF.cpp
URL: http://llvm.org/viewvc/llvm-project/lld/trunk/COFF/ICF.cpp?rev=322736&r1=322735&r2=322736&view=diff
==============================================================================
--- lld/trunk/COFF/ICF.cpp (original)
+++ lld/trunk/COFF/ICF.cpp Wed Jan 17 11:16:26 2018
@@ -21,6 +21,7 @@
#include "Chunks.h"
#include "Symbols.h"
#include "lld/Common/ErrorHandler.h"
+#include "lld/Common/Timer.h"
#include "llvm/ADT/Hashing.h"
#include "llvm/Support/Debug.h"
#include "llvm/Support/Parallel.h"
@@ -34,6 +35,8 @@ using namespace llvm;
namespace lld {
namespace coff {
+static Timer ICFTimer("ICF", Timer::root());
+
class ICF {
public:
void run(ArrayRef<Chunk *> V);
@@ -207,6 +210,8 @@ void ICF::forEachClass(std::function<voi
// Two sections are considered the same if their section headers,
// contents and relocations are all the same.
void ICF::run(ArrayRef<Chunk *> Vec) {
+ ScopedTimer T(ICFTimer);
+
// Collect only mergeable sections and group by hash value.
uint32_t NextId = 1;
for (Chunk *C : Vec) {
Modified: lld/trunk/COFF/MarkLive.cpp
URL: http://llvm.org/viewvc/llvm-project/lld/trunk/COFF/MarkLive.cpp?rev=322736&r1=322735&r2=322736&view=diff
==============================================================================
--- lld/trunk/COFF/MarkLive.cpp (original)
+++ lld/trunk/COFF/MarkLive.cpp Wed Jan 17 11:16:26 2018
@@ -9,16 +9,21 @@
#include "Chunks.h"
#include "Symbols.h"
+#include "lld/Common/Timer.h"
#include "llvm/ADT/STLExtras.h"
#include <vector>
namespace lld {
namespace coff {
+static Timer GCTimer("GC", Timer::root());
+
// Set live bit on for each reachable chunk. Unmarked (unreachable)
// COMDAT chunks will be ignored by Writer, so they will be excluded
// from the final output.
void markLive(ArrayRef<Chunk *> Chunks) {
+ ScopedTimer T(GCTimer);
+
// We build up a worklist of sections which have been marked as live. We only
// push into the worklist when we discover an unmarked section, and we mark
// as we push, so sections never appear twice in the list.
Modified: lld/trunk/COFF/Options.td
URL: http://llvm.org/viewvc/llvm-project/lld/trunk/COFF/Options.td?rev=322736&r1=322735&r2=322736&view=diff
==============================================================================
--- lld/trunk/COFF/Options.td (original)
+++ lld/trunk/COFF/Options.td Wed Jan 17 11:16:26 2018
@@ -132,6 +132,7 @@ def dash_dash_version : Flag<["--"], "ve
// Flags for debugging
def lldmap : F<"lldmap">;
def lldmap_file : Joined<["/", "-"], "lldmap:">;
+def show_timing : F<"time">;
//==============================================================================
// The flags below do nothing. They are defined only for link.exe compatibility.
Modified: lld/trunk/COFF/PDB.cpp
URL: http://llvm.org/viewvc/llvm-project/lld/trunk/COFF/PDB.cpp?rev=322736&r1=322735&r2=322736&view=diff
==============================================================================
--- lld/trunk/COFF/PDB.cpp (original)
+++ lld/trunk/COFF/PDB.cpp Wed Jan 17 11:16:26 2018
@@ -15,6 +15,7 @@
#include "Symbols.h"
#include "Writer.h"
#include "lld/Common/ErrorHandler.h"
+#include "lld/Common/Timer.h"
#include "llvm/DebugInfo/CodeView/CVDebugRecord.h"
#include "llvm/DebugInfo/CodeView/DebugSubsectionRecord.h"
#include "llvm/DebugInfo/CodeView/GlobalTypeTableBuilder.h"
@@ -62,6 +63,15 @@ using llvm::object::coff_section;
static ExitOnError ExitOnErr;
+static Timer TotalPdbLinkTimer("PDB Emission (Cumulative)", Timer::root());
+
+static Timer AddObjectsTimer("Add Objects", TotalPdbLinkTimer);
+static Timer TypeMergingTimer("Type Merging", AddObjectsTimer);
+static Timer SymbolMergingTimer("Symbol Merging", AddObjectsTimer);
+static Timer GlobalsLayoutTimer("Globals Stream Layout", TotalPdbLinkTimer);
+static Timer TpiStreamLayoutTimer("TPI Stream Layout", TotalPdbLinkTimer);
+static Timer DiskCommitTimer("Commit to Disk", TotalPdbLinkTimer);
+
namespace {
/// Map from type index and item index in a type server PDB to the
/// corresponding index in the destination PDB.
@@ -233,6 +243,8 @@ maybeReadTypeServerRecord(CVTypeArray &T
const CVIndexMap &PDBLinker::mergeDebugT(ObjFile *File,
CVIndexMap &ObjectIndexMap) {
+ ScopedTimer T(TypeMergingTimer);
+
ArrayRef<uint8_t> Data = getDebugSection(File, ".debug$T");
if (Data.empty())
return ObjectIndexMap;
@@ -747,6 +759,8 @@ void PDBLinker::addObjFile(ObjFile *File
CVIndexMap ObjectIndexMap;
const CVIndexMap &IndexMap = mergeDebugT(File, ObjectIndexMap);
+ ScopedTimer T(SymbolMergingTimer);
+
// Now do all live .debug$S sections.
DebugStringTableSubsectionRef CVStrTab;
DebugChecksumsSubsectionRef Checksums;
@@ -864,12 +878,15 @@ static PublicSym32 createPublic(Defined
// Add all object files to the PDB. Merge .debug$T sections into IpiData and
// TpiData.
void PDBLinker::addObjectsToPDB() {
+ ScopedTimer T1(AddObjectsTimer);
for (ObjFile *File : ObjFile::Instances)
addObjFile(File);
Builder.getStringTableBuilder().setStrings(PDBStrTab);
+ T1.stop();
// Construct TPI and IPI stream contents.
+ ScopedTimer T2(TpiStreamLayoutTimer);
if (Config->DebugGHashes) {
addTypeInfo(Builder.getTpiBuilder(), GlobalTypeTable);
addTypeInfo(Builder.getIpiBuilder(), GlobalIDTable);
@@ -877,7 +894,9 @@ void PDBLinker::addObjectsToPDB() {
addTypeInfo(Builder.getTpiBuilder(), TypeTable);
addTypeInfo(Builder.getIpiBuilder(), IDTable);
}
+ T2.stop();
+ ScopedTimer T3(GlobalsLayoutTimer);
// Compute the public and global symbols.
auto &GsiBuilder = Builder.getGsiBuilder();
std::vector<PublicSym32> Publics;
@@ -974,10 +993,13 @@ void coff::createPDB(SymbolTable *Symtab
ArrayRef<OutputSection *> OutputSections,
ArrayRef<uint8_t> SectionTable,
const llvm::codeview::DebugInfo &BuildId) {
+ ScopedTimer T1(TotalPdbLinkTimer);
PDBLinker PDB(Symtab);
PDB.initialize(BuildId);
PDB.addObjectsToPDB();
PDB.addSections(OutputSections, SectionTable);
+
+ ScopedTimer T2(DiskCommitTimer);
PDB.commit();
}
Modified: lld/trunk/COFF/SymbolTable.cpp
URL: http://llvm.org/viewvc/llvm-project/lld/trunk/COFF/SymbolTable.cpp?rev=322736&r1=322735&r2=322736&view=diff
==============================================================================
--- lld/trunk/COFF/SymbolTable.cpp (original)
+++ lld/trunk/COFF/SymbolTable.cpp Wed Jan 17 11:16:26 2018
@@ -14,6 +14,7 @@
#include "Symbols.h"
#include "lld/Common/ErrorHandler.h"
#include "lld/Common/Memory.h"
+#include "lld/Common/Timer.h"
#include "llvm/IR/LLVMContext.h"
#include "llvm/Support/Debug.h"
#include "llvm/Support/raw_ostream.h"
@@ -24,6 +25,8 @@ using namespace llvm;
namespace lld {
namespace coff {
+static Timer LTOTimer("LTO", Timer::root());
+
SymbolTable *Symtab;
void SymbolTable::addFile(InputFile *File) {
@@ -384,6 +387,8 @@ std::vector<StringRef> SymbolTable::comp
void SymbolTable::addCombinedLTOObjects() {
if (BitcodeFile::Instances.empty())
return;
+
+ ScopedTimer T(LTOTimer);
for (StringRef Object : compileBitcodeFiles()) {
auto *Obj = make<ObjFile>(MemoryBufferRef(Object, "lto.tmp"));
Obj->parse();
Modified: lld/trunk/COFF/Writer.cpp
URL: http://llvm.org/viewvc/llvm-project/lld/trunk/COFF/Writer.cpp?rev=322736&r1=322735&r2=322736&view=diff
==============================================================================
--- lld/trunk/COFF/Writer.cpp (original)
+++ lld/trunk/COFF/Writer.cpp Wed Jan 17 11:16:26 2018
@@ -17,6 +17,7 @@
#include "Symbols.h"
#include "lld/Common/ErrorHandler.h"
#include "lld/Common/Memory.h"
+#include "lld/Common/Timer.h"
#include "llvm/ADT/DenseMap.h"
#include "llvm/ADT/STLExtras.h"
#include "llvm/ADT/StringSwitch.h"
@@ -163,6 +164,9 @@ private:
namespace lld {
namespace coff {
+static Timer CodeLayoutTimer("Code Layout", Timer::root());
+static Timer DiskCommitTimer("Commit Output File", Timer::root());
+
void writeResult() { Writer().run(); }
void OutputSection::setRVA(uint64_t RVA) {
@@ -287,6 +291,8 @@ static Optional<codeview::DebugInfo> loa
// The main function of the writer.
void Writer::run() {
+ ScopedTimer T1(CodeLayoutTimer);
+
createSections();
createMiscChunks();
createImportTables();
@@ -315,14 +321,16 @@ void Writer::run() {
sortExceptionTable();
writeBuildId();
- if (!Config->PDBPath.empty() && Config->Debug) {
+ T1.stop();
+ if (!Config->PDBPath.empty() && Config->Debug) {
assert(BuildId);
createPDB(Symtab, OutputSections, SectionTable, *BuildId->BuildId);
}
writeMapFile(OutputSections);
+ ScopedTimer T2(DiskCommitTimer);
if (auto E = Buffer->commit())
fatal("failed to write the output file: " + toString(std::move(E)));
}
Modified: lld/trunk/COFF/Writer.h
URL: http://llvm.org/viewvc/llvm-project/lld/trunk/COFF/Writer.h?rev=322736&r1=322735&r2=322736&view=diff
==============================================================================
--- lld/trunk/COFF/Writer.h (original)
+++ lld/trunk/COFF/Writer.h Wed Jan 17 11:16:26 2018
@@ -13,6 +13,7 @@
#include "Chunks.h"
#include "llvm/ADT/StringRef.h"
#include "llvm/Object/COFF.h"
+#include <chrono>
#include <cstdint>
#include <vector>
Modified: lld/trunk/Common/CMakeLists.txt
URL: http://llvm.org/viewvc/llvm-project/lld/trunk/Common/CMakeLists.txt?rev=322736&r1=322735&r2=322736&view=diff
==============================================================================
--- lld/trunk/Common/CMakeLists.txt (original)
+++ lld/trunk/Common/CMakeLists.txt Wed Jan 17 11:16:26 2018
@@ -10,6 +10,7 @@ add_lld_library(lldCommon
Strings.cpp
TargetOptionsCommandFlags.cpp
Threads.cpp
+ Timer.cpp
Version.cpp
ADDITIONAL_HEADER_DIRS
Added: lld/trunk/Common/Timer.cpp
URL: http://llvm.org/viewvc/llvm-project/lld/trunk/Common/Timer.cpp?rev=322736&view=auto
==============================================================================
--- lld/trunk/Common/Timer.cpp (added)
+++ lld/trunk/Common/Timer.cpp Wed Jan 17 11:16:26 2018
@@ -0,0 +1,71 @@
+#include "lld/Common/Timer.h"
+#include "lld/Common/ErrorHandler.h"
+#include "llvm/Support/Format.h"
+
+using namespace lld;
+using namespace llvm;
+
+ScopedTimer::ScopedTimer(Timer &T) : T(&T) { T.start(); }
+
+void ScopedTimer::stop() {
+ if (!T)
+ return;
+ T->stop();
+ T = nullptr;
+}
+
+ScopedTimer::~ScopedTimer() { stop(); }
+
+Timer::Timer(llvm::StringRef Name) : Name(Name), Parent(nullptr) {}
+Timer::Timer(llvm::StringRef Name, Timer &Parent)
+ : Name(Name), Parent(&Parent) {}
+
+void Timer::start() {
+ if (Parent && Total.count() == 0)
+ Parent->Children.push_back(this);
+ StartTime = std::chrono::high_resolution_clock::now();
+}
+
+void Timer::stop() {
+ Total += (std::chrono::high_resolution_clock::now() - StartTime);
+}
+
+Timer &Timer::root() {
+ static Timer RootTimer("Total Link Time");
+ return RootTimer;
+}
+
+void Timer::print() {
+ double TotalDuration = static_cast<double>(root().millis());
+
+ // We want to print the grand total under all the intermediate phases, so we
+ // print all children first, then print the total under that.
+ for (const auto &Child : Children)
+ Child->print(1, TotalDuration);
+
+ message(std::string(49, '-'));
+
+ root().print(0, root().millis(), false);
+}
+
+double Timer::millis() const {
+ return std::chrono::duration_cast<std::chrono::duration<double, std::milli>>(
+ Total)
+ .count();
+}
+
+void Timer::print(int Depth, double TotalDuration, bool Recurse) const {
+ double P = 100.0 * millis() / TotalDuration;
+
+ SmallString<32> Str;
+ llvm::raw_svector_ostream Stream(Str);
+ std::string S = std::string(Depth * 2, ' ') + Name + std::string(":");
+ Stream << format("%-30s%5d ms (%5.1f%%)", S.c_str(), (int)millis(), P);
+
+ message(Str);
+
+ if (Recurse) {
+ for (const auto &Child : Children)
+ Child->print(Depth + 1, TotalDuration);
+ }
+}
Added: lld/trunk/include/lld/Common/Timer.h
URL: http://llvm.org/viewvc/llvm-project/lld/trunk/include/lld/Common/Timer.h?rev=322736&view=auto
==============================================================================
--- lld/trunk/include/lld/Common/Timer.h (added)
+++ lld/trunk/include/lld/Common/Timer.h Wed Jan 17 11:16:26 2018
@@ -0,0 +1,59 @@
+//===- Timer.h ----------------------------------------------*- C++ -*-===//
+//
+// The LLVM Linker
+//
+// This file is distributed under the University of Illinois Open Source
+// License. See LICENSE.TXT for details.
+//
+//===----------------------------------------------------------------------===//
+
+#ifndef LLD_COMMON_TIMER_H
+#define LLD_COMMON_TIMER_H
+
+#include "llvm/ADT/DenseMap.h"
+#include "llvm/ADT/StringRef.h"
+#include <assert.h>
+#include <chrono>
+#include <map>
+#include <memory>
+
+namespace lld {
+
+class Timer;
+
+struct ScopedTimer {
+ explicit ScopedTimer(Timer &T);
+
+ ~ScopedTimer();
+
+ void stop();
+
+ Timer *T = nullptr;
+};
+
+class Timer {
+public:
+ Timer(llvm::StringRef Name, Timer &Parent);
+
+ static Timer &root();
+
+ void start();
+ void stop();
+ void print();
+
+ double millis() const;
+
+private:
+ explicit Timer(llvm::StringRef Name);
+ void print(int Depth, double TotalDuration, bool Recurse = true) const;
+
+ std::chrono::time_point<std::chrono::high_resolution_clock> StartTime;
+ std::chrono::nanoseconds Total;
+ std::vector<Timer *> Children;
+ std::string Name;
+ Timer *Parent;
+};
+
+} // namespace lld
+
+#endif
More information about the llvm-commits
mailing list