[Timer] On macOS count number of executed instructions

In addition to wall time etc. this should allow us to get less noisy
values for time measurements.

Reviewed By: JDevlieghere

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

Author: ahoppen

clang-tools-extra/test/clang-tidy/infrastructure/clang-tidy-store-check-profile-one-tu.cpp

@@ -17,8 +17,9 @@
 // CHECK-FILE-NEXT:"profile": {
 // CHECK-FILE-NEXT:	"time.clang-tidy.readability-function-size.wall": {{.*}}{{[0-9]}}.{{[0-9]+}}e{{[-+]}}{{[0-9]}}{{[0-9]}},
 // CHECK-FILE-NEXT:	"time.clang-tidy.readability-function-size.user": {{.*}}{{[0-9]}}.{{[0-9]+}}e{{[-+]}}{{[0-9]}}{{[0-9]}},
-// CHECK-FILE-NEXT:	"time.clang-tidy.readability-function-size.sys": {{.*}}{{[0-9]}}.{{[0-9]+}}e{{[-+]}}{{[0-9]}}{{[0-9]}}
-// CHECK-FILE-NEXT: }
+// CHECK-FILE-NEXT:	"time.clang-tidy.readability-function-size.sys": {{.*}}{{[0-9]}}.{{[0-9]+}}e{{[-+]}}{{[0-9]}}{{[0-9]}}{{,?}}
+// If available on the platform, we also have a "time.clang-tidy.readability-function-size.instr" entry
+// CHECK-FILE: }
 // CHECK-FILE-NEXT: }
 
 // CHECK-FILE-NOT: {
@@ -27,7 +28,7 @@
 // CHECK-FILE-NOT: "profile": {
 // CHECK-FILE-NOT:	"time.clang-tidy.readability-function-size.wall": {{.*}}{{[0-9]}}.{{[0-9]+}}e{{[-+]}}{{[0-9]}}{{[0-9]}},
 // CHECK-FILE-NOT:	"time.clang-tidy.readability-function-size.user": {{.*}}{{[0-9]}}.{{[0-9]+}}e{{[-+]}}{{[0-9]}}{{[0-9]}},
-// CHECK-FILE-NOT:	"time.clang-tidy.readability-function-size.sys": {{.*}}{{[0-9]}}.{{[0-9]+}}e{{[-+]}}{{[0-9]}}{{[0-9]}}
+// CHECK-FILE-NOT:	"time.clang-tidy.readability-function-size.sys": {{.*}}{{[0-9]}}.{{[0-9]+}}e{{[-+]}}{{[0-9]}}{{[0-9]}}{{,?}}
 // CHECK-FILE-NOT: }
 // CHECK-FILE-NOT: }
 

llvm/CMakeLists.txt

@@ -649,6 +649,12 @@ if (LLVM_BUILD_STATIC)
   endforeach()
 endif()
 
+include(CheckSymbolExists)
+check_symbol_exists(proc_pid_rusage "libproc.h" HAVE_PROC_PID_RUSAGE)
+if(HAVE_PROC_PID_RUSAGE)
+  list(APPEND CMAKE_REQUIRED_LIBRARIES proc)
+endif()
+
 # Use libtool instead of ar if you are both on an Apple host, and targeting Apple.
 if(CMAKE_HOST_APPLE AND APPLE)
   include(UseLibtool)

llvm/include/llvm/Config/config.h.cmake

@@ -353,4 +353,6 @@
 /* Whether Timers signpost passes in Xcode Instruments */
 #cmakedefine01 LLVM_SUPPORT_XCODE_SIGNPOSTS
 
+#cmakedefine HAVE_PROC_PID_RUSAGE 1
+
 #endif

llvm/include/llvm/Support/Timer.h

@@ -24,12 +24,15 @@ class TimerGroup;
 class raw_ostream;
 
 class TimeRecord {
-  double WallTime;       ///< Wall clock time elapsed in seconds.
-  double UserTime;       ///< User time elapsed.
-  double SystemTime;     ///< System time elapsed.
-  ssize_t MemUsed;       ///< Memory allocated (in bytes).
+  double WallTime;               ///< Wall clock time elapsed in seconds.
+  double UserTime;               ///< User time elapsed.
+  double SystemTime;             ///< System time elapsed.
+  ssize_t MemUsed;               ///< Memory allocated (in bytes).
+  uint64_t InstructionsExecuted; ///< Number of instructions executed
 public:
-  TimeRecord() : WallTime(0), UserTime(0), SystemTime(0), MemUsed(0) {}
+  TimeRecord()
+      : WallTime(0), UserTime(0), SystemTime(0), MemUsed(0),
+        InstructionsExecuted(0) {}
 
   /// Get the current time and memory usage.  If Start is true we get the memory
   /// usage before the time, otherwise we get time before memory usage.  This
@@ -42,23 +45,26 @@ class TimeRecord {
   double getSystemTime() const { return SystemTime; }
   double getWallTime() const { return WallTime; }
   ssize_t getMemUsed() const { return MemUsed; }
+  uint64_t getInstructionsExecuted() const { return InstructionsExecuted; }
 
   bool operator<(const TimeRecord &T) const {
     // Sort by Wall Time elapsed, as it is the only thing really accurate
     return WallTime < T.WallTime;
   }
 
   void operator+=(const TimeRecord &RHS) {
-    WallTime   += RHS.WallTime;
-    UserTime   += RHS.UserTime;
+    WallTime += RHS.WallTime;
+    UserTime += RHS.UserTime;
     SystemTime += RHS.SystemTime;
-    MemUsed    += RHS.MemUsed;
+    MemUsed += RHS.MemUsed;
+    InstructionsExecuted += RHS.InstructionsExecuted;
   }
   void operator-=(const TimeRecord &RHS) {
-    WallTime   -= RHS.WallTime;
-    UserTime   -= RHS.UserTime;
+    WallTime -= RHS.WallTime;
+    UserTime -= RHS.UserTime;
     SystemTime -= RHS.SystemTime;
-    MemUsed    -= RHS.MemUsed;
+    MemUsed -= RHS.MemUsed;
+    InstructionsExecuted -= RHS.InstructionsExecuted;
   }
 
   /// Print the current time record to \p OS, with a breakdown showing

llvm/lib/Support/Timer.cpp

@@ -13,6 +13,7 @@
 #include "llvm/Support/Timer.h"
 #include "llvm/ADT/Statistic.h"
 #include "llvm/ADT/StringMap.h"
+#include "llvm/Config/config.h"
 #include "llvm/Support/CommandLine.h"
 #include "llvm/Support/FileSystem.h"
 #include "llvm/Support/Format.h"
@@ -24,6 +25,14 @@
 #include "llvm/Support/raw_ostream.h"
 #include <limits>
 
+#if HAVE_UNISTD_H
+#include <unistd.h>
+#endif
+
+#ifdef HAVE_PROC_PID_RUSAGE
+#include <libproc.h>
+#endif
+
 using namespace llvm;
 
 // This ugly hack is brought to you courtesy of constructor/destructor ordering
@@ -120,6 +129,17 @@ static inline size_t getMemUsage() {
   return sys::Process::GetMallocUsage();
 }
 
+static uint64_t getCurInstructionsExecuted() {
+#if defined(HAVE_UNISTD_H) && defined(HAVE_PROC_PID_RUSAGE) &&                 \
+    defined(RUSAGE_INFO_V4)
+  struct rusage_info_v4 ru;
+  if (proc_pid_rusage(getpid(), RUSAGE_INFO_V4, (rusage_info_t *)&ru) == 0) {
+    return ru.ri_instructions;
+  }
+#endif
+  return 0;
+}
+
 TimeRecord TimeRecord::getCurrentTime(bool Start) {
   using Seconds = std::chrono::duration<double, std::ratio<1>>;
   TimeRecord Result;
@@ -128,9 +148,11 @@ TimeRecord TimeRecord::getCurrentTime(bool Start) {
 
   if (Start) {
     Result.MemUsed = getMemUsage();
+    Result.InstructionsExecuted = getCurInstructionsExecuted();
     sys::Process::GetTimeUsage(now, user, sys);
   } else {
     sys::Process::GetTimeUsage(now, user, sys);
+    Result.InstructionsExecuted = getCurInstructionsExecuted();
     Result.MemUsed = getMemUsage();
   }
 
@@ -180,6 +202,8 @@ void TimeRecord::print(const TimeRecord &Total, raw_ostream &OS) const {
 
   if (Total.getMemUsed())
     OS << format("%9" PRId64 "  ", (int64_t)getMemUsed());
+  if (Total.getInstructionsExecuted())
+    OS << format("%9" PRId64 "  ", (int64_t)getInstructionsExecuted());
 }
 
 
@@ -339,6 +363,8 @@ void TimerGroup::PrintQueuedTimers(raw_ostream &OS) {
   OS << "   ---Wall Time---";
   if (Total.getMemUsed())
     OS << "  ---Mem---";
+  if (Total.getInstructionsExecuted())
+    OS << "  ---Instr---";
   OS << "  --- Name ---\n";
 
   // Loop through all of the timing data, printing it out.
@@ -433,6 +459,10 @@ const char *TimerGroup::printJSONValues(raw_ostream &OS, const char *delim) {
       OS << delim;
       printJSONValue(OS, R, ".mem", T.getMemUsed());
     }
+    if (T.getInstructionsExecuted()) {
+      OS << delim;
+      printJSONValue(OS, R, ".instr", T.getInstructionsExecuted());
+    }
   }
   TimersToPrint.clear();
   return delim;