[Open Screen] Adds a unit test for logging macros.
- Adds unit tests for the macros defined in util/osp_logging.h
- Adds testing hooks to logging_posix.h
Tests both behavior in _DEBUG and !_DEBUG builds.
Change-Id: I5fa3382d5455fbdf5e5b75d0d519cd43c5960d12
Reviewed-on: https://chromium-review.googlesource.com/c/openscreen/+/2289036
Commit-Queue: mark a. foltz <mfoltz@chromium.org>
Reviewed-by: Brandon Tolsch <btolsch@chromium.org>
diff --git a/platform/impl/logging_unittest.cc b/platform/impl/logging_unittest.cc
new file mode 100644
index 0000000..84018b3
--- /dev/null
+++ b/platform/impl/logging_unittest.cc
@@ -0,0 +1,321 @@
+// Copyright 2020 The Chromium Authors. All rights reserved.
+// Use of this source code is governed by a BSD-style license that can be
+// found in the LICENSE file.
+
+#include "platform/api/logging.h"
+
+#include <string>
+#include <vector>
+
+#include "absl/strings/match.h"
+#include "absl/strings/str_cat.h"
+#include "absl/strings/string_view.h"
+#include "gtest/gtest.h"
+#include "platform/impl/logging.h"
+#include "platform/impl/logging_test.h"
+#include "util/osp_logging.h"
+
+namespace openscreen {
+
+class LoggingTest : public ::testing::Test {
+ public:
+ LoggingTest() {}
+
+ void SetUp() {
+ previous_log_level = GetLogLevel();
+ SetLogLevel(LogLevel::kInfo);
+ SetLogBufferForTest(&log_messages);
+ }
+
+ void TearDown() {
+ SetLogLevel(previous_log_level);
+ SetLogBufferForTest(nullptr);
+ DisableBreakForTest(nullptr);
+ }
+
+ protected:
+ void DisableBreak() { DisableBreakForTest(&break_was_called); }
+
+ void ExpectLog(LogLevel level, absl::string_view message) {
+ const char* level_string = "";
+ switch (level) {
+ case LogLevel::kVerbose:
+ level_string = "VERBOSE";
+ break;
+ case LogLevel::kInfo:
+ level_string = "INFO";
+ break;
+ case LogLevel::kWarning:
+ level_string = "WARNING";
+ break;
+ case LogLevel::kError:
+ level_string = "ERROR";
+ break;
+ case LogLevel::kFatal:
+ level_string = "FATAL";
+ break;
+ }
+ expected_messages.push_back({level_string, std::string(message)});
+ }
+
+ void VerifyNoLogs() { EXPECT_TRUE(log_messages.empty()); }
+
+ void VerifyLogs() {
+ ASSERT_EQ(expected_messages.size(), log_messages.size());
+ auto expected_it = expected_messages.begin();
+ auto actual_it = log_messages.begin();
+ // NOTE: This is somewhat brittle; it relies on details of how
+ // logging_posix.cc formats log messages.
+ while (expected_it != expected_messages.end()) {
+ EXPECT_TRUE(
+ absl::StartsWith(*actual_it, absl::StrCat("[", expected_it->level)));
+ EXPECT_TRUE(absl::EndsWith(
+ *actual_it, absl::StrCat("] ", expected_it->message, "\n")));
+ actual_it++;
+ expected_it++;
+ }
+ expected_messages.clear();
+ log_messages.clear();
+ }
+
+ void ExpectBreakAndClear() {
+ EXPECT_TRUE(break_was_called);
+ break_was_called = false;
+ }
+
+ void ExpectDebugBreakAndClear() {
+#if OSP_DCHECK_IS_ON()
+ EXPECT_TRUE(break_was_called);
+ break_was_called = false;
+#else
+ EXPECT_FALSE(break_was_called);
+#endif // OSP_DCHECK_IS_ON()
+ }
+
+ private:
+ struct LogMessage {
+ std::string level;
+ std::string message;
+ };
+ std::vector<std::string> log_messages;
+ std::vector<LogMessage> expected_messages;
+ bool break_was_called = false;
+ LogLevel previous_log_level = LogLevel::kWarning;
+};
+
+TEST_F(LoggingTest, UnconditionalLogging) {
+ SetLogLevel(LogLevel::kVerbose);
+ ExpectLog(LogLevel::kVerbose, "Verbose");
+ ExpectLog(LogLevel::kInfo, "Info");
+ ExpectLog(LogLevel::kWarning, "Warning");
+ ExpectLog(LogLevel::kError, "Error");
+
+ OSP_VLOG << "Verbose";
+ OSP_LOG_INFO << "Info";
+ OSP_LOG_WARN << "Warning";
+ OSP_LOG_ERROR << "Error";
+
+ VerifyLogs();
+
+ SetLogLevel(LogLevel::kWarning);
+ ExpectLog(LogLevel::kWarning, "Warning");
+ ExpectLog(LogLevel::kError, "Error");
+
+ OSP_VLOG << "Verbose";
+ OSP_LOG_INFO << "Info";
+ OSP_LOG_WARN << "Warning";
+ OSP_LOG_ERROR << "Error";
+
+ VerifyLogs();
+}
+
+TEST_F(LoggingTest, ConditionalLogging) {
+ SetLogLevel(LogLevel::kVerbose);
+
+ ExpectLog(LogLevel::kVerbose, "Verbose");
+ ExpectLog(LogLevel::kInfo, "Info");
+ ExpectLog(LogLevel::kWarning, "Warning");
+ ExpectLog(LogLevel::kError, "Error");
+
+ OSP_VLOG_IF(true) << "Verbose";
+ OSP_LOG_IF(INFO, true) << "Info";
+ OSP_LOG_IF(WARN, true) << "Warning";
+ OSP_LOG_IF(ERROR, true) << "Error";
+ VerifyLogs();
+
+ OSP_VLOG_IF(false) << "Verbose";
+ OSP_LOG_IF(INFO, false) << "Info";
+ OSP_LOG_IF(WARN, false) << "Warning";
+ OSP_LOG_IF(ERROR, false) << "Error";
+ VerifyNoLogs();
+}
+
+TEST_F(LoggingTest, DebugUnconditionalLogging) {
+ SetLogLevel(LogLevel::kVerbose);
+ OSP_DVLOG << "Verbose";
+ OSP_DLOG_INFO << "Info";
+ OSP_DLOG_WARN << "Warning";
+ OSP_DLOG_ERROR << "Error";
+
+#if OSP_DCHECK_IS_ON()
+ ExpectLog(LogLevel::kVerbose, "Verbose");
+ ExpectLog(LogLevel::kInfo, "Info");
+ ExpectLog(LogLevel::kWarning, "Warning");
+ ExpectLog(LogLevel::kError, "Error");
+ VerifyLogs();
+#else
+ VerifyNoLogs();
+#endif // OSP_DCHECK_IS_ON()
+
+ SetLogLevel(LogLevel::kWarning);
+
+ OSP_DVLOG << "Verbose";
+ OSP_DLOG_INFO << "Info";
+ OSP_DLOG_WARN << "Warning";
+ OSP_DLOG_ERROR << "Error";
+
+#if OSP_DCHECK_IS_ON()
+ ExpectLog(LogLevel::kWarning, "Warning");
+ ExpectLog(LogLevel::kError, "Error");
+ VerifyLogs();
+#else
+ VerifyNoLogs();
+#endif // OSP_DCHECK_IS_ON()
+}
+
+TEST_F(LoggingTest, DebugConditionalLogging) {
+ SetLogLevel(LogLevel::kVerbose);
+
+ OSP_DVLOG_IF(true) << "Verbose";
+ OSP_DLOG_IF(INFO, true) << "Info";
+ OSP_DLOG_IF(WARN, true) << "Warning";
+ OSP_DLOG_IF(ERROR, true) << "Error";
+
+#if OSP_DCHECK_IS_ON()
+ ExpectLog(LogLevel::kVerbose, "Verbose");
+ ExpectLog(LogLevel::kInfo, "Info");
+ ExpectLog(LogLevel::kWarning, "Warning");
+ ExpectLog(LogLevel::kError, "Error");
+ VerifyLogs();
+#else
+ VerifyNoLogs();
+#endif // OSP_DCHECK_IS_ON()
+
+ OSP_DVLOG_IF(false) << "Verbose";
+ OSP_DLOG_IF(INFO, false) << "Info";
+ OSP_DLOG_IF(WARN, false) << "Warning";
+ OSP_DLOG_IF(ERROR, false) << "Error";
+ VerifyNoLogs();
+}
+
+TEST_F(LoggingTest, CheckAndLogFatal) {
+ DisableBreak();
+
+ ExpectLog(LogLevel::kFatal, "OSP_CHECK(false) failed: ");
+ OSP_CHECK(false);
+ ExpectBreakAndClear();
+
+ ExpectLog(LogLevel::kFatal, "OSP_CHECK((1) == (2)) failed: 1 vs. 2: ");
+ OSP_CHECK_EQ(1, 2);
+ ExpectBreakAndClear();
+
+ ExpectLog(LogLevel::kFatal, "OSP_CHECK((1) != (1)) failed: 1 vs. 1: ");
+ OSP_CHECK_NE(1, 1);
+ ExpectBreakAndClear();
+
+ ExpectLog(LogLevel::kFatal, "OSP_CHECK((2) < (1)) failed: 2 vs. 1: ");
+ OSP_CHECK_LT(2, 1);
+ ExpectBreakAndClear();
+
+ ExpectLog(LogLevel::kFatal, "OSP_CHECK((2) <= (1)) failed: 2 vs. 1: ");
+ OSP_CHECK_LE(2, 1);
+ ExpectBreakAndClear();
+
+ ExpectLog(LogLevel::kFatal, "OSP_CHECK((1) > (2)) failed: 1 vs. 2: ");
+ OSP_CHECK_GT(1, 2);
+ ExpectBreakAndClear();
+
+ ExpectLog(LogLevel::kFatal, "OSP_CHECK((1) >= (2)) failed: 1 vs. 2: ");
+ OSP_CHECK_GE(1, 2);
+ ExpectBreakAndClear();
+
+ ExpectLog(LogLevel::kFatal, "Fatal");
+ OSP_LOG_FATAL << "Fatal";
+ ExpectBreakAndClear();
+
+ VerifyLogs();
+}
+
+TEST_F(LoggingTest, DCheckAndDLogFatal) {
+ DisableBreak();
+
+ ExpectLog(LogLevel::kFatal, "OSP_CHECK(false) failed: ");
+ OSP_DCHECK(false);
+ ExpectDebugBreakAndClear();
+
+ ExpectLog(LogLevel::kFatal, "OSP_CHECK((1) == (2)) failed: 1 vs. 2: ");
+ OSP_DCHECK_EQ(1, 2);
+ ExpectDebugBreakAndClear();
+
+ ExpectLog(LogLevel::kFatal, "OSP_CHECK((1) != (1)) failed: 1 vs. 1: ");
+ OSP_DCHECK_NE(1, 1);
+ ExpectDebugBreakAndClear();
+
+ ExpectLog(LogLevel::kFatal, "OSP_CHECK((2) < (1)) failed: 2 vs. 1: ");
+ OSP_DCHECK_LT(2, 1);
+ ExpectDebugBreakAndClear();
+
+ ExpectLog(LogLevel::kFatal, "OSP_CHECK((2) <= (1)) failed: 2 vs. 1: ");
+ OSP_DCHECK_LE(2, 1);
+ ExpectDebugBreakAndClear();
+
+ ExpectLog(LogLevel::kFatal, "OSP_CHECK((1) > (2)) failed: 1 vs. 2: ");
+ OSP_DCHECK_GT(1, 2);
+ ExpectDebugBreakAndClear();
+
+ ExpectLog(LogLevel::kFatal, "OSP_CHECK((1) >= (2)) failed: 1 vs. 2: ");
+ OSP_DCHECK_GE(1, 2);
+ ExpectDebugBreakAndClear();
+
+ ExpectLog(LogLevel::kFatal, "Fatal");
+ OSP_DLOG_FATAL << "Fatal";
+ ExpectDebugBreakAndClear();
+
+#if OSP_DCHECK_IS_ON()
+ VerifyLogs();
+#else
+ VerifyNoLogs();
+#endif // OSP_DCHECK_IS_ON()
+}
+
+TEST_F(LoggingTest, OspUnimplemented) {
+ // Default is to log once per process if the level >= kWarning.
+ SetLogLevel(LogLevel::kWarning);
+ ExpectLog(LogLevel::kWarning, "TestBody: UNIMPLEMENTED() hit.");
+ for (int i = 0; i < 2; i++) {
+ OSP_UNIMPLEMENTED();
+ }
+ VerifyLogs();
+
+ // Setting the level to kVerbose logs every time.
+ SetLogLevel(LogLevel::kVerbose);
+ std::string message("TestBody: UNIMPLEMENTED() hit.");
+ ExpectLog(LogLevel::kVerbose, message);
+ ExpectLog(LogLevel::kVerbose, message);
+ for (int i = 0; i < 2; i++) {
+ OSP_UNIMPLEMENTED();
+ }
+ VerifyLogs();
+}
+
+TEST_F(LoggingTest, OspNotReached) {
+ DisableBreak();
+ ExpectLog(LogLevel::kFatal, "TestBody: NOTREACHED() hit.");
+
+ OSP_NOTREACHED();
+
+ VerifyLogs();
+ ExpectBreakAndClear();
+}
+
+} // namespace openscreen