[Legacy][TimePasses] allow -time-passes reporting into a custom stream

As a followup to newpm -time-passes fix (D59366), now adding a similar
functionality to legacy time-passes.

Enhancing llvm::reportAndResetTimings to accept an optional stream
for reporting output. By default it still reports into the stream created
by CreateInfoOutputFile (-info-output-file).

Also fixing to actually reset after printing as declared.

Reviewed By: philip.pfaffe
Differential Revision: https://reviews.llvm.org/D59416

llvm-svn: 356824

include/llvm/IR/PassTimingInfo.h

@@ -29,8 +29,9 @@ class PassInstrumentationCallbacks;
 class raw_ostream;
 
 /// If -time-passes has been specified, report the timings immediately and then
-/// reset the timers to zero.
-void reportAndResetTimings();
+/// reset the timers to zero. By default it uses the stream created by
+/// CreateInfoOutputFile().
+void reportAndResetTimings(raw_ostream *OutStream = nullptr);
 
 /// Request the timer for this legacy-pass-manager's pass instance.
 Timer *getPassTimer(Pass *);
@@ -64,8 +65,8 @@ class TimePassesHandler {
   SmallVector<Timer *, 8> TimerStack;
 
   /// Custom output stream to print timing information into.
-  /// By default (== nullptr) we emit time report into the stream controlled by
-  /// -info-output-file.
+  /// By default (== nullptr) we emit time report into the stream created by
+  /// CreateInfoOutputFile().
   raw_ostream *OutStream = nullptr;
 
   bool Enabled;

include/llvm/Support/Timer.h

@@ -205,8 +205,9 @@ public:
     Description.assign(NewDescription.begin(), NewDescription.end());
   }
 
-  /// Print any started timers in this group.
-  void print(raw_ostream &OS);
+  /// Print any started timers in this group, optionally resetting timers after
+  /// printing them.
+  void print(raw_ostream &OS, bool ResetAfterPrint = false);
 
   /// Clear all timers in this group.
   void clear();
@@ -233,7 +234,7 @@ private:
   friend void PrintStatisticsJSON(raw_ostream &OS);
   void addTimer(Timer &T);
   void removeTimer(Timer &T);
-  void prepareToPrintList();
+  void prepareToPrintList(bool reset_time = false);
   void PrintQueuedTimers(raw_ostream &OS);
   void printJSONValue(raw_ostream &OS, const PrintRecord &R,
                       const char *suffix, double Value);

lib/IR/PassTimingInfo.cpp

@@ -77,7 +77,8 @@ public:
   static void init();
 
   /// Prints out timing information and then resets the timers.
-  void print();
+  /// By default it uses the stream created by CreateInfoOutputFile().
+  void print(raw_ostream *OutStream = nullptr);
 
   /// Returns the timer for the specified pass if it exists.
   Timer *getPassTimer(Pass *, PassInstanceID);
@@ -111,7 +112,9 @@ void PassTimingInfo::init() {
 }
 
 /// Prints out timing information and then resets the timers.
-void PassTimingInfo::print() { TG.print(*CreateInfoOutputFile()); }
+void PassTimingInfo::print(raw_ostream *OutStream) {
+  TG.print(OutStream ? *OutStream : *CreateInfoOutputFile(), true);
+}
 
 Timer *PassTimingInfo::newPassTimer(StringRef PassID, StringRef PassDesc) {
   unsigned &num = PassIDCountMap[PassID];
@@ -153,9 +156,9 @@ Timer *getPassTimer(Pass *P) {
 
 /// If timing is enabled, report the times collected up to now and then reset
 /// them.
-void reportAndResetTimings() {
+void reportAndResetTimings(raw_ostream *OutStream) {
   if (legacy::PassTimingInfo::TheTimeInfo)
-    legacy::PassTimingInfo::TheTimeInfo->print();
+    legacy::PassTimingInfo::TheTimeInfo->print(OutStream);
 }
 
 //===----------------------------------------------------------------------===//
@@ -188,8 +191,7 @@ void TimePassesHandler::setOutStream(raw_ostream &Out) {
 void TimePassesHandler::print() {
   if (!Enabled)
     return;
-  TG.print(OutStream ? *OutStream : *CreateInfoOutputFile());
-  TG.clear();
+  TG.print(OutStream ? *OutStream : *CreateInfoOutputFile(), true);
 }
 
 LLVM_DUMP_METHOD void TimePassesHandler::dump() const {

lib/Support/Timer.cpp

@@ -347,7 +347,7 @@ void TimerGroup::PrintQueuedTimers(raw_ostream &OS) {
   TimersToPrint.clear();
 }
 
-void TimerGroup::prepareToPrintList() {
+void TimerGroup::prepareToPrintList(bool ResetTime) {
   // See if any of our timers were started, if so add them to TimersToPrint.
   for (Timer *T = FirstTimer; T; T = T->Next) {
     if (!T->hasTriggered()) continue;
@@ -357,15 +357,20 @@ void TimerGroup::prepareToPrintList() {
 
     TimersToPrint.emplace_back(T->Time, T->Name, T->Description);
 
+    if (ResetTime)
+      T->clear();
+
     if (WasRunning)
       T->startTimer();
   }
 }
 
-void TimerGroup::print(raw_ostream &OS) {
-  sys::SmartScopedLock<true> L(*TimerLock);
-
-  prepareToPrintList();
+void TimerGroup::print(raw_ostream &OS, bool ResetAfterPrint) {
+  {
+    // After preparing the timers we can free the lock
+    sys::SmartScopedLock<true> L(*TimerLock);
+    prepareToPrintList(ResetAfterPrint);
+  }
 
   // If any timers were started, print the group.
   if (!TimersToPrint.empty())
@@ -405,7 +410,7 @@ void TimerGroup::printJSONValue(raw_ostream &OS, const PrintRecord &R,
 const char *TimerGroup::printJSONValues(raw_ostream &OS, const char *delim) {
   sys::SmartScopedLock<true> L(*TimerLock);
 
-  prepareToPrintList();
+  prepareToPrintList(false);
   for (const PrintRecord &R : TimersToPrint) {
     OS << delim;
     delim = ",\n";

unittests/IR/TimePassesTest.cpp

@@ -8,6 +8,7 @@
 
 #include <gtest/gtest.h>
 #include <llvm/ADT/SmallString.h>
+#include "llvm/IR/LegacyPassManager.h"
 #include <llvm/IR/LLVMContext.h>
 #include <llvm/IR/Module.h>
 #include <llvm/IR/PassInstrumentation.h>
@@ -17,7 +18,97 @@
 
 using namespace llvm;
 
+//===----------------------------------------------------------------------===//
+// Define dummy passes for legacy pass manager run.
+
+namespace llvm {
+
+void initializePass1Pass(PassRegistry &);
+void initializePass2Pass(PassRegistry &);
+
 namespace {
+struct Pass1 : public ModulePass {
+  static char ID;
+
+public:
+  Pass1() : ModulePass(ID) {}
+  bool runOnModule(Module &M) override { return false; }
+  void getAnalysisUsage(AnalysisUsage &AU) const override {
+    AU.setPreservesAll();
+  }
+  StringRef getPassName() const override { return "Pass1"; }
+};
+char Pass1::ID;
+
+struct Pass2 : public ModulePass {
+  static char ID;
+
+public:
+  Pass2() : ModulePass(ID) {}
+  bool runOnModule(Module &M) override { return false; }
+  void getAnalysisUsage(AnalysisUsage &AU) const override {
+    AU.setPreservesAll();
+  }
+  StringRef getPassName() const override { return "Pass2"; }
+};
+char Pass2::ID;
+} // namespace
+} // namespace llvm
+
+INITIALIZE_PASS(Pass1, "Pass1", "Pass1", false, false)
+INITIALIZE_PASS(Pass2, "Pass2", "Pass2", false, false)
+
+namespace {
+
+TEST(TimePassesTest, LegacyCustomOut) {
+  PassInstrumentationCallbacks PIC;
+  PassInstrumentation PI(&PIC);
+
+  LLVMContext Context;
+  Module M("TestModule", Context);
+
+  SmallString<0> TimePassesStr;
+  raw_svector_ostream ReportStream(TimePassesStr);
+
+  // Setup pass manager
+  legacy::PassManager PM1;
+  PM1.add(new llvm::Pass1());
+  PM1.add(new llvm::Pass2());
+
+  // Enable time-passes and run passes.
+  TimePassesIsEnabled = true;
+  PM1.run(M);
+
+  // Generating report.
+  reportAndResetTimings(&ReportStream);
+
+  // There should be Pass1 and Pass2 in the report
+  EXPECT_FALSE(TimePassesStr.empty());
+  EXPECT_TRUE(TimePassesStr.str().contains("report"));
+  EXPECT_TRUE(TimePassesStr.str().contains("Pass1"));
+  EXPECT_TRUE(TimePassesStr.str().contains("Pass2"));
+
+  // Clear and generate report again.
+  TimePassesStr.clear();
+  reportAndResetTimings(&ReportStream);
+
+  // Since we did not run any passes since last print, report should be empty.
+  EXPECT_TRUE(TimePassesStr.empty());
+
+  // Now run just a single pass to populate timers again.
+  legacy::PassManager PM2;
+  PM2.add(new llvm::Pass2());
+  PM2.run(M);
+
+  // Generate report again.
+  reportAndResetTimings(&ReportStream);
+
+  // There should be Pass2 in this report and no Pass1.
+  EXPECT_FALSE(TimePassesStr.str().empty());
+  EXPECT_TRUE(TimePassesStr.str().contains("report"));
+  EXPECT_FALSE(TimePassesStr.str().contains("Pass1"));
+  EXPECT_TRUE(TimePassesStr.str().contains("Pass2"));
+}
 
 class MyPass1 : public PassInfoMixin<MyPass1> {};
 class MyPass2 : public PassInfoMixin<MyPass2> {};
@@ -40,7 +131,7 @@ TEST(TimePassesTest, CustomOut) {
   TimePasses->setOutStream(ReportStream);
   TimePasses->registerCallbacks(PIC);
 
-  // Running some passes to trigger the timers.
+  // Pretending that passes are running to trigger the timers.
   PI.runBeforePass(Pass1, M);
   PI.runBeforePass(Pass2, M);
   PI.runAfterPass(Pass2, M);
@@ -61,7 +152,7 @@ TEST(TimePassesTest, CustomOut) {
   // Since we did not run any passes since last print, report should be empty.
   EXPECT_TRUE(TimePassesStr.empty());
 
-  // Now run just a single pass to populate timers again.
+  // Now trigger just a single pass to populate timers again.
   PI.runBeforePass(Pass2, M);
   PI.runAfterPass(Pass2, M);