Add license information for all source code.
[platform/upstream/glog.git] / src / logging_unittest.cc
1 // Copyright (c) 2002, Google Inc.
2 // All rights reserved.
3 //
4 // Redistribution and use in source and binary forms, with or without
5 // modification, are permitted provided that the following conditions are
6 // met:
7 //
8 //     * Redistributions of source code must retain the above copyright
9 // notice, this list of conditions and the following disclaimer.
10 //     * Redistributions in binary form must reproduce the above
11 // copyright notice, this list of conditions and the following disclaimer
12 // in the documentation and/or other materials provided with the
13 // distribution.
14 //     * Neither the name of Google Inc. nor the names of its
15 // contributors may be used to endorse or promote products derived from
16 // this software without specific prior written permission.
17 //
18 // THIS SOFTWARE IS PROVIDED BY THE COPYRIGHT HOLDERS AND CONTRIBUTORS
19 // "AS IS" AND ANY EXPRESS OR IMPLIED WARRANTIES, INCLUDING, BUT NOT
20 // LIMITED TO, THE IMPLIED WARRANTIES OF MERCHANTABILITY AND FITNESS FOR
21 // A PARTICULAR PURPOSE ARE DISCLAIMED. IN NO EVENT SHALL THE COPYRIGHT
22 // OWNER OR CONTRIBUTORS BE LIABLE FOR ANY DIRECT, INDIRECT, INCIDENTAL,
23 // SPECIAL, EXEMPLARY, OR CONSEQUENTIAL DAMAGES (INCLUDING, BUT NOT
24 // LIMITED TO, PROCUREMENT OF SUBSTITUTE GOODS OR SERVICES; LOSS OF USE,
25 // DATA, OR PROFITS; OR BUSINESS INTERRUPTION) HOWEVER CAUSED AND ON ANY
26 // THEORY OF LIABILITY, WHETHER IN CONTRACT, STRICT LIABILITY, OR TORT
27 // (INCLUDING NEGLIGENCE OR OTHERWISE) ARISING IN ANY WAY OUT OF THE USE
28 // OF THIS SOFTWARE, EVEN IF ADVISED OF THE POSSIBILITY OF SUCH DAMAGE.
29 //
30 // Author: Ray Sidney
31
32 #include "config_for_unittests.h"
33 #include "utilities.h"
34
35 #include <fcntl.h>
36 #ifdef HAVE_GLOB_H
37 # include <glob.h>
38 #endif
39 #include <sys/stat.h>
40 #ifdef HAVE_UNISTD_H
41 # include <unistd.h>
42 #endif
43
44 #include <iomanip>
45 #include <iostream>
46 #include <queue>
47 #include <sstream>
48 #include <string>
49 #include <vector>
50
51 #include "base/commandlineflags.h"
52 #include "glog/logging.h"
53 #include "glog/raw_logging.h"
54 #include "googletest.h"
55
56 DECLARE_string(log_backtrace_at);  // logging.cc
57
58 #ifdef HAVE_LIB_GMOCK
59 #include <gmock/gmock.h>
60 #include "mock-log.h"
61 // Introduce several symbols from gmock.
62 using testing::_;
63 using testing::AnyNumber;
64 using testing::HasSubstr;
65 using testing::AllOf;
66 using testing::StrNe;
67 using testing::StrictMock;
68 using testing::InitGoogleMock;
69 using GOOGLE_NAMESPACE::glog_testing::ScopedMockLog;
70 #endif
71
72 using namespace std;
73 using namespace GOOGLE_NAMESPACE;
74
75 // Some non-advertised functions that we want to test or use.
76 _START_GOOGLE_NAMESPACE_
77 namespace base {
78 namespace internal {
79 bool GetExitOnDFatal();
80 void SetExitOnDFatal(bool value);
81 }  // namespace internal
82 }  // namespace base
83 _END_GOOGLE_NAMESPACE_
84
85 static void TestLogging(bool check_counts);
86 static void TestRawLogging();
87 static void LogWithLevels(int v, int severity, bool err, bool alsoerr);
88 static void TestLoggingLevels();
89 static void TestLogString();
90 static void TestLogSink();
91 static void TestLogToString();
92 static void TestLogSinkWaitTillSent();
93 static void TestCHECK();
94 static void TestDCHECK();
95 static void TestSTREQ();
96 static void TestBasename();
97 static void TestSymlink();
98 static void TestExtension();
99 static void TestWrapper();
100 static void TestErrno();
101 static void TestTruncate();
102
103 static int x = -1;
104 static void BM_Check1(int n) {
105   while (n-- > 0) {
106     CHECK_GE(n, x);
107     CHECK_GE(n, x);
108     CHECK_GE(n, x);
109     CHECK_GE(n, x);
110     CHECK_GE(n, x);
111     CHECK_GE(n, x);
112     CHECK_GE(n, x);
113     CHECK_GE(n, x);
114   }
115 }
116 BENCHMARK(BM_Check1);
117
118 static void CheckFailure(int a, int b, const char* file, int line, const char* msg);
119 static void BM_Check3(int n) {
120   while (n-- > 0) {
121     if (n < x) CheckFailure(n, x, __FILE__, __LINE__, "n < x");
122     if (n < x) CheckFailure(n, x, __FILE__, __LINE__, "n < x");
123     if (n < x) CheckFailure(n, x, __FILE__, __LINE__, "n < x");
124     if (n < x) CheckFailure(n, x, __FILE__, __LINE__, "n < x");
125     if (n < x) CheckFailure(n, x, __FILE__, __LINE__, "n < x");
126     if (n < x) CheckFailure(n, x, __FILE__, __LINE__, "n < x");
127     if (n < x) CheckFailure(n, x, __FILE__, __LINE__, "n < x");
128     if (n < x) CheckFailure(n, x, __FILE__, __LINE__, "n < x");
129   }
130 }
131 BENCHMARK(BM_Check3);
132
133 static void BM_Check2(int n) {
134   if (n == 17) {
135     x = 5;
136   }
137   while (n-- > 0) {
138     CHECK(n >= x);
139     CHECK(n >= x);
140     CHECK(n >= x);
141     CHECK(n >= x);
142     CHECK(n >= x);
143     CHECK(n >= x);
144     CHECK(n >= x);
145     CHECK(n >= x);
146   }
147 }
148 BENCHMARK(BM_Check2);
149
150 static void CheckFailure(int a, int b, const char* file, int line, const char* msg) {
151 }
152
153 static void BM_logspeed(int n) {
154   while (n-- > 0) {
155     LOG(INFO) << "test message";
156   }
157 }
158 BENCHMARK(BM_logspeed);
159
160 static void BM_vlog(int n) {
161   while (n-- > 0) {
162     VLOG(1) << "test message";
163   }
164 }
165 BENCHMARK(BM_vlog);
166
167 int main(int argc, char **argv) {
168   // Test some basics before InitGoogleLogging:
169   CaptureTestStderr();
170   LogWithLevels(FLAGS_v, FLAGS_stderrthreshold,
171                 FLAGS_logtostderr, FLAGS_alsologtostderr);
172   LogWithLevels(0, 0, 0, 0);  // simulate "before global c-tors"
173   const string early_stderr = GetCapturedTestStderr();
174
175   InitGoogleLogging(argv[0]);
176
177   RunSpecifiedBenchmarks();
178
179   FLAGS_logtostderr = true;
180
181   InitGoogleTest(&argc, argv);
182 #ifdef HAVE_LIB_GMOCK
183   InitGoogleMock(&argc, argv);
184 #endif
185
186   // so that death tests run before we use threads
187   CHECK_EQ(RUN_ALL_TESTS(), 0);
188
189   CaptureTestStderr();
190
191   // re-emit early_stderr
192   LogMessage("dummy", LogMessage::kNoLogPrefix, INFO).stream() << early_stderr;
193
194   TestLogging(true);
195   TestRawLogging();
196   TestLoggingLevels();
197   TestLogString();
198   TestLogSink();
199   TestLogToString();
200   TestLogSinkWaitTillSent();
201   TestCHECK();
202   TestDCHECK();
203   TestSTREQ();
204
205   // TODO: The golden test portion of this test is very flakey.
206   EXPECT_TRUE(
207       MungeAndDiffTestStderr(FLAGS_test_srcdir + "/src/logging_unittest.err"));
208
209   FLAGS_logtostderr = false;
210
211   TestBasename();
212   TestSymlink();
213   TestExtension();
214   TestWrapper();
215   TestErrno();
216   TestTruncate();
217
218   fprintf(stdout, "PASS\n");
219   return 0;
220 }
221
222 void TestLogging(bool check_counts) {
223   int64 base_num_infos   = LogMessage::num_messages(INFO);
224   int64 base_num_warning = LogMessage::num_messages(WARNING);
225   int64 base_num_errors  = LogMessage::num_messages(ERROR);
226
227   LOG(INFO) << string("foo ") << "bar " << 10 << ' ' << 3.4;
228   for ( int i = 0; i < 10; ++i ) {
229     int old_errno = errno;
230     errno = i;
231     PLOG_EVERY_N(ERROR, 2) << "Plog every 2, iteration " << COUNTER;
232     errno = old_errno;
233
234     LOG_EVERY_N(ERROR, 3) << "Log every 3, iteration " << COUNTER << endl;
235     LOG_EVERY_N(ERROR, 4) << "Log every 4, iteration " << COUNTER << endl;
236
237     LOG_IF_EVERY_N(WARNING, true, 5) << "Log if every 5, iteration " << COUNTER;
238     LOG_IF_EVERY_N(WARNING, false, 3)
239         << "Log if every 3, iteration " << COUNTER;
240     LOG_IF_EVERY_N(INFO, true, 1) << "Log if every 1, iteration " << COUNTER;
241     LOG_IF_EVERY_N(ERROR, (i < 3), 2)
242         << "Log if less than 3 every 2, iteration " << COUNTER;
243   }
244   LOG_IF(WARNING, true) << "log_if this";
245   LOG_IF(WARNING, false) << "don't log_if this";
246
247   char s[] = "array";
248   LOG(INFO) << s;
249   const char const_s[] = "const array";
250   LOG(INFO) << const_s;
251   int j = 1000;
252   LOG(ERROR) << string("foo") << ' '<< j << ' ' << setw(10) << j << " "
253              << setw(1) << hex << j;
254
255   LogMessage("foo", LogMessage::kNoLogPrefix, INFO).stream() << "no prefix";
256
257   if (check_counts) {
258     CHECK_EQ(base_num_infos   + 14, LogMessage::num_messages(INFO));
259     CHECK_EQ(base_num_warning + 3,  LogMessage::num_messages(WARNING));
260     CHECK_EQ(base_num_errors  + 15, LogMessage::num_messages(ERROR));
261   }
262 }
263
264 static void NoAllocNewHook() {
265   CHECK(false) << "unexpected new";
266 }
267
268 struct NewHook {
269   NewHook() {
270     g_new_hook = &NoAllocNewHook;
271   }
272   ~NewHook() {
273     g_new_hook = NULL;
274   }
275 };
276
277 TEST(DeathNoAllocNewHook, logging) {
278   // tests that NewHook used below works
279   NewHook new_hook;
280   ASSERT_DEATH({
281     new int;
282   }, "unexpected new");
283 }
284
285 void TestRawLogging() {
286   string* foo = new string("foo ");
287   string huge_str(50000, 'a');
288
289   FlagSaver saver;
290
291   // Check that RAW loggging does not use mallocs.
292   NewHook new_hook;
293
294   RAW_LOG(INFO, "%s%s%d%c%f", foo->c_str(), "bar ", 10, ' ', 3.4);
295   char s[] = "array";
296   RAW_LOG(WARNING, "%s", s);
297   const char const_s[] = "const array";
298   RAW_LOG(INFO, "%s", const_s);
299   void* p = reinterpret_cast<void*>(0x12345678);
300   RAW_LOG(INFO, "ptr %p", p);
301   p = NULL;
302   RAW_LOG(INFO, "ptr %p", p);
303   int j = 1000;
304   RAW_LOG(ERROR, "%s%d%c%010d%s%1x", foo->c_str(), j, ' ', j, " ", j);
305   RAW_VLOG(0, "foo %d", j);
306
307 #ifdef NDEBUG
308   RAW_LOG(INFO, "foo %d", j);  // so that have same stderr to compare
309 #else
310   RAW_DLOG(INFO, "foo %d", j);  // test RAW_DLOG in debug mode
311 #endif
312
313   // test how long messages are chopped:
314   RAW_LOG(WARNING, "Huge string: %s", huge_str.c_str());
315   RAW_VLOG(0, "Huge string: %s", huge_str.c_str());
316
317   FLAGS_v = 0;
318   RAW_LOG(INFO, "log");
319   RAW_VLOG(0, "vlog 0 on");
320   RAW_VLOG(1, "vlog 1 off");
321   RAW_VLOG(2, "vlog 2 off");
322   RAW_VLOG(3, "vlog 3 off");
323   FLAGS_v = 2;
324   RAW_LOG(INFO, "log");
325   RAW_VLOG(1, "vlog 1 on");
326   RAW_VLOG(2, "vlog 2 on");
327   RAW_VLOG(3, "vlog 3 off");
328
329 #ifdef NDEBUG
330   RAW_DCHECK(1 == 2, " RAW_DCHECK's shouldn't be compiled in normal mode");
331 #endif
332
333   RAW_CHECK(1 == 1, "should be ok");
334   RAW_DCHECK(true, "should be ok");
335
336   delete foo;
337 }
338
339 void LogWithLevels(int v, int severity, bool err, bool alsoerr) {
340   RAW_LOG(INFO,
341           "Test: v=%d stderrthreshold=%d logtostderr=%d alsologtostderr=%d",
342           v, severity, err, alsoerr);
343
344   FlagSaver saver;
345
346   FLAGS_v = v;
347   FLAGS_stderrthreshold = severity;
348   FLAGS_logtostderr = err;
349   FLAGS_alsologtostderr = alsoerr;
350
351   RAW_VLOG(-1, "vlog -1");
352   RAW_VLOG(0, "vlog 0");
353   RAW_VLOG(1, "vlog 1");
354   RAW_LOG(INFO, "log info");
355   RAW_LOG(WARNING, "log warning");
356   RAW_LOG(ERROR, "log error");
357
358   VLOG(-1) << "vlog -1";
359   VLOG(0) << "vlog 0";
360   VLOG(1) << "vlog 1";
361   LOG(INFO) << "log info";
362   LOG(WARNING) << "log warning";
363   LOG(ERROR) << "log error";
364
365   VLOG_IF(-1, true) << "vlog_if -1";
366   VLOG_IF(-1, false) << "don't vlog_if -1";
367   VLOG_IF(0, true) << "vlog_if 0";
368   VLOG_IF(0, false) << "don't vlog_if 0";
369   VLOG_IF(1, true) << "vlog_if 1";
370   VLOG_IF(1, false) << "don't vlog_if 1";
371   LOG_IF(INFO, true) << "log_if info";
372   LOG_IF(INFO, false) << "don't log_if info";
373   LOG_IF(WARNING, true) << "log_if warning";
374   LOG_IF(WARNING, false) << "don't log_if warning";
375   LOG_IF(ERROR, true) << "log_if error";
376   LOG_IF(ERROR, false) << "don't log_if error";
377
378   int c;
379   c = 1; VLOG_IF(100, c -= 2) << "vlog_if 100 expr"; EXPECT_EQ(c, -1);
380   c = 1; VLOG_IF(0, c -= 2) << "vlog_if 0 expr"; EXPECT_EQ(c, -1);
381   c = 1; LOG_IF(INFO, c -= 2) << "log_if info expr"; EXPECT_EQ(c, -1);
382   c = 1; LOG_IF(ERROR, c -= 2) << "log_if error expr"; EXPECT_EQ(c, -1);
383   c = 2; VLOG_IF(0, c -= 2) << "don't vlog_if 0 expr"; EXPECT_EQ(c, 0);
384   c = 2; LOG_IF(ERROR, c -= 2) << "don't log_if error expr"; EXPECT_EQ(c, 0);
385
386   c = 3; LOG_IF_EVERY_N(INFO, c -= 4, 1) << "log_if info every 1 expr";
387   EXPECT_EQ(c, -1);
388   c = 3; LOG_IF_EVERY_N(ERROR, c -= 4, 1) << "log_if error every 1 expr";
389   EXPECT_EQ(c, -1);
390   c = 4; LOG_IF_EVERY_N(ERROR, c -= 4, 3) << "don't log_if info every 3 expr";
391   EXPECT_EQ(c, 0);
392   c = 4; LOG_IF_EVERY_N(ERROR, c -= 4, 3) << "don't log_if error every 3 expr";
393   EXPECT_EQ(c, 0);
394   c = 5; VLOG_IF_EVERY_N(0, c -= 4, 1) << "vlog_if 0 every 1 expr";
395   EXPECT_EQ(c, 1);
396   c = 5; VLOG_IF_EVERY_N(100, c -= 4, 3) << "vlog_if 100 every 3 expr";
397   EXPECT_EQ(c, 1);
398   c = 6; VLOG_IF_EVERY_N(0, c -= 6, 1) << "don't vlog_if 0 every 1 expr";
399   EXPECT_EQ(c, 0);
400   c = 6; VLOG_IF_EVERY_N(100, c -= 6, 3) << "don't vlog_if 100 every 1 expr";
401   EXPECT_EQ(c, 0);
402 }
403
404 void TestLoggingLevels() {
405   LogWithLevels(0, INFO, false, false);
406   LogWithLevels(1, INFO, false, false);
407   LogWithLevels(-1, INFO, false, false);
408   LogWithLevels(0, WARNING, false, false);
409   LogWithLevels(0, ERROR, false, false);
410   LogWithLevels(0, FATAL, false, false);
411   LogWithLevels(0, FATAL, true, false);
412   LogWithLevels(0, FATAL, false, true);
413   LogWithLevels(1, WARNING, false, false);
414   LogWithLevels(1, FATAL, false, true);
415 }
416
417 TEST(DeathRawCHECK, logging) {
418   ASSERT_DEATH(RAW_CHECK(false, "failure 1"),
419                "RAW: Check false failed: failure 1");
420   ASSERT_DEBUG_DEATH(RAW_DCHECK(1 == 2, "failure 2"),
421                "RAW: Check 1 == 2 failed: failure 2");
422 }
423
424 void TestLogString() {
425   vector<string> errors;
426   vector<string> *no_errors = NULL;
427
428   LOG_STRING(INFO, &errors) << "LOG_STRING: " << "collected info";
429   LOG_STRING(WARNING, &errors) << "LOG_STRING: " << "collected warning";
430   LOG_STRING(ERROR, &errors) << "LOG_STRING: " << "collected error";
431
432   LOG_STRING(INFO, no_errors) << "LOG_STRING: " << "reported info";
433   LOG_STRING(WARNING, no_errors) << "LOG_STRING: " << "reported warning";
434   LOG_STRING(ERROR, NULL) << "LOG_STRING: " << "reported error";
435
436   for (size_t i = 0; i < errors.size(); ++i) {
437     LOG(INFO) << "Captured by LOG_STRING:  " << errors[i];
438   }
439 }
440
441 void TestLogToString() {
442   string error;
443   string* no_error = NULL;
444
445   LOG_TO_STRING(INFO, &error) << "LOG_TO_STRING: " << "collected info";
446   LOG(INFO) << "Captured by LOG_TO_STRING:  " << error;
447   LOG_TO_STRING(WARNING, &error) << "LOG_TO_STRING: " << "collected warning";
448   LOG(INFO) << "Captured by LOG_TO_STRING:  " << error;
449   LOG_TO_STRING(ERROR, &error) << "LOG_TO_STRING: " << "collected error";
450   LOG(INFO) << "Captured by LOG_TO_STRING:  " << error;
451
452   LOG_TO_STRING(INFO, no_error) << "LOG_TO_STRING: " << "reported info";
453   LOG_TO_STRING(WARNING, no_error) << "LOG_TO_STRING: " << "reported warning";
454   LOG_TO_STRING(ERROR, NULL) << "LOG_TO_STRING: " << "reported error";
455 }
456
457 class TestLogSinkImpl : public LogSink {
458  public:
459   vector<string> errors;
460   virtual void send(LogSeverity severity, const char* full_filename,
461                     const char* base_filename, int line,
462                     const struct tm* tm_time,
463                     const char* message, size_t message_len) {
464     errors.push_back(
465       ToString(severity, base_filename, line, tm_time, message, message_len));
466   }
467 };
468
469 void TestLogSink() {
470   TestLogSinkImpl sink;
471   LogSink *no_sink = NULL;
472
473   LOG_TO_SINK(&sink, INFO) << "LOG_TO_SINK: " << "collected info";
474   LOG_TO_SINK(&sink, WARNING) << "LOG_TO_SINK: " << "collected warning";
475   LOG_TO_SINK(&sink, ERROR) << "LOG_TO_SINK: " << "collected error";
476
477   LOG_TO_SINK(no_sink, INFO) << "LOG_TO_SINK: " << "reported info";
478   LOG_TO_SINK(no_sink, WARNING) << "LOG_TO_SINK: " << "reported warning";
479   LOG_TO_SINK(NULL, ERROR) << "LOG_TO_SINK: " << "reported error";
480
481   LOG_TO_SINK_BUT_NOT_TO_LOGFILE(&sink, INFO)
482       << "LOG_TO_SINK_BUT_NOT_TO_LOGFILE: " << "collected info";
483   LOG_TO_SINK_BUT_NOT_TO_LOGFILE(&sink, WARNING)
484       << "LOG_TO_SINK_BUT_NOT_TO_LOGFILE: " << "collected warning";
485   LOG_TO_SINK_BUT_NOT_TO_LOGFILE(&sink, ERROR)
486       << "LOG_TO_SINK_BUT_NOT_TO_LOGFILE: " << "collected error";
487
488   LOG_TO_SINK_BUT_NOT_TO_LOGFILE(no_sink, INFO)
489       << "LOG_TO_SINK_BUT_NOT_TO_LOGFILE: " << "thrashed info";
490   LOG_TO_SINK_BUT_NOT_TO_LOGFILE(no_sink, WARNING)
491       << "LOG_TO_SINK_BUT_NOT_TO_LOGFILE: " << "thrashed warning";
492   LOG_TO_SINK_BUT_NOT_TO_LOGFILE(NULL, ERROR)
493       << "LOG_TO_SINK_BUT_NOT_TO_LOGFILE: " << "thrashed error";
494
495   LOG(INFO) << "Captured by LOG_TO_SINK:";
496   for (size_t i = 0; i < sink.errors.size(); ++i) {
497     LogMessage("foo", LogMessage::kNoLogPrefix, INFO).stream()
498       << sink.errors[i];
499   }
500 }
501
502 // For testing using CHECK*() on anonymous enums.
503 enum {
504   CASE_A,
505   CASE_B
506 };
507
508 void TestCHECK() {
509   // Tests using CHECK*() on int values.
510   CHECK(1 == 1);
511   CHECK_EQ(1, 1);
512   CHECK_NE(1, 2);
513   CHECK_GE(1, 1);
514   CHECK_GE(2, 1);
515   CHECK_LE(1, 1);
516   CHECK_LE(1, 2);
517   CHECK_GT(2, 1);
518   CHECK_LT(1, 2);
519
520   // Tests using CHECK*() on anonymous enums.
521   // Apple's GCC doesn't like this.
522 #if !defined(OS_MACOSX)
523   CHECK_EQ(CASE_A, CASE_A);
524   CHECK_NE(CASE_A, CASE_B);
525   CHECK_GE(CASE_A, CASE_A);
526   CHECK_GE(CASE_B, CASE_A);
527   CHECK_LE(CASE_A, CASE_A);
528   CHECK_LE(CASE_A, CASE_B);
529   CHECK_GT(CASE_B, CASE_A);
530   CHECK_LT(CASE_A, CASE_B);
531 #endif
532 }
533
534 void TestDCHECK() {
535 #ifdef NDEBUG
536   DCHECK( 1 == 2 ) << " DCHECK's shouldn't be compiled in normal mode";
537 #endif
538   DCHECK( 1 == 1 );
539   DCHECK_EQ(1, 1);
540   DCHECK_NE(1, 2);
541   DCHECK_GE(1, 1);
542   DCHECK_GE(2, 1);
543   DCHECK_LE(1, 1);
544   DCHECK_LE(1, 2);
545   DCHECK_GT(2, 1);
546   DCHECK_LT(1, 2);
547 }
548
549 void TestSTREQ() {
550   CHECK_STREQ("this", "this");
551   CHECK_STREQ(NULL, NULL);
552   CHECK_STRCASEEQ("this", "tHiS");
553   CHECK_STRCASEEQ(NULL, NULL);
554   CHECK_STRNE("this", "tHiS");
555   CHECK_STRNE("this", NULL);
556   CHECK_STRCASENE("this", "that");
557   CHECK_STRCASENE(NULL, "that");
558   CHECK_STREQ((string("a")+"b").c_str(), "ab");
559   CHECK_STREQ(string("test").c_str(),
560               (string("te") + string("st")).c_str());
561 }
562
563 TEST(DeathSTREQ, logging) {
564   ASSERT_DEATH(CHECK_STREQ(NULL, "this"), "");
565   ASSERT_DEATH(CHECK_STREQ("this", "siht"), "");
566   ASSERT_DEATH(CHECK_STRCASEEQ(NULL, "siht"), "");
567   ASSERT_DEATH(CHECK_STRCASEEQ("this", "siht"), "");
568   ASSERT_DEATH(CHECK_STRNE(NULL, NULL), "");
569   ASSERT_DEATH(CHECK_STRNE("this", "this"), "");
570   ASSERT_DEATH(CHECK_STREQ((string("a")+"b").c_str(), "abc"), "");
571 }
572
573 TEST(CheckNOTNULL, Simple) {
574   int64 t;
575   void *ptr = static_cast<void *>(&t);
576   void *ref = CHECK_NOTNULL(ptr);
577   EXPECT_EQ(ptr, ref);
578   CHECK_NOTNULL(reinterpret_cast<char *>(&t));
579   CHECK_NOTNULL(reinterpret_cast<unsigned char *>(&t));
580   CHECK_NOTNULL(reinterpret_cast<int *>(&t));
581   CHECK_NOTNULL(reinterpret_cast<int64 *>(&t));
582 }
583
584 TEST(DeathCheckNN, Simple) {
585   ASSERT_DEATH(CHECK_NOTNULL(static_cast<void *>(NULL)), "");
586 }
587
588 // Get list of file names that match pattern
589 static void GetFiles(const string& pattern, vector<string>* files) {
590   files->clear();
591 #if defined(HAVE_GLOB_H)
592   glob_t g;
593   const int r = glob(pattern.c_str(), 0, NULL, &g);
594   CHECK((r == 0) || (r == GLOB_NOMATCH)) << ": error matching " << pattern;
595   for (int i = 0; i < g.gl_pathc; i++) {
596     files->push_back(string(g.gl_pathv[i]));
597   }
598   globfree(&g);
599 #elif defined(OS_WINDOWS)
600   WIN32_FIND_DATAA data;
601   HANDLE handle = FindFirstFileA(pattern.c_str(), &data);
602   size_t index = pattern.rfind('\\');
603   if (index == string::npos) {
604     LOG(FATAL) << "No directory separator.";
605   }
606   const string dirname = pattern.substr(0, index + 1);
607   if (FAILED(handle)) {
608     // Finding no files is OK.
609     return;
610   }
611   do {
612     files->push_back(dirname + data.cFileName);
613   } while (FindNextFileA(handle, &data));
614   LOG_SYSRESULT(FindClose(handle));
615 #else
616 # error There is no way to do glob.
617 #endif
618 }
619
620 // Delete files patching pattern
621 static void DeleteFiles(const string& pattern) {
622   vector<string> files;
623   GetFiles(pattern, &files);
624   for (size_t i = 0; i < files.size(); i++) {
625     CHECK(unlink(files[i].c_str()) == 0) << ": " << strerror(errno);
626   }
627 }
628
629 static void CheckFile(const string& name, const string& expected_string) {
630   vector<string> files;
631   GetFiles(name + "*", &files);
632   CHECK_EQ(files.size(), 1);
633
634   FILE* file = fopen(files[0].c_str(), "r");
635   CHECK(file != NULL) << ": could not open " << files[0];
636   char buf[1000];
637   while (fgets(buf, sizeof(buf), file) != NULL) {
638     if (strstr(buf, expected_string.c_str()) != NULL) {
639       fclose(file);
640       return;
641     }
642   }
643   fclose(file);
644   LOG(FATAL) << "Did not find " << expected_string << " in " << files[0];
645 }
646
647 static void TestBasename() {
648   fprintf(stderr, "==== Test setting log file basename\n");
649   const string dest = FLAGS_test_tmpdir + "/logging_test_basename";
650   DeleteFiles(dest + "*");
651
652   SetLogDestination(INFO, dest.c_str());
653   LOG(INFO) << "message to new base";
654   FlushLogFiles(INFO);
655
656   CheckFile(dest, "message to new base");
657
658   // Release file handle for the destination file to unlock the file in Windows.
659   LogToStderr();
660   DeleteFiles(dest + "*");
661 }
662
663 static void TestSymlink() {
664 #ifndef OS_WINDOWS
665   fprintf(stderr, "==== Test setting log file symlink\n");
666   string dest = FLAGS_test_tmpdir + "/logging_test_symlink";
667   string sym = FLAGS_test_tmpdir + "/symlinkbase";
668   DeleteFiles(dest + "*");
669   DeleteFiles(sym + "*");
670
671   SetLogSymlink(INFO, "symlinkbase");
672   SetLogDestination(INFO, dest.c_str());
673   LOG(INFO) << "message to new symlink";
674   FlushLogFiles(INFO);
675   CheckFile(sym, "message to new symlink");
676
677   DeleteFiles(dest + "*");
678   DeleteFiles(sym + "*");
679 #endif
680 }
681
682 static void TestExtension() {
683   fprintf(stderr, "==== Test setting log file extension\n");
684   string dest = FLAGS_test_tmpdir + "/logging_test_extension";
685   DeleteFiles(dest + "*");
686
687   SetLogDestination(INFO, dest.c_str());
688   SetLogFilenameExtension("specialextension");
689   LOG(INFO) << "message to new extension";
690   FlushLogFiles(INFO);
691   CheckFile(dest, "message to new extension");
692
693   // Check that file name ends with extension
694   vector<string> filenames;
695   GetFiles(dest + "*", &filenames);
696   CHECK_EQ(filenames.size(), 1);
697   CHECK(strstr(filenames[0].c_str(), "specialextension") != NULL);
698
699   // Release file handle for the destination file to unlock the file in Windows.
700   LogToStderr();
701   DeleteFiles(dest + "*");
702 }
703
704 struct MyLogger : public base::Logger {
705   string data;
706
707   virtual void Write(bool should_flush,
708                      time_t timestamp,
709                      const char* message,
710                      int length) {
711     data.append(message, length);
712   }
713
714   virtual void Flush() { }
715
716   virtual uint32 LogSize() { return data.length(); }
717 };
718
719 static void TestWrapper() {
720   fprintf(stderr, "==== Test log wrapper\n");
721
722   MyLogger my_logger;
723   base::Logger* old_logger = base::GetLogger(INFO);
724   base::SetLogger(INFO, &my_logger);
725   LOG(INFO) << "Send to wrapped logger";
726   FlushLogFiles(INFO);
727   base::SetLogger(INFO, old_logger);
728
729   CHECK(strstr(my_logger.data.c_str(), "Send to wrapped logger") != NULL);
730 }
731
732 static void TestErrno() {
733   fprintf(stderr, "==== Test errno preservation\n");
734
735   errno = ENOENT;
736   TestLogging(false);
737   CHECK_EQ(errno, ENOENT);
738 }
739
740 static void TestOneTruncate(const char *path, int64 limit, int64 keep,
741                             int64 dsize, int64 ksize, int64 expect) {
742   int fd;
743   CHECK_ERR(fd = open(path, O_RDWR | O_CREAT | O_TRUNC, 0600));
744
745   const char *discardstr = "DISCARDME!", *keepstr = "KEEPME!";
746
747   // Fill the file with the requested data; first discard data, then kept data
748   int64 written = 0;
749   while (written < dsize) {
750     int bytes = min<int64>(dsize - written, strlen(discardstr));
751     CHECK_ERR(write(fd, discardstr, bytes));
752     written += bytes;
753   }
754   written = 0;
755   while (written < ksize) {
756     int bytes = min<int64>(ksize - written, strlen(keepstr));
757     CHECK_ERR(write(fd, keepstr, bytes));
758     written += bytes;
759   }
760
761   TruncateLogFile(path, limit, keep);
762
763   // File should now be shorter
764   struct stat statbuf;
765   CHECK_ERR(fstat(fd, &statbuf));
766   CHECK_EQ(statbuf.st_size, expect);
767   CHECK_ERR(lseek(fd, 0, SEEK_SET));
768
769   // File should contain the suffix of the original file
770   int buf_size = statbuf.st_size + 1;
771   char* buf = new char[buf_size];
772   memset(buf, 0, sizeof(buf));
773   CHECK_ERR(read(fd, buf, buf_size));
774
775   const char *p = buf;
776   int64 checked = 0;
777   while (checked < expect) {
778     int bytes = min<int64>(expect - checked, strlen(keepstr));
779     CHECK(!memcmp(p, keepstr, bytes));
780     checked += bytes;
781   }
782   close(fd);
783   delete[] buf;
784 }
785
786 static void TestTruncate() {
787 #ifdef HAVE_UNISTD_H
788   fprintf(stderr, "==== Test log truncation\n");
789   string path = FLAGS_test_tmpdir + "/truncatefile";
790
791   // Test on a small file
792   TestOneTruncate(path.c_str(), 10, 10, 10, 10, 10);
793
794   // And a big file (multiple blocks to copy)
795   TestOneTruncate(path.c_str(), 2<<20, 4<<10, 3<<20, 4<<10, 4<<10);
796
797   // Check edge-case limits
798   TestOneTruncate(path.c_str(), 10, 20, 0, 20, 20);
799   TestOneTruncate(path.c_str(), 10, 0, 0, 0, 0);
800   TestOneTruncate(path.c_str(), 10, 50, 0, 10, 10);
801   TestOneTruncate(path.c_str(), 50, 100, 0, 30, 30);
802
803   // MacOSX 10.4 doesn't fail in this case.
804   // Windows doesn't have symlink.
805   // Let's just ignore this test for these cases.
806 #if !defined(OS_MACOSX) && !defined(OS_WINDOWS)
807   // Through a symlink should fail to truncate
808   string linkname = path + ".link";
809   unlink(linkname.c_str());
810   CHECK_ERR(symlink(path.c_str(), linkname.c_str()));
811   TestOneTruncate(linkname.c_str(), 10, 10, 0, 30, 30);
812 #endif
813
814   // The /proc/self path makes sense only for linux.
815 #if defined(OS_LINUX)
816   // Through an open fd symlink should work
817   int fd;
818   CHECK_ERR(fd = open(path.c_str(), O_APPEND | O_WRONLY));
819   char fdpath[64];
820   snprintf(fdpath, sizeof(fdpath), "/proc/self/fd/%d", fd);
821   TestOneTruncate(fdpath, 10, 10, 10, 10, 10);
822 #endif
823
824 #endif
825 }
826
827 _START_GOOGLE_NAMESPACE_
828 namespace glog_internal_namespace_ {
829 extern  // in logging.cc
830 bool SafeFNMatch_(const char* pattern, size_t patt_len,
831                   const char* str, size_t str_len);
832 } // namespace glog_internal_namespace_
833 using glog_internal_namespace_::SafeFNMatch_;
834 _END_GOOGLE_NAMESPACE_
835
836 static bool WrapSafeFNMatch(string pattern, string str) {
837   pattern += "abc";
838   str += "defgh";
839   return SafeFNMatch_(pattern.data(), pattern.size() - 3,
840                       str.data(), str.size() - 5);
841 }
842
843 TEST(SafeFNMatch, logging) {
844   CHECK(WrapSafeFNMatch("foo", "foo"));
845   CHECK(!WrapSafeFNMatch("foo", "bar"));
846   CHECK(!WrapSafeFNMatch("foo", "fo"));
847   CHECK(!WrapSafeFNMatch("foo", "foo2"));
848   CHECK(WrapSafeFNMatch("bar/foo.ext", "bar/foo.ext"));
849   CHECK(WrapSafeFNMatch("*ba*r/fo*o.ext*", "bar/foo.ext"));
850   CHECK(!WrapSafeFNMatch("bar/foo.ext", "bar/baz.ext"));
851   CHECK(!WrapSafeFNMatch("bar/foo.ext", "bar/foo"));
852   CHECK(!WrapSafeFNMatch("bar/foo.ext", "bar/foo.ext.zip"));
853   CHECK(WrapSafeFNMatch("ba?/*.ext", "bar/foo.ext"));
854   CHECK(WrapSafeFNMatch("ba?/*.ext", "baZ/FOO.ext"));
855   CHECK(!WrapSafeFNMatch("ba?/*.ext", "barr/foo.ext"));
856   CHECK(!WrapSafeFNMatch("ba?/*.ext", "bar/foo.ext2"));
857   CHECK(WrapSafeFNMatch("ba?/*", "bar/foo.ext2"));
858   CHECK(WrapSafeFNMatch("ba?/*", "bar/"));
859   CHECK(!WrapSafeFNMatch("ba?/?", "bar/"));
860   CHECK(!WrapSafeFNMatch("ba?/*", "bar"));
861 }
862
863 // TestWaitingLogSink will save messages here
864 // No lock: Accessed only by TestLogSinkWriter thread
865 // and after its demise by its creator.
866 static vector<string> global_messages;
867
868 // helper for TestWaitingLogSink below.
869 // Thread that does the logic of TestWaitingLogSink
870 // It's free to use LOG() itself.
871 class TestLogSinkWriter : public Thread {
872  public:
873
874   TestLogSinkWriter() : should_exit_(false) {
875     SetJoinable(true);
876     Start();
877   }
878
879   // Just buffer it (can't use LOG() here).
880   void Buffer(const string& message) {
881     mutex_.Lock();
882     RAW_LOG(INFO, "Buffering");
883     messages_.push(message);
884     mutex_.Unlock();
885     RAW_LOG(INFO, "Buffered");
886   }
887
888   // Wait for the buffer to clear (can't use LOG() here).
889   void Wait() {
890     RAW_LOG(INFO, "Waiting");
891     mutex_.Lock();
892     while (!NoWork()) {
893       mutex_.Unlock();
894       SleepForMilliseconds(1);
895       mutex_.Lock();
896     }
897     RAW_LOG(INFO, "Waited");
898     mutex_.Unlock();
899   }
900
901   // Trigger thread exit.
902   void Stop() {
903     MutexLock l(&mutex_);
904     should_exit_ = true;
905   }
906
907  private:
908
909   // helpers ---------------
910
911   // For creating a "Condition".
912   bool NoWork() { return messages_.empty(); }
913   bool HaveWork() { return !messages_.empty() || should_exit_; }
914
915   // Thread body; CAN use LOG() here!
916   virtual void Run() {
917     while (1) {
918       mutex_.Lock();
919       while (!HaveWork()) {
920         mutex_.Unlock();
921         SleepForMilliseconds(1);
922         mutex_.Lock();
923       }
924       if (should_exit_ && messages_.empty()) {
925         mutex_.Unlock();
926         break;
927       }
928       // Give the main thread time to log its message,
929       // so that we get a reliable log capture to compare to golden file.
930       // Same for the other sleep below.
931       SleepForMilliseconds(20);
932       RAW_LOG(INFO, "Sink got a messages");  // only RAW_LOG under mutex_ here
933       string message = messages_.front();
934       messages_.pop();
935       // Normally this would be some more real/involved logging logic
936       // where LOG() usage can't be eliminated,
937       // e.g. pushing the message over with an RPC:
938       int messages_left = messages_.size();
939       mutex_.Unlock();
940       SleepForMilliseconds(20);
941       // May not use LOG while holding mutex_, because Buffer()
942       // acquires mutex_, and Buffer is called from LOG(),
943       // which has its own internal mutex:
944       // LOG()->LogToSinks()->TestWaitingLogSink::send()->Buffer()
945       LOG(INFO) << "Sink is sending out a message: " << message;
946       LOG(INFO) << "Have " << messages_left << " left";
947       global_messages.push_back(message);
948     }
949   }
950
951   // data ---------------
952
953   Mutex mutex_;
954   bool should_exit_;
955   queue<string> messages_;  // messages to be logged
956 };
957
958 // A log sink that exercises WaitTillSent:
959 // it pushes data to a buffer and wakes up another thread to do the logging
960 // (that other thread can than use LOG() itself),
961 class TestWaitingLogSink : public LogSink {
962  public:
963
964   TestWaitingLogSink() {
965     tid_ = pthread_self();  // for thread-specific behavior
966     AddLogSink(this);
967   }
968   ~TestWaitingLogSink() {
969     RemoveLogSink(this);
970     writer_.Stop();
971     writer_.Join();
972   }
973
974   // (re)define LogSink interface
975
976   virtual void send(LogSeverity severity, const char* full_filename,
977                     const char* base_filename, int line,
978                     const struct tm* tm_time,
979                     const char* message, size_t message_len) {
980     // Push it to Writer thread if we are the original logging thread.
981     // Note: Something like ThreadLocalLogSink is a better choice
982     //       to do thread-specific LogSink logic for real.
983     if (pthread_equal(tid_, pthread_self())) {
984       writer_.Buffer(ToString(severity, base_filename, line,
985                               tm_time, message, message_len));
986     }
987   }
988   virtual void WaitTillSent() {
989     // Wait for Writer thread if we are the original logging thread.
990     if (pthread_equal(tid_, pthread_self()))  writer_.Wait();
991   }
992
993  private:
994
995   pthread_t tid_;
996   TestLogSinkWriter writer_;
997 };
998
999 // Check that LogSink::WaitTillSent can be used in the advertised way.
1000 // We also do golden-stderr comparison.
1001 static void TestLogSinkWaitTillSent() {
1002   { TestWaitingLogSink sink;
1003     // Sleeps give the sink threads time to do all their work,
1004     // so that we get a reliable log capture to compare to the golden file.
1005     LOG(INFO) << "Message 1";
1006     SleepForMilliseconds(60);
1007     LOG(ERROR) << "Message 2";
1008     SleepForMilliseconds(60);
1009     LOG(WARNING) << "Message 3";
1010     SleepForMilliseconds(60);
1011   }
1012   for (size_t i = 0; i < global_messages.size(); ++i) {
1013     LOG(INFO) << "Sink capture: " << global_messages[i];
1014   }
1015   CHECK_EQ(global_messages.size(), 3);
1016 }
1017
1018 TEST(Strerror, logging) {
1019   int errcode = EINTR;
1020   char *msg = strdup(strerror(errcode));
1021   int buf_size = strlen(msg) + 1;
1022   char *buf = new char[buf_size];
1023   CHECK_EQ(posix_strerror_r(errcode, NULL, 0), -1);
1024   buf[0] = 'A';
1025   CHECK_EQ(posix_strerror_r(errcode, buf, 0), -1);
1026   CHECK_EQ(buf[0], 'A');
1027   CHECK_EQ(posix_strerror_r(errcode, NULL, buf_size), -1);
1028 #if defined(OS_MACOSX) || defined(OS_FREEBSD)
1029   // MacOSX or FreeBSD considers this case is an error since there is
1030   // no enough space.
1031   CHECK_EQ(posix_strerror_r(errcode, buf, 1), -1);
1032 #else
1033   CHECK_EQ(posix_strerror_r(errcode, buf, 1), 0);
1034 #endif
1035   CHECK_STREQ(buf, "");
1036   CHECK_EQ(posix_strerror_r(errcode, buf, buf_size), 0);
1037   CHECK_STREQ(buf, msg);
1038   free(msg);
1039   delete[] buf;
1040 }
1041
1042 // Simple routines to look at the sizes of generated code for LOG(FATAL) and
1043 // CHECK(..) via objdump
1044 void MyFatal() {
1045   LOG(FATAL) << "Failed";
1046 }
1047 void MyCheck(bool a, bool b) {
1048   CHECK_EQ(a, b);
1049 }
1050
1051 #ifdef HAVE_LIB_GMOCK
1052
1053 TEST(DVLog, Basic) {
1054   ScopedMockLog log;
1055
1056 #if NDEBUG
1057   // We are expecting that nothing is logged.
1058   EXPECT_CALL(log, Log(_, _, _)).Times(0);
1059 #else
1060   EXPECT_CALL(log, Log(INFO, __FILE__, "debug log"));
1061 #endif
1062
1063   FLAGS_v = 1;
1064   DVLOG(1) << "debug log";
1065 }
1066
1067 TEST(DVLog, V0) {
1068   ScopedMockLog log;
1069
1070   // We are expecting that nothing is logged.
1071   EXPECT_CALL(log, Log(_, _, _)).Times(0);
1072
1073   FLAGS_v = 0;
1074   DVLOG(1) << "debug log";
1075 }
1076
1077 TEST(LogAtLevel, Basic) {
1078   ScopedMockLog log;
1079
1080   // The function version outputs "logging.h" as a file name.
1081   EXPECT_CALL(log, Log(WARNING, StrNe(__FILE__), "function version"));
1082   EXPECT_CALL(log, Log(INFO, __FILE__, "macro version"));
1083
1084   int severity = WARNING;
1085   LogAtLevel(severity, "function version");
1086
1087   severity = INFO;
1088   // We can use the macro version as a C++ stream.
1089   LOG_AT_LEVEL(severity) << "macro" << ' ' << "version";
1090 }
1091
1092 TEST(TestExitOnDFatal, ToBeOrNotToBe) {
1093   // Check the default setting...
1094   EXPECT_TRUE(base::internal::GetExitOnDFatal());
1095
1096   // Turn off...
1097   base::internal::SetExitOnDFatal(false);
1098   EXPECT_FALSE(base::internal::GetExitOnDFatal());
1099
1100   // We don't die.
1101   {
1102     ScopedMockLog log;
1103     //EXPECT_CALL(log, Log(_, _, _)).Times(AnyNumber());
1104     // LOG(DFATAL) has severity FATAL if debugging, but is
1105     // downgraded to ERROR if not debugging.
1106     const LogSeverity severity =
1107 #ifdef NDEBUG
1108         ERROR;
1109 #else
1110         FATAL;
1111 #endif
1112     EXPECT_CALL(log, Log(severity, __FILE__, "This should not be fatal"));
1113     LOG(DFATAL) << "This should not be fatal";
1114   }
1115
1116   // Turn back on...
1117   base::internal::SetExitOnDFatal(true);
1118   EXPECT_TRUE(base::internal::GetExitOnDFatal());
1119
1120   // Death comes on little cats' feet.
1121   EXPECT_DEBUG_DEATH({
1122       LOG(DFATAL) << "This should be fatal in debug mode";
1123     }, "This should be fatal in debug mode");
1124 }
1125
1126 #ifdef HAVE_STACKTRACE
1127
1128 static void BacktraceAtHelper() {
1129   LOG(INFO) << "Not me";
1130
1131 // The vertical spacing of the next 3 lines is significant.
1132   LOG(INFO) << "Backtrace me";
1133 }
1134 static int kBacktraceAtLine = __LINE__ - 2;  // The line of the LOG(INFO) above
1135
1136 TEST(LogBacktraceAt, DoesNotBacktraceWhenDisabled) {
1137   StrictMock<ScopedMockLog> log;
1138
1139   FLAGS_log_backtrace_at = "";
1140
1141   EXPECT_CALL(log, Log(_, _, "Backtrace me"));
1142   EXPECT_CALL(log, Log(_, _, "Not me"));
1143
1144   BacktraceAtHelper();
1145 }
1146
1147 TEST(LogBacktraceAt, DoesBacktraceAtRightLineWhenEnabled) {
1148   StrictMock<ScopedMockLog> log;
1149
1150   char where[100];
1151   snprintf(where, 100, "%s:%d", const_basename(__FILE__), kBacktraceAtLine);
1152   FLAGS_log_backtrace_at = where;
1153
1154   // The LOG at the specified line should include a stacktrace which includes
1155   // the name of the containing function, followed by the log message.
1156   // We use HasSubstr()s instead of ContainsRegex() for environments
1157   // which don't have regexp.
1158   EXPECT_CALL(log, Log(_, _, AllOf(HasSubstr("stacktrace:"),
1159                                    HasSubstr("BacktraceAtHelper"),
1160                                    HasSubstr("main"),
1161                                    HasSubstr("Backtrace me"))));
1162   // Other LOGs should not include a backtrace.
1163   EXPECT_CALL(log, Log(_, _, "Not me"));
1164
1165   BacktraceAtHelper();
1166 }
1167
1168 #endif // HAVE_STACKTRACE
1169
1170 #endif // HAVE_LIB_GMOCK
1171
1172 struct UserDefinedClass {
1173   bool operator==(const UserDefinedClass& rhs) const { return true; }
1174 };
1175
1176 inline ostream& operator<<(ostream& out, const UserDefinedClass& u) {
1177   out << "OK";
1178   return out;
1179 }
1180
1181 TEST(UserDefinedClass, logging) {
1182   UserDefinedClass u;
1183   vector<string> buf;
1184   LOG_STRING(INFO, &buf) << u;
1185   CHECK_EQ(1, buf.size());
1186   CHECK(buf[0].find("OK") != string::npos);
1187
1188   // We must be able to compile this.
1189   CHECK_EQ(u, u);
1190 }