[dsymutil] Print statistics about debug_info reduction in verbose mode.

[JDevlieghere]

Summary

This patch adds statistics about the the contribution of each object file to the linked debug info to verbose mode. After linking it prints a table as illustrated below with the object file, the old debug info size, the new debug info size and the percentage difference. The table is sorted by the output size, so the object files contributing the most to the link are listed first.

-------------------------------------------------------------------------------
Object File                                    Bytes Input -> Output     Change
-------------------------------------------------------------------------------
basic2.macho.x86_64.o                                  210 -> 165        24.00%
basic3.macho.x86_64.o                                  177 -> 150        16.51%
basic1.macho.x86_64.o                                  125 -> 129        3.15%
-------------------------------------------------------------------------------
Total                                                  512 -> 444        14.23%
-------------------------------------------------------------------------------

[friss]

LGTM, with one potential suggestion:

llvm/lib/DWARFLinker/DWARFLinker.cpp

2533

Should we be using a different --stat flag for this? The verbose flag will output so much info on a real link...

[JDevlieghere]

llvm/lib/DWARFLinker/DWARFLinker.cpp

2533

Not to mention that verbose mode implies single threaded, which is the reason I put it under verbose. If we want to use --stats we'll need a way to synchronize the printing across architectures for fat binaries. Do you think that's worth it?

[friss]

llvm/lib/DWARFLinker/DWARFLinker.cpp

2533

Do we need to synchronize? Maybe we should just print the current architecture at the beginning of the line to disambiguate?

[JDevlieghere]

llvm/lib/DWARFLinker/DWARFLinker.cpp

2533

We do, the output is all intertwined otherwise. I actually implemented the --stats thing you suggested before moving it under verbose for exactly this reason.

[JDevlieghere]

Make statistics a new option.

[JDevlieghere]

Fix aligment

[avl]

Probably, it makes sense to not put printing code into DWARFLinker? i.e. add callbacks to DwarfFile:

class DwarfFile {
...

std::function <(StringRef FileName, StringRef TableName, uint64_t TableFinalSize)> StatisticsCallback;

};

or to add callback to DWARFlinker:

/// Report statistics.
void setStatisticCallback ( std::function <(StringRef FileName, StringRef TableName, uint64_t TableFinalSize)> StatisticsCallback );

So, that DWARFlinker reports statistics, but analyzing and displaying would be done separately.
In this case in dsymutil`s DwarfLinkerForBinary.cpp. What do you think?

[aprantl]

llvm/docs/CommandGuide/dsymutil.rst

102

typo: object

Does this count .debug_info only, or also the other sections?

How does type uniquing factor into this? Are we counting the input or the actual contribution?

llvm/include/llvm/DWARFLinker/DWARFLinker.h

561

Can you please document the return value?

llvm/lib/DWARFLinker/DWARFLinker.cpp

42

of the debug_info *section*?

2543

using a float to store the result of an operation on 64-bit integers sounds risky to me. Should we at least use a double?

2545

I'd feel more comfortable if we replaced this with
if (Input == 0 && Output == 0) or with if (Sum < epsilon) or something that doesn't rely on floating point landing on exact zero

[aprantl]

basic3.macho.x86_64.o                                  177 -> 150        16.51%
basic1.macho.x86_64.o                                  125 -> 129        3.15%

Could we right-align the numbers?

llvm/docs/CommandGuide/dsymutil.rst

 .. option:: --oso-prepend-path=<path>
 
  Specifies a ``path`` to prepend to all debug symbol object file paths.
 
 .. option:: -o <filename>, --out <filename>
 
  Specifies an alternate ``path`` to place the dSYM bundle. The default dSYM
  bundle path is created by appending ``.dSYM`` to the executable name.
- 
 .. option:: --papertrail
 
  When running dsymutil as part of your build system, it can be desirable for
  warnings to be part of the end product, rather than just being emitted to the
  output stream. When enabled warnings are embedded in the linked DWARF debug
  information.
 
 .. option:: --remarks-output-format <format>
 
  Specify the format to be used when serializing the linked remarks.
 
 .. option:: --remarks-prepend-path <path>
 
  Specify a directory to prepend the paths of the external remark files.
 
+.. option:: --statistics
+
+ Print statistics about the contribution of each object file to the linked
+ debug info. This prints a table after linking with the object file name, the
+ size of the debug info in the object file (in bytes) and the size contributed
+ (in bytes) to the linked dSYM. The table is sorted by the output size listing
+ the obj ect files with the largest contribution first.
+
 .. option:: --symbol-map <bcsymbolmap>
 
  Update the existing dSYMs inplace using symbol map specified.
 
 .. option:: -s, --symtab
 
  Dumps the symbol table found in *executable* or object file(s) and exits.
 

llvm/include/llvm/DWARFLinker/DWARFLinker.h

public:
   /// files are linked all together.
   bool link();
 
   /// A number of methods setting various linking options:
 
   /// Allows to generate log of linking process to the standard output.
   void setVerbosity(bool Verbose) { Options.Verbose = Verbose; }
 
+  /// Print statistics to standard output.
+  void setStatistics(bool Statistics) { Options.Statistics = Statistics; }
+
   /// Do not emit linked dwarf info.
   void setNoOutput(bool NoOut) { Options.NoOutput = NoOut; }
 
   /// Do not unique types according to ODR.
   void setNoODR(bool NoODR) { Options.NoODR = NoODR; }
 
   /// update existing DWARF info(for the linked binary).
   void setUpdate(bool Update) { Options.Update = Update; }
public:
     /// \returns the root of the cloned tree or null if nothing was selected.
     DIE *cloneDIE(const DWARFDie &InputDIE, const DwarfFile &File,
                   CompileUnit &U, OffsetsStringPool &StringPool,
                   int64_t PCOffset, uint32_t OutOffset, unsigned Flags,
                   bool IsLittleEndian, DIE *Die = nullptr);
 
     /// Construct the output DIE tree by cloning the DIEs we
     /// chose to keep above. If there are no valid relocs, then there's
     /// nothing to clone/emit.
-    void cloneAllCompileUnits(DWARFContext &DwarfContext, const DwarfFile &File,
+    uint64_t cloneAllCompileUnits(DWARFContext &DwarfContext,
+                                  const DwarfFile &File,
                                   OffsetsStringPool &StringPool,
                                   bool IsLittleEndian);
 
   private:
     using AttributeSpec = DWARFAbbreviationDeclaration::AttributeSpec;
 
     /// Information gathered and exchanged between the various
     /// clone*Attributes helpers about the attributes of a particular DIE.
     struct AttributesInfo {
       /// Names.
private:
 
   std::function<StringRef(StringRef)> StringsTranslator = nullptr;
 
   /// linking options
   struct DWARFLinkerOptions {
     /// Generate processing log to the standard output.
     bool Verbose = false;
 
+    /// Print statistics.
+    bool Statistics = false;
+
     /// Skip emitting output
     bool NoOutput = false;
 
     /// Do not unique types according to ODR
     bool NoODR = false;
 
     /// Update
     bool Update = false;

llvm/lib/DWARFLinker/DWARFLinker.cpp

 #include "llvm/DebugInfo/DWARF/DWARFDie.h"
 #include "llvm/DebugInfo/DWARF/DWARFFormValue.h"
 #include "llvm/DebugInfo/DWARF/DWARFSection.h"
 #include "llvm/DebugInfo/DWARF/DWARFUnit.h"
 #include "llvm/Support/DataExtractor.h"
 #include "llvm/Support/Error.h"
 #include "llvm/Support/ErrorHandling.h"
 #include "llvm/Support/ErrorOr.h"
+#include "llvm/Support/FormatVariadic.h"
 #include "llvm/Support/LEB128.h"
 #include "llvm/Support/Path.h"
 #include "llvm/Support/ThreadPool.h"
 #include <vector>
 
 namespace llvm {
 
+/// Hold the input and output of the debug info size in bytes.
+struct DebugInfoSize {
+  uint64_t Input;
+  uint64_t Output;
+};
+
+/// Compute the total size of the debug info.
+static uint64_t getDebugInfoSize(DWARFContext &Dwarf) {
+  uint64_t Size = 0;
+  for (auto &Unit : Dwarf.compile_units()) {
+    Size += Unit->getLength();
+  }
+  return Size;
+}
+
 /// Similar to DWARFUnitSection::getUnitForOffset(), but returning our
 /// CompileUnit object instead.
 static CompileUnit *getUnitForOffset(const UnitListTy &Units, uint64_t Offset) {
   auto CU = std::upper_bound(
       Units.begin(), Units.end(), Offset,
       [](uint64_t LHS, const std::unique_ptr<CompileUnit> &RHS) {
         return LHS < RHS->getOrigUnit().getNextUnitOffset();
       });
Error DWARFLinker::loadClangModule(
   assert(TheDwarfEmitter);
   DIECloner(*this, TheDwarfEmitter, *ErrOrObj, DIEAlloc, CompileUnits,
             Options.Update)
       .cloneAllCompileUnits(*(ErrOrObj->Dwarf), File, StringPool,
                             IsLittleEndian);
   return Error::success();
 }
 
-void DWARFLinker::DIECloner::cloneAllCompileUnits(DWARFContext &DwarfContext,
-                                                  const DwarfFile &File,
-                                                  OffsetsStringPool &StringPool,
-                                                  bool IsLittleEndian) {
+uint64_t DWARFLinker::DIECloner::cloneAllCompileUnits(
+    DWARFContext &DwarfContext, const DwarfFile &File,
+    OffsetsStringPool &StringPool, bool IsLittleEndian) {
   uint64_t OutputDebugInfoSize =
       Linker.Options.NoOutput ? 0 : Emitter->getDebugInfoSectionSize();
+  const uint64_t StartOutputDebugInfoSize = OutputDebugInfoSize;
+
   for (auto &CurrentUnit : CompileUnits) {
     auto InputDIE = CurrentUnit->getOrigUnit().getUnitDIE();
     CurrentUnit->setStartOffset(OutputDebugInfoSize);
     if (!InputDIE) {
       OutputDebugInfoSize = CurrentUnit->computeNextUnitOffset();
       continue;
     }
     if (CurrentUnit->getInfo(0).Keep) {
for (auto &CurrentUnit : CompileUnits) {
       assert(Emitter->getDebugInfoSectionSize() ==
              CurrentUnit->getStartOffset());
       Emitter->emitCompileUnitHeader(*CurrentUnit);
       Emitter->emitDIE(*CurrentUnit->getOutputUnitDIE());
       assert(Emitter->getDebugInfoSectionSize() ==
              CurrentUnit->computeNextUnitOffset());
     }
   }
+
+  return OutputDebugInfoSize - StartOutputDebugInfoSize;
 }
 
 void DWARFLinker::updateAccelKind(DWARFContext &Dwarf) {
   if (Options.TheAccelTableKind != AccelTableKind::Default)
     return;
 
   auto &DwarfObj = Dwarf.getDWARFObj();
 
for (auto &CurrentUnit : Context.CompileUnits) {
                          UniquingStringPool, ODRContexts, ModulesEndOffset,
                          Options.ParseableSwiftInterfaces,
                          [&](const Twine &Warning, const DWARFDie &DIE) {
                            reportWarning(Warning, Context.File, &DIE);
                          });
     }
   };
 
+  // For each object file map how many bytes were emitted.
+  StringMap<DebugInfoSize> SizeByObject;
+
   // And then the remaining work in serial again.
   // Note, although this loop runs in serial, it can run in parallel with
   // the analyzeContextInfo loop so long as we process files with indices >=
   // than those processed by analyzeContextInfo.
   auto CloneLambda = [&](size_t I) {
     auto &OptContext = ObjectContexts[I];
     if (OptContext.Skip || !OptContext.File.Dwarf)
       return;
if (LLVM_UNLIKELY(Options.Update)) {
                           OptContext.File, *CurrentUnit, 0);
     }
 
     // The calls to applyValidRelocs inside cloneDIE will walk the reloc
     // array again (in the same way findValidRelocsInDebugInfo() did). We
     // need to reset the NextValidReloc index to the beginning.
     if (OptContext.File.Addresses->hasValidRelocs() ||
         LLVM_UNLIKELY(Options.Update)) {
+      SizeByObject[OptContext.File.FileName].Input =
+          getDebugInfoSize(*OptContext.File.Dwarf);
+      SizeByObject[OptContext.File.FileName].Output =
           DIECloner(*this, TheDwarfEmitter, OptContext.File, DIEAlloc,
                     OptContext.CompileUnits, Options.Update)
               .cloneAllCompileUnits(*OptContext.File.Dwarf, OptContext.File,
                                     OffsetsStringPool,
                                     OptContext.File.Dwarf->isLittleEndian());
     }
     if (!Options.NoOutput && !OptContext.CompileUnits.empty() &&
         LLVM_LIKELY(!Options.Update))
       patchFrameInfoForObject(
           OptContext.File, OptContext.File.Addresses->getValidAddressRanges(),
           *OptContext.File.Dwarf,
           OptContext.CompileUnits[0]->getOrigUnit().getAddressByteSize());
 
if (Options.Threads == 1) {
     EmitLambda();
   } else {
     ThreadPool Pool(hardware_concurrency(2));
     Pool.async(AnalyzeAll);
     Pool.async(CloneAll);
     Pool.wait();
   }
 
+  if (Options.Statistics) {
+    // Create a vector sorted in descending order by output size.
+    std::vector<std::pair<StringRef, DebugInfoSize>> Sorted;
+    for (auto &E : SizeByObject)
+      Sorted.emplace_back(E.first(), E.second);
+    sort(Sorted.begin(), Sorted.end(), [](auto &LHS, auto &RHS) {
+      return LHS.second.Output > RHS.second.Output;
+    });
+
+    auto ComputePercentange = [](int64_t Input, int64_t Output) -> float {
+      const float Difference = Output - Input;
+      const float Sum = Input + Output;
+      if (Sum == 0)
+        return 0;
+      return (Difference / (Sum / 2));
+    };
+
+    int64_t InputTotal = 0;
+    int64_t OutputTotal = 0;
+    const char *FormatStr = "{0,-45} {1,10}b  {2,10}b {3,8:P}\n";
+
+    // Print header.
+    outs() << ".debug_info section size (in bytes)\n";
+    outs() << "----------------------------------------------------------------"
+              "---------------\n";
+    outs() << "Filename                                           Object       "
+              "  dSYM   Change\n";
+    outs() << "----------------------------------------------------------------"
+              "---------------\n";
+
+    // Print body.
+    for (auto &E : Sorted) {
+      InputTotal += E.second.Input;
+      OutputTotal += E.second.Output;
+      llvm::outs() << formatv(
+          FormatStr, sys::path::filename(E.first).take_back(45), E.second.Input,
+          E.second.Output, ComputePercentange(E.second.Input, E.second.Output));
+    }
+    // Print total and footer.
+    outs() << "----------------------------------------------------------------"
+              "---------------\n";
+    llvm::outs() << formatv(FormatStr, "Total", InputTotal, OutputTotal,
+                            ComputePercentange(InputTotal, OutputTotal));
+    outs() << "----------------------------------------------------------------"
+              "---------------\n\n";
+  }
+
   return true;
 }
 
 } // namespace llvm

llvm/test/tools/dsymutil/X86/statistics.test

+# RUN: dsymutil -statistics -oso-prepend-path=%p/.. %p/../Inputs/basic.macho.x86_64 %p/../Inputs/basic-archive.macho.x86_64 %p/../Inputs/basic-lto.macho.x86_64 %p/../Inputs/basic-lto-dw4.macho.x86_64 -o %t 2>&1 | FileCheck %s
+#
+# CHECK: -------------------------------------------------------------------------------
+# CHECK-NEXT: Filename                                           Object         dSYM   Change
+# CHECK-NEXT: -------------------------------------------------------------------------------
+# CHECK-DAG: basic2.macho.x86_64.o {{[0-9]+}}b {{[0-9]+}}b{{.*}}{{[0-9]+}}.{{[0-9]+}}%
+# CHECK-DAG: basic3.macho.x86_64.o {{[0-9]+}}b {{[0-9]+}}b{{.*}}{{[0-9]+}}.{{[0-9]+}}%
+# CHECK-DAG: basic1.macho.x86_64.o {{[0-9]+}}b {{[0-9]+}}b{{.*}}{{[0-9]+}}.{{[0-9]+}}%
+# CHECK: -------------------------------------------------------------------------------
+# CHECK-NEXT: Total                {{[0-9]+}}b {{[0-9]+}}b{{.*}}{{[0-9]+}}.{{[0-9]+}}%
+# CHECK-NEXT: -------------------------------------------------------------------------------
+
+---
+triple:          'x86_64-apple-darwin'
+objects:
+  - filename:        invalid.o
+    timestamp:       1518197670
+    symbols:
+      - { sym: _main, objAddr: 0x0000000000000010, binAddr: 0x0000000100000FB0, size: 0x00000008 }
+      - { sym: _g, objAddr: 0x0000000000000000, binAddr: 0x0000000100000FA0, size: 0x00000010 }
+...

llvm/test/tools/dsymutil/cmdline.test

 HELP: -no-swiftmodule-timestamp
 HELP: -num-threads <threads>
 HELP: -object-prefix-map <prefix=remapped>
 HELP: -oso-prepend-path <path>
 HELP: {{ -o <filename> }}
 HELP: -papertrail
 HELP: -remarks-output-format <format>
 HELP: -remarks-prepend-path <path>
+HELP: -statistics
 HELP: -symbol-map
 HELP: -symtab
 HELP: {{ -S }}
 HELP: -toolchain
 HELP: -update
 HELP: -verbose
 HELP: -verify
 HELP: {{ -y }}

llvm/tools/dsymutil/DwarfLinkerForBinary.cpp

bool DwarfLinkerForBinary::link(const DebugMap &Map) {
   GeneralLinker.setObjectPrefixMap(&Options.ObjectPrefixMap);
 
   std::function<StringRef(StringRef)> TranslationLambda = [&](StringRef Input) {
     assert(Options.Translator);
     return Options.Translator(Input);
   };
 
   GeneralLinker.setVerbosity(Options.Verbose);
+  GeneralLinker.setStatistics(Options.Statistics);
   GeneralLinker.setNoOutput(Options.NoOutput);
   GeneralLinker.setNoODR(Options.NoODR);
   GeneralLinker.setUpdate(Options.Update);
   GeneralLinker.setNumThreads(Options.Threads);
   GeneralLinker.setAccelTableKind(Options.TheAccelTableKind);
   GeneralLinker.setPrependPath(Options.PrependPath);
   if (Options.Translator)
     GeneralLinker.setStringsTranslator(TranslationLambda);

llvm/tools/dsymutil/LinkUtils.h

 
 namespace llvm {
 namespace dsymutil {
 
 struct LinkOptions {
   /// Verbosity
   bool Verbose = false;
 
+  /// Statistics
+  bool Statistics = false;
+
   /// Skip emitting output
   bool NoOutput = false;
 
   /// Do not unique types according to ODR
   bool NoODR = false;
 
   /// Update
   bool Update = false;

llvm/tools/dsymutil/Options.td

def: Flag<["-"], "v">,
   Alias<version>,
   HelpText<"Alias for --version">,
   Group<grp_general>;
 
 def verbose: F<"verbose">,
   HelpText<"Enable verbose mode.">,
   Group<grp_general>;
 
+def statistics: F<"statistics">,
+  HelpText<"Print statistics about the contribution of each object file to "
+           "the linked debug info. This prints a table after linking with the "
+           "object file name, the size of the debug info in the object file "
+           "(in bytes) and the size contributed (in bytes) to the linked dSYM. "
+           "The table is sorted by the output size listing the object files "
+           "with the largest contribution first.">,
+  Group<grp_general>;
+
 def verify: F<"verify">,
   HelpText<"Run the DWARF verifier on the linked DWARF debug info.">,
   Group<grp_general>;
 
 def no_output: F<"no-output">,
   HelpText<"Do the link in memory, but do not emit the result file.">,
   Group<grp_general>;
 

llvm/tools/dsymutil/dsymutil.cpp

static Expected<DsymutilOptions> getOptions(opt::InputArgList &Args) {
   Options.Verify = Args.hasArg(OPT_verify);
 
   Options.LinkOpts.Minimize = Args.hasArg(OPT_minimize);
   Options.LinkOpts.NoODR = Args.hasArg(OPT_no_odr);
   Options.LinkOpts.NoOutput = Args.hasArg(OPT_no_output);
   Options.LinkOpts.NoTimestamp = Args.hasArg(OPT_no_swiftmodule_timestamp);
   Options.LinkOpts.Update = Args.hasArg(OPT_update);
   Options.LinkOpts.Verbose = Args.hasArg(OPT_verbose);
+  Options.LinkOpts.Statistics = Args.hasArg(OPT_statistics);
 
   if (Expected<AccelTableKind> AccelKind = getAccelTableKind(Args)) {
     Options.LinkOpts.TheAccelTableKind = *AccelKind;
   } else {
     return AccelKind.takeError();
   }
 
   if (opt::Arg *SymbolMap = Args.getLastArg(OPT_symbolmap))
for (auto &InputFile : Options.InputFiles) {
     if (DebugMapPtrsOrErr->empty()) {
       WithColor::error() << "no architecture to link\n";
       return 1;
     }
 
     // Shared a single binary holder for all the link steps.
     BinaryHolder BinHolder(Options.LinkOpts.VFS);
 
-    ThreadPoolStrategy S = hardware_concurrency(Options.LinkOpts.Threads);
+    // Statistics only require different architectures to be processed
+    // sequentially, the link itself can still happen in parallel. Change the
+    // thread pool strategy here instead of modifying LinkOpts.Threads.
+    ThreadPoolStrategy S = hardware_concurrency(
+        Options.LinkOpts.Statistics ? 1 : Options.LinkOpts.Threads);
     if (Options.LinkOpts.Threads == 0) {
       // If NumThreads is not specified, create one thread for each input, up to
       // the number of hardware threads.
       S.ThreadsRequested = DebugMapPtrsOrErr->size();
       S.Limit = true;
     }
     ThreadPool Threads(S);