From deba0ff3212e9c8a263ade6280cfba4c5a1843d1 Mon Sep 17 00:00:00 2001
From: "akalin@chromium.org"
<akalin@chromium.org@0039d316-1c4b-4281-b951-d872f2087c98>
Date: Wed, 3 Nov 2010 05:30:14 +0000
Subject: [PATCH] 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
---
base/logging.cc | 2 +-
base/logging.h | 51 +++++++++++------------
base/logging_unittest.cc | 70 ++++++++++++++++++++++++++++----
ipc/ipc_sync_channel_unittest.cc | 11 ++---
4 files changed, 95 insertions(+), 39 deletions(-)
diff --git a/base/logging.cc b/base/logging.cc
index a9ce81584aed2..ee4a4da64760c 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 d33d678cb0995..e1b088c44afe3 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 e03c45ec179c8..4b7fdbcd46ad5 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 ffd2efd230b1d..15d5a38a5672d 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().
--
GitLab