1 // Copyright (c) 2002, Google Inc.
2 // All rights reserved.
4 // Redistribution and use in source and binary forms, with or without
5 // modification, are permitted provided that the following conditions are
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
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.
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.
32 #include "config_for_unittests.h"
33 #include "utilities.h"
55 #include "base/commandlineflags.h"
56 #include "glog/logging.h"
57 #include "glog/raw_logging.h"
58 #include "googletest.h"
60 DECLARE_string(log_backtrace_at); // logging.cc
62 #ifdef HAVE_LIB_GFLAGS
63 #include <gflags/gflags.h>
64 using namespace GFLAGS_NAMESPACE;
68 #include <gmock/gmock.h>
70 // Introduce several symbols from gmock.
72 using testing::AnyNumber;
73 using testing::HasSubstr;
76 using testing::StrictMock;
77 using testing::InitGoogleMock;
78 using GOOGLE_NAMESPACE::glog_testing::ScopedMockLog;
82 using namespace GOOGLE_NAMESPACE;
84 // Some non-advertised functions that we want to test or use.
85 _START_GOOGLE_NAMESPACE_
88 bool GetExitOnDFatal();
89 void SetExitOnDFatal(bool value);
90 } // namespace internal
92 _END_GOOGLE_NAMESPACE_
94 static void TestLogging(bool check_counts);
95 static void TestRawLogging();
96 static void LogWithLevels(int v, int severity, bool err, bool alsoerr);
97 static void TestLoggingLevels();
98 static void TestLogString();
99 static void TestLogSink();
100 static void TestLogToString();
101 static void TestLogSinkWaitTillSent();
102 static void TestCHECK();
103 static void TestDCHECK();
104 static void TestSTREQ();
105 static void TestBasename();
106 static void TestSymlink();
107 static void TestExtension();
108 static void TestWrapper();
109 static void TestErrno();
110 static void TestTruncate();
113 static void BM_Check1(int n) {
125 BENCHMARK(BM_Check1);
127 static void CheckFailure(int a, int b, const char* file, int line, const char* msg);
128 static void BM_Check3(int n) {
130 if (n < x) CheckFailure(n, x, __FILE__, __LINE__, "n < x");
131 if (n < x) CheckFailure(n, x, __FILE__, __LINE__, "n < x");
132 if (n < x) CheckFailure(n, x, __FILE__, __LINE__, "n < x");
133 if (n < x) CheckFailure(n, x, __FILE__, __LINE__, "n < x");
134 if (n < x) CheckFailure(n, x, __FILE__, __LINE__, "n < x");
135 if (n < x) CheckFailure(n, x, __FILE__, __LINE__, "n < x");
136 if (n < x) CheckFailure(n, x, __FILE__, __LINE__, "n < x");
137 if (n < x) CheckFailure(n, x, __FILE__, __LINE__, "n < x");
140 BENCHMARK(BM_Check3);
142 static void BM_Check2(int n) {
157 BENCHMARK(BM_Check2);
159 static void CheckFailure(int, int, const char* /* file */, int /* line */,
160 const char* /* msg */) {
163 static void BM_logspeed(int n) {
165 LOG(INFO) << "test message";
168 BENCHMARK(BM_logspeed);
170 static void BM_vlog(int n) {
172 VLOG(1) << "test message";
177 int main(int argc, char **argv) {
178 FLAGS_colorlogtostderr = false;
179 #ifdef HAVE_LIB_GFLAGS
180 ParseCommandLineFlags(&argc, &argv, true);
182 // Make sure stderr is not buffered as stderr seems to be buffered
183 // on recent windows.
184 setbuf(stderr, NULL);
186 // Test some basics before InitGoogleLogging:
188 LogWithLevels(FLAGS_v, FLAGS_stderrthreshold,
189 FLAGS_logtostderr, FLAGS_alsologtostderr);
190 LogWithLevels(0, 0, 0, 0); // simulate "before global c-tors"
191 const string early_stderr = GetCapturedTestStderr();
193 InitGoogleLogging(argv[0]);
195 RunSpecifiedBenchmarks();
197 FLAGS_logtostderr = true;
199 InitGoogleTest(&argc, argv);
200 #ifdef HAVE_LIB_GMOCK
201 InitGoogleMock(&argc, argv);
204 // so that death tests run before we use threads
205 CHECK_EQ(RUN_ALL_TESTS(), 0);
209 // re-emit early_stderr
210 LogMessage("dummy", LogMessage::kNoLogPrefix, GLOG_INFO).stream() << early_stderr;
218 TestLogSinkWaitTillSent();
223 // TODO: The golden test portion of this test is very flakey.
225 MungeAndDiffTestStderr(FLAGS_test_srcdir + "/src/logging_unittest.err"));
227 FLAGS_logtostderr = false;
236 ShutdownGoogleLogging();
238 fprintf(stdout, "PASS\n");
242 void TestLogging(bool check_counts) {
243 int64 base_num_infos = LogMessage::num_messages(GLOG_INFO);
244 int64 base_num_warning = LogMessage::num_messages(GLOG_WARNING);
245 int64 base_num_errors = LogMessage::num_messages(GLOG_ERROR);
247 LOG(INFO) << string("foo ") << "bar " << 10 << ' ' << 3.4;
248 for ( int i = 0; i < 10; ++i ) {
249 int old_errno = errno;
251 PLOG_EVERY_N(ERROR, 2) << "Plog every 2, iteration " << COUNTER;
254 LOG_EVERY_N(ERROR, 3) << "Log every 3, iteration " << COUNTER << endl;
255 LOG_EVERY_N(ERROR, 4) << "Log every 4, iteration " << COUNTER << endl;
257 LOG_IF_EVERY_N(WARNING, true, 5) << "Log if every 5, iteration " << COUNTER;
258 LOG_IF_EVERY_N(WARNING, false, 3)
259 << "Log if every 3, iteration " << COUNTER;
260 LOG_IF_EVERY_N(INFO, true, 1) << "Log if every 1, iteration " << COUNTER;
261 LOG_IF_EVERY_N(ERROR, (i < 3), 2)
262 << "Log if less than 3 every 2, iteration " << COUNTER;
264 LOG_IF(WARNING, true) << "log_if this";
265 LOG_IF(WARNING, false) << "don't log_if this";
269 const char const_s[] = "const array";
270 LOG(INFO) << const_s;
272 LOG(ERROR) << string("foo") << ' '<< j << ' ' << setw(10) << j << " "
273 << setw(1) << hex << j;
276 google::LogMessage outer(__FILE__, __LINE__, google::ERROR);
277 outer.stream() << "outer";
279 LOG(ERROR) << "inner";
282 LogMessage("foo", LogMessage::kNoLogPrefix, GLOG_INFO).stream() << "no prefix";
285 CHECK_EQ(base_num_infos + 14, LogMessage::num_messages(GLOG_INFO));
286 CHECK_EQ(base_num_warning + 3, LogMessage::num_messages(GLOG_WARNING));
287 CHECK_EQ(base_num_errors + 17, LogMessage::num_messages(GLOG_ERROR));
291 static void NoAllocNewHook() {
292 LOG(FATAL) << "unexpected new";
297 g_new_hook = &NoAllocNewHook;
304 TEST(DeathNoAllocNewHook, logging) {
305 // tests that NewHook used below works
309 }, "unexpected new");
312 void TestRawLogging() {
313 string* foo = new string("foo ");
314 string huge_str(50000, 'a');
318 // Check that RAW loggging does not use mallocs.
321 RAW_LOG(INFO, "%s%s%d%c%f", foo->c_str(), "bar ", 10, ' ', 3.4);
323 RAW_LOG(WARNING, "%s", s);
324 const char const_s[] = "const array";
325 RAW_LOG(INFO, "%s", const_s);
326 void* p = reinterpret_cast<void*>(0x12345678);
327 RAW_LOG(INFO, "ptr %p", p);
329 RAW_LOG(INFO, "ptr %p", p);
331 RAW_LOG(ERROR, "%s%d%c%010d%s%1x", foo->c_str(), j, ' ', j, " ", j);
332 RAW_VLOG(0, "foo %d", j);
335 RAW_LOG(INFO, "foo %d", j); // so that have same stderr to compare
337 RAW_DLOG(INFO, "foo %d", j); // test RAW_DLOG in debug mode
340 // test how long messages are chopped:
341 RAW_LOG(WARNING, "Huge string: %s", huge_str.c_str());
342 RAW_VLOG(0, "Huge string: %s", huge_str.c_str());
345 RAW_LOG(INFO, "log");
346 RAW_VLOG(0, "vlog 0 on");
347 RAW_VLOG(1, "vlog 1 off");
348 RAW_VLOG(2, "vlog 2 off");
349 RAW_VLOG(3, "vlog 3 off");
351 RAW_LOG(INFO, "log");
352 RAW_VLOG(1, "vlog 1 on");
353 RAW_VLOG(2, "vlog 2 on");
354 RAW_VLOG(3, "vlog 3 off");
357 RAW_DCHECK(1 == 2, " RAW_DCHECK's shouldn't be compiled in normal mode");
360 RAW_CHECK(1 == 1, "should be ok");
361 RAW_DCHECK(true, "should be ok");
366 void LogWithLevels(int v, int severity, bool err, bool alsoerr) {
368 "Test: v=%d stderrthreshold=%d logtostderr=%d alsologtostderr=%d",
369 v, severity, err, alsoerr);
374 FLAGS_stderrthreshold = severity;
375 FLAGS_logtostderr = err;
376 FLAGS_alsologtostderr = alsoerr;
378 RAW_VLOG(-1, "vlog -1");
379 RAW_VLOG(0, "vlog 0");
380 RAW_VLOG(1, "vlog 1");
381 RAW_LOG(INFO, "log info");
382 RAW_LOG(WARNING, "log warning");
383 RAW_LOG(ERROR, "log error");
385 VLOG(-1) << "vlog -1";
388 LOG(INFO) << "log info";
389 LOG(WARNING) << "log warning";
390 LOG(ERROR) << "log error";
392 VLOG_IF(-1, true) << "vlog_if -1";
393 VLOG_IF(-1, false) << "don't vlog_if -1";
394 VLOG_IF(0, true) << "vlog_if 0";
395 VLOG_IF(0, false) << "don't vlog_if 0";
396 VLOG_IF(1, true) << "vlog_if 1";
397 VLOG_IF(1, false) << "don't vlog_if 1";
398 LOG_IF(INFO, true) << "log_if info";
399 LOG_IF(INFO, false) << "don't log_if info";
400 LOG_IF(WARNING, true) << "log_if warning";
401 LOG_IF(WARNING, false) << "don't log_if warning";
402 LOG_IF(ERROR, true) << "log_if error";
403 LOG_IF(ERROR, false) << "don't log_if error";
406 c = 1; VLOG_IF(100, c -= 2) << "vlog_if 100 expr"; EXPECT_EQ(c, -1);
407 c = 1; VLOG_IF(0, c -= 2) << "vlog_if 0 expr"; EXPECT_EQ(c, -1);
408 c = 1; LOG_IF(INFO, c -= 2) << "log_if info expr"; EXPECT_EQ(c, -1);
409 c = 1; LOG_IF(ERROR, c -= 2) << "log_if error expr"; EXPECT_EQ(c, -1);
410 c = 2; VLOG_IF(0, c -= 2) << "don't vlog_if 0 expr"; EXPECT_EQ(c, 0);
411 c = 2; LOG_IF(ERROR, c -= 2) << "don't log_if error expr"; EXPECT_EQ(c, 0);
413 c = 3; LOG_IF_EVERY_N(INFO, c -= 4, 1) << "log_if info every 1 expr";
415 c = 3; LOG_IF_EVERY_N(ERROR, c -= 4, 1) << "log_if error every 1 expr";
417 c = 4; LOG_IF_EVERY_N(ERROR, c -= 4, 3) << "don't log_if info every 3 expr";
419 c = 4; LOG_IF_EVERY_N(ERROR, c -= 4, 3) << "don't log_if error every 3 expr";
421 c = 5; VLOG_IF_EVERY_N(0, c -= 4, 1) << "vlog_if 0 every 1 expr";
423 c = 5; VLOG_IF_EVERY_N(100, c -= 4, 3) << "vlog_if 100 every 3 expr";
425 c = 6; VLOG_IF_EVERY_N(0, c -= 6, 1) << "don't vlog_if 0 every 1 expr";
427 c = 6; VLOG_IF_EVERY_N(100, c -= 6, 3) << "don't vlog_if 100 every 1 expr";
431 void TestLoggingLevels() {
432 LogWithLevels(0, GLOG_INFO, false, false);
433 LogWithLevels(1, GLOG_INFO, false, false);
434 LogWithLevels(-1, GLOG_INFO, false, false);
435 LogWithLevels(0, GLOG_WARNING, false, false);
436 LogWithLevels(0, GLOG_ERROR, false, false);
437 LogWithLevels(0, GLOG_FATAL, false, false);
438 LogWithLevels(0, GLOG_FATAL, true, false);
439 LogWithLevels(0, GLOG_FATAL, false, true);
440 LogWithLevels(1, GLOG_WARNING, false, false);
441 LogWithLevels(1, GLOG_FATAL, false, true);
444 TEST(DeathRawCHECK, logging) {
445 ASSERT_DEATH(RAW_CHECK(false, "failure 1"),
446 "RAW: Check false failed: failure 1");
447 ASSERT_DEBUG_DEATH(RAW_DCHECK(1 == 2, "failure 2"),
448 "RAW: Check 1 == 2 failed: failure 2");
451 void TestLogString() {
452 vector<string> errors;
453 vector<string> *no_errors = NULL;
455 LOG_STRING(INFO, &errors) << "LOG_STRING: " << "collected info";
456 LOG_STRING(WARNING, &errors) << "LOG_STRING: " << "collected warning";
457 LOG_STRING(ERROR, &errors) << "LOG_STRING: " << "collected error";
459 LOG_STRING(INFO, no_errors) << "LOG_STRING: " << "reported info";
460 LOG_STRING(WARNING, no_errors) << "LOG_STRING: " << "reported warning";
461 LOG_STRING(ERROR, NULL) << "LOG_STRING: " << "reported error";
463 for (size_t i = 0; i < errors.size(); ++i) {
464 LOG(INFO) << "Captured by LOG_STRING: " << errors[i];
468 void TestLogToString() {
470 string* no_error = NULL;
472 LOG_TO_STRING(INFO, &error) << "LOG_TO_STRING: " << "collected info";
473 LOG(INFO) << "Captured by LOG_TO_STRING: " << error;
474 LOG_TO_STRING(WARNING, &error) << "LOG_TO_STRING: " << "collected warning";
475 LOG(INFO) << "Captured by LOG_TO_STRING: " << error;
476 LOG_TO_STRING(ERROR, &error) << "LOG_TO_STRING: " << "collected error";
477 LOG(INFO) << "Captured by LOG_TO_STRING: " << error;
479 LOG_TO_STRING(INFO, no_error) << "LOG_TO_STRING: " << "reported info";
480 LOG_TO_STRING(WARNING, no_error) << "LOG_TO_STRING: " << "reported warning";
481 LOG_TO_STRING(ERROR, NULL) << "LOG_TO_STRING: " << "reported error";
484 class TestLogSinkImpl : public LogSink {
486 vector<string> errors;
487 virtual void send(LogSeverity severity, const char* /* full_filename */,
488 const char* base_filename, int line,
489 const struct tm* tm_time,
490 const char* message, size_t message_len) {
492 ToString(severity, base_filename, line, tm_time, message, message_len));
497 TestLogSinkImpl sink;
498 LogSink *no_sink = NULL;
500 LOG_TO_SINK(&sink, INFO) << "LOG_TO_SINK: " << "collected info";
501 LOG_TO_SINK(&sink, WARNING) << "LOG_TO_SINK: " << "collected warning";
502 LOG_TO_SINK(&sink, ERROR) << "LOG_TO_SINK: " << "collected error";
504 LOG_TO_SINK(no_sink, INFO) << "LOG_TO_SINK: " << "reported info";
505 LOG_TO_SINK(no_sink, WARNING) << "LOG_TO_SINK: " << "reported warning";
506 LOG_TO_SINK(NULL, ERROR) << "LOG_TO_SINK: " << "reported error";
508 LOG_TO_SINK_BUT_NOT_TO_LOGFILE(&sink, INFO)
509 << "LOG_TO_SINK_BUT_NOT_TO_LOGFILE: " << "collected info";
510 LOG_TO_SINK_BUT_NOT_TO_LOGFILE(&sink, WARNING)
511 << "LOG_TO_SINK_BUT_NOT_TO_LOGFILE: " << "collected warning";
512 LOG_TO_SINK_BUT_NOT_TO_LOGFILE(&sink, ERROR)
513 << "LOG_TO_SINK_BUT_NOT_TO_LOGFILE: " << "collected error";
515 LOG_TO_SINK_BUT_NOT_TO_LOGFILE(no_sink, INFO)
516 << "LOG_TO_SINK_BUT_NOT_TO_LOGFILE: " << "thrashed info";
517 LOG_TO_SINK_BUT_NOT_TO_LOGFILE(no_sink, WARNING)
518 << "LOG_TO_SINK_BUT_NOT_TO_LOGFILE: " << "thrashed warning";
519 LOG_TO_SINK_BUT_NOT_TO_LOGFILE(NULL, ERROR)
520 << "LOG_TO_SINK_BUT_NOT_TO_LOGFILE: " << "thrashed error";
522 LOG(INFO) << "Captured by LOG_TO_SINK:";
523 for (size_t i = 0; i < sink.errors.size(); ++i) {
524 LogMessage("foo", LogMessage::kNoLogPrefix, GLOG_INFO).stream()
529 // For testing using CHECK*() on anonymous enums.
536 // Tests using CHECK*() on int values.
547 // Tests using CHECK*() on anonymous enums.
548 // Apple's GCC doesn't like this.
549 #if !defined(OS_MACOSX)
550 CHECK_EQ(CASE_A, CASE_A);
551 CHECK_NE(CASE_A, CASE_B);
552 CHECK_GE(CASE_A, CASE_A);
553 CHECK_GE(CASE_B, CASE_A);
554 CHECK_LE(CASE_A, CASE_A);
555 CHECK_LE(CASE_A, CASE_B);
556 CHECK_GT(CASE_B, CASE_A);
557 CHECK_LT(CASE_A, CASE_B);
563 DCHECK( 1 == 2 ) << " DCHECK's shouldn't be compiled in normal mode";
575 auto_ptr<int64> sptr(new int64);
576 int64* ptr = DCHECK_NOTNULL(sptr.get());
577 CHECK_EQ(ptr, sptr.get());
581 CHECK_STREQ("this", "this");
582 CHECK_STREQ(NULL, NULL);
583 CHECK_STRCASEEQ("this", "tHiS");
584 CHECK_STRCASEEQ(NULL, NULL);
585 CHECK_STRNE("this", "tHiS");
586 CHECK_STRNE("this", NULL);
587 CHECK_STRCASENE("this", "that");
588 CHECK_STRCASENE(NULL, "that");
589 CHECK_STREQ((string("a")+"b").c_str(), "ab");
590 CHECK_STREQ(string("test").c_str(),
591 (string("te") + string("st")).c_str());
594 TEST(DeathSTREQ, logging) {
595 ASSERT_DEATH(CHECK_STREQ(NULL, "this"), "");
596 ASSERT_DEATH(CHECK_STREQ("this", "siht"), "");
597 ASSERT_DEATH(CHECK_STRCASEEQ(NULL, "siht"), "");
598 ASSERT_DEATH(CHECK_STRCASEEQ("this", "siht"), "");
599 ASSERT_DEATH(CHECK_STRNE(NULL, NULL), "");
600 ASSERT_DEATH(CHECK_STRNE("this", "this"), "");
601 ASSERT_DEATH(CHECK_STREQ((string("a")+"b").c_str(), "abc"), "");
604 TEST(CheckNOTNULL, Simple) {
606 void *ptr = static_cast<void *>(&t);
607 void *ref = CHECK_NOTNULL(ptr);
609 CHECK_NOTNULL(reinterpret_cast<char *>(ptr));
610 CHECK_NOTNULL(reinterpret_cast<unsigned char *>(ptr));
611 CHECK_NOTNULL(reinterpret_cast<int *>(ptr));
612 CHECK_NOTNULL(reinterpret_cast<int64 *>(ptr));
615 TEST(DeathCheckNN, Simple) {
616 ASSERT_DEATH(CHECK_NOTNULL(static_cast<void *>(NULL)), "");
619 // Get list of file names that match pattern
620 static void GetFiles(const string& pattern, vector<string>* files) {
622 #if defined(HAVE_GLOB_H)
624 const int r = glob(pattern.c_str(), 0, NULL, &g);
625 CHECK((r == 0) || (r == GLOB_NOMATCH)) << ": error matching " << pattern;
626 for (size_t i = 0; i < g.gl_pathc; i++) {
627 files->push_back(string(g.gl_pathv[i]));
630 #elif defined(OS_WINDOWS)
631 WIN32_FIND_DATAA data;
632 HANDLE handle = FindFirstFileA(pattern.c_str(), &data);
633 size_t index = pattern.rfind('\\');
634 if (index == string::npos) {
635 LOG(FATAL) << "No directory separator.";
637 const string dirname = pattern.substr(0, index + 1);
638 if (handle == INVALID_HANDLE_VALUE) {
639 // Finding no files is OK.
643 files->push_back(dirname + data.cFileName);
644 } while (FindNextFileA(handle, &data));
645 BOOL result = FindClose(handle);
646 LOG_SYSRESULT(result);
648 # error There is no way to do glob.
652 // Delete files patching pattern
653 static void DeleteFiles(const string& pattern) {
654 vector<string> files;
655 GetFiles(pattern, &files);
656 for (size_t i = 0; i < files.size(); i++) {
657 CHECK(unlink(files[i].c_str()) == 0) << ": " << strerror(errno);
661 static void CheckFile(const string& name, const string& expected_string) {
662 vector<string> files;
663 GetFiles(name + "*", &files);
664 CHECK_EQ(files.size(), 1UL);
666 FILE* file = fopen(files[0].c_str(), "r");
667 CHECK(file != NULL) << ": could not open " << files[0];
669 while (fgets(buf, sizeof(buf), file) != NULL) {
670 if (strstr(buf, expected_string.c_str()) != NULL) {
676 LOG(FATAL) << "Did not find " << expected_string << " in " << files[0];
679 static void TestBasename() {
680 fprintf(stderr, "==== Test setting log file basename\n");
681 const string dest = FLAGS_test_tmpdir + "/logging_test_basename";
682 DeleteFiles(dest + "*");
684 SetLogDestination(GLOG_INFO, dest.c_str());
685 LOG(INFO) << "message to new base";
686 FlushLogFiles(GLOG_INFO);
688 CheckFile(dest, "message to new base");
690 // Release file handle for the destination file to unlock the file in Windows.
692 DeleteFiles(dest + "*");
695 static void TestSymlink() {
697 fprintf(stderr, "==== Test setting log file symlink\n");
698 string dest = FLAGS_test_tmpdir + "/logging_test_symlink";
699 string sym = FLAGS_test_tmpdir + "/symlinkbase";
700 DeleteFiles(dest + "*");
701 DeleteFiles(sym + "*");
703 SetLogSymlink(GLOG_INFO, "symlinkbase");
704 SetLogDestination(GLOG_INFO, dest.c_str());
705 LOG(INFO) << "message to new symlink";
706 FlushLogFiles(GLOG_INFO);
707 CheckFile(sym, "message to new symlink");
709 DeleteFiles(dest + "*");
710 DeleteFiles(sym + "*");
714 static void TestExtension() {
715 fprintf(stderr, "==== Test setting log file extension\n");
716 string dest = FLAGS_test_tmpdir + "/logging_test_extension";
717 DeleteFiles(dest + "*");
719 SetLogDestination(GLOG_INFO, dest.c_str());
720 SetLogFilenameExtension("specialextension");
721 LOG(INFO) << "message to new extension";
722 FlushLogFiles(GLOG_INFO);
723 CheckFile(dest, "message to new extension");
725 // Check that file name ends with extension
726 vector<string> filenames;
727 GetFiles(dest + "*", &filenames);
728 CHECK_EQ(filenames.size(), 1UL);
729 CHECK(strstr(filenames[0].c_str(), "specialextension") != NULL);
731 // Release file handle for the destination file to unlock the file in Windows.
733 DeleteFiles(dest + "*");
736 struct MyLogger : public base::Logger {
739 virtual void Write(bool /* should_flush */,
740 time_t /* timestamp */,
743 data.append(message, length);
746 virtual void Flush() { }
748 virtual uint32 LogSize() { return data.length(); }
751 static void TestWrapper() {
752 fprintf(stderr, "==== Test log wrapper\n");
755 base::Logger* old_logger = base::GetLogger(GLOG_INFO);
756 base::SetLogger(GLOG_INFO, &my_logger);
757 LOG(INFO) << "Send to wrapped logger";
758 FlushLogFiles(GLOG_INFO);
759 base::SetLogger(GLOG_INFO, old_logger);
761 CHECK(strstr(my_logger.data.c_str(), "Send to wrapped logger") != NULL);
764 static void TestErrno() {
765 fprintf(stderr, "==== Test errno preservation\n");
769 CHECK_EQ(errno, ENOENT);
772 static void TestOneTruncate(const char *path, int64 limit, int64 keep,
773 int64 dsize, int64 ksize, int64 expect) {
775 CHECK_ERR(fd = open(path, O_RDWR | O_CREAT | O_TRUNC, 0600));
777 const char *discardstr = "DISCARDME!", *keepstr = "KEEPME!";
779 // Fill the file with the requested data; first discard data, then kept data
781 while (written < dsize) {
782 int bytes = min<int64>(dsize - written, strlen(discardstr));
783 CHECK_ERR(write(fd, discardstr, bytes));
787 while (written < ksize) {
788 int bytes = min<int64>(ksize - written, strlen(keepstr));
789 CHECK_ERR(write(fd, keepstr, bytes));
793 TruncateLogFile(path, limit, keep);
795 // File should now be shorter
797 CHECK_ERR(fstat(fd, &statbuf));
798 CHECK_EQ(statbuf.st_size, expect);
799 CHECK_ERR(lseek(fd, 0, SEEK_SET));
801 // File should contain the suffix of the original file
802 const size_t buf_size = statbuf.st_size + 1;
803 char* buf = new char[buf_size];
804 memset(buf, 0, buf_size);
805 CHECK_ERR(read(fd, buf, buf_size));
809 while (checked < expect) {
810 int bytes = min<int64>(expect - checked, strlen(keepstr));
811 CHECK(!memcmp(p, keepstr, bytes));
818 static void TestTruncate() {
820 fprintf(stderr, "==== Test log truncation\n");
821 string path = FLAGS_test_tmpdir + "/truncatefile";
823 // Test on a small file
824 TestOneTruncate(path.c_str(), 10, 10, 10, 10, 10);
826 // And a big file (multiple blocks to copy)
827 TestOneTruncate(path.c_str(), 2<<20, 4<<10, 3<<20, 4<<10, 4<<10);
829 // Check edge-case limits
830 TestOneTruncate(path.c_str(), 10, 20, 0, 20, 20);
831 TestOneTruncate(path.c_str(), 10, 0, 0, 0, 0);
832 TestOneTruncate(path.c_str(), 10, 50, 0, 10, 10);
833 TestOneTruncate(path.c_str(), 50, 100, 0, 30, 30);
835 // MacOSX 10.4 doesn't fail in this case.
836 // Windows doesn't have symlink.
837 // Let's just ignore this test for these cases.
838 #if !defined(OS_MACOSX) && !defined(OS_WINDOWS)
839 // Through a symlink should fail to truncate
840 string linkname = path + ".link";
841 unlink(linkname.c_str());
842 CHECK_ERR(symlink(path.c_str(), linkname.c_str()));
843 TestOneTruncate(linkname.c_str(), 10, 10, 0, 30, 30);
846 // The /proc/self path makes sense only for linux.
847 #if defined(OS_LINUX)
848 // Through an open fd symlink should work
850 CHECK_ERR(fd = open(path.c_str(), O_APPEND | O_WRONLY));
852 snprintf(fdpath, sizeof(fdpath), "/proc/self/fd/%d", fd);
853 TestOneTruncate(fdpath, 10, 10, 10, 10, 10);
859 _START_GOOGLE_NAMESPACE_
860 namespace glog_internal_namespace_ {
861 extern // in logging.cc
862 bool SafeFNMatch_(const char* pattern, size_t patt_len,
863 const char* str, size_t str_len);
864 } // namespace glog_internal_namespace_
865 using glog_internal_namespace_::SafeFNMatch_;
866 _END_GOOGLE_NAMESPACE_
868 static bool WrapSafeFNMatch(string pattern, string str) {
871 return SafeFNMatch_(pattern.data(), pattern.size() - 3,
872 str.data(), str.size() - 5);
875 TEST(SafeFNMatch, logging) {
876 CHECK(WrapSafeFNMatch("foo", "foo"));
877 CHECK(!WrapSafeFNMatch("foo", "bar"));
878 CHECK(!WrapSafeFNMatch("foo", "fo"));
879 CHECK(!WrapSafeFNMatch("foo", "foo2"));
880 CHECK(WrapSafeFNMatch("bar/foo.ext", "bar/foo.ext"));
881 CHECK(WrapSafeFNMatch("*ba*r/fo*o.ext*", "bar/foo.ext"));
882 CHECK(!WrapSafeFNMatch("bar/foo.ext", "bar/baz.ext"));
883 CHECK(!WrapSafeFNMatch("bar/foo.ext", "bar/foo"));
884 CHECK(!WrapSafeFNMatch("bar/foo.ext", "bar/foo.ext.zip"));
885 CHECK(WrapSafeFNMatch("ba?/*.ext", "bar/foo.ext"));
886 CHECK(WrapSafeFNMatch("ba?/*.ext", "baZ/FOO.ext"));
887 CHECK(!WrapSafeFNMatch("ba?/*.ext", "barr/foo.ext"));
888 CHECK(!WrapSafeFNMatch("ba?/*.ext", "bar/foo.ext2"));
889 CHECK(WrapSafeFNMatch("ba?/*", "bar/foo.ext2"));
890 CHECK(WrapSafeFNMatch("ba?/*", "bar/"));
891 CHECK(!WrapSafeFNMatch("ba?/?", "bar/"));
892 CHECK(!WrapSafeFNMatch("ba?/*", "bar"));
895 // TestWaitingLogSink will save messages here
896 // No lock: Accessed only by TestLogSinkWriter thread
897 // and after its demise by its creator.
898 static vector<string> global_messages;
900 // helper for TestWaitingLogSink below.
901 // Thread that does the logic of TestWaitingLogSink
902 // It's free to use LOG() itself.
903 class TestLogSinkWriter : public Thread {
906 TestLogSinkWriter() : should_exit_(false) {
911 // Just buffer it (can't use LOG() here).
912 void Buffer(const string& message) {
914 RAW_LOG(INFO, "Buffering");
915 messages_.push(message);
917 RAW_LOG(INFO, "Buffered");
920 // Wait for the buffer to clear (can't use LOG() here).
922 RAW_LOG(INFO, "Waiting");
926 SleepForMilliseconds(1);
929 RAW_LOG(INFO, "Waited");
933 // Trigger thread exit.
935 MutexLock l(&mutex_);
941 // helpers ---------------
943 // For creating a "Condition".
944 bool NoWork() { return messages_.empty(); }
945 bool HaveWork() { return !messages_.empty() || should_exit_; }
947 // Thread body; CAN use LOG() here!
951 while (!HaveWork()) {
953 SleepForMilliseconds(1);
956 if (should_exit_ && messages_.empty()) {
960 // Give the main thread time to log its message,
961 // so that we get a reliable log capture to compare to golden file.
962 // Same for the other sleep below.
963 SleepForMilliseconds(20);
964 RAW_LOG(INFO, "Sink got a messages"); // only RAW_LOG under mutex_ here
965 string message = messages_.front();
967 // Normally this would be some more real/involved logging logic
968 // where LOG() usage can't be eliminated,
969 // e.g. pushing the message over with an RPC:
970 int messages_left = messages_.size();
972 SleepForMilliseconds(20);
973 // May not use LOG while holding mutex_, because Buffer()
974 // acquires mutex_, and Buffer is called from LOG(),
975 // which has its own internal mutex:
976 // LOG()->LogToSinks()->TestWaitingLogSink::send()->Buffer()
977 LOG(INFO) << "Sink is sending out a message: " << message;
978 LOG(INFO) << "Have " << messages_left << " left";
979 global_messages.push_back(message);
983 // data ---------------
987 queue<string> messages_; // messages to be logged
990 // A log sink that exercises WaitTillSent:
991 // it pushes data to a buffer and wakes up another thread to do the logging
992 // (that other thread can than use LOG() itself),
993 class TestWaitingLogSink : public LogSink {
996 TestWaitingLogSink() {
997 tid_ = pthread_self(); // for thread-specific behavior
1000 ~TestWaitingLogSink() {
1001 RemoveLogSink(this);
1006 // (re)define LogSink interface
1008 virtual void send(LogSeverity severity, const char* /* full_filename */,
1009 const char* base_filename, int line,
1010 const struct tm* tm_time,
1011 const char* message, size_t message_len) {
1012 // Push it to Writer thread if we are the original logging thread.
1013 // Note: Something like ThreadLocalLogSink is a better choice
1014 // to do thread-specific LogSink logic for real.
1015 if (pthread_equal(tid_, pthread_self())) {
1016 writer_.Buffer(ToString(severity, base_filename, line,
1017 tm_time, message, message_len));
1020 virtual void WaitTillSent() {
1021 // Wait for Writer thread if we are the original logging thread.
1022 if (pthread_equal(tid_, pthread_self())) writer_.Wait();
1028 TestLogSinkWriter writer_;
1031 // Check that LogSink::WaitTillSent can be used in the advertised way.
1032 // We also do golden-stderr comparison.
1033 static void TestLogSinkWaitTillSent() {
1034 { TestWaitingLogSink sink;
1035 // Sleeps give the sink threads time to do all their work,
1036 // so that we get a reliable log capture to compare to the golden file.
1037 LOG(INFO) << "Message 1";
1038 SleepForMilliseconds(60);
1039 LOG(ERROR) << "Message 2";
1040 SleepForMilliseconds(60);
1041 LOG(WARNING) << "Message 3";
1042 SleepForMilliseconds(60);
1044 for (size_t i = 0; i < global_messages.size(); ++i) {
1045 LOG(INFO) << "Sink capture: " << global_messages[i];
1047 CHECK_EQ(global_messages.size(), 3UL);
1050 TEST(Strerror, logging) {
1051 int errcode = EINTR;
1052 char *msg = strdup(strerror(errcode));
1053 const size_t buf_size = strlen(msg) + 1;
1054 char *buf = new char[buf_size];
1055 CHECK_EQ(posix_strerror_r(errcode, NULL, 0), -1);
1057 CHECK_EQ(posix_strerror_r(errcode, buf, 0), -1);
1058 CHECK_EQ(buf[0], 'A');
1059 CHECK_EQ(posix_strerror_r(errcode, NULL, buf_size), -1);
1060 #if defined(OS_MACOSX) || defined(OS_FREEBSD) || defined(OS_OPENBSD)
1061 // MacOSX or FreeBSD considers this case is an error since there is
1063 CHECK_EQ(posix_strerror_r(errcode, buf, 1), -1);
1065 CHECK_EQ(posix_strerror_r(errcode, buf, 1), 0);
1067 CHECK_STREQ(buf, "");
1068 CHECK_EQ(posix_strerror_r(errcode, buf, buf_size), 0);
1069 CHECK_STREQ(buf, msg);
1071 CHECK_EQ(msg, StrError(errcode));
1075 // Simple routines to look at the sizes of generated code for LOG(FATAL) and
1076 // CHECK(..) via objdump
1078 LOG(FATAL) << "Failed";
1080 void MyCheck(bool a, bool b) {
1084 #ifdef HAVE_LIB_GMOCK
1086 TEST(DVLog, Basic) {
1090 // We are expecting that nothing is logged.
1091 EXPECT_CALL(log, Log(_, _, _)).Times(0);
1093 EXPECT_CALL(log, Log(INFO, __FILE__, "debug log"));
1097 DVLOG(1) << "debug log";
1103 // We are expecting that nothing is logged.
1104 EXPECT_CALL(log, Log(_, _, _)).Times(0);
1107 DVLOG(1) << "debug log";
1110 TEST(LogAtLevel, Basic) {
1113 // The function version outputs "logging.h" as a file name.
1114 EXPECT_CALL(log, Log(WARNING, StrNe(__FILE__), "function version"));
1115 EXPECT_CALL(log, Log(INFO, __FILE__, "macro version"));
1117 int severity = WARNING;
1118 LogAtLevel(severity, "function version");
1121 // We can use the macro version as a C++ stream.
1122 LOG_AT_LEVEL(severity) << "macro" << ' ' << "version";
1125 TEST(TestExitOnDFatal, ToBeOrNotToBe) {
1126 // Check the default setting...
1127 EXPECT_TRUE(base::internal::GetExitOnDFatal());
1130 base::internal::SetExitOnDFatal(false);
1131 EXPECT_FALSE(base::internal::GetExitOnDFatal());
1136 //EXPECT_CALL(log, Log(_, _, _)).Times(AnyNumber());
1137 // LOG(DFATAL) has severity FATAL if debugging, but is
1138 // downgraded to ERROR if not debugging.
1139 const LogSeverity severity =
1145 EXPECT_CALL(log, Log(severity, __FILE__, "This should not be fatal"));
1146 LOG(DFATAL) << "This should not be fatal";
1150 base::internal::SetExitOnDFatal(true);
1151 EXPECT_TRUE(base::internal::GetExitOnDFatal());
1153 #ifdef GTEST_HAS_DEATH_TEST
1154 // Death comes on little cats' feet.
1155 EXPECT_DEBUG_DEATH({
1156 LOG(DFATAL) << "This should be fatal in debug mode";
1157 }, "This should be fatal in debug mode");
1161 #ifdef HAVE_STACKTRACE
1163 static void BacktraceAtHelper() {
1164 LOG(INFO) << "Not me";
1166 // The vertical spacing of the next 3 lines is significant.
1167 LOG(INFO) << "Backtrace me";
1169 static int kBacktraceAtLine = __LINE__ - 2; // The line of the LOG(INFO) above
1171 TEST(LogBacktraceAt, DoesNotBacktraceWhenDisabled) {
1172 StrictMock<ScopedMockLog> log;
1174 FLAGS_log_backtrace_at = "";
1176 EXPECT_CALL(log, Log(_, _, "Backtrace me"));
1177 EXPECT_CALL(log, Log(_, _, "Not me"));
1179 BacktraceAtHelper();
1182 TEST(LogBacktraceAt, DoesBacktraceAtRightLineWhenEnabled) {
1183 StrictMock<ScopedMockLog> log;
1186 snprintf(where, 100, "%s:%d", const_basename(__FILE__), kBacktraceAtLine);
1187 FLAGS_log_backtrace_at = where;
1189 // The LOG at the specified line should include a stacktrace which includes
1190 // the name of the containing function, followed by the log message.
1191 // We use HasSubstr()s instead of ContainsRegex() for environments
1192 // which don't have regexp.
1193 EXPECT_CALL(log, Log(_, _, AllOf(HasSubstr("stacktrace:"),
1194 HasSubstr("BacktraceAtHelper"),
1196 HasSubstr("Backtrace me"))));
1197 // Other LOGs should not include a backtrace.
1198 EXPECT_CALL(log, Log(_, _, "Not me"));
1200 BacktraceAtHelper();
1203 #endif // HAVE_STACKTRACE
1205 #endif // HAVE_LIB_GMOCK
1207 struct UserDefinedClass {
1208 bool operator==(const UserDefinedClass&) const { return true; }
1211 inline ostream& operator<<(ostream& out, const UserDefinedClass&) {
1216 TEST(UserDefinedClass, logging) {
1219 LOG_STRING(INFO, &buf) << u;
1220 CHECK_EQ(1UL, buf.size());
1221 CHECK(buf[0].find("OK") != string::npos);
1223 // We must be able to compile this.