Fixed bug where CHECKs don't fire if min_log_level > FATAL

BUG=61510
TEST=New unittests in base_unittests

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

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

4 files changed, 95 insertions, 39 deletions

diff --git a/base/logging.cc b/base/logging.cc
index a9ce815..ee4a4da 100644
--- a/base/logging.cc
+++ b/base/logging.cc
@@ -382,7 +382,7 @@ bool BaseInitLoggingImpl(const PathChar* new_log_file,
 }
 
 void SetMinLogLevel(int level) {
-  min_log_level = level;
+  min_log_level = std::min(LOG_ERROR_REPORT, level);
 }
 
 int GetMinLogLevel() {
diff --git a/base/logging.h b/base/logging.h
index d33d678..e1b088c 100644
--- a/base/logging.h
+++ b/base/logging.h
@@ -316,6 +316,10 @@ const LogSeverity LOG_DFATAL = LOG_FATAL;
 // Needed for LOG_IS_ON(ERROR).
 const LogSeverity LOG_0 = LOG_ERROR;
 
+// As special cases, we can assume that LOG_IS_ON(ERROR_REPORT) and
+// LOG_IS_ON(FATAL) always hold.  Also, LOG_IS_ON(DFATAL) always holds
+// in debug mode.  In particular, CHECK()s will always fire if they
+// fail.
 #define LOG_IS_ON(severity) \
   ((::logging::LOG_ ## severity) >= ::logging::GetMinLogLevel())
 
@@ -398,9 +402,6 @@ const LogSeverity LOG_0 = LOG_ERROR;
 //
 // 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 ". "
@@ -577,7 +578,9 @@ enum { DEBUG_MODE = ENABLE_DLOG };
 
 #if defined(NDEBUG)
 
-#define DCHECK_SEVERITY ERROR_REPORT
+#define COMPACT_GOOGLE_LOG_EX_DCHECK(ClassName, ...) \
+  COMPACT_GOOGLE_LOG_EX_ERROR_REPORT(ClassName , ##__VA_ARGS__)
+#define COMPACT_GOOGLE_LOG_DCHECK COMPACT_GOOGLE_LOG_ERROR_REPORT
 const LogSeverity LOG_DCHECK = LOG_ERROR_REPORT;
 // This is set to true in InitLogging when we want to enable the
 // DCHECKs in release.
@@ -587,41 +590,38 @@ extern bool g_enable_dcheck;
 #else  // defined(NDEBUG)
 
 // On a regular debug build, we want to have DCHECKs enabled.
-#define DCHECK_SEVERITY FATAL
+#define COMPACT_GOOGLE_LOG_EX_DCHECK(ClassName, ...) \
+  COMPACT_GOOGLE_LOG_EX_FATAL(ClassName , ##__VA_ARGS__)
+#define COMPACT_GOOGLE_LOG_DCHECK COMPACT_GOOGLE_LOG_FATAL
 const LogSeverity LOG_DCHECK = LOG_FATAL;
-// TODO(akalin): We don't define this as 'true' since if the log level
-// is above FATAL, the DCHECK won't go through anyway.  Make it so
-// that DCHECKs work regardless of the logging level, then set this to
-// 'true'.
-#define DCHECK_IS_ON() LOG_IS_ON(DCHECK)
+#define DCHECK_IS_ON() true
 
 #endif  // defined(NDEBUG)
 
 #else  // ENABLE_DCHECK
 
-#define DCHECK_SEVERITY FATAL
-const LogSeverity LOG_DCHECK = LOG_FATAL;
+// These are just dummy values since DCHECK_IS_ON() is always false in
+// this case.
+#define COMPACT_GOOGLE_LOG_EX_DCHECK(ClassName, ...) \
+  COMPACT_GOOGLE_LOG_EX_INFO(ClassName , ##__VA_ARGS__)
+#define COMPACT_GOOGLE_LOG_DCHECK COMPACT_GOOGLE_LOG_INFO
+const LogSeverity LOG_DCHECK = LOG_INFO;
 #define DCHECK_IS_ON() false
 
 #endif  // ENABLE_DCHECK
 #undef ENABLE_DCHECK
 
-// Unlike CHECK et al., DCHECK et al. *does* evaluate their arguments
-// lazily.
-
-// DCHECK et al. also make sure to reference |condition| regardless of
+// DCHECK et al. make sure to reference |condition| regardless of
 // whether DCHECKs are enabled; this is so that we don't get unused
 // variable warnings if the only use of a variable is in a DCHECK.
 // This behavior is different from DLOG_IF et al.
 
-#define DCHECK(condition)                       \
-  !DCHECK_IS_ON() ? (void) 0 :                  \
-  LOG_IF(DCHECK_SEVERITY, !(condition))         \
+#define DCHECK(condition)                                           \
+  LAZY_STREAM(LOG_STREAM(DCHECK), DCHECK_IS_ON() && !(condition))   \
   << "Check failed: " #condition ". "
 
-#define DPCHECK(condition)                      \
-  !DCHECK_IS_ON() ? (void) 0 :                  \
-  PLOG_IF(DCHECK_SEVERITY, !(condition))        \
+#define DPCHECK(condition)                                          \
+  LAZY_STREAM(PLOG_STREAM(DCHECK), DCHECK_IS_ON() && !(condition))  \
   << "Check failed: " #condition ". "
 
 // Helper macro for binary operators.
@@ -635,9 +635,10 @@ const LogSeverity LOG_DCHECK = LOG_FATAL;
           __FILE__, __LINE__, ::logging::LOG_DCHECK,            \
           _result).stream()
 
-// 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
-// must have operator<<(ostream, ...) defined.
+// Equality/Inequality checks - compare two values, and log a
+// LOG_DCHECK message including the two values when the result is not
+// as expected.  The values must have operator<<(ostream, ...)
+// defined.
 //
 // You may append to the error message like so:
 //   DCHECK_NE(1, 2) << ": The world must be ending!";
diff --git a/base/logging_unittest.cc b/base/logging_unittest.cc
index e03c45e..4b7fdbc 100644
--- a/base/logging_unittest.cc
+++ b/base/logging_unittest.cc
@@ -80,6 +80,64 @@ TEST_F(LoggingTest, BasicLogging) {
   DVLOG_IF(0, true) << mock_log_source.Log();
 }
 
+TEST_F(LoggingTest, LogIsOn) {
+#if defined(NDEBUG)
+  const bool kDfatalIsFatal = false;
+#else  // defined(NDEBUG)
+  const bool kDfatalIsFatal = true;
+#endif  // defined(NDEBUG)
+
+  SetMinLogLevel(LOG_INFO);
+  EXPECT_TRUE(LOG_IS_ON(INFO));
+  EXPECT_TRUE(LOG_IS_ON(WARNING));
+  EXPECT_TRUE(LOG_IS_ON(ERROR));
+  EXPECT_TRUE(LOG_IS_ON(ERROR_REPORT));
+  EXPECT_TRUE(LOG_IS_ON(FATAL));
+  EXPECT_TRUE(LOG_IS_ON(DFATAL));
+
+  SetMinLogLevel(LOG_WARNING);
+  EXPECT_FALSE(LOG_IS_ON(INFO));
+  EXPECT_TRUE(LOG_IS_ON(WARNING));
+  EXPECT_TRUE(LOG_IS_ON(ERROR));
+  EXPECT_TRUE(LOG_IS_ON(ERROR_REPORT));
+  EXPECT_TRUE(LOG_IS_ON(FATAL));
+  EXPECT_TRUE(LOG_IS_ON(DFATAL));
+
+  SetMinLogLevel(LOG_ERROR);
+  EXPECT_FALSE(LOG_IS_ON(INFO));
+  EXPECT_FALSE(LOG_IS_ON(WARNING));
+  EXPECT_TRUE(LOG_IS_ON(ERROR));
+  EXPECT_TRUE(LOG_IS_ON(ERROR_REPORT));
+  EXPECT_TRUE(LOG_IS_ON(FATAL));
+  EXPECT_TRUE(LOG_IS_ON(DFATAL));
+
+  SetMinLogLevel(LOG_ERROR_REPORT);
+  EXPECT_FALSE(LOG_IS_ON(INFO));
+  EXPECT_FALSE(LOG_IS_ON(WARNING));
+  EXPECT_FALSE(LOG_IS_ON(ERROR));
+  EXPECT_TRUE(LOG_IS_ON(ERROR_REPORT));
+  EXPECT_TRUE(LOG_IS_ON(FATAL));
+  EXPECT_EQ(kDfatalIsFatal, LOG_IS_ON(DFATAL));
+
+  // LOG_IS_ON(ERROR_REPORT) should always be true.
+  SetMinLogLevel(LOG_FATAL);
+  EXPECT_FALSE(LOG_IS_ON(INFO));
+  EXPECT_FALSE(LOG_IS_ON(WARNING));
+  EXPECT_FALSE(LOG_IS_ON(ERROR));
+  EXPECT_TRUE(LOG_IS_ON(ERROR_REPORT));
+  EXPECT_TRUE(LOG_IS_ON(FATAL));
+  EXPECT_EQ(kDfatalIsFatal, LOG_IS_ON(DFATAL));
+
+  // So should LOG_IS_ON(FATAL).
+  SetMinLogLevel(LOG_FATAL + 1);
+  EXPECT_FALSE(LOG_IS_ON(INFO));
+  EXPECT_FALSE(LOG_IS_ON(WARNING));
+  EXPECT_FALSE(LOG_IS_ON(ERROR));
+  EXPECT_TRUE(LOG_IS_ON(ERROR_REPORT));
+  EXPECT_TRUE(LOG_IS_ON(FATAL));
+  EXPECT_EQ(kDfatalIsFatal, LOG_IS_ON(DFATAL));
+}
+
 TEST_F(LoggingTest, LoggingIsLazy) {
   MockLogSource mock_log_source;
   EXPECT_CALL(mock_log_source, Log()).Times(0);
@@ -105,14 +163,13 @@ TEST_F(LoggingTest, LoggingIsLazy) {
   DVLOG_IF(1, true) << mock_log_source.Log();
 }
 
-TEST_F(LoggingTest, ChecksAreNotLazy) {
+TEST_F(LoggingTest, CheckStreamsAreLazy) {
   MockLogSource mock_log_source, uncalled_mock_log_source;
   EXPECT_CALL(mock_log_source, Log()).Times(8).
       WillRepeatedly(Return("check message"));
   EXPECT_CALL(uncalled_mock_log_source, Log()).Times(0);
 
-  SetMinLogLevel(LOG_FATAL + 1);
-  EXPECT_FALSE(LOG_IS_ON(FATAL));
+  SetLogAssertHandler(&LogSink);
 
   CHECK(mock_log_source.Log()) << uncalled_mock_log_source.Log();
   PCHECK(!mock_log_source.Log()) << mock_log_source.Log();
@@ -134,22 +191,19 @@ TEST_F(LoggingTest, DebugLoggingReleaseBehavior) {
   DVLOG_IF(1, debug_only_variable) << "test";
 }
 
-TEST_F(LoggingTest, DchecksAreLazy) {
+TEST_F(LoggingTest, DcheckStreamsAreLazy) {
   MockLogSource mock_log_source;
   EXPECT_CALL(mock_log_source, Log()).Times(0);
 
 #if !defined(LOGGING_IS_OFFICIAL_BUILD) && defined(NDEBUG)
   // Unofficial release build.
   logging::g_enable_dcheck = false;
-#else  // !defined(LOGGING_IS_OFFICIAL_BUILD) && defined(NDEBUG)
-  SetMinLogLevel(LOG_FATAL + 1);
-  EXPECT_FALSE(LOG_IS_ON(FATAL));
-#endif  // !defined(LOGGING_IS_OFFICIAL_BUILD) && defined(NDEBUG)
   DCHECK(mock_log_source.Log()) << mock_log_source.Log();
   DPCHECK(mock_log_source.Log()) << mock_log_source.Log();
   DCHECK_EQ(0, 0) << mock_log_source.Log();
   DCHECK_EQ(mock_log_source.Log(), static_cast<const char*>(NULL))
       << mock_log_source.Log();
+#endif  // !defined(LOGGING_IS_OFFICIAL_BUILD) && defined(NDEBUG)
 }
 
 TEST_F(LoggingTest, Dcheck) {
diff --git a/ipc/ipc_sync_channel_unittest.cc b/ipc/ipc_sync_channel_unittest.cc
index ffd2efd..15d5a38 100644
--- a/ipc/ipc_sync_channel_unittest.cc
+++ b/ipc/ipc_sync_channel_unittest.cc
@@ -808,6 +808,8 @@ TEST_F(IPCSyncChannelTest, QueuedReply) {
 
 namespace {
 
+void DropAssert(const std::string&) {}
+
 class BadServer : public Worker {
  public:
   explicit BadServer(bool pump_during_send)
@@ -822,12 +824,11 @@ class BadServer : public Worker {
     if (pump_during_send_)
       msg->EnableMessagePumping();
 
-    // Temporarily set the minimum logging very high so that the assertion
-    // in ipc_message_utils doesn't fire.
-    int log_level = logging::GetMinLogLevel();
-    logging::SetMinLogLevel(kint32max);
+    // Temporarily ignore asserts so that the assertion in
+    // ipc_message_utils doesn't cause termination.
+    logging::SetLogAssertHandler(&DropAssert);
     bool result = Send(msg);
-    logging::SetMinLogLevel(log_level);
+    logging::SetLogAssertHandler(NULL);
     DCHECK(!result);
 
     // Need to send another message to get the client to call Done().