Loading liblog/include/log/log_time.h +7 −8 Original line number Diff line number Diff line Loading @@ -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<uint32_t>(T.tv_sec); tv_nsec = static_cast<uint32_t>(T.tv_nsec); log_time(const timespec& T) : tv_sec(static_cast<uint32_t>(T.tv_sec)), tv_nsec(static_cast<uint32_t>(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 Loading @@ -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<uint32_t>(T.tv_sec); tv_nsec = static_cast<uint32_t>(T.tv_nsec); } #endif log_time(const char* T) { explicit log_time(const char* T) { const uint8_t* c = reinterpret_cast<const uint8_t*>(T); tv_sec = c[0] | (static_cast<uint32_t>(c[1]) << 8) | (static_cast<uint32_t>(c[2]) << 16) | Loading logd/LogBuffer.cpp +26 −6 Original line number Diff line number Diff line Loading @@ -43,6 +43,8 @@ // Default #define log_buffer_size(id) mMaxSize[id] const log_time LogBuffer::pruneMargin(3, 0); void LogBuffer::init() { log_id_for_each(i) { mLastSet[i] = false; Loading Loading @@ -672,6 +674,8 @@ bool LogBuffer::prune(log_id_t id, unsigned long pruneRows, uid_t caller_uid) { } times++; } log_time watermark(log_time::tv_sec_max, log_time::tv_nsec_max); if (oldest) watermark = oldest->mStart - pruneMargin; LogBufferElementCollection::iterator it; Loading @@ -693,7 +697,7 @@ bool LogBuffer::prune(log_id_t id, unsigned long pruneRows, uid_t caller_uid) { mLastSet[id] = true; } if (oldest && (oldest->mStart <= element->getRealTime().nsec())) { if (oldest && (watermark <= element->getRealTime())) { busy = true; if (oldest->mTimeout.tv_sec || oldest->mTimeout.tv_nsec) { oldest->triggerReader_Locked(); Loading Loading @@ -785,7 +789,7 @@ bool LogBuffer::prune(log_id_t id, unsigned long pruneRows, uid_t caller_uid) { while (it != mLogElements.end()) { LogBufferElement* element = *it; if (oldest && (oldest->mStart <= element->getRealTime().nsec())) { if (oldest && (watermark <= element->getRealTime())) { busy = true; if (oldest->mTimeout.tv_sec || oldest->mTimeout.tv_nsec) { oldest->triggerReader_Locked(); Loading Loading @@ -939,7 +943,7 @@ bool LogBuffer::prune(log_id_t id, unsigned long pruneRows, uid_t caller_uid) { mLastSet[id] = true; } if (oldest && (oldest->mStart <= element->getRealTime().nsec())) { if (oldest && (watermark <= element->getRealTime())) { busy = true; if (whitelist) { break; Loading Loading @@ -983,7 +987,7 @@ bool LogBuffer::prune(log_id_t id, unsigned long pruneRows, uid_t caller_uid) { mLastSet[id] = true; } if (oldest && (oldest->mStart <= element->getRealTime().nsec())) { if (oldest && (watermark <= element->getRealTime())) { busy = true; if (stats.sizes(id) > (2 * log_buffer_size(id))) { // kick a misbehaving log reader client off the island Loading Loading @@ -1090,13 +1094,15 @@ log_time LogBuffer::flushTo(SocketClient* reader, const log_time& start, // client wants to start from the beginning it = mLogElements.begin(); } else { LogBufferElementCollection::iterator last; // 3 second limit to continue search for out-of-order entries. log_time min = start - log_time(3, 0); log_time min = start - pruneMargin; // Cap to 300 iterations we look back for out-of-order entries. size_t count = 300; // Client wants to start from some specified time. Chances are // we are better off starting from the end of the time sorted list. LogBufferElementCollection::iterator last; for (last = it = mLogElements.end(); it != mLogElements.begin(); /* do nothing */) { --it; Loading @@ -1112,9 +1118,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; } Loading Loading @@ -1159,6 +1178,7 @@ log_time LogBuffer::flushTo(SocketClient* reader, const log_time& start, return max; } skip = maxSkip; pthread_mutex_lock(&mLogElementsLock); } pthread_mutex_unlock(&mLogElementsLock); Loading logd/LogBuffer.h +1 −0 Original line number Diff line number Diff line Loading @@ -174,6 +174,7 @@ class LogBuffer { private: static constexpr size_t minPrune = 4; static constexpr size_t maxPrune = 256; static const log_time pruneMargin; void maybePrune(log_id_t id); bool prune(log_id_t id, unsigned long pruneRows, uid_t uid = AID_ROOT); Loading logd/tests/logd_test.cpp +12 −4 Original line number Diff line number Diff line Loading @@ -670,8 +670,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 Loading Loading @@ -723,8 +727,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; Loading Loading
liblog/include/log/log_time.h +7 −8 Original line number Diff line number Diff line Loading @@ -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<uint32_t>(T.tv_sec); tv_nsec = static_cast<uint32_t>(T.tv_nsec); log_time(const timespec& T) : tv_sec(static_cast<uint32_t>(T.tv_sec)), tv_nsec(static_cast<uint32_t>(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 Loading @@ -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<uint32_t>(T.tv_sec); tv_nsec = static_cast<uint32_t>(T.tv_nsec); } #endif log_time(const char* T) { explicit log_time(const char* T) { const uint8_t* c = reinterpret_cast<const uint8_t*>(T); tv_sec = c[0] | (static_cast<uint32_t>(c[1]) << 8) | (static_cast<uint32_t>(c[2]) << 16) | Loading
logd/LogBuffer.cpp +26 −6 Original line number Diff line number Diff line Loading @@ -43,6 +43,8 @@ // Default #define log_buffer_size(id) mMaxSize[id] const log_time LogBuffer::pruneMargin(3, 0); void LogBuffer::init() { log_id_for_each(i) { mLastSet[i] = false; Loading Loading @@ -672,6 +674,8 @@ bool LogBuffer::prune(log_id_t id, unsigned long pruneRows, uid_t caller_uid) { } times++; } log_time watermark(log_time::tv_sec_max, log_time::tv_nsec_max); if (oldest) watermark = oldest->mStart - pruneMargin; LogBufferElementCollection::iterator it; Loading @@ -693,7 +697,7 @@ bool LogBuffer::prune(log_id_t id, unsigned long pruneRows, uid_t caller_uid) { mLastSet[id] = true; } if (oldest && (oldest->mStart <= element->getRealTime().nsec())) { if (oldest && (watermark <= element->getRealTime())) { busy = true; if (oldest->mTimeout.tv_sec || oldest->mTimeout.tv_nsec) { oldest->triggerReader_Locked(); Loading Loading @@ -785,7 +789,7 @@ bool LogBuffer::prune(log_id_t id, unsigned long pruneRows, uid_t caller_uid) { while (it != mLogElements.end()) { LogBufferElement* element = *it; if (oldest && (oldest->mStart <= element->getRealTime().nsec())) { if (oldest && (watermark <= element->getRealTime())) { busy = true; if (oldest->mTimeout.tv_sec || oldest->mTimeout.tv_nsec) { oldest->triggerReader_Locked(); Loading Loading @@ -939,7 +943,7 @@ bool LogBuffer::prune(log_id_t id, unsigned long pruneRows, uid_t caller_uid) { mLastSet[id] = true; } if (oldest && (oldest->mStart <= element->getRealTime().nsec())) { if (oldest && (watermark <= element->getRealTime())) { busy = true; if (whitelist) { break; Loading Loading @@ -983,7 +987,7 @@ bool LogBuffer::prune(log_id_t id, unsigned long pruneRows, uid_t caller_uid) { mLastSet[id] = true; } if (oldest && (oldest->mStart <= element->getRealTime().nsec())) { if (oldest && (watermark <= element->getRealTime())) { busy = true; if (stats.sizes(id) > (2 * log_buffer_size(id))) { // kick a misbehaving log reader client off the island Loading Loading @@ -1090,13 +1094,15 @@ log_time LogBuffer::flushTo(SocketClient* reader, const log_time& start, // client wants to start from the beginning it = mLogElements.begin(); } else { LogBufferElementCollection::iterator last; // 3 second limit to continue search for out-of-order entries. log_time min = start - log_time(3, 0); log_time min = start - pruneMargin; // Cap to 300 iterations we look back for out-of-order entries. size_t count = 300; // Client wants to start from some specified time. Chances are // we are better off starting from the end of the time sorted list. LogBufferElementCollection::iterator last; for (last = it = mLogElements.end(); it != mLogElements.begin(); /* do nothing */) { --it; Loading @@ -1112,9 +1118,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; } Loading Loading @@ -1159,6 +1178,7 @@ log_time LogBuffer::flushTo(SocketClient* reader, const log_time& start, return max; } skip = maxSkip; pthread_mutex_lock(&mLogElementsLock); } pthread_mutex_unlock(&mLogElementsLock); Loading
logd/LogBuffer.h +1 −0 Original line number Diff line number Diff line Loading @@ -174,6 +174,7 @@ class LogBuffer { private: static constexpr size_t minPrune = 4; static constexpr size_t maxPrune = 256; static const log_time pruneMargin; void maybePrune(log_id_t id); bool prune(log_id_t id, unsigned long pruneRows, uid_t uid = AID_ROOT); Loading
logd/tests/logd_test.cpp +12 −4 Original line number Diff line number Diff line Loading @@ -670,8 +670,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 Loading Loading @@ -723,8 +727,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; Loading