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