llvm.org GIT mirror llvm / 7086bb6
[TimePasses] allow -time-passes reporting into a custom stream TimePassesHandler object (implementation of time-passes for new pass manager) gains ability to report into a stream customizable per-instance (per pipeline). Intended use is to specify separate time-passes output stream per each compilation, setting up TimePasses member of StandardInstrumentation during PassBuilder setup. That allows to get independent non-overlapping pass-times reports for parallel independent compilations (in JIT-like setups). By default it still puts timing reports into the info-output-file stream (created by CreateInfoOutputFile every time report is requested). Unit-test added for non-default case, and it also allowed to discover that print() does not work as declared - it did not reset the timers, leading to yet another report being printed into the default stream. Fixed print() to actually reset timers according to what was declared in print's comments before. Reviewed By: philip.pfaffe Differential Revision: https://reviews.llvm.org/D59366 git-svn-id: https://llvm.org/svn/llvm-project/llvm/trunk@356305 91177308-0d34-0410-b5e6-96231b3b80d8 Fedor Sergeev 5 months ago
6 changed file(s) with 111 addition(s) and 7 deletion(s). Raw diff Collapse all Expand all
2525
2626 class Pass;
2727 class PassInstrumentationCallbacks;
28 class raw_ostream;
2829
2930 /// If -time-passes has been specified, report the timings immediately and then
3031 /// reset the timers to zero.
6162 /// Stack of currently active timers.
6263 SmallVector TimerStack;
6364
65 /// Custom output stream to print timing information into.
66 /// By default (== nullptr) we emit time report into the stream controlled by
67 /// -info-output-file.
68 raw_ostream *OutStream = nullptr;
69
6470 bool Enabled;
6571
6672 public:
6773 TimePassesHandler(bool Enabled = TimePassesIsEnabled);
6874
6975 /// Destructor handles the print action if it has not been handled before.
70 ~TimePassesHandler() {
71 // First destroying the timers from TimingData, which deploys all their
72 // collected data into the TG time group member, which later prints itself
73 // when being destroyed.
74 TimingData.clear();
75 }
76 ~TimePassesHandler() { print(); }
7677
7778 /// Prints out timing information and then resets the timers.
7879 void print();
8283 void operator=(const TimePassesHandler &) = delete;
8384
8485 void registerCallbacks(PassInstrumentationCallbacks &PIC);
86
87 /// Set a custom output stream for subsequent reporting.
88 void setOutStream(raw_ostream &OutStream);
8589
8690 private:
8791 /// Dumps information for running/triggered timers, useful for debugging
6262 StandardInstrumentations() = default;
6363
6464 void registerCallbacks(PassInstrumentationCallbacks &PIC);
65
66 TimePassesHandler &getTimePasses() { return TimePasses; }
6567 };
6668 } // namespace llvm
6769
180180 TimePassesHandler::TimePassesHandler(bool Enabled)
181181 : TG("pass", "... Pass execution timing report ..."), Enabled(Enabled) {}
182182
183 void TimePassesHandler::print() { TG.print(*CreateInfoOutputFile()); }
183 void TimePassesHandler::setOutStream(raw_ostream &Out) {
184 OutStream = &Out;
185 }
186
187 void TimePassesHandler::print() {
188 if (!Enabled)
189 return;
190 TG.print(OutStream ? *OutStream : *CreateInfoOutputFile());
191 TG.clear();
192 }
184193
185194 LLVM_DUMP_METHOD void TimePassesHandler::dump() const {
186195 dbgs() << "Dumping timers for " << getTypeName()
22 ; RUN: opt < %s -disable-output -passes='instcombine,instcombine,loop(licm)' -time-passes 2>&1 | FileCheck %s --check-prefix=TIME --check-prefix=TIME-NEW
33 ; RUN: opt < %s -disable-output -passes='instcombine,loop(licm),instcombine,loop(licm)' -time-passes 2>&1 | FileCheck %s --check-prefix=TIME --check-prefix=TIME-NEW -check-prefix=TIME-DOUBLE-LICM-NEW
44 ; RUN: opt < %s -disable-output -passes='default' -time-passes 2>&1 | FileCheck %s --check-prefix=TIME
5 ;
6 ; The following 4 test runs verify -info-output-file interaction (default goes to stderr, '-' goes to stdout).
7 ; RUN: opt < %s -disable-output -O2 -time-passes -info-output-file='-' 2>/dev/null | FileCheck %s --check-prefix=TIME
8 ; RUN: opt < %s -disable-output -passes='default' -time-passes -info-output-file='-' 2>/dev/null | FileCheck %s --check-prefix=TIME
9 ;
10 ; RUN: rm -f %t; opt < %s -disable-output -O2 -time-passes -info-output-file=%t
11 ; RUN: cat %t | FileCheck %s --check-prefix=TIME
12 ;
13 ; RUN: rm -f %t; opt < %s -disable-output -passes='default' -time-passes -info-output-file=%t
14 ; RUN: cat %t | FileCheck %s --check-prefix=TIME
515 ;
616 ; TIME: Pass execution timing report
717 ; TIME: Total Execution Time:
2929 ModuleTest.cpp
3030 PassManagerTest.cpp
3131 PatternMatch.cpp
32 TimePassesTest.cpp
3233 TypesTest.cpp
3334 UseTest.cpp
3435 UserTest.cpp
0 //===- unittests/IR/TimePassesTest.cpp - TimePassesHandler tests ----------===//
1 //
2 // Part of the LLVM Project, under the Apache License v2.0 with LLVM Exceptions.
3 // See https://llvm.org/LICENSE.txt for license information.
4 // SPDX-License-Identifier: Apache-2.0 WITH LLVM-exception
5 //
6 //===----------------------------------------------------------------------===//
7
8 #include
9 #include
10 #include
11 #include
12 #include
13 #include
14 #include
15 #include
16
17 using namespace llvm;
18
19 namespace {
20
21 class MyPass1 : public PassInfoMixin {};
22 class MyPass2 : public PassInfoMixin {};
23
24 TEST(TimePassesTest, CustomOut) {
25 PassInstrumentationCallbacks PIC;
26 PassInstrumentation PI(&PIC);
27
28 LLVMContext Context;
29 Module M("TestModule", Context);
30 MyPass1 Pass1;
31 MyPass2 Pass2;
32
33 SmallString<0> TimePassesStr;
34 raw_svector_ostream ReportStream(TimePassesStr);
35
36 // Setup time-passes handler and redirect output to the stream.
37 std::unique_ptr TimePasses =
38 llvm::make_unique(true);
39 TimePasses->setOutStream(ReportStream);
40 TimePasses->registerCallbacks(PIC);
41
42 // Running some passes to trigger the timers.
43 PI.runBeforePass(Pass1, M);
44 PI.runBeforePass(Pass2, M);
45 PI.runAfterPass(Pass2, M);
46 PI.runAfterPass(Pass1, M);
47
48 // Generating report.
49 TimePasses->print();
50
51 // There should be Pass1 and Pass2 in the report
52 EXPECT_FALSE(TimePassesStr.empty());
53 EXPECT_TRUE(TimePassesStr.str().contains("report"));
54 EXPECT_TRUE(TimePassesStr.str().contains("Pass1"));
55 EXPECT_TRUE(TimePassesStr.str().contains("Pass2"));
56
57 // Clear and generate report again.
58 TimePassesStr.clear();
59 TimePasses->print();
60 // Since we did not run any passes since last print, report should be empty.
61 EXPECT_TRUE(TimePassesStr.empty());
62
63 // Now run just a single pass to populate timers again.
64 PI.runBeforePass(Pass2, M);
65 PI.runAfterPass(Pass2, M);
66
67 // Generate report by deleting the handler.
68 TimePasses.reset();
69
70 // There should be Pass2 in this report and no Pass1.
71 EXPECT_FALSE(TimePassesStr.str().empty());
72 EXPECT_TRUE(TimePassesStr.str().contains("report"));
73 EXPECT_FALSE(TimePassesStr.str().contains("Pass1"));
74 EXPECT_TRUE(TimePassesStr.str().contains("Pass2"));
75 }
76
77 } // end anonymous namespace