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#ifndef ABSL_LOG_LOG_BASIC_TEST_IMPL_H_ 20#define ABSL_LOG_LOG_BASIC_TEST_IMPL_H_ 21 22// Verify that both sets of macros behave identically by parameterizing the 23// entire test file. 24#ifndef ABSL_TEST_LOG 25#error ABSL_TEST_LOG must be defined for these tests to work. 26#endif 27 28#ifndef ABSL_TEST_DLOG 29#error ABSL_TEST_DLOG must be defined for these tests to work. 30#endif 31 32#include <cerrno> 33#include <sstream> 34#include <string> 35 36#include "gmock/gmock.h" 37#include "gtest/gtest.h" 38#include "absl/base/internal/sysinfo.h" 39#include "absl/base/log_severity.h" 40#include "absl/log/globals.h" 41#include "absl/log/internal/globals.h" 42#include "absl/log/internal/test_actions.h" 43#include "absl/log/internal/test_helpers.h" 44#include "absl/log/internal/test_matchers.h" 45#include "absl/log/log_entry.h" 46#include "absl/log/scoped_mock_log.h" 47 48namespace absl_log_internal { 49#if GTEST_HAS_DEATH_TEST 50using ::absl::log_internal::DeathTestExpectedLogging; 51using ::absl::log_internal::DeathTestUnexpectedLogging; 52using ::absl::log_internal::DeathTestValidateExpectations; 53using ::absl::log_internal::DiedOfFatal; 54using ::absl::log_internal::DiedOfQFatal; 55#endif 56using ::absl::log_internal::LoggingEnabledAt; 57using ::absl::log_internal::LogSeverity; 58using ::absl::log_internal::Prefix; 59using ::absl::log_internal::SourceBasename; 60using ::absl::log_internal::SourceFilename; 61using ::absl::log_internal::SourceLine; 62using ::absl::log_internal::Stacktrace; 63using ::absl::log_internal::TextMessage; 64using ::absl::log_internal::ThreadID; 65using ::absl::log_internal::TimestampInMatchWindow; 66using ::absl::log_internal::Verbosity; 67using ::testing::AnyNumber; 68using ::testing::Eq; 69using ::testing::IsEmpty; 70using ::testing::IsTrue; 71 72class BasicLogTest : public testing::TestWithParam<absl::LogSeverityAtLeast> {}; 73 74std::string ThresholdName( 75 testing::TestParamInfo<absl::LogSeverityAtLeast> severity) { 76 std::stringstream ostr; 77 ostr << severity.param; 78 return ostr.str().substr( 79 severity.param == absl::LogSeverityAtLeast::kInfinity ? 0 : 2); 80} 81 82INSTANTIATE_TEST_SUITE_P(WithParam, BasicLogTest, 83 testing::Values(absl::LogSeverityAtLeast::kInfo, 84 absl::LogSeverityAtLeast::kWarning, 85 absl::LogSeverityAtLeast::kError, 86 absl::LogSeverityAtLeast::kFatal, 87 absl::LogSeverityAtLeast::kInfinity), 88 ThresholdName); 89 90TEST_P(BasicLogTest, Info) { 91 absl::log_internal::ScopedMinLogLevel scoped_min_log_level(GetParam()); 92 93 absl::ScopedMockLog test_sink(absl::MockLogDefault::kDisallowUnexpected); 94 95 const int log_line = __LINE__ + 1; 96 auto do_log = [] { ABSL_TEST_LOG(INFO) << "hello world"; }; 97 98 if (LoggingEnabledAt(absl::LogSeverity::kInfo)) { 99 EXPECT_CALL( 100 test_sink, 101 Send(AllOf(SourceFilename(Eq(__FILE__)), 102 SourceBasename(Eq("log_basic_test_impl.inc")), 103 SourceLine(Eq(log_line)), Prefix(IsTrue()), 104 LogSeverity(Eq(absl::LogSeverity::kInfo)), 105 TimestampInMatchWindow(), 106 ThreadID(Eq(absl::base_internal::GetTID())), 107 TextMessage(Eq("hello world")), 108 Verbosity(Eq(absl::LogEntry::kNoVerbosityLevel)), 109 ENCODED_MESSAGE(EqualsProto(R"pb(value { 110 literal: "hello world" 111 })pb")), 112 Stacktrace(IsEmpty())))); 113 } 114 115 test_sink.StartCapturingLogs(); 116 do_log(); 117} 118 119TEST_P(BasicLogTest, Warning) { 120 absl::log_internal::ScopedMinLogLevel scoped_min_log_level(GetParam()); 121 122 absl::ScopedMockLog test_sink(absl::MockLogDefault::kDisallowUnexpected); 123 124 const int log_line = __LINE__ + 1; 125 auto do_log = [] { ABSL_TEST_LOG(WARNING) << "hello world"; }; 126 127 if (LoggingEnabledAt(absl::LogSeverity::kWarning)) { 128 EXPECT_CALL( 129 test_sink, 130 Send(AllOf(SourceFilename(Eq(__FILE__)), 131 SourceBasename(Eq("log_basic_test_impl.inc")), 132 SourceLine(Eq(log_line)), Prefix(IsTrue()), 133 LogSeverity(Eq(absl::LogSeverity::kWarning)), 134 TimestampInMatchWindow(), 135 ThreadID(Eq(absl::base_internal::GetTID())), 136 TextMessage(Eq("hello world")), 137 Verbosity(Eq(absl::LogEntry::kNoVerbosityLevel)), 138 ENCODED_MESSAGE(EqualsProto(R"pb(value { 139 literal: "hello world" 140 })pb")), 141 Stacktrace(IsEmpty())))); 142 } 143 144 test_sink.StartCapturingLogs(); 145 do_log(); 146} 147 148TEST_P(BasicLogTest, Error) { 149 absl::log_internal::ScopedMinLogLevel scoped_min_log_level(GetParam()); 150 151 absl::ScopedMockLog test_sink(absl::MockLogDefault::kDisallowUnexpected); 152 153 const int log_line = __LINE__ + 1; 154 auto do_log = [] { ABSL_TEST_LOG(ERROR) << "hello world"; }; 155 156 if (LoggingEnabledAt(absl::LogSeverity::kError)) { 157 EXPECT_CALL( 158 test_sink, 159 Send(AllOf(SourceFilename(Eq(__FILE__)), 160 SourceBasename(Eq("log_basic_test_impl.inc")), 161 SourceLine(Eq(log_line)), Prefix(IsTrue()), 162 LogSeverity(Eq(absl::LogSeverity::kError)), 163 TimestampInMatchWindow(), 164 ThreadID(Eq(absl::base_internal::GetTID())), 165 TextMessage(Eq("hello world")), 166 Verbosity(Eq(absl::LogEntry::kNoVerbosityLevel)), 167 ENCODED_MESSAGE(EqualsProto(R"pb(value { 168 literal: "hello world" 169 })pb")), 170 Stacktrace(IsEmpty())))); 171 } 172 173 test_sink.StartCapturingLogs(); 174 do_log(); 175} 176 177#if GTEST_HAS_DEATH_TEST 178using BasicLogDeathTest = BasicLogTest; 179 180INSTANTIATE_TEST_SUITE_P(WithParam, BasicLogDeathTest, 181 testing::Values(absl::LogSeverityAtLeast::kInfo, 182 absl::LogSeverityAtLeast::kFatal, 183 absl::LogSeverityAtLeast::kInfinity), 184 ThresholdName); 185 186TEST_P(BasicLogDeathTest, Fatal) { 187 absl::log_internal::ScopedMinLogLevel scoped_min_log_level(GetParam()); 188 189 const int log_line = __LINE__ + 1; 190 auto do_log = [] { ABSL_TEST_LOG(FATAL) << "hello world"; }; 191 192 EXPECT_EXIT( 193 { 194 absl::ScopedMockLog test_sink( 195 absl::MockLogDefault::kDisallowUnexpected); 196 197 EXPECT_CALL(test_sink, Send) 198 .Times(AnyNumber()) 199 .WillRepeatedly(DeathTestUnexpectedLogging()); 200 201 ::testing::InSequence s; 202 203 // Note the logic in DeathTestValidateExpectations() caters for the case 204 // of logging being disabled at FATAL level. 205 206 if (LoggingEnabledAt(absl::LogSeverity::kFatal)) { 207 // The first call without the stack trace. 208 EXPECT_CALL( 209 test_sink, 210 Send(AllOf(SourceFilename(Eq(__FILE__)), 211 SourceBasename(Eq("log_basic_test_impl.inc")), 212 SourceLine(Eq(log_line)), Prefix(IsTrue()), 213 LogSeverity(Eq(absl::LogSeverity::kFatal)), 214 TimestampInMatchWindow(), 215 ThreadID(Eq(absl::base_internal::GetTID())), 216 TextMessage(Eq("hello world")), 217 Verbosity(Eq(absl::LogEntry::kNoVerbosityLevel)), 218 ENCODED_MESSAGE(EqualsProto( 219 R"pb(value { literal: "hello world" })pb")), 220 Stacktrace(IsEmpty())))) 221 .WillOnce(DeathTestExpectedLogging()); 222 223 // The second call with the stack trace. 224 EXPECT_CALL( 225 test_sink, 226 Send(AllOf(SourceFilename(Eq(__FILE__)), 227 SourceBasename(Eq("log_basic_test_impl.inc")), 228 SourceLine(Eq(log_line)), Prefix(IsTrue()), 229 LogSeverity(Eq(absl::LogSeverity::kFatal)), 230 TimestampInMatchWindow(), 231 ThreadID(Eq(absl::base_internal::GetTID())), 232 TextMessage(Eq("hello world")), 233 Verbosity(Eq(absl::LogEntry::kNoVerbosityLevel)), 234 ENCODED_MESSAGE(EqualsProto( 235 R"pb(value { literal: "hello world" })pb")), 236 Stacktrace(Not(IsEmpty()))))) 237 .WillOnce(DeathTestExpectedLogging()); 238 } 239 240 test_sink.StartCapturingLogs(); 241 do_log(); 242 }, 243 DiedOfFatal, DeathTestValidateExpectations()); 244} 245 246TEST_P(BasicLogDeathTest, QFatal) { 247 absl::log_internal::ScopedMinLogLevel scoped_min_log_level(GetParam()); 248 249 const int log_line = __LINE__ + 1; 250 auto do_log = [] { ABSL_TEST_LOG(QFATAL) << "hello world"; }; 251 252 EXPECT_EXIT( 253 { 254 absl::ScopedMockLog test_sink( 255 absl::MockLogDefault::kDisallowUnexpected); 256 257 EXPECT_CALL(test_sink, Send) 258 .Times(AnyNumber()) 259 .WillRepeatedly(DeathTestUnexpectedLogging()); 260 261 if (LoggingEnabledAt(absl::LogSeverity::kFatal)) { 262 EXPECT_CALL( 263 test_sink, 264 Send(AllOf(SourceFilename(Eq(__FILE__)), 265 SourceBasename(Eq("log_basic_test_impl.inc")), 266 SourceLine(Eq(log_line)), Prefix(IsTrue()), 267 LogSeverity(Eq(absl::LogSeverity::kFatal)), 268 TimestampInMatchWindow(), 269 ThreadID(Eq(absl::base_internal::GetTID())), 270 TextMessage(Eq("hello world")), 271 Verbosity(Eq(absl::LogEntry::kNoVerbosityLevel)), 272 ENCODED_MESSAGE(EqualsProto( 273 R"pb(value { literal: "hello world" })pb")), 274 Stacktrace(IsEmpty())))) 275 .WillOnce(DeathTestExpectedLogging()); 276 } 277 278 test_sink.StartCapturingLogs(); 279 do_log(); 280 }, 281 DiedOfQFatal, DeathTestValidateExpectations()); 282} 283#endif 284 285#ifdef NDEBUG 286TEST_P(BasicLogTest, DFatal) { 287 absl::log_internal::ScopedMinLogLevel scoped_min_log_level(GetParam()); 288 289 absl::ScopedMockLog test_sink(absl::MockLogDefault::kDisallowUnexpected); 290 291 const int log_line = __LINE__ + 1; 292 auto do_log = [] { ABSL_TEST_LOG(DFATAL) << "hello world"; }; 293 294 if (LoggingEnabledAt(absl::LogSeverity::kError)) { 295 EXPECT_CALL( 296 test_sink, 297 Send(AllOf(SourceFilename(Eq(__FILE__)), 298 SourceBasename(Eq("log_basic_test_impl.inc")), 299 SourceLine(Eq(log_line)), Prefix(IsTrue()), 300 LogSeverity(Eq(absl::LogSeverity::kError)), 301 TimestampInMatchWindow(), 302 ThreadID(Eq(absl::base_internal::GetTID())), 303 TextMessage(Eq("hello world")), 304 Verbosity(Eq(absl::LogEntry::kNoVerbosityLevel)), 305 ENCODED_MESSAGE(EqualsProto(R"pb(value { 306 literal: "hello world" 307 })pb")), 308 Stacktrace(IsEmpty())))); 309 } 310 311 test_sink.StartCapturingLogs(); 312 do_log(); 313} 314 315#elif GTEST_HAS_DEATH_TEST 316TEST_P(BasicLogDeathTest, DFatal) { 317 // TODO(b/242568884): re-enable once bug is fixed. 318 // absl::log_internal::ScopedMinLogLevel scoped_min_log_level(GetParam()); 319 320 const int log_line = __LINE__ + 1; 321 auto do_log = [] { ABSL_TEST_LOG(DFATAL) << "hello world"; }; 322 323 EXPECT_EXIT( 324 { 325 absl::ScopedMockLog test_sink( 326 absl::MockLogDefault::kDisallowUnexpected); 327 328 EXPECT_CALL(test_sink, Send) 329 .Times(AnyNumber()) 330 .WillRepeatedly(DeathTestUnexpectedLogging()); 331 332 ::testing::InSequence s; 333 334 if (LoggingEnabledAt(absl::LogSeverity::kFatal)) { 335 // The first call without the stack trace. 336 EXPECT_CALL( 337 test_sink, 338 Send(AllOf(SourceFilename(Eq(__FILE__)), 339 SourceBasename(Eq("log_basic_test_impl.inc")), 340 SourceLine(Eq(log_line)), Prefix(IsTrue()), 341 LogSeverity(Eq(absl::LogSeverity::kFatal)), 342 TimestampInMatchWindow(), 343 ThreadID(Eq(absl::base_internal::GetTID())), 344 TextMessage(Eq("hello world")), 345 Verbosity(Eq(absl::LogEntry::kNoVerbosityLevel)), 346 ENCODED_MESSAGE(EqualsProto( 347 R"pb(value { literal: "hello world" })pb")), 348 Stacktrace(IsEmpty())))) 349 .WillOnce(DeathTestExpectedLogging()); 350 351 // The second call with the stack trace. 352 EXPECT_CALL( 353 test_sink, 354 Send(AllOf(SourceFilename(Eq(__FILE__)), 355 SourceBasename(Eq("log_basic_test_impl.inc")), 356 SourceLine(Eq(log_line)), Prefix(IsTrue()), 357 LogSeverity(Eq(absl::LogSeverity::kFatal)), 358 TimestampInMatchWindow(), 359 ThreadID(Eq(absl::base_internal::GetTID())), 360 TextMessage(Eq("hello world")), 361 Verbosity(Eq(absl::LogEntry::kNoVerbosityLevel)), 362 ENCODED_MESSAGE(EqualsProto( 363 R"pb(value { literal: "hello world" })pb")), 364 Stacktrace(Not(IsEmpty()))))) 365 .WillOnce(DeathTestExpectedLogging()); 366 } 367 368 test_sink.StartCapturingLogs(); 369 do_log(); 370 }, 371 DiedOfFatal, DeathTestValidateExpectations()); 372} 373#endif 374 375#ifndef NDEBUG 376TEST_P(BasicLogTest, DFatalIsCancellable) { 377 // LOG(DFATAL) does not die when DFATAL death is disabled. 378 absl::log_internal::SetExitOnDFatal(false); 379 ABSL_TEST_LOG(DFATAL) << "hello world"; 380 absl::log_internal::SetExitOnDFatal(true); 381} 382 383#if GTEST_HAS_DEATH_TEST 384TEST_P(BasicLogDeathTest, DLogFatalIsNotCancellable) { 385 EXPECT_EXIT( 386 { 387 absl::log_internal::SetExitOnDFatal(false); 388 ABSL_TEST_DLOG(FATAL) << "hello world"; 389 absl::log_internal::SetExitOnDFatal(true); 390 }, 391 DiedOfFatal, ""); 392} 393#endif 394#endif 395 396TEST_P(BasicLogTest, Level) { 397 absl::log_internal::ScopedMinLogLevel scoped_min_log_level(GetParam()); 398 399 for (auto severity : {absl::LogSeverity::kInfo, absl::LogSeverity::kWarning, 400 absl::LogSeverity::kError}) { 401 absl::ScopedMockLog test_sink(absl::MockLogDefault::kDisallowUnexpected); 402 403 const int log_line = __LINE__ + 2; 404 auto do_log = [severity] { 405 ABSL_TEST_LOG(LEVEL(severity)) << "hello world"; 406 }; 407 408 if (LoggingEnabledAt(severity)) { 409 EXPECT_CALL( 410 test_sink, 411 Send(AllOf(SourceFilename(Eq(__FILE__)), 412 SourceBasename(Eq("log_basic_test_impl.inc")), 413 SourceLine(Eq(log_line)), Prefix(IsTrue()), 414 LogSeverity(Eq(severity)), TimestampInMatchWindow(), 415 ThreadID(Eq(absl::base_internal::GetTID())), 416 TextMessage(Eq("hello world")), 417 Verbosity(Eq(absl::LogEntry::kNoVerbosityLevel)), 418 ENCODED_MESSAGE(EqualsProto(R"pb(value { 419 literal: "hello world" 420 })pb")), 421 Stacktrace(IsEmpty())))); 422 } 423 test_sink.StartCapturingLogs(); 424 do_log(); 425 } 426} 427 428#if GTEST_HAS_DEATH_TEST 429TEST_P(BasicLogDeathTest, Level) { 430 // TODO(b/242568884): re-enable once bug is fixed. 431 // absl::log_internal::ScopedMinLogLevel scoped_min_log_level(GetParam()); 432 433 // Ensure that `severity` is not a compile-time constant to prove that 434 // `LOG(LEVEL(severity))` works regardless: 435 auto volatile severity = absl::LogSeverity::kFatal; 436 437 const int log_line = __LINE__ + 1; 438 auto do_log = [severity] { ABSL_TEST_LOG(LEVEL(severity)) << "hello world"; }; 439 440 EXPECT_EXIT( 441 { 442 absl::ScopedMockLog test_sink( 443 absl::MockLogDefault::kDisallowUnexpected); 444 445 EXPECT_CALL(test_sink, Send) 446 .Times(AnyNumber()) 447 .WillRepeatedly(DeathTestUnexpectedLogging()); 448 449 ::testing::InSequence s; 450 451 if (LoggingEnabledAt(absl::LogSeverity::kFatal)) { 452 EXPECT_CALL( 453 test_sink, 454 Send(AllOf(SourceFilename(Eq(__FILE__)), 455 SourceBasename(Eq("log_basic_test_impl.inc")), 456 SourceLine(Eq(log_line)), Prefix(IsTrue()), 457 LogSeverity(Eq(absl::LogSeverity::kFatal)), 458 TimestampInMatchWindow(), 459 ThreadID(Eq(absl::base_internal::GetTID())), 460 TextMessage(Eq("hello world")), 461 Verbosity(Eq(absl::LogEntry::kNoVerbosityLevel)), 462 ENCODED_MESSAGE(EqualsProto( 463 R"pb(value { literal: "hello world" })pb")), 464 Stacktrace(IsEmpty())))) 465 .WillOnce(DeathTestExpectedLogging()); 466 467 EXPECT_CALL( 468 test_sink, 469 Send(AllOf(SourceFilename(Eq(__FILE__)), 470 SourceBasename(Eq("log_basic_test_impl.inc")), 471 SourceLine(Eq(log_line)), Prefix(IsTrue()), 472 LogSeverity(Eq(absl::LogSeverity::kFatal)), 473 TimestampInMatchWindow(), 474 ThreadID(Eq(absl::base_internal::GetTID())), 475 TextMessage(Eq("hello world")), 476 Verbosity(Eq(absl::LogEntry::kNoVerbosityLevel)), 477 ENCODED_MESSAGE(EqualsProto( 478 R"pb(value { literal: "hello world" })pb")), 479 Stacktrace(Not(IsEmpty()))))) 480 .WillOnce(DeathTestExpectedLogging()); 481 } 482 483 test_sink.StartCapturingLogs(); 484 do_log(); 485 }, 486 DiedOfFatal, DeathTestValidateExpectations()); 487} 488#endif 489 490TEST_P(BasicLogTest, LevelClampsNegativeValues) { 491 absl::log_internal::ScopedMinLogLevel scoped_min_log_level(GetParam()); 492 493 if (!LoggingEnabledAt(absl::LogSeverity::kInfo)) { 494 GTEST_SKIP() << "This test cases required INFO log to be enabled"; 495 return; 496 } 497 498 absl::ScopedMockLog test_sink(absl::MockLogDefault::kDisallowUnexpected); 499 500 EXPECT_CALL(test_sink, Send(LogSeverity(Eq(absl::LogSeverity::kInfo)))); 501 502 test_sink.StartCapturingLogs(); 503 ABSL_TEST_LOG(LEVEL(-1)) << "hello world"; 504} 505 506TEST_P(BasicLogTest, LevelClampsLargeValues) { 507 absl::log_internal::ScopedMinLogLevel scoped_min_log_level(GetParam()); 508 509 if (!LoggingEnabledAt(absl::LogSeverity::kError)) { 510 GTEST_SKIP() << "This test cases required ERROR log to be enabled"; 511 return; 512 } 513 514 absl::ScopedMockLog test_sink(absl::MockLogDefault::kDisallowUnexpected); 515 516 EXPECT_CALL(test_sink, Send(LogSeverity(Eq(absl::LogSeverity::kError)))); 517 518 test_sink.StartCapturingLogs(); 519 ABSL_TEST_LOG(LEVEL(static_cast<int>(absl::LogSeverity::kFatal) + 1)) 520 << "hello world"; 521} 522 523TEST(ErrnoPreservationTest, InSeverityExpression) { 524 errno = 77; 525 int saved_errno; 526 ABSL_TEST_LOG(LEVEL((saved_errno = errno, absl::LogSeverity::kInfo))); 527 EXPECT_THAT(saved_errno, Eq(77)); 528} 529 530TEST(ErrnoPreservationTest, InStreamedExpression) { 531 if (!LoggingEnabledAt(absl::LogSeverity::kInfo)) { 532 GTEST_SKIP() << "This test cases required INFO log to be enabled"; 533 return; 534 } 535 536 errno = 77; 537 int saved_errno = 0; 538 ABSL_TEST_LOG(INFO) << (saved_errno = errno, "hello world"); 539 EXPECT_THAT(saved_errno, Eq(77)); 540} 541 542TEST(ErrnoPreservationTest, AfterStatement) { 543 errno = 77; 544 ABSL_TEST_LOG(INFO); 545 const int saved_errno = errno; 546 EXPECT_THAT(saved_errno, Eq(77)); 547} 548 549// Tests that using a variable/parameter in a logging statement suppresses 550// unused-variable/parameter warnings. 551// ----------------------------------------------------------------------- 552class UnusedVariableWarningCompileTest { 553 // These four don't prove anything unless `ABSL_MIN_LOG_LEVEL` is greater than 554 // `kInfo`. 555 static void LoggedVariable() { 556 const int x = 0; 557 ABSL_TEST_LOG(INFO) << x; 558 } 559 static void LoggedParameter(const int x) { ABSL_TEST_LOG(INFO) << x; } 560 static void SeverityVariable() { 561 const int x = 0; 562 ABSL_TEST_LOG(LEVEL(x)) << "hello world"; 563 } 564 static void SeverityParameter(const int x) { 565 ABSL_TEST_LOG(LEVEL(x)) << "hello world"; 566 } 567}; 568 569} // namespace absl_log_internal 570 571#endif // ABSL_LOG_LOG_BASIC_TEST_IMPL_H_ 572