diff --git a/base/include/android-base/test_utils.h b/base/include/android-base/test_utils.h index 9e2ea97f2..2abe68e02 100644 --- a/base/include/android-base/test_utils.h +++ b/base/include/android-base/test_utils.h @@ -62,16 +62,18 @@ class CapturedStdFd { CapturedStdFd(int std_fd); ~CapturedStdFd(); - int fd() const; std::string str(); - private: - void Init(); + void Start(); + void Stop(); void Reset(); + private: + int fd() const; + TemporaryFile temp_file_; int std_fd_; - int old_fd_; + int old_fd_ = -1; DISALLOW_COPY_AND_ASSIGN(CapturedStdFd); }; diff --git a/base/logging_test.cpp b/base/logging_test.cpp index 75b4ea045..3113fb47a 100644 --- a/base/logging_test.cpp +++ b/base/logging_test.cpp @@ -206,10 +206,8 @@ static std::string make_log_pattern(android::base::LogSeverity severity, } #endif -static void CheckMessage(CapturedStderr& cap, android::base::LogSeverity severity, +static void CheckMessage(const std::string& output, android::base::LogSeverity severity, const char* expected, const char* expected_tag = nullptr) { - std::string output = cap.str(); - // We can't usefully check the output of any of these on Windows because we // don't have std::regex, but we can at least make sure we printed at least as // many characters are in the log message. @@ -231,20 +229,28 @@ static void CheckMessage(CapturedStderr& cap, android::base::LogSeverity severit #endif } +static void CheckMessage(CapturedStderr& cap, android::base::LogSeverity severity, + const char* expected, const char* expected_tag = nullptr) { + cap.Stop(); + std::string output = cap.str(); + return CheckMessage(output, severity, expected, expected_tag); +} -#define CHECK_LOG_STREAM_DISABLED(severity) \ - { \ +#define CHECK_LOG_STREAM_DISABLED(severity) \ + { \ android::base::ScopedLogSeverity sls1(android::base::FATAL); \ - CapturedStderr cap1; \ - LOG_STREAM(severity) << "foo bar"; \ - ASSERT_EQ(0, lseek(cap1.fd(), 0, SEEK_CUR)); \ - } \ - { \ + CapturedStderr cap1; \ + LOG_STREAM(severity) << "foo bar"; \ + cap1.Stop(); \ + ASSERT_EQ("", cap1.str()); \ + } \ + { \ android::base::ScopedLogSeverity sls1(android::base::FATAL); \ - CapturedStderr cap1; \ - LOG_STREAM(::android::base::severity) << "foo bar"; \ - ASSERT_EQ(0, lseek(cap1.fd(), 0, SEEK_CUR)); \ - } \ + CapturedStderr cap1; \ + LOG_STREAM(::android::base::severity) << "foo bar"; \ + cap1.Stop(); \ + ASSERT_EQ("", cap1.str()); \ + } #define CHECK_LOG_STREAM_ENABLED(severity) \ { \ @@ -265,7 +271,7 @@ TEST(logging, LOG_STREAM_FATAL_WITHOUT_ABORT_disabled) { } TEST(logging, LOG_STREAM_FATAL_WITHOUT_ABORT_enabled) { - CHECK_LOG_STREAM_ENABLED(FATAL_WITHOUT_ABORT); + ASSERT_NO_FATAL_FAILURE(CHECK_LOG_STREAM_ENABLED(FATAL_WITHOUT_ABORT)); } TEST(logging, LOG_STREAM_ERROR_disabled) { @@ -273,7 +279,7 @@ TEST(logging, LOG_STREAM_ERROR_disabled) { } TEST(logging, LOG_STREAM_ERROR_enabled) { - CHECK_LOG_STREAM_ENABLED(ERROR); + ASSERT_NO_FATAL_FAILURE(CHECK_LOG_STREAM_ENABLED(ERROR)); } TEST(logging, LOG_STREAM_WARNING_disabled) { @@ -281,7 +287,7 @@ TEST(logging, LOG_STREAM_WARNING_disabled) { } TEST(logging, LOG_STREAM_WARNING_enabled) { - CHECK_LOG_STREAM_ENABLED(WARNING); + ASSERT_NO_FATAL_FAILURE(CHECK_LOG_STREAM_ENABLED(WARNING)); } TEST(logging, LOG_STREAM_INFO_disabled) { @@ -289,7 +295,7 @@ TEST(logging, LOG_STREAM_INFO_disabled) { } TEST(logging, LOG_STREAM_INFO_enabled) { - CHECK_LOG_STREAM_ENABLED(INFO); + ASSERT_NO_FATAL_FAILURE(CHECK_LOG_STREAM_ENABLED(INFO)); } TEST(logging, LOG_STREAM_DEBUG_disabled) { @@ -297,7 +303,7 @@ TEST(logging, LOG_STREAM_DEBUG_disabled) { } TEST(logging, LOG_STREAM_DEBUG_enabled) { - CHECK_LOG_STREAM_ENABLED(DEBUG); + ASSERT_NO_FATAL_FAILURE(CHECK_LOG_STREAM_ENABLED(DEBUG)); } TEST(logging, LOG_STREAM_VERBOSE_disabled) { @@ -305,26 +311,27 @@ TEST(logging, LOG_STREAM_VERBOSE_disabled) { } TEST(logging, LOG_STREAM_VERBOSE_enabled) { - CHECK_LOG_STREAM_ENABLED(VERBOSE); + ASSERT_NO_FATAL_FAILURE(CHECK_LOG_STREAM_ENABLED(VERBOSE)); } #undef CHECK_LOG_STREAM_DISABLED #undef CHECK_LOG_STREAM_ENABLED - -#define CHECK_LOG_DISABLED(severity) \ - { \ +#define CHECK_LOG_DISABLED(severity) \ + { \ android::base::ScopedLogSeverity sls1(android::base::FATAL); \ - CapturedStderr cap1; \ - LOG(severity) << "foo bar"; \ - ASSERT_EQ(0, lseek(cap1.fd(), 0, SEEK_CUR)); \ - } \ - { \ + CapturedStderr cap1; \ + LOG(severity) << "foo bar"; \ + cap1.Stop(); \ + ASSERT_EQ("", cap1.str()); \ + } \ + { \ android::base::ScopedLogSeverity sls1(android::base::FATAL); \ - CapturedStderr cap1; \ - LOG(::android::base::severity) << "foo bar"; \ - ASSERT_EQ(0, lseek(cap1.fd(), 0, SEEK_CUR)); \ - } \ + CapturedStderr cap1; \ + LOG(::android::base::severity) << "foo bar"; \ + cap1.Stop(); \ + ASSERT_EQ("", cap1.str()); \ + } #define CHECK_LOG_ENABLED(severity) \ { \ @@ -350,7 +357,7 @@ TEST(logging, LOG_FATAL_WITHOUT_ABORT_disabled) { } TEST(logging, LOG_FATAL_WITHOUT_ABORT_enabled) { - CHECK_LOG_ENABLED(FATAL_WITHOUT_ABORT); + ASSERT_NO_FATAL_FAILURE(CHECK_LOG_ENABLED(FATAL_WITHOUT_ABORT)); } TEST(logging, LOG_ERROR_disabled) { @@ -358,7 +365,7 @@ TEST(logging, LOG_ERROR_disabled) { } TEST(logging, LOG_ERROR_enabled) { - CHECK_LOG_ENABLED(ERROR); + ASSERT_NO_FATAL_FAILURE(CHECK_LOG_ENABLED(ERROR)); } TEST(logging, LOG_WARNING_disabled) { @@ -366,7 +373,7 @@ TEST(logging, LOG_WARNING_disabled) { } TEST(logging, LOG_WARNING_enabled) { - CHECK_LOG_ENABLED(WARNING); + ASSERT_NO_FATAL_FAILURE(CHECK_LOG_ENABLED(WARNING)); } TEST(logging, LOG_INFO_disabled) { @@ -374,7 +381,7 @@ TEST(logging, LOG_INFO_disabled) { } TEST(logging, LOG_INFO_enabled) { - CHECK_LOG_ENABLED(INFO); + ASSERT_NO_FATAL_FAILURE(CHECK_LOG_ENABLED(INFO)); } TEST(logging, LOG_DEBUG_disabled) { @@ -382,7 +389,7 @@ TEST(logging, LOG_DEBUG_disabled) { } TEST(logging, LOG_DEBUG_enabled) { - CHECK_LOG_ENABLED(DEBUG); + ASSERT_NO_FATAL_FAILURE(CHECK_LOG_ENABLED(DEBUG)); } TEST(logging, LOG_VERBOSE_disabled) { @@ -390,28 +397,28 @@ TEST(logging, LOG_VERBOSE_disabled) { } TEST(logging, LOG_VERBOSE_enabled) { - CHECK_LOG_ENABLED(VERBOSE); + ASSERT_NO_FATAL_FAILURE(CHECK_LOG_ENABLED(VERBOSE)); } #undef CHECK_LOG_DISABLED #undef CHECK_LOG_ENABLED - TEST(logging, LOG_complex_param) { -#define CHECK_LOG_COMBINATION(use_scoped_log_severity_info, use_logging_severity_info) \ - { \ - android::base::ScopedLogSeverity sls( \ - (use_scoped_log_severity_info) ? ::android::base::INFO : ::android::base::WARNING); \ - CapturedStderr cap; \ - LOG((use_logging_severity_info) ? ::android::base::INFO : ::android::base::WARNING) \ - << "foobar"; \ - if ((use_scoped_log_severity_info) || !(use_logging_severity_info)) { \ - CheckMessage(cap, \ - (use_logging_severity_info) ? ::android::base::INFO : ::android::base::WARNING, \ - "foobar"); \ - } else { \ - ASSERT_EQ(0, lseek(cap.fd(), 0, SEEK_CUR)); \ - } \ +#define CHECK_LOG_COMBINATION(use_scoped_log_severity_info, use_logging_severity_info) \ + { \ + android::base::ScopedLogSeverity sls( \ + (use_scoped_log_severity_info) ? ::android::base::INFO : ::android::base::WARNING); \ + CapturedStderr cap; \ + LOG((use_logging_severity_info) ? ::android::base::INFO : ::android::base::WARNING) \ + << "foobar"; \ + if ((use_scoped_log_severity_info) || !(use_logging_severity_info)) { \ + ASSERT_NO_FATAL_FAILURE(CheckMessage( \ + cap, (use_logging_severity_info) ? ::android::base::INFO : ::android::base::WARNING, \ + "foobar")); \ + } else { \ + cap.Stop(); \ + ASSERT_EQ("", cap.str()); \ + } \ } CHECK_LOG_COMBINATION(false,false); @@ -429,7 +436,7 @@ TEST(logging, LOG_does_not_clobber_errno) { LOG(INFO) << (errno = 67890); EXPECT_EQ(12345, errno) << "errno was not restored"; - CheckMessage(cap, android::base::INFO, "67890"); + ASSERT_NO_FATAL_FAILURE(CheckMessage(cap, android::base::INFO, "67890")); } TEST(logging, PLOG_does_not_clobber_errno) { @@ -438,7 +445,7 @@ TEST(logging, PLOG_does_not_clobber_errno) { PLOG(INFO) << (errno = 67890); EXPECT_EQ(12345, errno) << "errno was not restored"; - CheckMessage(cap, android::base::INFO, "67890"); + ASSERT_NO_FATAL_FAILURE(CheckMessage(cap, android::base::INFO, "67890")); } TEST(logging, LOG_does_not_have_dangling_if) { @@ -464,19 +471,21 @@ TEST(logging, LOG_does_not_have_dangling_if) { EXPECT_FALSE(flag) << "LOG macro probably has a dangling if with no else"; } -#define CHECK_PLOG_DISABLED(severity) \ - { \ +#define CHECK_PLOG_DISABLED(severity) \ + { \ android::base::ScopedLogSeverity sls1(android::base::FATAL); \ - CapturedStderr cap1; \ - PLOG(severity) << "foo bar"; \ - ASSERT_EQ(0, lseek(cap1.fd(), 0, SEEK_CUR)); \ - } \ - { \ + CapturedStderr cap1; \ + PLOG(severity) << "foo bar"; \ + cap1.Stop(); \ + ASSERT_EQ("", cap1.str()); \ + } \ + { \ android::base::ScopedLogSeverity sls1(android::base::FATAL); \ - CapturedStderr cap1; \ - PLOG(severity) << "foo bar"; \ - ASSERT_EQ(0, lseek(cap1.fd(), 0, SEEK_CUR)); \ - } \ + CapturedStderr cap1; \ + PLOG(severity) << "foo bar"; \ + cap1.Stop(); \ + ASSERT_EQ("", cap1.str()); \ + } #define CHECK_PLOG_ENABLED(severity) \ { \ @@ -504,7 +513,7 @@ TEST(logging, PLOG_FATAL_WITHOUT_ABORT_disabled) { } TEST(logging, PLOG_FATAL_WITHOUT_ABORT_enabled) { - CHECK_PLOG_ENABLED(FATAL_WITHOUT_ABORT); + ASSERT_NO_FATAL_FAILURE(CHECK_PLOG_ENABLED(FATAL_WITHOUT_ABORT)); } TEST(logging, PLOG_ERROR_disabled) { @@ -512,7 +521,7 @@ TEST(logging, PLOG_ERROR_disabled) { } TEST(logging, PLOG_ERROR_enabled) { - CHECK_PLOG_ENABLED(ERROR); + ASSERT_NO_FATAL_FAILURE(CHECK_PLOG_ENABLED(ERROR)); } TEST(logging, PLOG_WARNING_disabled) { @@ -520,7 +529,7 @@ TEST(logging, PLOG_WARNING_disabled) { } TEST(logging, PLOG_WARNING_enabled) { - CHECK_PLOG_ENABLED(WARNING); + ASSERT_NO_FATAL_FAILURE(CHECK_PLOG_ENABLED(WARNING)); } TEST(logging, PLOG_INFO_disabled) { @@ -528,7 +537,7 @@ TEST(logging, PLOG_INFO_disabled) { } TEST(logging, PLOG_INFO_enabled) { - CHECK_PLOG_ENABLED(INFO); + ASSERT_NO_FATAL_FAILURE(CHECK_PLOG_ENABLED(INFO)); } TEST(logging, PLOG_DEBUG_disabled) { @@ -536,7 +545,7 @@ TEST(logging, PLOG_DEBUG_disabled) { } TEST(logging, PLOG_DEBUG_enabled) { - CHECK_PLOG_ENABLED(DEBUG); + ASSERT_NO_FATAL_FAILURE(CHECK_PLOG_ENABLED(DEBUG)); } TEST(logging, PLOG_VERBOSE_disabled) { @@ -544,7 +553,7 @@ TEST(logging, PLOG_VERBOSE_disabled) { } TEST(logging, PLOG_VERBOSE_enabled) { - CHECK_PLOG_ENABLED(VERBOSE); + ASSERT_NO_FATAL_FAILURE(CHECK_PLOG_ENABLED(VERBOSE)); } #undef CHECK_PLOG_DISABLED @@ -557,7 +566,7 @@ TEST(logging, UNIMPLEMENTED) { CapturedStderr cap; errno = ENOENT; UNIMPLEMENTED(ERROR); - CheckMessage(cap, android::base::ERROR, expected.c_str()); + ASSERT_NO_FATAL_FAILURE(CheckMessage(cap, android::base::ERROR, expected.c_str())); } static void NoopAborter(const char* msg ATTRIBUTE_UNUSED) { @@ -565,17 +574,19 @@ static void NoopAborter(const char* msg ATTRIBUTE_UNUSED) { } TEST(logging, LOG_FATAL_NOOP_ABORTER) { + CapturedStderr cap; { android::base::SetAborter(NoopAborter); android::base::ScopedLogSeverity sls(android::base::ERROR); - CapturedStderr cap; LOG(FATAL) << "foobar"; - CheckMessage(cap, android::base::FATAL, "foobar"); - CheckMessage(cap, android::base::ERROR, "called noop"); + cap.Stop(); android::base::SetAborter(android::base::DefaultAborter); } + std::string output = cap.str(); + ASSERT_NO_FATAL_FAILURE(CheckMessage(output, android::base::FATAL, "foobar")); + ASSERT_NO_FATAL_FAILURE(CheckMessage(output, android::base::ERROR, "called noop")); ASSERT_DEATH({SuppressAbortUI(); LOG(FATAL) << "foobar";}, "foobar"); } @@ -619,25 +630,21 @@ TEST(logging, SetDefaultTag) { LOG(INFO) << expected_msg; android::base::SetDefaultTag(old_default_tag); } - CheckMessage(cap, android::base::LogSeverity::INFO, expected_msg, expected_tag); + ASSERT_NO_FATAL_FAILURE( + CheckMessage(cap, android::base::LogSeverity::INFO, expected_msg, expected_tag)); } TEST(logging, StdioLogger) { - std::string err_str; - std::string out_str; - { - CapturedStderr cap_err; - CapturedStdout cap_out; - android::base::SetLogger(android::base::StdioLogger); - LOG(INFO) << "out"; - LOG(ERROR) << "err"; - err_str = cap_err.str(); - out_str = cap_out.str(); - } + CapturedStderr cap_err; + CapturedStdout cap_out; + android::base::SetLogger(android::base::StdioLogger); + LOG(INFO) << "out"; + LOG(ERROR) << "err"; + cap_err.Stop(); + cap_out.Stop(); // For INFO we expect just the literal "out\n". - ASSERT_EQ("out\n", out_str) << out_str; + ASSERT_EQ("out\n", cap_out.str()); // Whereas ERROR logging includes the program name. - ASSERT_EQ(android::base::Basename(android::base::GetExecutablePath()) + ": err\n", err_str) - << err_str; + ASSERT_EQ(android::base::Basename(android::base::GetExecutablePath()) + ": err\n", cap_err.str()); } diff --git a/base/test_utils.cpp b/base/test_utils.cpp index 5096369e7..4d9466b30 100644 --- a/base/test_utils.cpp +++ b/base/test_utils.cpp @@ -126,11 +126,13 @@ bool TemporaryDir::init(const std::string& tmp_dir) { } CapturedStdFd::CapturedStdFd(int std_fd) : std_fd_(std_fd), old_fd_(-1) { - Init(); + Start(); } CapturedStdFd::~CapturedStdFd() { - Reset(); + if (old_fd_ != -1) { + Stop(); + } } int CapturedStdFd::fd() const { @@ -144,19 +146,28 @@ std::string CapturedStdFd::str() { return result; } -void CapturedStdFd::Init() { +void CapturedStdFd::Reset() { + // Do not reset while capturing. + CHECK_EQ(-1, old_fd_); + CHECK_EQ(0, TEMP_FAILURE_RETRY(lseek(fd(), 0, SEEK_SET))); + CHECK_EQ(0, ftruncate(fd(), 0)); +} + +void CapturedStdFd::Start() { #if defined(_WIN32) // On Windows, stderr is often buffered, so make sure it is unbuffered so // that we can immediately read back what was written to stderr. - if (std_fd_ == STDERR_FILENO) CHECK_EQ(0, setvbuf(stderr, NULL, _IONBF, 0)); + if (std_fd_ == STDERR_FILENO) CHECK_EQ(0, setvbuf(stderr, nullptr, _IONBF, 0)); #endif old_fd_ = dup(std_fd_); CHECK_NE(-1, old_fd_); CHECK_NE(-1, dup2(fd(), std_fd_)); } -void CapturedStdFd::Reset() { +void CapturedStdFd::Stop() { + CHECK_NE(-1, old_fd_); CHECK_NE(-1, dup2(old_fd_, std_fd_)); - CHECK_EQ(0, close(old_fd_)); + close(old_fd_); + old_fd_ = -1; // Note: cannot restore prior setvbuf() setting. } diff --git a/base/test_utils_test.cpp b/base/test_utils_test.cpp index 597271a72..15a79dd9d 100644 --- a/base/test_utils_test.cpp +++ b/base/test_utils_test.cpp @@ -14,6 +14,8 @@ * limitations under the License. */ +#include + #include "android-base/test_utils.h" #include @@ -42,5 +44,43 @@ TEST(TestUtilsTest, ExpectNotMatch) { EXPECT_NONFATAL_FAILURE(EXPECT_NOT_MATCH("foobar", R"(foobar)"), "regex mismatch"); } +TEST(TestUtilsTest, CaptureStdout_smoke) { + CapturedStdout cap; + printf("This should be captured.\n"); + cap.Stop(); + printf("This will not be captured.\n"); + ASSERT_EQ("This should be captured.\n", cap.str()); + + cap.Start(); + printf("And this text should be captured too.\n"); + cap.Stop(); + ASSERT_EQ("This should be captured.\nAnd this text should be captured too.\n", cap.str()); + + printf("Still not going to be captured.\n"); + cap.Reset(); + cap.Start(); + printf("Only this will be captured.\n"); + ASSERT_EQ("Only this will be captured.\n", cap.str()); +} + +TEST(TestUtilsTest, CaptureStderr_smoke) { + CapturedStderr cap; + fprintf(stderr, "This should be captured.\n"); + cap.Stop(); + fprintf(stderr, "This will not be captured.\n"); + ASSERT_EQ("This should be captured.\n", cap.str()); + + cap.Start(); + fprintf(stderr, "And this text should be captured too.\n"); + cap.Stop(); + ASSERT_EQ("This should be captured.\nAnd this text should be captured too.\n", cap.str()); + + fprintf(stderr, "Still not going to be captured.\n"); + cap.Reset(); + cap.Start(); + fprintf(stderr, "Only this will be captured.\n"); + ASSERT_EQ("Only this will be captured.\n", cap.str()); +} + } // namespace base } // namespace android