[Timers] Add a flag to set a minimum timer value for printing

[alanzhao1]

The new LLVM flag -timer-min-print-time is the number of seconds a timer must have in order for its value to be printed in either JSON or human readable formatting. This may be used, for example, with Clang's -ftime-report to reduce its output size by not printing insignificant values.

The default value of this flag is 0 which retains the current behavior of printing all timer values.

[llvmbot]

@llvm/pr-subscribers-llvm-support

Author: Alan Zhao (alanzhao1)

Changes

The new LLVM flag -min-print-time is the number of seconds a timer must have in order for its value to be printed in either JSON or human readable formatting. This may be used, for example, with Clang's -ftime-report to reduce its output size by not printing insignificant values.

The default value of this flag is 0 which retains the current behavior of printing all timer values.

---

Full diff: https://github.com/llvm/llvm-project/pull/139306.diff

2 Files Affected:

• (modified) llvm/lib/Support/Timer.cpp (+28-10)
• (modified) llvm/unittests/Support/TimerTest.cpp (+39-5)

diff --git a/llvm/lib/Support/Timer.cpp b/llvm/lib/Support/Timer.cpp
index 22811d7b4af0a..9cc22fbb8bc38 100644
--- a/llvm/lib/Support/Timer.cpp
+++ b/llvm/lib/Support/Timer.cpp
@@ -53,6 +53,7 @@ class Name2PairMap;
 static std::string &libSupportInfoOutputFilename();
 static bool trackSpace();
 static bool sortTimers();
+cl::opt<unsigned> &minPrintTime();
 [[maybe_unused]]
 static SignpostEmitter &signposts();
 static sys::SmartMutex<true> &timerLock();
@@ -380,8 +381,12 @@ void TimerGroup::PrintQueuedTimers(raw_ostream &OS) {
 
   // Loop through all of the timing data, printing it out.
   for (const PrintRecord &Record : llvm::reverse(TimersToPrint)) {
-    Record.Time.print(Total, OS);
-    OS << Record.Description << '\n';
+    if (const TimeRecord &TR = Record.Time; TR.getUserTime() >= minPrintTime() ||
+                                            TR.getSystemTime() >= minPrintTime() ||
+                                            TR.getWallTime() >= minPrintTime()) {
+      Record.Time.print(Total, OS);
+      OS << Record.Description << '\n';
+    }
   }
 
   Total.print(Total, OS);
@@ -452,22 +457,31 @@ const char *TimerGroup::printJSONValues(raw_ostream &OS, const char *delim) {
 
   prepareToPrintList(false);
   for (const PrintRecord &R : TimersToPrint) {
-    OS << delim;
-    delim = ",\n";
-
     const TimeRecord &T = R.Time;
-    printJSONValue(OS, R, ".wall", T.getWallTime());
-    OS << delim;
-    printJSONValue(OS, R, ".user", T.getUserTime());
-    OS << delim;
-    printJSONValue(OS, R, ".sys", T.getSystemTime());
+    if (double Value = T.getWallTime(); Value >= minPrintTime()) {
+      OS << delim;
+      printJSONValue(OS, R, ".wall", Value);
+      delim = ",\n";
+    }
+    if (double Value = T.getWallTime(); Value >= minPrintTime()) {
+      OS << delim;
+      printJSONValue(OS, R, ".user", T.getUserTime());
+      delim = ",\n";
+    }
+    if (double Value = T.getWallTime(); Value >= minPrintTime()) {
+      OS << delim;
+      printJSONValue(OS, R, ".sys", T.getSystemTime());
+      delim = ",\n";
+    }
     if (T.getMemUsed()) {
       OS << delim;
       printJSONValue(OS, R, ".mem", T.getMemUsed());
+      delim = ",\n";
     }
     if (T.getInstructionsExecuted()) {
       OS << delim;
       printJSONValue(OS, R, ".instr", T.getInstructionsExecuted());
+      delim = ",\n";
     }
   }
   TimersToPrint.clear();
@@ -515,6 +529,9 @@ class llvm::TimerGlobals {
       cl::desc("In the report, sort the timers in each group in wall clock"
                " time order"),
       cl::init(true), cl::Hidden};
+  cl::opt<unsigned> MinPrintTime{
+      "min-print-time",
+      cl::desc("Minimum time in seconds for a timer to be printed"), cl::init(0)};
 
   sys::SmartMutex<true> TimerLock;
   TimerGroup DefaultTimerGroup{"misc", "Miscellaneous Ungrouped Timers",
@@ -541,6 +558,7 @@ static std::string &libSupportInfoOutputFilename() {
 }
 static bool trackSpace() { return ManagedTimerGlobals->TrackSpace; }
 static bool sortTimers() { return ManagedTimerGlobals->SortTimers; }
+cl::opt<unsigned> &minPrintTime() { return ManagedTimerGlobals->MinPrintTime; }
 static SignpostEmitter &signposts() { return ManagedTimerGlobals->Signposts; }
 static sys::SmartMutex<true> &timerLock() {
   return ManagedTimerGlobals->TimerLock;
diff --git a/llvm/unittests/Support/TimerTest.cpp b/llvm/unittests/Support/TimerTest.cpp
index 612fd7231da70..0eb81f07bed5a 100644
--- a/llvm/unittests/Support/TimerTest.cpp
+++ b/llvm/unittests/Support/TimerTest.cpp
@@ -7,6 +7,8 @@
 //===----------------------------------------------------------------------===//
 
 #include "llvm/Support/Timer.h"
+#include "llvm/Support/CommandLine.h"
+#include "gmock/gmock.h"
 #include "gtest/gtest.h"
 
 #if _WIN32
@@ -17,18 +19,20 @@
 
 using namespace llvm;
 
+cl::opt<unsigned> &minPrintTime();
+
 namespace {
 
 // FIXME: Put this somewhere in Support, it's also used in LockFileManager.
-void SleepMS() {
+void SleepMS(int ms = 1) {
 #if _WIN32
-  Sleep(1);
+  Sleep(ms);
 #else
   struct timespec Interval;
-  Interval.tv_sec = 0;
-  Interval.tv_nsec = 1000000;
+  Interval.tv_sec = ms / 1000;
+  Interval.tv_nsec = 1000000 * (ms % 1000);
 #if defined(__MVS__)
-  long Microseconds = (Interval.tv_nsec + 999) / 1000;
+  long Microseconds = (Interval.tv_nsec + Interval.tv_sec * 1000 + 999) / 1000;
   usleep(Microseconds);
 #else
   nanosleep(&Interval, nullptr);
@@ -82,4 +86,34 @@ TEST(Timer, TimerGroupTimerDestructed) {
   EXPECT_FALSE(testing::internal::GetCapturedStderr().empty());
 }
 
+TEST(Timer, MinTimerFlag) {
+  testing::internal::CaptureStderr();
+
+  Timer T1("T1", "T1");
+  Timer T2("T2", "T2");
+
+  minPrintTime().setValue(2);
+
+  T1.startTimer();
+  T2.startTimer();
+
+  SleepMS(1000);
+  T1.stopTimer();
+
+  SleepMS(2000);
+  T2.stopTimer();
+
+  TimerGroup::printAll(llvm::errs());
+  std::string stderr = testing::internal::GetCapturedStderr();
+  EXPECT_THAT(stderr, testing::HasSubstr("T2"));
+  EXPECT_THAT(stderr, testing::Not(testing::HasSubstr("T1")));
+
+  testing::internal::CaptureStderr();
+
+  TimerGroup::printAllJSONValues(llvm::errs(), "");
+  stderr = testing::internal::GetCapturedStderr();
+  EXPECT_THAT(stderr, testing::HasSubstr("T2.wall"));
+  EXPECT_THAT(stderr, testing::Not(testing::HasSubstr("T1.wall")));
+}
+
 } // namespace

[github-actions]

✅ With the latest revision this PR passed the C/C++ code formatter.