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