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