[ORC] Improve debugging output for ORC.

(1) Print debugging output under a session lock to avoid garbled messages when
compiling on multiple threads.

(2) Name MaterializationUnits, add an ostream operator for them, and so they can
be easily referenced in debugging output, and have that ostream operator
optionally print code/data/hidden symbols provided by that materialization unit
based on command line options.

llvm-svn: 343323

include/llvm/ExecutionEngine/Orc/Core.h

@@ -46,31 +46,47 @@ using VModuleKey = uint64_t;
 //         efficiency).
 using SymbolNameSet = std::set<SymbolStringPtr>;
 
-/// Render a SymbolNameSet to an ostream.
-raw_ostream &operator<<(raw_ostream &OS, const SymbolNameSet &Symbols);
-
 /// A map from symbol names (as SymbolStringPtrs) to JITSymbols
 ///        (address/flags pairs).
 using SymbolMap = std::map<SymbolStringPtr, JITEvaluatedSymbol>;
 
-/// Render a SymbolMap to an ostream.
-raw_ostream &operator<<(raw_ostream &OS, const SymbolMap &Symbols);
-
 /// A map from symbol names (as SymbolStringPtrs) to JITSymbolFlags.
 using SymbolFlagsMap = std::map<SymbolStringPtr, JITSymbolFlags>;
 
-/// Render a SymbolMap to an ostream.
-raw_ostream &operator<<(raw_ostream &OS, const SymbolFlagsMap &Symbols);
-
 /// A base class for materialization failures that allows the failing
 ///        symbols to be obtained for logging.
 using SymbolDependenceMap = std::map<JITDylib *, SymbolNameSet>;
 
+/// A list of JITDylib pointers.
+using JITDylibList = std::vector<JITDylib *>;
+
+/// Render a SymbolStringPtr.
+raw_ostream &operator<<(raw_ostream &OS, const SymbolStringPtr &Sym);
+
+/// Render a SymbolNameSet.
+raw_ostream &operator<<(raw_ostream &OS, const SymbolNameSet &Symbols);
+
+/// Render a SymbolFlagsMap entry.
+raw_ostream &operator<<(raw_ostream &OS, const SymbolFlagsMap::value_type &KV);
+
+/// Render a SymbolMap entry.
+raw_ostream &operator<<(raw_ostream &OS, const SymbolMap::value_type &KV);
+
+/// Render a SymbolFlagsMap.
+raw_ostream &operator<<(raw_ostream &OS, const SymbolFlagsMap &SymbolFlags);
+
+/// Render a SymbolMap.
+raw_ostream &operator<<(raw_ostream &OS, const SymbolMap &Symbols);
+
+/// Render a SymbolDependenceMap entry.
+raw_ostream &operator<<(raw_ostream &OS,
+                        const SymbolDependenceMap::value_type &KV);
+
 /// Render a SymbolDependendeMap.
 raw_ostream &operator<<(raw_ostream &OS, const SymbolDependenceMap &Deps);
 
-/// A list of JITDylib pointers.
-using JITDylibList = std::vector<JITDylib *>;
+/// Render a MaterializationUnit.
+raw_ostream &operator<<(raw_ostream &OS, const MaterializationUnit &MU);
 
 /// Render a JITDylibList.
 raw_ostream &operator<<(raw_ostream &OS, const JITDylibList &JDs);
@@ -223,6 +239,10 @@ public:
 
   virtual ~MaterializationUnit() {}
 
+  /// Return the name of this materialization unit. Useful for debugging
+  /// output.
+  virtual StringRef getName() const = 0;
+
   /// Return the set of symbols that this source provides.
   const SymbolFlagsMap &getSymbols() const { return SymbolFlags; }
 
@@ -269,6 +289,8 @@ class AbsoluteSymbolsMaterializationUnit : public MaterializationUnit {
 public:
   AbsoluteSymbolsMaterializationUnit(SymbolMap Symbols);
 
+  StringRef getName() const override;
+
 private:
   void materialize(MaterializationResponsibility R) override;
   void discard(const JITDylib &JD, SymbolStringPtr Name) override;
@@ -318,6 +340,8 @@ public:
   ///       resolved.
   ReExportsMaterializationUnit(JITDylib *SourceJD, SymbolAliasMap Aliases);
 
+  StringRef getName() const override;
+
 private:
   void materialize(MaterializationResponsibility R) override;
   void discard(const JITDylib &JD, SymbolStringPtr Name) override;
@@ -742,8 +766,10 @@ public:
   /// Materialize the given unit.
   void dispatchMaterialization(JITDylib &JD,
                                std::unique_ptr<MaterializationUnit> MU) {
-    LLVM_DEBUG(dbgs() << "For " << JD.getName() << " compiling "
-                      << MU->getSymbols() << "\n");
+    LLVM_DEBUG(runSessionLocked([&]() {
+                 dbgs() << "Compiling, for " << JD.getName() << ", " << *MU
+                        << "\n";
+               }););
     DispatchMaterialization(JD, std::move(MU));
   }
 

include/llvm/ExecutionEngine/Orc/Layer.h

@@ -86,6 +86,9 @@ public:
   IRMaterializationUnit(ThreadSafeModule TSM, SymbolFlagsMap SymbolFlags,
                         SymbolNameToDefinitionMap SymbolToDefinition);
 
+  /// Return the ModuleIdentifier as the name for this MaterializationUnit.
+  StringRef getName() const override;
+
 protected:
   ThreadSafeModule TSM;
   SymbolNameToDefinitionMap SymbolToDefinition;
@@ -147,6 +150,9 @@ public:
                                       std::unique_ptr<MemoryBuffer> O,
                                       SymbolFlagsMap SymbolFlags);
 
+  /// Return the buffer's identifier as the name for this MaterializationUnit.
+  StringRef getName() const override;
+
 private:
 
   void materialize(MaterializationResponsibility R) override;

include/llvm/ExecutionEngine/Orc/LazyReexports.h

@@ -161,6 +161,8 @@ public:
                                    JITDylib &SourceJD,
                                    SymbolAliasMap CallableAliases);
 
+  StringRef getName() const override;
+
 private:
   void materialize(MaterializationResponsibility R) override;
   void discard(const JITDylib &JD, SymbolStringPtr Name) override;

lib/ExecutionEngine/Orc/Core.cpp

@@ -11,6 +11,7 @@
 #include "llvm/Config/llvm-config.h"
 #include "llvm/ExecutionEngine/Orc/OrcError.h"
 #include "llvm/IR/Mangler.h"
+#include "llvm/Support/CommandLine.h"
 #include "llvm/Support/Debug.h"
 #include "llvm/Support/Format.h"
 
@@ -20,6 +21,116 @@
 
 #define DEBUG_TYPE "orc"
 
+using namespace llvm;
+
+namespace {
+
+#ifndef NDEBUG
+
+cl::opt<bool> PrintHidden("debug-orc-print-hidden", cl::init(false),
+                          cl::desc("debug print hidden symbols defined by "
+                                   "materialization units"),
+                          cl::Hidden);
+
+cl::opt<bool> PrintCallable("debug-orc-print-callable", cl::init(false),
+                            cl::desc("debug print callable symbols defined by "
+                                     "materialization units"),
+                            cl::Hidden);
+
+cl::opt<bool> PrintData("debug-orc-print-data", cl::init(false),
+                        cl::desc("debug print data symbols defined by "
+                                 "materialization units"),
+                        cl::Hidden);
+
+#endif // NDEBUG
+
+// SetPrinter predicate that prints every element.
+template <typename T> struct PrintAll {
+  bool operator()(const T &E) { return true; }
+};
+
+bool anyPrintSymbolOptionSet() {
+#ifndef NDEBUG
+  return PrintHidden || PrintCallable || PrintData;
+#else
+  return false;
+#endif // NDEBUG
+}
+
+bool flagsMatchCLOpts(const JITSymbolFlags &Flags) {
+#ifndef NDEBUG
+  // Bail out early if this is a hidden symbol and we're not printing hiddens.
+  if (!PrintHidden && !Flags.isExported())
+    return false;
+
+  // Return true if this is callable and we're printing callables.
+  if (PrintCallable && Flags.isCallable())
+    return true;
+
+  // Return true if this is data and we're printing data.
+  if (PrintData && !Flags.isCallable())
+    return true;
+
+  // otherwise return false.
+  return false;
+#else
+  return false;
+#endif // NDEBUG
+}
+
+// Prints a set of items, filtered by an user-supplied predicate.
+template <typename Set, typename Pred = PrintAll<typename Set::value_type>>
+class SetPrinter {
+public:
+  SetPrinter(const Set &S, Pred ShouldPrint = Pred())
+      : S(S), ShouldPrint(std::move(ShouldPrint)) {}
+
+  void printTo(llvm::raw_ostream &OS) const {
+    bool PrintComma = false;
+    OS << "{";
+    for (auto &E : S) {
+      if (ShouldPrint(E)) {
+        if (PrintComma)
+          OS << ',';
+        OS << ' ' << E;
+        PrintComma = true;
+      }
+    }
+    OS << " }";
+  }
+
+private:
+  const Set &S;
+  mutable Pred ShouldPrint;
+};
+
+template <typename Set, typename Pred>
+SetPrinter<Set, Pred> printSet(const Set &S, Pred P = Pred()) {
+  return SetPrinter<Set, Pred>(S, std::move(P));
+}
+
+// Render a SetPrinter by delegating to its printTo method.
+template <typename Set, typename Pred>
+llvm::raw_ostream &operator<<(llvm::raw_ostream &OS,
+                              const SetPrinter<Set, Pred> &Printer) {
+  Printer.printTo(OS);
+  return OS;
+}
+
+struct PrintSymbolFlagsMapElemsMatchingCLOpts {
+  bool operator()(const orc::SymbolFlagsMap::value_type &KV) {
+    return flagsMatchCLOpts(KV.second);
+  }
+};
+
+struct PrintSymbolMapElemsMatchingCLOpts {
+  bool operator()(const orc::SymbolMap::value_type &KV) {
+    return flagsMatchCLOpts(KV.second.getFlags());
+  }
+};
+
+} // end anonymous namespace
+
 namespace llvm {
 namespace orc {
 
@@ -31,6 +142,14 @@ RegisterDependenciesFunction NoDependenciesToRegister =
 
 void MaterializationUnit::anchor() {}
 
+raw_ostream &operator<<(raw_ostream &OS, const SymbolStringPtr &Sym) {
+  return OS << *Sym;
+}
+
+raw_ostream &operator<<(raw_ostream &OS, const SymbolNameSet &Symbols) {
+  return OS << printSet(Symbols, PrintAll<SymbolStringPtr>());
+}
+
 raw_ostream &operator<<(raw_ostream &OS, const JITSymbolFlags &Flags) {
   if (Flags.isCallable())
     OS << "[Callable]";
@@ -48,60 +167,39 @@ raw_ostream &operator<<(raw_ostream &OS, const JITSymbolFlags &Flags) {
 }
 
 raw_ostream &operator<<(raw_ostream &OS, const JITEvaluatedSymbol &Sym) {
-  OS << format("0x%016x", Sym.getAddress()) << " " << Sym.getFlags();
-  return OS;
+  return OS << format("0x%016x", Sym.getAddress()) << " " << Sym.getFlags();
+}
+
+raw_ostream &operator<<(raw_ostream &OS, const SymbolFlagsMap::value_type &KV) {
+  return OS << "(\"" << KV.first << "\", " << KV.second << ")";
 }
 
 raw_ostream &operator<<(raw_ostream &OS, const SymbolMap::value_type &KV) {
-  OS << "\"" << *KV.first << "\": " << KV.second;
-  return OS;
-}
-
-raw_ostream &operator<<(raw_ostream &OS, const SymbolNameSet &Symbols) {
-  OS << "{";
-  if (!Symbols.empty()) {
-    OS << " \"" << **Symbols.begin() << "\"";
-    for (auto &Sym : make_range(std::next(Symbols.begin()), Symbols.end()))
-      OS << ", \"" << *Sym << "\"";
-  }
-  OS << " }";
-  return OS;
-}
-
-raw_ostream &operator<<(raw_ostream &OS, const SymbolMap &Symbols) {
-  OS << "{";
-  if (!Symbols.empty()) {
-    OS << " {" << *Symbols.begin() << "}";
-    for (auto &Sym : make_range(std::next(Symbols.begin()), Symbols.end()))
-      OS << ", {" << Sym << "}";
-  }
-  OS << " }";
-  return OS;
+  return OS << "(\"" << KV.first << "\": " << KV.second << ")";
 }
 
 raw_ostream &operator<<(raw_ostream &OS, const SymbolFlagsMap &SymbolFlags) {
-  OS << "{";
-  if (!SymbolFlags.empty()) {
-    OS << " {\"" << *SymbolFlags.begin()->first
-       << "\": " << SymbolFlags.begin()->second << "}";
-    for (auto &KV :
-         make_range(std::next(SymbolFlags.begin()), SymbolFlags.end()))
-      OS << ", {\"" << *KV.first << "\": " << KV.second << "}";
-  }
-  OS << " }";
-  return OS;
+  return OS << printSet(SymbolFlags, PrintSymbolFlagsMapElemsMatchingCLOpts());
+}
+
+raw_ostream &operator<<(raw_ostream &OS, const SymbolMap &Symbols) {
+  return OS << printSet(Symbols, PrintSymbolMapElemsMatchingCLOpts());
+}
+
+raw_ostream &operator<<(raw_ostream &OS,
+                        const SymbolDependenceMap::value_type &KV) {
+  return OS << "(" << KV.first << ", " << KV.second << ")";
 }
 
 raw_ostream &operator<<(raw_ostream &OS, const SymbolDependenceMap &Deps) {
-  OS << "{";
-  if (!Deps.empty()) {
-    OS << " { " << Deps.begin()->first->getName() << ": "
-       << Deps.begin()->second << " }";
-    for (auto &KV : make_range(std::next(Deps.begin()), Deps.end()))
-      OS << ", { " << KV.first->getName() << ": " << KV.second << " }";
-  }
-  OS << " }";
-  return OS;
+  return OS << printSet(Deps, PrintAll<SymbolDependenceMap::value_type>());
+}
+
+raw_ostream &operator<<(raw_ostream &OS, const MaterializationUnit &MU) {
+  OS << "MU@" << &MU << " (\"" << MU.getName() << "\"";
+  if (anyPrintSymbolOptionSet())
+    OS << ", " << MU.getSymbols();
+  return OS << ")";
 }
 
 raw_ostream &operator<<(raw_ostream &OS, const JITDylibList &JDs) {
@@ -336,7 +434,10 @@ void MaterializationResponsibility::replace(
   for (auto &KV : MU->getSymbols())
     SymbolFlags.erase(KV.first);
 
-  LLVM_DEBUG(dbgs() << "For " << JD.getName() << " replacing " << MU->getSymbols() << "\n");
+  LLVM_DEBUG(JD.getExecutionSession().runSessionLocked([&]() {
+    dbgs() << "In " << JD.getName() << " replacing symbols with MU@" << MU.get()
+           << " (" << MU->getName() << ")\n";
+  }););
 
   JD.replace(std::move(MU));
 }
@@ -375,6 +476,10 @@ AbsoluteSymbolsMaterializationUnit::AbsoluteSymbolsMaterializationUnit(
     SymbolMap Symbols)
     : MaterializationUnit(extractFlags(Symbols)), Symbols(std::move(Symbols)) {}
 
+StringRef AbsoluteSymbolsMaterializationUnit::getName() const {
+  return "<Absolute Symbols>";
+}
+
 void AbsoluteSymbolsMaterializationUnit::materialize(
     MaterializationResponsibility R) {
   R.resolve(Symbols);
@@ -400,6 +505,10 @@ ReExportsMaterializationUnit::ReExportsMaterializationUnit(
     : MaterializationUnit(extractFlags(Aliases)), SourceJD(SourceJD),
       Aliases(std::move(Aliases)) {}
 
+StringRef ReExportsMaterializationUnit::getName() const {
+  return "<Reexports>";
+}
+
 void ReExportsMaterializationUnit::materialize(
     MaterializationResponsibility R) {
 

lib/ExecutionEngine/Orc/IndirectionUtils.cpp

@@ -31,15 +31,17 @@ public:
       : MaterializationUnit(SymbolFlagsMap({{Name, JITSymbolFlags::Exported}})),
         Name(std::move(Name)), Compile(std::move(Compile)) {}
 
+  StringRef getName() const override { return "<Compile Callbacks>"; }
+
 private:
-  void materialize(MaterializationResponsibility R) {
+  void materialize(MaterializationResponsibility R) override {
     SymbolMap Result;
     Result[Name] = JITEvaluatedSymbol(Compile(), JITSymbolFlags::Exported);
     R.resolve(Result);
     R.emit();
   }
 
-  void discard(const JITDylib &JD, SymbolStringPtr Name) {
+  void discard(const JITDylib &JD, SymbolStringPtr Name) override {
     llvm_unreachable("Discard should never occur on a LMU?");
   }
 

lib/ExecutionEngine/Orc/Layer.cpp

@@ -9,6 +9,9 @@
 
 #include "llvm/ExecutionEngine/Orc/Layer.h"
 #include "llvm/Object/ObjectFile.h"
+#include "llvm/Support/Debug.h"
+
+#define DEBUG_TYPE "orc"
 
 namespace llvm {
 namespace orc {
@@ -44,7 +47,18 @@ IRMaterializationUnit::IRMaterializationUnit(
     : MaterializationUnit(std::move(SymbolFlags)), TSM(std::move(TSM)),
       SymbolToDefinition(std::move(SymbolToDefinition)) {}
 
+StringRef IRMaterializationUnit::getName() const {
+  if (TSM.getModule())
+    return TSM.getModule()->getModuleIdentifier();
+  return "<null module>";
+}
+
 void IRMaterializationUnit::discard(const JITDylib &JD, SymbolStringPtr Name) {
+  LLVM_DEBUG(JD.getExecutionSession().runSessionLocked([&]() {
+    dbgs() << "In " << JD.getName() << " discarding " << *Name << " from MU@"
+           << this << " (" << getName() << ")\n";
+  }););
+
   auto I = SymbolToDefinition.find(Name);
   assert(I != SymbolToDefinition.end() &&
          "Symbol not provided by this MU, or previously discarded");
@@ -65,8 +79,20 @@ void BasicIRLayerMaterializationUnit::materialize(
   if (L.getCloneToNewContextOnEmit())
     TSM = cloneToNewContext(TSM);
 
+#ifndef NDEBUG
+  auto &ES = R.getTargetJITDylib().getExecutionSession();
+#endif // NDEBUG
+
   auto Lock = TSM.getContextLock();
+  LLVM_DEBUG(ES.runSessionLocked([&]() {
+    dbgs() << "Emitting, for " << R.getTargetJITDylib().getName() << ", "
+           << *this << "\n";
+  }););
   L.emit(std::move(R), std::move(K), std::move(TSM));
+  LLVM_DEBUG(ES.runSessionLocked([&]() {
+    dbgs() << "Finished emitting, for " << R.getTargetJITDylib().getName()
+           << ", " << *this << "\n";
+  }););
 }
 
 ObjectLayer::ObjectLayer(ExecutionSession &ES) : ES(ES) {}
@@ -102,6 +128,12 @@ BasicObjectLayerMaterializationUnit::BasicObjectLayerMaterializationUnit(
     : MaterializationUnit(std::move(SymbolFlags)), L(L), K(std::move(K)),
       O(std::move(O)) {}
 
+StringRef BasicObjectLayerMaterializationUnit::getName() const {
+  if (O)
+    return O->getBufferIdentifier();
+  return "<null object>";
+}
+
 void BasicObjectLayerMaterializationUnit::materialize(
     MaterializationResponsibility R) {
   L.emit(std::move(R), std::move(K), std::move(O));

lib/ExecutionEngine/Orc/LazyReexports.cpp

@@ -135,6 +135,10 @@ LazyReexportsMaterializationUnit::LazyReexportsMaterializationUnit(
             return ISManager.updatePointer(*SymbolName, ResolvedAddr);
           })) {}
 
+StringRef LazyReexportsMaterializationUnit::getName() const {
+  return "<Lazy Reexports>";
+}
+
 void LazyReexportsMaterializationUnit::materialize(
     MaterializationResponsibility R) {
   auto RequestedSymbols = R.getRequestedSymbols();