Fixing issue where default_logger.h conflates LOG and VLOG. Issue reported and original idea for a fix provided by ben.darnell.

git-svn-id: http://libphonenumber.googlecode.com/svn/trunk@599 ee073f10-1060-11df-b6a4-87a95322a99c

4 files changed, 113 insertions, 23 deletions

diff --git a/cpp/src/phonenumbers/default_logger.cc b/cpp/src/phonenumbers/default_logger.cc
index 44379a5..c54b640 100644
--- a/cpp/src/phonenumbers/default_logger.cc
+++ b/cpp/src/phonenumbers/default_logger.cc
@@ -29,18 +29,27 @@ void StdoutLogger::WriteMessage(const string& msg) {
 }
 
 void StdoutLogger::WriteLevel() {
-  LogLevel log_level = level();
+  int verbosity_level = level();
+  if (verbosity_level <= 0) {
+    verbosity_level = LOG_FATAL;
+  }
+
   cout << "[";
 
-  switch (log_level) {
-    case LOG_FATAL:   cout << "FATAL"; break;
+  // Handle verbose logs first.
+  if (verbosity_level > LOG_DEBUG) {
+    cout << "VLOG" << (verbosity_level - LOG_DEBUG);
+  } else {
+    switch (verbosity_level) {
+      case LOG_FATAL:   cout << "FATAL"; break;
 #ifdef ERROR  // In case ERROR is defined by MSVC (i.e not set to LOG_ERROR).
-    case ERROR:
+      case ERROR:
 #endif
-    case LOG_ERROR:   cout << "ERROR"; break;
-    case LOG_WARNING: cout << "WARNING"; break;
-    case LOG_INFO:    cout << "INFO"; break;
-    case LOG_DEBUG:   cout << "DEBUG"; break;
+      case LOG_ERROR:   cout << "ERROR"; break;
+      case LOG_WARNING: cout << "WARNING"; break;
+      case LOG_INFO:    cout << "INFO"; break;
+      case LOG_DEBUG:   cout << "DEBUG"; break;
+    }
   }
   cout << "]";
 }
diff --git a/cpp/src/phonenumbers/default_logger.h b/cpp/src/phonenumbers/default_logger.h
index afb6fc9..25754d7 100644
--- a/cpp/src/phonenumbers/default_logger.h
+++ b/cpp/src/phonenumbers/default_logger.h
@@ -74,7 +74,7 @@ class LoggerHandler {
   Logger* const impl_;
 };
 
-inline LoggerHandler VLOG(int n) {
+inline LoggerHandler LOG(int n) {
   Logger* const logger_impl = Logger::mutable_logger_impl();
   if (logger_impl->level() < n) {
     return LoggerHandler(NULL);
@@ -83,8 +83,10 @@ inline LoggerHandler VLOG(int n) {
   return LoggerHandler(logger_impl);
 }
 
-inline LoggerHandler LOG(int n) {
-  return VLOG(n);
+inline LoggerHandler VLOG(int n) {
+  // VLOG(1) is the next logging level after LOG(DEBUG).
+  n += LOG_DEBUG;
+  return LOG(n);
 }
 
 // Default logger implementation used by PhoneNumberUtil class. It outputs the
diff --git a/cpp/src/phonenumbers/logger.h b/cpp/src/phonenumbers/logger.h
index 4a6d23b..9d67f91 100644
--- a/cpp/src/phonenumbers/logger.h
+++ b/cpp/src/phonenumbers/logger.h
@@ -25,7 +25,7 @@ namespace phonenumbers {
 
 using std::string;
 
-enum LogLevel {
+enum {
   LOG_FATAL = 1,
   LOG_ERROR,
   LOG_WARNING,
@@ -54,14 +54,26 @@ class Logger {
   // Writes the provided message to the underlying output stream.
   virtual void WriteMessage(const string& msg) = 0;
 
-  inline LogLevel level() const {
+  // Note that if set_verbosity_level has been used to set the level to a value
+  // that is not represented by an enum, the result here will be a log
+  // level that is higher than LOG_DEBUG.
+  inline int level() const {
     return level_;
   }
 
-  inline void set_level(LogLevel level) {
+  inline void set_level(int level) {
     level_ = level;
   }
 
+  // If you want to see verbose logs in addition to other logs, use this method.
+  // This will result in all log messages at the levels above being shown, along
+  // with calls to VLOG with the verbosity level set to this level or lower.
+  // For example, set_verbosity_level(2) will show calls of VLOG(1) and VLOG(2)
+  // but not VLOG(3), along with all calls to LOG().
+  inline void set_verbosity_level(int verbose_logs_level) {
+    set_level(LOG_DEBUG + verbose_logs_level);
+  }
+
   static inline Logger* set_logger_impl(Logger* logger) {
     impl_ = logger;
     return logger;
@@ -73,7 +85,7 @@ class Logger {
 
  private:
   static Logger* impl_;
-  LogLevel level_;
+  int level_;
 };
 
 // Logger that does not log anything. It could be useful to "mute" the
diff --git a/cpp/test/phonenumbers/logger_test.cc b/cpp/test/phonenumbers/logger_test.cc
index 1cdabf2..dcd94e5 100644
--- a/cpp/test/phonenumbers/logger_test.cc
+++ b/cpp/test/phonenumbers/logger_test.cc
@@ -20,6 +20,7 @@
 
 #include "phonenumbers/base/memory/scoped_ptr.h"
 #include "phonenumbers/default_logger.h"
+#include "phonenumbers/logger.h"
 
 namespace i18n {
 namespace phonenumbers {
@@ -69,37 +70,103 @@ class LoggerTest : public ::testing::Test {
 TEST_F(LoggerTest, LoggerIgnoresHigherVerbosity) {
   // The logger verbosity is set to LOG_INFO, therefore LOG_DEBUG messages
   // should be ignored.
-  VLOG(LOG_DEBUG) << "Hello";
+  LOG(LOG_DEBUG) << "Hello";
   EXPECT_EQ("", test_logger_->message());
 }
 
 TEST_F(LoggerTest, LoggerOutputsNewline) {
-  VLOG(LOG_INFO) << "Hello";
+  LOG(LOG_INFO) << "Hello";
   EXPECT_EQ("Hello\n", test_logger_->message());
 }
 
 TEST_F(LoggerTest, LoggerLogsEqualVerbosity) {
-  VLOG(LOG_INFO) << "Hello";
+  LOG(LOG_INFO) << "Hello";
   EXPECT_EQ("Hello\n", test_logger_->message());
 }
 
-TEST_F(LoggerTest, LoggerLogsLowerVerbosity) {
-  VLOG(LOG_WARNING) << "Hello";
+TEST_F(LoggerTest, LoggerLogsMoreSeriousMessages) {
+  // The logger verbosity is set to LOG_INFO, therefore LOG_WARNING messages
+  // should still be printed.
+  LOG(LOG_WARNING) << "Hello";
   EXPECT_EQ("Hello\n", test_logger_->message());
 }
 
 TEST_F(LoggerTest, LoggerConcatenatesMessages) {
-  VLOG(LOG_INFO) << "Hello";
+  LOG(LOG_INFO) << "Hello";
   ASSERT_EQ("Hello\n", test_logger_->message());
 
-  VLOG(LOG_INFO) << " World";
+  LOG(LOG_INFO) << " World";
   EXPECT_EQ("Hello\n World\n", test_logger_->message());
 }
 
 TEST_F(LoggerTest, LoggerHandlesDifferentTypes) {
-  VLOG(LOG_INFO) << "Hello " << 42;
+  LOG(LOG_INFO) << "Hello " << 42;
   EXPECT_EQ("Hello 42\n", test_logger_->message());
 }
 
+TEST_F(LoggerTest, LoggerIgnoresVerboseLogs) {
+  // VLOG is always lower verbosity than LOG, so with LOG_INFO set as the
+  // verbosity level, no VLOG call should result in anything.
+  VLOG(1) << "Hello";
+  EXPECT_EQ("", test_logger_->message());
+
+  // VLOG(0) is the same as LOG_DEBUG.
+  VLOG(0) << "Hello";
+  EXPECT_EQ("", test_logger_->message());
+
+  // With LOG_DEBUG as the current verbosity level, VLOG(1) should still not
+  // result in anything.
+  test_logger_->set_level(LOG_DEBUG);
+
+  VLOG(1) << "Hello";
+  EXPECT_EQ("", test_logger_->message());
+
+  // However, VLOG(0) does.
+  VLOG(0) << "Hello";
+  EXPECT_EQ("Hello\n", test_logger_->message());
+}
+
+TEST_F(LoggerTest, LoggerShowsDebugLogsAtDebugLevel) {
+  test_logger_->set_level(LOG_DEBUG);
+  // Debug logs should still be seen.
+  LOG(LOG_DEBUG) << "Debug hello";
+  EXPECT_EQ("Debug hello\n", test_logger_->message());
+}
+
+TEST_F(LoggerTest, LoggerOutputsDebugLogsWhenVerbositySet) {
+  // This should now output LOG_DEBUG.
+  int verbose_log_level = 2;
+  test_logger_->set_verbosity_level(verbose_log_level);
+
+  LOG(LOG_DEBUG) << "Debug hello";
+  EXPECT_EQ("Debug hello\n", test_logger_->message());
+}
+
+TEST_F(LoggerTest, LoggerOutputsErrorLogsWhenVerbositySet) {
+  // This should now output LOG_ERROR.
+  int verbose_log_level = 2;
+  test_logger_->set_verbosity_level(verbose_log_level);
+
+  LOG(ERROR) << "Error hello";
+  EXPECT_EQ("Error hello\n", test_logger_->message());
+}
+
+TEST_F(LoggerTest, LoggerOutputsLogsAccordingToVerbosity) {
+  int verbose_log_level = 2;
+  test_logger_->set_verbosity_level(verbose_log_level);
+
+  // More verbose than the current limit.
+  VLOG(verbose_log_level + 1) << "Hello 3";
+  EXPECT_EQ("", test_logger_->message());
+
+  // Less verbose than the current limit.
+  VLOG(verbose_log_level - 1) << "Hello";
+  EXPECT_EQ("Hello\n", test_logger_->message());
+
+  // At the current limit. This will be appended to the previous log output.
+  VLOG(verbose_log_level) << "Hello 2";
+  EXPECT_EQ("Hello\nHello 2\n", test_logger_->message());
+}
+
 }  // namespace phonenumbers
 }  // namespace i18n