blob: 593e2c100a79c5677654008a6417dae51da4a0cd [file] [log] [blame]
Dan Albert58310b42015-03-13 23:06:01 -07001/*
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
Elliott Hughes4f713192015-12-04 22:00:26 -080017#include "android-base/logging.h"
Dan Albert58310b42015-03-13 23:06:01 -070018
Elliott Hughes2e5ae002015-08-13 20:09:29 -070019#include <libgen.h>
20
Spencer Low765ae6b2015-09-17 19:36:10 -070021#if defined(_WIN32)
22#include <signal.h>
23#endif
24
Dan Albert58310b42015-03-13 23:06:01 -070025#include <regex>
26#include <string>
Tom Cherry953c0de2020-04-17 13:05:11 -070027#include <thread>
Dan Albert58310b42015-03-13 23:06:01 -070028
Elliott Hughes4f713192015-12-04 22:00:26 -080029#include "android-base/file.h"
Tom Cherry953c0de2020-04-17 13:05:11 -070030#include "android-base/scopeguard.h"
Elliott Hughes4f713192015-12-04 22:00:26 -080031#include "android-base/stringprintf.h"
32#include "android-base/test_utils.h"
Dan Albert58310b42015-03-13 23:06:01 -070033
34#include <gtest/gtest.h>
35
36#ifdef __ANDROID__
37#define HOST_TEST(suite, name) TEST(suite, DISABLED_ ## name)
38#else
39#define HOST_TEST(suite, name) TEST(suite, name)
40#endif
41
Spencer Low765ae6b2015-09-17 19:36:10 -070042#if defined(_WIN32)
43static void ExitSignalAbortHandler(int) {
44 _exit(3);
45}
46#endif
47
48static void SuppressAbortUI() {
49#if defined(_WIN32)
50 // We really just want to call _set_abort_behavior(0, _CALL_REPORTFAULT) to
51 // suppress the Windows Error Reporting dialog box, but that API is not
52 // available in the OS-supplied C Runtime, msvcrt.dll, that we currently
53 // use (it is available in the Visual Studio C runtime).
54 //
55 // Instead, we setup a SIGABRT handler, which is called in abort() right
56 // before calling Windows Error Reporting. In the handler, we exit the
57 // process just like abort() does.
58 ASSERT_NE(SIG_ERR, signal(SIGABRT, ExitSignalAbortHandler));
59#endif
60}
61
Dan Albertb547c852015-03-27 11:20:14 -070062TEST(logging, CHECK) {
Spencer Low765ae6b2015-09-17 19:36:10 -070063 ASSERT_DEATH({SuppressAbortUI(); CHECK(false);}, "Check failed: false ");
Dan Albert58310b42015-03-13 23:06:01 -070064 CHECK(true);
65
Spencer Low765ae6b2015-09-17 19:36:10 -070066 ASSERT_DEATH({SuppressAbortUI(); CHECK_EQ(0, 1);}, "Check failed: 0 == 1 ");
Dan Albert58310b42015-03-13 23:06:01 -070067 CHECK_EQ(0, 0);
68
Spencer Low765ae6b2015-09-17 19:36:10 -070069 ASSERT_DEATH({SuppressAbortUI(); CHECK_STREQ("foo", "bar");},
70 R"(Check failed: "foo" == "bar")");
Dan Albert58310b42015-03-13 23:06:01 -070071 CHECK_STREQ("foo", "foo");
Spencer Low765ae6b2015-09-17 19:36:10 -070072
73 // Test whether CHECK() and CHECK_STREQ() have a dangling if with no else.
74 bool flag = false;
75 if (true)
76 CHECK(true);
77 else
78 flag = true;
79 EXPECT_FALSE(flag) << "CHECK macro probably has a dangling if with no else";
80
81 flag = false;
82 if (true)
83 CHECK_STREQ("foo", "foo");
84 else
85 flag = true;
86 EXPECT_FALSE(flag) << "CHECK_STREQ probably has a dangling if with no else";
Dan Albert58310b42015-03-13 23:06:01 -070087}
88
Andreas Gamped8f26e22016-09-13 10:44:46 -070089TEST(logging, DCHECK) {
90 if (android::base::kEnableDChecks) {
91 ASSERT_DEATH({SuppressAbortUI(); DCHECK(false);}, "DCheck failed: false ");
92 }
93 DCHECK(true);
94
95 if (android::base::kEnableDChecks) {
96 ASSERT_DEATH({SuppressAbortUI(); DCHECK_EQ(0, 1);}, "DCheck failed: 0 == 1 ");
97 }
98 DCHECK_EQ(0, 0);
99
100 if (android::base::kEnableDChecks) {
101 ASSERT_DEATH({SuppressAbortUI(); DCHECK_STREQ("foo", "bar");},
102 R"(DCheck failed: "foo" == "bar")");
103 }
104 DCHECK_STREQ("foo", "foo");
105
106 // No testing whether we have a dangling else, possibly. That's inherent to the if (constexpr)
107 // setup we intentionally chose to force type-checks of debug code even in release builds (so
108 // we don't get more bit-rot).
109}
110
Andreas Gampe436f5a02016-09-22 10:15:01 -0700111
Andreas Gampe1f5fb432016-09-23 16:37:12 -0700112#define CHECK_WOULD_LOG_DISABLED(severity) \
113 static_assert(android::base::severity < android::base::FATAL, "Bad input"); \
114 for (size_t i = static_cast<size_t>(android::base::severity) + 1; \
115 i <= static_cast<size_t>(android::base::FATAL); \
116 ++i) { \
117 { \
118 android::base::ScopedLogSeverity sls2(static_cast<android::base::LogSeverity>(i)); \
119 EXPECT_FALSE(WOULD_LOG(severity)) << i; \
120 } \
121 { \
122 android::base::ScopedLogSeverity sls2(static_cast<android::base::LogSeverity>(i)); \
123 EXPECT_FALSE(WOULD_LOG(::android::base::severity)) << i; \
124 } \
125 } \
126
127#define CHECK_WOULD_LOG_ENABLED(severity) \
128 for (size_t i = static_cast<size_t>(android::base::VERBOSE); \
129 i <= static_cast<size_t>(android::base::severity); \
130 ++i) { \
131 { \
132 android::base::ScopedLogSeverity sls2(static_cast<android::base::LogSeverity>(i)); \
133 EXPECT_TRUE(WOULD_LOG(severity)) << i; \
134 } \
135 { \
136 android::base::ScopedLogSeverity sls2(static_cast<android::base::LogSeverity>(i)); \
137 EXPECT_TRUE(WOULD_LOG(::android::base::severity)) << i; \
138 } \
139 } \
Andreas Gampe436f5a02016-09-22 10:15:01 -0700140
141TEST(logging, WOULD_LOG_FATAL) {
142 CHECK_WOULD_LOG_ENABLED(FATAL);
143}
144
Andreas Gampe436f5a02016-09-22 10:15:01 -0700145TEST(logging, WOULD_LOG_FATAL_WITHOUT_ABORT_enabled) {
146 CHECK_WOULD_LOG_ENABLED(FATAL_WITHOUT_ABORT);
147}
148
149TEST(logging, WOULD_LOG_ERROR_disabled) {
150 CHECK_WOULD_LOG_DISABLED(ERROR);
151}
152
153TEST(logging, WOULD_LOG_ERROR_enabled) {
154 CHECK_WOULD_LOG_ENABLED(ERROR);
155}
156
157TEST(logging, WOULD_LOG_WARNING_disabled) {
158 CHECK_WOULD_LOG_DISABLED(WARNING);
159}
160
161TEST(logging, WOULD_LOG_WARNING_enabled) {
162 CHECK_WOULD_LOG_ENABLED(WARNING);
163}
164
165TEST(logging, WOULD_LOG_INFO_disabled) {
166 CHECK_WOULD_LOG_DISABLED(INFO);
167}
168
169TEST(logging, WOULD_LOG_INFO_enabled) {
170 CHECK_WOULD_LOG_ENABLED(INFO);
171}
172
173TEST(logging, WOULD_LOG_DEBUG_disabled) {
174 CHECK_WOULD_LOG_DISABLED(DEBUG);
175}
176
177TEST(logging, WOULD_LOG_DEBUG_enabled) {
178 CHECK_WOULD_LOG_ENABLED(DEBUG);
179}
180
181TEST(logging, WOULD_LOG_VERBOSE_disabled) {
182 CHECK_WOULD_LOG_DISABLED(VERBOSE);
183}
184
185TEST(logging, WOULD_LOG_VERBOSE_enabled) {
186 CHECK_WOULD_LOG_ENABLED(VERBOSE);
187}
188
189#undef CHECK_WOULD_LOG_DISABLED
190#undef CHECK_WOULD_LOG_ENABLED
191
192
Dan Willemsen528f1442017-11-29 18:06:11 -0800193#if !defined(_WIN32)
Elliott Hughes13d78e42016-09-07 16:22:40 -0700194static std::string make_log_pattern(android::base::LogSeverity severity,
195 const char* message) {
Andreas Gampe550829d2016-09-07 10:10:50 -0700196 static const char log_characters[] = "VDIWEFF";
197 static_assert(arraysize(log_characters) - 1 == android::base::FATAL + 1,
198 "Mismatch in size of log_characters and values in LogSeverity");
Dan Albert58310b42015-03-13 23:06:01 -0700199 char log_char = log_characters[severity];
Spencer Lowbdab59a2015-08-11 16:00:13 -0700200 std::string holder(__FILE__);
Dan Albert58310b42015-03-13 23:06:01 -0700201 return android::base::StringPrintf(
Elliott Hughes13d78e42016-09-07 16:22:40 -0700202 "%c \\d+-\\d+ \\d+:\\d+:\\d+ \\s*\\d+ \\s*\\d+ %s:\\d+] %s",
Spencer Lowbdab59a2015-08-11 16:00:13 -0700203 log_char, basename(&holder[0]), message);
Dan Albert58310b42015-03-13 23:06:01 -0700204}
Dan Willemsen528f1442017-11-29 18:06:11 -0800205#endif
Dan Albert58310b42015-03-13 23:06:01 -0700206
Christopher Ferriseea85c92018-08-30 13:31:45 -0700207static void CheckMessage(const std::string& output, android::base::LogSeverity severity,
Andreas Gampe1923e762018-03-05 10:00:19 -0800208 const char* expected, const char* expected_tag = nullptr) {
Dan Albert5c190402015-04-29 11:32:23 -0700209 // We can't usefully check the output of any of these on Windows because we
210 // don't have std::regex, but we can at least make sure we printed at least as
211 // many characters are in the log message.
Elliott Hughes13d78e42016-09-07 16:22:40 -0700212 ASSERT_GT(output.length(), strlen(expected));
213 ASSERT_NE(nullptr, strstr(output.c_str(), expected)) << output;
Andreas Gampe1923e762018-03-05 10:00:19 -0800214 if (expected_tag != nullptr) {
215 ASSERT_NE(nullptr, strstr(output.c_str(), expected_tag)) << output;
216 }
Dan Albert58310b42015-03-13 23:06:01 -0700217
Dan Albert5c190402015-04-29 11:32:23 -0700218#if !defined(_WIN32)
Andreas Gampe1923e762018-03-05 10:00:19 -0800219 std::string regex_str;
220 if (expected_tag != nullptr) {
221 regex_str.append(expected_tag);
222 regex_str.append(" ");
223 }
224 regex_str.append(make_log_pattern(severity, expected));
225 std::regex message_regex(regex_str);
Elliott Hughes13d78e42016-09-07 16:22:40 -0700226 ASSERT_TRUE(std::regex_search(output, message_regex)) << output;
Dan Albert5c190402015-04-29 11:32:23 -0700227#endif
Dan Albert58310b42015-03-13 23:06:01 -0700228}
229
Christopher Ferriseea85c92018-08-30 13:31:45 -0700230static void CheckMessage(CapturedStderr& cap, android::base::LogSeverity severity,
231 const char* expected, const char* expected_tag = nullptr) {
232 cap.Stop();
233 std::string output = cap.str();
234 return CheckMessage(output, severity, expected, expected_tag);
235}
Andreas Gampe1f5fb432016-09-23 16:37:12 -0700236
Christopher Ferriseea85c92018-08-30 13:31:45 -0700237#define CHECK_LOG_STREAM_DISABLED(severity) \
238 { \
Andreas Gampe1f5fb432016-09-23 16:37:12 -0700239 android::base::ScopedLogSeverity sls1(android::base::FATAL); \
Christopher Ferriseea85c92018-08-30 13:31:45 -0700240 CapturedStderr cap1; \
241 LOG_STREAM(severity) << "foo bar"; \
242 cap1.Stop(); \
243 ASSERT_EQ("", cap1.str()); \
244 } \
245 { \
Andreas Gampe1f5fb432016-09-23 16:37:12 -0700246 android::base::ScopedLogSeverity sls1(android::base::FATAL); \
Christopher Ferriseea85c92018-08-30 13:31:45 -0700247 CapturedStderr cap1; \
248 LOG_STREAM(::android::base::severity) << "foo bar"; \
249 cap1.Stop(); \
250 ASSERT_EQ("", cap1.str()); \
251 }
Andreas Gampe19ff8f12016-09-23 13:31:52 -0700252
253#define CHECK_LOG_STREAM_ENABLED(severity) \
Andreas Gampe1f5fb432016-09-23 16:37:12 -0700254 { \
255 android::base::ScopedLogSeverity sls2(android::base::severity); \
256 CapturedStderr cap2; \
257 LOG_STREAM(severity) << "foobar"; \
258 CheckMessage(cap2, android::base::severity, "foobar"); \
259 } \
260 { \
261 android::base::ScopedLogSeverity sls2(android::base::severity); \
262 CapturedStderr cap2; \
263 LOG_STREAM(::android::base::severity) << "foobar"; \
264 CheckMessage(cap2, android::base::severity, "foobar"); \
265 } \
Andreas Gampe436f5a02016-09-22 10:15:01 -0700266
Andreas Gampe19ff8f12016-09-23 13:31:52 -0700267TEST(logging, LOG_STREAM_FATAL_WITHOUT_ABORT_enabled) {
Christopher Ferriseea85c92018-08-30 13:31:45 -0700268 ASSERT_NO_FATAL_FAILURE(CHECK_LOG_STREAM_ENABLED(FATAL_WITHOUT_ABORT));
Andreas Gampe436f5a02016-09-22 10:15:01 -0700269}
270
Andreas Gampe19ff8f12016-09-23 13:31:52 -0700271TEST(logging, LOG_STREAM_ERROR_disabled) {
272 CHECK_LOG_STREAM_DISABLED(ERROR);
Andreas Gampe436f5a02016-09-22 10:15:01 -0700273}
274
Andreas Gampe19ff8f12016-09-23 13:31:52 -0700275TEST(logging, LOG_STREAM_ERROR_enabled) {
Christopher Ferriseea85c92018-08-30 13:31:45 -0700276 ASSERT_NO_FATAL_FAILURE(CHECK_LOG_STREAM_ENABLED(ERROR));
Andreas Gampe436f5a02016-09-22 10:15:01 -0700277}
278
Andreas Gampe19ff8f12016-09-23 13:31:52 -0700279TEST(logging, LOG_STREAM_WARNING_disabled) {
280 CHECK_LOG_STREAM_DISABLED(WARNING);
Andreas Gampe436f5a02016-09-22 10:15:01 -0700281}
282
Andreas Gampe19ff8f12016-09-23 13:31:52 -0700283TEST(logging, LOG_STREAM_WARNING_enabled) {
Christopher Ferriseea85c92018-08-30 13:31:45 -0700284 ASSERT_NO_FATAL_FAILURE(CHECK_LOG_STREAM_ENABLED(WARNING));
Andreas Gampe436f5a02016-09-22 10:15:01 -0700285}
286
Andreas Gampe19ff8f12016-09-23 13:31:52 -0700287TEST(logging, LOG_STREAM_INFO_disabled) {
288 CHECK_LOG_STREAM_DISABLED(INFO);
289}
Andreas Gampe436f5a02016-09-22 10:15:01 -0700290
Andreas Gampe19ff8f12016-09-23 13:31:52 -0700291TEST(logging, LOG_STREAM_INFO_enabled) {
Christopher Ferriseea85c92018-08-30 13:31:45 -0700292 ASSERT_NO_FATAL_FAILURE(CHECK_LOG_STREAM_ENABLED(INFO));
Andreas Gampe19ff8f12016-09-23 13:31:52 -0700293}
294
295TEST(logging, LOG_STREAM_DEBUG_disabled) {
296 CHECK_LOG_STREAM_DISABLED(DEBUG);
297}
298
299TEST(logging, LOG_STREAM_DEBUG_enabled) {
Christopher Ferriseea85c92018-08-30 13:31:45 -0700300 ASSERT_NO_FATAL_FAILURE(CHECK_LOG_STREAM_ENABLED(DEBUG));
Andreas Gampe19ff8f12016-09-23 13:31:52 -0700301}
302
303TEST(logging, LOG_STREAM_VERBOSE_disabled) {
304 CHECK_LOG_STREAM_DISABLED(VERBOSE);
305}
306
307TEST(logging, LOG_STREAM_VERBOSE_enabled) {
Christopher Ferriseea85c92018-08-30 13:31:45 -0700308 ASSERT_NO_FATAL_FAILURE(CHECK_LOG_STREAM_ENABLED(VERBOSE));
Andreas Gampe19ff8f12016-09-23 13:31:52 -0700309}
310
311#undef CHECK_LOG_STREAM_DISABLED
312#undef CHECK_LOG_STREAM_ENABLED
313
Christopher Ferriseea85c92018-08-30 13:31:45 -0700314#define CHECK_LOG_DISABLED(severity) \
315 { \
Andreas Gampe1f5fb432016-09-23 16:37:12 -0700316 android::base::ScopedLogSeverity sls1(android::base::FATAL); \
Christopher Ferriseea85c92018-08-30 13:31:45 -0700317 CapturedStderr cap1; \
318 LOG(severity) << "foo bar"; \
319 cap1.Stop(); \
320 ASSERT_EQ("", cap1.str()); \
321 } \
322 { \
Andreas Gampe1f5fb432016-09-23 16:37:12 -0700323 android::base::ScopedLogSeverity sls1(android::base::FATAL); \
Christopher Ferriseea85c92018-08-30 13:31:45 -0700324 CapturedStderr cap1; \
325 LOG(::android::base::severity) << "foo bar"; \
326 cap1.Stop(); \
327 ASSERT_EQ("", cap1.str()); \
328 }
Andreas Gampe436f5a02016-09-22 10:15:01 -0700329
330#define CHECK_LOG_ENABLED(severity) \
Andreas Gampe1f5fb432016-09-23 16:37:12 -0700331 { \
332 android::base::ScopedLogSeverity sls2(android::base::severity); \
333 CapturedStderr cap2; \
334 LOG(severity) << "foobar"; \
335 CheckMessage(cap2, android::base::severity, "foobar"); \
336 } \
337 { \
338 android::base::ScopedLogSeverity sls2(android::base::severity); \
339 CapturedStderr cap2; \
340 LOG(::android::base::severity) << "foobar"; \
341 CheckMessage(cap2, android::base::severity, "foobar"); \
342 } \
Andreas Gampe436f5a02016-09-22 10:15:01 -0700343
Elliott Hughes13d78e42016-09-07 16:22:40 -0700344TEST(logging, LOG_FATAL) {
345 ASSERT_DEATH({SuppressAbortUI(); LOG(FATAL) << "foobar";}, "foobar");
Andreas Gampe1f5fb432016-09-23 16:37:12 -0700346 ASSERT_DEATH({SuppressAbortUI(); LOG(::android::base::FATAL) << "foobar";}, "foobar");
Elliott Hughes13d78e42016-09-07 16:22:40 -0700347}
Dan Albert58310b42015-03-13 23:06:01 -0700348
Andreas Gampe550829d2016-09-07 10:10:50 -0700349TEST(logging, LOG_FATAL_WITHOUT_ABORT_enabled) {
Christopher Ferriseea85c92018-08-30 13:31:45 -0700350 ASSERT_NO_FATAL_FAILURE(CHECK_LOG_ENABLED(FATAL_WITHOUT_ABORT));
Andreas Gampe550829d2016-09-07 10:10:50 -0700351}
352
Elliott Hughes13d78e42016-09-07 16:22:40 -0700353TEST(logging, LOG_ERROR_disabled) {
354 CHECK_LOG_DISABLED(ERROR);
355}
Dan Albert58310b42015-03-13 23:06:01 -0700356
Elliott Hughes13d78e42016-09-07 16:22:40 -0700357TEST(logging, LOG_ERROR_enabled) {
Christopher Ferriseea85c92018-08-30 13:31:45 -0700358 ASSERT_NO_FATAL_FAILURE(CHECK_LOG_ENABLED(ERROR));
Elliott Hughes13d78e42016-09-07 16:22:40 -0700359}
360
361TEST(logging, LOG_WARNING_disabled) {
362 CHECK_LOG_DISABLED(WARNING);
363}
364
365TEST(logging, LOG_WARNING_enabled) {
Christopher Ferriseea85c92018-08-30 13:31:45 -0700366 ASSERT_NO_FATAL_FAILURE(CHECK_LOG_ENABLED(WARNING));
Elliott Hughes13d78e42016-09-07 16:22:40 -0700367}
368
369TEST(logging, LOG_INFO_disabled) {
370 CHECK_LOG_DISABLED(INFO);
371}
372
373TEST(logging, LOG_INFO_enabled) {
Christopher Ferriseea85c92018-08-30 13:31:45 -0700374 ASSERT_NO_FATAL_FAILURE(CHECK_LOG_ENABLED(INFO));
Elliott Hughes13d78e42016-09-07 16:22:40 -0700375}
376
377TEST(logging, LOG_DEBUG_disabled) {
378 CHECK_LOG_DISABLED(DEBUG);
379}
380
381TEST(logging, LOG_DEBUG_enabled) {
Christopher Ferriseea85c92018-08-30 13:31:45 -0700382 ASSERT_NO_FATAL_FAILURE(CHECK_LOG_ENABLED(DEBUG));
Elliott Hughes13d78e42016-09-07 16:22:40 -0700383}
384
385TEST(logging, LOG_VERBOSE_disabled) {
386 CHECK_LOG_DISABLED(VERBOSE);
387}
388
389TEST(logging, LOG_VERBOSE_enabled) {
Christopher Ferriseea85c92018-08-30 13:31:45 -0700390 ASSERT_NO_FATAL_FAILURE(CHECK_LOG_ENABLED(VERBOSE));
Elliott Hughes13d78e42016-09-07 16:22:40 -0700391}
392
Andreas Gampe436f5a02016-09-22 10:15:01 -0700393#undef CHECK_LOG_DISABLED
394#undef CHECK_LOG_ENABLED
395
Andreas Gampe1f5fb432016-09-23 16:37:12 -0700396TEST(logging, LOG_complex_param) {
Christopher Ferriseea85c92018-08-30 13:31:45 -0700397#define CHECK_LOG_COMBINATION(use_scoped_log_severity_info, use_logging_severity_info) \
398 { \
399 android::base::ScopedLogSeverity sls( \
400 (use_scoped_log_severity_info) ? ::android::base::INFO : ::android::base::WARNING); \
401 CapturedStderr cap; \
402 LOG((use_logging_severity_info) ? ::android::base::INFO : ::android::base::WARNING) \
403 << "foobar"; \
404 if ((use_scoped_log_severity_info) || !(use_logging_severity_info)) { \
405 ASSERT_NO_FATAL_FAILURE(CheckMessage( \
406 cap, (use_logging_severity_info) ? ::android::base::INFO : ::android::base::WARNING, \
407 "foobar")); \
408 } else { \
409 cap.Stop(); \
410 ASSERT_EQ("", cap.str()); \
411 } \
Andreas Gampe436f5a02016-09-22 10:15:01 -0700412 }
413
Andreas Gampe1f5fb432016-09-23 16:37:12 -0700414 CHECK_LOG_COMBINATION(false,false);
415 CHECK_LOG_COMBINATION(false,true);
416 CHECK_LOG_COMBINATION(true,false);
417 CHECK_LOG_COMBINATION(true,true);
Andreas Gampe436f5a02016-09-22 10:15:01 -0700418
Andreas Gampe1f5fb432016-09-23 16:37:12 -0700419#undef CHECK_LOG_COMBINATION
Andreas Gampe436f5a02016-09-22 10:15:01 -0700420}
421
422
Elliott Hughes13d78e42016-09-07 16:22:40 -0700423TEST(logging, LOG_does_not_clobber_errno) {
424 CapturedStderr cap;
425 errno = 12345;
426 LOG(INFO) << (errno = 67890);
427 EXPECT_EQ(12345, errno) << "errno was not restored";
428
Christopher Ferriseea85c92018-08-30 13:31:45 -0700429 ASSERT_NO_FATAL_FAILURE(CheckMessage(cap, android::base::INFO, "67890"));
Elliott Hughes13d78e42016-09-07 16:22:40 -0700430}
431
432TEST(logging, PLOG_does_not_clobber_errno) {
433 CapturedStderr cap;
434 errno = 12345;
435 PLOG(INFO) << (errno = 67890);
436 EXPECT_EQ(12345, errno) << "errno was not restored";
437
Christopher Ferriseea85c92018-08-30 13:31:45 -0700438 ASSERT_NO_FATAL_FAILURE(CheckMessage(cap, android::base::INFO, "67890"));
Elliott Hughes13d78e42016-09-07 16:22:40 -0700439}
440
441TEST(logging, LOG_does_not_have_dangling_if) {
442 CapturedStderr cap; // So the logging below has no side-effects.
443
444 // Do the test two ways: once where we hypothesize that LOG()'s if
445 // will evaluate to true (when severity is high enough) and once when we
446 // expect it to evaluate to false (when severity is not high enough).
447 bool flag = false;
448 if (true)
449 LOG(INFO) << "foobar";
450 else
451 flag = true;
452
453 EXPECT_FALSE(flag) << "LOG macro probably has a dangling if with no else";
454
455 flag = false;
456 if (true)
457 LOG(VERBOSE) << "foobar";
458 else
459 flag = true;
460
461 EXPECT_FALSE(flag) << "LOG macro probably has a dangling if with no else";
Andreas Gampe436f5a02016-09-22 10:15:01 -0700462}
Elliott Hughes13d78e42016-09-07 16:22:40 -0700463
Christopher Ferriseea85c92018-08-30 13:31:45 -0700464#define CHECK_PLOG_DISABLED(severity) \
465 { \
Andreas Gampe1f5fb432016-09-23 16:37:12 -0700466 android::base::ScopedLogSeverity sls1(android::base::FATAL); \
Christopher Ferriseea85c92018-08-30 13:31:45 -0700467 CapturedStderr cap1; \
468 PLOG(severity) << "foo bar"; \
469 cap1.Stop(); \
470 ASSERT_EQ("", cap1.str()); \
471 } \
472 { \
Andreas Gampe1f5fb432016-09-23 16:37:12 -0700473 android::base::ScopedLogSeverity sls1(android::base::FATAL); \
Christopher Ferriseea85c92018-08-30 13:31:45 -0700474 CapturedStderr cap1; \
475 PLOG(severity) << "foo bar"; \
476 cap1.Stop(); \
477 ASSERT_EQ("", cap1.str()); \
478 }
Elliott Hughes13d78e42016-09-07 16:22:40 -0700479
480#define CHECK_PLOG_ENABLED(severity) \
Andreas Gampe1f5fb432016-09-23 16:37:12 -0700481 { \
482 android::base::ScopedLogSeverity sls2(android::base::severity); \
483 CapturedStderr cap2; \
484 errno = ENOENT; \
485 PLOG(severity) << "foobar"; \
486 CheckMessage(cap2, android::base::severity, "foobar: No such file or directory"); \
487 } \
488 { \
489 android::base::ScopedLogSeverity sls2(android::base::severity); \
490 CapturedStderr cap2; \
491 errno = ENOENT; \
492 PLOG(severity) << "foobar"; \
493 CheckMessage(cap2, android::base::severity, "foobar: No such file or directory"); \
494 } \
Elliott Hughes13d78e42016-09-07 16:22:40 -0700495
Andreas Gampe550829d2016-09-07 10:10:50 -0700496TEST(logging, PLOG_FATAL) {
497 ASSERT_DEATH({SuppressAbortUI(); PLOG(FATAL) << "foobar";}, "foobar");
Andreas Gampe1f5fb432016-09-23 16:37:12 -0700498 ASSERT_DEATH({SuppressAbortUI(); PLOG(::android::base::FATAL) << "foobar";}, "foobar");
Andreas Gampe550829d2016-09-07 10:10:50 -0700499}
500
Andreas Gampe550829d2016-09-07 10:10:50 -0700501TEST(logging, PLOG_FATAL_WITHOUT_ABORT_enabled) {
Christopher Ferriseea85c92018-08-30 13:31:45 -0700502 ASSERT_NO_FATAL_FAILURE(CHECK_PLOG_ENABLED(FATAL_WITHOUT_ABORT));
Andreas Gampe550829d2016-09-07 10:10:50 -0700503}
504
Elliott Hughes13d78e42016-09-07 16:22:40 -0700505TEST(logging, PLOG_ERROR_disabled) {
506 CHECK_PLOG_DISABLED(ERROR);
507}
508
509TEST(logging, PLOG_ERROR_enabled) {
Christopher Ferriseea85c92018-08-30 13:31:45 -0700510 ASSERT_NO_FATAL_FAILURE(CHECK_PLOG_ENABLED(ERROR));
Elliott Hughes13d78e42016-09-07 16:22:40 -0700511}
512
513TEST(logging, PLOG_WARNING_disabled) {
514 CHECK_PLOG_DISABLED(WARNING);
515}
516
517TEST(logging, PLOG_WARNING_enabled) {
Christopher Ferriseea85c92018-08-30 13:31:45 -0700518 ASSERT_NO_FATAL_FAILURE(CHECK_PLOG_ENABLED(WARNING));
Elliott Hughes13d78e42016-09-07 16:22:40 -0700519}
520
521TEST(logging, PLOG_INFO_disabled) {
522 CHECK_PLOG_DISABLED(INFO);
523}
524
525TEST(logging, PLOG_INFO_enabled) {
Christopher Ferriseea85c92018-08-30 13:31:45 -0700526 ASSERT_NO_FATAL_FAILURE(CHECK_PLOG_ENABLED(INFO));
Elliott Hughes13d78e42016-09-07 16:22:40 -0700527}
528
529TEST(logging, PLOG_DEBUG_disabled) {
530 CHECK_PLOG_DISABLED(DEBUG);
531}
532
533TEST(logging, PLOG_DEBUG_enabled) {
Christopher Ferriseea85c92018-08-30 13:31:45 -0700534 ASSERT_NO_FATAL_FAILURE(CHECK_PLOG_ENABLED(DEBUG));
Elliott Hughes13d78e42016-09-07 16:22:40 -0700535}
536
537TEST(logging, PLOG_VERBOSE_disabled) {
538 CHECK_PLOG_DISABLED(VERBOSE);
539}
540
541TEST(logging, PLOG_VERBOSE_enabled) {
Christopher Ferriseea85c92018-08-30 13:31:45 -0700542 ASSERT_NO_FATAL_FAILURE(CHECK_PLOG_ENABLED(VERBOSE));
Dan Albert58310b42015-03-13 23:06:01 -0700543}
544
Andreas Gampe436f5a02016-09-22 10:15:01 -0700545#undef CHECK_PLOG_DISABLED
546#undef CHECK_PLOG_ENABLED
547
548
Dan Albertb547c852015-03-27 11:20:14 -0700549TEST(logging, UNIMPLEMENTED) {
Elliott Hughes13d78e42016-09-07 16:22:40 -0700550 std::string expected = android::base::StringPrintf("%s unimplemented ", __PRETTY_FUNCTION__);
Dan Albert58310b42015-03-13 23:06:01 -0700551
Elliott Hughes13d78e42016-09-07 16:22:40 -0700552 CapturedStderr cap;
553 errno = ENOENT;
554 UNIMPLEMENTED(ERROR);
Christopher Ferriseea85c92018-08-30 13:31:45 -0700555 ASSERT_NO_FATAL_FAILURE(CheckMessage(cap, android::base::ERROR, expected.c_str()));
Dan Albert58310b42015-03-13 23:06:01 -0700556}
Andreas Gampe2691e332016-09-08 11:03:58 -0700557
558static void NoopAborter(const char* msg ATTRIBUTE_UNUSED) {
559 LOG(ERROR) << "called noop";
560}
561
562TEST(logging, LOG_FATAL_NOOP_ABORTER) {
Christopher Ferriseea85c92018-08-30 13:31:45 -0700563 CapturedStderr cap;
Andreas Gampe2691e332016-09-08 11:03:58 -0700564 {
565 android::base::SetAborter(NoopAborter);
566
567 android::base::ScopedLogSeverity sls(android::base::ERROR);
Andreas Gampe2691e332016-09-08 11:03:58 -0700568 LOG(FATAL) << "foobar";
Christopher Ferriseea85c92018-08-30 13:31:45 -0700569 cap.Stop();
Andreas Gampe2691e332016-09-08 11:03:58 -0700570
571 android::base::SetAborter(android::base::DefaultAborter);
572 }
Christopher Ferriseea85c92018-08-30 13:31:45 -0700573 std::string output = cap.str();
574 ASSERT_NO_FATAL_FAILURE(CheckMessage(output, android::base::FATAL, "foobar"));
575 ASSERT_NO_FATAL_FAILURE(CheckMessage(output, android::base::ERROR, "called noop"));
Andreas Gampe2691e332016-09-08 11:03:58 -0700576
577 ASSERT_DEATH({SuppressAbortUI(); LOG(FATAL) << "foobar";}, "foobar");
578}
Andreas Gampeb4e32f32016-10-04 19:17:07 -0700579
580struct CountLineAborter {
581 static void CountLineAborterFunction(const char* msg) {
582 while (*msg != 0) {
583 if (*msg == '\n') {
584 newline_count++;
585 }
586 msg++;
587 }
588 }
589 static size_t newline_count;
590};
591size_t CountLineAborter::newline_count = 0;
592
593TEST(logging, LOG_FATAL_ABORTER_MESSAGE) {
594 CountLineAborter::newline_count = 0;
595 android::base::SetAborter(CountLineAborter::CountLineAborterFunction);
596
597 android::base::ScopedLogSeverity sls(android::base::ERROR);
598 CapturedStderr cap;
599 LOG(FATAL) << "foo\nbar";
600
Tom Cherry953c0de2020-04-17 13:05:11 -0700601 EXPECT_EQ(CountLineAborter::newline_count, 1U);
Andreas Gampeb4e32f32016-10-04 19:17:07 -0700602}
Yabin Cui0c689532017-01-23 10:29:23 -0800603
604__attribute__((constructor)) void TestLoggingInConstructor() {
605 LOG(ERROR) << "foobar";
606}
Andreas Gampe1923e762018-03-05 10:00:19 -0800607
Elliott Hughes1be0d142018-05-23 09:16:46 -0700608TEST(logging, StdioLogger) {
Christopher Ferriseea85c92018-08-30 13:31:45 -0700609 CapturedStderr cap_err;
610 CapturedStdout cap_out;
611 android::base::SetLogger(android::base::StdioLogger);
612 LOG(INFO) << "out";
613 LOG(ERROR) << "err";
614 cap_err.Stop();
615 cap_out.Stop();
Elliott Hughes1be0d142018-05-23 09:16:46 -0700616
617 // For INFO we expect just the literal "out\n".
Christopher Ferriseea85c92018-08-30 13:31:45 -0700618 ASSERT_EQ("out\n", cap_out.str());
Elliott Hughes1be0d142018-05-23 09:16:46 -0700619 // Whereas ERROR logging includes the program name.
Christopher Ferriseea85c92018-08-30 13:31:45 -0700620 ASSERT_EQ(android::base::Basename(android::base::GetExecutablePath()) + ": err\n", cap_err.str());
Elliott Hughes1be0d142018-05-23 09:16:46 -0700621}
Tom Cherry953c0de2020-04-17 13:05:11 -0700622
623TEST(logging, ForkSafe) {
624#if !defined(_WIN32)
625 using namespace android::base;
626 SetLogger(
627 [&](LogId, LogSeverity, const char*, const char*, unsigned int, const char*) { sleep(3); });
628
629 auto guard = make_scope_guard([&] {
630#ifdef __ANDROID__
631 SetLogger(LogdLogger());
632#else
633 SetLogger(StderrLogger);
634#endif
635 });
636
637 auto thread = std::thread([] {
638 LOG(ERROR) << "This should sleep for 3 seconds, long enough to fork another process, if there "
639 "is no intervention";
640 });
641 thread.detach();
642
643 auto pid = fork();
644 ASSERT_NE(-1, pid);
645
646 if (pid == 0) {
647 // Reset the logger, so the next message doesn't sleep().
648 SetLogger([](LogId, LogSeverity, const char*, const char*, unsigned int, const char*) {});
649 LOG(ERROR) << "This should succeed in the child, only if libbase is forksafe.";
650 _exit(EXIT_SUCCESS);
651 }
652
653 // Wait for up to 3 seconds for the child to exit.
654 int tries = 3;
655 bool found_child = false;
656 while (tries-- > 0) {
657 auto result = waitpid(pid, nullptr, WNOHANG);
658 EXPECT_NE(-1, result);
659 if (result == pid) {
660 found_child = true;
661 break;
662 }
663 sleep(1);
664 }
665
666 EXPECT_TRUE(found_child);
667
668 // Kill the child if it did not exit.
669 if (!found_child) {
670 kill(pid, SIGKILL);
671 }
672#endif
673}