From 219ef270a6907f4310bc1640ac404707c5a6ecc4 Mon Sep 17 00:00:00 2001 From: Mark Salyzyn Date: Mon, 17 Apr 2017 12:37:11 -0700 Subject: [PATCH 1/3] liblog: log_time add explicit to some constructors. (cherry pick from commit d87d47f7dda69bf5729c31fb832e6e42886e68c8) Add explicit to constructors, to prevent implicit conversions. Test: compile Bug: 37378309 Change-Id: I3f9f8d561e84c492eafa6528db7c238da072dad8 --- liblog/include/log/log_time.h | 15 +++++++-------- 1 file changed, 7 insertions(+), 8 deletions(-) diff --git a/liblog/include/log/log_time.h b/liblog/include/log/log_time.h index 5f70f7d4c..9ece0b328 100644 --- a/liblog/include/log/log_time.h +++ b/liblog/include/log/log_time.h @@ -41,13 +41,12 @@ struct log_time { static const uint32_t tv_sec_max = 0xFFFFFFFFUL; static const uint32_t tv_nsec_max = 999999999UL; - log_time(const timespec& T) { - tv_sec = static_cast(T.tv_sec); - tv_nsec = static_cast(T.tv_nsec); + log_time(const timespec& T) + : tv_sec(static_cast(T.tv_sec)), + tv_nsec(static_cast(T.tv_nsec)) { } - log_time(uint32_t sec, uint32_t nsec) { - tv_sec = sec; - tv_nsec = nsec; + explicit log_time(uint32_t sec, uint32_t nsec = 0) + : tv_sec(sec), tv_nsec(nsec) { } #ifdef _SYSTEM_CORE_INCLUDE_PRIVATE_ANDROID_LOGGER_H_ #define __struct_log_time_private_defined @@ -56,14 +55,14 @@ struct log_time { log_time() { } #ifdef __linux__ - log_time(clockid_t id) { + explicit log_time(clockid_t id) { timespec T; clock_gettime(id, &T); tv_sec = static_cast(T.tv_sec); tv_nsec = static_cast(T.tv_nsec); } #endif - log_time(const char* T) { + explicit log_time(const char* T) { const uint8_t* c = reinterpret_cast(T); tv_sec = c[0] | (static_cast(c[1]) << 8) | (static_cast(c[2]) << 16) | From 9decb90e8c445d775a908f9282b8e58fe3f5ae07 Mon Sep 17 00:00:00 2001 From: Mark Salyzyn Date: Mon, 17 Apr 2017 12:46:12 -0700 Subject: [PATCH 2/3] logd: iterator corruption paranoia (cherry pick from commit 3614a0c5d4aec84fbc5f6cbf1e919e8b3825b818) Add checking for impossible(tm) scenarios within LogBuffer::flushTo: 1) When iterating through the log entries, check if the iterator returns two identical element references and break out of the loop. 2) Cap the maximum number of log entries we will skip while holding the iterator lock at 4194304, break out of the loop. We print a message to the kernel logs if we hit these cases. ToDo: Remove this paranoia at some future date. Test: gTest liblog-unit-tests logcat-unit-tests and logd-unit-tests Bug: 37378309 Change-Id: I789594649db14093238828b9f6d1daeca8b780c2 --- logd/LogBuffer.cpp | 14 ++++++++++++++ 1 file changed, 14 insertions(+) diff --git a/logd/LogBuffer.cpp b/logd/LogBuffer.cpp index 1eda15d3f..4aa2c9fa0 100644 --- a/logd/LogBuffer.cpp +++ b/logd/LogBuffer.cpp @@ -1120,9 +1120,22 @@ log_time LogBuffer::flushTo(SocketClient* reader, const log_time& start, log_time max = start; + LogBufferElement* lastElement = nullptr; // iterator corruption paranoia + static const size_t maxSkip = 4194304; // maximum entries to skip + size_t skip = maxSkip; for (; it != mLogElements.end(); ++it) { LogBufferElement* element = *it; + if (!--skip) { + android::prdebug("reader.per: too many elements skipped"); + break; + } + if (element == lastElement) { + android::prdebug("reader.per: identical elements"); + break; + } + lastElement = element; + if (!privileged && (element->getUid() != uid)) { continue; } @@ -1167,6 +1180,7 @@ log_time LogBuffer::flushTo(SocketClient* reader, const log_time& start, return max; } + skip = maxSkip; pthread_mutex_lock(&mLogElementsLock); } pthread_mutex_unlock(&mLogElementsLock); From 0a0a4652aaf33e3b20c3c546b4539f09c552721a Mon Sep 17 00:00:00 2001 From: Mark Salyzyn Date: Mon, 17 Apr 2017 12:39:13 -0700 Subject: [PATCH 3/3] logd: instrument tests better for failure (cherry pick from commit 24aa9a41e158e197ff8c22c731a9208d650a0a38) Failure to open socket misbehaved and told us nothing. Test: gTest logd-unit-tests Bug: 37378309 Change-Id: Iec369a50ccb1027e96947465e90d9572c9f4047f --- logd/tests/logd_test.cpp | 16 ++++++++++++---- 1 file changed, 12 insertions(+), 4 deletions(-) diff --git a/logd/tests/logd_test.cpp b/logd/tests/logd_test.cpp index ddff39350..c81aa32be 100644 --- a/logd/tests/logd_test.cpp +++ b/logd/tests/logd_test.cpp @@ -668,8 +668,12 @@ TEST(logd, timeout) { while (--i) { int fd = socket_local_client("logdr", ANDROID_SOCKET_NAMESPACE_RESERVED, SOCK_SEQPACKET); - EXPECT_LT(0, fd); - if (fd < 0) _exit(fd); + int save_errno = errno; + if (fd < 0) { + fprintf(stderr, "failed to open /dev/socket/logdr %s\n", + strerror(save_errno)); + _exit(fd); + } std::string ask = android::base::StringPrintf( "dumpAndClose lids=0,1,2,3,4,5 timeout=6 start=%" PRIu32 @@ -721,8 +725,12 @@ TEST(logd, timeout) { // active _or_ inactive during the test. if (content_timeout) { log_time msg(msg_timeout.entry.sec, msg_timeout.entry.nsec); - EXPECT_FALSE(msg < now); - if (msg < now) _exit(-1); + if (msg < now) { + fprintf(stderr, "%u.%09u < %u.%09u\n", msg_timeout.entry.sec, + msg_timeout.entry.nsec, (unsigned)now.tv_sec, + (unsigned)now.tv_nsec); + _exit(-1); + } if (msg > now) { now = msg; now.tv_sec += 30;