[Support] Make llvm::Timer reusable

[vsk]

Summary

Make llvm::Timer reusable by allowing it to be started + stopped repeatedly.

This gets rid of an awkward static variable (ActiveTimers) and makes the API more flexible. It also adds a unittest, which I can extend in a later patch.

Rationale: In my use case, I have a long-running tool which periodically calls into llvm. I need to time a few regions multiple times. It makes life much easier to use a single Timer for this.

This patch also cleans up some documentation -- that will go in a separate NFC commit.

[vsk]

• Make TimerGroup use accessors instead of accessing Timer directly.
• Retain the old T.Started behavior with T.hasTriggered(). This checks whether the Timer has ever been started. Fixes -ftime-report behavior.

[vsk]

• Added unittest, made some cosmetic changes.
• Removed bruno and joker.eph as reviewers since they are on vacation, added chapuni.

[vsk]

I forgot to include the unittest in the previous diff.

[vsk]

• Make clear() reset the timer, instead of just the total time field.
• Fix up the unit test.

[vsk]

• Attached the complete diff this time.

[• rafael]

include/llvm/Support/Timer.h

65

Please drop the duplicated name.

106

Don't repeat the name in the comment.

107

Is this reliable? Will it return true in

Foo.startTimer();
Foo.hasTriggered();

That is, if hasTriggered is called immediately after the start.

[vsk]

• Used a new bool to implement hasTriggered() for simplicity.

include/llvm/Support/Timer.h

107

Yes it will return true in that scenario. I added a bool to make this clearer, and a CheckIfTriggered unit test.

[• rafael]

include/llvm/Support/Timer.h

83

Don't you have to set it to false in init()?

lib/Support/Timer.cpp

99

This is a nice independent cleanup. Please commit and rebase.

142

Deleting this is a nice independent cleanup. Please commit and rebase. Looks like it is dead since 99841.

147

These two lines are just:

+= (TimeRecord::getCurrentTime(false) - StartTime);

[vsk]

Thanks Rafael. Comments inline, updated diff coming --

lib/Support/Timer.cpp

142

This still prevents us from doing:

T.startTimer()
T.stopTimer()
T.stopTimer()

So I don't think it's dead.

147

There is no operator- for TimeRecord. Should we have one, and if so, is that a separate commit?

[vsk]

• Addressed Rafael's comments.
• Rebased to master.

[• rafael]

lib/Support/Timer.cpp

146

"Running" might be a better name for Started now.

152

The comment says "This does not affect the result of hasTriggered()."

[vsk]

• Style fixes per Rafael's comments.

[• rafael]

LGTM

[thakis]

If you can't fix this quickly, consider reverting.

unittests/Support/TimerTest.cpp

12

This doesn't build on Windows:

FAILED: C:\PROGRA~2\MICROS~1.0\VC\bin\cl.exe /nologo /TP /DWIN32 /D_WINDOWS -wd4141 -wd4146 -wd4180 -wd4244 -wd4258 -wd4267 -wd4291 -wd4345 -wd4351 -wd4355 -wd4456 -wd4457 -wd4458 -wd4459 -wd4503 -wd4624 -wd4722 -wd4800 -wd4100 -wd4127 -wd4512 -wd4505 -wd4610 -wd4510 -wd4702 -wd4245 -wd4706 -wd4310 -wd4701 -wd4703 -wd4389 -wd4611 -wd4805 -wd4204 -wd4577 -wd4091 -wd4592 -wd4324 -w14062 -we4238 /W4 /Zc:inline /MD /O2 /Ob2 -Iunittests\Support -IC:\buildbot\slave-config\clang-x86-win2008-selfhost\llvm\unittests\Support -Iinclude -IC:\buildbot\slave-config\clang-x86-win2008-selfhost\llvm\include -IC:\buildbot\slave-config\clang-x86-win2008-selfhost\llvm\utils\unittest\googletest\include -UNDEBUG /EHs-c- /GR- /showIncludes -DGTEST_HAS_RTTI=0 -D_CRT_NONSTDC_NO_DEPRECATE -D_CRT_NONSTDC_NO_WARNINGS -D_CRT_SECURE_NO_DEPRECATE -D_CRT_SECURE_NO_WARNINGS -D_DEBUG_POINTER_IMPL="" -D_HAS_EXCEPTIONS=0 -D_SCL_SECURE_NO_DEPRECATE -D_SCL_SECURE_NO_WARNINGS -DSTDC_CONSTANT_MACROS -DSTDC_FORMAT_MACROS -DSTDC_LIMIT_MACROS /Founittests\Support\CMakeFiles\SupportTests.dir\TimerTest.cpp.obj /Fdunittests\Support\CMakeFiles\SupportTests.dir\ /FS -c C:\buildbot\slave-config\clang-x86-win2008-selfhost\llvm\unittests\Support\TimerTest.cpp
C:\Program Files (x86)\Microsoft Visual Studio 12.0\VC\INCLUDE\concrt.h(313) : warning C4530: C++ exception handler used, but unwind semantics are not enabled. Specify /EHsc
C:\Program Files (x86)\Microsoft Visual Studio 12.0\VC\INCLUDE\concrt.h(4774) : error C3861: 'uncaught_exception': identifier not found

See the goop in include/llvm/Support/ThreadPool.h for what you probably need to do here.

[vsk]

unittests/Support/TimerTest.cpp

12

Sorry for the delay. I got bitten by hfs case-insensitivity in r256290, hopefully r256292 fixes things.

[thakis]

Now it fails to build on Linux for me:

FAILED: /usr/bin/g++ -DGTEST_HAS_PTHREAD=0 -DGTEST_HAS_RTTI=0 -D_DEBUG
-D_GNU_SOURCE -DSTDC_CONSTANT_MACROS -DSTDC_FORMAT_MACROS
-D__STDC_LIMIT_MACROS -fPIC -fvisibility-inlines-hidden -Wall -W
-Wno-unused-parameter -Wwrite-strings -Wcast-qual
-Wno-missing-field-initializers -pedantic -Wno-long-long
-Wno-maybe-uninitialized -Wdelete-non-virtual-dtor -Wno-comment -std=c++11
-ffunction-sections -fdata-sections -O3 -Iunittests/Support
-I/usr/local/google/home/thakis/src/chrome/src/third_party/llvm/unittests/Support
-Iinclude
-I/usr/local/google/home/thakis/src/chrome/src/third_party/llvm/include
-I/usr/local/google/home/thakis/src/chrome/src/third_party/llvm/utils/unittest/googletest/include

-UNDEBUG  -Wno-variadic-macros -fno-exceptions -fno-rtti -MMD -MT

unittests/Support/CMakeFiles/SupportTests.dir/TimerTest.cpp.o -MF
unittests/Support/CMakeFiles/SupportTests.dir/TimerTest.cpp.o.d -o
unittests/Support/CMakeFiles/SupportTests.dir/TimerTest.cpp.o -c
/usr/local/google/home/thakis/src/chrome/src/third_party/llvm/unittests/Support/TimerTest.cpp

chrome/src/third_party/llvm/unittests/Support/TimerTest.cpp:29:8: error:
‘std::this_thread’ has not been declared

std::this_thread::sleep_for(std::chrono::milliseconds(1));

[thakis]

...because llvm/Support/thread.h only includes <thread> if LLVM_ENABLE_THREADS is defined.

[thakis]

I tried to fix that problem in r256308. Maybe you can take a look at the FIXME in that revision.

[vsk]

More phab GC'ing.

include/llvm/Support/Timer.h

   }
   void operator-=(const TimeRecord &RHS) {
     WallTime   -= RHS.WallTime;
     UserTime   -= RHS.UserTime;
     SystemTime -= RHS.SystemTime;
     MemUsed    -= RHS.MemUsed;
   }
 
-  /// print - Print the current timer to standard error, and reset the "Started"
-  /// flag.
+  /// 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;
 };
 
 /// Timer - This class is used to track the amount of time spent between
 /// invocations of its startTimer()/stopTimer() methods.  Given appropriate OS
 /// support it can also keep track of the RSS of the program at various points.
 /// By default, the Timer will print the amount of time it has captured to
 /// standard error when the last timer is destroyed, otherwise it is printed
 /// when its TimerGroup is destroyed.  Timers do not print their information
 /// if they are never started.
 ///
 class Timer {
-  TimeRecord Time;
+  TimeRecord Time;       // The total time captured
+  TimeRecord StartTime;  // The time startTimer() was last called
   std::string Name;      // The name of this time variable.
-  bool Started;          // Has this time variable ever been started?
+  bool Running;          // Is the timer currently running?
+  bool Triggered;        // Has the timer ever been triggered?
   TimerGroup *TG;        // The TimerGroup this Timer is in.
 
   Timer **Prev, *Next;   // Doubly linked list of timers in the group.
 public:
   explicit Timer(StringRef N) : TG(nullptr) { init(N); }
   Timer(StringRef N, TimerGroup &tg) : TG(nullptr) { init(N, tg); }
   Timer(const Timer &RHS) : TG(nullptr) {
     assert(!RHS.TG && "Can only copy uninitialized timers");
   }
   const Timer &operator=(const Timer &T) {
     assert(!TG && !T.TG && "Can only assign uninit timers");
     return *this;
   }
   ~Timer();
 
   // Create an uninitialized timer, client must use 'init'.
   explicit Timer() : TG(nullptr) {}
   void init(StringRef N);
   void init(StringRef N, TimerGroup &tg);
 
   const std::string &getName() const { return Name; }
   bool isInitialized() const { return TG != nullptr; }
 
-  /// startTimer - Start the timer running.  Time between calls to
-  /// startTimer/stopTimer is counted by the Timer class.  Note that these calls
-  /// must be correctly paired.
-  ///
+  /// Check if startTimer() has ever been called on this timer.
+  bool hasTriggered() const { return Triggered; }
+
+  /// Start the timer running.  Time between calls to startTimer/stopTimer is
+  /// counted by the Timer class.  Note that these calls must be correctly
+  /// paired.
   void startTimer();
 
-  /// stopTimer - Stop the timer.
-  ///
+  /// Stop the timer.
   void stopTimer();
 
+  /// Clear the timer state.
+  void clear();
+
+  /// Return the duration for which this timer has been running.
+  TimeRecord getTotalTime() const { return Time; }
+
 private:
   friend class TimerGroup;
 };
 
 /// The TimeRegion class is used as a helper class to call the startTimer() and
 /// stopTimer() methods of the Timer class.  When the object is constructed, it
 /// starts the timer specified as its argument.  When it is destroyed, it stops
 /// the relevant timer.  This makes it easy to time a region of code.

lib/Support/Timer.cpp

   return tmp;
 }
 
 //===----------------------------------------------------------------------===//
 // Timer Implementation
 //===----------------------------------------------------------------------===//
 
 void Timer::init(StringRef N) {
   init(N, *getDefaultTimerGroup());
 }
 
 void Timer::init(StringRef N, TimerGroup &tg) {
   assert(!TG && "Timer already initialized");
   Name.assign(N.begin(), N.end());
-  Started = false;
+  Running = Triggered = false;
   TG = &tg;
   TG->addTimer(*this);
 }
 
 Timer::~Timer() {
   if (!TG) return;  // Never initialized, or already cleared.
   TG->removeTimer(*this);
 }

   }
 
   Result.WallTime   =  now.seconds() +  now.microseconds() / 1000000.0;
   Result.UserTime   = user.seconds() + user.microseconds() / 1000000.0;
   Result.SystemTime =  sys.seconds() +  sys.microseconds() / 1000000.0;
   return Result;
 }
 
-static ManagedStatic<std::vector<Timer*> > ActiveTimers;
-
 void Timer::startTimer() {
-  Started = true;
-  ActiveTimers->push_back(this);
-  Time -= TimeRecord::getCurrentTime(true);
+  assert(!Running && "Cannot start a running timer");
+  Running = Triggered = true;
+  StartTime = TimeRecord::getCurrentTime(true);
 }
 
 void Timer::stopTimer() {
+  assert(Running && "Cannot stop a paused timer");
+  Running = false;
   Time += TimeRecord::getCurrentTime(false);
+  Time -= StartTime;
+}
 
-  if (ActiveTimers->back() == this) {
-    ActiveTimers->pop_back();
-  } else {
-    std::vector<Timer*>::iterator I =
-      std::find(ActiveTimers->begin(), ActiveTimers->end(), this);
-    assert(I != ActiveTimers->end() && "stop but no startTimer?");
-    ActiveTimers->erase(I);
-  }
+void Timer::clear() {
+  Running = Triggered = false;
+  Time = StartTime = TimeRecord();
 }
 
 static void printVal(double Val, double Total, raw_ostream &OS) {
   if (Total < 1e-7)   // Avoid dividing by zero.
     OS << "        -----     ";
   else
     OS << format("  %7.4f (%5.1f%%)", Val, Val*100/Total);
 }

     Next->Prev = Prev;
 }
 
 
 void TimerGroup::removeTimer(Timer &T) {
   sys::SmartScopedLock<true> L(*TimerLock);
   
   // If the timer was started, move its data to TimersToPrint.
-  if (T.Started)
+  if (T.hasTriggered())
     TimersToPrint.emplace_back(T.Time, T.Name);
 
   T.TG = nullptr;
   
   // Unlink the timer from our list.
   *T.Prev = T.Next;
   if (T.Next)
     T.Next->Prev = T.Prev;

 
 /// print - Print any started timers in this group and zero them.
 void TimerGroup::print(raw_ostream &OS) {
   sys::SmartScopedLock<true> L(*TimerLock);
 
   // See if any of our timers were started, if so add them to TimersToPrint and
   // reset them.
   for (Timer *T = FirstTimer; T; T = T->Next) {
-    if (!T->Started) continue;
+    if (!T->hasTriggered()) continue;
     TimersToPrint.emplace_back(T->Time, T->Name);
     
     // Clear out the time.
-    T->Started = 0;
-    T->Time = TimeRecord();
+    T->clear();
   }
 
   // If any timers were started, print the group.
   if (!TimersToPrint.empty())
     PrintQueuedTimers(OS);
 }
 
 /// printAll - This static method prints all timers and clears them all out.
 void TimerGroup::printAll(raw_ostream &OS) {
   sys::SmartScopedLock<true> L(*TimerLock);
 
   for (TimerGroup *TG = TimerGroupList; TG; TG = TG->Next)
     TG->print(OS);
 }

unittests/Support/CMakeLists.txt

add_llvm_unittest(SupportTests
   SourceMgrTest.cpp
   SpecialCaseListTest.cpp
   StreamingMemoryObject.cpp
   StringPool.cpp
   SwapByteOrderTest.cpp
   TargetRegistry.cpp
   ThreadLocalTest.cpp
   ThreadPool.cpp
+  TimerTest.cpp
   TimeValueTest.cpp
   TrailingObjectsTest.cpp
   UnicodeTest.cpp
   YAMLIOTest.cpp
   YAMLParserTest.cpp
   formatted_raw_ostream_test.cpp
   raw_ostream_test.cpp
   raw_pwrite_stream_test.cpp
   )
 
 # ManagedStatic.cpp uses <pthread>.
 if(LLVM_ENABLE_THREADS AND HAVE_LIBPTHREAD)
   target_link_libraries(SupportTests pthread)
 endif()

unittests/Support/TimerTest.cpp

+//===- unittests/TimerTest.cpp - Timer tests ------------------------------===//
+//
+//                     The LLVM Compiler Infrastructure
+//
+// This file is distributed under the University of Illinois Open Source
+// License. See LICENSE.TXT for details.
+//
+//===----------------------------------------------------------------------===//
+
+#include "llvm/Support/Timer.h"
+#include "gtest/gtest.h"
+#include <chrono>
+#include <thread>
+
+using namespace llvm;
+
+namespace {
+
+TEST(Timer, Additivity) {
+  Timer T1("T1");
+
+  EXPECT_TRUE(T1.isInitialized());
+
+  T1.startTimer();
+  T1.stopTimer();
+  auto TR1 = T1.getTotalTime();
+
+  T1.startTimer();
+  std::this_thread::sleep_for(std::chrono::milliseconds(1));
+  T1.stopTimer();
+  auto TR2 = T1.getTotalTime();
+
+  EXPECT_TRUE(TR1 < TR2);
+}
+
+TEST(Timer, CheckIfTriggered) {
+  Timer T1("T1");
+
+  EXPECT_FALSE(T1.hasTriggered());
+  T1.startTimer();
+  EXPECT_TRUE(T1.hasTriggered());
+  T1.stopTimer();
+  EXPECT_TRUE(T1.hasTriggered());
+
+  T1.clear();
+  EXPECT_FALSE(T1.hasTriggered());
+}
+
+} // end anon namespace