1 //===-- timing_test.cpp -----------------------------------------*- C++ -*-===//
3 // Part of the LLVM Project, under the Apache License v2.0 with LLVM Exceptions.
4 // See https://llvm.org/LICENSE.txt for license information.
5 // SPDX-License-Identifier: Apache-2.0 WITH LLVM-exception
7 //===----------------------------------------------------------------------===//
9 #include "tests/scudo_unit_test.h"
16 class ScudoTimingTest
: public Test
{
18 void testFunc1() { scudo::ScopedTimer
ST(Manager
, __func__
); }
21 scudo::ScopedTimer
ST(Manager
, __func__
);
25 void testChainedCalls() {
26 scudo::ScopedTimer
ST(Manager
, __func__
);
30 void testIgnoredTimer() {
31 scudo::ScopedTimer
ST(Manager
, __func__
);
35 void printAllTimersStats() { Manager
.printAll(); }
37 void getAllTimersStats(scudo::ScopedString
&Str
) { Manager
.getAll(Str
); }
39 scudo::TimingManager
&getTimingManager() { return Manager
; }
41 void testCallTimers() {
42 scudo::ScopedTimer
Outer(getTimingManager(), "Level1");
44 scudo::ScopedTimer
Inner1(getTimingManager(), Outer
, "Level2");
45 { scudo::ScopedTimer
Inner2(getTimingManager(), Inner1
, "Level3"); }
50 scudo::TimingManager Manager
;
53 TEST_F(ScudoTimingTest
, SimpleTimer
) {
56 scudo::ScopedString Str
;
57 getAllTimersStats(Str
);
59 std::string
Output(Str
.data());
60 EXPECT_TRUE(Output
.find("testIgnoredTimer (1)") == std::string::npos
);
61 EXPECT_TRUE(Output
.find("testChainedCalls (1)") != std::string::npos
);
62 EXPECT_TRUE(Output
.find("testFunc2 (1)") != std::string::npos
);
63 EXPECT_TRUE(Output
.find("testFunc1 (1)") != std::string::npos
);
66 TEST_F(ScudoTimingTest
, NestedTimer
) {
68 scudo::ScopedTimer
Outer(getTimingManager(), "Outer");
70 scudo::ScopedTimer
Inner1(getTimingManager(), Outer
, "Inner1");
71 { scudo::ScopedTimer
Inner2(getTimingManager(), Inner1
, "Inner2"); }
74 scudo::ScopedString Str
;
75 getAllTimersStats(Str
);
77 std::string
Output(Str
.data());
78 EXPECT_TRUE(Output
.find("Outer (1)") != std::string::npos
);
79 EXPECT_TRUE(Output
.find("Inner1 (1)") != std::string::npos
);
80 EXPECT_TRUE(Output
.find("Inner2 (1)") != std::string::npos
);
83 TEST_F(ScudoTimingTest
, VerifyChainedTimerCalculations
) {
85 scudo::ScopedTimer
Outer(getTimingManager(), "Level1");
88 scudo::ScopedTimer
Inner1(getTimingManager(), Outer
, "Level2");
91 scudo::ScopedTimer
Inner2(getTimingManager(), Inner1
, "Level3");
96 scudo::ScopedString Str
;
97 getAllTimersStats(Str
);
98 std::string
Output(Str
.data());
100 // Get the individual timer values for the average and maximum, then
101 // verify that the timer values are being calculated properly.
102 Output
= Output
.substr(Output
.find('\n') + 1);
104 unsigned long long Level1AvgNs
= std::strtoull(Output
.c_str(), &end
, 10);
105 ASSERT_TRUE(end
!= nullptr);
106 unsigned long long Level1MaxNs
= std::strtoull(&end
[6], &end
, 10);
107 ASSERT_TRUE(end
!= nullptr);
108 EXPECT_EQ(Level1AvgNs
, Level1MaxNs
);
110 Output
= Output
.substr(Output
.find('\n') + 1);
111 unsigned long long Level2AvgNs
= std::strtoull(Output
.c_str(), &end
, 10);
112 ASSERT_TRUE(end
!= nullptr);
113 unsigned long long Level2MaxNs
= std::strtoull(&end
[6], &end
, 10);
114 ASSERT_TRUE(end
!= nullptr);
115 EXPECT_EQ(Level2AvgNs
, Level2MaxNs
);
117 Output
= Output
.substr(Output
.find('\n') + 1);
118 unsigned long long Level3AvgNs
= std::strtoull(Output
.c_str(), &end
, 10);
119 ASSERT_TRUE(end
!= nullptr);
120 unsigned long long Level3MaxNs
= std::strtoull(&end
[6], &end
, 10);
121 ASSERT_TRUE(end
!= nullptr);
122 EXPECT_EQ(Level3AvgNs
, Level3MaxNs
);
124 EXPECT_GT(Level1AvgNs
, Level2AvgNs
);
125 EXPECT_GT(Level2AvgNs
, Level3AvgNs
);
127 // The time for the first timer needs to be at least six seconds.
128 EXPECT_GT(Level1AvgNs
, 6000000000U);
129 // The time for the second timer needs to be at least five seconds.
130 EXPECT_GT(Level2AvgNs
, 5000000000U);
131 // The time for the third timer needs to be at least three seconds.
132 EXPECT_GT(Level3AvgNs
, 3000000000U);
133 // The time between the first and second timer needs to be at least one
135 EXPECT_GT(Level1AvgNs
- Level2AvgNs
, 1000000000U);
136 // The time between the second and third timer needs to be at least two
138 EXPECT_GT(Level2AvgNs
- Level3AvgNs
, 2000000000U);
141 TEST_F(ScudoTimingTest
, VerifyMax
) {
142 for (size_t i
= 0; i
< 3; i
++) {
143 scudo::ScopedTimer
Outer(getTimingManager(), "Level1");
146 scudo::ScopedString Str
;
147 getAllTimersStats(Str
);
148 std::string
Output(Str
.data());
150 Output
= Output
.substr(Output
.find('\n') + 1);
152 unsigned long long AvgNs
= std::strtoull(Output
.c_str(), &end
, 10);
153 ASSERT_TRUE(end
!= nullptr);
154 unsigned long long MaxNs
= std::strtoull(&end
[6], &end
, 10);
155 ASSERT_TRUE(end
!= nullptr);
157 EXPECT_GE(MaxNs
, AvgNs
);
160 TEST_F(ScudoTimingTest
, VerifyMultipleTimerCalls
) {
161 for (size_t i
= 0; i
< 5; i
++)
164 scudo::ScopedString Str
;
165 getAllTimersStats(Str
);
166 std::string
Output(Str
.data());
167 EXPECT_TRUE(Output
.find("Level1 (5)") != std::string::npos
);
168 EXPECT_TRUE(Output
.find("Level2 (5)") != std::string::npos
);
169 EXPECT_TRUE(Output
.find("Level3 (5)") != std::string::npos
);
172 TEST_F(ScudoTimingTest
, VerifyHeader
) {
173 { scudo::ScopedTimer
Outer(getTimingManager(), "Timer"); }
174 scudo::ScopedString Str
;
175 getAllTimersStats(Str
);
177 std::string
Output(Str
.data());
178 std::string
Header(Output
.substr(0, Output
.find('\n')));
179 EXPECT_EQ(Header
, "-- Average Operation Time -- -- Maximum Operation Time -- "
180 "-- Name (# of Calls) --");
183 TEST_F(ScudoTimingTest
, VerifyTimerFormat
) {
185 scudo::ScopedString Str
;
186 getAllTimersStats(Str
);
187 std::string
Output(Str
.data());
189 // Check the top level line, should look similar to:
190 // 11718.0(ns) 11718(ns) Level1 (1)
191 Output
= Output
.substr(Output
.find('\n') + 1);
193 // Verify that the Average Operation Time is in the correct location.
194 EXPECT_EQ(".0(ns) ", Output
.substr(14, 7));
196 // Verify that the Maximum Operation Time is in the correct location.
197 EXPECT_EQ("(ns) ", Output
.substr(45, 5));
199 // Verify that the first timer name is in the correct location.
200 EXPECT_EQ("Level1 (1)\n", Output
.substr(61, 11));
202 // Check a chained timer, should look similar to:
203 // 5331.0(ns) 5331(ns) Level2 (1)
204 Output
= Output
.substr(Output
.find('\n') + 1);
206 // Verify that the Average Operation Time is in the correct location.
207 EXPECT_EQ(".0(ns) ", Output
.substr(14, 7));
209 // Verify that the Maximum Operation Time is in the correct location.
210 EXPECT_EQ("(ns) ", Output
.substr(45, 5));
212 // Verify that the first timer name is in the correct location.
213 EXPECT_EQ(" Level2 (1)\n", Output
.substr(61, 13));
215 // Check a secondary chained timer, should look similar to:
216 // 814.0(ns) 814(ns) Level3 (1)
217 Output
= Output
.substr(Output
.find('\n') + 1);
219 // Verify that the Average Operation Time is in the correct location.
220 EXPECT_EQ(".0(ns) ", Output
.substr(14, 7));
222 // Verify that the Maximum Operation Time is in the correct location.
223 EXPECT_EQ("(ns) ", Output
.substr(45, 5));
225 // Verify that the first timer name is in the correct location.
226 EXPECT_EQ(" Level3 (1)\n", Output
.substr(61, 15));
230 TEST_F(ScudoTimingTest
, VerifyPrintMatchesGet
) {
231 testing::internal::LogToStderr();
232 testing::internal::CaptureStderr();
235 { scudo::ScopedTimer
Outer(getTimingManager(), "Timer"); }
236 printAllTimersStats();
237 std::string PrintOutput
= testing::internal::GetCapturedStderr();
238 EXPECT_TRUE(PrintOutput
.size() != 0);
240 scudo::ScopedString Str
;
241 getAllTimersStats(Str
);
242 std::string
GetOutput(Str
.data());
243 EXPECT_TRUE(GetOutput
.size() != 0);
245 EXPECT_EQ(PrintOutput
, GetOutput
);
250 TEST_F(ScudoTimingTest
, VerifyReporting
) {
251 testing::internal::LogToStderr();
252 testing::internal::CaptureStderr();
253 // Every 100 calls generates a report, but run a few extra to verify the
254 // report happened at call 100.
255 for (size_t i
= 0; i
< 110; i
++)
256 scudo::ScopedTimer
Outer(getTimingManager(), "VerifyReportTimer");
258 std::string Output
= testing::internal::GetCapturedStderr();
259 EXPECT_TRUE(Output
.find("VerifyReportTimer (100)") != std::string::npos
);