1 /*
2 * Copyright (C) 2015 The Android Open Source Project
3 *
4 * Licensed under the Apache License, Version 2.0 (the "License");
5 * you may not use this file except in compliance with the License.
6 * You may obtain a copy of the License at
7 *
8 * http://www.apache.org/licenses/LICENSE-2.0
9 *
10 * Unless required by applicable law or agreed to in writing, software
11 * distributed under the License is distributed on an "AS IS" BASIS,
12 * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
13 * See the License for the specific language governing permissions and
14 * limitations under the License.
15 */
16
17 #include "android-base/logging.h"
18
19 #include <libgen.h>
20
21 #if defined(_WIN32)
22 #include <signal.h>
23 #endif
24
25 #include <memory>
26 #include <regex>
27 #include <string>
28 #include <thread>
29
30 #include "android-base/file.h"
31 #include "android-base/scopeguard.h"
32 #include "android-base/stringprintf.h"
33 #include "android-base/test_utils.h"
34
35 #include <gtest/gtest.h>
36
37 #ifdef __ANDROID__
38 #define HOST_TEST(suite, name) TEST(suite, DISABLED_ ## name)
39 #else
40 #define HOST_TEST(suite, name) TEST(suite, name)
41 #endif
42
43 #if defined(_WIN32)
ExitSignalAbortHandler(int)44 static void ExitSignalAbortHandler(int) {
45 _exit(3);
46 }
47 #endif
48
SuppressAbortUI()49 static void SuppressAbortUI() {
50 #if defined(_WIN32)
51 // We really just want to call _set_abort_behavior(0, _CALL_REPORTFAULT) to
52 // suppress the Windows Error Reporting dialog box, but that API is not
53 // available in the OS-supplied C Runtime, msvcrt.dll, that we currently
54 // use (it is available in the Visual Studio C runtime).
55 //
56 // Instead, we setup a SIGABRT handler, which is called in abort() right
57 // before calling Windows Error Reporting. In the handler, we exit the
58 // process just like abort() does.
59 ASSERT_NE(SIG_ERR, signal(SIGABRT, ExitSignalAbortHandler));
60 #endif
61 }
62
TEST(logging,CHECK)63 TEST(logging, CHECK) {
64 ASSERT_DEATH({SuppressAbortUI(); CHECK(false);}, "Check failed: false ");
65 CHECK(true);
66
67 ASSERT_DEATH({SuppressAbortUI(); CHECK_EQ(0, 1);}, "Check failed: 0 == 1 ");
68 CHECK_EQ(0, 0);
69
70 std::unique_ptr<int> p;
71 ASSERT_DEATH(CHECK_NE(p, nullptr), "Check failed");
72 CHECK_EQ(p, nullptr);
73 CHECK_EQ(p, p);
74
75 const char* kText = "Some text";
76 ASSERT_DEATH(CHECK_NE(kText, kText), "Check failed");
77 ASSERT_DEATH(CHECK_EQ(kText, nullptr), "Check failed.*null");
78 CHECK_EQ(kText, kText);
79
80 ASSERT_DEATH({SuppressAbortUI(); CHECK_STREQ("foo", "bar");},
81 R"(Check failed: "foo" == "bar")");
82 CHECK_STREQ("foo", "foo");
83
84 // Test whether CHECK() and CHECK_STREQ() have a dangling if with no else.
85 bool flag = false;
86 if (true)
87 CHECK(true);
88 else
89 flag = true;
90 EXPECT_FALSE(flag) << "CHECK macro probably has a dangling if with no else";
91
92 flag = false;
93 if (true)
94 CHECK_STREQ("foo", "foo");
95 else
96 flag = true;
97 EXPECT_FALSE(flag) << "CHECK_STREQ probably has a dangling if with no else";
98 }
99
TEST(logging,DCHECK)100 TEST(logging, DCHECK) {
101 if (android::base::kEnableDChecks) {
102 ASSERT_DEATH({SuppressAbortUI(); DCHECK(false);}, "DCheck failed: false ");
103 }
104 DCHECK(true);
105
106 if (android::base::kEnableDChecks) {
107 ASSERT_DEATH({SuppressAbortUI(); DCHECK_EQ(0, 1);}, "DCheck failed: 0 == 1 ");
108 }
109 DCHECK_EQ(0, 0);
110
111 std::unique_ptr<int> p;
112 if (android::base::kEnableDChecks) {
113 ASSERT_DEATH(DCHECK_NE(p, nullptr), "DCheck failed");
114 }
115 DCHECK_EQ(p, nullptr);
116 DCHECK_EQ(p, p);
117
118 if (android::base::kEnableDChecks) {
119 ASSERT_DEATH({SuppressAbortUI(); DCHECK_STREQ("foo", "bar");},
120 R"(DCheck failed: "foo" == "bar")");
121 }
122 DCHECK_STREQ("foo", "foo");
123
124 // No testing whether we have a dangling else, possibly. That's inherent to the if (constexpr)
125 // setup we intentionally chose to force type-checks of debug code even in release builds (so
126 // we don't get more bit-rot).
127 }
128
129
130 #define CHECK_WOULD_LOG_DISABLED(severity) \
131 static_assert(android::base::severity < android::base::FATAL, "Bad input"); \
132 for (size_t i = static_cast<size_t>(android::base::severity) + 1; \
133 i <= static_cast<size_t>(android::base::FATAL); \
134 ++i) { \
135 { \
136 android::base::ScopedLogSeverity sls2(static_cast<android::base::LogSeverity>(i)); \
137 EXPECT_FALSE(WOULD_LOG(severity)) << i; \
138 } \
139 { \
140 android::base::ScopedLogSeverity sls2(static_cast<android::base::LogSeverity>(i)); \
141 EXPECT_FALSE(WOULD_LOG(::android::base::severity)) << i; \
142 } \
143 } \
144
145 #define CHECK_WOULD_LOG_ENABLED(severity) \
146 for (size_t i = static_cast<size_t>(android::base::VERBOSE); \
147 i <= static_cast<size_t>(android::base::severity); \
148 ++i) { \
149 { \
150 android::base::ScopedLogSeverity sls2(static_cast<android::base::LogSeverity>(i)); \
151 EXPECT_TRUE(WOULD_LOG(severity)) << i; \
152 } \
153 { \
154 android::base::ScopedLogSeverity sls2(static_cast<android::base::LogSeverity>(i)); \
155 EXPECT_TRUE(WOULD_LOG(::android::base::severity)) << i; \
156 } \
157 } \
158
TEST(logging,WOULD_LOG_FATAL)159 TEST(logging, WOULD_LOG_FATAL) {
160 CHECK_WOULD_LOG_ENABLED(FATAL);
161 }
162
TEST(logging,WOULD_LOG_FATAL_WITHOUT_ABORT_enabled)163 TEST(logging, WOULD_LOG_FATAL_WITHOUT_ABORT_enabled) {
164 CHECK_WOULD_LOG_ENABLED(FATAL_WITHOUT_ABORT);
165 }
166
TEST(logging,WOULD_LOG_ERROR_disabled)167 TEST(logging, WOULD_LOG_ERROR_disabled) {
168 CHECK_WOULD_LOG_DISABLED(ERROR);
169 }
170
TEST(logging,WOULD_LOG_ERROR_enabled)171 TEST(logging, WOULD_LOG_ERROR_enabled) {
172 CHECK_WOULD_LOG_ENABLED(ERROR);
173 }
174
TEST(logging,WOULD_LOG_WARNING_disabled)175 TEST(logging, WOULD_LOG_WARNING_disabled) {
176 CHECK_WOULD_LOG_DISABLED(WARNING);
177 }
178
TEST(logging,WOULD_LOG_WARNING_enabled)179 TEST(logging, WOULD_LOG_WARNING_enabled) {
180 CHECK_WOULD_LOG_ENABLED(WARNING);
181 }
182
TEST(logging,WOULD_LOG_INFO_disabled)183 TEST(logging, WOULD_LOG_INFO_disabled) {
184 CHECK_WOULD_LOG_DISABLED(INFO);
185 }
186
TEST(logging,WOULD_LOG_INFO_enabled)187 TEST(logging, WOULD_LOG_INFO_enabled) {
188 CHECK_WOULD_LOG_ENABLED(INFO);
189 }
190
TEST(logging,WOULD_LOG_DEBUG_disabled)191 TEST(logging, WOULD_LOG_DEBUG_disabled) {
192 CHECK_WOULD_LOG_DISABLED(DEBUG);
193 }
194
TEST(logging,WOULD_LOG_DEBUG_enabled)195 TEST(logging, WOULD_LOG_DEBUG_enabled) {
196 CHECK_WOULD_LOG_ENABLED(DEBUG);
197 }
198
TEST(logging,WOULD_LOG_VERBOSE_disabled)199 TEST(logging, WOULD_LOG_VERBOSE_disabled) {
200 CHECK_WOULD_LOG_DISABLED(VERBOSE);
201 }
202
TEST(logging,WOULD_LOG_VERBOSE_enabled)203 TEST(logging, WOULD_LOG_VERBOSE_enabled) {
204 CHECK_WOULD_LOG_ENABLED(VERBOSE);
205 }
206
207 #undef CHECK_WOULD_LOG_DISABLED
208 #undef CHECK_WOULD_LOG_ENABLED
209
210
211 #if !defined(_WIN32)
make_log_pattern(android::base::LogSeverity severity,const char * message)212 static std::string make_log_pattern(android::base::LogSeverity severity,
213 const char* message) {
214 static const char log_characters[] = "VDIWEFF";
215 static_assert(arraysize(log_characters) - 1 == android::base::FATAL + 1,
216 "Mismatch in size of log_characters and values in LogSeverity");
217 char log_char = log_characters[severity];
218 std::string holder(__FILE__);
219 return android::base::StringPrintf(
220 "%c \\d+-\\d+ \\d+:\\d+:\\d+ \\s*\\d+ \\s*\\d+ %s:\\d+] %s",
221 log_char, basename(&holder[0]), message);
222 }
223 #endif
224
CheckMessage(const std::string & output,android::base::LogSeverity severity,const char * expected,const char * expected_tag=nullptr)225 static void CheckMessage(const std::string& output, android::base::LogSeverity severity,
226 const char* expected, const char* expected_tag = nullptr) {
227 // We can't usefully check the output of any of these on Windows because we
228 // don't have std::regex, but we can at least make sure we printed at least as
229 // many characters are in the log message.
230 ASSERT_GT(output.length(), strlen(expected));
231 ASSERT_NE(nullptr, strstr(output.c_str(), expected)) << output;
232 if (expected_tag != nullptr) {
233 ASSERT_NE(nullptr, strstr(output.c_str(), expected_tag)) << output;
234 }
235
236 #if !defined(_WIN32)
237 std::string regex_str;
238 if (expected_tag != nullptr) {
239 regex_str.append(expected_tag);
240 regex_str.append(" ");
241 }
242 regex_str.append(make_log_pattern(severity, expected));
243 std::regex message_regex(regex_str);
244 ASSERT_TRUE(std::regex_search(output, message_regex)) << output;
245 #endif
246 }
247
CheckMessage(CapturedStderr & cap,android::base::LogSeverity severity,const char * expected,const char * expected_tag=nullptr)248 static void CheckMessage(CapturedStderr& cap, android::base::LogSeverity severity,
249 const char* expected, const char* expected_tag = nullptr) {
250 cap.Stop();
251 std::string output = cap.str();
252 return CheckMessage(output, severity, expected, expected_tag);
253 }
254
255 #define CHECK_LOG_STREAM_DISABLED(severity) \
256 { \
257 android::base::ScopedLogSeverity sls1(android::base::FATAL); \
258 CapturedStderr cap1; \
259 LOG_STREAM(severity) << "foo bar"; \
260 cap1.Stop(); \
261 ASSERT_EQ("", cap1.str()); \
262 } \
263 { \
264 android::base::ScopedLogSeverity sls1(android::base::FATAL); \
265 CapturedStderr cap1; \
266 LOG_STREAM(::android::base::severity) << "foo bar"; \
267 cap1.Stop(); \
268 ASSERT_EQ("", cap1.str()); \
269 }
270
271 #define CHECK_LOG_STREAM_ENABLED(severity) \
272 { \
273 android::base::ScopedLogSeverity sls2(android::base::severity); \
274 CapturedStderr cap2; \
275 LOG_STREAM(severity) << "foobar"; \
276 CheckMessage(cap2, android::base::severity, "foobar"); \
277 } \
278 { \
279 android::base::ScopedLogSeverity sls2(android::base::severity); \
280 CapturedStderr cap2; \
281 LOG_STREAM(::android::base::severity) << "foobar"; \
282 CheckMessage(cap2, android::base::severity, "foobar"); \
283 } \
284
TEST(logging,LOG_STREAM_FATAL_WITHOUT_ABORT_enabled)285 TEST(logging, LOG_STREAM_FATAL_WITHOUT_ABORT_enabled) {
286 ASSERT_NO_FATAL_FAILURE(CHECK_LOG_STREAM_ENABLED(FATAL_WITHOUT_ABORT));
287 }
288
TEST(logging,LOG_STREAM_ERROR_disabled)289 TEST(logging, LOG_STREAM_ERROR_disabled) {
290 CHECK_LOG_STREAM_DISABLED(ERROR);
291 }
292
TEST(logging,LOG_STREAM_ERROR_enabled)293 TEST(logging, LOG_STREAM_ERROR_enabled) {
294 ASSERT_NO_FATAL_FAILURE(CHECK_LOG_STREAM_ENABLED(ERROR));
295 }
296
TEST(logging,LOG_STREAM_WARNING_disabled)297 TEST(logging, LOG_STREAM_WARNING_disabled) {
298 CHECK_LOG_STREAM_DISABLED(WARNING);
299 }
300
TEST(logging,LOG_STREAM_WARNING_enabled)301 TEST(logging, LOG_STREAM_WARNING_enabled) {
302 ASSERT_NO_FATAL_FAILURE(CHECK_LOG_STREAM_ENABLED(WARNING));
303 }
304
TEST(logging,LOG_STREAM_INFO_disabled)305 TEST(logging, LOG_STREAM_INFO_disabled) {
306 CHECK_LOG_STREAM_DISABLED(INFO);
307 }
308
TEST(logging,LOG_STREAM_INFO_enabled)309 TEST(logging, LOG_STREAM_INFO_enabled) {
310 ASSERT_NO_FATAL_FAILURE(CHECK_LOG_STREAM_ENABLED(INFO));
311 }
312
TEST(logging,LOG_STREAM_DEBUG_disabled)313 TEST(logging, LOG_STREAM_DEBUG_disabled) {
314 CHECK_LOG_STREAM_DISABLED(DEBUG);
315 }
316
TEST(logging,LOG_STREAM_DEBUG_enabled)317 TEST(logging, LOG_STREAM_DEBUG_enabled) {
318 ASSERT_NO_FATAL_FAILURE(CHECK_LOG_STREAM_ENABLED(DEBUG));
319 }
320
TEST(logging,LOG_STREAM_VERBOSE_disabled)321 TEST(logging, LOG_STREAM_VERBOSE_disabled) {
322 CHECK_LOG_STREAM_DISABLED(VERBOSE);
323 }
324
TEST(logging,LOG_STREAM_VERBOSE_enabled)325 TEST(logging, LOG_STREAM_VERBOSE_enabled) {
326 ASSERT_NO_FATAL_FAILURE(CHECK_LOG_STREAM_ENABLED(VERBOSE));
327 }
328
329 #undef CHECK_LOG_STREAM_DISABLED
330 #undef CHECK_LOG_STREAM_ENABLED
331
332 #define CHECK_LOG_DISABLED(severity) \
333 { \
334 android::base::ScopedLogSeverity sls1(android::base::FATAL); \
335 CapturedStderr cap1; \
336 LOG(severity) << "foo bar"; \
337 cap1.Stop(); \
338 ASSERT_EQ("", cap1.str()); \
339 } \
340 { \
341 android::base::ScopedLogSeverity sls1(android::base::FATAL); \
342 CapturedStderr cap1; \
343 LOG(::android::base::severity) << "foo bar"; \
344 cap1.Stop(); \
345 ASSERT_EQ("", cap1.str()); \
346 }
347
348 #define CHECK_LOG_ENABLED(severity) \
349 { \
350 android::base::ScopedLogSeverity sls2(android::base::severity); \
351 CapturedStderr cap2; \
352 LOG(severity) << "foobar"; \
353 CheckMessage(cap2, android::base::severity, "foobar"); \
354 } \
355 { \
356 android::base::ScopedLogSeverity sls2(android::base::severity); \
357 CapturedStderr cap2; \
358 LOG(::android::base::severity) << "foobar"; \
359 CheckMessage(cap2, android::base::severity, "foobar"); \
360 } \
361
TEST(logging,LOG_FATAL)362 TEST(logging, LOG_FATAL) {
363 ASSERT_DEATH({SuppressAbortUI(); LOG(FATAL) << "foobar";}, "foobar");
364 ASSERT_DEATH({SuppressAbortUI(); LOG(::android::base::FATAL) << "foobar";}, "foobar");
365 }
366
TEST(logging,LOG_FATAL_WITHOUT_ABORT_enabled)367 TEST(logging, LOG_FATAL_WITHOUT_ABORT_enabled) {
368 ASSERT_NO_FATAL_FAILURE(CHECK_LOG_ENABLED(FATAL_WITHOUT_ABORT));
369 }
370
TEST(logging,LOG_ERROR_disabled)371 TEST(logging, LOG_ERROR_disabled) {
372 CHECK_LOG_DISABLED(ERROR);
373 }
374
TEST(logging,LOG_ERROR_enabled)375 TEST(logging, LOG_ERROR_enabled) {
376 ASSERT_NO_FATAL_FAILURE(CHECK_LOG_ENABLED(ERROR));
377 }
378
TEST(logging,LOG_WARNING_disabled)379 TEST(logging, LOG_WARNING_disabled) {
380 CHECK_LOG_DISABLED(WARNING);
381 }
382
TEST(logging,LOG_WARNING_enabled)383 TEST(logging, LOG_WARNING_enabled) {
384 ASSERT_NO_FATAL_FAILURE(CHECK_LOG_ENABLED(WARNING));
385 }
386
TEST(logging,LOG_INFO_disabled)387 TEST(logging, LOG_INFO_disabled) {
388 CHECK_LOG_DISABLED(INFO);
389 }
390
TEST(logging,LOG_INFO_enabled)391 TEST(logging, LOG_INFO_enabled) {
392 ASSERT_NO_FATAL_FAILURE(CHECK_LOG_ENABLED(INFO));
393 }
394
TEST(logging,LOG_DEBUG_disabled)395 TEST(logging, LOG_DEBUG_disabled) {
396 CHECK_LOG_DISABLED(DEBUG);
397 }
398
TEST(logging,LOG_DEBUG_enabled)399 TEST(logging, LOG_DEBUG_enabled) {
400 ASSERT_NO_FATAL_FAILURE(CHECK_LOG_ENABLED(DEBUG));
401 }
402
TEST(logging,LOG_VERBOSE_disabled)403 TEST(logging, LOG_VERBOSE_disabled) {
404 CHECK_LOG_DISABLED(VERBOSE);
405 }
406
TEST(logging,LOG_VERBOSE_enabled)407 TEST(logging, LOG_VERBOSE_enabled) {
408 ASSERT_NO_FATAL_FAILURE(CHECK_LOG_ENABLED(VERBOSE));
409 }
410
411 #undef CHECK_LOG_DISABLED
412 #undef CHECK_LOG_ENABLED
413
TEST(logging,LOG_complex_param)414 TEST(logging, LOG_complex_param) {
415 #define CHECK_LOG_COMBINATION(use_scoped_log_severity_info, use_logging_severity_info) \
416 { \
417 android::base::ScopedLogSeverity sls( \
418 (use_scoped_log_severity_info) ? ::android::base::INFO : ::android::base::WARNING); \
419 CapturedStderr cap; \
420 LOG((use_logging_severity_info) ? ::android::base::INFO : ::android::base::WARNING) \
421 << "foobar"; \
422 if ((use_scoped_log_severity_info) || !(use_logging_severity_info)) { \
423 ASSERT_NO_FATAL_FAILURE(CheckMessage( \
424 cap, (use_logging_severity_info) ? ::android::base::INFO : ::android::base::WARNING, \
425 "foobar")); \
426 } else { \
427 cap.Stop(); \
428 ASSERT_EQ("", cap.str()); \
429 } \
430 }
431
432 CHECK_LOG_COMBINATION(false,false);
433 CHECK_LOG_COMBINATION(false,true);
434 CHECK_LOG_COMBINATION(true,false);
435 CHECK_LOG_COMBINATION(true,true);
436
437 #undef CHECK_LOG_COMBINATION
438 }
439
440
TEST(logging,LOG_does_not_clobber_errno)441 TEST(logging, LOG_does_not_clobber_errno) {
442 CapturedStderr cap;
443 errno = 12345;
444 LOG(INFO) << (errno = 67890);
445 EXPECT_EQ(12345, errno) << "errno was not restored";
446
447 ASSERT_NO_FATAL_FAILURE(CheckMessage(cap, android::base::INFO, "67890"));
448 }
449
TEST(logging,PLOG_does_not_clobber_errno)450 TEST(logging, PLOG_does_not_clobber_errno) {
451 CapturedStderr cap;
452 errno = 12345;
453 PLOG(INFO) << (errno = 67890);
454 EXPECT_EQ(12345, errno) << "errno was not restored";
455
456 ASSERT_NO_FATAL_FAILURE(CheckMessage(cap, android::base::INFO, "67890"));
457 }
458
TEST(logging,LOG_does_not_have_dangling_if)459 TEST(logging, LOG_does_not_have_dangling_if) {
460 CapturedStderr cap; // So the logging below has no side-effects.
461
462 // Do the test two ways: once where we hypothesize that LOG()'s if
463 // will evaluate to true (when severity is high enough) and once when we
464 // expect it to evaluate to false (when severity is not high enough).
465 bool flag = false;
466 if (true)
467 LOG(INFO) << "foobar";
468 else
469 flag = true;
470
471 EXPECT_FALSE(flag) << "LOG macro probably has a dangling if with no else";
472
473 flag = false;
474 if (true)
475 LOG(VERBOSE) << "foobar";
476 else
477 flag = true;
478
479 EXPECT_FALSE(flag) << "LOG macro probably has a dangling if with no else";
480 }
481
482 #define CHECK_PLOG_DISABLED(severity) \
483 { \
484 android::base::ScopedLogSeverity sls1(android::base::FATAL); \
485 CapturedStderr cap1; \
486 PLOG(severity) << "foo bar"; \
487 cap1.Stop(); \
488 ASSERT_EQ("", cap1.str()); \
489 } \
490 { \
491 android::base::ScopedLogSeverity sls1(android::base::FATAL); \
492 CapturedStderr cap1; \
493 PLOG(severity) << "foo bar"; \
494 cap1.Stop(); \
495 ASSERT_EQ("", cap1.str()); \
496 }
497
498 #define CHECK_PLOG_ENABLED(severity) \
499 { \
500 android::base::ScopedLogSeverity sls2(android::base::severity); \
501 CapturedStderr cap2; \
502 errno = ENOENT; \
503 PLOG(severity) << "foobar"; \
504 CheckMessage(cap2, android::base::severity, "foobar: No such file or directory"); \
505 } \
506 { \
507 android::base::ScopedLogSeverity sls2(android::base::severity); \
508 CapturedStderr cap2; \
509 errno = ENOENT; \
510 PLOG(severity) << "foobar"; \
511 CheckMessage(cap2, android::base::severity, "foobar: No such file or directory"); \
512 } \
513
TEST(logging,PLOG_FATAL)514 TEST(logging, PLOG_FATAL) {
515 ASSERT_DEATH({SuppressAbortUI(); PLOG(FATAL) << "foobar";}, "foobar");
516 ASSERT_DEATH({SuppressAbortUI(); PLOG(::android::base::FATAL) << "foobar";}, "foobar");
517 }
518
TEST(logging,PLOG_FATAL_WITHOUT_ABORT_enabled)519 TEST(logging, PLOG_FATAL_WITHOUT_ABORT_enabled) {
520 ASSERT_NO_FATAL_FAILURE(CHECK_PLOG_ENABLED(FATAL_WITHOUT_ABORT));
521 }
522
TEST(logging,PLOG_ERROR_disabled)523 TEST(logging, PLOG_ERROR_disabled) {
524 CHECK_PLOG_DISABLED(ERROR);
525 }
526
TEST(logging,PLOG_ERROR_enabled)527 TEST(logging, PLOG_ERROR_enabled) {
528 ASSERT_NO_FATAL_FAILURE(CHECK_PLOG_ENABLED(ERROR));
529 }
530
TEST(logging,PLOG_WARNING_disabled)531 TEST(logging, PLOG_WARNING_disabled) {
532 CHECK_PLOG_DISABLED(WARNING);
533 }
534
TEST(logging,PLOG_WARNING_enabled)535 TEST(logging, PLOG_WARNING_enabled) {
536 ASSERT_NO_FATAL_FAILURE(CHECK_PLOG_ENABLED(WARNING));
537 }
538
TEST(logging,PLOG_INFO_disabled)539 TEST(logging, PLOG_INFO_disabled) {
540 CHECK_PLOG_DISABLED(INFO);
541 }
542
TEST(logging,PLOG_INFO_enabled)543 TEST(logging, PLOG_INFO_enabled) {
544 ASSERT_NO_FATAL_FAILURE(CHECK_PLOG_ENABLED(INFO));
545 }
546
TEST(logging,PLOG_DEBUG_disabled)547 TEST(logging, PLOG_DEBUG_disabled) {
548 CHECK_PLOG_DISABLED(DEBUG);
549 }
550
TEST(logging,PLOG_DEBUG_enabled)551 TEST(logging, PLOG_DEBUG_enabled) {
552 ASSERT_NO_FATAL_FAILURE(CHECK_PLOG_ENABLED(DEBUG));
553 }
554
TEST(logging,PLOG_VERBOSE_disabled)555 TEST(logging, PLOG_VERBOSE_disabled) {
556 CHECK_PLOG_DISABLED(VERBOSE);
557 }
558
TEST(logging,PLOG_VERBOSE_enabled)559 TEST(logging, PLOG_VERBOSE_enabled) {
560 ASSERT_NO_FATAL_FAILURE(CHECK_PLOG_ENABLED(VERBOSE));
561 }
562
563 #undef CHECK_PLOG_DISABLED
564 #undef CHECK_PLOG_ENABLED
565
566
TEST(logging,UNIMPLEMENTED)567 TEST(logging, UNIMPLEMENTED) {
568 std::string expected = android::base::StringPrintf("%s unimplemented ", __PRETTY_FUNCTION__);
569
570 CapturedStderr cap;
571 errno = ENOENT;
572 UNIMPLEMENTED(ERROR);
573 ASSERT_NO_FATAL_FAILURE(CheckMessage(cap, android::base::ERROR, expected.c_str()));
574 }
575
NoopAborter(const char * msg ATTRIBUTE_UNUSED)576 static void NoopAborter(const char* msg ATTRIBUTE_UNUSED) {
577 LOG(ERROR) << "called noop";
578 }
579
TEST(logging,LOG_FATAL_NOOP_ABORTER)580 TEST(logging, LOG_FATAL_NOOP_ABORTER) {
581 CapturedStderr cap;
582 {
583 android::base::SetAborter(NoopAborter);
584
585 android::base::ScopedLogSeverity sls(android::base::ERROR);
586 LOG(FATAL) << "foobar";
587 cap.Stop();
588
589 android::base::SetAborter(android::base::DefaultAborter);
590 }
591 std::string output = cap.str();
592 ASSERT_NO_FATAL_FAILURE(CheckMessage(output, android::base::FATAL, "foobar"));
593 ASSERT_NO_FATAL_FAILURE(CheckMessage(output, android::base::ERROR, "called noop"));
594
595 ASSERT_DEATH({SuppressAbortUI(); LOG(FATAL) << "foobar";}, "foobar");
596 }
597
598 struct CountLineAborter {
CountLineAborterFunctionCountLineAborter599 static void CountLineAborterFunction(const char* msg) {
600 while (*msg != 0) {
601 if (*msg == '\n') {
602 newline_count++;
603 }
604 msg++;
605 }
606 }
607 static size_t newline_count;
608 };
609 size_t CountLineAborter::newline_count = 0;
610
TEST(logging,LOG_FATAL_ABORTER_MESSAGE)611 TEST(logging, LOG_FATAL_ABORTER_MESSAGE) {
612 CountLineAborter::newline_count = 0;
613 android::base::SetAborter(CountLineAborter::CountLineAborterFunction);
614
615 android::base::ScopedLogSeverity sls(android::base::ERROR);
616 CapturedStderr cap;
617 LOG(FATAL) << "foo\nbar";
618
619 EXPECT_EQ(CountLineAborter::newline_count, 1U);
620 }
621
TestLoggingInConstructor()622 __attribute__((constructor)) void TestLoggingInConstructor() {
623 LOG(ERROR) << "foobar";
624 }
625
TEST(logging,StdioLogger)626 TEST(logging, StdioLogger) {
627 CapturedStderr cap_err;
628 CapturedStdout cap_out;
629 android::base::SetLogger(android::base::StdioLogger);
630 LOG(INFO) << "out";
631 LOG(ERROR) << "err";
632 cap_err.Stop();
633 cap_out.Stop();
634
635 // For INFO we expect just the literal "out\n".
636 ASSERT_EQ("out\n", cap_out.str());
637 // Whereas ERROR logging includes the program name.
638 ASSERT_EQ(android::base::Basename(android::base::GetExecutablePath()) + ": err\n", cap_err.str());
639 }
640
TEST(logging,ForkSafe)641 TEST(logging, ForkSafe) {
642 #if !defined(_WIN32)
643 using namespace android::base;
644 SetLogger(
645 [&](LogId, LogSeverity, const char*, const char*, unsigned int, const char*) { sleep(3); });
646
647 auto guard = make_scope_guard([&] {
648 #ifdef __ANDROID__
649 SetLogger(LogdLogger());
650 #else
651 SetLogger(StderrLogger);
652 #endif
653 });
654
655 auto thread = std::thread([] {
656 LOG(ERROR) << "This should sleep for 3 seconds, long enough to fork another process, if there "
657 "is no intervention";
658 });
659 thread.detach();
660
661 auto pid = fork();
662 ASSERT_NE(-1, pid);
663
664 if (pid == 0) {
665 // Reset the logger, so the next message doesn't sleep().
666 SetLogger([](LogId, LogSeverity, const char*, const char*, unsigned int, const char*) {});
667 LOG(ERROR) << "This should succeed in the child, only if libbase is forksafe.";
668 _exit(EXIT_SUCCESS);
669 }
670
671 // Wait for up to 3 seconds for the child to exit.
672 int tries = 3;
673 bool found_child = false;
674 while (tries-- > 0) {
675 auto result = waitpid(pid, nullptr, WNOHANG);
676 EXPECT_NE(-1, result);
677 if (result == pid) {
678 found_child = true;
679 break;
680 }
681 sleep(1);
682 }
683
684 EXPECT_TRUE(found_child);
685
686 // Kill the child if it did not exit.
687 if (!found_child) {
688 kill(pid, SIGKILL);
689 }
690 #endif
691 }
692