Backport -ftime-trace from upstream llvm & clang (microsoft#4873)

* Backport -ftime-trace from upstream llvm & clang

This change back-ports the -ftime-trace feature implemented by Aras
Pranckevičius (@aras-p) into DXC.

Aras has a great blog post describing the motivaiton for this feature
and how to use it (see:
https://aras-p.info/blog/2019/01/16/time-trace-timeline-flame-chart-prof
iler-for-Clang/).

As shaders are getting more and more complex we need better timing data
for ourselves as compiler writers and our users as HLSL writers to know
how to improve compile times of complex shaders.

This implementation is a starting point to give us data to help drive
our efforts to improve compile-time performance.

Because DXC's LLVM is very far removed from the version of LLVM the
patch was originally written for this change is not strictly a
cherry-pick of
llvm/llvm-project@d880de2d19d46f7cfea7aa593602
458440bc1e8d. Instead this change is a manually applied and
reconstructed patch with significant alterations along the way. The
alaterations are performed by myself, but credit for the patch remains
with @aras-p.

Patch by Aras Pranckevičius (@aras-p).

Author: llvm-beanz

include/dxc/Support/HLSLOptions.h

@@ -207,6 +207,7 @@ class DxcOpts {
   bool EnableLifetimeMarkers = false; // OPT_enable_lifetime_markers
   bool ForceDisableLocTracking = false; // OPT_fdisable_loc_tracking
   bool TimeReport = false; // OPT_ftime_report
+  std::string TimeTrace = ""; // OPT_ftime_trace[EQ]
 
   // Optimization pass enables, disables and selects
   std::map<std::string, bool> DxcOptimizationToggles; // OPT_opt_enable & OPT_opt_disable

include/dxc/Support/HLSLOptions.td

@@ -174,6 +174,12 @@ def fdisable_loc_tracking : Flag<["-"], "fdisable-loc-tracking">,
 
 
 def ftime_report : Flag<["-"], "ftime-report">, Group<hlslcomp_Group>, Flags<[CoreOption]>, HelpText<"Print time report">;
+def ftime_trace : Flag<["-"], "ftime-trace">,
+  Group<hlslcomp_Group>, Flags<[CoreOption]>,
+  HelpText<"Print hierchial time tracing to stdout">;
+def ftime_trace_EQ : Joined<["-"], "ftime-trace=">,
+  Group<hlslcomp_Group>, Flags<[CoreOption]>,
+  HelpText<"Print hierchial time tracing to file">;
 
 /*
 def fno_caret_diagnostics : Flag<["-"], "fno-caret-diagnostics">, Group<hlslcomp_Group>,

include/dxc/Support/dxcapi.impl.h

@@ -98,6 +98,7 @@ inline DxcOutputType DxcGetOutputType(DXC_OUT_KIND kind) {
   case DXC_OUT_TEXT:
   case DXC_OUT_REMARKS:
   case DXC_OUT_TIME_REPORT:
+  case DXC_OUT_TIME_TRACE:
     return DxcOutputType_Text;
   default:
     return DxcOutputType_None;

include/dxc/dxcapi.h

@@ -478,8 +478,9 @@ typedef enum DXC_OUT_KIND {
   DXC_OUT_EXTRA_OUTPUTS  = 10,// IDxcExtraResults - Extra outputs
   DXC_OUT_REMARKS = 11,       // IDxcBlobUtf8 or IDxcBlobWide - text directed at stdout
   DXC_OUT_TIME_REPORT = 12,   // IDxcBlobUtf8 or IDxcBlobWide - text directed at stdout
+  DXC_OUT_TIME_TRACE = 13,   // IDxcBlobUtf8 or IDxcBlobWide - text directed at stdout
 
-  DXC_OUT_LAST = DXC_OUT_TIME_REPORT, // Last value for a counter
+  DXC_OUT_LAST = DXC_OUT_TIME_TRACE, // Last value for a counter
 
   DXC_OUT_NUM_ENUMS,
   DXC_OUT_FORCE_DWORD = 0xFFFFFFFF

include/llvm/Support/TimeProfiler.h

@@ -0,0 +1,71 @@
+//===- llvm/Support/TimeProfiler.h - Hierarchical Time Profiler -*- C++ -*-===//
+//
+//                     The LLVM Compiler Infrastructure
+//
+// This file is distributed under the University of Illinois Open Source
+// License. See LICENSE.TXT for details.
+//
+//===----------------------------------------------------------------------===//
+
+#ifndef LLVM_SUPPORT_TIME_PROFILER_H
+#define LLVM_SUPPORT_TIME_PROFILER_H
+
+#include "llvm/ADT/STLExtras.h"
+#include "llvm/Support/raw_ostream.h"
+
+namespace llvm {
+
+struct TimeTraceProfiler;
+extern TimeTraceProfiler *TimeTraceProfilerInstance;
+
+/// Initialize the time trace profiler.
+/// This sets up the global \p TimeTraceProfilerInstance
+/// variable to be the profiler instance.
+void timeTraceProfilerInitialize();
+
+/// Cleanup the time trace profiler, if it was initialized.
+void timeTraceProfilerCleanup();
+
+/// Is the time trace profiler enabled, i.e. initialized?
+inline bool timeTraceProfilerEnabled() {
+  return TimeTraceProfilerInstance != nullptr;
+}
+
+/// Write profiling data to output file.
+/// Data produced is JSON, in Chrome "Trace Event" format, see
+/// https://docs.google.com/document/d/1CvAClvFfyA5R-PhYUmn5OOQtYMH4h6I0nSsKchNAySU/preview
+void timeTraceProfilerWrite(raw_ostream &OS);
+
+/// Manually begin a time section, with the given \p Name and \p Detail.
+/// Profiler copies the string data, so the pointers can be given into
+/// temporaries. Time sections can be hierarchical; every Begin must have a
+/// matching End pair but they can nest.
+void timeTraceProfilerBegin(StringRef Name, StringRef Detail);
+void timeTraceProfilerBegin(StringRef Name,
+                            llvm::function_ref<std::string()> Detail);
+
+/// Manually end the last time section.
+void timeTraceProfilerEnd();
+
+/// The TimeTraceScope is a helper class to call the begin and end functions
+/// of the time trace profiler.  When the object is constructed, it begins
+/// the section; and when it is destroyed, it stops it. If the time profiler
+/// is not initialized, the overhead is a single branch.
+struct TimeTraceScope {
+  TimeTraceScope(StringRef Name, StringRef Detail) {
+    if (TimeTraceProfilerInstance != nullptr)
+      timeTraceProfilerBegin(Name, Detail);
+  }
+  TimeTraceScope(StringRef Name, llvm::function_ref<std::string()> Detail) {
+    if (TimeTraceProfilerInstance != nullptr)
+      timeTraceProfilerBegin(Name, Detail);
+  }
+  ~TimeTraceScope() {
+    if (TimeTraceProfilerInstance != nullptr)
+      timeTraceProfilerEnd();
+  }
+};
+
+} // end namespace llvm
+
+#endif

lib/Analysis/IPA/CallGraphSCCPass.cpp

@@ -26,6 +26,7 @@
 #include "llvm/Support/CommandLine.h"
 #include "llvm/Support/Debug.h"
 #include "llvm/Support/Timer.h"
+#include "llvm/Support/TimeProfiler.h" // HLSL Change
 #include "llvm/Support/raw_ostream.h"
 using namespace llvm;
 
@@ -126,6 +127,12 @@ bool CGPassManager::RunPassOnSCC(Pass *P, CallGraphSCC &CurSCC,
     }
 
     {
+      // HLSL Change Begin - Support hierarchial time tracing.
+      StringRef FnName = (*CurSCC.begin())->getFunction()
+                             ? (*CurSCC.begin())->getFunction()->getName()
+                             : "Unnamed";
+      TimeTraceScope FunctionScope("CGSCCPass-Function", FnName);
+      // HLSL Change End - Support hierarchial time tracing.
       TimeRegion PassTimer(getPassTimer(CGSP));
       Changed = CGSP->runOnSCC(CurSCC);
     }
@@ -150,6 +157,9 @@ bool CGPassManager::RunPassOnSCC(Pass *P, CallGraphSCC &CurSCC,
     if (Function *F = CGN->getFunction()) {
       dumpPassInfo(P, EXECUTION_MSG, ON_FUNCTION_MSG, F->getName());
       {
+        // HLSL Change Begin - Support hierarchial time tracing.
+        TimeTraceScope FunctionScope("CGSCCPass-Function", F->getName());
+        // HLSL Change End - Support hierarchial time tracing.
         TimeRegion PassTimer(getPassTimer(FPP));
         Changed |= FPP->runOnFunction(*F);
       }
@@ -398,6 +408,9 @@ bool CGPassManager::RunAllPassesOnSCC(CallGraphSCC &CurSCC, CallGraph &CG,
   for (unsigned PassNo = 0, e = getNumContainedPasses();
        PassNo != e; ++PassNo) {
     Pass *P = getContainedPass(PassNo);
+    // HLSL Change Begin - Support hierarchial time tracing.
+    TimeTraceScope PassScope("RunCallGraphSCCPass", P->getPassName());
+    // HLSL Change End - Support hierarchial time tracing.
 
     // If we're in -debug-pass=Executions mode, construct the SCC node list,
     // otherwise avoid constructing this string as it is expensive.

lib/DxcSupport/HLSLOptions.cpp

@@ -782,6 +782,9 @@ int ReadDxcOpts(const OptTable *optionTable, unsigned flagsToInclude,
   opts.ForceDisableLocTracking =
       Args.hasFlag(OPT_fdisable_loc_tracking, OPT_INVALID, false);
   opts.TimeReport = Args.hasFlag(OPT_ftime_report, OPT_INVALID, false);
+  opts.TimeTrace = Args.hasFlag(OPT_ftime_trace, OPT_INVALID, false) ? "-" : "";
+  if (Args.hasArg(OPT_ftime_trace_EQ))
+    opts.TimeTrace = Args.getLastArgValue(OPT_ftime_trace_EQ);
   opts.EnablePayloadQualifiers = Args.hasFlag(OPT_enable_payload_qualifiers, OPT_INVALID,
                                             DXIL::CompareVersions(Major, Minor, 6, 7) >= 0); 
 

lib/IR/LegacyPassManager.cpp

@@ -24,6 +24,7 @@
 #include "llvm/Support/Mutex.h"
 #include "llvm/Support/TimeValue.h"
 #include "llvm/Support/Timer.h"
+#include "llvm/Support/TimeProfiler.h"
 #include "llvm/Support/raw_ostream.h"
 #include <algorithm>
 #include <map>
@@ -1321,7 +1322,7 @@ bool BBPassManager::runOnFunction(Function &F) {
 
   bool Changed = doInitialization(F);
 
-  for (Function::iterator I = F.begin(), E = F.end(); I != E; ++I)
+  for (Function::iterator I = F.begin(), E = F.end(); I != E; ++I) 
     for (unsigned Index = 0; Index < getNumContainedPasses(); ++Index) {
       BasicBlockPass *BP = getContainedPass(Index);
       bool LocalChanged = false;
@@ -1552,10 +1553,18 @@ bool FPPassManager::runOnFunction(Function &F) {
   // Collect inherited analysis from Module level pass manager.
   populateInheritedAnalysis(TPM->activeStack);
 
+  // HLSL Change Begin - Support hierarchial time tracing.
+  llvm::TimeTraceScope FunctionScope("OptFunction", F.getName());
+  // HLSL Change End
+
   for (unsigned Index = 0; Index < getNumContainedPasses(); ++Index) {
     FunctionPass *FP = getContainedPass(Index);
     bool LocalChanged = false;
 
+    // HLSL Change Begin - Support hierarchial time tracing.
+    llvm::TimeTraceScope PassScope("RunFunctionPass", FP->getPassName());
+    // HLSL Change End - Support hierarchial time tracing.
+
     dumpPassInfo(FP, EXECUTION_MSG, ON_FUNCTION_MSG, F.getName());
     dumpRequiredSet(FP);
 
@@ -1578,12 +1587,14 @@ bool FPPassManager::runOnFunction(Function &F) {
     recordAvailableAnalysis(FP);
     removeDeadPasses(FP, F.getName(), ON_FUNCTION_MSG);
   }
+
   return Changed;
 }
 
 bool FPPassManager::runOnModule(Module &M) {
   bool Changed = false;
 
+  llvm::TimeTraceScope TimeScope("OptModule", M.getName());
   for (Function &F : M)
     Changed |= runOnFunction(F);
 
@@ -1616,6 +1627,8 @@ bool FPPassManager::doFinalization(Module &M) {
 /// the module, and if so, return true.
 bool
 MPPassManager::runOnModule(Module &M) {
+  llvm::TimeTraceScope TimeScope("OptModule", M.getName());
+
   bool Changed = false;
 
   // Initialize on-the-fly passes
@@ -1632,6 +1645,8 @@ MPPassManager::runOnModule(Module &M) {
     ModulePass *MP = getContainedPass(Index);
     bool LocalChanged = false;
 
+    llvm::TimeTraceScope PassScope("RunModulePass", MP->getPassName());
+
     dumpPassInfo(MP, EXECUTION_MSG, ON_MODULE_MSG, M.getModuleIdentifier());
     dumpRequiredSet(MP);
 

lib/Support/CMakeLists.txt

@@ -131,6 +131,7 @@ add_llvm_library(LLVMSupport
   TargetRegistry.cpp
   ThreadLocal.cpp
   Threading.cpp
+  TimeProfiler.cpp # HLSL Change - Support hierarchial time tracing.
   TimeValue.cpp
   Valgrind.cpp
   Watchdog.cpp