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