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