Revert 61142 - Made logging macros evaluate its stream arguments lazily.

Also added logging unittests.

BUG=57383
TEST=logging_unittest.cc

Committed: http://src.chromium.org/viewvc/chrome?view=rev&revision=61127

Review URL: http://codereview.chromium.org/3575008

TBR=akalin@chromium.org
Review URL: http://codereview.chromium.org/3527004

git-svn-id: svn://svn.chromium.org/chrome/trunk/src@61143 0039d316-1c4b-4281-b951-d872f2087c98

1 files changed, 185 insertions, 149 deletions

diff --git a/base/logging.h b/base/logging.h
index 4c7421f..386b8ba 100644
--- a/base/logging.h
+++ b/base/logging.h
@@ -261,11 +261,11 @@ const LogSeverity LOG_ERROR_REPORT = 3;
 const LogSeverity LOG_FATAL = 4;
 const LogSeverity LOG_NUM_SEVERITIES = 5;
 
-// LOG_DFATAL is LOG_FATAL in debug mode, ERROR in normal mode
+// LOG_DFATAL_LEVEL is LOG_FATAL in debug mode, ERROR in normal mode
 #ifdef NDEBUG
-const LogSeverity LOG_DFATAL = LOG_ERROR;
+const LogSeverity LOG_DFATAL_LEVEL = LOG_ERROR;
 #else
-const LogSeverity LOG_DFATAL = LOG_FATAL;
+const LogSeverity LOG_DFATAL_LEVEL = LOG_FATAL;
 #endif
 
 // A few definitions of macros that don't generate much code. These are used
@@ -283,7 +283,8 @@ const LogSeverity LOG_DFATAL = LOG_FATAL;
 #define COMPACT_GOOGLE_LOG_EX_FATAL(ClassName, ...) \
   logging::ClassName(__FILE__, __LINE__, logging::LOG_FATAL , ##__VA_ARGS__)
 #define COMPACT_GOOGLE_LOG_EX_DFATAL(ClassName, ...) \
-  logging::ClassName(__FILE__, __LINE__, logging::LOG_DFATAL , ##__VA_ARGS__)
+  logging::ClassName(__FILE__, __LINE__, \
+                     logging::LOG_DFATAL_LEVEL , ##__VA_ARGS__)
 
 #define COMPACT_GOOGLE_LOG_INFO \
   COMPACT_GOOGLE_LOG_EX_INFO(LogMessage)
@@ -307,23 +308,6 @@ const LogSeverity LOG_DFATAL = LOG_FATAL;
 #define COMPACT_GOOGLE_LOG_EX_0(ClassName, ...) \
   COMPACT_GOOGLE_LOG_EX_ERROR(ClassName , ##__VA_ARGS__)
 #define COMPACT_GOOGLE_LOG_0 COMPACT_GOOGLE_LOG_ERROR
-// Needed for LOG_IS_ON(ERROR).
-const LogSeverity LOG_0 = LOG_ERROR;
-
-#define LOG_IS_ON(severity) \
-  ((::logging::LOG_ ## severity) >= ::logging::GetMinLogLevel())
-
-// We can't do any caching tricks with VLOG_IS_ON() like the
-// google-glog version since it requires GCC extensions.  This means
-// that using the v-logging functions in conjunction with --vmodule
-// may be slow.
-#define VLOG_IS_ON(verboselevel) \
-  ((verboselevel) <= ::logging::GetVlogLevel(__FILE__))
-
-// Helper macro which avoids evaluating the arguments to a stream if
-// the condition doesn't hold.
-#define LAZY_STREAM(stream, condition)                                  \
-  !(condition) ? (void) 0 : ::logging::LogMessageVoidify() & (stream)
 
 // We use the preprocessor's merging operator, "##", so that, e.g.,
 // LOG(INFO) becomes the token COMPACT_GOOGLE_LOG_INFO.  There's some funny
@@ -333,75 +317,62 @@ const LogSeverity LOG_0 = LOG_ERROR;
 // impossible to stream something like a string directly to an unnamed
 // ostream. We employ a neat hack by calling the stream() member
 // function of LogMessage which seems to avoid the problem.
-#define LOG_STREAM(severity) COMPACT_GOOGLE_LOG_ ## severity.stream()
-
-#define LOG(severity) LAZY_STREAM(LOG_STREAM(severity), LOG_IS_ON(severity))
-#define LOG_IF(severity, condition) \
-  LAZY_STREAM(LOG_STREAM(severity), LOG_IS_ON(severity) && (condition))
+//
+// We can't do any caching tricks with VLOG_IS_ON() like the
+// google-glog version since it requires GCC extensions.  This means
+// that using the v-logging functions in conjunction with --vmodule
+// may be slow.
+#define VLOG_IS_ON(verboselevel) \
+  (logging::GetVlogLevel(__FILE__) >= (verboselevel))
 
+#define LOG(severity) COMPACT_GOOGLE_LOG_ ## severity.stream()
 #define SYSLOG(severity) LOG(severity)
-#define SYSLOG_IF(severity, condition) LOG_IF(severity, condition)
-
 #define VLOG(verboselevel) LOG_IF(INFO, VLOG_IS_ON(verboselevel))
-#define VLOG_IF(verboselevel, condition) \
-  LOG_IF(INFO, VLOG_IS_ON(verboselevel) && (condition))
 
 // TODO(akalin): Add more VLOG variants, e.g. VPLOG.
 
+#define LOG_IF(severity, condition) \
+  !(condition) ? (void) 0 : logging::LogMessageVoidify() & LOG(severity)
+#define SYSLOG_IF(severity, condition) LOG_IF(severity, condition)
+#define VLOG_IF(verboselevel, condition) \
+  LOG_IF(INFO, (condition) && VLOG_IS_ON(verboselevel))
+
 #define LOG_ASSERT(condition)  \
   LOG_IF(FATAL, !(condition)) << "Assert failed: " #condition ". "
 #define SYSLOG_ASSERT(condition) \
   SYSLOG_IF(FATAL, !(condition)) << "Assert failed: " #condition ". "
 
 #if defined(OS_WIN)
-#define LOG_GETLASTERROR_STREAM(severity) \
+#define LOG_GETLASTERROR(severity) \
   COMPACT_GOOGLE_LOG_EX_ ## severity(Win32ErrorLogMessage, \
       ::logging::GetLastSystemErrorCode()).stream()
-#define LOG_GETLASTERROR(severity) \
-  LAZY_STREAM(LOG_GETLASTERROR_STREAM(severity), LOG_IS_ON(severity))
-#define LOG_GETLASTERROR_MODULE_STREAM(severity, module) \
+#define LOG_GETLASTERROR_MODULE(severity, module) \
   COMPACT_GOOGLE_LOG_EX_ ## severity(Win32ErrorLogMessage, \
       ::logging::GetLastSystemErrorCode(), module).stream()
-#define LOG_GETLASTERROR_MODULE(severity, module)                       \
-  LAZY_STREAM(LOG_GETLASTERROR_STREAM(severity, module),                \
-              LOG_IS_ON(severity))
-// PLOG_STREAM is used by PLOG, which is the usual error logging macro
-// for each platform.
-#define PLOG_STREAM(severity) LOG_GETLASTERROR_STREAM(severity)
+// PLOG is the usual error logging macro for each platform.
+#define PLOG(severity) LOG_GETLASTERROR(severity)
+#define DPLOG(severity) DLOG_GETLASTERROR(severity)
 #elif defined(OS_POSIX)
-#define LOG_ERRNO_STREAM(severity) \
+#define LOG_ERRNO(severity) \
   COMPACT_GOOGLE_LOG_EX_ ## severity(ErrnoLogMessage, \
       ::logging::GetLastSystemErrorCode()).stream()
-#define LOG_ERRNO(severity) \
-  LAZY_STREAM(LOG_ERRNO_STREAM(severity), LOG_IS_ON(severity))
-// PLOG_STREAM is used by PLOG, which is the usual error logging macro
-// for each platform.
-#define PLOG_STREAM(severity) LOG_ERRNO_STREAM(severity)
+// PLOG is the usual error logging macro for each platform.
+#define PLOG(severity) LOG_ERRNO(severity)
+#define DPLOG(severity) DLOG_ERRNO(severity)
 // TODO(tschmelcher): Should we add OSStatus logging for Mac?
 #endif
 
-#define PLOG(severity)                                          \
-  LAZY_STREAM(PLOG_STREAM(severity), LOG_IS_ON(severity))
-
 #define PLOG_IF(severity, condition) \
-  LAZY_STREAM(PLOG_STREAM(severity), LOG_IS_ON(severity) && (condition))
+  !(condition) ? (void) 0 : logging::LogMessageVoidify() & PLOG(severity)
 
 // CHECK dies with a fatal error if condition is not true.  It is *not*
 // controlled by NDEBUG, so the check will be executed regardless of
 // compilation mode.
-//
-// We make sure CHECK et al. always evaluates their arguments, as
-// doing CHECK(FunctionWithSideEffect()) is a common idiom.
-//
-// TODO(akalin): Fix the problem where if the min log level is >
-// FATAL, CHECK() et al. won't terminate the program.
-#define CHECK(condition)                       \
-  LAZY_STREAM(LOG_STREAM(FATAL), !(condition)) \
-  << "Check failed: " #condition ". "
+#define CHECK(condition) \
+  LOG_IF(FATAL, !(condition)) << "Check failed: " #condition ". "
 
 #define PCHECK(condition) \
-  LAZY_STREAM(PLOG_STREAM(FATAL), !(condition)) \
-  << "Check failed: " #condition ". "
+  PLOG_IF(FATAL, !(condition)) << "Check failed: " #condition ". "
 
 // A container for a string pointer which can be evaluated to a bool -
 // true iff the pointer is NULL.
@@ -442,20 +413,13 @@ extern template std::string* MakeCheckOpString<std::string, std::string>(
 
 // Helper macro for binary operators.
 // Don't use this macro directly in your code, use CHECK_EQ et al below.
-//
-// TODO(akalin): Rewrite this so that constructs like if (...)
-// CHECK_EQ(...) else { ... } work properly.
-#define CHECK_OP(name, op, val1, val2)                          \
-  if (logging::CheckOpString _result =                          \
-      logging::Check##name##Impl((val1), (val2),                \
-                                 #val1 " " #op " " #val2))      \
+#define CHECK_OP(name, op, val1, val2)  \
+  if (logging::CheckOpString _result = \
+      logging::Check##name##Impl((val1), (val2), #val1 " " #op " " #val2)) \
     logging::LogMessage(__FILE__, __LINE__, _result).stream()
 
 // Helper functions for string comparisons.
 // To avoid bloat, the definitions are in logging.cc.
-//
-// TODO(akalin): Actually have the implementations in logging.cc, or
-// remove these.
 #define DECLARE_CHECK_STROP_IMPL(func, expected) \
   std::string* Check##func##expected##Impl(const char* s1, \
                                            const char* s2, \
@@ -520,6 +484,49 @@ DECLARE_CHECK_STROP_IMPL(_stricmp, false)
 
 // Definitions for DLOG et al.
 
+#if ENABLE_DLOG
+
+#define DLOG(severity) LOG(severity)
+#define DLOG_IF(severity, condition) LOG_IF(severity, condition)
+#define DLOG_ASSERT(condition) LOG_ASSERT(condition)
+
+#if defined(OS_WIN)
+#define DLOG_GETLASTERROR(severity) LOG_GETLASTERROR(severity)
+#define DLOG_GETLASTERROR_MODULE(severity, module) \
+  LOG_GETLASTERROR_MODULE(severity, module)
+#elif defined(OS_POSIX)
+#define DLOG_ERRNO(severity) LOG_ERRNO(severity)
+#endif
+
+#define DPLOG_IF(severity, condition) PLOG_IF(severity, condition)
+
+#else  // ENABLE_DLOG
+
+#define DLOG(severity) \
+  true ? (void) 0 : logging::LogMessageVoidify() & LOG(severity)
+
+#define DLOG_IF(severity, condition) \
+  true ? (void) 0 : logging::LogMessageVoidify() & LOG(severity)
+
+#define DLOG_ASSERT(condition) \
+  true ? (void) 0 : LOG_ASSERT(condition)
+
+#if defined(OS_WIN)
+#define DLOG_GETLASTERROR(severity) \
+  true ? (void) 0 : logging::LogMessageVoidify() & LOG_GETLASTERROR(severity)
+#define DLOG_GETLASTERROR_MODULE(severity, module) \
+  true ? (void) 0 : logging::LogMessageVoidify() & \
+      LOG_GETLASTERROR_MODULE(severity, module)
+#elif defined(OS_POSIX)
+#define DLOG_ERRNO(severity) \
+  true ? (void) 0 : logging::LogMessageVoidify() & LOG_ERRNO(severity)
+#endif
+
+#define DPLOG_IF(severity, condition) \
+  true ? (void) 0 : logging::LogMessageVoidify() & PLOG(severity)
+
+#endif  // ENABLE_DLOG
+
 // DEBUG_MODE is for uses like
 //   if (DEBUG_MODE) foo.CheckThatFoo();
 // instead of
@@ -532,86 +539,89 @@ enum { DEBUG_MODE = ENABLE_DLOG };
 
 #undef ENABLE_DLOG
 
-#define DLOG_IS_ON(severity) (::logging::DEBUG_MODE && LOG_IS_ON(severity))
-
-#define DLOG(severity)                                          \
-  LAZY_STREAM(LOG_STREAM(severity), DLOG_IS_ON(severity))
-#define DLOG_IF(severity, condition)                                    \
-  LAZY_STREAM(LOG_STREAM(severity), DLOG_IS_ON(severity) && (condition))
+// Definitions for DCHECK et al.
 
-#define DLOG_ASSERT(condition)                                          \
-  DLOG_IF(FATAL, !(condition)) << "Assert failed: " #condition ". "
+// This macro can be followed by a sequence of stream parameters in
+// non-debug mode. The DCHECK and friends macros use this so that
+// the expanded expression DCHECK(foo) << "asdf" is still syntactically
+// valid, even though the expression will get optimized away.
+#define DCHECK_EAT_STREAM_PARAMETERS \
+  logging::LogMessage(__FILE__, __LINE__).stream()
 
-#if defined(OS_WIN)
-#define DLOG_GETLASTERROR(severity) \
-  LAZY_STREAM(LOG_GETLASTERROR_STREAM(severity), DLOG_IS_ON(severity))
-#define DLOG_GETLASTERROR_MODULE(severity, module)                      \
-  LAZY_STREAM(LOG_GETLASTERROR_STREAM(severity, module),                \
-              DLOG_IS_ON(severity))
-#elif defined(OS_POSIX)
-#define DLOG_ERRNO(severity)                                    \
-  LAZY_STREAM(LOG_ERRNO_STREAM(severity), DLOG_IS_ON(severity))
-#endif
+#if ENABLE_DCHECK
 
-#define DPLOG(severity)                                         \
-  LAZY_STREAM(PLOG_STREAM(severity), DLOG_IS_ON(severity))
-#define DPLOG_IF(severity, condition) \
-  LAZY_STREAM(PLOG_STREAM(severity), DLOG_IS_ON(severity) && (condition))
+#ifndef NDEBUG
+// On a regular debug build, we want to have DCHECKS enabled.
 
-#define DVLOG(verboselevel) DLOG_IF(INFO, VLOG_IS_ON(verboselevel))
-#define DVLOG_IF(verboselevel, condition) \
-  DLOG_IF(INFO, VLOG_IS_ON(verboselevel) && (condition))
+#define DCHECK(condition) CHECK(condition)
+#define DPCHECK(condition) PCHECK(condition)
 
-// Definitions for DCHECK et al.
+// Helper macro for binary operators.
+// Don't use this macro directly in your code, use DCHECK_EQ et al below.
+#define DCHECK_OP(name, op, val1, val2)  \
+  if (logging::CheckOpString _result = \
+      logging::Check##name##Impl((val1), (val2), #val1 " " #op " " #val2)) \
+    logging::LogMessage(__FILE__, __LINE__, _result).stream()
 
-#if ENABLE_DCHECK
+// Helper macro for string comparisons.
+// Don't use this macro directly in your code, use CHECK_STREQ et al below.
+#define DCHECK_STROP(func, op, expected, s1, s2) \
+  while (CheckOpString _result = \
+      logging::Check##func##expected##Impl((s1), (s2), \
+                                           #s1 " " #op " " #s2)) \
+    LOG(FATAL) << *_result.str_
 
-#if defined(NDEBUG)
+// String (char*) equality/inequality checks.
+// CASE versions are case-insensitive.
+//
+// Note that "s1" and "s2" may be temporary strings which are destroyed
+// by the compiler at the end of the current "full expression"
+// (e.g. DCHECK_STREQ(Foo().c_str(), Bar().c_str())).
 
-// Set to true in InitLogging when we want to enable the dchecks in release.
-extern bool g_enable_dcheck;
-#define DCHECK_IS_ON() (::logging::g_enable_dcheck)
-#define DCHECK_SEVERITY ERROR_REPORT
-const LogSeverity LOG_DCHECK = LOG_ERROR_REPORT;
+#define DCHECK_STREQ(s1, s2) DCHECK_STROP(strcmp, ==, true, s1, s2)
+#define DCHECK_STRNE(s1, s2) DCHECK_STROP(strcmp, !=, false, s1, s2)
+#define DCHECK_STRCASEEQ(s1, s2) DCHECK_STROP(_stricmp, ==, true, s1, s2)
+#define DCHECK_STRCASENE(s1, s2) DCHECK_STROP(_stricmp, !=, false, s1, s2)
 
-#else  // defined(NDEBUG)
+#define DCHECK_INDEX(I,A) DCHECK(I < (sizeof(A)/sizeof(A[0])))
+#define DCHECK_BOUND(B,A) DCHECK(B <= (sizeof(A)/sizeof(A[0])))
 
-// On a regular debug build, we want to have DCHECKS enabled.
-#define DCHECK_IS_ON() (true)
-#define DCHECK_SEVERITY FATAL
-const LogSeverity LOG_DCHECK = LOG_FATAL;
+#else  // NDEBUG
+// On a regular release build we want to be able to enable DCHECKS through the
+// command line.
 
-#endif  // defined(NDEBUG)
+// Set to true in InitLogging when we want to enable the dchecks in release.
+extern bool g_enable_dcheck;
+#define DCHECK(condition) \
+    !logging::g_enable_dcheck ? void (0) : \
+        LOG_IF(ERROR_REPORT, !(condition)) << "Check failed: " #condition ". "
 
-#else  // ENABLE_DCHECK
+#define DPCHECK(condition) \
+    !logging::g_enable_dcheck ? void (0) : \
+        PLOG_IF(ERROR_REPORT, !(condition)) << "Check failed: " #condition ". "
 
-#define DCHECK_IS_ON() (false)
-#define DCHECK_SEVERITY FATAL
-const LogSeverity LOG_DCHECK = LOG_FATAL;
+// Helper macro for binary operators.
+// Don't use this macro directly in your code, use DCHECK_EQ et al below.
+#define DCHECK_OP(name, op, val1, val2)  \
+  if (logging::g_enable_dcheck) \
+    if (logging::CheckOpString _result = \
+        logging::Check##name##Impl((val1), (val2), #val1 " " #op " " #val2)) \
+      logging::LogMessage(__FILE__, __LINE__, logging::LOG_ERROR_REPORT, \
+                          _result).stream()
 
-#endif  // ENABLE_DCHECK
+#define DCHECK_STREQ(str1, str2) \
+  while (false) DCHECK_EAT_STREAM_PARAMETERS
 
-// Unlike CHECK et al., DCHECK et al. *does* evaluate their arguments
-// lazily.
+#define DCHECK_STRCASEEQ(str1, str2) \
+  while (false) DCHECK_EAT_STREAM_PARAMETERS
 
-#define DCHECK(condition)                                         \
-  DLOG_IF(DCHECK_SEVERITY, DCHECK_IS_ON() && !(condition))        \
-  << "Check failed: " #condition ". "
+#define DCHECK_STRNE(str1, str2) \
+  while (false) DCHECK_EAT_STREAM_PARAMETERS
 
-#define DPCHECK(condition)                                        \
-  DPLOG_IF(DCHECK_SEVERITY, DCHECK_IS_ON() && !(condition))       \
-  << "Check failed: " #condition ". "
+#define DCHECK_STRCASENE(str1, str2) \
+  while (false) DCHECK_EAT_STREAM_PARAMETERS
 
-// Helper macro for binary operators.
-// Don't use this macro directly in your code, use DCHECK_EQ et al below.
-#define DCHECK_OP(name, op, val1, val2)                         \
-  if (DLOG_IS_ON(DCHECK_SEVERITY))                              \
-    if (logging::CheckOpString _result =                        \
-        logging::Check##name##Impl((val1), (val2),              \
-                                   #val1 " " #op " " #val2))    \
-      logging::LogMessage(                                      \
-          __FILE__, __LINE__, ::logging::LOG_DCHECK,            \
-          _result).stream()
+#endif  // NDEBUG
 
 // Equality/Inequality checks - compare two values, and log a LOG_FATAL message
 // including the two values when the result is not as expected.  The values
@@ -638,25 +648,51 @@ const LogSeverity LOG_DCHECK = LOG_FATAL;
 #define DCHECK_GE(val1, val2) DCHECK_OP(GE, >=, val1, val2)
 #define DCHECK_GT(val1, val2) DCHECK_OP(GT, > , val1, val2)
 
-// Helper macro for string comparisons.
-// Don't use this macro directly in your code, use DCHECK_STREQ et al below.
-#define DCHECK_STROP(func, op, expected, s1, s2)        \
-  if (DCHECK_IS_ON()) CHECK_STROP(func, op, expected, s1, s2)
+#else  // ENABLE_DCHECK
 
-// String (char*) equality/inequality checks.
-// CASE versions are case-insensitive.
-//
-// Note that "s1" and "s2" may be temporary strings which are destroyed
-// by the compiler at the end of the current "full expression"
-// (e.g. DCHECK_STREQ(Foo().c_str(), Bar().c_str())).
+// In order to avoid variable unused warnings for code that only uses a
+// variable in a CHECK, we make sure to use the macro arguments.
 
-#define DCHECK_STREQ(s1, s2) DCHECK_STROP(strcmp, ==, true, s1, s2)
-#define DCHECK_STRNE(s1, s2) DCHECK_STROP(strcmp, !=, false, s1, s2)
-#define DCHECK_STRCASEEQ(s1, s2) DCHECK_STROP(_stricmp, ==, true, s1, s2)
-#define DCHECK_STRCASENE(s1, s2) DCHECK_STROP(_stricmp, !=, false, s1, s2)
+#define DCHECK(condition) \
+  while (false && (condition)) DCHECK_EAT_STREAM_PARAMETERS
 
-#define DCHECK_INDEX(I,A) DCHECK(I < (sizeof(A)/sizeof(A[0])))
-#define DCHECK_BOUND(B,A) DCHECK(B <= (sizeof(A)/sizeof(A[0])))
+#define DPCHECK(condition) \
+  while (false && (condition)) DCHECK_EAT_STREAM_PARAMETERS
+
+#define DCHECK_EQ(val1, val2) \
+  while (false && (val1) == (val2)) DCHECK_EAT_STREAM_PARAMETERS
+
+#define DCHECK_NE(val1, val2) \
+  while (false && (val1) == (val2)) DCHECK_EAT_STREAM_PARAMETERS
+
+#define DCHECK_LE(val1, val2) \
+  while (false && (val1) == (val2)) DCHECK_EAT_STREAM_PARAMETERS
+
+#define DCHECK_LT(val1, val2) \
+  while (false && (val1) == (val2)) DCHECK_EAT_STREAM_PARAMETERS
+
+#define DCHECK_GE(val1, val2) \
+  while (false && (val1) == (val2)) DCHECK_EAT_STREAM_PARAMETERS
+
+#define DCHECK_GT(val1, val2) \
+  while (false && (val1) == (val2)) DCHECK_EAT_STREAM_PARAMETERS
+
+#define DCHECK_STREQ(str1, str2) \
+  while (false && (str1) == (str2)) DCHECK_EAT_STREAM_PARAMETERS
+
+#define DCHECK_STRCASEEQ(str1, str2) \
+  while (false && (str1) == (str2)) DCHECK_EAT_STREAM_PARAMETERS
+
+#define DCHECK_STRNE(str1, str2) \
+  while (false && (str1) == (str2)) DCHECK_EAT_STREAM_PARAMETERS
+
+#define DCHECK_STRCASENE(str1, str2) \
+  while (false && (str1) == (str2)) DCHECK_EAT_STREAM_PARAMETERS
+
+#endif  // ENABLE_DCHECK
+#undef ENABLE_DCHECK
+
+#undef DCHECK_EAT_STREAM_PARAMETERS
 
 // Helper functions for CHECK_OP macro.
 // The (int, int) specialization works around the issue that the compiler