1 // Copyright 2020 The Chromium Authors. All rights reserved.
2 // Use of this source code is governed by a BSD-style license that can be
3 // found in the LICENSE file.
4
5 #include "platform/api/logging.h"
6
7 #include <string>
8 #include <vector>
9
10 #include "absl/strings/match.h"
11 #include "absl/strings/str_cat.h"
12 #include "absl/strings/string_view.h"
13 #include "gtest/gtest.h"
14 #include "platform/impl/logging.h"
15 #include "platform/impl/logging_test.h"
16 #include "util/osp_logging.h"
17
18 namespace openscreen {
19
20 class LoggingTest : public ::testing::Test {
21 public:
LoggingTest()22 LoggingTest() {}
23
SetUp()24 void SetUp() {
25 previous_log_level = GetLogLevel();
26 SetLogLevel(LogLevel::kInfo);
27 SetLogBufferForTest(&log_messages);
28 testing::FLAGS_gtest_death_test_style = "threadsafe";
29 }
30
TearDown()31 void TearDown() {
32 SetLogLevel(previous_log_level);
33 SetLogBufferForTest(nullptr);
34 }
35
36 protected:
ExpectLog(LogLevel level,absl::string_view message)37 void ExpectLog(LogLevel level, absl::string_view message) {
38 const char* level_string = "";
39 switch (level) {
40 case LogLevel::kVerbose:
41 level_string = "VERBOSE";
42 break;
43 case LogLevel::kInfo:
44 level_string = "INFO";
45 break;
46 case LogLevel::kWarning:
47 level_string = "WARNING";
48 break;
49 case LogLevel::kError:
50 level_string = "ERROR";
51 break;
52 case LogLevel::kFatal:
53 level_string = "FATAL";
54 break;
55 }
56 expected_messages.push_back({level_string, std::string(message)});
57 }
58
VerifyNoLogs()59 void VerifyNoLogs() { EXPECT_TRUE(log_messages.empty()); }
60
VerifyLogs()61 void VerifyLogs() {
62 ASSERT_EQ(expected_messages.size(), log_messages.size());
63 auto expected_it = expected_messages.begin();
64 auto actual_it = log_messages.begin();
65 // NOTE: This is somewhat brittle; it relies on details of how
66 // logging_posix.cc formats log messages.
67 while (expected_it != expected_messages.end()) {
68 EXPECT_TRUE(
69 absl::StartsWith(*actual_it, absl::StrCat("[", expected_it->level)));
70 EXPECT_TRUE(absl::EndsWith(
71 *actual_it, absl::StrCat("] ", expected_it->message, "\n")));
72 actual_it++;
73 expected_it++;
74 }
75 expected_messages.clear();
76 log_messages.clear();
77 }
78
79 private:
80 struct LogMessage {
81 std::string level;
82 std::string message;
83 };
84 std::vector<std::string> log_messages;
85 std::vector<LogMessage> expected_messages;
86 LogLevel previous_log_level = LogLevel::kWarning;
87 };
88
TEST_F(LoggingTest,UnconditionalLogging)89 TEST_F(LoggingTest, UnconditionalLogging) {
90 SetLogLevel(LogLevel::kVerbose);
91 ExpectLog(LogLevel::kVerbose, "Verbose");
92 ExpectLog(LogLevel::kInfo, "Info");
93 ExpectLog(LogLevel::kWarning, "Warning");
94 ExpectLog(LogLevel::kError, "Error");
95
96 OSP_VLOG << "Verbose";
97 OSP_LOG_INFO << "Info";
98 OSP_LOG_WARN << "Warning";
99 OSP_LOG_ERROR << "Error";
100
101 VerifyLogs();
102
103 SetLogLevel(LogLevel::kWarning);
104 ExpectLog(LogLevel::kWarning, "Warning");
105 ExpectLog(LogLevel::kError, "Error");
106
107 OSP_VLOG << "Verbose";
108 OSP_LOG_INFO << "Info";
109 OSP_LOG_WARN << "Warning";
110 OSP_LOG_ERROR << "Error";
111
112 VerifyLogs();
113 }
114
TEST_F(LoggingTest,ConditionalLogging)115 TEST_F(LoggingTest, ConditionalLogging) {
116 SetLogLevel(LogLevel::kVerbose);
117
118 ExpectLog(LogLevel::kVerbose, "Verbose");
119 ExpectLog(LogLevel::kInfo, "Info");
120 ExpectLog(LogLevel::kWarning, "Warning");
121 ExpectLog(LogLevel::kError, "Error");
122
123 OSP_VLOG_IF(true) << "Verbose";
124 OSP_LOG_IF(INFO, true) << "Info";
125 OSP_LOG_IF(WARN, true) << "Warning";
126 OSP_LOG_IF(ERROR, true) << "Error";
127 VerifyLogs();
128
129 OSP_VLOG_IF(false) << "Verbose";
130 OSP_LOG_IF(INFO, false) << "Info";
131 OSP_LOG_IF(WARN, false) << "Warning";
132 OSP_LOG_IF(ERROR, false) << "Error";
133 VerifyNoLogs();
134 }
135
TEST_F(LoggingTest,DebugUnconditionalLogging)136 TEST_F(LoggingTest, DebugUnconditionalLogging) {
137 SetLogLevel(LogLevel::kVerbose);
138 OSP_DVLOG << "Verbose";
139 OSP_DLOG_INFO << "Info";
140 OSP_DLOG_WARN << "Warning";
141 OSP_DLOG_ERROR << "Error";
142
143 #if OSP_DCHECK_IS_ON()
144 ExpectLog(LogLevel::kVerbose, "Verbose");
145 ExpectLog(LogLevel::kInfo, "Info");
146 ExpectLog(LogLevel::kWarning, "Warning");
147 ExpectLog(LogLevel::kError, "Error");
148 VerifyLogs();
149 #else
150 VerifyNoLogs();
151 #endif // OSP_DCHECK_IS_ON()
152
153 SetLogLevel(LogLevel::kWarning);
154
155 OSP_DVLOG << "Verbose";
156 OSP_DLOG_INFO << "Info";
157 OSP_DLOG_WARN << "Warning";
158 OSP_DLOG_ERROR << "Error";
159
160 #if OSP_DCHECK_IS_ON()
161 ExpectLog(LogLevel::kWarning, "Warning");
162 ExpectLog(LogLevel::kError, "Error");
163 VerifyLogs();
164 #else
165 VerifyNoLogs();
166 #endif // OSP_DCHECK_IS_ON()
167 }
168
TEST_F(LoggingTest,DebugConditionalLogging)169 TEST_F(LoggingTest, DebugConditionalLogging) {
170 SetLogLevel(LogLevel::kVerbose);
171
172 OSP_DVLOG_IF(true) << "Verbose";
173 OSP_DLOG_IF(INFO, true) << "Info";
174 OSP_DLOG_IF(WARN, true) << "Warning";
175 OSP_DLOG_IF(ERROR, true) << "Error";
176
177 #if OSP_DCHECK_IS_ON()
178 ExpectLog(LogLevel::kVerbose, "Verbose");
179 ExpectLog(LogLevel::kInfo, "Info");
180 ExpectLog(LogLevel::kWarning, "Warning");
181 ExpectLog(LogLevel::kError, "Error");
182 VerifyLogs();
183 #else
184 VerifyNoLogs();
185 #endif // OSP_DCHECK_IS_ON()
186
187 OSP_DVLOG_IF(false) << "Verbose";
188 OSP_DLOG_IF(INFO, false) << "Info";
189 OSP_DLOG_IF(WARN, false) << "Warning";
190 OSP_DLOG_IF(ERROR, false) << "Error";
191 VerifyNoLogs();
192 }
193
TEST_F(LoggingTest,CheckAndLogFatal)194 TEST_F(LoggingTest, CheckAndLogFatal) {
195 ASSERT_DEATH(OSP_CHECK(false), ".*OSP_CHECK\\(false\\) failed: ");
196
197 ASSERT_DEATH(OSP_CHECK_EQ(1, 2),
198 ".*OSP_CHECK\\(\\(1\\) == \\(2\\)\\) failed: 1 vs\\. 2: ");
199
200 ASSERT_DEATH(OSP_CHECK_NE(1, 1),
201 ".*OSP_CHECK\\(\\(1\\) != \\(1\\)\\) failed: 1 vs\\. 1: ");
202
203 ASSERT_DEATH(OSP_CHECK_LT(2, 1),
204 ".*OSP_CHECK\\(\\(2\\) < \\(1\\)\\) failed: 2 vs\\. 1: ");
205
206 ASSERT_DEATH(OSP_CHECK_LE(2, 1),
207 ".*OSP_CHECK\\(\\(2\\) <= \\(1\\)\\) failed: 2 vs\\. 1: ");
208
209 ASSERT_DEATH(OSP_CHECK_GT(1, 2),
210 ".*OSP_CHECK\\(\\(1\\) > \\(2\\)\\) failed: 1 vs\\. 2: ");
211
212 ASSERT_DEATH(OSP_CHECK_GE(1, 2),
213 ".*OSP_CHECK\\(\\(1\\) >= \\(2\\)\\) failed: 1 vs\\. 2: ");
214
215 ASSERT_DEATH((OSP_LOG_FATAL << "Fatal"), ".*Fatal");
216
217 VerifyLogs();
218 }
219
TEST_F(LoggingTest,DCheckAndDLogFatal)220 TEST_F(LoggingTest, DCheckAndDLogFatal) {
221 #if OSP_DCHECK_IS_ON()
222 ASSERT_DEATH(OSP_DCHECK(false), ".*OSP_CHECK\\(false\\) failed: ");
223
224 ASSERT_DEATH(OSP_DCHECK_EQ(1, 2),
225 ".*OSP_CHECK\\(\\(1\\) == \\(2\\)\\) failed: 1 vs\\. 2: ");
226
227 ASSERT_DEATH(OSP_DCHECK_NE(1, 1),
228 ".*OSP_CHECK\\(\\(1\\) != \\(1\\)\\) failed: 1 vs\\. 1: ");
229
230 ASSERT_DEATH(OSP_DCHECK_LT(2, 1),
231 ".*OSP_CHECK\\(\\(2\\) < \\(1\\)\\) failed: 2 vs\\. 1: ");
232
233 ASSERT_DEATH(OSP_DCHECK_LE(2, 1),
234 ".*OSP_CHECK\\(\\(2\\) <= \\(1\\)\\) failed: 2 vs\\. 1: ");
235
236 ASSERT_DEATH(OSP_DCHECK_GT(1, 2),
237 ".*OSP_CHECK\\(\\(1\\) > \\(2\\)\\) failed: 1 vs\\. 2: ");
238
239 ASSERT_DEATH(OSP_DCHECK_GE(1, 2),
240 ".*OSP_CHECK\\(\\(1\\) >= \\(2\\)\\) failed: 1 vs\\. 2: ");
241
242 ASSERT_DEATH((OSP_DLOG_FATAL << "Fatal"), ".*Fatal");
243
244 VerifyLogs();
245 #else
246 VerifyNoLogs();
247 #endif // OSP_DCHECK_IS_ON()
248 }
249
TEST_F(LoggingTest,OspUnimplemented)250 TEST_F(LoggingTest, OspUnimplemented) {
251 // Default is to log once per process if the level >= kWarning.
252 SetLogLevel(LogLevel::kWarning);
253 ExpectLog(LogLevel::kWarning, "TestBody: UNIMPLEMENTED() hit.");
254 for (int i = 0; i < 2; i++) {
255 OSP_UNIMPLEMENTED();
256 }
257 VerifyLogs();
258
259 // Setting the level to kVerbose logs every time.
260 SetLogLevel(LogLevel::kVerbose);
261 std::string message("TestBody: UNIMPLEMENTED() hit.");
262 ExpectLog(LogLevel::kVerbose, message);
263 ExpectLog(LogLevel::kVerbose, message);
264 for (int i = 0; i < 2; i++) {
265 OSP_UNIMPLEMENTED();
266 }
267 VerifyLogs();
268 }
269
TEST_F(LoggingTest,OspNotReached)270 TEST_F(LoggingTest, OspNotReached) {
271 ASSERT_DEATH(OSP_NOTREACHED(), ".*TestBody: NOTREACHED\\(\\) hit.");
272 }
273
274 } // namespace openscreen
275