<div dir="ltr">Apologies, this is committed by accident. I'll roll this change back.</div><br><div class="gmail_quote"><div dir="ltr" class="gmail_attr">On Fri, Dec 13, 2019 at 3:16 PM Rui Ueyama via llvm-commits <<a href="mailto:llvm-commits@lists.llvm.org">llvm-commits@lists.llvm.org</a>> wrote:<br></div><blockquote class="gmail_quote" style="margin:0px 0px 0px 0.8ex;border-left:1px solid rgb(204,204,204);padding-left:1ex"><br>
Author: Rui Ueyama<br>
Date: 2019-12-13T14:35:03+09:00<br>
New Revision: af5ca40b47b3e85c3add81ccdc0b787c4bc355ae<br>
<br>
URL: <a href="https://github.com/llvm/llvm-project/commit/af5ca40b47b3e85c3add81ccdc0b787c4bc355ae" rel="noreferrer" target="_blank">https://github.com/llvm/llvm-project/commit/af5ca40b47b3e85c3add81ccdc0b787c4bc355ae</a><br>
DIFF: <a href="https://github.com/llvm/llvm-project/commit/af5ca40b47b3e85c3add81ccdc0b787c4bc355ae.diff" rel="noreferrer" target="_blank">https://github.com/llvm/llvm-project/commit/af5ca40b47b3e85c3add81ccdc0b787c4bc355ae.diff</a><br>
<br>
LOG: temporary<br>
<br>
Added: <br>
    lld/test/ELF/check-time-trace.s<br>
    lld/test/ELF/lto/thinlto-time-trace.ll<br>
<br>
Modified: <br>
    lld/ELF/Config.h<br>
    lld/ELF/Driver.cpp<br>
    lld/ELF/ICF.cpp<br>
    lld/ELF/LTO.cpp<br>
    lld/ELF/MarkLive.cpp<br>
    lld/ELF/Options.td<br>
    lld/ELF/SyntheticSections.cpp<br>
    lld/ELF/Writer.cpp<br>
    llvm/include/llvm/LTO/Config.h<br>
    llvm/lib/LTO/LTO.cpp<br>
<br>
Removed: <br>
<br>
<br>
<br>
################################################################################<br>
diff  --git a/lld/ELF/Config.h b/lld/ELF/Config.h<br>
index d7e715ebf357..6d804ee2bbe6 100644<br>
--- a/lld/ELF/Config.h<br>
+++ b/lld/ELF/Config.h<br>
@@ -191,6 +191,7 @@ struct Configuration {<br>
   bool trace;<br>
   bool thinLTOEmitImportsFiles;<br>
   bool thinLTOIndexOnly;<br>
+  bool timeTraceEnabled;<br>
   bool tocOptimize;<br>
   bool undefinedVersion;<br>
   bool useAndroidRelrTags = false;<br>
@@ -240,6 +241,7 @@ struct Configuration {<br>
   unsigned ltoo;<br>
   unsigned optimize;<br>
   unsigned thinLTOJobs;<br>
+  unsigned timeTraceGranularity;<br>
   int32_t splitStackAdjustSize;<br>
<br>
   // The following config options do not directly correspond to any<br>
<br>
diff  --git a/lld/ELF/Driver.cpp b/lld/ELF/Driver.cpp<br>
index c721e872e12e..cc4cefc6ed97 100644<br>
--- a/lld/ELF/Driver.cpp<br>
+++ b/lld/ELF/Driver.cpp<br>
@@ -56,6 +56,7 @@<br>
 #include "llvm/Support/Path.h"<br>
 #include "llvm/Support/TarWriter.h"<br>
 #include "llvm/Support/TargetSelect.h"<br>
+#include "llvm/Support/TimeProfiler.h"<br>
 #include "llvm/Support/raw_ostream.h"<br>
 #include <cstdlib><br>
 #include <utility><br>
@@ -490,6 +491,10 @@ void LinkerDriver::main(ArrayRef<const char *> argsArr) {<br>
   if (args.hasArg(OPT_version))<br>
     return;<br>
<br>
+  // Initialize time trace.<br>
+  if (config->timeTraceEnabled)<br>
+    timeTraceProfilerInitialize(config->timeTraceGranularity, config->progName);<br>
+<br>
   initLLVM();<br>
   createFiles(args);<br>
   if (errorCount())<br>
@@ -509,19 +514,34 @@ void LinkerDriver::main(ArrayRef<const char *> argsArr) {<br>
   switch (config->ekind) {<br>
   case ELF32LEKind:<br>
     link<ELF32LE>(args);<br>
-    return;<br>
+    break;<br>
   case ELF32BEKind:<br>
     link<ELF32BE>(args);<br>
-    return;<br>
+    break;<br>
   case ELF64LEKind:<br>
     link<ELF64LE>(args);<br>
-    return;<br>
+    break;<br>
   case ELF64BEKind:<br>
     link<ELF64BE>(args);<br>
-    return;<br>
+    break;<br>
   default:<br>
     llvm_unreachable("unknown Config->EKind");<br>
   }<br>
+<br>
+  if (config->timeTraceEnabled) {<br>
+    std::string path = args.getLastArgValue(OPT_time_trace_file_eq);<br>
+    if (path.empty())<br>
+      path = (config->outputFile + ".time-trace").str();<br>
+<br>
+    std::error_code ec;<br>
+    raw_fd_ostream os(path, errorCode, sys::fs::F_Text);<br>
+    if (ec) {<br>
+      error("cannot open " + path + ": " + ec.message());<br>
+      return;<br>
+    }<br>
+    timeTraceProfilerWrite(os);<br>
+    timeTraceProfilerCleanup();<br>
+  }<br>
 }<br>
<br>
 static std::string getRpath(opt::InputArgList &args) {<br>
@@ -953,6 +973,9 @@ static void readConfigs(opt::InputArgList &args) {<br>
       getOldNewOptions(args, OPT_thinlto_object_suffix_replace_eq);<br>
   config->thinLTOPrefixReplace =<br>
       getOldNewOptions(args, OPT_thinlto_prefix_replace_eq);<br>
+  config->timeTraceEnabled = args.hasArg(OPT_time_trace);<br>
+  config->timeTraceGranularity =<br>
+      args::getInteger(args, OPT_time_trace_granularity, 500);<br>
   config->trace = args.hasArg(OPT_trace);<br>
   config->undefined = args::getStrings(args, OPT_undefined);<br>
   config->undefinedVersion =<br>
@@ -1597,6 +1620,7 @@ static Symbol *addUndefined(StringRef name) {<br>
 // Because all bitcode files that the program consists of are passed to<br>
 // the compiler at once, it can do a whole-program optimization.<br>
 template <class ELFT> void LinkerDriver::compileBitcodeFiles() {<br>
+  llvm::TimeTraceScope timeScope("LTO");<br>
   // Compile bitcode files and replace bitcode symbols.<br>
   lto.reset(new BitcodeCompiler);<br>
   for (BitcodeFile *file : bitcodeFiles)<br>
@@ -1723,6 +1747,8 @@ template <class ELFT> static uint32_t getAndFeatures() {<br>
 // Do actual linking. Note that when this function is called,<br>
 // all linker scripts have already been parsed.<br>
 template <class ELFT> void LinkerDriver::link(opt::InputArgList &args) {<br>
+  llvm::TimeTraceScope timeScope("ExecuteLinker");<br>
+<br>
   // If a -hash-style option was not given, set to a default value,<br>
   // which varies depending on the target.<br>
   if (!args.hasArg(OPT_hash_style)) {<br>
@@ -1762,8 +1788,11 @@ template <class ELFT> void LinkerDriver::link(opt::InputArgList &args) {<br>
   // symbols that we need to the symbol table. This process might<br>
   // add files to the link, via autolinking, these files are always<br>
   // appended to the Files vector.<br>
-  for (size_t i = 0; i < files.size(); ++i)<br>
-    parseFile(files[i]);<br>
+  {<br>
+    llvm::TimeTraceScope timeScope("Parse input files");<br>
+    for (size_t i = 0; i < files.size(); ++i)<br>
+      parseFile(files[i]);<br>
+  }<br>
<br>
   // Now that we have every file, we can decide if we will need a<br>
   // dynamic symbol table.<br>
@@ -1981,11 +2010,15 @@ template <class ELFT> void LinkerDriver::link(opt::InputArgList &args) {<br>
   // merging MergeInputSections into a single MergeSyntheticSection. From this<br>
   // point onwards InputSectionDescription::sections should be used instead of<br>
   // sectionBases.<br>
-  for (BaseCommand *base : script->sectionCommands)<br>
-    if (auto *sec = dyn_cast<OutputSection>(base))<br>
-      sec->finalizeInputSections();<br>
-  llvm::erase_if(inputSections,<br>
-                 [](InputSectionBase *s) { return isa<MergeInputSection>(s); });<br>
+  {<br>
+    llvm::TimeTraceScope timeScope("Merge input sections");<br>
+    for (BaseCommand *base : script->sectionCommands)<br>
+      if (auto *sec = dyn_cast<OutputSection>(base))<br>
+        sec->finalizeInputSections();<br>
+    llvm::erase_if(inputSections, [](InputSectionBase *s) {<br>
+      return isa<MergeInputSection>(s);<br>
+    });<br>
+  }<br>
<br>
   // Two input sections with <br>
diff erent output sections should not be folded.<br>
   // ICF runs after processSectionCommands() so that we know the output sections.<br>
<br>
diff  --git a/lld/ELF/ICF.cpp b/lld/ELF/ICF.cpp<br>
index 5e38066f45ba..7838a45557cc 100644<br>
--- a/lld/ELF/ICF.cpp<br>
+++ b/lld/ELF/ICF.cpp<br>
@@ -84,6 +84,7 @@<br>
 #include "llvm/ADT/StringExtras.h"<br>
 #include "llvm/BinaryFormat/ELF.h"<br>
 #include "llvm/Object/ELF.h"<br>
+#include "llvm/Support/TimeProfiler.h"<br>
 #include "llvm/Support/xxhash.h"<br>
 #include <algorithm><br>
 #include <atomic><br>
@@ -452,6 +453,7 @@ static void print(const Twine &s) {<br>
<br>
 // The main function of ICF.<br>
 template <class ELFT> void ICF<ELFT>::run() {<br>
+  llvm::TimeTraceScope timeScope("ICF");<br>
   // Compute isPreemptible early. We may add more symbols later, so this loop<br>
   // cannot be merged with the later computeIsPreemptible() pass which is used<br>
   // by scanRelocations().<br>
<br>
diff  --git a/lld/ELF/LTO.cpp b/lld/ELF/LTO.cpp<br>
index 524d552b0b84..3f677d86f13a 100644<br>
--- a/lld/ELF/LTO.cpp<br>
+++ b/lld/ELF/LTO.cpp<br>
@@ -108,6 +108,9 @@ static lto::Config createConfig() {<br>
   c.DebugPassManager = config->ltoDebugPassManager;<br>
   c.DwoDir = config->dwoDir;<br>
<br>
+  c.TimeTraceEnabled = config->timeTraceEnabled;<br>
+  c.TimeTraceGranularity = config->timeTraceGranularity;<br>
+<br>
   c.CSIRProfile = config->ltoCSProfileFile;<br>
   c.RunCSIRInstr = config->ltoCSProfileGenerate;<br>
<br>
<br>
diff  --git a/lld/ELF/MarkLive.cpp b/lld/ELF/MarkLive.cpp<br>
index bb0105c28928..b77fab9abb62 100644<br>
--- a/lld/ELF/MarkLive.cpp<br>
+++ b/lld/ELF/MarkLive.cpp<br>
@@ -31,6 +31,7 @@<br>
 #include "lld/Common/Strings.h"<br>
 #include "llvm/ADT/STLExtras.h"<br>
 #include "llvm/Object/ELF.h"<br>
+#include "llvm/Support/TimeProfiler.h"<br>
 #include <functional><br>
 #include <vector><br>
<br>
@@ -323,6 +324,7 @@ template <class ELFT> void MarkLive<ELFT>::moveToMain() {<br>
 // input sections. This function make some or all of them on<br>
 // so that they are emitted to the output file.<br>
 template <class ELFT> void markLive() {<br>
+  llvm::TimeTraceScope timeScope("GC");<br>
   // If -gc-sections is not given, no sections are removed.<br>
   if (!config->gcSections) {<br>
     for (InputSectionBase *sec : inputSections)<br>
<br>
diff  --git a/lld/ELF/Options.td b/lld/ELF/Options.td<br>
index b86a670915c1..3ee1d17b31df 100644<br>
--- a/lld/ELF/Options.td<br>
+++ b/lld/ELF/Options.td<br>
@@ -358,6 +358,12 @@ defm threads: B<"threads",<br>
     "Run the linker multi-threaded (default)",<br>
     "Do not run the linker multi-threaded">;<br>
<br>
+def time_trace: F<"time-trace">, HelpText<"Record time trace">;<br>
+def time_trace_file_eq: J<"time-trace-file=">, HelpText<"Specify time trace output file">;<br>
+<br>
+defm time_trace_granularity: Eq<"time-trace-granularity",<br>
+  "Minimum time granularity (in microseconds) traced by time profiler">;<br>
+<br>
 defm toc_optimize : B<"toc-optimize",<br>
     "(PowerPC64) Enable TOC related optimizations (default)",<br>
     "(PowerPC64) Disable TOC related optimizations">;<br>
<br>
diff  --git a/lld/ELF/SyntheticSections.cpp b/lld/ELF/SyntheticSections.cpp<br>
index d014da220817..e765d2a9465b 100644<br>
--- a/lld/ELF/SyntheticSections.cpp<br>
+++ b/lld/ELF/SyntheticSections.cpp<br>
@@ -36,6 +36,7 @@<br>
 #include "llvm/Support/Endian.h"<br>
 #include "llvm/Support/LEB128.h"<br>
 #include "llvm/Support/MD5.h"<br>
+#include "llvm/Support/TimeProfiler.h"<br>
 #include <cstdlib><br>
 #include <thread><br>
<br>
@@ -3132,6 +3133,7 @@ MergeSyntheticSection *createMergeSynthetic(StringRef name, uint32_t type,<br>
 }<br>
<br>
 template <class ELFT> void splitSections() {<br>
+  llvm::TimeTraceScope timeScope("Split sections");<br>
   // splitIntoPieces needs to be called on each MergeInputSection<br>
   // before calling finalizeContents().<br>
   parallelForEach(inputSections, [](InputSectionBase *sec) {<br>
<br>
diff  --git a/lld/ELF/Writer.cpp b/lld/ELF/Writer.cpp<br>
index 38009bdd9aa3..67fd2b9a8c53 100644<br>
--- a/lld/ELF/Writer.cpp<br>
+++ b/lld/ELF/Writer.cpp<br>
@@ -27,6 +27,7 @@<br>
 #include "llvm/ADT/StringSwitch.h"<br>
 #include "llvm/Support/RandomNumberGenerator.h"<br>
 #include "llvm/Support/SHA1.h"<br>
+#include "llvm/Support/TimeProfiler.h"<br>
 #include "llvm/Support/xxhash.h"<br>
 #include <climits><br>
<br>
@@ -139,7 +140,10 @@ static bool needsInterpSection() {<br>
          script->needsInterpSection();<br>
 }<br>
<br>
-template <class ELFT> void writeResult() { Writer<ELFT>().run(); }<br>
+template <class ELFT> void writeResult() {<br>
+  llvm::TimeTraceScope timeScope("Write output file");<br>
+  Writer<ELFT>().run();<br>
+}<br>
<br>
 static void removeEmptyPTLoad(std::vector<PhdrEntry *> &phdrs) {<br>
   llvm::erase_if(phdrs, [&](const PhdrEntry *p) {<br>
<br>
diff  --git a/lld/test/ELF/check-time-trace.s b/lld/test/ELF/check-time-trace.s<br>
new file mode 100644<br>
index 000000000000..8144b2abefb5<br>
--- /dev/null<br>
+++ b/lld/test/ELF/check-time-trace.s<br>
@@ -0,0 +1,39 @@<br>
+# REQUIRES: x86<br>
+# RUN: llvm-mc -filetype=obj -triple=x86_64-unknown-linux %s -o %t.o<br>
+<br>
+# Test implicit trace file name<br>
+# RUN: ld.lld -time-trace -time-trace-granularity=0 -o %t1.elf %t.o<br>
+# RUN: cat %t1.elf.time-trace \<br>
+# RUN:   | %python -c 'import json, sys; json.dump(json.loads(sys.stdin.read()), sys.stdout, sort_keys=True, indent=2)' \<br>
+# RUN:   | FileCheck %s<br>
+<br>
+# Test specified trace file name<br>
+# RUN: ld.lld -time-trace -time-trace-file=%t2.json -time-trace-granularity=0 -o %t2.elf %t.o<br>
+# RUN: cat %t2.json \<br>
+# RUN:   | %python -c 'import json, sys; json.dump(json.loads(sys.stdin.read()), sys.stdout, sort_keys=True, indent=2)' \<br>
+# RUN:   | FileCheck %s<br>
+<br>
+# Test trace requested to stdout<br>
+# RUN: ld.lld -time-trace -time-trace-file=- -time-trace-granularity=0 -o %t3.elf %t.o \<br>
+# RUN:   | %python -c 'import json, sys; json.dump(json.loads(sys.stdin.read()), sys.stdout, sort_keys=True, indent=2)' \<br>
+# RUN:   | FileCheck %s<br>
+<br>
+# CHECK: "traceEvents": [<br>
+# Check one event has correct fields<br>
+# CHECK: "dur":<br>
+# CHECK-NEXT: "name":<br>
+# CHECK-NEXT: "ph":<br>
+# CHECK-NEXT: "pid":<br>
+# CHECK-NEXT: "tid":<br>
+# CHECK-NEXT: "ts":<br>
+<br>
+# Check there is an ExecuteLinker event<br>
+# CHECK: "name": "ExecuteLinker"<br>
+<br>
+# Check process_name entry field<br>
+# CHECK: "name": "ld.lld{{(.exe)?}}"<br>
+# CHECK: "name": "process_name"<br>
+<br>
+.globl _start<br>
+_start:<br>
+  ret<br>
<br>
diff  --git a/lld/test/ELF/lto/thinlto-time-trace.ll b/lld/test/ELF/lto/thinlto-time-trace.ll<br>
new file mode 100644<br>
index 000000000000..1b8335cbb9a9<br>
--- /dev/null<br>
+++ b/lld/test/ELF/lto/thinlto-time-trace.ll<br>
@@ -0,0 +1,43 @@<br>
+; REQUIRES: x86<br>
+<br>
+; Test ThinLTO with time trace<br>
+; RUN: opt -module-summary %s -o %t1.o<br>
+; RUN: opt -module-summary %p/Inputs/thinlto.ll -o %t2.o<br>
+<br>
+; Test single-threaded<br>
+; RUN: ld.lld --thinlto-jobs=1 -time-trace -time-trace-granularity=0 -shared %t1.o %t2.o -o %t3.so<br>
+; RUN: cat %t3.so.time-trace \<br>
+; RUN:   | %python -c 'import json, sys; json.dump(json.loads(sys.stdin.read()), sys.stdout, sort_keys=True, indent=2)' \<br>
+; RUN:   | FileCheck %s<br>
+<br>
+; Test multi-threaded<br>
+; RUN: ld.lld -time-trace -time-trace-granularity=0 -shared %t1.o %t2.o -o %t4.so<br>
+; RUN: cat %t4.so.time-trace \<br>
+; RUN:   | %python -c 'import json, sys; json.dump(json.loads(sys.stdin.read()), sys.stdout, sort_keys=True, indent=2)' \<br>
+; RUN:   | FileCheck %s<br>
+<br>
+; CHECK: "traceEvents": [<br>
+; Check fields for an event are present<br>
+; CHECK: "args":<br>
+; CHECK-NEXT: "detail":<br>
+; CHECK: "dur":<br>
+; CHECK-NEXT: "name":<br>
+; CHECK-NEXT: "ph":<br>
+; CHECK-NEXT: "pid":<br>
+; CHECK-NEXT: "tid":<br>
+; CHECK-NEXT: "ts":<br>
+<br>
+; Check that an optimisation event is present<br>
+; CHECK: "name": "OptModule"<br>
+<br>
+target datalayout = "e-m:e-p270:32:32-p271:32:32-p272:64:64-i64:64-f80:128-n8:16:32:64-S128"<br>
+target triple = "x86_64-unknown-linux-gnu"<br>
+<br>
+declare void @g(...)<br>
+<br>
+define void @f() {<br>
+entry:<br>
+  call void (...) @g()<br>
+  ret void<br>
+}<br>
+<br>
<br>
diff  --git a/llvm/include/llvm/LTO/Config.h b/llvm/include/llvm/LTO/Config.h<br>
index 754e3126f8a9..6db1235a692c 100644<br>
--- a/llvm/include/llvm/LTO/Config.h<br>
+++ b/llvm/include/llvm/LTO/Config.h<br>
@@ -117,6 +117,12 @@ struct Config {<br>
   /// Statistics output file path.<br>
   std::string StatsFile;<br>
<br>
+  /// Time trace enabled<br>
+  bool TimeTraceEnabled = false;<br>
+<br>
+  /// Time trace granularity<br>
+  unsigned TimeTraceGranularity = 500;<br>
+<br>
   bool ShouldDiscardValueNames = true;<br>
   DiagnosticHandlerFunction DiagHandler;<br>
<br>
<br>
diff  --git a/llvm/lib/LTO/LTO.cpp b/llvm/lib/LTO/LTO.cpp<br>
index 0d48090e4268..e2c8aa159896 100644<br>
--- a/llvm/lib/LTO/LTO.cpp<br>
+++ b/llvm/lib/LTO/LTO.cpp<br>
@@ -39,6 +39,7 @@<br>
 #include "llvm/Support/TargetRegistry.h"<br>
 #include "llvm/Support/ThreadPool.h"<br>
 #include "llvm/Support/Threading.h"<br>
+#include "llvm/Support/TimeProfiler.h"<br>
 #include "llvm/Support/VCSRevision.h"<br>
 #include "llvm/Support/raw_ostream.h"<br>
 #include "llvm/Target/TargetMachine.h"<br>
@@ -1133,6 +1134,9 @@ class InProcessThinBackend : public ThinBackendProc {<br>
                 &ResolvedODR,<br>
             const GVSummaryMapTy &DefinedGlobals,<br>
             MapVector<StringRef, BitcodeModule> &ModuleMap) {<br>
+          if (Conf.TimeTraceEnabled)<br>
+            timeTraceProfilerInitialize(Conf.TimeTraceGranularity,<br>
+                                        "thin backend");<br>
           Error E = runThinLTOBackendThread(<br>
               AddStream, Cache, Task, BM, CombinedIndex, ImportList, ExportList,<br>
               ResolvedODR, DefinedGlobals, ModuleMap);<br>
@@ -1143,6 +1147,8 @@ class InProcessThinBackend : public ThinBackendProc {<br>
             else<br>
               Err = std::move(E);<br>
           }<br>
+          if (timeTraceProfilerEnabled())<br>
+            timeTraceProfilerFinishThread();<br>
         },<br>
         BM, std::ref(CombinedIndex), std::ref(ImportList), std::ref(ExportList),<br>
         std::ref(ResolvedODR), std::ref(DefinedGlobals), std::ref(ModuleMap));<br>
<br>
<br>
<br>
_______________________________________________<br>
llvm-commits mailing list<br>
<a href="mailto:llvm-commits@lists.llvm.org" target="_blank">llvm-commits@lists.llvm.org</a><br>
<a href="https://lists.llvm.org/cgi-bin/mailman/listinfo/llvm-commits" rel="noreferrer" target="_blank">https://lists.llvm.org/cgi-bin/mailman/listinfo/llvm-commits</a><br>
</blockquote></div>