[Timer] On macOS count number of executed instructions

[ahoppen]

Summary

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

[ahoppen]

Fixed an issue caused by me using an old revions as the commit's base.

[JDevlieghere]

Seems useful! LGTM.

[thakis]

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

356

Any reason to use #cmakedefine instead of cmakedefine01 here? This type of check usually uses #cmakedefine01 in this file.

[thakis]

llvm/CMakeLists.txt

656

also, any reason to not do this in llvm/cmake/config-ix.cmake where all the other checks like this are?

[thakis]

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

356

Please ignore this, #cmakedefine is what most other HAVE_ things use. I misremembered this.

[ahoppen]

llvm/CMakeLists.txt

656

No, I just didn't know about llvm/cmake/config-ix.cmake. I’ll move it there. Thanks!

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

 // CHECK-CONSOLE-NOT: ===-------------------------------------------------------------------------===
 
 // CHECK-FILE: {
 // CHECK-FILE-NEXT:"file": "{{.*}}clang-tidy-store-check-profile-one-tu.cpp",
 // CHECK-FILE-NEXT:"timestamp": "{{[0-9]+}}-{{[0-9]+}}-{{[0-9]+}} {{[0-9]+}}:{{[0-9]+}}:{{[0-9]+}}.{{[0-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: {
 // CHECK-FILE-NOT: "file": {{.*}}clang-tidy-store-check-profile-one-tu.cpp{{.*}},
 // CHECK-FILE-NOT: "timestamp": "{{[0-9]+}}-{{[0-9]+}}-{{[0-9]+}} {{[0-9]+}}:{{[0-9]+}}:{{[0-9]+}}.{{[0-9]+}}",
 // 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: }
 
 class A {
   A() {}
   ~A() {}
 };

llvm/CMakeLists.txt

if (LLVM_BUILD_STATIC)
   foreach (shared_lib_suffix ${CMAKE_SHARED_LIBRARY_SUFFIX} ${CMAKE_IMPORT_LIBRARY_SUFFIX})
     list(FIND CMAKE_FIND_LIBRARY_SUFFIXES ${shared_lib_suffix} shared_lib_suffix_idx)
     if(NOT ${shared_lib_suffix_idx} EQUAL -1)
       list(REMOVE_AT CMAKE_FIND_LIBRARY_SUFFIXES ${shared_lib_suffix_idx})
     endif()
   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)
 endif()
 
 # Override the default target with an environment variable named by LLVM_TARGET_TRIPLE_ENV.
 set(LLVM_TARGET_TRIPLE_ENV CACHE STRING "The name of environment variable to override default target. Disabled by blank.")
 mark_as_advanced(LLVM_TARGET_TRIPLE_ENV)

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

 #cmakedefine01 LLVM_GISEL_COV_ENABLED
 
 /* Define to the default GlobalISel coverage file prefix */
 #cmakedefine LLVM_GISEL_COV_PREFIX "${LLVM_GISEL_COV_PREFIX}"
 
 /* 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

 
 namespace llvm {
 
 class Timer;
 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
   /// matters if the time to get the memory usage is significant and shouldn't
   /// be counted as part of a duration.
   static TimeRecord getCurrentTime(bool Start = true);
 
   double getProcessTime() const { return UserTime + SystemTime; }
   double getUserTime() const { return UserTime; }
   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
   /// contributions to the \p Total time record.
   void print(const TimeRecord &Total, raw_ostream &OS) const;
 };
 
 /// This class is used to track the amount of time spent between invocations of

llvm/lib/Support/Timer.cpp

 //===-- Timer.cpp - Interval Timing Support -------------------------------===//
 //
 // Part of the LLVM Project, under the Apache License v2.0 with LLVM Exceptions.
 // See https://llvm.org/LICENSE.txt for license information.
 // SPDX-License-Identifier: Apache-2.0 WITH LLVM-exception
 //
 //===----------------------------------------------------------------------===//
 //
 /// \file Interval Timing implementation.
 //
 //===----------------------------------------------------------------------===//
 
 #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"
 #include "llvm/Support/ManagedStatic.h"
 #include "llvm/Support/Mutex.h"
 #include "llvm/Support/Process.h"
 #include "llvm/Support/Signposts.h"
 #include "llvm/Support/YAMLTraits.h"
 #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
 // being unspecified by C++.  Basically the problem is that a Statistic object
 // gets destroyed, which ends up calling 'GetLibSupportInfoOutputFile()'
 // (below), which calls this function.  LibSupportInfoOutputFilename used to be
 // a global variable, but sometimes it would get destroyed before the Statistic,
 // causing havoc to ensue.  We "fix" this by creating the string the first time
Timer::~Timer() {
   TG->removeTimer(*this);
 }
 
 static inline size_t getMemUsage() {
   if (!TrackSpace) return 0;
   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;
   sys::TimePoint<> now;
   std::chrono::nanoseconds user, sys;
 
   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();
   }
 
   Result.WallTime = Seconds(now.time_since_epoch()).count();
   Result.UserTime = Seconds(user).count();
   Result.SystemTime = Seconds(sys).count();
   return Result;
 }
void TimeRecord::print(const TimeRecord &Total, raw_ostream &OS) const {
   if (Total.getProcessTime())
     printVal(getProcessTime(), Total.getProcessTime(), OS);
   printVal(getWallTime(), Total.getWallTime(), OS);
 
   OS << "  ";
 
   if (Total.getMemUsed())
     OS << format("%9" PRId64 "  ", (int64_t)getMemUsed());
+  if (Total.getInstructionsExecuted())
+    OS << format("%9" PRId64 "  ", (int64_t)getInstructionsExecuted());
 }
 
 
 //===----------------------------------------------------------------------===//
 //   NamedRegionTimer Implementation
 //===----------------------------------------------------------------------===//
 
 namespace {
if (Total.getUserTime())
     OS << "   ---User Time---";
   if (Total.getSystemTime())
     OS << "   --System Time--";
   if (Total.getProcessTime())
     OS << "   --User+System--";
   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.
   for (const PrintRecord &Record : make_range(TimersToPrint.rbegin(),
                                               TimersToPrint.rend())) {
     Record.Time.print(Total, OS);
     OS << Record.Description << '\n';
   }
for (const PrintRecord &R : TimersToPrint) {
     OS << delim;
     printJSONValue(OS, R, ".user", T.getUserTime());
     OS << delim;
     printJSONValue(OS, R, ".sys", T.getSystemTime());
     if (T.getMemUsed()) {
       OS << delim;
       printJSONValue(OS, R, ".mem", T.getMemUsed());
     }
+    if (T.getInstructionsExecuted()) {
+      OS << delim;
+      printJSONValue(OS, R, ".instr", T.getInstructionsExecuted());
+    }
   }
   TimersToPrint.clear();
   return delim;
 }
 
 const char *TimerGroup::printAllJSONValues(raw_ostream &OS, const char *delim) {
   sys::SmartScopedLock<true> L(*TimerLock);
   for (TimerGroup *TG = TimerGroupList; TG; TG = TG->Next)