1 //
2 // Copyright 2022 The Abseil Authors.
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 // https://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 #include "absl/log/scoped_mock_log.h"
17
18 #include <memory>
19 #include <thread> // NOLINT(build/c++11)
20
21 #include "gmock/gmock.h"
22 #include "gtest/gtest-spi.h"
23 #include "gtest/gtest.h"
24 #include "absl/base/attributes.h"
25 #include "absl/base/log_severity.h"
26 #include "absl/log/globals.h"
27 #include "absl/log/internal/test_helpers.h"
28 #include "absl/log/internal/test_matchers.h"
29 #include "absl/log/log.h"
30 #include "absl/memory/memory.h"
31 #include "absl/strings/match.h"
32 #include "absl/strings/string_view.h"
33 #include "absl/synchronization/barrier.h"
34 #include "absl/synchronization/notification.h"
35
36 namespace {
37
38 using ::testing::_;
39 using ::testing::AnyNumber;
40 using ::testing::Eq;
41 using ::testing::HasSubstr;
42 using ::testing::InSequence;
43 using ::testing::Lt;
44 using ::testing::Truly;
45 using absl::log_internal::SourceBasename;
46 using absl::log_internal::SourceFilename;
47 using absl::log_internal::SourceLine;
48 using absl::log_internal::TextMessageWithPrefix;
49 using absl::log_internal::ThreadID;
50
51 auto* test_env ABSL_ATTRIBUTE_UNUSED = ::testing::AddGlobalTestEnvironment(
52 new absl::log_internal::LogTestEnvironment);
53
54 #if GTEST_HAS_DEATH_TEST
TEST(ScopedMockLogDeathTest,StartCapturingLogsCannotBeCalledWhenAlreadyCapturing)55 TEST(ScopedMockLogDeathTest,
56 StartCapturingLogsCannotBeCalledWhenAlreadyCapturing) {
57 EXPECT_DEATH(
58 {
59 absl::ScopedMockLog log;
60 log.StartCapturingLogs();
61 log.StartCapturingLogs();
62 },
63 "StartCapturingLogs");
64 }
65
TEST(ScopedMockLogDeathTest,StopCapturingLogsCannotBeCalledWhenNotCapturing)66 TEST(ScopedMockLogDeathTest, StopCapturingLogsCannotBeCalledWhenNotCapturing) {
67 EXPECT_DEATH(
68 {
69 absl::ScopedMockLog log;
70 log.StopCapturingLogs();
71 },
72 "StopCapturingLogs");
73 }
74
TEST(ScopedMockLogDeathTest,FailsCheckIfStartCapturingLogsIsNeverCalled)75 TEST(ScopedMockLogDeathTest, FailsCheckIfStartCapturingLogsIsNeverCalled) {
76 EXPECT_DEATH({ absl::ScopedMockLog log; },
77 "Did you forget to call StartCapturingLogs");
78 }
79 #endif
80
81 // Tests that ScopedMockLog intercepts LOG()s when it's alive.
TEST(ScopedMockLogTest,LogMockCatchAndMatchStrictExpectations)82 TEST(ScopedMockLogTest, LogMockCatchAndMatchStrictExpectations) {
83 absl::ScopedMockLog log;
84
85 // The following expectations must match in the order they appear.
86 InSequence s;
87 EXPECT_CALL(log,
88 Log(absl::LogSeverity::kWarning, HasSubstr(__FILE__), "Danger."));
89 EXPECT_CALL(log, Log(absl::LogSeverity::kInfo, _, "Working...")).Times(2);
90 EXPECT_CALL(log, Log(absl::LogSeverity::kError, _, "Bad!!"));
91
92 log.StartCapturingLogs();
93 LOG(WARNING) << "Danger.";
94 LOG(INFO) << "Working...";
95 LOG(INFO) << "Working...";
96 LOG(ERROR) << "Bad!!";
97 }
98
TEST(ScopedMockLogTest,LogMockCatchAndMatchSendExpectations)99 TEST(ScopedMockLogTest, LogMockCatchAndMatchSendExpectations) {
100 absl::ScopedMockLog log;
101
102 EXPECT_CALL(
103 log,
104 Send(AllOf(SourceFilename(Eq("/my/very/very/very_long_source_file.cc")),
105 SourceBasename(Eq("very_long_source_file.cc")),
106 SourceLine(Eq(777)), ThreadID(Eq(absl::LogEntry::tid_t{1234})),
107 TextMessageWithPrefix(Truly([](absl::string_view msg) {
108 return absl::EndsWith(
109 msg, " very_long_source_file.cc:777] Info message");
110 })))));
111
112 log.StartCapturingLogs();
113 LOG(INFO)
114 .AtLocation("/my/very/very/very_long_source_file.cc", 777)
115 .WithThreadID(1234)
116 << "Info message";
117 }
118
TEST(ScopedMockLogTest,ScopedMockLogCanBeNice)119 TEST(ScopedMockLogTest, ScopedMockLogCanBeNice) {
120 absl::ScopedMockLog log;
121
122 InSequence s;
123 EXPECT_CALL(log,
124 Log(absl::LogSeverity::kWarning, HasSubstr(__FILE__), "Danger."));
125 EXPECT_CALL(log, Log(absl::LogSeverity::kInfo, _, "Working...")).Times(2);
126 EXPECT_CALL(log, Log(absl::LogSeverity::kError, _, "Bad!!"));
127
128 log.StartCapturingLogs();
129
130 // Any number of these are OK.
131 LOG(INFO) << "Info message.";
132 // Any number of these are OK.
133 LOG(WARNING).AtLocation("SomeOtherFile.cc", 100) << "Danger ";
134
135 LOG(WARNING) << "Danger.";
136
137 // Any number of these are OK.
138 LOG(INFO) << "Info message.";
139 // Any number of these are OK.
140 LOG(WARNING).AtLocation("SomeOtherFile.cc", 100) << "Danger ";
141
142 LOG(INFO) << "Working...";
143
144 // Any number of these are OK.
145 LOG(INFO) << "Info message.";
146 // Any number of these are OK.
147 LOG(WARNING).AtLocation("SomeOtherFile.cc", 100) << "Danger ";
148
149 LOG(INFO) << "Working...";
150
151 // Any number of these are OK.
152 LOG(INFO) << "Info message.";
153 // Any number of these are OK.
154 LOG(WARNING).AtLocation("SomeOtherFile.cc", 100) << "Danger ";
155
156 LOG(ERROR) << "Bad!!";
157
158 // Any number of these are OK.
159 LOG(INFO) << "Info message.";
160 // Any number of these are OK.
161 LOG(WARNING).AtLocation("SomeOtherFile.cc", 100) << "Danger ";
162 }
163
164 // Tests that ScopedMockLog generates a test failure if a message is logged
165 // that is not expected (here, that means ERROR or FATAL).
TEST(ScopedMockLogTest,RejectsUnexpectedLogs)166 TEST(ScopedMockLogTest, RejectsUnexpectedLogs) {
167 EXPECT_NONFATAL_FAILURE(
168 {
169 absl::ScopedMockLog log(absl::MockLogDefault::kDisallowUnexpected);
170 // Any INFO and WARNING messages are permitted.
171 EXPECT_CALL(log, Log(Lt(absl::LogSeverity::kError), _, _))
172 .Times(AnyNumber());
173 log.StartCapturingLogs();
174 LOG(INFO) << "Ignored";
175 LOG(WARNING) << "Ignored";
176 LOG(ERROR) << "Should not be ignored";
177 },
178 "Should not be ignored");
179 }
180
TEST(ScopedMockLogTest,CapturesLogsAfterStartCapturingLogs)181 TEST(ScopedMockLogTest, CapturesLogsAfterStartCapturingLogs) {
182 absl::SetStderrThreshold(absl::LogSeverityAtLeast::kInfinity);
183 absl::ScopedMockLog log;
184
185 // The ScopedMockLog object shouldn't see these LOGs, as it hasn't
186 // started capturing LOGs yet.
187 LOG(INFO) << "Ignored info";
188 LOG(WARNING) << "Ignored warning";
189 LOG(ERROR) << "Ignored error";
190
191 EXPECT_CALL(log, Log(absl::LogSeverity::kInfo, _, "Expected info"));
192 log.StartCapturingLogs();
193
194 // Only this LOG will be seen by the ScopedMockLog.
195 LOG(INFO) << "Expected info";
196 }
197
TEST(ScopedMockLogTest,DoesNotCaptureLogsAfterStopCapturingLogs)198 TEST(ScopedMockLogTest, DoesNotCaptureLogsAfterStopCapturingLogs) {
199 absl::ScopedMockLog log;
200 EXPECT_CALL(log, Log(absl::LogSeverity::kInfo, _, "Expected info"));
201
202 log.StartCapturingLogs();
203
204 // This LOG should be seen by the ScopedMockLog.
205 LOG(INFO) << "Expected info";
206
207 log.StopCapturingLogs();
208
209 // The ScopedMockLog object shouldn't see these LOGs, as it has
210 // stopped capturing LOGs.
211 LOG(INFO) << "Ignored info";
212 LOG(WARNING) << "Ignored warning";
213 LOG(ERROR) << "Ignored error";
214 }
215
216 // Tests that all messages are intercepted regardless of issuing thread. The
217 // purpose of this test is NOT to exercise thread-safety.
TEST(ScopedMockLogTest,LogFromMultipleThreads)218 TEST(ScopedMockLogTest, LogFromMultipleThreads) {
219 absl::ScopedMockLog log;
220
221 // We don't establish an order to expectations here, since the threads may
222 // execute their log statements in different order.
223 EXPECT_CALL(log, Log(absl::LogSeverity::kInfo, __FILE__, "Thread 1"));
224 EXPECT_CALL(log, Log(absl::LogSeverity::kInfo, __FILE__, "Thread 2"));
225
226 log.StartCapturingLogs();
227
228 absl::Barrier barrier(2);
229 std::thread thread1([&barrier]() {
230 barrier.Block();
231 LOG(INFO) << "Thread 1";
232 });
233 std::thread thread2([&barrier]() {
234 barrier.Block();
235 LOG(INFO) << "Thread 2";
236 });
237
238 thread1.join();
239 thread2.join();
240 }
241
242 // Tests that no sequence will be imposed on two LOG message expectations from
243 // different threads. This test would actually deadlock if replaced to two LOG
244 // statements from the same thread.
TEST(ScopedMockLogTest,NoSequenceWithMultipleThreads)245 TEST(ScopedMockLogTest, NoSequenceWithMultipleThreads) {
246 absl::ScopedMockLog log;
247
248 absl::Barrier barrier(2);
249 EXPECT_CALL(log, Log(absl::LogSeverity::kInfo, _, _))
250 .Times(2)
251 .WillRepeatedly([&barrier]() { barrier.Block(); });
252
253 log.StartCapturingLogs();
254
255 std::thread thread1([]() { LOG(INFO) << "Thread 1"; });
256 std::thread thread2([]() { LOG(INFO) << "Thread 2"; });
257
258 thread1.join();
259 thread2.join();
260 }
261
TEST(ScopedMockLogTsanTest,ScopedMockLogCanBeDeletedWhenAnotherThreadIsLogging)262 TEST(ScopedMockLogTsanTest,
263 ScopedMockLogCanBeDeletedWhenAnotherThreadIsLogging) {
264 auto log = absl::make_unique<absl::ScopedMockLog>();
265 EXPECT_CALL(*log, Log(absl::LogSeverity::kInfo, __FILE__, "Thread log"))
266 .Times(AnyNumber());
267
268 log->StartCapturingLogs();
269
270 absl::Notification logging_started;
271
272 std::thread thread([&logging_started]() {
273 for (int i = 0; i < 100; ++i) {
274 if (i == 50) logging_started.Notify();
275 LOG(INFO) << "Thread log";
276 }
277 });
278
279 logging_started.WaitForNotification();
280 log.reset();
281 thread.join();
282 }
283
TEST(ScopedMockLogTest,AsLocalSink)284 TEST(ScopedMockLogTest, AsLocalSink) {
285 absl::ScopedMockLog log(absl::MockLogDefault::kDisallowUnexpected);
286
287 EXPECT_CALL(log, Log(_, _, "two"));
288 EXPECT_CALL(log, Log(_, _, "three"));
289
290 LOG(INFO) << "one";
291 LOG(INFO).ToSinkOnly(&log.UseAsLocalSink()) << "two";
292 LOG(INFO).ToSinkAlso(&log.UseAsLocalSink()) << "three";
293 }
294
295 } // namespace
296