From af3503cff4f98b8165d67714a6cb15f9467106ff Mon Sep 17 00:00:00 2001 From: Mark Salyzyn Date: Tue, 27 Dec 2016 09:28:46 -0800 Subject: [PATCH 1/2] liblog: test failures due to permission issues Test: gTest liblog-unit-tests passes Change-Id: Ia9452b3ee9e6068723e8bef48c4d88d3769951a8 --- liblog/tests/liblog_test.cpp | 108 +++++++++++++++++++++++------------ 1 file changed, 71 insertions(+), 37 deletions(-) diff --git a/liblog/tests/liblog_test.cpp b/liblog/tests/liblog_test.cpp index 01a562c9f..371e6caca 100644 --- a/liblog/tests/liblog_test.cpp +++ b/liblog/tests/liblog_test.cpp @@ -214,6 +214,8 @@ static bool isLogdwActive() { } return false; } + +bool tested__android_log_close; #endif TEST(liblog, __android_log_btwrite__android_logger_list_read) { @@ -228,22 +230,33 @@ TEST(liblog, __android_log_btwrite__android_logger_list_read) { // Check that we can close and reopen the logger log_time ts(CLOCK_MONOTONIC); ASSERT_LT(0, __android_log_btwrite(0, EVENT_TYPE_LONG, &ts, sizeof(ts))); - bool pmsgActiveAfter__android_log_btwrite = isPmsgActive(); - bool logdwActiveAfter__android_log_btwrite = isLogdwActive(); - EXPECT_TRUE(pmsgActiveAfter__android_log_btwrite); - EXPECT_TRUE(logdwActiveAfter__android_log_btwrite); + bool pmsgActiveAfter__android_log_btwrite; + bool logdwActiveAfter__android_log_btwrite; + if (getuid() == AID_ROOT) { + tested__android_log_close = true; + pmsgActiveAfter__android_log_btwrite = isPmsgActive(); + logdwActiveAfter__android_log_btwrite = isLogdwActive(); + EXPECT_TRUE(pmsgActiveAfter__android_log_btwrite); + EXPECT_TRUE(logdwActiveAfter__android_log_btwrite); + } else if (!tested__android_log_close) { + fprintf(stderr, "WARNING: can not test __android_log_close()\n"); + } __android_log_close(); - bool pmsgActiveAfter__android_log_close = isPmsgActive(); - bool logdwActiveAfter__android_log_close = isLogdwActive(); - EXPECT_FALSE(pmsgActiveAfter__android_log_close); - EXPECT_FALSE(logdwActiveAfter__android_log_close); + if (getuid() == AID_ROOT) { + bool pmsgActiveAfter__android_log_close = isPmsgActive(); + bool logdwActiveAfter__android_log_close = isLogdwActive(); + EXPECT_FALSE(pmsgActiveAfter__android_log_close); + EXPECT_FALSE(logdwActiveAfter__android_log_close); + } log_time ts1(CLOCK_MONOTONIC); ASSERT_LT(0, __android_log_btwrite(0, EVENT_TYPE_LONG, &ts1, sizeof(ts1))); - pmsgActiveAfter__android_log_btwrite = isPmsgActive(); - logdwActiveAfter__android_log_btwrite = isLogdwActive(); - EXPECT_TRUE(pmsgActiveAfter__android_log_btwrite); - EXPECT_TRUE(logdwActiveAfter__android_log_btwrite); + if (getuid() == AID_ROOT) { + pmsgActiveAfter__android_log_btwrite = isPmsgActive(); + logdwActiveAfter__android_log_btwrite = isLogdwActive(); + EXPECT_TRUE(pmsgActiveAfter__android_log_btwrite); + EXPECT_TRUE(logdwActiveAfter__android_log_btwrite); + } usleep(1000000); int count = 0; @@ -539,7 +552,6 @@ TEST(liblog, __security_buffer) { bool set_persist = false; bool allow_security = false; - setuid(AID_SYSTEM); // only one that can read security buffer if (__android_log_security()) { allow_security = true; } else { @@ -612,6 +624,8 @@ TEST(liblog, __security_buffer) { return; } + setuid(AID_SYSTEM); // only one that can read security buffer + pid_t pid = getpid(); ASSERT_TRUE(NULL != (logger_list = android_logger_list_open( @@ -2662,10 +2676,15 @@ static const char __pmsg_file[] = TEST(liblog, __android_log_pmsg_file_write) { #ifdef __ANDROID__ __android_log_close(); - bool pmsgActiveAfter__android_log_close = isPmsgActive(); - bool logdwActiveAfter__android_log_close = isLogdwActive(); - EXPECT_FALSE(pmsgActiveAfter__android_log_close); - EXPECT_FALSE(logdwActiveAfter__android_log_close); + if (getuid() == AID_ROOT) { + tested__android_log_close = true; + bool pmsgActiveAfter__android_log_close = isPmsgActive(); + bool logdwActiveAfter__android_log_close = isLogdwActive(); + EXPECT_FALSE(pmsgActiveAfter__android_log_close); + EXPECT_FALSE(logdwActiveAfter__android_log_close); + } else if (!tested__android_log_close) { + fprintf(stderr, "WARNING: can not test __android_log_close()\n"); + } int return__android_log_pmsg_file_write = __android_log_pmsg_file_write( LOG_ID_CRASH, ANDROID_LOG_VERBOSE, __pmsg_file, max_payload_buf, sizeof(max_payload_buf)); @@ -2679,24 +2698,32 @@ TEST(liblog, __android_log_pmsg_file_write) { "with liblog.__android_log_msg_file_read test\n", __pmsg_file); } - bool pmsgActiveAfter__android_pmsg_file_write = isPmsgActive(); - bool logdwActiveAfter__android_pmsg_file_write = isLogdwActive(); - EXPECT_FALSE(pmsgActiveAfter__android_pmsg_file_write); - EXPECT_FALSE(logdwActiveAfter__android_pmsg_file_write); + bool pmsgActiveAfter__android_pmsg_file_write; + bool logdwActiveAfter__android_pmsg_file_write; + if (getuid() == AID_ROOT) { + pmsgActiveAfter__android_pmsg_file_write = isPmsgActive(); + logdwActiveAfter__android_pmsg_file_write = isLogdwActive(); + EXPECT_FALSE(pmsgActiveAfter__android_pmsg_file_write); + EXPECT_FALSE(logdwActiveAfter__android_pmsg_file_write); + } EXPECT_LT(0, __android_log_buf_print(LOG_ID_MAIN, ANDROID_LOG_INFO, "TEST__android_log_pmsg_file_write", "main")); - bool pmsgActiveAfter__android_log_buf_print = isPmsgActive(); - bool logdwActiveAfter__android_log_buf_print = isLogdwActive(); - EXPECT_TRUE(pmsgActiveAfter__android_log_buf_print); - EXPECT_TRUE(logdwActiveAfter__android_log_buf_print); + if (getuid() == AID_ROOT) { + bool pmsgActiveAfter__android_log_buf_print = isPmsgActive(); + bool logdwActiveAfter__android_log_buf_print = isLogdwActive(); + EXPECT_TRUE(pmsgActiveAfter__android_log_buf_print); + EXPECT_TRUE(logdwActiveAfter__android_log_buf_print); + } EXPECT_LT(0, __android_log_pmsg_file_write( LOG_ID_CRASH, ANDROID_LOG_VERBOSE, __pmsg_file, max_payload_buf, sizeof(max_payload_buf))); - pmsgActiveAfter__android_pmsg_file_write = isPmsgActive(); - logdwActiveAfter__android_pmsg_file_write = isLogdwActive(); - EXPECT_TRUE(pmsgActiveAfter__android_pmsg_file_write); - EXPECT_TRUE(logdwActiveAfter__android_pmsg_file_write); + if (getuid() == AID_ROOT) { + pmsgActiveAfter__android_pmsg_file_write = isPmsgActive(); + logdwActiveAfter__android_pmsg_file_write = isLogdwActive(); + EXPECT_TRUE(pmsgActiveAfter__android_pmsg_file_write); + EXPECT_TRUE(logdwActiveAfter__android_pmsg_file_write); + } #else GTEST_LOG_(INFO) << "This test does nothing.\n"; #endif @@ -2731,19 +2758,26 @@ TEST(liblog, __android_log_pmsg_file_read) { signaled = 0; __android_log_close(); - bool pmsgActiveAfter__android_log_close = isPmsgActive(); - bool logdwActiveAfter__android_log_close = isLogdwActive(); - EXPECT_FALSE(pmsgActiveAfter__android_log_close); - EXPECT_FALSE(logdwActiveAfter__android_log_close); + if (getuid() == AID_ROOT) { + tested__android_log_close = true; + bool pmsgActiveAfter__android_log_close = isPmsgActive(); + bool logdwActiveAfter__android_log_close = isLogdwActive(); + EXPECT_FALSE(pmsgActiveAfter__android_log_close); + EXPECT_FALSE(logdwActiveAfter__android_log_close); + } else if (!tested__android_log_close) { + fprintf(stderr, "WARNING: can not test __android_log_close()\n"); + } ssize_t ret = __android_log_pmsg_file_read( LOG_ID_CRASH, ANDROID_LOG_VERBOSE, __pmsg_file, __pmsg_fn, NULL); - bool pmsgActiveAfter__android_log_pmsg_file_read = isPmsgActive(); - bool logdwActiveAfter__android_log_pmsg_file_read = isLogdwActive(); - EXPECT_FALSE(pmsgActiveAfter__android_log_pmsg_file_read); - EXPECT_FALSE(logdwActiveAfter__android_log_pmsg_file_read); + if (getuid() == AID_ROOT) { + bool pmsgActiveAfter__android_log_pmsg_file_read = isPmsgActive(); + bool logdwActiveAfter__android_log_pmsg_file_read = isLogdwActive(); + EXPECT_FALSE(pmsgActiveAfter__android_log_pmsg_file_read); + EXPECT_FALSE(logdwActiveAfter__android_log_pmsg_file_read); + } if (ret == -ENOENT) { fprintf(stderr, From a46326a51c966fcd65463635c1fd4360e3d1d231 Mon Sep 17 00:00:00 2001 From: Mark Salyzyn Date: Tue, 27 Dec 2016 10:50:21 -0800 Subject: [PATCH 2/2] logcat: unit test produces log stutter logd now counts multiple identical messages, causing messages to be held back. Stop doing that in the tests. When that filter appeared, the logcat-unit-tests went from 23 seconds to a couple of minutes of runtime breakign the automated testing. Test: gTest logcat-unit-tests total time less than 1 minute. Bug: 33845198 Bug: 33535908 Change-Id: I6145bae89b6d5e5024ef4f8fe66440c9ae53f7c6 --- logcat/tests/logcat_test.cpp | 9 ++++++--- 1 file changed, 6 insertions(+), 3 deletions(-) diff --git a/logcat/tests/logcat_test.cpp b/logcat/tests/logcat_test.cpp index 11cffe64b..725d76e89 100644 --- a/logcat/tests/logcat_test.cpp +++ b/logcat/tests/logcat_test.cpp @@ -451,11 +451,12 @@ TEST(logcat, bad_buffer) { "logcat -v brief -b radio,events,bogo,system,main -g 2>/dev/null")); } -static void caught_blocking(int /*signum*/) +static void caught_blocking(int signum) { unsigned long long v = 0xDEADBEEFA55A0000ULL; v += getpid() & 0xFFFF; + if (signum == 0) ++v; LOG_FAILURE_RETRY(__android_log_btwrite(0, EVENT_TYPE_LONG, &v, sizeof(v))); } @@ -520,11 +521,12 @@ TEST(logcat, blocking) { EXPECT_EQ(1, signals); } -static void caught_blocking_tail(int /*signum*/) +static void caught_blocking_tail(int signum) { unsigned long long v = 0xA55ADEADBEEF0000ULL; v += getpid() & 0xFFFF; + if (signum == 0) ++v; LOG_FAILURE_RETRY(__android_log_btwrite(0, EVENT_TYPE_LONG, &v, sizeof(v))); } @@ -955,10 +957,11 @@ TEST(logcat, logrotate_nodir) { " -n 256 -r 1024")); } -static void caught_blocking_clear(int /*signum*/) { +static void caught_blocking_clear(int signum) { unsigned long long v = 0xDEADBEEFA55C0000ULL; v += getpid() & 0xFFFF; + if (signum == 0) ++v; LOG_FAILURE_RETRY(__android_log_btwrite(0, EVENT_TYPE_LONG, &v, sizeof(v))); }