Allow signposts to take advantage of deferred string substitution

One nice feature of the os_signpost API is that format string
substitutions happen in the consumer, not the logging
application. LLVM's current Signpost class doesn't take advantage of
this though and instead always uses a static "Begin/End %s" format
string.

This patch uses variadic macros to allow the API to be used as
intended. Unfortunately, the primary use-case I had in mind (the
LLDB_SCOPED_TIMER() macro) does not get much better from this, because
__PRETTY_FUNCTION__ is *not* a macro, but a static string, so
signposts created by LLDB_SCOPED_TIMER() still use a static "%s"
format string. At least LLDB_SCOPED_TIMERF() works as intended.

This reapplies the previsously reverted patch with additional MachO.h
macro #undefs.

Differential Revision: https://reviews.llvm.org/D103575

lldb/include/lldb/Utility/Timer.h

@@ -10,10 +10,16 @@
 #define LLDB_UTILITY_TIMER_H
 
 #include "lldb/lldb-defines.h"
+#include "llvm/ADT/ScopeExit.h"
 #include "llvm/Support/Chrono.h"
+#include "llvm/Support/Signposts.h"
 #include <atomic>
 #include <cstdint>
 
+namespace llvm {
+  class SignpostEmitter;
+}
+
 namespace lldb_private {
 class Stream;
 
@@ -72,15 +78,28 @@ private:
   const Timer &operator=(const Timer &) = delete;
 };
 
+llvm::SignpostEmitter &GetSignposts();
+
 } // namespace lldb_private
 
 // Use a format string because LLVM_PRETTY_FUNCTION might not be a string
 // literal.
 #define LLDB_SCOPED_TIMER()                                                    \
   static ::lldb_private::Timer::Category _cat(LLVM_PRETTY_FUNCTION);           \
-  ::lldb_private::Timer _scoped_timer(_cat, "%s", LLVM_PRETTY_FUNCTION)
-#define LLDB_SCOPED_TIMERF(...)                                                \
+  ::lldb_private::Timer _scoped_timer(_cat, "%s", LLVM_PRETTY_FUNCTION);       \
+  SIGNPOST_EMITTER_START_INTERVAL(::lldb_private::GetSignposts(),              \
+                                  &_scoped_timer, "%s", LLVM_PRETTY_FUNCTION); \
+  auto _scoped_signpost = llvm::make_scope_exit([&_scoped_timer]() {           \
+    ::lldb_private::GetSignposts().endInterval(&_scoped_timer);                \
+  })
+
+#define LLDB_SCOPED_TIMERF(FMT, ...)                                           \
   static ::lldb_private::Timer::Category _cat(LLVM_PRETTY_FUNCTION);           \
-  ::lldb_private::Timer _scoped_timer(_cat, __VA_ARGS__)
+  ::lldb_private::Timer _scoped_timer(_cat, FMT, __VA_ARGS__);                 \
+  SIGNPOST_EMITTER_START_INTERVAL(::lldb_private::GetSignposts(),              \
+                                  &_scoped_timer, FMT, __VA_ARGS__);           \
+  auto _scoped_signpost = llvm::make_scope_exit([&_scoped_timer]() {           \
+    ::lldb_private::GetSignposts().endInterval(&_scoped_timer);                \
+  })
 
 #endif // LLDB_UTILITY_TIMER_H

lldb/source/Plugins/ObjectFile/Mach-O/ObjectFileMachO.cpp

@@ -65,6 +65,63 @@
 #include <memory>
 
 // Unfortunately the signpost header pulls in the system MachO header, too.
+#ifdef MH_MAGIC
+#undef MH_MAGIC
+#endif
+#ifdef MH_CIGAM
+#undef MH_CIGAM
+#endif
+#ifdef MH_MAGIC_64
+#undef MH_MAGIC_64
+#endif
+#ifdef MH_CIGAM_64
+#undef MH_CIGAM_64
+#endif
+#ifdef MH_OBJECT
+#undef MH_OBJECT
+#endif
+#ifdef MH_EXECUTE
+#undef MH_EXECUTE
+#endif
+#ifdef MH_FVMLIB
+#undef MH_FVMLIB
+#endif
+#ifdef MH_CORE
+#undef MH_CORE
+#endif
+#ifdef MH_PRELOAD
+#undef MH_PRELOAD
+#endif
+#ifdef MH_DYLIB
+#undef MH_DYLIB
+#endif
+#ifdef MH_DYLINKER
+#undef MH_DYLINKER
+#endif
+#ifdef MH_DYLIB_STUB
+#undef MH_DYLIB_STUB
+#endif
+#ifdef MH_DSYM
+#undef MH_DSYM
+#endif
+#ifdef MH_BUNDLE
+#undef MH_BUNDLE
+#endif
+#ifdef MH_KEXT_BUNDLE
+#undef MH_KEXT_BUNDLE
+#endif
+#ifdef MH_NOUNDEFS
+#undef MH_NOUNDEFS
+#endif
+#ifdef MH_INCRLINK
+#undef MH_INCRLINK
+#endif
+#ifdef MH_DYLDLINK
+#undef MH_DYLDLINK
+#endif
+#ifdef MH_BINDATLOAD
+#undef MH_BINDATLOAD
+#endif
 #ifdef CPU_TYPE_ARM
 #undef CPU_TYPE_ARM
 #endif

lldb/source/Utility/Timer.cpp

@@ -33,6 +33,8 @@ static std::atomic<Timer::Category *> g_categories;
 /// Allows llvm::Timer to emit signposts when supported.
 static llvm::ManagedStatic<llvm::SignpostEmitter> Signposts;
 
+llvm::SignpostEmitter &lldb_private::GetSignposts() { return *Signposts; }
+
 std::atomic<bool> Timer::g_quiet(true);
 std::atomic<unsigned> Timer::g_display_depth(0);
 static std::mutex &GetFileMutex() {
@@ -59,7 +61,6 @@ void Timer::SetQuiet(bool value) { g_quiet = value; }
 
 Timer::Timer(Timer::Category &category, const char *format, ...)
     : m_category(category), m_total_start(std::chrono::steady_clock::now()) {
-  Signposts->startInterval(this, m_category.GetName());
   TimerStack &stack = GetTimerStackForCurrentThread();
 
   stack.push_back(this);
@@ -86,8 +87,6 @@ Timer::~Timer() {
   auto total_dur = stop_time - m_total_start;
   auto timer_dur = total_dur - m_child_duration;
 
-  Signposts->endInterval(this, m_category.GetName());
-
   TimerStack &stack = GetTimerStackForCurrentThread();
   if (g_quiet && stack.size() <= g_display_depth) {
     std::lock_guard<std::mutex> lock(GetFileMutex());

llvm/include/llvm/Support/Signposts.h

@@ -18,8 +18,17 @@
 #define LLVM_SUPPORT_SIGNPOSTS_H
 
 #include "llvm/ADT/StringRef.h"
+#include "llvm/Config/config.h"
 #include <memory>
 
+#if LLVM_SUPPORT_XCODE_SIGNPOSTS
+#include <Availability.h>
+#include <os/signpost.h>
+#endif
+
+#define SIGNPOSTS_AVAILABLE()                                                  \
+  __builtin_available(macos 10.14, iOS 12, tvOS 12, watchOS 5, *)
+
 namespace llvm {
 class SignpostEmitterImpl;
 
@@ -36,8 +45,33 @@ public:
 
   /// Begin a signposted interval for a given object.
   void startInterval(const void *O, StringRef Name);
+
+#if LLVM_SUPPORT_XCODE_SIGNPOSTS
+  os_log_t &getLogger() const;
+  os_signpost_id_t getSignpostForObject(const void *O);
+#endif
+
+  /// A macro to take advantage of the special format string handling
+  /// in the os_signpost API. The format string substitution is
+  /// deferred to the log consumer and done outside of the
+  /// application.
+#if LLVM_SUPPORT_XCODE_SIGNPOSTS
+#define SIGNPOST_EMITTER_START_INTERVAL(SIGNPOST_EMITTER, O, ...)              \
+  do {                                                                         \
+    if ((SIGNPOST_EMITTER).isEnabled())                                        \
+      if (SIGNPOSTS_AVAILABLE())                                               \
+        os_signpost_interval_begin((SIGNPOST_EMITTER).getLogger(),             \
+                                   (SIGNPOST_EMITTER).getSignpostForObject(O), \
+                                   "LLVM Timers", __VA_ARGS__);                \
+  } while (0)
+#else
+#define SIGNPOST_EMITTER_START_INTERVAL(SIGNPOST_EMITTER, O, ...)              \
+  do {                                                                         \
+  } while (0)
+#endif
+
   /// End a signposted interval for a given object.
-  void endInterval(const void *O, StringRef Name);
+  void endInterval(const void *O);
 };
 
 } // end namespace llvm

llvm/lib/Support/Signposts.cpp

@@ -10,19 +10,14 @@
 #include "llvm/Support/Signposts.h"
 #include "llvm/Support/Timer.h"
 
-#include "llvm/Config/config.h"
 #if LLVM_SUPPORT_XCODE_SIGNPOSTS
 #include "llvm/ADT/DenseMap.h"
 #include "llvm/Support/Mutex.h"
-#include <Availability.h>
-#include <os/signpost.h>
 #endif // if LLVM_SUPPORT_XCODE_SIGNPOSTS
 
 using namespace llvm;
 
 #if LLVM_SUPPORT_XCODE_SIGNPOSTS
-#define SIGNPOSTS_AVAILABLE()                                                  \
-  __builtin_available(macos 10.14, iOS 12, tvOS 12, watchOS 5, *)
 namespace {
 os_log_t *LogCreator() {
   os_log_t *X = new os_log_t;
@@ -40,13 +35,13 @@ struct LogDeleter {
 namespace llvm {
 class SignpostEmitterImpl {
   using LogPtrTy = std::unique_ptr<os_log_t, LogDeleter>;
-  using LogTy = LogPtrTy::element_type;
 
   LogPtrTy SignpostLog;
   DenseMap<const void *, os_signpost_id_t> Signposts;
   sys::SmartMutex<true> Mutex;
 
-  LogTy &getLogger() const { return *SignpostLog; }
+public:
+  os_log_t &getLogger() const { return *SignpostLog; }
   os_signpost_id_t getSignpostForObject(const void *O) {
     sys::SmartScopedLock<true> Lock(Mutex);
     const auto &I = Signposts.find(O);
@@ -60,7 +55,6 @@ class SignpostEmitterImpl {
     return Inserted.first->second;
   }
 
-public:
   SignpostEmitterImpl() : SignpostLog(LogCreator()) {}
 
   bool isEnabled() const {
@@ -79,7 +73,7 @@ public:
     }
   }
 
-  void endInterval(const void *O, llvm::StringRef Name) {
+  void endInterval(const void *O) {
     if (isEnabled()) {
       if (SIGNPOSTS_AVAILABLE()) {
         // Both strings used here are required to be constant literal strings.
@@ -125,10 +119,17 @@ void SignpostEmitter::startInterval(const void *O, StringRef Name) {
 #endif // if !HAVE_ANY_SIGNPOST_IMPL
 }
 
-void SignpostEmitter::endInterval(const void *O, StringRef Name) {
+#if HAVE_ANY_SIGNPOST_IMPL
+os_log_t &SignpostEmitter::getLogger() const { return Impl->getLogger(); }
+os_signpost_id_t SignpostEmitter::getSignpostForObject(const void *O) {
+  return Impl->getSignpostForObject(O);
+}
+#endif
+
+void SignpostEmitter::endInterval(const void *O) {
 #if HAVE_ANY_SIGNPOST_IMPL
   if (Impl == nullptr)
     return;
-  Impl->endInterval(O, Name);
+  Impl->endInterval(O);
 #endif // if !HAVE_ANY_SIGNPOST_IMPL
 }

llvm/lib/Support/Timer.cpp

@@ -174,7 +174,7 @@ void Timer::stopTimer() {
   Running = false;
   Time += TimeRecord::getCurrentTime(false);
   Time -= StartTime;
-  Signposts->endInterval(this, getName());
+  Signposts->endInterval(this);
 }
 
 void Timer::clear() {