[LLD] Add summary support

[aganea]

Summary

I am proposing a very simple summary of the data processed by LLD, to be displayed at the end of linking.
Currently, this is enabled through a hidden (LLD-specific) COFF flag /summary, but it could be used in the other drivers too.
Here's an example output:

                                    Summary
--------------------------------------------------------------------------------
           4777 Input OBJ files (expanded from all cmd-line inputs)
             68 Dependent PDB files
             31 Dependent PCH OBJ files
          49283 Output PDB strings
        1785681 Output global symbol records

It is purposely very simple: it displays only a <u64,string> pair; there's no grouping or sorting whatsoever.
Also, the line will not be displayed if the value is zero, to avoid noise.

[aganea]

I would also like an overall opinion from you all: when using /summary in production, the numbers can get pretty big.
For example, a day-to-day developement build:

                                     Summary
--------------------------------------------------------------------------------
           4785 Input OBJ files (expanded from all cmd-line inputs)
             71 Dependent PDB files
             27 Dependent PCH OBJ files
      139948902 Input type records (across all OBJ and dependencies)
     8449407544 Input type records bytes (across all OBJ and dependencies)
        9664019 Output merged type records
       40258663 Output merged symbol records
          48454 Output PDB strings

A similar target, but non-unity TUs:

                                    Summary
--------------------------------------------------------------------------------
           6031 Input OBJ files (expanded from all cmd-line inputs)
              0 Dependent PDB files
              1 Dependent PCH OBJ files
     1854813694 Input type records (across all OBJ and dependencies)
   107738367784 Input type records bytes (across all OBJ and dependencies)
       14259032 Output merged type records
       86900071 Output merged symbol records
          23641 Output PDB strings

The numbers become meaningless because they are too big. It might take you a bit to count the digits to understand it's 107 GB there for the "Input type records bytes" line.

We could use the locale, but things are not much better:

                                    Summary
--------------------------------------------------------------------------------
            6,031 Input OBJ files (expanded from all cmd-line inputs)
                0 Dependent PDB files
                1 Dependent PCH OBJ files
    1,854,813,694 Input type records (across all OBJ and dependencies)
  107,738,367,784 Input type records bytes (across all OBJ and dependencies)
       14,259,032 Output merged type records
       86,900,071 Output merged symbol records
           23,641 Output PDB strings

So maybe we could round some of these numbers, just to give a first order of magnitude information:

                                    Summary
--------------------------------------------------------------------------------
            6,031 Input OBJ files (expanded from all cmd-line inputs)
                0 Dependent PDB files
                1 Dependent PCH OBJ files
             1.8B Input type records (across all OBJ and dependencies)
          107.7GB Input type records bytes (across all OBJ and dependencies)
            14.2M Output merged type records
            86.9M Output merged symbol records
           23,641 Output PDB strings

And maybe have /summary+ if you want the precise numbers. What do you think?

[ruiu]

Could you elaborate a bit about why you want this feature?

Instead of adding a flag, you might want to do that when /verbose is given.

COFF/PDB.cpp

1361 ↗

(On Diff #188099)

Looks like instead of pushing stats data to a Summary class and print it out later, you could print out the stats right here.

[aganea]

In D58599#1409821, @ruiu wrote:

Could you elaborate a bit about why you want this feature?

Instead of adding a flag, you might want to do that when /verbose is given.

Essentially to have a better understanding of where the timings go. With many different clients and many different usages, seeing the /time values does not tell me what caused those timings. /summary gives me more hints on the "what" and also allows compares between different usages. This is primarily geared towards the PDB generation, because that's what takes the most time, and because that's where I'd like to put the most efforts on.

In contrast, /verbose is more for the day-to-day users of the linker. For example if you want to understand wrong lib paths, or missing symbols.
I suppose I could print the information I want for summary at the end of /verbose output, however that forces to wait on the excruciatingly long /verbose console output. Output which cannot be redirected by the way, for a reason I haven't investigated yet.
The following does not produce the expected result - instead the text is half-printed on the console, and the dump file only contains partial information (Discarded symbols and the cmd-line):

lld-link.exe ... /verbose >dump.txt

COFF/PDB.cpp

1361 ↗

(On Diff #188099)

That would skew profiles recorded for /time. I often use /time and /summary at the same time.

[rnk]

In D58599#1410086, @aganea wrote:> The following does not produce the expected result - instead the text is half-printed on the console, and the dump file only contains partial information (Discarded symbols and the cmd-line):

lld-link.exe ... /verbose >dump.txt

Because, of course, we log to stderr. =p I think it's just a holdover convention from the compiler, where everything must be sent to stderr in case the user puts -o - on the command line, which would end up mixing diagnostics with binary output. This gets set here:
https://github.com/llvm/llvm-project/blob/master/lld/include/lld/Common/ErrorHandler.h#L89

You could probably change the convention for lld-link, but maybe it's best to leave ELF alone.

[aganea]

In D58599#1412659, @rnk wrote:

Because, of course, we log to stderr. =p

Thanks Reid! :) I figured it was something related to stderr, but turns out my command-line wasn't right.
One must redirect stderr to stdout after the redirection to file:

lld-link.exe ... /verbose >dump.txt 2>&1

[ruiu]

In D58599#1410086, @aganea wrote:

In D58599#1409821, @ruiu wrote:

Could you elaborate a bit about why you want this feature?

Instead of adding a flag, you might want to do that when /verbose is given.

Essentially to have a better understanding of where the timings go. With many different clients and many different usages, seeing the /time values does not tell me what caused those timings. /summary gives me more hints on the "what" and also allows compares between different usages. This is primarily geared towards the PDB generation, because that's what takes the most time, and because that's where I'd like to put the most efforts on.

In contrast, /verbose is more for the day-to-day users of the linker. For example if you want to understand wrong lib paths, or missing symbols.

It sounds like /summary is more like a developer option and should be hidden from the user. By hiding it, I mean the option shouldn't be in the option list in /help.

COFF/PDB.cpp

1361 ↗

(On Diff #188099)

You can stop the timer and resume it after you are done with summary.

[aganea]

In D58599#1412972, @ruiu wrote:

It sounds like /summary is more like a developer option and should be hidden from the user. By hiding it, I mean the option shouldn't be in the option list in /help.

It is hidden indeed as it is.

Please let me know if you find this feature useful and if you'd use it. I don't expect you to accept all of my patches, but I thought this would be useful for the other drivers too.

COFF/PDB.cpp

1361 ↗

(On Diff #188099)

The main selling point was for this to be a one-liner call. However, it's only meant for high-level information, so maybe it won't be that much of an issue for timings.

Common/Summary.cpp

33 ↗

(On Diff #188099)

Alternatively, I could accumulate the stats into a static string, and print it on exit. Would you consider that a better approach?

[ruiu]

COFF/PDB.cpp

1361 ↗

(On Diff #188099)

That's my feeling. Printing out a few lines doesn't seem to affect too much to the statistics of /time. I still believe you can just print it out from here.

[aganea]

COFF/PDB.cpp

1361 ↗

(On Diff #188099)

I will do that.

[aganea]

Simplified as suggested.

Given that lines are printed on-the-spot now, unfortunately they can be interleaved with warnings:

                                    Summary
--------------------------------------------------------------------------------
              3 Input OBJ files (expanded from all cmd-line inputs)
lld-link: warning: Cannot use debug info for 'precomp-invalid.obj' [LNK4099]
>>> failed to load reference 'f:\svn\lld\test\coff\precomp\precomp.obj': The signature does not match; the file(s) might be out of date.
              2 Dependent PCH OBJ files
              4 Output PDB strings
              3 Output global symbol records

Is that what we want?
It wouldn't make things more complicated if we accumulated the messages, and print them on exit?

[ruiu]

I guess that you could just move the code to the end of the function?

[aganea]

In D58599#1426688, @ruiu wrote:

I guess that you could just move the code to the end of the function?

I've moved printing the statistics in its own function. Does this look more acceptable?

[ruiu]

COFF/PDB.cpp

1365 ↗

(On Diff #190498)

I'm sorry to be repeat saying the same thing, but can't you just print them out in this function? This way, there's no chance that some other log message is displayed between the following lines.

[aganea]

This comment has been deleted.

COFF/PDB.cpp

1365 ↗

(On Diff #190498)

Of course, but my original intent was to provide an interface for adding statistics for the whole LLD. Meanning not just for the PDBLinker, but allowing to log stats from anywhere. Thus the original intent for buffering the values instead of printing on the spot.
We're drifting away from that, and I can very well remove the Summary class, and print everything here. Is that what you suggest?

[ruiu]

Yes, I don't think we need Suymmary class. I'd really like to avoid creating a generic infrastructure too far ahead of time. If we would like to print out stuff all at once at the end of the process in the future, we'll be able to easily do that and change the existing code to print out to that output buffer instead of out().

[aganea]

In D58599#1428277, @ruiu wrote:

Yes, I don't think we need Suymmary class. I'd really like to avoid creating a generic infrastructure too far ahead of time. If we would like to print out stuff all at once at the end of the process in the future, we'll be able to easily do that and change the existing code to print out to that output buffer instead of out().

Ok, once you've mentionned outs() it made everything clear, and I agree. I'll keep that in mind for potential upgrades, if need arises.
In the meanwhile, please see the updated code.

[ruiu]

Generally looking good, thank you for updating it.

COFF/Driver.cpp

1002–1003 ↗

(On Diff #190609)

nit: you could directly assign, like Config->ShowSummary = Args.hasArg(OPT_summary).

COFF/PDB.cpp

1374–1375 ↗

(On Diff #190609)

Printing out all values even if they are zero makes more sense to me, because having zero records is still a piece of information.

[aganea]

As requested. Thanks to you for taking the time!

[ruiu]

LGTM

lld/trunk/COFF/Config.h

struct Configuration {
   bool Relocatable = true;
   bool ForceMultiple = false;
   bool ForceUnresolved = false;
   bool Debug = false;
   bool DebugDwarf = false;
   bool DebugGHashes = false;
   bool DebugSymtab = false;
   bool ShowTiming = false;
+  bool ShowSummary = false;
   unsigned DebugTypes = static_cast<unsigned>(DebugType::None);
   std::vector<std::string> NatvisFiles;
   llvm::SmallString<128> PDBAltPath;
   llvm::SmallString<128> PDBPath;
   llvm::SmallString<128> PDBSourcePath;
   std::vector<llvm::StringRef> Argv;
 
   // Symbols in this set are considered as live by the garbage collector.

lld/trunk/COFF/Driver.cpp

if (Args.hasArg(OPT_help)) {
     return;
   }
 
   lld::ThreadsEnabled = Args.hasFlag(OPT_threads, OPT_threads_no, true);
 
   if (Args.hasArg(OPT_show_timing))
     Config->ShowTiming = true;
 
+  Config->ShowSummary = Args.hasArg(OPT_summary);
+
   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.
   if (Args.hasArg(OPT_dash_dash_version)) {
     outs() << getLLDVersion() << "\n";
     return;
   }

lld/trunk/COFF/Options.td

 defm threads: B<"threads",
     "Run the linker multi-threaded (default)",
     "Do not run the linker multi-threaded">;
 
 // Flags for debugging
 def lldmap : F<"lldmap">;
 def lldmap_file : Joined<["/", "-"], "lldmap:">;
 def show_timing : F<"time">;
+def summary : F<"summary">;
 
 //==============================================================================
 // The flags below do nothing. They are defined only for link.exe compatibility.
 //==============================================================================
 
 class QF<string name> : Joined<["/", "-", "-?"], name#":">;
 
 def ignoreidl : F<"ignoreidl">;

lld/trunk/COFF/PDB.cpp

TypeCollection &getIDTable() {
     if (Config->DebugGHashes)
       return GlobalIDTable;
     return IDTable;
   }
 
   /// Write the PDB to disk and store the Guid generated for it in *Guid.
   void commit(codeview::GUID *Guid);
 
+  // Print statistics regarding the final PDB
+  void printStats();
+
 private:
   BumpPtrAllocator Alloc;
 
   SymbolTable *Symtab;
 
   pdb::PDBFileBuilder Builder;
 
   /// Type records that will go into the PDB TPI stream.
private:
 
   /// Type index mappings of precompiled objects type map that we've loaded so
   /// far.
   std::map<uint32_t, CVIndexMap> PrecompTypeIndexMappings;
 
   /// List of TypeServer PDBs which cannot be loaded.
   /// Cached to prevent repeated load attempts.
   std::map<codeview::GUID, std::string> MissingTypeServerPDBs;
+
+  // For statistics
+  uint64_t GlobalSymbols = 0;
+  uint64_t ModuleSymbols = 0;
+  uint64_t PublicSymbols = 0;
 };
 
 class DebugSHandler {
   PDBLinker &Linker;
 
   /// The object file whose .debug$S sections we're processing.
   ObjFile &File;
 
cantFail(forEachCodeViewRecord<CVSymbol>(
           scopeStackOpen(Scopes, CurSymOffset, Sym);
         else if (symbolEndsScope(Sym.kind()))
           scopeStackClose(Scopes, CurSymOffset, File);
 
         // Add the symbol to the globals stream if necessary.  Do this before
         // adding the symbol to the module since we may need to get the next
         // symbol offset, and writing to the module's symbol stream will update
         // that offset.
-        if (symbolGoesInGlobalsStream(Sym, Scopes.empty()))
+        if (symbolGoesInGlobalsStream(Sym, Scopes.empty())) {
           addGlobalSymbol(Builder.getGsiBuilder(),
                           File->ModuleDBI->getModuleIndex(), CurSymOffset, Sym);
+          ++GlobalSymbols;
+        }
 
         if (symbolGoesInModuleStream(Sym, Scopes.empty())) {
           // Add symbols to the module in bulk. If this symbol is contiguous
           // with the previous run of symbols to add, combine the ranges. If
           // not, close the previous range of symbols and start a new one.
           if (Sym.data().data() == BulkSymbols.end()) {
             BulkSymbols = makeArrayRef(BulkSymbols.data(),
                                        BulkSymbols.size() + Sym.length());
           } else {
             File->ModuleDBI->addSymbolsInBulk(BulkSymbols);
             BulkSymbols = RecordBytes;
           }
           CurSymOffset += Sym.length();
+          ++ModuleSymbols;
         }
         return Error::success();
       }));
 
   // Add any remaining symbols we've accumulated.
   File->ModuleDBI->addSymbolsInBulk(BulkSymbols);
 }
 
void PDBLinker::addObjectsToPDB() {
   Symtab->forEachSymbol([&Publics](Symbol *S) {
     // Only emit defined, live symbols that have a chunk.
     auto *Def = dyn_cast<Defined>(S);
     if (Def && Def->isLive() && Def->getChunk())
       Publics.push_back(createPublic(Def));
   });
 
   if (!Publics.empty()) {
+    PublicSymbols = Publics.size();
     // Sort the public symbols and add them to the stream.
     parallelSort(Publics, [](const PublicSym32 &L, const PublicSym32 &R) {
       return L.Name < R.Name;
     });
     for (const PublicSym32 &Pub : Publics)
       GsiBuilder.addPublicSymbol(Pub);
   }
 }
 
+void PDBLinker::printStats() {
+  if (!Config->ShowSummary)
+    return;
+
+  SmallString<256> Buffer;
+  raw_svector_ostream Stream(Buffer);
+
+  Stream << center_justify("Summary", 80) << '\n'
+         << std::string(80, '-') << '\n';
+
+  auto Print = [&](uint64_t V, StringRef S) {
+    Stream << format_decimal(V, 15) << " " << S << '\n';
+  };
+
+  Print(ObjFile::Instances.size(),
+        "Input OBJ files (expanded from all cmd-line inputs)");
+  Print(TypeServerIndexMappings.size(), "PDB type server dependencies");
+  Print(PrecompTypeIndexMappings.size(), "Precomp OBJ dependencies");
+  Print(getTypeTable().size() + getIDTable().size(), "Merged TPI records");
+  Print(PDBStrTab.size(), "Output PDB strings");
+  Print(GlobalSymbols, "Global symbol records");
+  Print(ModuleSymbols, "Module symbol records");
+  Print(PublicSymbols, "Public symbol records");
+
+  message(Buffer);
+}
+
 void PDBLinker::addNatvisFiles() {
   for (StringRef File : Config->NatvisFiles) {
     ErrorOr<std::unique_ptr<MemoryBuffer>> DataOrErr =
         MemoryBuffer::getFile(File);
     if (!DataOrErr) {
       warn("Cannot open input file: " + File);
       continue;
     }
void coff::createPDB(SymbolTable *Symtab,
   PDB.addObjectsToPDB();
   PDB.addSections(OutputSections, SectionTable);
   PDB.addNatvisFiles();
 
   ScopedTimer T2(DiskCommitTimer);
   codeview::GUID Guid;
   PDB.commit(&Guid);
   memcpy(&BuildId->PDB70.Signature, &Guid, 16);
+
+  T2.stop();
+  T1.stop();
+  PDB.printStats();
 }
 
 void PDBLinker::initialize(llvm::codeview::DebugInfo *BuildId) {
   ExitOnErr(Builder.initialize(4096)); // 4096 is blocksize
 
   BuildId->Signature.CVSignature = OMF::Signature::PDB70;
   // Signature is set to a hash of the PDB contents when the PDB is done.
   memset(BuildId->PDB70.Signature, 0, 16);

lld/trunk/test/COFF/pdb-type-server-simple.test

 $ cl -c a.c b.c -Zi -Fdts.pdb
 
 $ lld-link a.obj b.obj -debug -entry:main -nodefaultlib -out:t.exe
 
 RUN: rm -rf %t && mkdir -p %t && cd %t
 RUN: yaml2obj %S/Inputs/pdb-type-server-simple-a.yaml -o a.obj
 RUN: yaml2obj %S/Inputs/pdb-type-server-simple-b.yaml -o b.obj
 RUN: llvm-pdbutil yaml2pdb %S/Inputs/pdb-type-server-simple-ts.yaml -pdb ts.pdb
-RUN: lld-link a.obj b.obj -entry:main -debug -out:t.exe -pdb:t.pdb -nodefaultlib
+RUN: lld-link a.obj b.obj -entry:main -debug -out:t.exe -pdb:t.pdb -nodefaultlib /summary | FileCheck %s -check-prefix SUMMARY
 RUN: llvm-pdbutil dump -symbols -types -ids -globals %t/t.pdb | FileCheck %s
 
 
 CHECK-LABEL: Types (TPI Stream)
 CHECK: ============================================================
 
 CHECK:   [[FOO_DECL:[^ ]*]] | LF_STRUCTURE [size = 36] `Foo`
 

 CHECK:            size = 0, padding size = 0, offset to padding = 0
 CHECK:            bytes of callee saved registers = 0, exception handler addr = 0000:0000
 CHECK:            flags = has async eh | opt speed
 CHECK:      180 | S_REGREL32 [size = 16] `p`
 CHECK:            type = [[FOO_PTR]] (Foo*), register = RSP, offset = 8
 CHECK:      196 | S_END [size = 4]
 CHECK:      200 | S_BUILDINFO [size = 8] BuildId = `[[B_BUILD]]`
 CHECK-LABEL:   Mod 0002 | `* Linker *`:
+
+SUMMARY:                                     Summary
+SUMMARY-NEXT: --------------------------------------------------------------------------------
+SUMMARY-NEXT:               2 Input OBJ files (expanded from all cmd-line inputs)
+SUMMARY-NEXT:               1 PDB type server dependencies
+SUMMARY-NEXT:               0 Precomp OBJ dependencies
+SUMMARY-NEXT:              25 Merged TPI records
+SUMMARY-NEXT:               3 Output PDB strings
+SUMMARY-NEXT:               4 Global symbol records
+SUMMARY-NEXT:              14 Module symbol records
+SUMMARY-NEXT:               2 Public symbol records
 No newline at end of file

lld/trunk/test/COFF/precomp-link.test

-RUN: lld-link %S/Inputs/precomp-a.obj %S/Inputs/precomp-b.obj %S/Inputs/precomp.obj /nodefaultlib /entry:main /debug /pdb:%t.pdb /out:%t.exe /opt:ref /opt:icf
+RUN: lld-link %S/Inputs/precomp-a.obj %S/Inputs/precomp-b.obj %S/Inputs/precomp.obj /nodefaultlib /entry:main /debug /pdb:%t.pdb /out:%t.exe /opt:ref /opt:icf /summary | FileCheck %s -check-prefix SUMMARY
 RUN: llvm-pdbutil dump -types %t.pdb | FileCheck %s
 
 RUN: lld-link %S/Inputs/precomp.obj %S/Inputs/precomp-a.obj %S/Inputs/precomp-b.obj /nodefaultlib /entry:main /debug /pdb:%t.pdb /out:%t.exe /opt:ref /opt:icf
 RUN: llvm-pdbutil dump -types %t.pdb | FileCheck %s
 
 RUN: lld-link %S/Inputs/precomp-a.obj %S/Inputs/precomp-invalid.obj %S/Inputs/precomp.obj /nodefaultlib /entry:main /debug /pdb:%t.pdb /out:%t.exe /opt:ref /opt:icf 2>&1 | FileCheck %s -check-prefix FAILURE
 
 RUN: not lld-link %S/Inputs/precomp-a.obj %S/Inputs/precomp-b.obj /nodefaultlib /entry:main /debug /pdb:%t.pdb /out:%t.exe /opt:ref /opt:icf 2>&1 | FileCheck %s -check-prefix FAILURE-MISSING-PRECOMPOBJ
 
 FAILURE: warning: Cannot use debug info for 'precomp-invalid.obj' [LNK4099]
 FAILURE-NEXT: failed to load reference '{{.*}}precomp.obj': The signature does not match; the file(s) might be out of date.
 
 FAILURE-MISSING-PRECOMPOBJ: warning: Cannot use debug info for 'precomp-a.obj' [LNK4099]
 FAILURE-MISSING-PRECOMPOBJ-NEXT: failed to load reference '{{.*}}precomp.obj': The path to this file must be provided on the command-line
 
 CHECK: Types (TPI Stream)
 CHECK-NOT: LF_PRECOMP
 CHECK-NOT: LF_ENDPRECOMP
 
+
+SUMMARY:                                     Summary
+SUMMARY-NEXT: --------------------------------------------------------------------------------
+SUMMARY-NEXT:               3 Input OBJ files (expanded from all cmd-line inputs)
+SUMMARY-NEXT:               0 PDB type server dependencies
+SUMMARY-NEXT:               1 Precomp OBJ dependencies
+SUMMARY-NEXT:            1044 Merged TPI records
+SUMMARY-NEXT:               5 Output PDB strings
+SUMMARY-NEXT:             167 Global symbol records
+SUMMARY-NEXT:              20 Module symbol records
+SUMMARY-NEXT:               3 Public symbol records
+
 // precomp.h
 #pragma once
 int Function(char A);
 
 // precomp.cpp
 #include "precomp.h"
 
 // a.cpp