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
19namespace mojo {
20namespace {
21
22class PtrToMemberHelper {
23 public:
24  int member;
25};
26
27bool DcheckTestHelper(bool* was_called) {
28  *was_called = true;
29  return false;
30}
31
32class LoggingTest : public testing::Test {
33 public:
34  LoggingTest() : environment_(NULL, &kMockLogger) {
35    minimum_log_level_ = MOJO_LOG_LEVEL_INFO;
36    ResetMockLogger();
37  }
38  virtual ~LoggingTest() {}
39
40 protected:
41  // Note: Does not reset |minimum_log_level_|.
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.
49  static bool NotCalledCondition() {
50    not_called_condition_was_called_ = true;
51    return false;
52  }
53
54  static bool log_message_was_called() { return log_message_was_called_; }
55  static MojoLogLevel last_log_level() { return last_log_level_; }
56  static const std::string& last_message() { return last_message_; }
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).
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
71  static MojoLogLevel MockGetMinimumLogLevel() {
72    return minimum_log_level_;
73  }
74
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
92const MojoLogger LoggingTest::kMockLogger = {
93  &LoggingTest::MockLogMessage,
94  &LoggingTest::MockGetMinimumLogLevel,
95  &LoggingTest::MockSetMinimumLogLevel
96};
97
98// static
99MojoLogLevel LoggingTest::minimum_log_level_ = MOJO_LOG_LEVEL_INFO;
100
101// static
102bool LoggingTest::log_message_was_called_ = MOJO_LOG_LEVEL_INFO;
103
104// static
105MojoLogLevel LoggingTest::last_log_level_ = MOJO_LOG_LEVEL_INFO;
106
107// static
108std::string LoggingTest::last_message_;
109
110// static
111bool LoggingTest::not_called_condition_was_called_ = false;
112
113std::string ExpectedLogMessage(int line, const char* message) {
114  std::ostringstream s;
115  s << OUR_FILENAME "(" << line << "): " << message;
116  return s.str();
117}
118
119TEST_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
183TEST_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
197TEST_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
238TEST_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
261TEST_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
300TEST_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
349TEST_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
377TEST_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
394TEST_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
433TEST_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