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