Skip to content

Commit 4df069e

Browse files
committed
[Timers] Add a flag to set a minimum timer value for printing
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.
1 parent cccb4fc commit 4df069e

File tree

2 files changed

+67
-15
lines changed

2 files changed

+67
-15
lines changed

llvm/lib/Support/Timer.cpp

Lines changed: 28 additions & 10 deletions
Original file line numberDiff line numberDiff line change
@@ -53,6 +53,7 @@ class Name2PairMap;
5353
static std::string &libSupportInfoOutputFilename();
5454
static bool trackSpace();
5555
static bool sortTimers();
56+
cl::opt<unsigned> &minPrintTime();
5657
[[maybe_unused]]
5758
static SignpostEmitter &signposts();
5859
static sys::SmartMutex<true> &timerLock();
@@ -380,8 +381,12 @@ void TimerGroup::PrintQueuedTimers(raw_ostream &OS) {
380381

381382
// Loop through all of the timing data, printing it out.
382383
for (const PrintRecord &Record : llvm::reverse(TimersToPrint)) {
383-
Record.Time.print(Total, OS);
384-
OS << Record.Description << '\n';
384+
if (const TimeRecord &TR = Record.Time; TR.getUserTime() >= minPrintTime() ||
385+
TR.getSystemTime() >= minPrintTime() ||
386+
TR.getWallTime() >= minPrintTime()) {
387+
Record.Time.print(Total, OS);
388+
OS << Record.Description << '\n';
389+
}
385390
}
386391

387392
Total.print(Total, OS);
@@ -452,22 +457,31 @@ const char *TimerGroup::printJSONValues(raw_ostream &OS, const char *delim) {
452457

453458
prepareToPrintList(false);
454459
for (const PrintRecord &R : TimersToPrint) {
455-
OS << delim;
456-
delim = ",\n";
457-
458460
const TimeRecord &T = R.Time;
459-
printJSONValue(OS, R, ".wall", T.getWallTime());
460-
OS << delim;
461-
printJSONValue(OS, R, ".user", T.getUserTime());
462-
OS << delim;
463-
printJSONValue(OS, R, ".sys", T.getSystemTime());
461+
if (double Value = T.getWallTime(); Value >= minPrintTime()) {
462+
OS << delim;
463+
printJSONValue(OS, R, ".wall", Value);
464+
delim = ",\n";
465+
}
466+
if (double Value = T.getWallTime(); Value >= minPrintTime()) {
467+
OS << delim;
468+
printJSONValue(OS, R, ".user", T.getUserTime());
469+
delim = ",\n";
470+
}
471+
if (double Value = T.getWallTime(); Value >= minPrintTime()) {
472+
OS << delim;
473+
printJSONValue(OS, R, ".sys", T.getSystemTime());
474+
delim = ",\n";
475+
}
464476
if (T.getMemUsed()) {
465477
OS << delim;
466478
printJSONValue(OS, R, ".mem", T.getMemUsed());
479+
delim = ",\n";
467480
}
468481
if (T.getInstructionsExecuted()) {
469482
OS << delim;
470483
printJSONValue(OS, R, ".instr", T.getInstructionsExecuted());
484+
delim = ",\n";
471485
}
472486
}
473487
TimersToPrint.clear();
@@ -515,6 +529,9 @@ class llvm::TimerGlobals {
515529
cl::desc("In the report, sort the timers in each group in wall clock"
516530
" time order"),
517531
cl::init(true), cl::Hidden};
532+
cl::opt<unsigned> MinPrintTime{
533+
"min-print-time",
534+
cl::desc("Minimum time in seconds for a timer to be printed"), cl::init(0)};
518535

519536
sys::SmartMutex<true> TimerLock;
520537
TimerGroup DefaultTimerGroup{"misc", "Miscellaneous Ungrouped Timers",
@@ -541,6 +558,7 @@ static std::string &libSupportInfoOutputFilename() {
541558
}
542559
static bool trackSpace() { return ManagedTimerGlobals->TrackSpace; }
543560
static bool sortTimers() { return ManagedTimerGlobals->SortTimers; }
561+
cl::opt<unsigned> &minPrintTime() { return ManagedTimerGlobals->MinPrintTime; }
544562
static SignpostEmitter &signposts() { return ManagedTimerGlobals->Signposts; }
545563
static sys::SmartMutex<true> &timerLock() {
546564
return ManagedTimerGlobals->TimerLock;

llvm/unittests/Support/TimerTest.cpp

Lines changed: 39 additions & 5 deletions
Original file line numberDiff line numberDiff line change
@@ -7,6 +7,8 @@
77
//===----------------------------------------------------------------------===//
88

99
#include "llvm/Support/Timer.h"
10+
#include "llvm/Support/CommandLine.h"
11+
#include "gmock/gmock.h"
1012
#include "gtest/gtest.h"
1113

1214
#if _WIN32
@@ -17,18 +19,20 @@
1719

1820
using namespace llvm;
1921

22+
cl::opt<unsigned> &minPrintTime();
23+
2024
namespace {
2125

2226
// FIXME: Put this somewhere in Support, it's also used in LockFileManager.
23-
void SleepMS() {
27+
void SleepMS(int ms = 1) {
2428
#if _WIN32
25-
Sleep(1);
29+
Sleep(ms);
2630
#else
2731
struct timespec Interval;
28-
Interval.tv_sec = 0;
29-
Interval.tv_nsec = 1000000;
32+
Interval.tv_sec = ms / 1000;
33+
Interval.tv_nsec = 1000000 * (ms % 1000);
3034
#if defined(__MVS__)
31-
long Microseconds = (Interval.tv_nsec + 999) / 1000;
35+
long Microseconds = (Interval.tv_nsec + Interval.tv_sec * 1000 + 999) / 1000;
3236
usleep(Microseconds);
3337
#else
3438
nanosleep(&Interval, nullptr);
@@ -82,4 +86,34 @@ TEST(Timer, TimerGroupTimerDestructed) {
8286
EXPECT_FALSE(testing::internal::GetCapturedStderr().empty());
8387
}
8488

89+
TEST(Timer, MinTimerFlag) {
90+
testing::internal::CaptureStderr();
91+
92+
Timer T1("T1", "T1");
93+
Timer T2("T2", "T2");
94+
95+
minPrintTime().setValue(2);
96+
97+
T1.startTimer();
98+
T2.startTimer();
99+
100+
SleepMS(1000);
101+
T1.stopTimer();
102+
103+
SleepMS(2000);
104+
T2.stopTimer();
105+
106+
TimerGroup::printAll(llvm::errs());
107+
std::string stderr = testing::internal::GetCapturedStderr();
108+
EXPECT_THAT(stderr, testing::HasSubstr("T2"));
109+
EXPECT_THAT(stderr, testing::Not(testing::HasSubstr("T1")));
110+
111+
testing::internal::CaptureStderr();
112+
113+
TimerGroup::printAllJSONValues(llvm::errs(), "");
114+
stderr = testing::internal::GetCapturedStderr();
115+
EXPECT_THAT(stderr, testing::HasSubstr("T2.wall"));
116+
EXPECT_THAT(stderr, testing::Not(testing::HasSubstr("T1.wall")));
117+
}
118+
85119
} // namespace

0 commit comments

Comments
 (0)