diff --git a/logd/Android.bp b/logd/Android.bp index 26632713d..b6d30cde8 100644 --- a/logd/Android.bp +++ b/logd/Android.bp @@ -36,9 +36,9 @@ cc_library_static { "CommandListener.cpp", "LogListener.cpp", "LogReader.cpp", + "LogReaderThread.cpp", "LogBuffer.cpp", "LogBufferElement.cpp", - "LogTimes.cpp", "LogStatistics.cpp", "LogWhiteBlackList.cpp", "libaudit.c", diff --git a/logd/LogAudit.cpp b/logd/LogAudit.cpp index d9cc0dba3..37067bd81 100644 --- a/logd/LogAudit.cpp +++ b/logd/LogAudit.cpp @@ -277,7 +277,7 @@ int LogAudit::logPrint(const char* fmt, ...) { : LOGGER_ENTRY_MAX_PAYLOAD; size_t message_len = str_len + sizeof(android_log_event_string_t); - log_mask_t notify = 0; + unsigned int notify = 0; if (events) { // begin scope for event buffer uint32_t buffer[(message_len + sizeof(uint32_t) - 1) / sizeof(uint32_t)]; diff --git a/logd/LogBuffer.cpp b/logd/LogBuffer.cpp index a3e4e094e..a7323e8e9 100644 --- a/logd/LogBuffer.cpp +++ b/logd/LogBuffer.cpp @@ -93,16 +93,16 @@ void LogBuffer::init() { } // Release any sleeping reader threads to dump their current content. - LogTimeEntry::wrlock(); + LogReaderThread::wrlock(); LastLogTimes::iterator times = mTimes.begin(); while (times != mTimes.end()) { - LogTimeEntry* entry = times->get(); + LogReaderThread* entry = times->get(); entry->triggerReader_Locked(); times++; } - LogTimeEntry::unlock(); + LogReaderThread::unlock(); } LogBuffer::LogBuffer(LastLogTimes* times, LogTags* tags, PruneList* prune) @@ -579,14 +579,14 @@ class LogBufferElementLast { // If the selected reader is blocking our pruning progress, decide on // what kind of mitigation is necessary to unblock the situation. -void LogBuffer::kickMe(LogTimeEntry* me, log_id_t id, unsigned long pruneRows) { +void LogBuffer::kickMe(LogReaderThread* me, log_id_t id, unsigned long pruneRows) { if (stats.sizes(id) > (2 * log_buffer_size(id))) { // +100% // A misbehaving or slow reader has its connection // dropped if we hit too much memory pressure. android::prdebug("Kicking blocked reader, pid %d, from LogBuffer::kickMe()\n", - me->mClient->getPid()); + me->client()->getPid()); me->release_Locked(); - } else if (me->mTimeout.tv_sec || me->mTimeout.tv_nsec) { + } else if (me->timeout().tv_sec || me->timeout().tv_nsec) { // Allow a blocked WRAP timeout reader to // trigger and start reporting the log data. me->triggerReader_Locked(); @@ -594,7 +594,7 @@ void LogBuffer::kickMe(LogTimeEntry* me, log_id_t id, unsigned long pruneRows) { // tell slow reader to skip entries to catch up android::prdebug( "Skipping %lu entries from slow reader, pid %d, from LogBuffer::kickMe()\n", - pruneRows, me->mClient->getPid()); + pruneRows, me->client()->getPid()); me->triggerSkip_Locked(id, pruneRows); } } @@ -647,20 +647,19 @@ void LogBuffer::kickMe(LogTimeEntry* me, log_id_t id, unsigned long pruneRows) { // LogBuffer::wrlock() must be held when this function is called. // bool LogBuffer::prune(log_id_t id, unsigned long pruneRows, uid_t caller_uid) { - LogTimeEntry* oldest = nullptr; + LogReaderThread* oldest = nullptr; bool busy = false; bool clearAll = pruneRows == ULONG_MAX; - LogTimeEntry::rdlock(); + LogReaderThread::rdlock(); // Region locked? LastLogTimes::iterator times = mTimes.begin(); while (times != mTimes.end()) { - LogTimeEntry* entry = times->get(); - if (entry->isWatching(id) && - (!oldest || (oldest->mStart > entry->mStart) || - ((oldest->mStart == entry->mStart) && - (entry->mTimeout.tv_sec || entry->mTimeout.tv_nsec)))) { + LogReaderThread* entry = times->get(); + if (entry->IsWatching(id) && (!oldest || oldest->start() > entry->start() || + (oldest->start() == entry->start() && + (entry->timeout().tv_sec || entry->timeout().tv_nsec)))) { oldest = entry; } times++; @@ -681,7 +680,7 @@ bool LogBuffer::prune(log_id_t id, unsigned long pruneRows, uid_t caller_uid) { continue; } - if (oldest && oldest->mStart <= element->getSequence()) { + if (oldest && oldest->start() <= element->getSequence()) { busy = true; kickMe(oldest, id, pruneRows); break; @@ -692,7 +691,7 @@ bool LogBuffer::prune(log_id_t id, unsigned long pruneRows, uid_t caller_uid) { break; } } - LogTimeEntry::unlock(); + LogReaderThread::unlock(); return busy; } @@ -772,7 +771,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->getSequence()) { + if (oldest && oldest->start() <= element->getSequence()) { busy = true; // Do not let chatty eliding trigger any reader mitigation break; @@ -914,7 +913,7 @@ bool LogBuffer::prune(log_id_t id, unsigned long pruneRows, uid_t caller_uid) { continue; } - if (oldest && oldest->mStart <= element->getSequence()) { + if (oldest && oldest->start() <= element->getSequence()) { busy = true; if (!whitelist) kickMe(oldest, id, pruneRows); break; @@ -942,7 +941,7 @@ bool LogBuffer::prune(log_id_t id, unsigned long pruneRows, uid_t caller_uid) { continue; } - if (oldest && oldest->mStart <= element->getSequence()) { + if (oldest && oldest->start() <= element->getSequence()) { busy = true; kickMe(oldest, id, pruneRows); break; @@ -953,7 +952,7 @@ bool LogBuffer::prune(log_id_t id, unsigned long pruneRows, uid_t caller_uid) { } } - LogTimeEntry::unlock(); + LogReaderThread::unlock(); return (pruneRows > 0) && busy; } @@ -976,20 +975,20 @@ bool LogBuffer::clear(log_id_t id, uid_t uid) { // readers and let the clear run (below) deal with determining // if we are still blocked and return an error code to caller. if (busy) { - LogTimeEntry::wrlock(); + LogReaderThread::wrlock(); LastLogTimes::iterator times = mTimes.begin(); while (times != mTimes.end()) { - LogTimeEntry* entry = times->get(); + LogReaderThread* entry = times->get(); // Killer punch - if (entry->isWatching(id)) { + if (entry->IsWatching(id)) { android::prdebug( "Kicking blocked reader, pid %d, from LogBuffer::clear()\n", - entry->mClient->getPid()); + entry->client()->getPid()); entry->release_Locked(); } times++; } - LogTimeEntry::unlock(); + LogReaderThread::unlock(); } } wrlock(); @@ -1033,7 +1032,7 @@ unsigned long LogBuffer::getSize(log_id_t id) { uint64_t LogBuffer::flushTo(SocketClient* reader, uint64_t start, pid_t* lastTid, bool privileged, bool security, - int (*filter)(const LogBufferElement* element, void* arg), void* arg) { + const std::function& filter) { LogBufferElementCollection::iterator it; uid_t uid = reader->getUid(); @@ -1071,7 +1070,7 @@ uint64_t LogBuffer::flushTo(SocketClient* reader, uint64_t start, pid_t* lastTid // NB: calling out to another object with wrlock() held (safe) if (filter) { - int ret = (*filter)(element, arg); + int ret = filter(element); if (ret == false) { continue; } diff --git a/logd/LogBuffer.h b/logd/LogBuffer.h index 9a367127a..eb41efb0f 100644 --- a/logd/LogBuffer.h +++ b/logd/LogBuffer.h @@ -27,9 +27,9 @@ #include #include "LogBufferElement.h" +#include "LogReaderThread.h" #include "LogStatistics.h" #include "LogTags.h" -#include "LogTimes.h" #include "LogWhiteBlackList.h" // @@ -115,8 +115,7 @@ class LogBuffer { uint64_t flushTo(SocketClient* writer, uint64_t start, pid_t* lastTid, // &lastTid[LOG_ID_MAX] or nullptr bool privileged, bool security, - int (*filter)(const LogBufferElement* element, void* arg) = nullptr, - void* arg = nullptr); + const std::function& filter); bool clear(log_id_t id, uid_t uid = AID_ROOT); unsigned long getSize(log_id_t id); @@ -152,7 +151,7 @@ class LogBuffer { static constexpr size_t maxPrune = 256; void maybePrune(log_id_t id); - void kickMe(LogTimeEntry* me, log_id_t id, unsigned long pruneRows); + void kickMe(LogReaderThread* me, log_id_t id, unsigned long pruneRows); bool prune(log_id_t id, unsigned long pruneRows, uid_t uid = AID_ROOT); LogBufferElementCollection::iterator erase( diff --git a/logd/LogKlog.cpp b/logd/LogKlog.cpp index edd326aec..5788ada47 100644 --- a/logd/LogKlog.cpp +++ b/logd/LogKlog.cpp @@ -819,7 +819,7 @@ int LogKlog::log(const char* buf, ssize_t len) { // notify readers if (rc > 0) { - reader->notifyNewLog(static_cast(1 << LOG_ID_KERNEL)); + reader->notifyNewLog(static_cast(1 << LOG_ID_KERNEL)); } return rc; diff --git a/logd/LogListener.cpp b/logd/LogListener.cpp index ba610424f..138ab2814 100644 --- a/logd/LogListener.cpp +++ b/logd/LogListener.cpp @@ -108,7 +108,7 @@ bool LogListener::onDataAvailable(SocketClient* cli) { int res = logbuf->log(logId, header->realtime, cred->uid, cred->pid, header->tid, msg, ((size_t)n <= UINT16_MAX) ? (uint16_t)n : UINT16_MAX); if (res > 0) { - reader->notifyNewLog(static_cast(1 << logId)); + reader->notifyNewLog(static_cast(1 << logId)); } return true; diff --git a/logd/LogReader.cpp b/logd/LogReader.cpp index c6dea69f8..4702de55e 100644 --- a/logd/LogReader.cpp +++ b/logd/LogReader.cpp @@ -39,20 +39,20 @@ LogReader::LogReader(LogBuffer* logbuf) // When we are notified a new log entry is available, inform // listening sockets who are watching this entry's log id. -void LogReader::notifyNewLog(log_mask_t log_mask) { +void LogReader::notifyNewLog(unsigned int log_mask) { LastLogTimes& times = mLogbuf.mTimes; - LogTimeEntry::wrlock(); + LogReaderThread::wrlock(); for (const auto& entry : times) { - if (!entry->isWatchingMultiple(log_mask)) { + if (!entry->IsWatchingMultiple(log_mask)) { continue; } - if (entry->mTimeout.tv_sec || entry->mTimeout.tv_nsec) { + if (entry->timeout().tv_sec || entry->timeout().tv_nsec) { continue; } entry->triggerReader_Locked(); } - LogTimeEntry::unlock(); + LogReaderThread::unlock(); } // Note returning false will release the SocketClient instance. @@ -74,15 +74,15 @@ bool LogReader::onDataAvailable(SocketClient* cli) { // Clients are only allowed to send one command, disconnect them if they // send another. - LogTimeEntry::wrlock(); + LogReaderThread::wrlock(); for (const auto& entry : mLogbuf.mTimes) { - if (entry->mClient == cli) { + if (entry->client() == cli) { entry->release_Locked(); - LogTimeEntry::unlock(); + LogReaderThread::unlock(); return false; } } - LogTimeEntry::unlock(); + LogReaderThread::unlock(); unsigned long tail = 0; static const char _tail[] = " tail="; @@ -137,8 +137,8 @@ bool LogReader::onDataAvailable(SocketClient* cli) { if (!fastcmp(buffer, "dumpAndClose", 12)) { // Allow writer to get some cycles, and wait for pending notifications sched_yield(); - LogTimeEntry::wrlock(); - LogTimeEntry::unlock(); + LogReaderThread::wrlock(); + LogReaderThread::unlock(); sched_yield(); nonBlock = true; } @@ -149,56 +149,37 @@ bool LogReader::onDataAvailable(SocketClient* cli) { uint64_t sequence = 1; // Convert realtime to sequence number if (start != log_time::EPOCH) { - class LogFindStart { - const pid_t mPid; - const unsigned mLogMask; - bool startTimeSet; - const log_time start; - uint64_t& sequence; - uint64_t last; - bool isMonotonic; - - public: - LogFindStart(unsigned logMask, pid_t pid, log_time start, uint64_t& sequence, - bool isMonotonic) - : mPid(pid), - mLogMask(logMask), - startTimeSet(false), - start(start), - sequence(sequence), - last(sequence), - isMonotonic(isMonotonic) {} - - static int callback(const LogBufferElement* element, void* obj) { - LogFindStart* me = reinterpret_cast(obj); - if ((!me->mPid || (me->mPid == element->getPid())) && - (me->mLogMask & (1 << element->getLogId()))) { - if (me->start == element->getRealTime()) { - me->sequence = element->getSequence(); - me->startTimeSet = true; - return -1; - } else if (!me->isMonotonic || android::isMonotonic(element->getRealTime())) { - if (me->start < element->getRealTime()) { - me->sequence = me->last; - me->startTimeSet = true; - return -1; - } - me->last = element->getSequence(); - } else { - me->last = element->getSequence(); - } - } - return false; + bool start_time_set = false; + bool is_monotonic = logbuf().isMonotonic() && android::isMonotonic(start); + uint64_t last = sequence; + auto log_find_start = [pid, logMask, start, is_monotonic, &sequence, &start_time_set, + &last](const LogBufferElement* element) -> int { + if (pid && pid != element->getPid()) { + return 0; } + if ((logMask & (1 << element->getLogId())) == 0) { + return 0; + } + if (start == element->getRealTime()) { + sequence = element->getSequence(); + start_time_set = true; + return -1; + } else if (!is_monotonic || android::isMonotonic(element->getRealTime())) { + if (start < element->getRealTime()) { + sequence = last; + start_time_set = true; + return -1; + } + last = element->getSequence(); + } else { + last = element->getSequence(); + } + return 0; + }; - bool found() { return startTimeSet; } - } logFindStart(logMask, pid, start, sequence, - logbuf().isMonotonic() && android::isMonotonic(start)); + logbuf().flushTo(cli, sequence, nullptr, privileged, can_read_security, log_find_start); - logbuf().flushTo(cli, sequence, nullptr, privileged, can_read_security, - logFindStart.callback, &logFindStart); - - if (!logFindStart.found()) { + if (!start_time_set) { if (nonBlock) { doSocketDelete(cli); return false; @@ -217,11 +198,12 @@ bool LogReader::onDataAvailable(SocketClient* cli) { timeout = 0; } - LogTimeEntry::wrlock(); - auto entry = std::make_unique(*this, cli, nonBlock, tail, logMask, pid, start, - sequence, timeout, privileged, can_read_security); + LogReaderThread::wrlock(); + auto entry = + std::make_unique(*this, cli, nonBlock, tail, logMask, pid, start, + sequence, timeout, privileged, can_read_security); if (!entry->startReader_Locked()) { - LogTimeEntry::unlock(); + LogReaderThread::unlock(); return false; } @@ -234,24 +216,24 @@ bool LogReader::onDataAvailable(SocketClient* cli) { setsockopt(cli->getSocket(), SOL_SOCKET, SO_SNDTIMEO, (const char*)&t, sizeof(t)); - LogTimeEntry::unlock(); + LogReaderThread::unlock(); return true; } void LogReader::doSocketDelete(SocketClient* cli) { LastLogTimes& times = mLogbuf.mTimes; - LogTimeEntry::wrlock(); + LogReaderThread::wrlock(); LastLogTimes::iterator it = times.begin(); while (it != times.end()) { - LogTimeEntry* entry = it->get(); - if (entry->mClient == cli) { + LogReaderThread* entry = it->get(); + if (entry->client() == cli) { entry->release_Locked(); break; } it++; } - LogTimeEntry::unlock(); + LogReaderThread::unlock(); } int LogReader::getLogSocket() { diff --git a/logd/LogReader.h b/logd/LogReader.h index b5312b60d..f00cc21cd 100644 --- a/logd/LogReader.h +++ b/logd/LogReader.h @@ -14,12 +14,11 @@ * limitations under the License. */ -#ifndef _LOGD_LOG_WRITER_H__ -#define _LOGD_LOG_WRITER_H__ +#pragma once #include -#include "LogTimes.h" +#include "LogReaderThread.h" #define LOGD_SNDTIMEO 32 @@ -30,7 +29,7 @@ class LogReader : public SocketListener { public: explicit LogReader(LogBuffer* logbuf); - void notifyNewLog(log_mask_t logMask); + void notifyNewLog(unsigned int logMask); LogBuffer& logbuf(void) const { return mLogbuf; @@ -44,5 +43,3 @@ class LogReader : public SocketListener { void doSocketDelete(SocketClient* cli); }; - -#endif diff --git a/logd/LogReaderThread.cpp b/logd/LogReaderThread.cpp new file mode 100644 index 000000000..5413c4de1 --- /dev/null +++ b/logd/LogReaderThread.cpp @@ -0,0 +1,240 @@ +/* + * Copyright (C) 2014 The Android Open Source Project + * + * Licensed under the Apache License, Version 2.0 (the "License"); + * you may not use this file except in compliance with the License. + * You may obtain a copy of the License at + * + * http://www.apache.org/licenses/LICENSE-2.0 + * + * Unless required by applicable law or agreed to in writing, software + * distributed under the License is distributed on an "AS IS" BASIS, + * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. + * See the License for the specific language governing permissions and + * limitations under the License. + */ + +#include "LogReaderThread.h" + +#include +#include +#include + +#include + +#include "LogBuffer.h" +#include "LogReader.h" + +using namespace std::placeholders; + +pthread_mutex_t LogReaderThread::timesLock = PTHREAD_MUTEX_INITIALIZER; + +LogReaderThread::LogReaderThread(LogReader& reader, SocketClient* client, bool non_block, + unsigned long tail, unsigned int log_mask, pid_t pid, + log_time start_time, uint64_t start, uint64_t timeout, + bool privileged, bool can_read_security_logs) + : leading_dropped_(false), + reader_(reader), + log_mask_(log_mask), + pid_(pid), + tail_(tail), + count_(0), + index_(0), + client_(client), + start_time_(start_time), + start_(start), + non_block_(non_block), + privileged_(privileged), + can_read_security_logs_(can_read_security_logs) { + timeout_.tv_sec = timeout / NS_PER_SEC; + timeout_.tv_nsec = timeout % NS_PER_SEC; + memset(last_tid_, 0, sizeof(last_tid_)); + pthread_cond_init(&thread_triggered_condition_, nullptr); + cleanSkip_Locked(); +} + +bool LogReaderThread::startReader_Locked() { + auto thread = std::thread{&LogReaderThread::ThreadFunction, this}; + thread.detach(); + return true; +} + +void LogReaderThread::ThreadFunction() { + prctl(PR_SET_NAME, "logd.reader.per"); + + SocketClient* client = client_; + + LogBuffer& logbuf = reader_.logbuf(); + + leading_dropped_ = true; + + wrlock(); + + uint64_t start = start_; + + while (!release_) { + if (timeout_.tv_sec || timeout_.tv_nsec) { + if (pthread_cond_clockwait(&thread_triggered_condition_, ×Lock, CLOCK_MONOTONIC, + &timeout_) == ETIMEDOUT) { + timeout_.tv_sec = 0; + timeout_.tv_nsec = 0; + } + if (release_) { + break; + } + } + + unlock(); + + if (tail_) { + logbuf.flushTo(client, start, nullptr, privileged_, can_read_security_logs_, + std::bind(&LogReaderThread::FilterFirstPass, this, _1)); + leading_dropped_ = + true; // TODO: Likely a bug, if leading_dropped_ was not true before calling + // flushTo(), then it should not be reset to true after. + } + start = logbuf.flushTo(client, start, last_tid_, privileged_, can_read_security_logs_, + std::bind(&LogReaderThread::FilterSecondPass, this, _1)); + + // We only ignore entries before the original start time for the first flushTo(), if we + // get entries after this first flush before the original start time, then the client + // wouldn't have seen them. + // Note: this is still racy and may skip out of order events that came in since the last + // time the client disconnected and then reconnected with the new start time. The long term + // solution here is that clients must request events since a specific sequence number. + start_time_.tv_sec = 0; + start_time_.tv_nsec = 0; + + wrlock(); + + if (start == LogBufferElement::FLUSH_ERROR) { + break; + } + + start_ = start + 1; + + if (non_block_ || release_) { + break; + } + + cleanSkip_Locked(); + + if (!timeout_.tv_sec && !timeout_.tv_nsec) { + pthread_cond_wait(&thread_triggered_condition_, ×Lock); + } + } + + LogReader& reader = reader_; + reader.release(client); + + client->decRef(); + + LastLogTimes& times = reader.logbuf().mTimes; + auto it = std::find_if(times.begin(), times.end(), + [this](const auto& other) { return other.get() == this; }); + + if (it != times.end()) { + times.erase(it); + } + + unlock(); +} + +// A first pass to count the number of elements +int LogReaderThread::FilterFirstPass(const LogBufferElement* element) { + LogReaderThread::wrlock(); + + if (leading_dropped_) { + if (element->getDropped()) { + LogReaderThread::unlock(); + return false; + } + leading_dropped_ = false; + } + + if (count_ == 0) { + start_ = element->getSequence(); + } + + if ((!pid_ || pid_ == element->getPid()) && IsWatching(element->getLogId()) && + (start_time_ == log_time::EPOCH || start_time_ <= element->getRealTime())) { + ++count_; + } + + LogReaderThread::unlock(); + + return false; +} + +// A second pass to send the selected elements +int LogReaderThread::FilterSecondPass(const LogBufferElement* element) { + LogReaderThread::wrlock(); + + start_ = element->getSequence(); + + if (skip_ahead_[element->getLogId()]) { + skip_ahead_[element->getLogId()]--; + goto skip; + } + + if (leading_dropped_) { + if (element->getDropped()) { + goto skip; + } + leading_dropped_ = false; + } + + // Truncate to close race between first and second pass + if (non_block_ && tail_ && index_ >= count_) { + goto stop; + } + + if (!IsWatching(element->getLogId())) { + goto skip; + } + + if (pid_ && pid_ != element->getPid()) { + goto skip; + } + + if (start_time_ != log_time::EPOCH && element->getRealTime() <= start_time_) { + goto skip; + } + + if (release_) { + goto stop; + } + + if (!tail_) { + goto ok; + } + + ++index_; + + if (count_ > tail_ && index_ <= (count_ - tail_)) { + goto skip; + } + + if (!non_block_) { + tail_ = 0; + } + +ok: + if (!skip_ahead_[element->getLogId()]) { + LogReaderThread::unlock(); + return true; + } + // FALLTHRU + +skip: + LogReaderThread::unlock(); + return false; + +stop: + LogReaderThread::unlock(); + return -1; +} + +void LogReaderThread::cleanSkip_Locked(void) { + memset(skip_ahead_, 0, sizeof(skip_ahead_)); +} diff --git a/logd/LogReaderThread.h b/logd/LogReaderThread.h new file mode 100644 index 000000000..39a8b63cb --- /dev/null +++ b/logd/LogReaderThread.h @@ -0,0 +1,126 @@ +/* + * Copyright (C) 2012-2013 The Android Open Source Project + * + * Licensed under the Apache License, Version 2.0 (the "License"); + * you may not use this file except in compliance with the License. + * You may obtain a copy of the License at + * + * http://www.apache.org/licenses/LICENSE-2.0 + * + * Unless required by applicable law or agreed to in writing, software + * distributed under the License is distributed on an "AS IS" BASIS, + * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. + * See the License for the specific language governing permissions and + * limitations under the License. + */ + +#pragma once + +#include +#include +#include +#include + +#include +#include + +#include +#include + +class LogReader; +class LogBufferElement; + +class LogReaderThread { + static pthread_mutex_t timesLock; + + public: + LogReaderThread(LogReader& reader, SocketClient* client, bool non_block, unsigned long tail, + unsigned int log_mask, pid_t pid, log_time start_time, uint64_t sequence, + uint64_t timeout, bool privileged, bool can_read_security_logs); + + // Protect List manipulations + static void wrlock() { pthread_mutex_lock(×Lock); } + static void rdlock() { pthread_mutex_lock(×Lock); } + static void unlock() { pthread_mutex_unlock(×Lock); } + + bool startReader_Locked(); + + void triggerReader_Locked() { pthread_cond_signal(&thread_triggered_condition_); } + + void triggerSkip_Locked(log_id_t id, unsigned int skip) { skip_ahead_[id] = skip; } + void cleanSkip_Locked(); + + void release_Locked() { + // gracefully shut down the socket. + shutdown(client_->getSocket(), SHUT_RDWR); + release_ = true; + pthread_cond_signal(&thread_triggered_condition_); + } + + bool IsWatching(log_id_t id) const { return log_mask_ & (1 << id); } + bool IsWatchingMultiple(unsigned int log_mask) const { return log_mask_ & log_mask; } + + const SocketClient* client() const { return client_; } + uint64_t start() const { return start_; } + const timespec& timeout() const { return timeout_; } + + private: + void ThreadFunction(); + // flushTo filter callbacks + int FilterFirstPass(const LogBufferElement* element); + int FilterSecondPass(const LogBufferElement* element); + + // Set to true to cause the thread to end and the LogReaderThread to delete itself. + bool release_ = false; + // Indicates whether or not 'leading' (first logs seen starting from start_) 'dropped' (chatty) + // messages should be ignored. + bool leading_dropped_; + + // Condition variable for waking the reader thread if there are messages pending for its client. + pthread_cond_t thread_triggered_condition_; + + // Reference to the parent thread that manages log reader sockets. + LogReader& reader_; + // A mask of the logs buffers that are read by this reader. + const unsigned int log_mask_; + // If set to non-zero, only pids equal to this are read by the reader. + const pid_t pid_; + // When a reader is referencing (via start_) old elements in the log buffer, and the log + // buffer's size grows past its memory limit, the log buffer may request the reader to skip + // ahead a specified number of logs. + unsigned int skip_ahead_[LOG_ID_MAX]; + // Used for distinguishing 'dropped' messages for duplicate logs vs chatty drops + pid_t last_tid_[LOG_ID_MAX]; + + // These next three variables are used for reading only the most recent lines aka `adb logcat + // -t` / `adb logcat -T`. + // tail_ is the number of most recent lines to print. + unsigned long tail_; + // count_ is the result of a first pass through the log buffer to determine how many total + // messages there are. + unsigned long count_; + // index_ is used along with count_ to only start sending lines once index_ > (count_ - tail_) + // and to disconnect the reader (if it is dumpAndClose, `adb logcat -t`), when index_ >= count_. + unsigned long index_; + + // A pointer to the socket for this reader. + SocketClient* client_; + // When a reader requests logs starting from a given timestamp, its stored here for the first + // pass, such that logs before this time stamp that are accumulated in the buffer are ignored. + log_time start_time_; + // The point from which the reader will read logs once awoken. + uint64_t start_; + // CLOCK_MONOTONIC based timeout used for log wrapping. If this timeout expires before logs + // wrap, then wake up and send the logs to the reader anyway. + timespec timeout_; + // If this reader is 'dumpAndClose' and will disconnect once it has read its intended logs. + const bool non_block_; + + // Whether or not this reader can read logs from all UIDs or only its own UID. See + // clientHasLogCredentials(). + bool privileged_; + // Whether or not this reader can read security logs. See CanReadSecurityLogs(). + bool can_read_security_logs_; +}; + +typedef std::list> LastLogTimes; diff --git a/logd/LogTimes.cpp b/logd/LogTimes.cpp deleted file mode 100644 index ad150bdb6..000000000 --- a/logd/LogTimes.cpp +++ /dev/null @@ -1,253 +0,0 @@ -/* - * Copyright (C) 2014 The Android Open Source Project - * - * Licensed under the Apache License, Version 2.0 (the "License"); - * you may not use this file except in compliance with the License. - * You may obtain a copy of the License at - * - * http://www.apache.org/licenses/LICENSE-2.0 - * - * Unless required by applicable law or agreed to in writing, software - * distributed under the License is distributed on an "AS IS" BASIS, - * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. - * See the License for the specific language governing permissions and - * limitations under the License. - */ - -#include -#include -#include - -#include "LogBuffer.h" -#include "LogReader.h" -#include "LogTimes.h" - -pthread_mutex_t LogTimeEntry::timesLock = PTHREAD_MUTEX_INITIALIZER; - -LogTimeEntry::LogTimeEntry(LogReader& reader, SocketClient* client, bool nonBlock, - unsigned long tail, log_mask_t logMask, pid_t pid, log_time start_time, - uint64_t start, uint64_t timeout, bool privileged, - bool can_read_security_logs) - : leadingDropped(false), - mReader(reader), - mLogMask(logMask), - mPid(pid), - mCount(0), - mTail(tail), - mIndex(0), - mClient(client), - mStartTime(start_time), - mStart(start), - mNonBlock(nonBlock), - privileged_(privileged), - can_read_security_logs_(can_read_security_logs) { - mTimeout.tv_sec = timeout / NS_PER_SEC; - mTimeout.tv_nsec = timeout % NS_PER_SEC; - memset(mLastTid, 0, sizeof(mLastTid)); - pthread_cond_init(&threadTriggeredCondition, nullptr); - cleanSkip_Locked(); -} - -bool LogTimeEntry::startReader_Locked() { - pthread_attr_t attr; - - if (!pthread_attr_init(&attr)) { - if (!pthread_attr_setdetachstate(&attr, PTHREAD_CREATE_DETACHED)) { - if (!pthread_create(&mThread, &attr, LogTimeEntry::threadStart, - this)) { - pthread_attr_destroy(&attr); - return true; - } - } - pthread_attr_destroy(&attr); - } - - return false; -} - -void* LogTimeEntry::threadStart(void* obj) { - prctl(PR_SET_NAME, "logd.reader.per"); - - LogTimeEntry* me = reinterpret_cast(obj); - - SocketClient* client = me->mClient; - - LogBuffer& logbuf = me->mReader.logbuf(); - - me->leadingDropped = true; - - wrlock(); - - uint64_t start = me->mStart; - - while (!me->mRelease) { - if (me->mTimeout.tv_sec || me->mTimeout.tv_nsec) { - if (pthread_cond_clockwait(&me->threadTriggeredCondition, ×Lock, CLOCK_MONOTONIC, - &me->mTimeout) == ETIMEDOUT) { - me->mTimeout.tv_sec = 0; - me->mTimeout.tv_nsec = 0; - } - if (me->mRelease) { - break; - } - } - - unlock(); - - if (me->mTail) { - logbuf.flushTo(client, start, nullptr, me->privileged_, me->can_read_security_logs_, - FilterFirstPass, me); - me->leadingDropped = true; - } - start = logbuf.flushTo(client, start, me->mLastTid, me->privileged_, - me->can_read_security_logs_, FilterSecondPass, me); - - // We only ignore entries before the original start time for the first flushTo(), if we - // get entries after this first flush before the original start time, then the client - // wouldn't have seen them. - // Note: this is still racy and may skip out of order events that came in since the last - // time the client disconnected and then reconnected with the new start time. The long term - // solution here is that clients must request events since a specific sequence number. - me->mStartTime.tv_sec = 0; - me->mStartTime.tv_nsec = 0; - - wrlock(); - - if (start == LogBufferElement::FLUSH_ERROR) { - break; - } - - me->mStart = start + 1; - - if (me->mNonBlock || me->mRelease) { - break; - } - - me->cleanSkip_Locked(); - - if (!me->mTimeout.tv_sec && !me->mTimeout.tv_nsec) { - pthread_cond_wait(&me->threadTriggeredCondition, ×Lock); - } - } - - LogReader& reader = me->mReader; - reader.release(client); - - client->decRef(); - - LastLogTimes& times = reader.logbuf().mTimes; - auto it = - std::find_if(times.begin(), times.end(), - [&me](const auto& other) { return other.get() == me; }); - - if (it != times.end()) { - times.erase(it); - } - - unlock(); - - return nullptr; -} - -// A first pass to count the number of elements -int LogTimeEntry::FilterFirstPass(const LogBufferElement* element, void* obj) { - LogTimeEntry* me = reinterpret_cast(obj); - - LogTimeEntry::wrlock(); - - if (me->leadingDropped) { - if (element->getDropped()) { - LogTimeEntry::unlock(); - return false; - } - me->leadingDropped = false; - } - - if (me->mCount == 0) { - me->mStart = element->getSequence(); - } - - if ((!me->mPid || me->mPid == element->getPid()) && me->isWatching(element->getLogId()) && - (me->mStartTime == log_time::EPOCH || me->mStartTime <= element->getRealTime())) { - ++me->mCount; - } - - LogTimeEntry::unlock(); - - return false; -} - -// A second pass to send the selected elements -int LogTimeEntry::FilterSecondPass(const LogBufferElement* element, void* obj) { - LogTimeEntry* me = reinterpret_cast(obj); - - LogTimeEntry::wrlock(); - - me->mStart = element->getSequence(); - - if (me->skipAhead[element->getLogId()]) { - me->skipAhead[element->getLogId()]--; - goto skip; - } - - if (me->leadingDropped) { - if (element->getDropped()) { - goto skip; - } - me->leadingDropped = false; - } - - // Truncate to close race between first and second pass - if (me->mNonBlock && me->mTail && (me->mIndex >= me->mCount)) { - goto stop; - } - - if (!me->isWatching(element->getLogId())) { - goto skip; - } - - if (me->mPid && (me->mPid != element->getPid())) { - goto skip; - } - - if (me->mStartTime != log_time::EPOCH && element->getRealTime() <= me->mStartTime) { - goto skip; - } - - if (me->mRelease) { - goto stop; - } - - if (!me->mTail) { - goto ok; - } - - ++me->mIndex; - - if ((me->mCount > me->mTail) && (me->mIndex <= (me->mCount - me->mTail))) { - goto skip; - } - - if (!me->mNonBlock) { - me->mTail = 0; - } - -ok: - if (!me->skipAhead[element->getLogId()]) { - LogTimeEntry::unlock(); - return true; - } -// FALLTHRU - -skip: - LogTimeEntry::unlock(); - return false; - -stop: - LogTimeEntry::unlock(); - return -1; -} - -void LogTimeEntry::cleanSkip_Locked(void) { - memset(skipAhead, 0, sizeof(skipAhead)); -} diff --git a/logd/LogTimes.h b/logd/LogTimes.h deleted file mode 100644 index 56c930a15..000000000 --- a/logd/LogTimes.h +++ /dev/null @@ -1,109 +0,0 @@ -/* - * Copyright (C) 2012-2013 The Android Open Source Project - * - * Licensed under the Apache License, Version 2.0 (the "License"); - * you may not use this file except in compliance with the License. - * You may obtain a copy of the License at - * - * http://www.apache.org/licenses/LICENSE-2.0 - * - * Unless required by applicable law or agreed to in writing, software - * distributed under the License is distributed on an "AS IS" BASIS, - * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. - * See the License for the specific language governing permissions and - * limitations under the License. - */ - -#ifndef _LOGD_LOG_TIMES_H__ -#define _LOGD_LOG_TIMES_H__ - -#include -#include -#include -#include - -#include -#include - -#include -#include - -typedef unsigned int log_mask_t; - -class LogReader; -class LogBufferElement; - -class LogTimeEntry { - static pthread_mutex_t timesLock; - bool mRelease = false; - bool leadingDropped; - pthread_cond_t threadTriggeredCondition; - pthread_t mThread; - LogReader& mReader; - static void* threadStart(void* me); - const log_mask_t mLogMask; - const pid_t mPid; - unsigned int skipAhead[LOG_ID_MAX]; - pid_t mLastTid[LOG_ID_MAX]; - unsigned long mCount; - unsigned long mTail; - unsigned long mIndex; - - public: - LogTimeEntry(LogReader& reader, SocketClient* client, bool nonBlock, unsigned long tail, - log_mask_t logMask, pid_t pid, log_time start_time, uint64_t sequence, - uint64_t timeout, bool privileged, bool can_read_security_logs); - - SocketClient* mClient; - log_time mStartTime; - uint64_t mStart; - struct timespec mTimeout; // CLOCK_MONOTONIC based timeout used for log wrapping. - const bool mNonBlock; - - // Protect List manipulations - static void wrlock(void) { - pthread_mutex_lock(×Lock); - } - static void rdlock(void) { - pthread_mutex_lock(×Lock); - } - static void unlock(void) { - pthread_mutex_unlock(×Lock); - } - - bool startReader_Locked(); - - void triggerReader_Locked(void) { - pthread_cond_signal(&threadTriggeredCondition); - } - - void triggerSkip_Locked(log_id_t id, unsigned int skip) { - skipAhead[id] = skip; - } - void cleanSkip_Locked(void); - - void release_Locked(void) { - // gracefully shut down the socket. - shutdown(mClient->getSocket(), SHUT_RDWR); - mRelease = true; - pthread_cond_signal(&threadTriggeredCondition); - } - - bool isWatching(log_id_t id) const { - return mLogMask & (1 << id); - } - bool isWatchingMultiple(log_mask_t logMask) const { - return mLogMask & logMask; - } - // flushTo filter callbacks - static int FilterFirstPass(const LogBufferElement* element, void* me); - static int FilterSecondPass(const LogBufferElement* element, void* me); - - private: - bool privileged_; - bool can_read_security_logs_; -}; - -typedef std::list> LastLogTimes; - -#endif // _LOGD_LOG_TIMES_H__ diff --git a/logd/fuzz/log_buffer_log_fuzzer.cpp b/logd/fuzz/log_buffer_log_fuzzer.cpp index 14c5163e2..8156612da 100644 --- a/logd/fuzz/log_buffer_log_fuzzer.cpp +++ b/logd/fuzz/log_buffer_log_fuzzer.cpp @@ -16,7 +16,7 @@ #include #include "../LogBuffer.h" -#include "../LogTimes.h" +#include "../LogReaderThread.h" // We don't want to waste a lot of entropy on messages #define MAX_MSG_LENGTH 5