blob: be2e042ede9738aa86cd31b24414aae07e268963 [file] [log] [blame]
Dan Alberte3ea0582015-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 Hughesb6351622015-12-04 22:00:26 -080017#include "android-base/logging.h"
Dan Alberte3ea0582015-03-13 23:06:01 -070018
Elliott Hughes4d4e90f2015-08-13 20:09:29 -070019#include <libgen.h>
20
Spencer Lowe0671d62015-09-17 19:36:10 -070021#if defined(_WIN32)
22#include <signal.h>
23#endif
24
Krzysztof Kosiński62164882020-06-20 04:20:37 -070025#include <memory>
Dan Alberte3ea0582015-03-13 23:06:01 -070026#include <regex>
27#include <string>
Tom Cherrya6872422020-04-17 13:05:11 -070028#include <thread>
Dan Alberte3ea0582015-03-13 23:06:01 -070029
Elliott Hughesb6351622015-12-04 22:00:26 -080030#include "android-base/file.h"
Tom Cherrya6872422020-04-17 13:05:11 -070031#include "android-base/scopeguard.h"
Elliott Hughesb6351622015-12-04 22:00:26 -080032#include "android-base/stringprintf.h"
33#include "android-base/test_utils.h"
Dan Alberte3ea0582015-03-13 23:06:01 -070034
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
Spencer Lowe0671d62015-09-17 19:36:10 -070043#if defined(_WIN32)
44static void ExitSignalAbortHandler(int) {
45 _exit(3);
46}
47#endif
48
49static 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
Dan Albert1f65c492015-03-27 11:20:14 -070063TEST(logging, CHECK) {
Spencer Lowe0671d62015-09-17 19:36:10 -070064 ASSERT_DEATH({SuppressAbortUI(); CHECK(false);}, "Check failed: false ");
Dan Alberte3ea0582015-03-13 23:06:01 -070065 CHECK(true);
66
Spencer Lowe0671d62015-09-17 19:36:10 -070067 ASSERT_DEATH({SuppressAbortUI(); CHECK_EQ(0, 1);}, "Check failed: 0 == 1 ");
Dan Alberte3ea0582015-03-13 23:06:01 -070068 CHECK_EQ(0, 0);
69
Krzysztof Kosiński62164882020-06-20 04:20:37 -070070 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
Spencer Lowe0671d62015-09-17 19:36:10 -070080 ASSERT_DEATH({SuppressAbortUI(); CHECK_STREQ("foo", "bar");},
81 R"(Check failed: "foo" == "bar")");
Dan Alberte3ea0582015-03-13 23:06:01 -070082 CHECK_STREQ("foo", "foo");
Spencer Lowe0671d62015-09-17 19:36:10 -070083
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";
Dan Alberte3ea0582015-03-13 23:06:01 -070098}
99
Andreas Gampe702ab482016-09-13 10:44:46 -0700100TEST(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
Krzysztof Kosiński62164882020-06-20 04:20:37 -0700111 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
Andreas Gampe702ab482016-09-13 10:44:46 -0700118 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
Andreas Gampeadc0e3d2016-09-22 10:15:01 -0700129
Andreas Gampecb35a4a2016-09-23 16:37:12 -0700130#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 } \
Andreas Gampeadc0e3d2016-09-22 10:15:01 -0700158
159TEST(logging, WOULD_LOG_FATAL) {
160 CHECK_WOULD_LOG_ENABLED(FATAL);
161}
162
Andreas Gampeadc0e3d2016-09-22 10:15:01 -0700163TEST(logging, WOULD_LOG_FATAL_WITHOUT_ABORT_enabled) {
164 CHECK_WOULD_LOG_ENABLED(FATAL_WITHOUT_ABORT);
165}
166
167TEST(logging, WOULD_LOG_ERROR_disabled) {
168 CHECK_WOULD_LOG_DISABLED(ERROR);
169}
170
171TEST(logging, WOULD_LOG_ERROR_enabled) {
172 CHECK_WOULD_LOG_ENABLED(ERROR);
173}
174
175TEST(logging, WOULD_LOG_WARNING_disabled) {
176 CHECK_WOULD_LOG_DISABLED(WARNING);
177}
178
179TEST(logging, WOULD_LOG_WARNING_enabled) {
180 CHECK_WOULD_LOG_ENABLED(WARNING);
181}
182
183TEST(logging, WOULD_LOG_INFO_disabled) {
184 CHECK_WOULD_LOG_DISABLED(INFO);
185}
186
187TEST(logging, WOULD_LOG_INFO_enabled) {
188 CHECK_WOULD_LOG_ENABLED(INFO);
189}
190
191TEST(logging, WOULD_LOG_DEBUG_disabled) {
192 CHECK_WOULD_LOG_DISABLED(DEBUG);
193}
194
195TEST(logging, WOULD_LOG_DEBUG_enabled) {
196 CHECK_WOULD_LOG_ENABLED(DEBUG);
197}
198
199TEST(logging, WOULD_LOG_VERBOSE_disabled) {
200 CHECK_WOULD_LOG_DISABLED(VERBOSE);
201}
202
203TEST(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
Dan Willemsenb80b3d52017-11-29 18:06:11 -0800211#if !defined(_WIN32)
Elliott Hughes762639d2016-09-07 16:22:40 -0700212static std::string make_log_pattern(android::base::LogSeverity severity,
213 const char* message) {
Andreas Gamped2a4f212016-09-07 10:10:50 -0700214 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");
Dan Alberte3ea0582015-03-13 23:06:01 -0700217 char log_char = log_characters[severity];
Spencer Low55853a92015-08-11 16:00:13 -0700218 std::string holder(__FILE__);
Dan Alberte3ea0582015-03-13 23:06:01 -0700219 return android::base::StringPrintf(
Elliott Hughes762639d2016-09-07 16:22:40 -0700220 "%c \\d+-\\d+ \\d+:\\d+:\\d+ \\s*\\d+ \\s*\\d+ %s:\\d+] %s",
Spencer Low55853a92015-08-11 16:00:13 -0700221 log_char, basename(&holder[0]), message);
Dan Alberte3ea0582015-03-13 23:06:01 -0700222}
Dan Willemsenb80b3d52017-11-29 18:06:11 -0800223#endif
Dan Alberte3ea0582015-03-13 23:06:01 -0700224
Christopher Ferrisa6f0b672018-08-30 13:31:45 -0700225static void CheckMessage(const std::string& output, android::base::LogSeverity severity,
Andreas Gampefec5b092018-03-05 10:00:19 -0800226 const char* expected, const char* expected_tag = nullptr) {
Dan Albertdc15ffd2015-04-29 11:32:23 -0700227 // 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.
Elliott Hughes762639d2016-09-07 16:22:40 -0700230 ASSERT_GT(output.length(), strlen(expected));
231 ASSERT_NE(nullptr, strstr(output.c_str(), expected)) << output;
Andreas Gampefec5b092018-03-05 10:00:19 -0800232 if (expected_tag != nullptr) {
233 ASSERT_NE(nullptr, strstr(output.c_str(), expected_tag)) << output;
234 }
Dan Alberte3ea0582015-03-13 23:06:01 -0700235
Dan Albertdc15ffd2015-04-29 11:32:23 -0700236#if !defined(_WIN32)
Andreas Gampefec5b092018-03-05 10:00:19 -0800237 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);
Elliott Hughes762639d2016-09-07 16:22:40 -0700244 ASSERT_TRUE(std::regex_search(output, message_regex)) << output;
Dan Albertdc15ffd2015-04-29 11:32:23 -0700245#endif
Dan Alberte3ea0582015-03-13 23:06:01 -0700246}
247
Christopher Ferrisa6f0b672018-08-30 13:31:45 -0700248static 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}
Andreas Gampecb35a4a2016-09-23 16:37:12 -0700254
Christopher Ferrisa6f0b672018-08-30 13:31:45 -0700255#define CHECK_LOG_STREAM_DISABLED(severity) \
256 { \
Andreas Gampecb35a4a2016-09-23 16:37:12 -0700257 android::base::ScopedLogSeverity sls1(android::base::FATAL); \
Christopher Ferrisa6f0b672018-08-30 13:31:45 -0700258 CapturedStderr cap1; \
259 LOG_STREAM(severity) << "foo bar"; \
260 cap1.Stop(); \
261 ASSERT_EQ("", cap1.str()); \
262 } \
263 { \
Andreas Gampecb35a4a2016-09-23 16:37:12 -0700264 android::base::ScopedLogSeverity sls1(android::base::FATAL); \
Christopher Ferrisa6f0b672018-08-30 13:31:45 -0700265 CapturedStderr cap1; \
266 LOG_STREAM(::android::base::severity) << "foo bar"; \
267 cap1.Stop(); \
268 ASSERT_EQ("", cap1.str()); \
269 }
Andreas Gampec65ea942016-09-23 13:31:52 -0700270
271#define CHECK_LOG_STREAM_ENABLED(severity) \
Andreas Gampecb35a4a2016-09-23 16:37:12 -0700272 { \
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 } \
Andreas Gampeadc0e3d2016-09-22 10:15:01 -0700284
Andreas Gampec65ea942016-09-23 13:31:52 -0700285TEST(logging, LOG_STREAM_FATAL_WITHOUT_ABORT_enabled) {
Christopher Ferrisa6f0b672018-08-30 13:31:45 -0700286 ASSERT_NO_FATAL_FAILURE(CHECK_LOG_STREAM_ENABLED(FATAL_WITHOUT_ABORT));
Andreas Gampeadc0e3d2016-09-22 10:15:01 -0700287}
288
Andreas Gampec65ea942016-09-23 13:31:52 -0700289TEST(logging, LOG_STREAM_ERROR_disabled) {
290 CHECK_LOG_STREAM_DISABLED(ERROR);
Andreas Gampeadc0e3d2016-09-22 10:15:01 -0700291}
292
Andreas Gampec65ea942016-09-23 13:31:52 -0700293TEST(logging, LOG_STREAM_ERROR_enabled) {
Christopher Ferrisa6f0b672018-08-30 13:31:45 -0700294 ASSERT_NO_FATAL_FAILURE(CHECK_LOG_STREAM_ENABLED(ERROR));
Andreas Gampeadc0e3d2016-09-22 10:15:01 -0700295}
296
Andreas Gampec65ea942016-09-23 13:31:52 -0700297TEST(logging, LOG_STREAM_WARNING_disabled) {
298 CHECK_LOG_STREAM_DISABLED(WARNING);
Andreas Gampeadc0e3d2016-09-22 10:15:01 -0700299}
300
Andreas Gampec65ea942016-09-23 13:31:52 -0700301TEST(logging, LOG_STREAM_WARNING_enabled) {
Christopher Ferrisa6f0b672018-08-30 13:31:45 -0700302 ASSERT_NO_FATAL_FAILURE(CHECK_LOG_STREAM_ENABLED(WARNING));
Andreas Gampeadc0e3d2016-09-22 10:15:01 -0700303}
304
Andreas Gampec65ea942016-09-23 13:31:52 -0700305TEST(logging, LOG_STREAM_INFO_disabled) {
306 CHECK_LOG_STREAM_DISABLED(INFO);
307}
Andreas Gampeadc0e3d2016-09-22 10:15:01 -0700308
Andreas Gampec65ea942016-09-23 13:31:52 -0700309TEST(logging, LOG_STREAM_INFO_enabled) {
Christopher Ferrisa6f0b672018-08-30 13:31:45 -0700310 ASSERT_NO_FATAL_FAILURE(CHECK_LOG_STREAM_ENABLED(INFO));
Andreas Gampec65ea942016-09-23 13:31:52 -0700311}
312
313TEST(logging, LOG_STREAM_DEBUG_disabled) {
314 CHECK_LOG_STREAM_DISABLED(DEBUG);
315}
316
317TEST(logging, LOG_STREAM_DEBUG_enabled) {
Christopher Ferrisa6f0b672018-08-30 13:31:45 -0700318 ASSERT_NO_FATAL_FAILURE(CHECK_LOG_STREAM_ENABLED(DEBUG));
Andreas Gampec65ea942016-09-23 13:31:52 -0700319}
320
321TEST(logging, LOG_STREAM_VERBOSE_disabled) {
322 CHECK_LOG_STREAM_DISABLED(VERBOSE);
323}
324
325TEST(logging, LOG_STREAM_VERBOSE_enabled) {
Christopher Ferrisa6f0b672018-08-30 13:31:45 -0700326 ASSERT_NO_FATAL_FAILURE(CHECK_LOG_STREAM_ENABLED(VERBOSE));
Andreas Gampec65ea942016-09-23 13:31:52 -0700327}
328
329#undef CHECK_LOG_STREAM_DISABLED
330#undef CHECK_LOG_STREAM_ENABLED
331
Christopher Ferrisa6f0b672018-08-30 13:31:45 -0700332#define CHECK_LOG_DISABLED(severity) \
333 { \
Andreas Gampecb35a4a2016-09-23 16:37:12 -0700334 android::base::ScopedLogSeverity sls1(android::base::FATAL); \
Christopher Ferrisa6f0b672018-08-30 13:31:45 -0700335 CapturedStderr cap1; \
336 LOG(severity) << "foo bar"; \
337 cap1.Stop(); \
338 ASSERT_EQ("", cap1.str()); \
339 } \
340 { \
Andreas Gampecb35a4a2016-09-23 16:37:12 -0700341 android::base::ScopedLogSeverity sls1(android::base::FATAL); \
Christopher Ferrisa6f0b672018-08-30 13:31:45 -0700342 CapturedStderr cap1; \
343 LOG(::android::base::severity) << "foo bar"; \
344 cap1.Stop(); \
345 ASSERT_EQ("", cap1.str()); \
346 }
Andreas Gampeadc0e3d2016-09-22 10:15:01 -0700347
348#define CHECK_LOG_ENABLED(severity) \
Andreas Gampecb35a4a2016-09-23 16:37:12 -0700349 { \
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 } \
Andreas Gampeadc0e3d2016-09-22 10:15:01 -0700361
Elliott Hughes762639d2016-09-07 16:22:40 -0700362TEST(logging, LOG_FATAL) {
363 ASSERT_DEATH({SuppressAbortUI(); LOG(FATAL) << "foobar";}, "foobar");
Andreas Gampecb35a4a2016-09-23 16:37:12 -0700364 ASSERT_DEATH({SuppressAbortUI(); LOG(::android::base::FATAL) << "foobar";}, "foobar");
Elliott Hughes762639d2016-09-07 16:22:40 -0700365}
Dan Alberte3ea0582015-03-13 23:06:01 -0700366
Andreas Gamped2a4f212016-09-07 10:10:50 -0700367TEST(logging, LOG_FATAL_WITHOUT_ABORT_enabled) {
Christopher Ferrisa6f0b672018-08-30 13:31:45 -0700368 ASSERT_NO_FATAL_FAILURE(CHECK_LOG_ENABLED(FATAL_WITHOUT_ABORT));
Andreas Gamped2a4f212016-09-07 10:10:50 -0700369}
370
Elliott Hughes762639d2016-09-07 16:22:40 -0700371TEST(logging, LOG_ERROR_disabled) {
372 CHECK_LOG_DISABLED(ERROR);
373}
Dan Alberte3ea0582015-03-13 23:06:01 -0700374
Elliott Hughes762639d2016-09-07 16:22:40 -0700375TEST(logging, LOG_ERROR_enabled) {
Christopher Ferrisa6f0b672018-08-30 13:31:45 -0700376 ASSERT_NO_FATAL_FAILURE(CHECK_LOG_ENABLED(ERROR));
Elliott Hughes762639d2016-09-07 16:22:40 -0700377}
378
379TEST(logging, LOG_WARNING_disabled) {
380 CHECK_LOG_DISABLED(WARNING);
381}
382
383TEST(logging, LOG_WARNING_enabled) {
Christopher Ferrisa6f0b672018-08-30 13:31:45 -0700384 ASSERT_NO_FATAL_FAILURE(CHECK_LOG_ENABLED(WARNING));
Elliott Hughes762639d2016-09-07 16:22:40 -0700385}
386
387TEST(logging, LOG_INFO_disabled) {
388 CHECK_LOG_DISABLED(INFO);
389}
390
391TEST(logging, LOG_INFO_enabled) {
Christopher Ferrisa6f0b672018-08-30 13:31:45 -0700392 ASSERT_NO_FATAL_FAILURE(CHECK_LOG_ENABLED(INFO));
Elliott Hughes762639d2016-09-07 16:22:40 -0700393}
394
395TEST(logging, LOG_DEBUG_disabled) {
396 CHECK_LOG_DISABLED(DEBUG);
397}
398
399TEST(logging, LOG_DEBUG_enabled) {
Christopher Ferrisa6f0b672018-08-30 13:31:45 -0700400 ASSERT_NO_FATAL_FAILURE(CHECK_LOG_ENABLED(DEBUG));
Elliott Hughes762639d2016-09-07 16:22:40 -0700401}
402
403TEST(logging, LOG_VERBOSE_disabled) {
404 CHECK_LOG_DISABLED(VERBOSE);
405}
406
407TEST(logging, LOG_VERBOSE_enabled) {
Christopher Ferrisa6f0b672018-08-30 13:31:45 -0700408 ASSERT_NO_FATAL_FAILURE(CHECK_LOG_ENABLED(VERBOSE));
Elliott Hughes762639d2016-09-07 16:22:40 -0700409}
410
Andreas Gampeadc0e3d2016-09-22 10:15:01 -0700411#undef CHECK_LOG_DISABLED
412#undef CHECK_LOG_ENABLED
413
Andreas Gampecb35a4a2016-09-23 16:37:12 -0700414TEST(logging, LOG_complex_param) {
Christopher Ferrisa6f0b672018-08-30 13:31:45 -0700415#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 } \
Andreas Gampeadc0e3d2016-09-22 10:15:01 -0700430 }
431
Andreas Gampecb35a4a2016-09-23 16:37:12 -0700432 CHECK_LOG_COMBINATION(false,false);
433 CHECK_LOG_COMBINATION(false,true);
434 CHECK_LOG_COMBINATION(true,false);
435 CHECK_LOG_COMBINATION(true,true);
Andreas Gampeadc0e3d2016-09-22 10:15:01 -0700436
Andreas Gampecb35a4a2016-09-23 16:37:12 -0700437#undef CHECK_LOG_COMBINATION
Andreas Gampeadc0e3d2016-09-22 10:15:01 -0700438}
439
440
Elliott Hughes762639d2016-09-07 16:22:40 -0700441TEST(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
Christopher Ferrisa6f0b672018-08-30 13:31:45 -0700447 ASSERT_NO_FATAL_FAILURE(CheckMessage(cap, android::base::INFO, "67890"));
Elliott Hughes762639d2016-09-07 16:22:40 -0700448}
449
450TEST(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
Christopher Ferrisa6f0b672018-08-30 13:31:45 -0700456 ASSERT_NO_FATAL_FAILURE(CheckMessage(cap, android::base::INFO, "67890"));
Elliott Hughes762639d2016-09-07 16:22:40 -0700457}
458
459TEST(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";
Andreas Gampeadc0e3d2016-09-22 10:15:01 -0700480}
Elliott Hughes762639d2016-09-07 16:22:40 -0700481
Christopher Ferrisa6f0b672018-08-30 13:31:45 -0700482#define CHECK_PLOG_DISABLED(severity) \
483 { \
Andreas Gampecb35a4a2016-09-23 16:37:12 -0700484 android::base::ScopedLogSeverity sls1(android::base::FATAL); \
Christopher Ferrisa6f0b672018-08-30 13:31:45 -0700485 CapturedStderr cap1; \
486 PLOG(severity) << "foo bar"; \
487 cap1.Stop(); \
488 ASSERT_EQ("", cap1.str()); \
489 } \
490 { \
Andreas Gampecb35a4a2016-09-23 16:37:12 -0700491 android::base::ScopedLogSeverity sls1(android::base::FATAL); \
Christopher Ferrisa6f0b672018-08-30 13:31:45 -0700492 CapturedStderr cap1; \
493 PLOG(severity) << "foo bar"; \
494 cap1.Stop(); \
495 ASSERT_EQ("", cap1.str()); \
496 }
Elliott Hughes762639d2016-09-07 16:22:40 -0700497
498#define CHECK_PLOG_ENABLED(severity) \
Andreas Gampecb35a4a2016-09-23 16:37:12 -0700499 { \
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 } \
Elliott Hughes762639d2016-09-07 16:22:40 -0700513
Andreas Gamped2a4f212016-09-07 10:10:50 -0700514TEST(logging, PLOG_FATAL) {
515 ASSERT_DEATH({SuppressAbortUI(); PLOG(FATAL) << "foobar";}, "foobar");
Andreas Gampecb35a4a2016-09-23 16:37:12 -0700516 ASSERT_DEATH({SuppressAbortUI(); PLOG(::android::base::FATAL) << "foobar";}, "foobar");
Andreas Gamped2a4f212016-09-07 10:10:50 -0700517}
518
Andreas Gamped2a4f212016-09-07 10:10:50 -0700519TEST(logging, PLOG_FATAL_WITHOUT_ABORT_enabled) {
Christopher Ferrisa6f0b672018-08-30 13:31:45 -0700520 ASSERT_NO_FATAL_FAILURE(CHECK_PLOG_ENABLED(FATAL_WITHOUT_ABORT));
Andreas Gamped2a4f212016-09-07 10:10:50 -0700521}
522
Elliott Hughes762639d2016-09-07 16:22:40 -0700523TEST(logging, PLOG_ERROR_disabled) {
524 CHECK_PLOG_DISABLED(ERROR);
525}
526
527TEST(logging, PLOG_ERROR_enabled) {
Christopher Ferrisa6f0b672018-08-30 13:31:45 -0700528 ASSERT_NO_FATAL_FAILURE(CHECK_PLOG_ENABLED(ERROR));
Elliott Hughes762639d2016-09-07 16:22:40 -0700529}
530
531TEST(logging, PLOG_WARNING_disabled) {
532 CHECK_PLOG_DISABLED(WARNING);
533}
534
535TEST(logging, PLOG_WARNING_enabled) {
Christopher Ferrisa6f0b672018-08-30 13:31:45 -0700536 ASSERT_NO_FATAL_FAILURE(CHECK_PLOG_ENABLED(WARNING));
Elliott Hughes762639d2016-09-07 16:22:40 -0700537}
538
539TEST(logging, PLOG_INFO_disabled) {
540 CHECK_PLOG_DISABLED(INFO);
541}
542
543TEST(logging, PLOG_INFO_enabled) {
Christopher Ferrisa6f0b672018-08-30 13:31:45 -0700544 ASSERT_NO_FATAL_FAILURE(CHECK_PLOG_ENABLED(INFO));
Elliott Hughes762639d2016-09-07 16:22:40 -0700545}
546
547TEST(logging, PLOG_DEBUG_disabled) {
548 CHECK_PLOG_DISABLED(DEBUG);
549}
550
551TEST(logging, PLOG_DEBUG_enabled) {
Christopher Ferrisa6f0b672018-08-30 13:31:45 -0700552 ASSERT_NO_FATAL_FAILURE(CHECK_PLOG_ENABLED(DEBUG));
Elliott Hughes762639d2016-09-07 16:22:40 -0700553}
554
555TEST(logging, PLOG_VERBOSE_disabled) {
556 CHECK_PLOG_DISABLED(VERBOSE);
557}
558
559TEST(logging, PLOG_VERBOSE_enabled) {
Christopher Ferrisa6f0b672018-08-30 13:31:45 -0700560 ASSERT_NO_FATAL_FAILURE(CHECK_PLOG_ENABLED(VERBOSE));
Dan Alberte3ea0582015-03-13 23:06:01 -0700561}
562
Andreas Gampeadc0e3d2016-09-22 10:15:01 -0700563#undef CHECK_PLOG_DISABLED
564#undef CHECK_PLOG_ENABLED
565
566
Dan Albert1f65c492015-03-27 11:20:14 -0700567TEST(logging, UNIMPLEMENTED) {
Elliott Hughes762639d2016-09-07 16:22:40 -0700568 std::string expected = android::base::StringPrintf("%s unimplemented ", __PRETTY_FUNCTION__);
Dan Alberte3ea0582015-03-13 23:06:01 -0700569
Elliott Hughes762639d2016-09-07 16:22:40 -0700570 CapturedStderr cap;
571 errno = ENOENT;
572 UNIMPLEMENTED(ERROR);
Christopher Ferrisa6f0b672018-08-30 13:31:45 -0700573 ASSERT_NO_FATAL_FAILURE(CheckMessage(cap, android::base::ERROR, expected.c_str()));
Dan Alberte3ea0582015-03-13 23:06:01 -0700574}
Andreas Gampe9008e8d2016-09-08 11:03:58 -0700575
576static void NoopAborter(const char* msg ATTRIBUTE_UNUSED) {
577 LOG(ERROR) << "called noop";
578}
579
580TEST(logging, LOG_FATAL_NOOP_ABORTER) {
Christopher Ferrisa6f0b672018-08-30 13:31:45 -0700581 CapturedStderr cap;
Andreas Gampe9008e8d2016-09-08 11:03:58 -0700582 {
583 android::base::SetAborter(NoopAborter);
584
585 android::base::ScopedLogSeverity sls(android::base::ERROR);
Andreas Gampe9008e8d2016-09-08 11:03:58 -0700586 LOG(FATAL) << "foobar";
Christopher Ferrisa6f0b672018-08-30 13:31:45 -0700587 cap.Stop();
Andreas Gampe9008e8d2016-09-08 11:03:58 -0700588
589 android::base::SetAborter(android::base::DefaultAborter);
590 }
Christopher Ferrisa6f0b672018-08-30 13:31:45 -0700591 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"));
Andreas Gampe9008e8d2016-09-08 11:03:58 -0700594
595 ASSERT_DEATH({SuppressAbortUI(); LOG(FATAL) << "foobar";}, "foobar");
596}
Andreas Gampe1ed2be02016-10-04 19:17:07 -0700597
598struct CountLineAborter {
599 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};
609size_t CountLineAborter::newline_count = 0;
610
611TEST(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
Tom Cherrya6872422020-04-17 13:05:11 -0700619 EXPECT_EQ(CountLineAborter::newline_count, 1U);
Andreas Gampe1ed2be02016-10-04 19:17:07 -0700620}
Yabin Cui7ff958a2017-01-23 10:29:23 -0800621
Krzysztof Kosińskiccbd5db2020-08-04 17:41:44 -0700622TEST(logging, SetAborterReturnsOldFunction) {
623 // std::function is not comparable, it only supports a null check.
624 android::base::AbortFunction old_aborter;
625 EXPECT_FALSE(old_aborter);
626 old_aborter = android::base::SetAborter(android::base::DefaultAborter);
627 EXPECT_TRUE(old_aborter);
628}
629
Yabin Cui7ff958a2017-01-23 10:29:23 -0800630__attribute__((constructor)) void TestLoggingInConstructor() {
631 LOG(ERROR) << "foobar";
632}
Andreas Gampefec5b092018-03-05 10:00:19 -0800633
Elliott Hughes1c1409f2018-05-23 09:16:46 -0700634TEST(logging, StdioLogger) {
Christopher Ferrisa6f0b672018-08-30 13:31:45 -0700635 CapturedStderr cap_err;
636 CapturedStdout cap_out;
637 android::base::SetLogger(android::base::StdioLogger);
638 LOG(INFO) << "out";
639 LOG(ERROR) << "err";
640 cap_err.Stop();
641 cap_out.Stop();
Elliott Hughes1c1409f2018-05-23 09:16:46 -0700642
643 // For INFO we expect just the literal "out\n".
Christopher Ferrisa6f0b672018-08-30 13:31:45 -0700644 ASSERT_EQ("out\n", cap_out.str());
Elliott Hughes1c1409f2018-05-23 09:16:46 -0700645 // Whereas ERROR logging includes the program name.
Christopher Ferrisa6f0b672018-08-30 13:31:45 -0700646 ASSERT_EQ(android::base::Basename(android::base::GetExecutablePath()) + ": err\n", cap_err.str());
Elliott Hughes1c1409f2018-05-23 09:16:46 -0700647}
Tom Cherrya6872422020-04-17 13:05:11 -0700648
Krzysztof Kosińskiccbd5db2020-08-04 17:41:44 -0700649TEST(logging, SetLoggerReturnsOldFunction) {
650 // std::function is not comparable, it only supports a null check.
651 android::base::LogFunction old_function;
652 EXPECT_FALSE(old_function);
653 old_function = android::base::SetLogger(android::base::StdioLogger);
654 EXPECT_TRUE(old_function);
655}
656
Tom Cherrya6872422020-04-17 13:05:11 -0700657TEST(logging, ForkSafe) {
658#if !defined(_WIN32)
659 using namespace android::base;
660 SetLogger(
661 [&](LogId, LogSeverity, const char*, const char*, unsigned int, const char*) { sleep(3); });
662
663 auto guard = make_scope_guard([&] {
664#ifdef __ANDROID__
665 SetLogger(LogdLogger());
666#else
667 SetLogger(StderrLogger);
668#endif
669 });
670
671 auto thread = std::thread([] {
672 LOG(ERROR) << "This should sleep for 3 seconds, long enough to fork another process, if there "
673 "is no intervention";
674 });
675 thread.detach();
676
677 auto pid = fork();
678 ASSERT_NE(-1, pid);
679
680 if (pid == 0) {
681 // Reset the logger, so the next message doesn't sleep().
682 SetLogger([](LogId, LogSeverity, const char*, const char*, unsigned int, const char*) {});
683 LOG(ERROR) << "This should succeed in the child, only if libbase is forksafe.";
684 _exit(EXIT_SUCCESS);
685 }
686
687 // Wait for up to 3 seconds for the child to exit.
688 int tries = 3;
689 bool found_child = false;
690 while (tries-- > 0) {
691 auto result = waitpid(pid, nullptr, WNOHANG);
692 EXPECT_NE(-1, result);
693 if (result == pid) {
694 found_child = true;
695 break;
696 }
697 sleep(1);
698 }
699
700 EXPECT_TRUE(found_child);
701
702 // Kill the child if it did not exit.
703 if (!found_child) {
704 kill(pid, SIGKILL);
705 }
706#endif
707}