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 // The testcases in this file are expected to pass or be skipped with any value
17 // of ABSL_MIN_LOG_LEVEL
18
19 #include <cerrno>
20 #include <sstream>
21 #include <string>
22
23 #include "gmock/gmock.h"
24 #include "gtest/gtest.h"
25 #include "absl/base/internal/sysinfo.h"
26 #include "absl/base/log_severity.h"
27 #include "absl/log/globals.h"
28 #include "absl/log/internal/test_actions.h"
29 #include "absl/log/internal/test_helpers.h"
30 #include "absl/log/internal/test_matchers.h"
31 #include "absl/log/log.h"
32 #include "absl/log/log_entry.h"
33 #include "absl/log/scoped_mock_log.h"
34
35 namespace {
36 #if GTEST_HAS_DEATH_TEST
37 using ::absl::log_internal::DeathTestExpectedLogging;
38 using ::absl::log_internal::DeathTestUnexpectedLogging;
39 using ::absl::log_internal::DeathTestValidateExpectations;
40 using ::absl::log_internal::DiedOfFatal;
41 using ::absl::log_internal::DiedOfQFatal;
42 #endif
43 using ::absl::log_internal::LoggingEnabledAt;
44 using ::absl::log_internal::LogSeverity;
45 using ::absl::log_internal::Prefix;
46 using ::absl::log_internal::SourceBasename;
47 using ::absl::log_internal::SourceFilename;
48 using ::absl::log_internal::SourceLine;
49 using ::absl::log_internal::Stacktrace;
50 using ::absl::log_internal::TextMessage;
51 using ::absl::log_internal::ThreadID;
52 using ::absl::log_internal::TimestampInMatchWindow;
53 using ::absl::log_internal::Verbosity;
54 using ::testing::AnyNumber;
55 using ::testing::Eq;
56 using ::testing::IsEmpty;
57 using ::testing::IsTrue;
58
59 class BasicLogTest : public testing::TestWithParam<absl::LogSeverityAtLeast> {};
60
ThresholdName(testing::TestParamInfo<absl::LogSeverityAtLeast> severity)61 std::string ThresholdName(
62 testing::TestParamInfo<absl::LogSeverityAtLeast> severity) {
63 std::stringstream ostr;
64 ostr << severity.param;
65 return ostr.str().substr(
66 severity.param == absl::LogSeverityAtLeast::kInfinity ? 0 : 2);
67 }
68
69 INSTANTIATE_TEST_SUITE_P(WithParam, BasicLogTest,
70 testing::Values(absl::LogSeverityAtLeast::kInfo,
71 absl::LogSeverityAtLeast::kWarning,
72 absl::LogSeverityAtLeast::kError,
73 absl::LogSeverityAtLeast::kFatal,
74 absl::LogSeverityAtLeast::kInfinity),
75 ThresholdName);
76
TEST_P(BasicLogTest,Info)77 TEST_P(BasicLogTest, Info) {
78 absl::log_internal::ScopedMinLogLevel scoped_min_log_level(GetParam());
79
80 absl::ScopedMockLog test_sink(absl::MockLogDefault::kDisallowUnexpected);
81
82 const int log_line = __LINE__ + 1;
83 auto do_log = [] { LOG(INFO) << "hello world"; };
84
85 if (LoggingEnabledAt(absl::LogSeverity::kInfo)) {
86 EXPECT_CALL(
87 test_sink,
88 Send(AllOf(SourceFilename(Eq(__FILE__)),
89 SourceBasename(Eq("basic_log_test.cc")),
90 SourceLine(Eq(log_line)), Prefix(IsTrue()),
91 LogSeverity(Eq(absl::LogSeverity::kInfo)),
92 TimestampInMatchWindow(),
93 ThreadID(Eq(absl::base_internal::GetTID())),
94 TextMessage(Eq("hello world")),
95 Verbosity(Eq(absl::LogEntry::kNoVerbosityLevel)),
96 ENCODED_MESSAGE(EqualsProto(R"pb(value {
97 literal: "hello world"
98 })pb")),
99 Stacktrace(IsEmpty()))));
100 }
101
102 test_sink.StartCapturingLogs();
103 do_log();
104 }
105
TEST_P(BasicLogTest,Warning)106 TEST_P(BasicLogTest, Warning) {
107 absl::log_internal::ScopedMinLogLevel scoped_min_log_level(GetParam());
108
109 absl::ScopedMockLog test_sink(absl::MockLogDefault::kDisallowUnexpected);
110
111 const int log_line = __LINE__ + 1;
112 auto do_log = [] { LOG(WARNING) << "hello world"; };
113
114 if (LoggingEnabledAt(absl::LogSeverity::kWarning)) {
115 EXPECT_CALL(
116 test_sink,
117 Send(AllOf(SourceFilename(Eq(__FILE__)),
118 SourceBasename(Eq("basic_log_test.cc")),
119 SourceLine(Eq(log_line)), Prefix(IsTrue()),
120 LogSeverity(Eq(absl::LogSeverity::kWarning)),
121 TimestampInMatchWindow(),
122 ThreadID(Eq(absl::base_internal::GetTID())),
123 TextMessage(Eq("hello world")),
124 Verbosity(Eq(absl::LogEntry::kNoVerbosityLevel)),
125 ENCODED_MESSAGE(EqualsProto(R"pb(value {
126 literal: "hello world"
127 })pb")),
128 Stacktrace(IsEmpty()))));
129 }
130
131 test_sink.StartCapturingLogs();
132 do_log();
133 }
134
TEST_P(BasicLogTest,Error)135 TEST_P(BasicLogTest, Error) {
136 absl::log_internal::ScopedMinLogLevel scoped_min_log_level(GetParam());
137
138 absl::ScopedMockLog test_sink(absl::MockLogDefault::kDisallowUnexpected);
139
140 const int log_line = __LINE__ + 1;
141 auto do_log = [] { LOG(ERROR) << "hello world"; };
142
143 if (LoggingEnabledAt(absl::LogSeverity::kError)) {
144 EXPECT_CALL(
145 test_sink,
146 Send(AllOf(SourceFilename(Eq(__FILE__)),
147 SourceBasename(Eq("basic_log_test.cc")),
148 SourceLine(Eq(log_line)), Prefix(IsTrue()),
149 LogSeverity(Eq(absl::LogSeverity::kError)),
150 TimestampInMatchWindow(),
151 ThreadID(Eq(absl::base_internal::GetTID())),
152 TextMessage(Eq("hello world")),
153 Verbosity(Eq(absl::LogEntry::kNoVerbosityLevel)),
154 ENCODED_MESSAGE(EqualsProto(R"pb(value {
155 literal: "hello world"
156 })pb")),
157 Stacktrace(IsEmpty()))));
158 }
159
160 test_sink.StartCapturingLogs();
161 do_log();
162 }
163
164 #if GTEST_HAS_DEATH_TEST
165 using BasicLogDeathTest = BasicLogTest;
166
167 INSTANTIATE_TEST_SUITE_P(WithParam, BasicLogDeathTest,
168 testing::Values(absl::LogSeverityAtLeast::kInfo,
169 absl::LogSeverityAtLeast::kFatal,
170 absl::LogSeverityAtLeast::kInfinity),
171 ThresholdName);
172
TEST_P(BasicLogDeathTest,Fatal)173 TEST_P(BasicLogDeathTest, Fatal) {
174 absl::log_internal::ScopedMinLogLevel scoped_min_log_level(GetParam());
175
176 const int log_line = __LINE__ + 1;
177 auto do_log = [] { LOG(FATAL) << "hello world"; };
178
179 EXPECT_EXIT(
180 {
181 absl::ScopedMockLog test_sink(
182 absl::MockLogDefault::kDisallowUnexpected);
183
184 EXPECT_CALL(test_sink, Send)
185 .Times(AnyNumber())
186 .WillRepeatedly(DeathTestUnexpectedLogging());
187
188 ::testing::InSequence s;
189
190 // Note the logic in DeathTestValidateExpectations() caters for the case
191 // of logging being disabled at FATAL level.
192
193 if (LoggingEnabledAt(absl::LogSeverity::kFatal)) {
194 // The first call without the stack trace.
195 EXPECT_CALL(
196 test_sink,
197 Send(AllOf(SourceFilename(Eq(__FILE__)),
198 SourceBasename(Eq("basic_log_test.cc")),
199 SourceLine(Eq(log_line)), Prefix(IsTrue()),
200 LogSeverity(Eq(absl::LogSeverity::kFatal)),
201 TimestampInMatchWindow(),
202 ThreadID(Eq(absl::base_internal::GetTID())),
203 TextMessage(Eq("hello world")),
204 Verbosity(Eq(absl::LogEntry::kNoVerbosityLevel)),
205 ENCODED_MESSAGE(EqualsProto(
206 R"pb(value { literal: "hello world" })pb")),
207 Stacktrace(IsEmpty()))))
208 .WillOnce(DeathTestExpectedLogging());
209
210 // The second call with the stack trace.
211 EXPECT_CALL(
212 test_sink,
213 Send(AllOf(SourceFilename(Eq(__FILE__)),
214 SourceBasename(Eq("basic_log_test.cc")),
215 SourceLine(Eq(log_line)), Prefix(IsTrue()),
216 LogSeverity(Eq(absl::LogSeverity::kFatal)),
217 TimestampInMatchWindow(),
218 ThreadID(Eq(absl::base_internal::GetTID())),
219 TextMessage(Eq("hello world")),
220 Verbosity(Eq(absl::LogEntry::kNoVerbosityLevel)),
221 ENCODED_MESSAGE(EqualsProto(
222 R"pb(value { literal: "hello world" })pb")),
223 Stacktrace(Not(IsEmpty())))))
224 .WillOnce(DeathTestExpectedLogging());
225 }
226
227 test_sink.StartCapturingLogs();
228 do_log();
229 },
230 DiedOfFatal, DeathTestValidateExpectations());
231 }
232
TEST_P(BasicLogDeathTest,QFatal)233 TEST_P(BasicLogDeathTest, QFatal) {
234 absl::log_internal::ScopedMinLogLevel scoped_min_log_level(GetParam());
235
236 const int log_line = __LINE__ + 1;
237 auto do_log = [] { LOG(QFATAL) << "hello world"; };
238
239 EXPECT_EXIT(
240 {
241 absl::ScopedMockLog test_sink(
242 absl::MockLogDefault::kDisallowUnexpected);
243
244 EXPECT_CALL(test_sink, Send)
245 .Times(AnyNumber())
246 .WillRepeatedly(DeathTestUnexpectedLogging());
247
248 if (LoggingEnabledAt(absl::LogSeverity::kFatal)) {
249 EXPECT_CALL(
250 test_sink,
251 Send(AllOf(SourceFilename(Eq(__FILE__)),
252 SourceBasename(Eq("basic_log_test.cc")),
253 SourceLine(Eq(log_line)), Prefix(IsTrue()),
254 LogSeverity(Eq(absl::LogSeverity::kFatal)),
255 TimestampInMatchWindow(),
256 ThreadID(Eq(absl::base_internal::GetTID())),
257 TextMessage(Eq("hello world")),
258 Verbosity(Eq(absl::LogEntry::kNoVerbosityLevel)),
259 ENCODED_MESSAGE(EqualsProto(
260 R"pb(value { literal: "hello world" })pb")),
261 Stacktrace(IsEmpty()))))
262 .WillOnce(DeathTestExpectedLogging());
263 }
264
265 test_sink.StartCapturingLogs();
266 do_log();
267 },
268 DiedOfQFatal, DeathTestValidateExpectations());
269 }
270 #endif
271
TEST_P(BasicLogTest,Level)272 TEST_P(BasicLogTest, Level) {
273 absl::log_internal::ScopedMinLogLevel scoped_min_log_level(GetParam());
274
275 for (auto severity : {absl::LogSeverity::kInfo, absl::LogSeverity::kWarning,
276 absl::LogSeverity::kError}) {
277 absl::ScopedMockLog test_sink(absl::MockLogDefault::kDisallowUnexpected);
278
279 const int log_line = __LINE__ + 1;
280 auto do_log = [severity] { LOG(LEVEL(severity)) << "hello world"; };
281
282 if (LoggingEnabledAt(severity)) {
283 EXPECT_CALL(
284 test_sink,
285 Send(AllOf(SourceFilename(Eq(__FILE__)),
286 SourceBasename(Eq("basic_log_test.cc")),
287 SourceLine(Eq(log_line)), Prefix(IsTrue()),
288 LogSeverity(Eq(severity)), TimestampInMatchWindow(),
289 ThreadID(Eq(absl::base_internal::GetTID())),
290 TextMessage(Eq("hello world")),
291 Verbosity(Eq(absl::LogEntry::kNoVerbosityLevel)),
292 ENCODED_MESSAGE(EqualsProto(R"pb(value {
293 literal: "hello world"
294 })pb")),
295 Stacktrace(IsEmpty()))));
296 }
297 test_sink.StartCapturingLogs();
298 do_log();
299 }
300 }
301
302 #if GTEST_HAS_DEATH_TEST
TEST_P(BasicLogDeathTest,Level)303 TEST_P(BasicLogDeathTest, Level) {
304 // TODO(b/242568884): re-enable once bug is fixed.
305 // absl::log_internal::ScopedMinLogLevel scoped_min_log_level(GetParam());
306
307 // Ensure that `severity` is not a compile-time constant to prove that
308 // `LOG(LEVEL(severity))` works regardless:
309 auto volatile severity = absl::LogSeverity::kFatal;
310
311 const int log_line = __LINE__ + 1;
312 auto do_log = [severity] { LOG(LEVEL(severity)) << "hello world"; };
313
314 EXPECT_EXIT(
315 {
316 absl::ScopedMockLog test_sink(
317 absl::MockLogDefault::kDisallowUnexpected);
318
319 EXPECT_CALL(test_sink, Send)
320 .Times(AnyNumber())
321 .WillRepeatedly(DeathTestUnexpectedLogging());
322
323 ::testing::InSequence s;
324
325 if (LoggingEnabledAt(absl::LogSeverity::kFatal)) {
326 EXPECT_CALL(
327 test_sink,
328 Send(AllOf(SourceFilename(Eq(__FILE__)),
329 SourceBasename(Eq("basic_log_test.cc")),
330 SourceLine(Eq(log_line)), Prefix(IsTrue()),
331 LogSeverity(Eq(absl::LogSeverity::kFatal)),
332 TimestampInMatchWindow(),
333 ThreadID(Eq(absl::base_internal::GetTID())),
334 TextMessage(Eq("hello world")),
335 Verbosity(Eq(absl::LogEntry::kNoVerbosityLevel)),
336 ENCODED_MESSAGE(EqualsProto(
337 R"pb(value { literal: "hello world" })pb")),
338 Stacktrace(IsEmpty()))))
339 .WillOnce(DeathTestExpectedLogging());
340
341 EXPECT_CALL(
342 test_sink,
343 Send(AllOf(SourceFilename(Eq(__FILE__)),
344 SourceBasename(Eq("basic_log_test.cc")),
345 SourceLine(Eq(log_line)), Prefix(IsTrue()),
346 LogSeverity(Eq(absl::LogSeverity::kFatal)),
347 TimestampInMatchWindow(),
348 ThreadID(Eq(absl::base_internal::GetTID())),
349 TextMessage(Eq("hello world")),
350 Verbosity(Eq(absl::LogEntry::kNoVerbosityLevel)),
351 ENCODED_MESSAGE(EqualsProto(
352 R"pb(value { literal: "hello world" })pb")),
353 Stacktrace(Not(IsEmpty())))))
354 .WillOnce(DeathTestExpectedLogging());
355 }
356
357 test_sink.StartCapturingLogs();
358 do_log();
359 },
360 DiedOfFatal, DeathTestValidateExpectations());
361 }
362 #endif
363
TEST_P(BasicLogTest,LevelClampsNegativeValues)364 TEST_P(BasicLogTest, LevelClampsNegativeValues) {
365 absl::log_internal::ScopedMinLogLevel scoped_min_log_level(GetParam());
366
367 if (!LoggingEnabledAt(absl::LogSeverity::kInfo)) {
368 GTEST_SKIP() << "This test cases required INFO log to be enabled";
369 return;
370 }
371
372 absl::ScopedMockLog test_sink(absl::MockLogDefault::kDisallowUnexpected);
373
374 EXPECT_CALL(test_sink, Send(LogSeverity(Eq(absl::LogSeverity::kInfo))));
375
376 test_sink.StartCapturingLogs();
377 LOG(LEVEL(-1)) << "hello world";
378 }
379
TEST_P(BasicLogTest,LevelClampsLargeValues)380 TEST_P(BasicLogTest, LevelClampsLargeValues) {
381 absl::log_internal::ScopedMinLogLevel scoped_min_log_level(GetParam());
382
383 if (!LoggingEnabledAt(absl::LogSeverity::kError)) {
384 GTEST_SKIP() << "This test cases required ERROR log to be enabled";
385 return;
386 }
387
388 absl::ScopedMockLog test_sink(absl::MockLogDefault::kDisallowUnexpected);
389
390 EXPECT_CALL(test_sink, Send(LogSeverity(Eq(absl::LogSeverity::kError))));
391
392 test_sink.StartCapturingLogs();
393 LOG(LEVEL(static_cast<int>(absl::LogSeverity::kFatal) + 1)) << "hello world";
394 }
395
TEST(ErrnoPreservationTest,InSeverityExpression)396 TEST(ErrnoPreservationTest, InSeverityExpression) {
397 errno = 77;
398 int saved_errno;
399 LOG(LEVEL((saved_errno = errno, absl::LogSeverity::kInfo)));
400 EXPECT_THAT(saved_errno, Eq(77));
401 }
402
TEST(ErrnoPreservationTest,InStreamedExpression)403 TEST(ErrnoPreservationTest, InStreamedExpression) {
404 if (!LoggingEnabledAt(absl::LogSeverity::kInfo)) {
405 GTEST_SKIP() << "This test cases required INFO log to be enabled";
406 return;
407 }
408
409 errno = 77;
410 int saved_errno = 0;
411 LOG(INFO) << (saved_errno = errno, "hello world");
412 EXPECT_THAT(saved_errno, Eq(77));
413 }
414
TEST(ErrnoPreservationTest,AfterStatement)415 TEST(ErrnoPreservationTest, AfterStatement) {
416 errno = 77;
417 LOG(INFO);
418 const int saved_errno = errno;
419 EXPECT_THAT(saved_errno, Eq(77));
420 }
421
422 // Tests that using a variable/parameter in a logging statement suppresses
423 // unused-variable/parameter warnings.
424 // -----------------------------------------------------------------------
425 class UnusedVariableWarningCompileTest {
426 // These four don't prove anything unless `ABSL_MIN_LOG_LEVEL` is greater than
427 // `kInfo`.
LoggedVariable()428 static void LoggedVariable() {
429 const int x = 0;
430 LOG(INFO) << x;
431 }
LoggedParameter(const int x)432 static void LoggedParameter(const int x) { LOG(INFO) << x; }
SeverityVariable()433 static void SeverityVariable() {
434 const int x = 0;
435 LOG(LEVEL(x)) << "hello world";
436 }
SeverityParameter(const int x)437 static void SeverityParameter(const int x) { LOG(LEVEL(x)) << "hello world"; }
438 };
439
440 } // namespace
441