1/*
2 * Copyright 2015-present Facebook, Inc.
3 *
4 * Licensed under the Apache License, Version 2.0 (the "License");
5 * you may not use this file except in compliance with the License.
6 * You may obtain a copy of the License at
7 *
8 * http://www.apache.org/licenses/LICENSE-2.0
9 *
10 * Unless required by applicable law or agreed to in writing, software
11 * distributed under the License is distributed on an "AS IS" BASIS,
12 * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
13 * See the License for the specific language governing permissions and
14 * limitations under the License.
15 */
16
17#include <folly/experimental/AutoTimer.h>
18
19#include <folly/portability/GTest.h>
20
21using namespace folly;
22using namespace std;
23
24struct StubLogger {
25 void operator()(StringPiece msg, std::chrono::duration<double> sec) {
26 m = msg.str();
27 t = sec.count();
28 }
29 static std::string m;
30 static double t;
31};
32
33std::string StubLogger::m = "";
34double StubLogger::t = 0;
35
36struct StubClock {
37 typedef std::chrono::seconds duration;
38
39 static std::chrono::time_point<StubClock> now() {
40 return std::chrono::time_point<StubClock>(std::chrono::duration<int>(t));
41 }
42 static int t;
43};
44
45int StubClock::t = 0;
46
47TEST(TestAutoTimer, HandleBasicClosure) {
48 auto logger = [](StringPiece mesg, auto sec) {
49 return StubLogger()(mesg, sec);
50 };
51 StubClock::t = 1;
52 // Here decltype is needed. But since most users are expected to use this
53 // method with the default clock, template specification won't be needed even
54 // when they use a closure. See test case HandleRealTimerClosure
55 auto timer = makeAutoTimer<decltype(logger), StubClock>(
56 "", std::chrono::duration<double>::zero(), std::move(logger));
57 StubClock::t = 3;
58 timer.log("foo");
59 ASSERT_EQ("foo", StubLogger::m);
60 ASSERT_EQ(2, StubLogger::t);
61 timer.logFormat("bar {}", 5e-2);
62 ASSERT_EQ("bar 0.05", StubLogger::m);
63 ASSERT_EQ(0, StubLogger::t);
64}
65
66TEST(TestAutoTimer, HandleBasic) {
67 StubClock::t = 1;
68 AutoTimer<StubLogger, StubClock> timer;
69 StubClock::t = 3;
70 timer.log("foo");
71 ASSERT_EQ("foo", StubLogger::m);
72 ASSERT_EQ(2, StubLogger::t);
73 timer.logFormat("bar {}", 5e-2);
74 ASSERT_EQ("bar 0.05", StubLogger::m);
75 ASSERT_EQ(0, StubLogger::t);
76}
77
78TEST(TestAutoTimer, HandleLogOnDestruct) {
79 {
80 StubClock::t = 0;
81 AutoTimer<StubLogger, StubClock> timer("message");
82 StubClock::t = 3;
83 timer.log("foo");
84 EXPECT_EQ("foo", StubLogger::m);
85 EXPECT_EQ(3, StubLogger::t);
86 StubClock::t = 5;
87 }
88 ASSERT_EQ("message", StubLogger::m);
89 ASSERT_EQ(2, StubLogger::t);
90}
91
92TEST(TestAutoTimer, HandleRealTimerClosure) {
93 auto t = makeAutoTimer(
94 "Third message on destruction",
95 std::chrono::duration<double>::zero(),
96 [](StringPiece mesg, auto sec) {
97 GoogleLogger<GoogleLoggerStyle::PRETTY>()(mesg, sec);
98 });
99 t.log("First message");
100 t.log("Second message");
101}
102
103TEST(TestAutoTimer, HandleRealTimer) {
104 AutoTimer<> t("Third message on destruction");
105 t.log("First message");
106 t.log("Second message");
107}
108
109TEST(TestAutoTimer, HandleMinLogTime) {
110 StubClock::t = 1;
111 AutoTimer<StubLogger, StubClock> timer("", std::chrono::duration<double>(3));
112 StubClock::t = 3;
113 // only 2 "seconds" have passed, so this shouldn't log
114 StubLogger::t = 0;
115 ASSERT_EQ(std::chrono::duration<double>(2), timer.log("foo"));
116 ASSERT_EQ(std::chrono::duration<double>::zero().count(), StubLogger::t);
117}
118
119TEST(TestAutoTimer, MovedObjectDestructionDoesntLog) {
120 const std::vector<std::string> expectedMsgs = {
121 "BEFORE_MOVE", "AFTER_MOVE", "END"};
122 int32_t current = 0;
123 SCOPE_EXIT {
124 EXPECT_EQ(3, current);
125 };
126
127 auto timer = [&expectedMsgs, &current] {
128 auto oldTimer = folly::makeAutoTimer(
129 "END",
130 std::chrono::duration<double>::zero(),
131 [&expectedMsgs, &current](
132 StringPiece msg, const std::chrono::duration<double>&) {
133 EXPECT_EQ(expectedMsgs.at(current), msg);
134 current++;
135 });
136 oldTimer.log("BEFORE_MOVE");
137 auto newTimer = std::move(oldTimer); // force the move-ctor
138 return newTimer;
139 }();
140 timer.log("AFTER_MOVE");
141}
142