[Support] Add reentrant start/stop Timer methods

[modocache]

Summary

In Clang's lib/CodeGen/CodeGenAction.cpp, a timer is used to measure
the amount of time spent generating LLVM IR. The timer is started and
stopped in a method, BackendConsumer::HandleTopLevelDecl, that is called
recursively. llvm::Timer does not allow starting a timer twice, so to
prevent a runtime assertion that would occur if the timer is started
a second time as the method recurses, it's guarded by a "reference
count" variable: if the reference count is incremented from 0 to 1, the
timer is started. Subsequent calls to start the timer increment the
reference count, but do not call startTimer(). stopTimer() is called when
the reference count goes from 1 to 0.

This pattern is useful when timing any recursive method, such as in
https://reviews.llvm.org/D36492.

Add startReentrantTimer and stopReentrantTimer methods that can be used for
situations such as these. Unlike startTimer/stopTimer, multiple calls to
startReentrantTimer are fine, as long as stopReentrantTimer is called an
equal number of times.

[vsk]

I tried this a while back: https://reviews.llvm.org/D20735

I ended up abandoning the patch because some some folks weren't totally comfortable with a timer that can be started twice. I think we're seeing that this is a use case that's becoming more important. Actually, @rafael mentioned that he's OK with ref-counted timers "if it is cumbersome to use a non ref counted timer in the current users", and it looks like that's the case. @davide, wdyt of revisiting the ref-counted timer decision?

[modocache]

Friendly ping -- does anyone have any thoughts here?

[davide]

Personally, I'd still be interested in understanding whether this can be fixed in the consumers.
You probably want to hear what @rsmith thinks (i.e. whether it's feasible to fix this in clang, which seems to be the only place where this code would be used).
In case you can't, I'm OK with revisiting/allowing this feature in Support/.

[MatzeB]

For something as simple as a timer, having two std::string, 3 pointers and now a vtable feels like too much. Of course that's not the fault of this patch.

That said you are adding 1 pointer (for the vtable) to the timer class and the start/stop calls become virtual. May just as well add the counter to the baseclass instead and have it always refcount to avoid the virtual methods.

Or alternatively just add startReentrant()/stopReentrant() methods to the baseclass. So the default startTimer()/stopTimer() methods remain the same?

In D36847#847700, @modocache wrote:

Friendly ping -- does anyone have any thoughts here?

[modocache]

Thanks for the suggestions, @MatzeB! I'll try to get rid of the added vtable.

fix this in clang, which seems to be the only place where this code would be used

@davide That's true, for now. But I also have https://reviews.llvm.org/D36492 out, which can also make use of this. So I am anticipating this will be used in more than just one place, and that there will be cases where it could not reasonably be solved in consumers.

[modocache]

Instead of using virtual methods, add Timer::startReentrantTimer and Timer::stopReentrantTimer. @MatzeB, let me know if this isn't what you had in mind -- thanks!

[modocache]

One downside of separate startReentrantTimer and stopReentrantTimer methods is that we may need to add a bool IsReentrant parameter to the initializer of TimeRegion, in order to support the way it's used in https://reviews.llvm.org/D36946.

[MatzeB]

FWIF: Looking at https://reviews.llvm.org/D36946 I'm not convinced yet that timer is a good idea there at all.

include/llvm/Support/Timer.h

82

Maybe this should be called StartCount instead of RefCount? It should be possible to get rid of the Running member at that point and check StartCount > 0 instead.

[modocache]

Replace Running member with StartCount.

Looking at https://reviews.llvm.org/D36946 I'm not convinced yet that timer is a good idea there at all.

Oh! Could you explain why you feel this way?

[MatzeB]

In D36847#850238, @modocache wrote:

Replace Running member with StartCount.

Looking at https://reviews.llvm.org/D36946 I'm not convinced yet that timer is a good idea there at all.

Oh! Could you explain why you feel this way?

Sorry, I meant D36492 which I commented on.

[dblaikie]

unittests/Support/TimerTest.cpp

65–75

This seems like an overly general tool given the singular use case - would the test be easier to read if this abstraction weren't used and the operations on the Timer were done directly in the test case? Also possibly testing the state of the Timer after startReentrant has been called but before stopReentrant has been called?

[modocache]

Thanks for the reviews, everyone! I'll try to come up with something better here, and submit it in its own diff at a later date.

include/llvm/Support/Timer.h

 /// 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;          ///< The total time captured.
   TimeRecord StartTime;     ///< The time startTimer() was last called.
   std::string Name;         ///< The name of this time variable.
   std::string Description;  ///< Description of this time variable.
-  bool Running;             ///< Is the timer currently running?
   bool Triggered;           ///< Has the timer ever been triggered?
+  unsigned StartCount;      ///< Number of times started without being stopped.
   TimerGroup *TG = nullptr; ///< The TimerGroup this Timer is in.
 
   Timer **Prev;             ///< Pointer to \p Next of previous timer in group.
   Timer *Next;              ///< Next timer in the group.
 public:
   explicit Timer(StringRef Name, StringRef Description) {
     init(Name, Description);
   }
public:
   void init(StringRef Name, StringRef Description);
   void init(StringRef Name, StringRef Description, TimerGroup &tg);
 
   const std::string &getName() const { return Name; }
   const std::string &getDescription() const { return Description; }
   bool isInitialized() const { return TG != nullptr; }
 
   /// Check if the timer is currently running.
-  bool isRunning() const { return Running; }
+  bool isRunning() const { return StartCount > 0; }
 
   /// 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.
+  /// paired.  It is an error to call this method on a Timer that has been
+  /// started via a call to startReentrantTimer.
   void startTimer();
 
-  /// Stop the timer.
+  /// Start the tumer running or, if it is already running from a prior call to
+  /// startRentrantTimer, increase the number of times stopReentrantTimer must
+  /// be called.  Any number of calls to startReentrantTimer are allowed, so
+  /// long as the same number of calls are eventually made to
+  /// stopReentrantTimer.  Time between the first call to startReentrantTimer
+  /// and the last call to stopReentrantTimer is counted by the Timer class.
+  /// It is an error to call this method on a Timer that has been started via
+  /// a call to startTimer.
+  void startReentrantTimer();
+
+  /// Stop the timer.  It is an error to call this method directly on a timer
+  /// that has been started with startReentrantTimer.
   void stopTimer();
 
+  /// Stop the timer or, if startReentrantTimer has been called more than once,
+  /// decrement the number of times stopReentrantTimer must be called in order
+  /// to stop the timer.  It is an error to call this method without ever having
+  /// called startReentrantTimer.
+  void stopReentrantTimer();
+
   /// 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;

lib/Support/Timer.cpp

 void Timer::init(StringRef Name, StringRef Description) {
   init(Name, Description, *getDefaultTimerGroup());
 }
 
 void Timer::init(StringRef Name, StringRef Description, TimerGroup &tg) {
   assert(!TG && "Timer already initialized");
   this->Name.assign(Name.begin(), Name.end());
   this->Description.assign(Description.begin(), Description.end());
-  Running = Triggered = false;
+  Triggered = false;
+  StartCount = 0;
   TG = &tg;
   TG->addTimer(*this);
 }
 
 Timer::~Timer() {
   if (!TG) return;  // Never initialized, or already cleared.
   TG->removeTimer(*this);
 }
TimeRecord TimeRecord::getCurrentTime(bool Start) {
 
   Result.WallTime = Seconds(now.time_since_epoch()).count();
   Result.UserTime = Seconds(user).count();
   Result.SystemTime = Seconds(sys).count();
   return Result;
 }
 
 void Timer::startTimer() {
-  assert(!Running && "Cannot start a running timer");
-  Running = Triggered = true;
+  assert(!isRunning() && "Cannot start a running timer");
+  Triggered = true;
+  StartCount += 1;
   StartTime = TimeRecord::getCurrentTime(true);
 }
 
+void Timer::startReentrantTimer() {
+  if (StartCount == 0)
+    startTimer();
+  else
+    StartCount += 1;
+}
+
 void Timer::stopTimer() {
-  assert(Running && "Cannot stop a paused timer");
-  Running = false;
+  assert(isRunning() && "Cannot stop a paused timer");
+  assert(StartCount == 1 &&
+         "startReentrantTimer must be matched with the same number of calls "
+         "to stopReentrantTimer");
+  StartCount -= 1;
   Time += TimeRecord::getCurrentTime(false);
   Time -= StartTime;
 }
 
+void Timer::stopReentrantTimer() {
+  assert(StartCount > 0 &&
+         "stopReentrantTimer cannot be called more times than "
+         "startReentrantTimer");
+  if (StartCount == 1)
+    stopTimer();
+  else
+    StartCount -= 1;
+}
+
 void Timer::clear() {
-  Running = Triggered = false;
+  Triggered = false;
+  StartCount = 0;
   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);

unittests/Support/TimerTest.cpp

TEST(Timer, CheckIfTriggered) {
   EXPECT_TRUE(T1.hasTriggered());
   T1.stopTimer();
   EXPECT_TRUE(T1.hasTriggered());
 
   T1.clear();
   EXPECT_FALSE(T1.hasTriggered());
 }
 
+class Recurser {
+public:
+  Timer T;
+  Recurser() : T("RCT1", "RCT1") {}
+  void Recurse(unsigned Depth) {
+    T.startReentrantTimer();
+    if (Depth < 1)
+      Recurse(Depth + 1);
+    T.stopReentrantTimer();
+  }
+};
+
+TEST(Timer, Reentrant) {
+  Recurser R;
+  ASSERT_FALSE(R.T.hasTriggered());
+  ASSERT_FALSE(R.T.isRunning());
+
+  R.Recurse(0);
+  ASSERT_TRUE(R.T.hasTriggered());
+  ASSERT_FALSE(R.T.isRunning());
+}
+
 } // end anon namespace