1// Copyright 2014 The Chromium Authors. All rights reserved. 2// Use of this source code is governed by a BSD-style license that can be 3// found in the LICENSE file. 4 5#include <stdlib.h> 6 7#include <sstream> 8#include <string> 9 10#include "mojo/public/cpp/environment/environment.h" 11#include "mojo/public/cpp/environment/logging.h" 12#include "mojo/public/cpp/system/macros.h" 13#include "testing/gtest/include/gtest/gtest.h" 14 15// A macro, so it can be automatically joined with other string literals. (Not 16// simply __FILE__, since that may contain a path.) 17#define OUR_FILENAME "logging_unittest.cc" 18 19namespace mojo { 20namespace { 21 22class PtrToMemberHelper { 23 public: 24 int member; 25}; 26 27bool DcheckTestHelper(bool* was_called) { 28 *was_called = true; 29 return false; 30} 31 32class LoggingTest : public testing::Test { 33 public: 34 LoggingTest() : environment_(NULL, &kMockLogger) { 35 minimum_log_level_ = MOJO_LOG_LEVEL_INFO; 36 ResetMockLogger(); 37 } 38 virtual ~LoggingTest() {} 39 40 protected: 41 // Note: Does not reset |minimum_log_level_|. 42 static void ResetMockLogger() { 43 log_message_was_called_ = false; 44 last_log_level_ = MOJO_LOG_LEVEL_INFO; 45 last_message_.clear(); 46 } 47 48 // A function returning |bool| that shouldn't be called. 49 static bool NotCalledCondition() { 50 not_called_condition_was_called_ = true; 51 return false; 52 } 53 54 static bool log_message_was_called() { return log_message_was_called_; } 55 static MojoLogLevel last_log_level() { return last_log_level_; } 56 static const std::string& last_message() { return last_message_; } 57 static bool not_called_condition_was_called() { 58 return not_called_condition_was_called_; 59 } 60 61 private: 62 // Note: We record calls even if |log_level| is below |minimum_log_level_| 63 // (since the macros should mostly avoid this, and we want to be able to check 64 // that they do). 65 static void MockLogMessage(MojoLogLevel log_level, const char* message) { 66 log_message_was_called_ = true; 67 last_log_level_ = log_level; 68 last_message_ = message; 69 } 70 71 static MojoLogLevel MockGetMinimumLogLevel() { 72 return minimum_log_level_; 73 } 74 75 static void MockSetMinimumLogLevel(MojoLogLevel minimum_log_level) { 76 minimum_log_level_ = minimum_log_level; 77 } 78 79 Environment environment_; 80 81 static const MojoLogger kMockLogger; 82 static MojoLogLevel minimum_log_level_; 83 static bool log_message_was_called_; 84 static MojoLogLevel last_log_level_; 85 static std::string last_message_; 86 static bool not_called_condition_was_called_; 87 88 MOJO_DISALLOW_COPY_AND_ASSIGN(LoggingTest); 89}; 90 91// static 92const MojoLogger LoggingTest::kMockLogger = { 93 &LoggingTest::MockLogMessage, 94 &LoggingTest::MockGetMinimumLogLevel, 95 &LoggingTest::MockSetMinimumLogLevel 96}; 97 98// static 99MojoLogLevel LoggingTest::minimum_log_level_ = MOJO_LOG_LEVEL_INFO; 100 101// static 102bool LoggingTest::log_message_was_called_ = MOJO_LOG_LEVEL_INFO; 103 104// static 105MojoLogLevel LoggingTest::last_log_level_ = MOJO_LOG_LEVEL_INFO; 106 107// static 108std::string LoggingTest::last_message_; 109 110// static 111bool LoggingTest::not_called_condition_was_called_ = false; 112 113std::string ExpectedLogMessage(int line, const char* message) { 114 std::ostringstream s; 115 s << OUR_FILENAME "(" << line << "): " << message; 116 return s.str(); 117} 118 119TEST_F(LoggingTest, InternalLogMessage) { 120 internal::LogMessage("foo.cc", 123, MOJO_LOG_LEVEL_INFO).stream() 121 << "hello " << "world"; 122 EXPECT_TRUE(log_message_was_called()); 123 EXPECT_EQ(MOJO_LOG_LEVEL_INFO, last_log_level()); 124 EXPECT_EQ("foo.cc(123): hello world", last_message()); 125 126 ResetMockLogger(); 127 128 internal::LogMessage("./path/to/foo.cc", 123, MOJO_LOG_LEVEL_WARNING).stream() 129 << "hello " << "world"; 130 EXPECT_TRUE(log_message_was_called()); 131 EXPECT_EQ(MOJO_LOG_LEVEL_WARNING, last_log_level()); 132 EXPECT_EQ("foo.cc(123): hello world", last_message()); 133 134 ResetMockLogger(); 135 136 internal::LogMessage("/path/to/foo.cc", 123, MOJO_LOG_LEVEL_ERROR).stream() 137 << "hello " << "world"; 138 EXPECT_TRUE(log_message_was_called()); 139 EXPECT_EQ(MOJO_LOG_LEVEL_ERROR, last_log_level()); 140 EXPECT_EQ("foo.cc(123): hello world", last_message()); 141 142 ResetMockLogger(); 143 144 internal::LogMessage("path/to/foo.cc", 123, MOJO_LOG_LEVEL_FATAL).stream() 145 << "hello " << "world"; 146 EXPECT_TRUE(log_message_was_called()); 147 EXPECT_EQ(MOJO_LOG_LEVEL_FATAL, last_log_level()); 148 EXPECT_EQ("foo.cc(123): hello world", last_message()); 149 150 ResetMockLogger(); 151 152 internal::LogMessage(".\\xy\\foo.cc", 123, MOJO_LOG_LEVEL_VERBOSE).stream() 153 << "hello " << "world"; 154 EXPECT_TRUE(log_message_was_called()); 155 EXPECT_EQ(MOJO_LOG_LEVEL_VERBOSE, last_log_level()); 156 EXPECT_EQ("foo.cc(123): hello world", last_message()); 157 158 ResetMockLogger(); 159 160 internal::LogMessage("xy\\foo.cc", 123, MOJO_LOG_LEVEL_VERBOSE-1).stream() 161 << "hello " << "world"; 162 EXPECT_TRUE(log_message_was_called()); 163 EXPECT_EQ(MOJO_LOG_LEVEL_VERBOSE-1, last_log_level()); 164 EXPECT_EQ("foo.cc(123): hello world", last_message()); 165 166 ResetMockLogger(); 167 168 internal::LogMessage("C:\\xy\\foo.cc", 123, MOJO_LOG_LEVEL_VERBOSE-9).stream() 169 << "hello " << "world"; 170 EXPECT_TRUE(log_message_was_called()); 171 EXPECT_EQ(MOJO_LOG_LEVEL_VERBOSE-9, last_log_level()); 172 EXPECT_EQ("foo.cc(123): hello world", last_message()); 173 174 ResetMockLogger(); 175 176 internal::LogMessage(__FILE__, 123, MOJO_LOG_LEVEL_INFO).stream() 177 << "hello " << "world"; 178 EXPECT_TRUE(log_message_was_called()); 179 EXPECT_EQ(MOJO_LOG_LEVEL_INFO, last_log_level()); 180 EXPECT_EQ(OUR_FILENAME "(123): hello world", last_message()); 181} 182 183TEST_F(LoggingTest, LogStream) { 184 MOJO_LOG_STREAM(INFO) << "hello"; 185 EXPECT_TRUE(log_message_was_called()); 186 EXPECT_EQ(MOJO_LOG_LEVEL_INFO, last_log_level()); 187 EXPECT_EQ(ExpectedLogMessage(__LINE__ - 3, "hello"), last_message()); 188 189 ResetMockLogger(); 190 191 MOJO_LOG_STREAM(ERROR) << "hi " << 123; 192 EXPECT_TRUE(log_message_was_called()); 193 EXPECT_EQ(MOJO_LOG_LEVEL_ERROR, last_log_level()); 194 EXPECT_EQ(ExpectedLogMessage(__LINE__ - 3, "hi 123"), last_message()); 195} 196 197TEST_F(LoggingTest, LazyLogStream) { 198 MOJO_LAZY_LOG_STREAM(INFO, true) << "hello"; 199 EXPECT_TRUE(log_message_was_called()); 200 EXPECT_EQ(MOJO_LOG_LEVEL_INFO, last_log_level()); 201 EXPECT_EQ(ExpectedLogMessage(__LINE__ - 3, "hello"), last_message()); 202 203 ResetMockLogger(); 204 205 MOJO_LAZY_LOG_STREAM(ERROR, true) << "hi " << 123; 206 EXPECT_TRUE(log_message_was_called()); 207 EXPECT_EQ(MOJO_LOG_LEVEL_ERROR, last_log_level()); 208 EXPECT_EQ(ExpectedLogMessage(__LINE__ - 3, "hi 123"), last_message()); 209 210 ResetMockLogger(); 211 212 MOJO_LAZY_LOG_STREAM(INFO, false) << "hello"; 213 EXPECT_FALSE(log_message_was_called()); 214 215 ResetMockLogger(); 216 217 MOJO_LAZY_LOG_STREAM(FATAL, false) << "hello"; 218 EXPECT_FALSE(log_message_was_called()); 219 220 ResetMockLogger(); 221 222 PtrToMemberHelper helper; 223 helper.member = 1; 224 int PtrToMemberHelper::*member_ptr = &PtrToMemberHelper::member; 225 226 // This probably fails to compile if we forget to parenthesize the condition 227 // in the macro (.* has lower precedence than !, which can't apply to 228 // |helper|). 229 MOJO_LAZY_LOG_STREAM(ERROR, helper.*member_ptr == 1) << "hello"; 230 EXPECT_TRUE(log_message_was_called()); 231 232 ResetMockLogger(); 233 234 MOJO_LAZY_LOG_STREAM(WARNING, helper.*member_ptr == 0) << "hello"; 235 EXPECT_FALSE(log_message_was_called()); 236} 237 238TEST_F(LoggingTest, ShouldLog) { 239 // We start at |MOJO_LOG_LEVEL_INFO|. 240 EXPECT_FALSE(MOJO_SHOULD_LOG(VERBOSE)); 241 EXPECT_TRUE(MOJO_SHOULD_LOG(INFO)); 242 EXPECT_TRUE(MOJO_SHOULD_LOG(WARNING)); 243 EXPECT_TRUE(MOJO_SHOULD_LOG(ERROR)); 244 EXPECT_TRUE(MOJO_SHOULD_LOG(FATAL)); 245 246 Environment::GetDefaultLogger()->SetMinimumLogLevel(MOJO_LOG_LEVEL_ERROR); 247 EXPECT_FALSE(MOJO_SHOULD_LOG(VERBOSE)); 248 EXPECT_FALSE(MOJO_SHOULD_LOG(INFO)); 249 EXPECT_FALSE(MOJO_SHOULD_LOG(WARNING)); 250 EXPECT_TRUE(MOJO_SHOULD_LOG(ERROR)); 251 EXPECT_TRUE(MOJO_SHOULD_LOG(FATAL)); 252 253 Environment::GetDefaultLogger()->SetMinimumLogLevel(MOJO_LOG_LEVEL_VERBOSE-1); 254 EXPECT_TRUE(MOJO_SHOULD_LOG(VERBOSE)); 255 EXPECT_TRUE(MOJO_SHOULD_LOG(INFO)); 256 EXPECT_TRUE(MOJO_SHOULD_LOG(WARNING)); 257 EXPECT_TRUE(MOJO_SHOULD_LOG(ERROR)); 258 EXPECT_TRUE(MOJO_SHOULD_LOG(FATAL)); 259} 260 261TEST_F(LoggingTest, Log) { 262 // We start at |MOJO_LOG_LEVEL_INFO|. 263 MOJO_LOG(VERBOSE) << "hello"; 264 EXPECT_FALSE(log_message_was_called()); 265 266 ResetMockLogger(); 267 268 MOJO_LOG(INFO) << "hello"; 269 EXPECT_TRUE(log_message_was_called()); 270 EXPECT_EQ(MOJO_LOG_LEVEL_INFO, last_log_level()); 271 EXPECT_EQ(ExpectedLogMessage(__LINE__ - 3, "hello"), last_message()); 272 273 ResetMockLogger(); 274 275 MOJO_LOG(ERROR) << "hello"; 276 EXPECT_TRUE(log_message_was_called()); 277 EXPECT_EQ(MOJO_LOG_LEVEL_ERROR, last_log_level()); 278 EXPECT_EQ(ExpectedLogMessage(__LINE__ - 3, "hello"), last_message()); 279 280 ResetMockLogger(); 281 282 Environment::GetDefaultLogger()->SetMinimumLogLevel(MOJO_LOG_LEVEL_ERROR); 283 284 MOJO_LOG(VERBOSE) << "hello"; 285 EXPECT_FALSE(log_message_was_called()); 286 287 ResetMockLogger(); 288 289 MOJO_LOG(INFO) << "hello"; 290 EXPECT_FALSE(log_message_was_called()); 291 292 ResetMockLogger(); 293 294 MOJO_LOG(ERROR) << "hello"; 295 EXPECT_TRUE(log_message_was_called()); 296 EXPECT_EQ(MOJO_LOG_LEVEL_ERROR, last_log_level()); 297 EXPECT_EQ(ExpectedLogMessage(__LINE__ - 3, "hello"), last_message()); 298} 299 300TEST_F(LoggingTest, LogIf) { 301 // We start at |MOJO_LOG_LEVEL_INFO|. 302 MOJO_LOG_IF(VERBOSE, true) << "hello"; 303 EXPECT_FALSE(log_message_was_called()); 304 305 ResetMockLogger(); 306 307 MOJO_LOG_IF(VERBOSE, false) << "hello"; 308 EXPECT_FALSE(log_message_was_called()); 309 310 ResetMockLogger(); 311 Environment::GetDefaultLogger()->SetMinimumLogLevel(MOJO_LOG_LEVEL_ERROR); 312 313 bool x = true; 314 // Also try to make sure that we parenthesize the condition properly. 315 MOJO_LOG_IF(INFO, false || x) << "hello"; 316 EXPECT_FALSE(log_message_was_called()); 317 318 ResetMockLogger(); 319 320 MOJO_LOG_IF(INFO, 0 != 1) << "hello"; 321 EXPECT_FALSE(log_message_was_called()); 322 323 ResetMockLogger(); 324 325 MOJO_LOG_IF(WARNING, 1 + 1 == 2) << "hello"; 326 EXPECT_FALSE(log_message_was_called()); 327 328 ResetMockLogger(); 329 330 MOJO_LOG_IF(ERROR, 1 * 2 == 2) << "hello"; 331 EXPECT_TRUE(log_message_was_called()); 332 EXPECT_EQ(MOJO_LOG_LEVEL_ERROR, last_log_level()); 333 EXPECT_EQ(ExpectedLogMessage(__LINE__ - 3, "hello"), last_message()); 334 335 ResetMockLogger(); 336 337 MOJO_LOG_IF(FATAL, 1 * 2 == 3) << "hello"; 338 EXPECT_FALSE(log_message_was_called()); 339 340 ResetMockLogger(); 341 342 // |MOJO_LOG_IF()| shouldn't evaluate its condition if the level is below the 343 // minimum. 344 MOJO_LOG_IF(INFO, NotCalledCondition()) << "hello"; 345 EXPECT_FALSE(not_called_condition_was_called()); 346 EXPECT_FALSE(log_message_was_called()); 347} 348 349TEST_F(LoggingTest, Check) { 350 MOJO_CHECK(true) << "hello"; 351 EXPECT_FALSE(log_message_was_called()); 352 353 ResetMockLogger(); 354 355 PtrToMemberHelper helper; 356 helper.member = 0; 357 int PtrToMemberHelper::*member_ptr = &PtrToMemberHelper::member; 358 359 // Also try to make sure that we parenthesize the condition properly. 360 MOJO_CHECK(helper.*member_ptr == 1) << "hello"; 361 EXPECT_TRUE(log_message_was_called()); 362 EXPECT_EQ(MOJO_LOG_LEVEL_FATAL, last_log_level()); 363 // Different compilers have different ideas about the line number of a split 364 // line. 365 int line = __LINE__; 366 EXPECT_EQ(ExpectedLogMessage(line - 5, 367 "Check failed: helper.*member_ptr == 1. hello"), 368 last_message()); 369 370 ResetMockLogger(); 371 372 // Also test a "naked" |MOJO_CHECK()|s. 373 MOJO_CHECK(1 + 2 == 3); 374 EXPECT_FALSE(log_message_was_called()); 375} 376 377TEST_F(LoggingTest, Dlog) { 378 // We start at |MOJO_LOG_LEVEL_INFO|. 379 MOJO_DLOG(VERBOSE) << "hello"; 380 EXPECT_FALSE(log_message_was_called()); 381 382 ResetMockLogger(); 383 384 MOJO_DLOG(INFO) << "hello"; 385#ifdef NDEBUG 386 EXPECT_FALSE(log_message_was_called()); 387#else 388 EXPECT_TRUE(log_message_was_called()); 389 EXPECT_EQ(MOJO_LOG_LEVEL_INFO, last_log_level()); 390 EXPECT_EQ(ExpectedLogMessage(__LINE__ - 6, "hello"), last_message()); 391#endif 392} 393 394TEST_F(LoggingTest, DlogIf) { 395 // We start at |MOJO_LOG_LEVEL_INFO|. It shouldn't evaluate the condition in 396 // this case. 397 MOJO_DLOG_IF(VERBOSE, NotCalledCondition()) << "hello"; 398 EXPECT_FALSE(not_called_condition_was_called()); 399 EXPECT_FALSE(log_message_was_called()); 400 401 ResetMockLogger(); 402 403 MOJO_DLOG_IF(INFO, 1 == 0) << "hello"; 404 EXPECT_FALSE(log_message_was_called()); 405 406 ResetMockLogger(); 407 408 MOJO_DLOG_IF(INFO, 1 == 1) << "hello"; 409#ifdef NDEBUG 410 EXPECT_FALSE(log_message_was_called()); 411#else 412 EXPECT_TRUE(log_message_was_called()); 413 EXPECT_EQ(MOJO_LOG_LEVEL_INFO, last_log_level()); 414 EXPECT_EQ(ExpectedLogMessage(__LINE__ - 6, "hello"), last_message()); 415#endif 416 417 ResetMockLogger(); 418 419 // |MOJO_DLOG_IF()| shouldn't compile its condition for non-debug builds. 420#ifndef NDEBUG 421 bool debug_only = true; 422#endif 423 MOJO_DLOG_IF(WARNING, debug_only) << "hello"; 424#ifdef NDEBUG 425 EXPECT_FALSE(log_message_was_called()); 426#else 427 EXPECT_TRUE(log_message_was_called()); 428 EXPECT_EQ(MOJO_LOG_LEVEL_WARNING, last_log_level()); 429 EXPECT_EQ(ExpectedLogMessage(__LINE__ - 6, "hello"), last_message()); 430#endif 431} 432 433TEST_F(LoggingTest, Dcheck) { 434 MOJO_DCHECK(true); 435 EXPECT_FALSE(log_message_was_called()); 436 437 ResetMockLogger(); 438 439 MOJO_DCHECK(true) << "hello"; 440 EXPECT_FALSE(log_message_was_called()); 441 442 ResetMockLogger(); 443 444 // |MOJO_DCHECK()| should compile (but not evaluate) its condition even for 445 // non-debug builds. (Hopefully, we'll get an unused variable error if it 446 // fails to compile the condition.) 447 bool was_called = false; 448 MOJO_DCHECK(DcheckTestHelper(&was_called)) << "hello"; 449#ifdef NDEBUG 450 EXPECT_FALSE(was_called); 451 EXPECT_FALSE(log_message_was_called()); 452#else 453 EXPECT_TRUE(was_called); 454 EXPECT_TRUE(log_message_was_called()); 455 EXPECT_EQ(MOJO_LOG_LEVEL_FATAL, last_log_level()); 456 // Different compilers have different ideas about the line number of a split 457 // line. 458 int line = __LINE__; 459 EXPECT_EQ( 460 ExpectedLogMessage(line - 10, 461 "Check failed: DcheckTestHelper(&was_called). hello"), 462 last_message()); 463#endif 464 465 ResetMockLogger(); 466 467 // Also try to make sure that we parenthesize the condition properly. 468 bool x = true; 469 MOJO_DCHECK(false || x) << "hello"; 470 EXPECT_FALSE(log_message_was_called()); 471} 472 473} // namespace 474} // namespace mojo 475