1 // Copyright 2014 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 <stdlib.h>
6
7 #include <sstream>
8 #include <string>
9
10 #include "mojo/public/cpp/environment/environment.h"
11 #include "mojo/public/cpp/environment/logging.h"
12 #include "mojo/public/cpp/system/macros.h"
13 #include "testing/gtest/include/gtest/gtest.h"
14
15 // A macro, so it can be automatically joined with other string literals. (Not
16 // simply __FILE__, since that may contain a path.)
17 #define OUR_FILENAME "logging_unittest.cc"
18
19 namespace mojo {
20 namespace {
21
22 class PtrToMemberHelper {
23 public:
24 int member;
25 };
26
DcheckTestHelper(bool * was_called)27 bool DcheckTestHelper(bool* was_called) {
28 *was_called = true;
29 return false;
30 }
31
32 class LoggingTest : public testing::Test {
33 public:
LoggingTest()34 LoggingTest() : environment_(NULL, &kMockLogger) {
35 minimum_log_level_ = MOJO_LOG_LEVEL_INFO;
36 ResetMockLogger();
37 }
~LoggingTest()38 virtual ~LoggingTest() {}
39
40 protected:
41 // Note: Does not reset |minimum_log_level_|.
ResetMockLogger()42 static void ResetMockLogger() {
43 log_message_was_called_ = false;
44 last_log_level_ = MOJO_LOG_LEVEL_INFO;
45 last_message_.clear();
46 }
47
48 // A function returning |bool| that shouldn't be called.
NotCalledCondition()49 static bool NotCalledCondition() {
50 not_called_condition_was_called_ = true;
51 return false;
52 }
53
log_message_was_called()54 static bool log_message_was_called() { return log_message_was_called_; }
last_log_level()55 static MojoLogLevel last_log_level() { return last_log_level_; }
last_message()56 static const std::string& last_message() { return last_message_; }
not_called_condition_was_called()57 static bool not_called_condition_was_called() {
58 return not_called_condition_was_called_;
59 }
60
61 private:
62 // Note: We record calls even if |log_level| is below |minimum_log_level_|
63 // (since the macros should mostly avoid this, and we want to be able to check
64 // that they do).
MockLogMessage(MojoLogLevel log_level,const char * message)65 static void MockLogMessage(MojoLogLevel log_level, const char* message) {
66 log_message_was_called_ = true;
67 last_log_level_ = log_level;
68 last_message_ = message;
69 }
70
MockGetMinimumLogLevel()71 static MojoLogLevel MockGetMinimumLogLevel() {
72 return minimum_log_level_;
73 }
74
MockSetMinimumLogLevel(MojoLogLevel minimum_log_level)75 static void MockSetMinimumLogLevel(MojoLogLevel minimum_log_level) {
76 minimum_log_level_ = minimum_log_level;
77 }
78
79 Environment environment_;
80
81 static const MojoLogger kMockLogger;
82 static MojoLogLevel minimum_log_level_;
83 static bool log_message_was_called_;
84 static MojoLogLevel last_log_level_;
85 static std::string last_message_;
86 static bool not_called_condition_was_called_;
87
88 MOJO_DISALLOW_COPY_AND_ASSIGN(LoggingTest);
89 };
90
91 // static
92 const MojoLogger LoggingTest::kMockLogger = {
93 &LoggingTest::MockLogMessage,
94 &LoggingTest::MockGetMinimumLogLevel,
95 &LoggingTest::MockSetMinimumLogLevel
96 };
97
98 // static
99 MojoLogLevel LoggingTest::minimum_log_level_ = MOJO_LOG_LEVEL_INFO;
100
101 // static
102 bool LoggingTest::log_message_was_called_ = MOJO_LOG_LEVEL_INFO;
103
104 // static
105 MojoLogLevel LoggingTest::last_log_level_ = MOJO_LOG_LEVEL_INFO;
106
107 // static
108 std::string LoggingTest::last_message_;
109
110 // static
111 bool LoggingTest::not_called_condition_was_called_ = false;
112
ExpectedLogMessage(int line,const char * message)113 std::string ExpectedLogMessage(int line, const char* message) {
114 std::ostringstream s;
115 s << OUR_FILENAME "(" << line << "): " << message;
116 return s.str();
117 }
118
TEST_F(LoggingTest,InternalLogMessage)119 TEST_F(LoggingTest, InternalLogMessage) {
120 internal::LogMessage("foo.cc", 123, MOJO_LOG_LEVEL_INFO).stream()
121 << "hello " << "world";
122 EXPECT_TRUE(log_message_was_called());
123 EXPECT_EQ(MOJO_LOG_LEVEL_INFO, last_log_level());
124 EXPECT_EQ("foo.cc(123): hello world", last_message());
125
126 ResetMockLogger();
127
128 internal::LogMessage("./path/to/foo.cc", 123, MOJO_LOG_LEVEL_WARNING).stream()
129 << "hello " << "world";
130 EXPECT_TRUE(log_message_was_called());
131 EXPECT_EQ(MOJO_LOG_LEVEL_WARNING, last_log_level());
132 EXPECT_EQ("foo.cc(123): hello world", last_message());
133
134 ResetMockLogger();
135
136 internal::LogMessage("/path/to/foo.cc", 123, MOJO_LOG_LEVEL_ERROR).stream()
137 << "hello " << "world";
138 EXPECT_TRUE(log_message_was_called());
139 EXPECT_EQ(MOJO_LOG_LEVEL_ERROR, last_log_level());
140 EXPECT_EQ("foo.cc(123): hello world", last_message());
141
142 ResetMockLogger();
143
144 internal::LogMessage("path/to/foo.cc", 123, MOJO_LOG_LEVEL_FATAL).stream()
145 << "hello " << "world";
146 EXPECT_TRUE(log_message_was_called());
147 EXPECT_EQ(MOJO_LOG_LEVEL_FATAL, last_log_level());
148 EXPECT_EQ("foo.cc(123): hello world", last_message());
149
150 ResetMockLogger();
151
152 internal::LogMessage(".\\xy\\foo.cc", 123, MOJO_LOG_LEVEL_VERBOSE).stream()
153 << "hello " << "world";
154 EXPECT_TRUE(log_message_was_called());
155 EXPECT_EQ(MOJO_LOG_LEVEL_VERBOSE, last_log_level());
156 EXPECT_EQ("foo.cc(123): hello world", last_message());
157
158 ResetMockLogger();
159
160 internal::LogMessage("xy\\foo.cc", 123, MOJO_LOG_LEVEL_VERBOSE-1).stream()
161 << "hello " << "world";
162 EXPECT_TRUE(log_message_was_called());
163 EXPECT_EQ(MOJO_LOG_LEVEL_VERBOSE-1, last_log_level());
164 EXPECT_EQ("foo.cc(123): hello world", last_message());
165
166 ResetMockLogger();
167
168 internal::LogMessage("C:\\xy\\foo.cc", 123, MOJO_LOG_LEVEL_VERBOSE-9).stream()
169 << "hello " << "world";
170 EXPECT_TRUE(log_message_was_called());
171 EXPECT_EQ(MOJO_LOG_LEVEL_VERBOSE-9, last_log_level());
172 EXPECT_EQ("foo.cc(123): hello world", last_message());
173
174 ResetMockLogger();
175
176 internal::LogMessage(__FILE__, 123, MOJO_LOG_LEVEL_INFO).stream()
177 << "hello " << "world";
178 EXPECT_TRUE(log_message_was_called());
179 EXPECT_EQ(MOJO_LOG_LEVEL_INFO, last_log_level());
180 EXPECT_EQ(OUR_FILENAME "(123): hello world", last_message());
181 }
182
TEST_F(LoggingTest,LogStream)183 TEST_F(LoggingTest, LogStream) {
184 MOJO_LOG_STREAM(INFO) << "hello";
185 EXPECT_TRUE(log_message_was_called());
186 EXPECT_EQ(MOJO_LOG_LEVEL_INFO, last_log_level());
187 EXPECT_EQ(ExpectedLogMessage(__LINE__ - 3, "hello"), last_message());
188
189 ResetMockLogger();
190
191 MOJO_LOG_STREAM(ERROR) << "hi " << 123;
192 EXPECT_TRUE(log_message_was_called());
193 EXPECT_EQ(MOJO_LOG_LEVEL_ERROR, last_log_level());
194 EXPECT_EQ(ExpectedLogMessage(__LINE__ - 3, "hi 123"), last_message());
195 }
196
TEST_F(LoggingTest,LazyLogStream)197 TEST_F(LoggingTest, LazyLogStream) {
198 MOJO_LAZY_LOG_STREAM(INFO, true) << "hello";
199 EXPECT_TRUE(log_message_was_called());
200 EXPECT_EQ(MOJO_LOG_LEVEL_INFO, last_log_level());
201 EXPECT_EQ(ExpectedLogMessage(__LINE__ - 3, "hello"), last_message());
202
203 ResetMockLogger();
204
205 MOJO_LAZY_LOG_STREAM(ERROR, true) << "hi " << 123;
206 EXPECT_TRUE(log_message_was_called());
207 EXPECT_EQ(MOJO_LOG_LEVEL_ERROR, last_log_level());
208 EXPECT_EQ(ExpectedLogMessage(__LINE__ - 3, "hi 123"), last_message());
209
210 ResetMockLogger();
211
212 MOJO_LAZY_LOG_STREAM(INFO, false) << "hello";
213 EXPECT_FALSE(log_message_was_called());
214
215 ResetMockLogger();
216
217 MOJO_LAZY_LOG_STREAM(FATAL, false) << "hello";
218 EXPECT_FALSE(log_message_was_called());
219
220 ResetMockLogger();
221
222 PtrToMemberHelper helper;
223 helper.member = 1;
224 int PtrToMemberHelper::*member_ptr = &PtrToMemberHelper::member;
225
226 // This probably fails to compile if we forget to parenthesize the condition
227 // in the macro (.* has lower precedence than !, which can't apply to
228 // |helper|).
229 MOJO_LAZY_LOG_STREAM(ERROR, helper.*member_ptr == 1) << "hello";
230 EXPECT_TRUE(log_message_was_called());
231
232 ResetMockLogger();
233
234 MOJO_LAZY_LOG_STREAM(WARNING, helper.*member_ptr == 0) << "hello";
235 EXPECT_FALSE(log_message_was_called());
236 }
237
TEST_F(LoggingTest,ShouldLog)238 TEST_F(LoggingTest, ShouldLog) {
239 // We start at |MOJO_LOG_LEVEL_INFO|.
240 EXPECT_FALSE(MOJO_SHOULD_LOG(VERBOSE));
241 EXPECT_TRUE(MOJO_SHOULD_LOG(INFO));
242 EXPECT_TRUE(MOJO_SHOULD_LOG(WARNING));
243 EXPECT_TRUE(MOJO_SHOULD_LOG(ERROR));
244 EXPECT_TRUE(MOJO_SHOULD_LOG(FATAL));
245
246 Environment::GetDefaultLogger()->SetMinimumLogLevel(MOJO_LOG_LEVEL_ERROR);
247 EXPECT_FALSE(MOJO_SHOULD_LOG(VERBOSE));
248 EXPECT_FALSE(MOJO_SHOULD_LOG(INFO));
249 EXPECT_FALSE(MOJO_SHOULD_LOG(WARNING));
250 EXPECT_TRUE(MOJO_SHOULD_LOG(ERROR));
251 EXPECT_TRUE(MOJO_SHOULD_LOG(FATAL));
252
253 Environment::GetDefaultLogger()->SetMinimumLogLevel(MOJO_LOG_LEVEL_VERBOSE-1);
254 EXPECT_TRUE(MOJO_SHOULD_LOG(VERBOSE));
255 EXPECT_TRUE(MOJO_SHOULD_LOG(INFO));
256 EXPECT_TRUE(MOJO_SHOULD_LOG(WARNING));
257 EXPECT_TRUE(MOJO_SHOULD_LOG(ERROR));
258 EXPECT_TRUE(MOJO_SHOULD_LOG(FATAL));
259 }
260
TEST_F(LoggingTest,Log)261 TEST_F(LoggingTest, Log) {
262 // We start at |MOJO_LOG_LEVEL_INFO|.
263 MOJO_LOG(VERBOSE) << "hello";
264 EXPECT_FALSE(log_message_was_called());
265
266 ResetMockLogger();
267
268 MOJO_LOG(INFO) << "hello";
269 EXPECT_TRUE(log_message_was_called());
270 EXPECT_EQ(MOJO_LOG_LEVEL_INFO, last_log_level());
271 EXPECT_EQ(ExpectedLogMessage(__LINE__ - 3, "hello"), last_message());
272
273 ResetMockLogger();
274
275 MOJO_LOG(ERROR) << "hello";
276 EXPECT_TRUE(log_message_was_called());
277 EXPECT_EQ(MOJO_LOG_LEVEL_ERROR, last_log_level());
278 EXPECT_EQ(ExpectedLogMessage(__LINE__ - 3, "hello"), last_message());
279
280 ResetMockLogger();
281
282 Environment::GetDefaultLogger()->SetMinimumLogLevel(MOJO_LOG_LEVEL_ERROR);
283
284 MOJO_LOG(VERBOSE) << "hello";
285 EXPECT_FALSE(log_message_was_called());
286
287 ResetMockLogger();
288
289 MOJO_LOG(INFO) << "hello";
290 EXPECT_FALSE(log_message_was_called());
291
292 ResetMockLogger();
293
294 MOJO_LOG(ERROR) << "hello";
295 EXPECT_TRUE(log_message_was_called());
296 EXPECT_EQ(MOJO_LOG_LEVEL_ERROR, last_log_level());
297 EXPECT_EQ(ExpectedLogMessage(__LINE__ - 3, "hello"), last_message());
298 }
299
TEST_F(LoggingTest,LogIf)300 TEST_F(LoggingTest, LogIf) {
301 // We start at |MOJO_LOG_LEVEL_INFO|.
302 MOJO_LOG_IF(VERBOSE, true) << "hello";
303 EXPECT_FALSE(log_message_was_called());
304
305 ResetMockLogger();
306
307 MOJO_LOG_IF(VERBOSE, false) << "hello";
308 EXPECT_FALSE(log_message_was_called());
309
310 ResetMockLogger();
311 Environment::GetDefaultLogger()->SetMinimumLogLevel(MOJO_LOG_LEVEL_ERROR);
312
313 bool x = true;
314 // Also try to make sure that we parenthesize the condition properly.
315 MOJO_LOG_IF(INFO, false || x) << "hello";
316 EXPECT_FALSE(log_message_was_called());
317
318 ResetMockLogger();
319
320 MOJO_LOG_IF(INFO, 0 != 1) << "hello";
321 EXPECT_FALSE(log_message_was_called());
322
323 ResetMockLogger();
324
325 MOJO_LOG_IF(WARNING, 1 + 1 == 2) << "hello";
326 EXPECT_FALSE(log_message_was_called());
327
328 ResetMockLogger();
329
330 MOJO_LOG_IF(ERROR, 1 * 2 == 2) << "hello";
331 EXPECT_TRUE(log_message_was_called());
332 EXPECT_EQ(MOJO_LOG_LEVEL_ERROR, last_log_level());
333 EXPECT_EQ(ExpectedLogMessage(__LINE__ - 3, "hello"), last_message());
334
335 ResetMockLogger();
336
337 MOJO_LOG_IF(FATAL, 1 * 2 == 3) << "hello";
338 EXPECT_FALSE(log_message_was_called());
339
340 ResetMockLogger();
341
342 // |MOJO_LOG_IF()| shouldn't evaluate its condition if the level is below the
343 // minimum.
344 MOJO_LOG_IF(INFO, NotCalledCondition()) << "hello";
345 EXPECT_FALSE(not_called_condition_was_called());
346 EXPECT_FALSE(log_message_was_called());
347 }
348
TEST_F(LoggingTest,Check)349 TEST_F(LoggingTest, Check) {
350 MOJO_CHECK(true) << "hello";
351 EXPECT_FALSE(log_message_was_called());
352
353 ResetMockLogger();
354
355 PtrToMemberHelper helper;
356 helper.member = 0;
357 int PtrToMemberHelper::*member_ptr = &PtrToMemberHelper::member;
358
359 // Also try to make sure that we parenthesize the condition properly.
360 MOJO_CHECK(helper.*member_ptr == 1) << "hello";
361 EXPECT_TRUE(log_message_was_called());
362 EXPECT_EQ(MOJO_LOG_LEVEL_FATAL, last_log_level());
363 // Different compilers have different ideas about the line number of a split
364 // line.
365 int line = __LINE__;
366 EXPECT_EQ(ExpectedLogMessage(line - 5,
367 "Check failed: helper.*member_ptr == 1. hello"),
368 last_message());
369
370 ResetMockLogger();
371
372 // Also test a "naked" |MOJO_CHECK()|s.
373 MOJO_CHECK(1 + 2 == 3);
374 EXPECT_FALSE(log_message_was_called());
375 }
376
TEST_F(LoggingTest,Dlog)377 TEST_F(LoggingTest, Dlog) {
378 // We start at |MOJO_LOG_LEVEL_INFO|.
379 MOJO_DLOG(VERBOSE) << "hello";
380 EXPECT_FALSE(log_message_was_called());
381
382 ResetMockLogger();
383
384 MOJO_DLOG(INFO) << "hello";
385 #ifdef NDEBUG
386 EXPECT_FALSE(log_message_was_called());
387 #else
388 EXPECT_TRUE(log_message_was_called());
389 EXPECT_EQ(MOJO_LOG_LEVEL_INFO, last_log_level());
390 EXPECT_EQ(ExpectedLogMessage(__LINE__ - 6, "hello"), last_message());
391 #endif
392 }
393
TEST_F(LoggingTest,DlogIf)394 TEST_F(LoggingTest, DlogIf) {
395 // We start at |MOJO_LOG_LEVEL_INFO|. It shouldn't evaluate the condition in
396 // this case.
397 MOJO_DLOG_IF(VERBOSE, NotCalledCondition()) << "hello";
398 EXPECT_FALSE(not_called_condition_was_called());
399 EXPECT_FALSE(log_message_was_called());
400
401 ResetMockLogger();
402
403 MOJO_DLOG_IF(INFO, 1 == 0) << "hello";
404 EXPECT_FALSE(log_message_was_called());
405
406 ResetMockLogger();
407
408 MOJO_DLOG_IF(INFO, 1 == 1) << "hello";
409 #ifdef NDEBUG
410 EXPECT_FALSE(log_message_was_called());
411 #else
412 EXPECT_TRUE(log_message_was_called());
413 EXPECT_EQ(MOJO_LOG_LEVEL_INFO, last_log_level());
414 EXPECT_EQ(ExpectedLogMessage(__LINE__ - 6, "hello"), last_message());
415 #endif
416
417 ResetMockLogger();
418
419 // |MOJO_DLOG_IF()| shouldn't compile its condition for non-debug builds.
420 #ifndef NDEBUG
421 bool debug_only = true;
422 #endif
423 MOJO_DLOG_IF(WARNING, debug_only) << "hello";
424 #ifdef NDEBUG
425 EXPECT_FALSE(log_message_was_called());
426 #else
427 EXPECT_TRUE(log_message_was_called());
428 EXPECT_EQ(MOJO_LOG_LEVEL_WARNING, last_log_level());
429 EXPECT_EQ(ExpectedLogMessage(__LINE__ - 6, "hello"), last_message());
430 #endif
431 }
432
TEST_F(LoggingTest,Dcheck)433 TEST_F(LoggingTest, Dcheck) {
434 MOJO_DCHECK(true);
435 EXPECT_FALSE(log_message_was_called());
436
437 ResetMockLogger();
438
439 MOJO_DCHECK(true) << "hello";
440 EXPECT_FALSE(log_message_was_called());
441
442 ResetMockLogger();
443
444 // |MOJO_DCHECK()| should compile (but not evaluate) its condition even for
445 // non-debug builds. (Hopefully, we'll get an unused variable error if it
446 // fails to compile the condition.)
447 bool was_called = false;
448 MOJO_DCHECK(DcheckTestHelper(&was_called)) << "hello";
449 #ifdef NDEBUG
450 EXPECT_FALSE(was_called);
451 EXPECT_FALSE(log_message_was_called());
452 #else
453 EXPECT_TRUE(was_called);
454 EXPECT_TRUE(log_message_was_called());
455 EXPECT_EQ(MOJO_LOG_LEVEL_FATAL, last_log_level());
456 // Different compilers have different ideas about the line number of a split
457 // line.
458 int line = __LINE__;
459 EXPECT_EQ(
460 ExpectedLogMessage(line - 10,
461 "Check failed: DcheckTestHelper(&was_called). hello"),
462 last_message());
463 #endif
464
465 ResetMockLogger();
466
467 // Also try to make sure that we parenthesize the condition properly.
468 bool x = true;
469 MOJO_DCHECK(false || x) << "hello";
470 EXPECT_FALSE(log_message_was_called());
471 }
472
473 } // namespace
474 } // namespace mojo
475