Home | History | Annotate | Download | only in tests 
      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 
     19 namespace mojo {
     20 namespace {
     21 
     22 class PtrToMemberHelper {
     23  public:
     24   int member;
     25 };
     26 
     27 bool DcheckTestHelper(bool* was_called) {
     28   *was_called = true;
     29   return false;
     30 }
     31 
     32 class 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
     92 const MojoLogger LoggingTest::kMockLogger = {
     93   &LoggingTest::MockLogMessage,
     94   &LoggingTest::MockGetMinimumLogLevel,
     95   &LoggingTest::MockSetMinimumLogLevel
     96 };
     97 
     98 // static
     99 MojoLogLevel LoggingTest::minimum_log_level_ = MOJO_LOG_LEVEL_INFO;
    100 
    101 // static
    102 bool LoggingTest::log_message_was_called_ = MOJO_LOG_LEVEL_INFO;
    103 
    104 // static
    105 MojoLogLevel LoggingTest::last_log_level_ = MOJO_LOG_LEVEL_INFO;
    106 
    107 // static
    108 std::string LoggingTest::last_message_;
    109 
    110 // static
    111 bool LoggingTest::not_called_condition_was_called_ = false;
    112 
    113 std::string ExpectedLogMessage(int line, const char* message) {
    114   std::ostringstream s;
    115   s << OUR_FILENAME "(" << line << "): " << message;
    116   return s.str();
    117 }
    118 
    119 TEST_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 
    183 TEST_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 
    197 TEST_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 
    238 TEST_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 
    261 TEST_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 
    300 TEST_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 
    349 TEST_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 
    377 TEST_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 
    394 TEST_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 
    433 TEST_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