[lld-macho] Add more TimeTraceScopes

[int3]

Summary

I added just enough to allow us to see a top-level breakdown of time taken. This
is the result of loading the time-trace output into chrome:://tracing:

https://gist.githubusercontent.com/int3/236c723cbb4b6fa3b2d340bb6395c797/raw/ef5e8234f3fdf609bf93b50f54f4e0d9bd439403/tracing.png

[int3]

lld/MachO/Driver.cpp

1069–1080

It's kind of silly that this takes a non-trivial amount of time. Perhaps that's where a chunk of the speedup in D98837 is coming from. Maybe once that lands we can remove this TimeTraceScope block.

cc @alexshap

[oontvoo]

lld/MachO/Driver.cpp

994–995

Do you want to move these two into the createFiles() too?

lld/MachO/Writer.cpp

946–947

Could this be moved to cover the whole function? I see the finalize*() functions have their own time-sccopes. Similarly, the write*() have theirs too.
So it doesn't seem consistent to have this "over-all" scope cover only half of this function 🤔

[int3]

address comments

[oontvoo]

The detailed graph looks nice! Thanks!

lld/MachO/Config.h

struct Configuration {
   bool searchDylibsFirst = false;
   bool saveTemps = false;
   bool adhocCodesign = false;
   bool emitFunctionStarts = false;
   bool timeTraceEnabled = false;
   uint32_t headerPad;
   uint32_t dylibCompatibilityVersion = 0;
   uint32_t dylibCurrentVersion = 0;
-  uint32_t timeTraceGranularity;
+  uint32_t timeTraceGranularity = 0;
   std::string progName;
   llvm::StringRef installName;
   llvm::StringRef mapFile;
   llvm::StringRef outputFile;
   llvm::StringRef ltoObjPath;
   bool demangle = false;
   llvm::MachO::Target target;
   PlatformInfo platformInfo;

lld/MachO/Driver.cpp

 static void initLLVM() {
   InitializeAllTargets();
   InitializeAllTargetMCs();
   InitializeAllAsmPrinters();
   InitializeAllAsmParsers();
 }
 
 static void compileBitcodeFiles() {
+  TimeTraceScope timeScope("LTO");
   auto *lto = make<BitcodeCompiler>();
   for (InputFile *file : inputFiles)
     if (auto *bitcodeFile = dyn_cast<BitcodeFile>(file))
       lto->add(*bitcodeFile);
 
   for (ObjFile *file : lto->compile())
     inputFiles.insert(file);
 }
 
 // Replaces common symbols with defined symbols residing in __common sections.
 // This function must be called after all symbol names are resolved (i.e. after
 // all InputFiles have been loaded.) As a result, later operations won't see
 // any CommonSymbols.
 static void replaceCommonSymbols() {
+  TimeTraceScope timeScope("Replace common symbols");
   for (macho::Symbol *sym : symtab->getSymbols()) {
     auto *common = dyn_cast<CommonSymbol>(sym);
     if (common == nullptr)
       continue;
 
     auto *isec = make<InputSection>();
     isec->file = common->getFile();
     isec->name = section_names::common;
for (const Arg *arg : args.filtered(listFileOptionCode)) {
     for (StringRef line : args::getLines(mbref)) {
       line = line.take_until([](char c) { return c == '#'; }).trim();
       if (!line.empty())
         symbolPatterns.insert(line);
     }
   }
 }
 
+void createFiles(const InputArgList &args) {
+  TimeTraceScope timeScope("Load input files");
+  // This loop should be reserved for options whose exact ordering matters.
+  // Other options should be handled via filtered() and/or getLastArg().
+  for (const Arg *arg : args) {
+    const Option &opt = arg->getOption();
+    switch (opt.getID()) {
+    case OPT_INPUT:
+      addFile(arg->getValue(), false);
+      break;
+    case OPT_weak_library:
+      if (auto *dylibFile =
+              dyn_cast_or_null<DylibFile>(addFile(arg->getValue(), false)))
+        dylibFile->forceWeakImport = true;
+      break;
+    case OPT_filelist:
+      addFileList(arg->getValue());
+      break;
+    case OPT_force_load:
+      addFile(arg->getValue(), true);
+      break;
+    case OPT_l:
+    case OPT_weak_l:
+      addLibrary(arg->getValue(), opt.getID() == OPT_weak_l);
+      break;
+    case OPT_framework:
+    case OPT_weak_framework:
+      addFramework(arg->getValue(), opt.getID() == OPT_weak_framework);
+      break;
+    default:
+      break;
+    }
+  }
+}
+
 bool macho::link(ArrayRef<const char *> argsArr, bool canExitEarly,
                  raw_ostream &stdoutOS, raw_ostream &stderrOS) {
   lld::stdoutOS = &stdoutOS;
   lld::stderrOS = &stderrOS;
 
   errorHandler().cleanupCallback = []() { freeArena(); };
 
   errorHandler().logName = args::getFilenameWithoutExe(argsArr[0]);
bool macho::link(ArrayRef<const char *> argsArr, bool canExitEarly,
 
   config->timeTraceEnabled = args.hasArg(OPT_time_trace);
 
   // Initialize time trace profiler.
   if (config->timeTraceEnabled)
     timeTraceProfilerInitialize(config->timeTraceGranularity, config->progName);
 
   {
-    llvm::TimeTraceScope timeScope("Link", StringRef("ExecuteLinker"));
+    TimeTraceScope timeScope("Link", StringRef("ExecuteLinker"));
 
     initLLVM(); // must be run before any call to addFile()
 
-    // This loop should be reserved for options whose exact ordering matters.
-    // Other options should be handled via filtered() and/or getLastArg().
     for (const Arg *arg : args) {
       const Option &opt = arg->getOption();
       warnIfDeprecatedOption(opt);
       warnIfUnimplementedOption(opt);
-
-      switch (opt.getID()) {
-      case OPT_INPUT:
-        addFile(arg->getValue(), false);
-        break;
-      case OPT_weak_library:
-        if (auto *dylibFile =
-                dyn_cast_or_null<DylibFile>(addFile(arg->getValue(), false)))
-          dylibFile->forceWeakImport = true;
-        break;
-      case OPT_filelist:
-        addFileList(arg->getValue());
-        break;
-      case OPT_force_load:
-        addFile(arg->getValue(), true);
-        break;
-      case OPT_l:
-      case OPT_weak_l:
-        addLibrary(arg->getValue(), opt.getID() == OPT_weak_l);
-        break;
-      case OPT_framework:
-      case OPT_weak_framework:
-        addFramework(arg->getValue(), opt.getID() == OPT_weak_framework);
-        break;
-      default:
-        break;
-      }
     }
 
+    createFiles(args);
+
     config->isPic = config->outputType == MH_DYLIB ||
                     config->outputType == MH_BUNDLE || isPie(args);
 
     // Now that all dylibs have been loaded, search for those that should be
     // re-exported.
     for (const Arg *arg : args.filtered(OPT_sub_library, OPT_sub_umbrella)) {
       config->hasReexports = true;
       StringRef searchName = arg->getValue();
for (const Arg *arg : args.filtered(OPT_sectcreate)) {
       StringRef segName = arg->getValue(0);
       StringRef sectName = arg->getValue(1);
       StringRef fileName = arg->getValue(2);
       Optional<MemoryBufferRef> buffer = readFile(fileName);
       if (buffer)
         inputFiles.insert(make<OpaqueFile>(*buffer, segName, sectName));
     }
 
-    // Initialize InputSections.
+    {
+      TimeTraceScope timeScope("Gathering input sections");
+      // Gather all InputSections into one vector.
       for (const InputFile *file : inputFiles) {
         for (const SubsectionMap &map : file->subsections) {
           for (const auto &p : map) {
             InputSection *isec = p.second;
             inputSections.push_back(isec);
           }
         }
       }
+    }
 
     // Write to an output file.
     writeResult();
   }
 
   if (config->timeTraceEnabled) {
     if (auto E = timeTraceProfilerWrite(
             args.getLastArgValue(OPT_time_trace_file_eq).str(),

lld/MachO/MapFile.cpp

 #include "Config.h"
 #include "InputFiles.h"
 #include "InputSection.h"
 #include "OutputSection.h"
 #include "OutputSegment.h"
 #include "Symbols.h"
 #include "Target.h"
 #include "llvm/Support/Parallel.h"
+#include "llvm/Support/TimeProfiler.h"
 
 using namespace llvm;
 using namespace llvm::sys;
 using namespace lld;
 using namespace lld::macho;
 
 using SymbolMapTy = DenseMap<const InputSection *, SmallVector<Defined *, 4>>;
 
for (size_t i = 0, e = syms.size(); i < e; ++i)
     ret[syms[i]] = std::move(str[i]);
   return ret;
 }
 
 void macho::writeMapFile() {
   if (config->mapFile.empty())
     return;
 
+  TimeTraceScope timeScope("Write map file");
+
   // Open a map file for writing.
   std::error_code ec;
   raw_fd_ostream os(config->mapFile, ec, sys::fs::OF_None);
   if (ec) {
     error("cannot open " + config->mapFile + ": " + ec.message());
     return;
   }
 

lld/MachO/Writer.cpp

 
 #include "lld/Common/ErrorHandler.h"
 #include "lld/Common/Memory.h"
 #include "llvm/BinaryFormat/MachO.h"
 #include "llvm/Config/llvm-config.h"
 #include "llvm/Support/LEB128.h"
 #include "llvm/Support/MathExtras.h"
 #include "llvm/Support/Path.h"
+#include "llvm/Support/TimeProfiler.h"
 #include "llvm/Support/xxhash.h"
 
 #include <algorithm>
 
 using namespace llvm;
 using namespace llvm::MachO;
 using namespace llvm::sys;
 using namespace lld;
if (relocAttrs.hasAttr(RelocAttrBits::BRANCH)) {
     // relative to the start of the referent section, and therefore have no
     // need of rebase opcodes.
     if (!(isThreadLocalVariables(isec->flags) && isa<Defined>(sym)))
       addNonLazyBindingEntries(sym, isec, r.offset, r.addend);
   }
 }
 
 void Writer::scanRelocations() {
+  TimeTraceScope timeScope("Scan relocations");
   for (InputSection *isec : inputSections) {
     if (isec->segname == segment_names::ld) {
       prepareCompactUnwind(isec);
       continue;
     }
 
     for (auto it = isec->relocs.begin(); it != isec->relocs.end(); ++it) {
       Reloc &r = *it;
for (auto it = isec->relocs.begin(); it != isec->relocs.end(); ++it) {
         if (!r.pcrel)
           in.rebase->addEntry(isec, r.offset);
       }
     }
   }
 }
 
 void Writer::scanSymbols() {
+  TimeTraceScope timeScope("Scan symbols");
   for (const macho::Symbol *sym : symtab->getSymbols()) {
     if (const auto *defined = dyn_cast<Defined>(sym)) {
       if (defined->overridesWeakDef)
         in.weakBinding->addNonWeakDefinition(defined);
     } else if (const auto *dysym = dyn_cast<DylibSymbol>(sym)) {
       if (dysym->isDynamicLookup())
         continue;
       dysym->getFile()->refState =

 static std::function<bool(T, T)> compareByOrder(F ord) {
   return [=](T a, T b) { return ord(a) < ord(b); };
 }
 
 // Sorting only can happen once all outputs have been collected. Here we sort
 // segments, output sections within each segment, and input sections within each
 // output segment.
 static void sortSegmentsAndSections() {
+  TimeTraceScope timeScope("Sort segments and sections");
+
   llvm::stable_sort(outputSegments,
                     compareByOrder<OutputSegment *>(segmentOrder));
 
   DenseMap<const InputSection *, size_t> isecPriorities =
       buildInputSectionPriorities();
 
   uint32_t sectionIndex = 0;
   for (OutputSegment *seg : outputSegments) {
if (newNames != config->sectionRenameMap.end())
     return newNames->second;
   auto newName = config->segmentRenameMap.find(key.first);
   if (newName != config->segmentRenameMap.end())
     return std::make_pair(newName->second, key.second);
   return key;
 }
 
 void Writer::createOutputSections() {
+  TimeTraceScope timeScope("Create output sections");
   // First, create hidden sections
   stringTableSection = make<StringTableSection>();
   unwindInfoSection = make<UnwindInfoSection>(); // TODO(gkm): only when no -r
   symtabSection = make<SymtabSection>(*stringTableSection);
   indirectSymtabSection = make<IndirectSymtabSection>();
   if (config->adhocCodesign)
     codeSignatureSection = make<CodeSignatureSection>();
   if (config->emitFunctionStarts)
for (SyntheticSection *ssec : syntheticSections) {
     }
   }
 
   // dyld requires __LINKEDIT segment to always exist (even if empty).
   linkEditSegment = getOrCreateOutputSegment(segment_names::linkEdit);
 }
 
 void Writer::finalizeAddressses() {
+  TimeTraceScope timeScope("Finalize addresses");
   // Ensure that segments (and the sections they contain) are allocated
   // addresses in ascending order, which dyld requires.
   //
   // Note that at this point, __LINKEDIT sections are empty, but we need to
   // determine addresses of other segments/sections before generating its
   // contents.
   for (OutputSegment *seg : outputSegments)
     if (seg != linkEditSegment)
       assignAddresses(seg);
 
   // FIXME(gkm): create branch-extension thunks here, then adjust addresses
 }
 
 void Writer::finalizeLinkEditSegment() {
+  TimeTraceScope timeScope("Finalize __LINKEDIT segment");
   // Fill __LINKEDIT contents.
   in.rebase->finalizeContents();
   in.binding->finalizeContents();
   in.weakBinding->finalizeContents();
   in.lazyBinding->finalizeContents();
   in.exports->finalizeContents();
   symtabSection->finalizeContents();
   indirectSymtabSection->finalizeContents();

 void Writer::writeSections() {
   uint8_t *buf = buffer->getBufferStart();
   for (const OutputSegment *seg : outputSegments)
     for (const OutputSection *osec : seg->getSections())
       osec->writeTo(buf + osec->fileOff);
 }
 
 void Writer::writeUuid() {
+  TimeTraceScope timeScope("Computing UUID");
   uint64_t digest =
       xxHash64({buffer->getBufferStart(), buffer->getBufferEnd()});
   uuidCommand->writeUuid(digest);
 }
 
 void Writer::writeCodeSignature() {
   if (codeSignatureSection)
     codeSignatureSection->writeHashes(buffer->getBufferStart());
 }
 
 void Writer::run() {
   prepareBranchTarget(config->entry);
   scanRelocations();
   if (in.stubHelper->isNeeded())
     in.stubHelper->setup();
   scanSymbols();
   createOutputSections();
   // No more sections nor segments are created beyond this point.
   sortSegmentsAndSections();
   createLoadCommands();
   finalizeAddressses();
   finalizeLinkEditSegment();
   writeMapFile();
+  {
+    TimeTraceScope timeScope("Write output file");
     openFile();
     if (errorCount())
       return;
     writeSections();
     writeUuid();
     writeCodeSignature();
 
     if (auto e = buffer->commit())
       error("failed to write to the output file: " + toString(std::move(e)));
   }
+}
 
 void macho::writeResult() { Writer().run(); }
 
 void macho::createSyntheticSections() {
   in.header = make<MachHeaderSection>();
   in.rebase = make<RebaseSection>();
   in.binding = make<BindingSection>();
   in.weakBinding = make<WeakBindingSection>();