ACPR/android_system_core
1
0
Fork 0
Code Issues Pull requests Projects Releases Packages Wiki Activity Actions

Merge changes I5731d640,Ia874b57a am: 0b3f9567c5

Browse source 
Change-Id: I6c8da8d8edf28440d8c6a4f737978e3757518b5c
This commit is contained in:
Tom Cherry 2020-05-13 16:23:43 +00:00 • committed by Automerger Merge Worker
commit 1dc6605a44
22 changed files with 430 additions and 433 deletions
Show stats Download patch file Download diff file Expand all files Collapse all files

3
logd/Android.bp
View file

@ -33,11 +33,12 @@ cc_library_static {
srcs: [ srcs: [
"LogCommand.cpp", "LogCommand.cpp",
"ChattyLogBuffer.cpp",
"CommandListener.cpp", "CommandListener.cpp",
"LogListener.cpp", "LogListener.cpp",
"LogReader.cpp", "LogReader.cpp",
"LogReaderList.cpp",
"LogReaderThread.cpp", "LogReaderThread.cpp",
"LogBuffer.cpp",
"LogBufferElement.cpp", "LogBufferElement.cpp",
"LogStatistics.cpp", "LogStatistics.cpp",
"LogWhiteBlackList.cpp", "LogWhiteBlackList.cpp",

242
logd/LogBuffer.cpp → logd/ChattyLogBuffer.cpp
View file

@ -13,9 +13,11 @@
* See the License for the specific language governing permissions and * See the License for the specific language governing permissions and
* limitations under the License. * limitations under the License.
*/ */
// for manual checking of stale entries during LogBuffer::erase() // for manual checking of stale entries during ChattyLogBuffer::erase()
//#define DEBUG_CHECK_FOR_STALE_ENTRIES //#define DEBUG_CHECK_FOR_STALE_ENTRIES
#include "ChattyLogBuffer.h"
#include <ctype.h> #include <ctype.h>
#include <endian.h> #include <endian.h>
#include <errno.h> #include <errno.h>
@ -32,7 +34,6 @@
#include <cutils/properties.h> #include <cutils/properties.h>
#include <private/android_logger.h> #include <private/android_logger.h>
#include "LogBuffer.h"
#include "LogKlog.h" #include "LogKlog.h"
#include "LogReader.h" #include "LogReader.h"
#include "LogUtils.h" #include "LogUtils.h"
@ -44,27 +45,22 @@
// Default // Default
#define log_buffer_size(id) mMaxSize[id] #define log_buffer_size(id) mMaxSize[id]
void LogBuffer::init() { void ChattyLogBuffer::Init() {
log_id_for_each(i) { log_id_for_each(i) {
if (setSize(i, __android_logger_get_buffer_size(i))) { if (SetSize(i, __android_logger_get_buffer_size(i))) {
setSize(i, LOG_BUFFER_MIN_SIZE); SetSize(i, LOG_BUFFER_MIN_SIZE);
} }
} }
// Release any sleeping reader threads to dump their current content. // Release any sleeping reader threads to dump their current content.
LogReaderThread::wrlock(); auto reader_threads_lock = std::lock_guard{reader_list_->reader_threads_lock()};
for (const auto& reader_thread : reader_list_->reader_threads()) {
LastLogTimes::iterator times = mTimes.begin(); reader_thread->triggerReader_Locked();
while (times != mTimes.end()) {
LogReaderThread* entry = times->get();
entry->triggerReader_Locked();
times++;
} }
LogReaderThread::unlock();
} }
LogBuffer::LogBuffer(LastLogTimes* times, LogTags* tags, PruneList* prune, LogStatistics* stats) ChattyLogBuffer::ChattyLogBuffer(LogReaderList* reader_list, LogTags* tags, PruneList* prune,
: mTimes(*times), tags_(tags), prune_(prune), stats_(stats) { LogStatistics* stats)
: reader_list_(reader_list), tags_(tags), prune_(prune), stats_(stats) {
pthread_rwlock_init(&mLogElementsLock, nullptr); pthread_rwlock_init(&mLogElementsLock, nullptr);
log_id_for_each(i) { log_id_for_each(i) {
@ -72,17 +68,17 @@ LogBuffer::LogBuffer(LastLogTimes* times, LogTags* tags, PruneList* prune, LogSt
droppedElements[i] = nullptr; droppedElements[i] = nullptr;
} }
init(); Init();
} }
LogBuffer::~LogBuffer() { ChattyLogBuffer::~ChattyLogBuffer() {
log_id_for_each(i) { log_id_for_each(i) {
delete lastLoggedElements[i]; delete lastLoggedElements[i];
delete droppedElements[i]; delete droppedElements[i];
} }
} }
LogBufferElementCollection::iterator LogBuffer::GetOldest(log_id_t log_id) { LogBufferElementCollection::iterator ChattyLogBuffer::GetOldest(log_id_t log_id) {
auto it = mLogElements.begin(); auto it = mLogElements.begin();
if (oldest_[log_id]) { if (oldest_[log_id]) {
it = *oldest_[log_id]; it = *oldest_[log_id];
@ -98,8 +94,7 @@ LogBufferElementCollection::iterator LogBuffer::GetOldest(log_id_t log_id) {
enum match_type { DIFFERENT, SAME, SAME_LIBLOG }; enum match_type { DIFFERENT, SAME, SAME_LIBLOG };
static enum match_type identical(LogBufferElement* elem, static enum match_type identical(LogBufferElement* elem, LogBufferElement* last) {
LogBufferElement* last) {
// is it mostly identical? // is it mostly identical?
// if (!elem) return DIFFERENT; // if (!elem) return DIFFERENT;
ssize_t lenl = elem->getMsgLen(); ssize_t lenl = elem->getMsgLen();
@ -113,8 +108,7 @@ static enum match_type identical(LogBufferElement* elem,
if (elem->getTid() != last->getTid()) return DIFFERENT; if (elem->getTid() != last->getTid()) return DIFFERENT;
// last is more than a minute old, stop squashing identical messages // last is more than a minute old, stop squashing identical messages
if (elem->getRealTime().nsec() > if (elem->getRealTime().nsec() > (last->getRealTime().nsec() + 60 * NS_PER_SEC))
(last->getRealTime().nsec() + 60 * NS_PER_SEC))
return DIFFERENT; return DIFFERENT;
// Identical message // Identical message
@ -123,21 +117,17 @@ static enum match_type identical(LogBufferElement* elem,
if (lenl == lenr) { if (lenl == lenr) {
if (!fastcmp<memcmp>(msgl, msgr, lenl)) return SAME; if (!fastcmp<memcmp>(msgl, msgr, lenl)) return SAME;
// liblog tagged messages (content gets summed) // liblog tagged messages (content gets summed)
if ((elem->getLogId() == LOG_ID_EVENTS) && if (elem->getLogId() == LOG_ID_EVENTS && lenl == sizeof(android_log_event_int_t) &&
(lenl == sizeof(android_log_event_int_t)) && !fastcmp<memcmp>(msgl, msgr, sizeof(android_log_event_int_t) - sizeof(int32_t)) &&
!fastcmp<memcmp>(msgl, msgr, sizeof(android_log_event_int_t) - elem->getTag() == LIBLOG_LOG_TAG) {
sizeof(int32_t)) &&
(elem->getTag() == LIBLOG_LOG_TAG)) {
return SAME_LIBLOG; return SAME_LIBLOG;
} }
} }
// audit message (except sequence number) identical? // audit message (except sequence number) identical?
if (last->isBinary() && if (last->isBinary() && lenl > static_cast<ssize_t>(sizeof(android_log_event_string_t)) &&
(lenl > static_cast<ssize_t>(sizeof(android_log_event_string_t))) && lenr > static_cast<ssize_t>(sizeof(android_log_event_string_t))) {
(lenr > static_cast<ssize_t>(sizeof(android_log_event_string_t)))) { if (fastcmp<memcmp>(msgl, msgr, sizeof(android_log_event_string_t) - sizeof(int32_t))) {
if (fastcmp<memcmp>(msgl, msgr, sizeof(android_log_event_string_t) -
sizeof(int32_t))) {
return DIFFERENT; return DIFFERENT;
} }
msgl += sizeof(android_log_event_string_t); msgl += sizeof(android_log_event_string_t);
@ -153,15 +143,14 @@ static enum match_type identical(LogBufferElement* elem,
if (!avcr) return DIFFERENT; if (!avcr) return DIFFERENT;
lenr -= avcr - msgr; lenr -= avcr - msgr;
if (lenl != lenr) return DIFFERENT; if (lenl != lenr) return DIFFERENT;
if (fastcmp<memcmp>(avcl + strlen(avc), avcr + strlen(avc), if (fastcmp<memcmp>(avcl + strlen(avc), avcr + strlen(avc), lenl - strlen(avc))) {
lenl - strlen(avc))) {
return DIFFERENT; return DIFFERENT;
} }
return SAME; return SAME;
} }
int LogBuffer::log(log_id_t log_id, log_time realtime, uid_t uid, pid_t pid, int ChattyLogBuffer::Log(log_id_t log_id, log_time realtime, uid_t uid, pid_t pid, pid_t tid,
pid_t tid, const char* msg, uint16_t len) { const char* msg, uint16_t len) {
if (log_id >= LOG_ID_MAX) { if (log_id >= LOG_ID_MAX) {
return -EINVAL; return -EINVAL;
} }
@ -283,8 +272,7 @@ int LogBuffer::log(log_id_t log_id, log_time realtime, uid_t uid, pid_t pid,
if (dropped) { if (dropped) {
// Sum up liblog tag messages? // Sum up liblog tag messages?
if ((count == 0) /* at Pass 1 */ && (match == SAME_LIBLOG)) { if ((count == 0) /* at Pass 1 */ && (match == SAME_LIBLOG)) {
android_log_event_int_t* event = android_log_event_int_t* event = reinterpret_cast<android_log_event_int_t*>(
reinterpret_cast<android_log_event_int_t*>(
const_cast<char*>(currentLast->getMsg())); const_cast<char*>(currentLast->getMsg()));
// //
// To unit test, differentiate with something like: // To unit test, differentiate with something like:
@ -295,7 +283,7 @@ int LogBuffer::log(log_id_t log_id, log_time realtime, uid_t uid, pid_t pid,
uint32_t swab = event->payload.data; uint32_t swab = event->payload.data;
unsigned long long total = htole32(swab); unsigned long long total = htole32(swab);
event = reinterpret_cast<android_log_event_int_t*>( event = reinterpret_cast<android_log_event_int_t*>(
const_cast<char*>(elem->getMsg())); const_cast<char*>(elem->getMsg()));
swab = event->payload.data; swab = event->payload.data;
lastLoggedElements[LOG_ID_EVENTS] = elem; lastLoggedElements[LOG_ID_EVENTS] = elem;
@ -350,23 +338,24 @@ int LogBuffer::log(log_id_t log_id, log_time realtime, uid_t uid, pid_t pid,
return len; return len;
} }
// assumes LogBuffer::wrlock() held, owns elem, look after garbage collection // assumes ChattyLogBuffer::wrlock() held, owns elem, look after garbage collection
void LogBuffer::log(LogBufferElement* elem) { void ChattyLogBuffer::log(LogBufferElement* elem) {
mLogElements.push_back(elem); mLogElements.push_back(elem);
stats_->Add(elem); stats_->Add(elem);
maybePrune(elem->getLogId()); maybePrune(elem->getLogId());
reader_list_->NotifyNewLog(1 << elem->getLogId());
} }
// LogBuffer::wrlock() must be held when this function is called. // ChattyLogBuffer::wrlock() must be held when this function is called.
void LogBuffer::maybePrune(log_id_t id) { void ChattyLogBuffer::maybePrune(log_id_t id) {
unsigned long prune_rows; unsigned long prune_rows;
if (stats_->ShouldPrune(id, log_buffer_size(id), &prune_rows)) { if (stats_->ShouldPrune(id, log_buffer_size(id), &prune_rows)) {
prune(id, prune_rows); prune(id, prune_rows);
} }
} }
LogBufferElementCollection::iterator LogBuffer::erase( LogBufferElementCollection::iterator ChattyLogBuffer::erase(LogBufferElementCollection::iterator it,
LogBufferElementCollection::iterator it, bool coalesce) { bool coalesce) {
LogBufferElement* element = *it; LogBufferElement* element = *it;
log_id_t id = element->getLogId(); log_id_t id = element->getLogId();
@ -374,9 +363,8 @@ LogBufferElementCollection::iterator LogBuffer::erase(
// after the element is erased from the main logging list. // after the element is erased from the main logging list.
{ // start of scope for found iterator { // start of scope for found iterator
int key = ((id == LOG_ID_EVENTS) || (id == LOG_ID_SECURITY)) int key = (id == LOG_ID_EVENTS || id == LOG_ID_SECURITY) ? element->getTag()
? element->getTag() : element->getUid();
: element->getUid();
LogBufferIteratorMap::iterator found = mLastWorst[id].find(key); LogBufferIteratorMap::iterator found = mLastWorst[id].find(key);
if ((found != mLastWorst[id].end()) && (it == found->second)) { if ((found != mLastWorst[id].end()) && (it == found->second)) {
mLastWorst[id].erase(found); mLastWorst[id].erase(found);
@ -387,10 +375,8 @@ LogBufferElementCollection::iterator LogBuffer::erase(
// element->getUid() may not be AID_SYSTEM for next-best-watermark. // element->getUid() may not be AID_SYSTEM for next-best-watermark.
// will not assume id != LOG_ID_EVENTS or LOG_ID_SECURITY for KISS and // will not assume id != LOG_ID_EVENTS or LOG_ID_SECURITY for KISS and
// long term code stability, find() check should be fast for those ids. // long term code stability, find() check should be fast for those ids.
LogBufferPidIteratorMap::iterator found = LogBufferPidIteratorMap::iterator found = mLastWorstPidOfSystem[id].find(element->getPid());
mLastWorstPidOfSystem[id].find(element->getPid()); if (found != mLastWorstPidOfSystem[id].end() && it == found->second) {
if ((found != mLastWorstPidOfSystem[id].end()) &&
(it == found->second)) {
mLastWorstPidOfSystem[id].erase(found); mLastWorstPidOfSystem[id].erase(found);
} }
} }
@ -400,9 +386,8 @@ LogBufferElementCollection::iterator LogBuffer::erase(
log_id_for_each(i) { doSetLast |= setLast[i] = oldest_[i] && it == *oldest_[i]; } log_id_for_each(i) { doSetLast |= setLast[i] = oldest_[i] && it == *oldest_[i]; }
#ifdef DEBUG_CHECK_FOR_STALE_ENTRIES #ifdef DEBUG_CHECK_FOR_STALE_ENTRIES
LogBufferElementCollection::iterator bad = it; LogBufferElementCollection::iterator bad = it;
int key = ((id == LOG_ID_EVENTS) || (id == LOG_ID_SECURITY)) int key =
? element->getTag() (id == LOG_ID_EVENTS || id == LOG_ID_SECURITY) ? element->getTag() : element->getUid();
: element->getUid();
#endif #endif
it = mLogElements.erase(it); it = mLogElements.erase(it);
if (doSetLast) { if (doSetLast) {
@ -421,14 +406,12 @@ LogBufferElementCollection::iterator LogBuffer::erase(
log_id_for_each(i) { log_id_for_each(i) {
for (auto b : mLastWorst[i]) { for (auto b : mLastWorst[i]) {
if (bad == b.second) { if (bad == b.second) {
android::prdebug("stale mLastWorst[%d] key=%d mykey=%d\n", i, android::prdebug("stale mLastWorst[%d] key=%d mykey=%d\n", i, b.first, key);
b.first, key);
} }
} }
for (auto b : mLastWorstPidOfSystem[i]) { for (auto b : mLastWorstPidOfSystem[i]) {
if (bad == b.second) { if (bad == b.second) {
android::prdebug("stale mLastWorstPidOfSystem[%d] pid=%d\n", i, android::prdebug("stale mLastWorstPidOfSystem[%d] pid=%d\n", i, b.first);
b.first);
} }
} }
} }
@ -456,26 +439,20 @@ class LogBufferElementKey {
uint64_t value; uint64_t value;
} __packed; } __packed;
public: public:
LogBufferElementKey(uid_t uid, pid_t pid, pid_t tid) LogBufferElementKey(uid_t uid, pid_t pid, pid_t tid) : uid(uid), pid(pid), tid(tid) {}
: uid(uid), pid(pid), tid(tid) { explicit LogBufferElementKey(uint64_t key) : value(key) {}
}
explicit LogBufferElementKey(uint64_t key) : value(key) {
}
uint64_t getKey() { uint64_t getKey() { return value; }
return value;
}
}; };
class LogBufferElementLast { class LogBufferElementLast {
typedef std::unordered_map<uint64_t, LogBufferElement*> LogBufferElementMap; typedef std::unordered_map<uint64_t, LogBufferElement*> LogBufferElementMap;
LogBufferElementMap map; LogBufferElementMap map;
public: public:
bool coalesce(LogBufferElement* element, uint16_t dropped) { bool coalesce(LogBufferElement* element, uint16_t dropped) {
LogBufferElementKey key(element->getUid(), element->getPid(), LogBufferElementKey key(element->getUid(), element->getPid(), element->getTid());
element->getTid());
LogBufferElementMap::iterator it = map.find(key.getKey()); LogBufferElementMap::iterator it = map.find(key.getKey());
if (it != map.end()) { if (it != map.end()) {
LogBufferElement* found = it->second; LogBufferElement* found = it->second;
@ -491,14 +468,11 @@ class LogBufferElementLast {
} }
void add(LogBufferElement* element) { void add(LogBufferElement* element) {
LogBufferElementKey key(element->getUid(), element->getPid(), LogBufferElementKey key(element->getUid(), element->getPid(), element->getTid());
element->getTid());
map[key.getKey()] = element; map[key.getKey()] = element;
} }
inline void clear() { void clear() { map.clear(); }
map.clear();
}
void clear(LogBufferElement* element) { void clear(LogBufferElement* element) {
uint64_t current = element->getRealTime().nsec() - (EXPIRE_RATELIMIT * NS_PER_SEC); uint64_t current = element->getRealTime().nsec() - (EXPIRE_RATELIMIT * NS_PER_SEC);
@ -516,21 +490,20 @@ class LogBufferElementLast {
// If the selected reader is blocking our pruning progress, decide on // If the selected reader is blocking our pruning progress, decide on
// what kind of mitigation is necessary to unblock the situation. // what kind of mitigation is necessary to unblock the situation.
void LogBuffer::kickMe(LogReaderThread* me, log_id_t id, unsigned long pruneRows) { void ChattyLogBuffer::kickMe(LogReaderThread* me, log_id_t id, unsigned long pruneRows) {
if (stats_->Sizes(id) > (2 * log_buffer_size(id))) { // +100% if (stats_->Sizes(id) > (2 * log_buffer_size(id))) { // +100%
// A misbehaving or slow reader has its connection // A misbehaving or slow reader has its connection
// dropped if we hit too much memory pressure. // dropped if we hit too much memory pressure.
android::prdebug("Kicking blocked reader, pid %d, from LogBuffer::kickMe()\n", android::prdebug("Kicking blocked reader, pid %d, from ChattyLogBuffer::kickMe()\n",
me->client()->getPid()); me->client()->getPid());
me->release_Locked(); me->release_Locked();
} else if (me->timeout().tv_sec || me->timeout().tv_nsec) { } else if (me->deadline().time_since_epoch().count() != 0) {
// Allow a blocked WRAP timeout reader to // Allow a blocked WRAP deadline reader to trigger and start reporting the log data.
// trigger and start reporting the log data.
me->triggerReader_Locked(); me->triggerReader_Locked();
} else { } else {
// tell slow reader to skip entries to catch up // tell slow reader to skip entries to catch up
android::prdebug( android::prdebug(
"Skipping %lu entries from slow reader, pid %d, from LogBuffer::kickMe()\n", "Skipping %lu entries from slow reader, pid %d, from ChattyLogBuffer::kickMe()\n",
pruneRows, me->client()->getPid()); pruneRows, me->client()->getPid());
me->triggerSkip_Locked(id, pruneRows); me->triggerSkip_Locked(id, pruneRows);
} }
@ -581,25 +554,25 @@ void LogBuffer::kickMe(LogReaderThread* me, log_id_t id, unsigned long pruneRows
// The third thread is optional, and only gets hit if there was a whitelist // The third thread is optional, and only gets hit if there was a whitelist
// and more needs to be pruned against the backstop of the region lock. // and more needs to be pruned against the backstop of the region lock.
// //
// LogBuffer::wrlock() must be held when this function is called. // ChattyLogBuffer::wrlock() must be held when this function is called.
// //
bool LogBuffer::prune(log_id_t id, unsigned long pruneRows, uid_t caller_uid) { bool ChattyLogBuffer::prune(log_id_t id, unsigned long pruneRows, uid_t caller_uid) {
LogReaderThread* oldest = nullptr; LogReaderThread* oldest = nullptr;
bool busy = false; bool busy = false;
bool clearAll = pruneRows == ULONG_MAX; bool clearAll = pruneRows == ULONG_MAX;
LogReaderThread::rdlock(); auto reader_threads_lock = std::lock_guard{reader_list_->reader_threads_lock()};
// Region locked? // Region locked?
LastLogTimes::iterator times = mTimes.begin(); for (const auto& reader_thread : reader_list_->reader_threads()) {
while (times != mTimes.end()) { if (!reader_thread->IsWatching(id)) {
LogReaderThread* entry = times->get(); continue;
if (entry->IsWatching(id) && (!oldest || oldest->start() > entry->start() || }
(oldest->start() == entry->start() && if (!oldest || oldest->start() > reader_thread->start() ||
(entry->timeout().tv_sec || entry->timeout().tv_nsec)))) { (oldest->start() == reader_thread->start() &&
oldest = entry; reader_thread->deadline().time_since_epoch().count() != 0)) {
oldest = reader_thread.get();
} }
times++;
} }
LogBufferElementCollection::iterator it; LogBufferElementCollection::iterator it;
@ -611,8 +584,7 @@ bool LogBuffer::prune(log_id_t id, unsigned long pruneRows, uid_t caller_uid) {
while (it != mLogElements.end()) { while (it != mLogElements.end()) {
LogBufferElement* element = *it; LogBufferElement* element = *it;
if ((element->getLogId() != id) || if (element->getLogId() != id || element->getUid() != caller_uid) {
(element->getUid() != caller_uid)) {
++it; ++it;
continue; continue;
} }
@ -628,7 +600,6 @@ bool LogBuffer::prune(log_id_t id, unsigned long pruneRows, uid_t caller_uid) {
break; break;
} }
} }
LogReaderThread::unlock();
return busy; return busy;
} }
@ -672,10 +643,8 @@ bool LogBuffer::prune(log_id_t id, unsigned long pruneRows, uid_t caller_uid) {
bool gc = pruneRows <= 1; bool gc = pruneRows <= 1;
if (!gc && (worst != -1)) { if (!gc && (worst != -1)) {
{ // begin scope for worst found iterator { // begin scope for worst found iterator
LogBufferIteratorMap::iterator found = LogBufferIteratorMap::iterator found = mLastWorst[id].find(worst);
mLastWorst[id].find(worst); if (found != mLastWorst[id].end() && found->second != mLogElements.end()) {
if ((found != mLastWorst[id].end()) &&
(found->second != mLogElements.end())) {
leading = false; leading = false;
it = found->second; it = found->second;
} }
@ -683,10 +652,9 @@ bool LogBuffer::prune(log_id_t id, unsigned long pruneRows, uid_t caller_uid) {
if (worstPid) { // begin scope for pid worst found iterator if (worstPid) { // begin scope for pid worst found iterator
// FYI: worstPid only set if !LOG_ID_EVENTS and // FYI: worstPid only set if !LOG_ID_EVENTS and
// !LOG_ID_SECURITY, not going to make that assumption ... // !LOG_ID_SECURITY, not going to make that assumption ...
LogBufferPidIteratorMap::iterator found = LogBufferPidIteratorMap::iterator found = mLastWorstPidOfSystem[id].find(worstPid);
mLastWorstPidOfSystem[id].find(worstPid); if (found != mLastWorstPidOfSystem[id].end() &&
if ((found != mLastWorstPidOfSystem[id].end()) && found->second != mLogElements.end()) {
(found->second != mLogElements.end())) {
leading = false; leading = false;
it = found->second; it = found->second;
} }
@ -695,7 +663,7 @@ bool LogBuffer::prune(log_id_t id, unsigned long pruneRows, uid_t caller_uid) {
if (leading) { if (leading) {
it = GetOldest(id); it = GetOldest(id);
} }
static const timespec too_old = { EXPIRE_HOUR_THRESHOLD * 60 * 60, 0 }; static const timespec too_old = {EXPIRE_HOUR_THRESHOLD * 60 * 60, 0};
LogBufferElementCollection::iterator lastt; LogBufferElementCollection::iterator lastt;
lastt = mLogElements.end(); lastt = mLogElements.end();
--lastt; --lastt;
@ -728,9 +696,8 @@ bool LogBuffer::prune(log_id_t id, unsigned long pruneRows, uid_t caller_uid) {
continue; continue;
} }
int key = ((id == LOG_ID_EVENTS) || (id == LOG_ID_SECURITY)) int key = (id == LOG_ID_EVENTS || id == LOG_ID_SECURITY) ? element->getTag()
? element->getTag() : element->getUid();
: element->getUid();
if (hasBlacklist && prune_->naughty(element)) { if (hasBlacklist && prune_->naughty(element)) {
last.clear(element); last.clear(element);
@ -761,10 +728,9 @@ bool LogBuffer::prune(log_id_t id, unsigned long pruneRows, uid_t caller_uid) {
if (dropped) { if (dropped) {
last.add(element); last.add(element);
if (worstPid && if (worstPid && ((!gc && element->getPid() == worstPid) ||
((!gc && (element->getPid() == worstPid)) || mLastWorstPidOfSystem[id].find(element->getPid()) ==
(mLastWorstPidOfSystem[id].find(element->getPid()) == mLastWorstPidOfSystem[id].end())) {
mLastWorstPidOfSystem[id].end()))) {
// element->getUid() may not be AID_SYSTEM, next best // element->getUid() may not be AID_SYSTEM, next best
// watermark if current one empty. id is not LOG_ID_EVENTS // watermark if current one empty. id is not LOG_ID_EVENTS
// or LOG_ID_SECURITY because of worstPid check. // or LOG_ID_SECURITY because of worstPid check.
@ -778,8 +744,7 @@ bool LogBuffer::prune(log_id_t id, unsigned long pruneRows, uid_t caller_uid) {
continue; continue;
} }
if ((key != worst) || if (key != worst || (worstPid && element->getPid() != worstPid)) {
(worstPid && (element->getPid() != worstPid))) {
leading = false; leading = false;
last.clear(element); last.clear(element);
++it; ++it;
@ -807,16 +772,14 @@ bool LogBuffer::prune(log_id_t id, unsigned long pruneRows, uid_t caller_uid) {
it = erase(it, true); it = erase(it, true);
} else { } else {
last.add(element); last.add(element);
if (worstPid && if (worstPid && (!gc || mLastWorstPidOfSystem[id].find(worstPid) ==
(!gc || (mLastWorstPidOfSystem[id].find(worstPid) == mLastWorstPidOfSystem[id].end())) {
mLastWorstPidOfSystem[id].end()))) {
// element->getUid() may not be AID_SYSTEM, next best // element->getUid() may not be AID_SYSTEM, next best
// watermark if current one empty. id is not // watermark if current one empty. id is not
// LOG_ID_EVENTS or LOG_ID_SECURITY because of worstPid. // LOG_ID_EVENTS or LOG_ID_SECURITY because of worstPid.
mLastWorstPidOfSystem[id][worstPid] = it; mLastWorstPidOfSystem[id][worstPid] = it;
} }
if ((!gc && !worstPid) || if ((!gc && !worstPid) || mLastWorst[id].find(worst) == mLastWorst[id].end()) {
(mLastWorst[id].find(worst) == mLastWorst[id].end())) {
mLastWorst[id][worst] = it; mLastWorst[id][worst] = it;
} }
++it; ++it;
@ -884,13 +847,11 @@ bool LogBuffer::prune(log_id_t id, unsigned long pruneRows, uid_t caller_uid) {
} }
} }
LogReaderThread::unlock();
return (pruneRows > 0) && busy; return (pruneRows > 0) && busy;
} }
// clear all rows of type "id" from the buffer. // clear all rows of type "id" from the buffer.
bool LogBuffer::clear(log_id_t id, uid_t uid) { bool ChattyLogBuffer::Clear(log_id_t id, uid_t uid) {
bool busy = true; bool busy = true;
// If it takes more than 4 tries (seconds) to clear, then kill reader(s) // If it takes more than 4 tries (seconds) to clear, then kill reader(s)
for (int retry = 4;;) { for (int retry = 4;;) {
@ -907,20 +868,15 @@ bool LogBuffer::clear(log_id_t id, uid_t uid) {
// readers and let the clear run (below) deal with determining // readers and let the clear run (below) deal with determining
// if we are still blocked and return an error code to caller. // if we are still blocked and return an error code to caller.
if (busy) { if (busy) {
LogReaderThread::wrlock(); auto reader_threads_lock = std::lock_guard{reader_list_->reader_threads_lock()};
LastLogTimes::iterator times = mTimes.begin(); for (const auto& reader_thread : reader_list_->reader_threads()) {
while (times != mTimes.end()) { if (reader_thread->IsWatching(id)) {
LogReaderThread* entry = times->get();
// Killer punch
if (entry->IsWatching(id)) {
android::prdebug( android::prdebug(
"Kicking blocked reader, pid %d, from LogBuffer::clear()\n", "Kicking blocked reader, pid %d, from ChattyLogBuffer::clear()\n",
entry->client()->getPid()); reader_thread->client()->getPid());
entry->release_Locked(); reader_thread->release_Locked();
} }
times++;
} }
LogReaderThread::unlock();
} }
} }
wrlock(); wrlock();
@ -935,7 +891,7 @@ bool LogBuffer::clear(log_id_t id, uid_t uid) {
} }
// set the total space allocated to "id" // set the total space allocated to "id"
int LogBuffer::setSize(log_id_t id, unsigned long size) { int ChattyLogBuffer::SetSize(log_id_t id, unsigned long size) {
// Reasonable limits ... // Reasonable limits ...
if (!__android_logger_valid_buffer_size(size)) { if (!__android_logger_valid_buffer_size(size)) {
return -1; return -1;
@ -947,16 +903,16 @@ int LogBuffer::setSize(log_id_t id, unsigned long size) {
} }
// get the total space allocated to "id" // get the total space allocated to "id"
unsigned long LogBuffer::getSize(log_id_t id) { unsigned long ChattyLogBuffer::GetSize(log_id_t id) {
rdlock(); rdlock();
size_t retval = log_buffer_size(id); size_t retval = log_buffer_size(id);
unlock(); unlock();
return retval; return retval;
} }
uint64_t LogBuffer::flushTo(SocketClient* reader, uint64_t start, pid_t* lastTid, bool privileged, uint64_t ChattyLogBuffer::FlushTo(
bool security, SocketClient* reader, uint64_t start, pid_t* lastTid, bool privileged, bool security,
const std::function<int(const LogBufferElement* element)>& filter) { const std::function<FlushToResult(const LogBufferElement* element)>& filter) {
LogBufferElementCollection::iterator it; LogBufferElementCollection::iterator it;
uid_t uid = reader->getUid(); uid_t uid = reader->getUid();
@ -994,11 +950,11 @@ uint64_t LogBuffer::flushTo(SocketClient* reader, uint64_t start, pid_t* lastTid
// NB: calling out to another object with wrlock() held (safe) // NB: calling out to another object with wrlock() held (safe)
if (filter) { if (filter) {
int ret = filter(element); FlushToResult ret = filter(element);
if (ret == false) { if (ret == FlushToResult::kSkip) {
continue; continue;
} }
if (ret != true) { if (ret == FlushToResult::kStop) {
break; break;
} }
} }
@ -1012,7 +968,7 @@ uint64_t LogBuffer::flushTo(SocketClient* reader, uint64_t start, pid_t* lastTid
// is due to spam filter. chatty to chatty of different // is due to spam filter. chatty to chatty of different
// source is also due to spam filter. // source is also due to spam filter.
lastTid[element->getLogId()] = lastTid[element->getLogId()] =
(element->getDropped() && !sameTid) ? 0 : element->getTid(); (element->getDropped() && !sameTid) ? 0 : element->getTid();
} }
unlock(); unlock();

97
logd/ChattyLogBuffer.h Normal file
View file

@ -0,0 +1,97 @@
/*
* Copyright (C) 2012-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.
*/
#pragma once
#include <sys/types.h>
#include <list>
#include <optional>
#include <string>
#include <android/log.h>
#include <private/android_filesystem_config.h>
#include <sysutils/SocketClient.h>
#include "LogBuffer.h"
#include "LogBufferElement.h"
#include "LogStatistics.h"
#include "LogTags.h"
#include "LogWhiteBlackList.h"
typedef std::list<LogBufferElement*> LogBufferElementCollection;
class LogReaderList;
class LogReaderThread;
class ChattyLogBuffer : public LogBuffer {
LogBufferElementCollection mLogElements;
pthread_rwlock_t mLogElementsLock;
// watermark of any worst/chatty uid processing
typedef std::unordered_map<uid_t, LogBufferElementCollection::iterator> LogBufferIteratorMap;
LogBufferIteratorMap mLastWorst[LOG_ID_MAX];
// watermark of any worst/chatty pid of system processing
typedef std::unordered_map<pid_t, LogBufferElementCollection::iterator> LogBufferPidIteratorMap;
LogBufferPidIteratorMap mLastWorstPidOfSystem[LOG_ID_MAX];
unsigned long mMaxSize[LOG_ID_MAX];
LogBufferElement* lastLoggedElements[LOG_ID_MAX];
LogBufferElement* droppedElements[LOG_ID_MAX];
void log(LogBufferElement* elem);
public:
ChattyLogBuffer(LogReaderList* reader_list, LogTags* tags, PruneList* prune,
LogStatistics* stats);
~ChattyLogBuffer();
void Init() override;
int Log(log_id_t log_id, log_time realtime, uid_t uid, pid_t pid, pid_t tid, const char* msg,
uint16_t len) override;
uint64_t FlushTo(
SocketClient* writer, uint64_t start, pid_t* lastTid, bool privileged, bool security,
const std::function<FlushToResult(const LogBufferElement* element)>& filter) override;
bool Clear(log_id_t id, uid_t uid = AID_ROOT) override;
unsigned long GetSize(log_id_t id) override;
int SetSize(log_id_t id, unsigned long size) override;
private:
void wrlock() { pthread_rwlock_wrlock(&mLogElementsLock); }
void rdlock() { pthread_rwlock_rdlock(&mLogElementsLock); }
void unlock() { pthread_rwlock_unlock(&mLogElementsLock); }
void maybePrune(log_id_t id);
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(LogBufferElementCollection::iterator it,
bool coalesce = false);
// Returns an iterator to the oldest element for a given log type, or mLogElements.end() if
// there are no logs for the given log type. Requires mLogElementsLock to be held.
LogBufferElementCollection::iterator GetOldest(log_id_t log_id);
LogReaderList* reader_list_;
LogTags* tags_;
PruneList* prune_;
LogStatistics* stats_;
// Keeps track of the iterator to the oldest log message of a given log type, as an
// optimization when pruning logs. Use GetOldest() to retrieve.
std::optional<LogBufferElementCollection::iterator> oldest_[LOG_ID_MAX];
};

8
logd/CommandListener.cpp
View file

@ -81,7 +81,7 @@ int CommandListener::ClearCmd::runCommand(SocketClient* cli, int argc,
return 0; return 0;
} }
cli->sendMsg(buf()->clear((log_id_t)id, uid) ? "busy" : "success"); cli->sendMsg(buf()->Clear((log_id_t)id, uid) ? "busy" : "success");
return 0; return 0;
} }
@ -99,7 +99,7 @@ int CommandListener::GetBufSizeCmd::runCommand(SocketClient* cli, int argc,
return 0; return 0;
} }
unsigned long size = buf()->getSize((log_id_t)id); unsigned long size = buf()->GetSize((log_id_t)id);
char buf[512]; char buf[512];
snprintf(buf, sizeof(buf), "%lu", size); snprintf(buf, sizeof(buf), "%lu", size);
cli->sendMsg(buf); cli->sendMsg(buf);
@ -126,7 +126,7 @@ int CommandListener::SetBufSizeCmd::runCommand(SocketClient* cli, int argc,
} }
unsigned long size = atol(argv[2]); unsigned long size = atol(argv[2]);
if (buf()->setSize((log_id_t)id, size)) { if (buf()->SetSize((log_id_t)id, size)) {
cli->sendMsg("Range Error"); cli->sendMsg("Range Error");
return 0; return 0;
} }
@ -299,7 +299,7 @@ int CommandListener::ReinitCmd::runCommand(SocketClient* cli, int /*argc*/,
setname(); setname();
android::prdebug("logd reinit"); android::prdebug("logd reinit");
buf()->init(); buf()->Init();
prune()->init(nullptr); prune()->init(nullptr);
// This only works on userdebug and eng devices to re-read the // This only works on userdebug and eng devices to re-read the

15
logd/LogAudit.cpp
View file

@ -37,7 +37,6 @@
#include <private/android_logger.h> #include <private/android_logger.h>
#include "LogKlog.h" #include "LogKlog.h"
#include "LogReader.h"
#include "LogUtils.h" #include "LogUtils.h"
#include "libaudit.h" #include "libaudit.h"
@ -45,10 +44,9 @@
'<', '0' + LOG_MAKEPRI(LOG_AUTH, LOG_PRI(PRI)) / 10, \ '<', '0' + LOG_MAKEPRI(LOG_AUTH, LOG_PRI(PRI)) / 10, \
'0' + LOG_MAKEPRI(LOG_AUTH, LOG_PRI(PRI)) % 10, '>' '0' + LOG_MAKEPRI(LOG_AUTH, LOG_PRI(PRI)) % 10, '>'
LogAudit::LogAudit(LogBuffer* buf, LogReader* reader, int fdDmesg, LogStatistics* stats) LogAudit::LogAudit(LogBuffer* buf, int fdDmesg, LogStatistics* stats)
: SocketListener(getLogSocket(), false), : SocketListener(getLogSocket(), false),
logbuf(buf), logbuf(buf),
reader(reader),
fdDmesg(fdDmesg), fdDmesg(fdDmesg),
main(__android_logger_property_get_bool("ro.logd.auditd.main", BOOL_DEFAULT_TRUE)), main(__android_logger_property_get_bool("ro.logd.auditd.main", BOOL_DEFAULT_TRUE)),
events(__android_logger_property_get_bool("ro.logd.auditd.events", BOOL_DEFAULT_TRUE)), events(__android_logger_property_get_bool("ro.logd.auditd.events", BOOL_DEFAULT_TRUE)),
@ -276,9 +274,8 @@ int LogAudit::logPrint(const char* fmt, ...) {
memcpy(event->data + str_len - denial_metadata.length(), memcpy(event->data + str_len - denial_metadata.length(),
denial_metadata.c_str(), denial_metadata.length()); denial_metadata.c_str(), denial_metadata.length());
rc = logbuf->log( rc = logbuf->Log(LOG_ID_EVENTS, now, uid, pid, tid, reinterpret_cast<char*>(event),
LOG_ID_EVENTS, now, uid, pid, tid, reinterpret_cast<char*>(event), (message_len <= UINT16_MAX) ? (uint16_t)message_len : UINT16_MAX);
(message_len <= UINT16_MAX) ? (uint16_t)message_len : UINT16_MAX);
if (rc >= 0) { if (rc >= 0) {
notify |= 1 << LOG_ID_EVENTS; notify |= 1 << LOG_ID_EVENTS;
} }
@ -330,9 +327,8 @@ int LogAudit::logPrint(const char* fmt, ...) {
strncpy(newstr + 1 + str_len + prefix_len + suffix_len, strncpy(newstr + 1 + str_len + prefix_len + suffix_len,
denial_metadata.c_str(), denial_metadata.length()); denial_metadata.c_str(), denial_metadata.length());
rc = logbuf->log( rc = logbuf->Log(LOG_ID_MAIN, now, uid, pid, tid, newstr,
LOG_ID_MAIN, now, uid, pid, tid, newstr, (message_len <= UINT16_MAX) ? (uint16_t)message_len : UINT16_MAX);
(message_len <= UINT16_MAX) ? (uint16_t)message_len : UINT16_MAX);
if (rc >= 0) { if (rc >= 0) {
notify |= 1 << LOG_ID_MAIN; notify |= 1 << LOG_ID_MAIN;
@ -344,7 +340,6 @@ int LogAudit::logPrint(const char* fmt, ...) {
free(str); free(str);
if (notify) { if (notify) {
reader->notifyNewLog(notify);
if (rc < 0) { if (rc < 0) {
rc = message_len; rc = message_len;
} }

5
logd/LogAudit.h
View file

@ -23,18 +23,15 @@
#include "LogBuffer.h" #include "LogBuffer.h"
#include "LogStatistics.h" #include "LogStatistics.h"
class LogReader;
class LogAudit : public SocketListener { class LogAudit : public SocketListener {
LogBuffer* logbuf; LogBuffer* logbuf;
LogReader* reader;
int fdDmesg; // fdDmesg >= 0 is functionally bool dmesg int fdDmesg; // fdDmesg >= 0 is functionally bool dmesg
bool main; bool main;
bool events; bool events;
bool initialized; bool initialized;
public: public:
LogAudit(LogBuffer* buf, LogReader* reader, int fdDmesg, LogStatistics* stats); LogAudit(LogBuffer* buf, int fdDmesg, LogStatistics* stats);
int log(char* buf, size_t len); int log(char* buf, size_t len);
protected: protected:

96
logd/LogBuffer.h
View file

@ -1,5 +1,5 @@
/* /*
* Copyright (C) 2012-2014 The Android Open Source Project * Copyright (C) 2020 The Android Open Source Project
* *
* Licensed under the Apache License, Version 2.0 (the "License"); * Licensed under the Apache License, Version 2.0 (the "License");
* you may not use this file except in compliance with the License. * you may not use this file except in compliance with the License.
@ -18,89 +18,37 @@
#include <sys/types.h> #include <sys/types.h>
#include <list> #include <functional>
#include <optional>
#include <string>
#include <android/log.h> #include <log/log.h>
#include <private/android_filesystem_config.h>
#include <sysutils/SocketClient.h> #include <sysutils/SocketClient.h>
#include "LogBufferElement.h" #include "LogBufferElement.h"
#include "LogReaderThread.h"
#include "LogStatistics.h"
#include "LogTags.h"
#include "LogWhiteBlackList.h"
typedef std::list<LogBufferElement*> LogBufferElementCollection; enum class FlushToResult {
kSkip,
kStop,
kWrite,
};
class LogBuffer { class LogBuffer {
LogBufferElementCollection mLogElements; public:
pthread_rwlock_t mLogElementsLock; virtual ~LogBuffer() {}
// watermark of any worst/chatty uid processing virtual void Init() = 0;
typedef std::unordered_map<uid_t, LogBufferElementCollection::iterator>
LogBufferIteratorMap;
LogBufferIteratorMap mLastWorst[LOG_ID_MAX];
// watermark of any worst/chatty pid of system processing
typedef std::unordered_map<pid_t, LogBufferElementCollection::iterator>
LogBufferPidIteratorMap;
LogBufferPidIteratorMap mLastWorstPidOfSystem[LOG_ID_MAX];
unsigned long mMaxSize[LOG_ID_MAX]; virtual int Log(log_id_t log_id, log_time realtime, uid_t uid, pid_t pid, pid_t tid,
const char* msg, uint16_t len) = 0;
LogBufferElement* lastLoggedElements[LOG_ID_MAX];
LogBufferElement* droppedElements[LOG_ID_MAX];
void log(LogBufferElement* elem);
public:
LastLogTimes& mTimes;
LogBuffer(LastLogTimes* times, LogTags* tags, PruneList* prune, LogStatistics* stats);
~LogBuffer();
void init();
int log(log_id_t log_id, log_time realtime, uid_t uid, pid_t pid, pid_t tid, const char* msg,
uint16_t len);
// lastTid is an optional context to help detect if the last previous // lastTid is an optional context to help detect if the last previous
// valid message was from the same source so we can differentiate chatty // valid message was from the same source so we can differentiate chatty
// filter types (identical or expired) // filter types (identical or expired)
uint64_t flushTo(SocketClient* writer, uint64_t start, virtual uint64_t FlushTo(
pid_t* lastTid, // &lastTid[LOG_ID_MAX] or nullptr SocketClient* writer, uint64_t start,
bool privileged, bool security, pid_t* last_tid, // nullable
const std::function<int(const LogBufferElement* element)>& filter); bool privileged, bool security,
const std::function<FlushToResult(const LogBufferElement* element)>& filter) = 0;
bool clear(log_id_t id, uid_t uid = AID_ROOT); virtual bool Clear(log_id_t id, uid_t uid) = 0;
unsigned long getSize(log_id_t id); virtual unsigned long GetSize(log_id_t id) = 0;
int setSize(log_id_t id, unsigned long size); virtual int SetSize(log_id_t id, unsigned long size) = 0;
};
private:
void wrlock() {
pthread_rwlock_wrlock(&mLogElementsLock);
}
void rdlock() {
pthread_rwlock_rdlock(&mLogElementsLock);
}
void unlock() {
pthread_rwlock_unlock(&mLogElementsLock);
}
void maybePrune(log_id_t id);
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(
LogBufferElementCollection::iterator it, bool coalesce = false);
// Returns an iterator to the oldest element for a given log type, or mLogElements.end() if
// there are no logs for the given log type. Requires mLogElementsLock to be held.
LogBufferElementCollection::iterator GetOldest(log_id_t log_id);
LogTags* tags_;
PruneList* prune_;
LogStatistics* stats_;
// Keeps track of the iterator to the oldest log message of a given log type, as an
// optimization when pruning logs. Use GetOldest() to retrieve.
std::optional<LogBufferElementCollection::iterator> oldest_[LOG_ID_MAX];
};

2
logd/LogBufferElement.cpp
View file

@ -27,9 +27,9 @@
#include <log/log_read.h> #include <log/log_read.h>
#include <private/android_logger.h> #include <private/android_logger.h>
#include "LogBuffer.h"
#include "LogCommand.h" #include "LogCommand.h"
#include "LogReader.h" #include "LogReader.h"
#include "LogStatistics.h"
#include "LogUtils.h" #include "LogUtils.h"
const uint64_t LogBufferElement::FLUSH_ERROR(0); const uint64_t LogBufferElement::FLUSH_ERROR(0);

3
logd/LogBufferElement.h
View file

@ -24,7 +24,6 @@
#include <log/log.h> #include <log/log.h>
#include <sysutils/SocketClient.h> #include <sysutils/SocketClient.h>
class LogBuffer;
class LogStatistics; class LogStatistics;
#define EXPIRE_HOUR_THRESHOLD 24 // Only expire chatty UID logs to preserve #define EXPIRE_HOUR_THRESHOLD 24 // Only expire chatty UID logs to preserve
@ -34,8 +33,6 @@ class LogStatistics;
#define EXPIRE_RATELIMIT 10 // maximum rate in seconds to report expiration #define EXPIRE_RATELIMIT 10 // maximum rate in seconds to report expiration
class __attribute__((packed)) LogBufferElement { class __attribute__((packed)) LogBufferElement {
friend LogBuffer;
// sized to match reality of incoming log packets // sized to match reality of incoming log packets
const uint32_t mUid; const uint32_t mUid;
const uint32_t mPid; const uint32_t mPid;

12
logd/LogKlog.cpp
View file

@ -31,7 +31,6 @@
#include <private/android_logger.h> #include <private/android_logger.h>
#include "LogBuffer.h" #include "LogBuffer.h"
#include "LogReader.h"
#define KMSG_PRIORITY(PRI) \ #define KMSG_PRIORITY(PRI) \
'<', '0' + (LOG_SYSLOG | (PRI)) / 10, '0' + (LOG_SYSLOG | (PRI)) % 10, '>' '<', '0' + (LOG_SYSLOG | (PRI)) / 10, '0' + (LOG_SYSLOG | (PRI)) % 10, '>'
@ -202,11 +201,9 @@ log_time LogKlog::correction = (log_time(CLOCK_REALTIME) < log_time(CLOCK_MONOTO
? log_time(log_time::EPOCH) ? log_time(log_time::EPOCH)
: (log_time(CLOCK_REALTIME) - log_time(CLOCK_MONOTONIC)); : (log_time(CLOCK_REALTIME) - log_time(CLOCK_MONOTONIC));
LogKlog::LogKlog(LogBuffer* buf, LogReader* reader, int fdWrite, int fdRead, bool auditd, LogKlog::LogKlog(LogBuffer* buf, int fdWrite, int fdRead, bool auditd, LogStatistics* stats)
LogStatistics* stats)
: SocketListener(fdRead, false), : SocketListener(fdRead, false),
logbuf(buf), logbuf(buf),
reader(reader),
signature(CLOCK_MONOTONIC), signature(CLOCK_MONOTONIC),
initialized(false), initialized(false),
enableLogging(true), enableLogging(true),
@ -770,12 +767,7 @@ int LogKlog::log(const char* buf, ssize_t len) {
} }
// Log message // Log message
int rc = logbuf->log(LOG_ID_KERNEL, now, uid, pid, tid, newstr, (uint16_t)n); int rc = logbuf->Log(LOG_ID_KERNEL, now, uid, pid, tid, newstr, (uint16_t)n);
// notify readers
if (rc > 0) {
reader->notifyNewLog(static_cast<unsigned int>(1 << LOG_ID_KERNEL));
}
return rc; return rc;
} }

5
logd/LogKlog.h
View file

@ -22,11 +22,9 @@
#include "LogStatistics.h" #include "LogStatistics.h"
class LogBuffer; class LogBuffer;
class LogReader;
class LogKlog : public SocketListener { class LogKlog : public SocketListener {
LogBuffer* logbuf; LogBuffer* logbuf;
LogReader* reader;
const log_time signature; const log_time signature;
// Set once thread is started, separates KLOG_ACTION_READ_ALL // Set once thread is started, separates KLOG_ACTION_READ_ALL
// and KLOG_ACTION_READ phases. // and KLOG_ACTION_READ phases.
@ -40,8 +38,7 @@ class LogKlog : public SocketListener {
static log_time correction; static log_time correction;
public: public:
LogKlog(LogBuffer* buf, LogReader* reader, int fdWrite, int fdRead, bool auditd, LogKlog(LogBuffer* buf, int fdWrite, int fdRead, bool auditd, LogStatistics* stats);
LogStatistics* stats);
int log(const char* buf, ssize_t len); int log(const char* buf, ssize_t len);
static void convertMonotonicToReal(log_time& real) { real += correction; } static void convertMonotonicToReal(log_time& real) { real += correction; }

12
logd/LogListener.cpp
View file

@ -32,8 +32,7 @@
#include "LogListener.h" #include "LogListener.h"
#include "LogUtils.h" #include "LogUtils.h"
LogListener::LogListener(LogBuffer* buf, LogReader* reader) LogListener::LogListener(LogBuffer* buf) : socket_(GetLogSocket()), logbuf_(buf) {}
: socket_(GetLogSocket()), logbuf_(buf), reader_(reader) {}
bool LogListener::StartListener() { bool LogListener::StartListener() {
if (socket_ <= 0) { if (socket_ <= 0) {
@ -117,13 +116,8 @@ void LogListener::HandleData() {
// NB: hdr.msg_flags & MSG_TRUNC is not tested, silently passing a // NB: hdr.msg_flags & MSG_TRUNC is not tested, silently passing a
// truncated message to the logs. // truncated message to the logs.
int res = logbuf_->log(logId, header->realtime, cred->uid, cred->pid, header->tid, msg, logbuf_->Log(logId, header->realtime, cred->uid, cred->pid, header->tid, msg,
((size_t)n <= UINT16_MAX) ? (uint16_t)n : UINT16_MAX); ((size_t)n <= UINT16_MAX) ? (uint16_t)n : UINT16_MAX);
if (res > 0) {
reader_->notifyNewLog(static_cast<unsigned int>(1 << logId));
}
return;
} }
int LogListener::GetLogSocket() { int LogListener::GetLogSocket() {

3
logd/LogListener.h
View file

@ -21,7 +21,7 @@
class LogListener { class LogListener {
public: public:
LogListener(LogBuffer* buf, LogReader* reader); LogListener(LogBuffer* buf);
bool StartListener(); bool StartListener();
private: private:
@ -31,5 +31,4 @@ class LogListener {
int socket_; int socket_;
LogBuffer* logbuf_; LogBuffer* logbuf_;
LogReader* reader_;
}; };

90
logd/LogReader.cpp
View file

@ -21,7 +21,10 @@
#include <sys/socket.h> #include <sys/socket.h>
#include <sys/types.h> #include <sys/types.h>
#include <chrono>
#include <cutils/sockets.h> #include <cutils/sockets.h>
#include <private/android_filesystem_config.h>
#include <private/android_logger.h> #include <private/android_logger.h>
#include "LogBuffer.h" #include "LogBuffer.h"
@ -33,27 +36,8 @@ static bool CanReadSecurityLogs(SocketClient* client) {
return client->getUid() == AID_SYSTEM || client->getGid() == AID_SYSTEM; return client->getUid() == AID_SYSTEM || client->getGid() == AID_SYSTEM;
} }
LogReader::LogReader(LogBuffer* logbuf) LogReader::LogReader(LogBuffer* logbuf, LogReaderList* reader_list)
: SocketListener(getLogSocket(), true), mLogbuf(*logbuf) { : SocketListener(getLogSocket(), true), log_buffer_(logbuf), reader_list_(reader_list) {}
}
// When we are notified a new log entry is available, inform
// listening sockets who are watching this entry's log id.
void LogReader::notifyNewLog(unsigned int log_mask) {
LastLogTimes& times = mLogbuf.mTimes;
LogReaderThread::wrlock();
for (const auto& entry : times) {
if (!entry->IsWatchingMultiple(log_mask)) {
continue;
}
if (entry->timeout().tv_sec || entry->timeout().tv_nsec) {
continue;
}
entry->triggerReader_Locked();
}
LogReaderThread::unlock();
}
// Note returning false will release the SocketClient instance. // Note returning false will release the SocketClient instance.
bool LogReader::onDataAvailable(SocketClient* cli) { bool LogReader::onDataAvailable(SocketClient* cli) {
@ -74,15 +58,15 @@ bool LogReader::onDataAvailable(SocketClient* cli) {
// Clients are only allowed to send one command, disconnect them if they // Clients are only allowed to send one command, disconnect them if they
// send another. // send another.
LogReaderThread::wrlock(); {
for (const auto& entry : mLogbuf.mTimes) { auto lock = std::lock_guard{reader_list_->reader_threads_lock()};
if (entry->client() == cli) { for (const auto& entry : reader_list_->reader_threads()) {
entry->release_Locked(); if (entry->client() == cli) {
LogReaderThread::unlock(); entry->release_Locked();
return false; return false;
}
} }
} }
LogReaderThread::unlock();
unsigned long tail = 0; unsigned long tail = 0;
static const char _tail[] = " tail="; static const char _tail[] = " tail=";
@ -99,11 +83,12 @@ bool LogReader::onDataAvailable(SocketClient* cli) {
start.strptime(cp + sizeof(_start) - 1, "%s.%q"); start.strptime(cp + sizeof(_start) - 1, "%s.%q");
} }
uint64_t timeout = 0; std::chrono::steady_clock::time_point deadline = {};
static const char _timeout[] = " timeout="; static const char _timeout[] = " timeout=";
cp = strstr(buffer, _timeout); cp = strstr(buffer, _timeout);
if (cp) { if (cp) {
timeout = atol(cp + sizeof(_timeout) - 1) * NS_PER_SEC + log_time(CLOCK_MONOTONIC).nsec(); long timeout_seconds = atol(cp + sizeof(_timeout) - 1);
deadline = std::chrono::steady_clock::now() + std::chrono::seconds(timeout_seconds);
} }
unsigned int logMask = -1; unsigned int logMask = -1;
@ -137,8 +122,8 @@ bool LogReader::onDataAvailable(SocketClient* cli) {
if (!fastcmp<strncmp>(buffer, "dumpAndClose", 12)) { if (!fastcmp<strncmp>(buffer, "dumpAndClose", 12)) {
// Allow writer to get some cycles, and wait for pending notifications // Allow writer to get some cycles, and wait for pending notifications
sched_yield(); sched_yield();
LogReaderThread::wrlock(); reader_list_->reader_threads_lock().lock();
LogReaderThread::unlock(); reader_list_->reader_threads_lock().unlock();
sched_yield(); sched_yield();
nonBlock = true; nonBlock = true;
} }
@ -152,29 +137,29 @@ bool LogReader::onDataAvailable(SocketClient* cli) {
bool start_time_set = false; bool start_time_set = false;
uint64_t last = sequence; uint64_t last = sequence;
auto log_find_start = [pid, logMask, start, &sequence, &start_time_set, auto log_find_start = [pid, logMask, start, &sequence, &start_time_set,
&last](const LogBufferElement* element) -> int { &last](const LogBufferElement* element) -> FlushToResult {
if (pid && pid != element->getPid()) { if (pid && pid != element->getPid()) {
return 0; return FlushToResult::kSkip;
} }
if ((logMask & (1 << element->getLogId())) == 0) { if ((logMask & (1 << element->getLogId())) == 0) {
return 0; return FlushToResult::kSkip;
} }
if (start == element->getRealTime()) { if (start == element->getRealTime()) {
sequence = element->getSequence(); sequence = element->getSequence();
start_time_set = true; start_time_set = true;
return -1; return FlushToResult::kStop;
} else { } else {
if (start < element->getRealTime()) { if (start < element->getRealTime()) {
sequence = last; sequence = last;
start_time_set = true; start_time_set = true;
return -1; return FlushToResult::kStop;
} }
last = element->getSequence(); last = element->getSequence();
} }
return 0; return FlushToResult::kSkip;
}; };
logbuf().flushTo(cli, sequence, nullptr, privileged, can_read_security, log_find_start); log_buffer_->FlushTo(cli, sequence, nullptr, privileged, can_read_security, log_find_start);
if (!start_time_set) { if (!start_time_set) {
if (nonBlock) { if (nonBlock) {
@ -187,42 +172,38 @@ bool LogReader::onDataAvailable(SocketClient* cli) {
android::prdebug( android::prdebug(
"logdr: UID=%d GID=%d PID=%d %c tail=%lu logMask=%x pid=%d " "logdr: UID=%d GID=%d PID=%d %c tail=%lu logMask=%x pid=%d "
"start=%" PRIu64 "ns timeout=%" PRIu64 "ns\n", "start=%" PRIu64 "ns deadline=%" PRIi64 "ns\n",
cli->getUid(), cli->getGid(), cli->getPid(), nonBlock ? 'n' : 'b', tail, logMask, cli->getUid(), cli->getGid(), cli->getPid(), nonBlock ? 'n' : 'b', tail, logMask,
(int)pid, start.nsec(), timeout); (int)pid, start.nsec(), static_cast<int64_t>(deadline.time_since_epoch().count()));
if (start == log_time::EPOCH) { if (start == log_time::EPOCH) {
timeout = 0; deadline = {};
} }
LogReaderThread::wrlock(); auto lock = std::lock_guard{reader_list_->reader_threads_lock()};
auto entry = auto entry = std::make_unique<LogReaderThread>(*this, *reader_list_, cli, nonBlock, tail,
std::make_unique<LogReaderThread>(*this, cli, nonBlock, tail, logMask, pid, start, logMask, pid, start, sequence, deadline,
sequence, timeout, privileged, can_read_security); privileged, can_read_security);
if (!entry->startReader_Locked()) { if (!entry->startReader_Locked()) {
LogReaderThread::unlock();
return false; return false;
} }
// release client and entry reference counts once done // release client and entry reference counts once done
cli->incRef(); cli->incRef();
mLogbuf.mTimes.emplace_front(std::move(entry)); reader_list_->reader_threads().emplace_front(std::move(entry));
// Set acceptable upper limit to wait for slow reader processing b/27242723 // Set acceptable upper limit to wait for slow reader processing b/27242723
struct timeval t = { LOGD_SNDTIMEO, 0 }; struct timeval t = { LOGD_SNDTIMEO, 0 };
setsockopt(cli->getSocket(), SOL_SOCKET, SO_SNDTIMEO, (const char*)&t, setsockopt(cli->getSocket(), SOL_SOCKET, SO_SNDTIMEO, (const char*)&t,
sizeof(t)); sizeof(t));
LogReaderThread::unlock();
return true; return true;
} }
void LogReader::doSocketDelete(SocketClient* cli) { void LogReader::doSocketDelete(SocketClient* cli) {
LastLogTimes& times = mLogbuf.mTimes; auto lock = std::lock_guard{reader_list_->reader_threads_lock()};
LogReaderThread::wrlock(); auto it = reader_list_->reader_threads().begin();
LastLogTimes::iterator it = times.begin(); while (it != reader_list_->reader_threads().end()) {
while (it != times.end()) {
LogReaderThread* entry = it->get(); LogReaderThread* entry = it->get();
if (entry->client() == cli) { if (entry->client() == cli) {
entry->release_Locked(); entry->release_Locked();
@ -230,7 +211,6 @@ void LogReader::doSocketDelete(SocketClient* cli) {
} }
it++; it++;
} }
LogReaderThread::unlock();
} }
int LogReader::getLogSocket() { int LogReader::getLogSocket() {

19
logd/LogReader.h
View file

@ -18,6 +18,7 @@
#include <sysutils/SocketListener.h> #include <sysutils/SocketListener.h>
#include "LogReaderList.h"
#include "LogReaderThread.h" #include "LogReaderThread.h"
#define LOGD_SNDTIMEO 32 #define LOGD_SNDTIMEO 32
@ -25,21 +26,19 @@
class LogBuffer; class LogBuffer;
class LogReader : public SocketListener { class LogReader : public SocketListener {
LogBuffer& mLogbuf; public:
explicit LogReader(LogBuffer* logbuf, LogReaderList* reader_list);
public: LogBuffer* log_buffer() const { return log_buffer_; }
explicit LogReader(LogBuffer* logbuf);
void notifyNewLog(unsigned int logMask);
LogBuffer& logbuf(void) const { protected:
return mLogbuf;
}
protected:
virtual bool onDataAvailable(SocketClient* cli); virtual bool onDataAvailable(SocketClient* cli);
private: private:
static int getLogSocket(); static int getLogSocket();
void doSocketDelete(SocketClient* cli); void doSocketDelete(SocketClient* cli);
LogBuffer* log_buffer_;
LogReaderList* reader_list_;
}; };

33
logd/LogReaderList.cpp Normal file
View file

@ -0,0 +1,33 @@
/*
* Copyright (C) 2020 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 "LogReaderList.h"
// When we are notified a new log entry is available, inform
// listening sockets who are watching this entry's log id.
void LogReaderList::NotifyNewLog(unsigned int log_mask) const {
auto lock = std::lock_guard{reader_threads_lock_};
for (const auto& entry : reader_threads_) {
if (!entry->IsWatchingMultiple(log_mask)) {
continue;
}
if (entry->deadline().time_since_epoch().count() != 0) {
continue;
}
entry->triggerReader_Locked();
}
}

35
logd/LogReaderList.h Normal file
View file

@ -0,0 +1,35 @@
/*
* Copyright (C) 2020 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 <list>
#include <memory>
#include <mutex>
#include "LogReaderThread.h"
class LogReaderList {
public:
void NotifyNewLog(unsigned int log_mask) const;
std::list<std::unique_ptr<LogReaderThread>>& reader_threads() { return reader_threads_; }
std::mutex& reader_threads_lock() { return reader_threads_lock_; }
private:
std::list<std::unique_ptr<LogReaderThread>> reader_threads_;
mutable std::mutex reader_threads_lock_;
};

97
logd/LogReaderThread.cpp
View file

@ -27,14 +27,14 @@
using namespace std::placeholders; using namespace std::placeholders;
pthread_mutex_t LogReaderThread::timesLock = PTHREAD_MUTEX_INITIALIZER; LogReaderThread::LogReaderThread(LogReader& reader, LogReaderList& reader_list,
SocketClient* client, bool non_block, unsigned long tail,
LogReaderThread::LogReaderThread(LogReader& reader, SocketClient* client, bool non_block, unsigned int log_mask, pid_t pid, log_time start_time,
unsigned long tail, unsigned int log_mask, pid_t pid, uint64_t start, std::chrono::steady_clock::time_point deadline,
log_time start_time, uint64_t start, uint64_t timeout,
bool privileged, bool can_read_security_logs) bool privileged, bool can_read_security_logs)
: leading_dropped_(false), : leading_dropped_(false),
reader_(reader), reader_(reader),
reader_list_(reader_list),
log_mask_(log_mask), log_mask_(log_mask),
pid_(pid), pid_(pid),
tail_(tail), tail_(tail),
@ -43,13 +43,11 @@ LogReaderThread::LogReaderThread(LogReader& reader, SocketClient* client, bool n
client_(client), client_(client),
start_time_(start_time), start_time_(start_time),
start_(start), start_(start),
deadline_(deadline),
non_block_(non_block), non_block_(non_block),
privileged_(privileged), privileged_(privileged),
can_read_security_logs_(can_read_security_logs) { 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_)); memset(last_tid_, 0, sizeof(last_tid_));
pthread_cond_init(&thread_triggered_condition_, nullptr);
cleanSkip_Locked(); cleanSkip_Locked();
} }
@ -64,36 +62,35 @@ void LogReaderThread::ThreadFunction() {
SocketClient* client = client_; SocketClient* client = client_;
LogBuffer& logbuf = reader_.logbuf(); LogBuffer& logbuf = *reader_.log_buffer();
leading_dropped_ = true; leading_dropped_ = true;
wrlock(); auto lock = std::unique_lock{reader_list_.reader_threads_lock()};
uint64_t start = start_; uint64_t start = start_;
while (!release_) { while (!release_) {
if (timeout_.tv_sec || timeout_.tv_nsec) { if (deadline_.time_since_epoch().count() != 0) {
if (pthread_cond_clockwait(&thread_triggered_condition_, &timesLock, CLOCK_MONOTONIC, if (thread_triggered_condition_.wait_until(lock, deadline_) ==
&timeout_) == ETIMEDOUT) { std::cv_status::timeout) {
timeout_.tv_sec = 0; deadline_ = {};
timeout_.tv_nsec = 0;
} }
if (release_) { if (release_) {
break; break;
} }
} }
unlock(); lock.unlock();
if (tail_) { if (tail_) {
logbuf.flushTo(client, start, nullptr, privileged_, can_read_security_logs_, logbuf.FlushTo(client, start, nullptr, privileged_, can_read_security_logs_,
std::bind(&LogReaderThread::FilterFirstPass, this, _1)); std::bind(&LogReaderThread::FilterFirstPass, this, _1));
leading_dropped_ = leading_dropped_ =
true; // TODO: Likely a bug, if leading_dropped_ was not true before calling true; // TODO: Likely a bug, if leading_dropped_ was not true before calling
// flushTo(), then it should not be reset to true after. // flushTo(), then it should not be reset to true after.
} }
start = logbuf.flushTo(client, start, last_tid_, privileged_, can_read_security_logs_, start = logbuf.FlushTo(client, start, last_tid_, privileged_, can_read_security_logs_,
std::bind(&LogReaderThread::FilterSecondPass, this, _1)); std::bind(&LogReaderThread::FilterSecondPass, this, _1));
// We only ignore entries before the original start time for the first flushTo(), if we // We only ignore entries before the original start time for the first flushTo(), if we
@ -105,7 +102,7 @@ void LogReaderThread::ThreadFunction() {
start_time_.tv_sec = 0; start_time_.tv_sec = 0;
start_time_.tv_nsec = 0; start_time_.tv_nsec = 0;
wrlock(); lock.lock();
if (start == LogBufferElement::FLUSH_ERROR) { if (start == LogBufferElement::FLUSH_ERROR) {
break; break;
@ -119,35 +116,30 @@ void LogReaderThread::ThreadFunction() {
cleanSkip_Locked(); cleanSkip_Locked();
if (!timeout_.tv_sec && !timeout_.tv_nsec) { if (deadline_.time_since_epoch().count() == 0) {
pthread_cond_wait(&thread_triggered_condition_, &timesLock); thread_triggered_condition_.wait(lock);
} }
} }
LogReader& reader = reader_; reader_.release(client);
reader.release(client);
client->decRef(); client->decRef();
LastLogTimes& times = reader.logbuf().mTimes; auto& log_reader_threads = reader_list_.reader_threads();
auto it = std::find_if(times.begin(), times.end(), auto it = std::find_if(log_reader_threads.begin(), log_reader_threads.end(),
[this](const auto& other) { return other.get() == this; }); [this](const auto& other) { return other.get() == this; });
if (it != times.end()) { if (it != log_reader_threads.end()) {
times.erase(it); log_reader_threads.erase(it);
} }
unlock();
} }
// A first pass to count the number of elements // A first pass to count the number of elements
int LogReaderThread::FilterFirstPass(const LogBufferElement* element) { FlushToResult LogReaderThread::FilterFirstPass(const LogBufferElement* element) {
LogReaderThread::wrlock(); auto lock = std::lock_guard{reader_list_.reader_threads_lock()};
if (leading_dropped_) { if (leading_dropped_) {
if (element->getDropped()) { if (element->getDropped()) {
LogReaderThread::unlock(); return FlushToResult::kSkip;
return false;
} }
leading_dropped_ = false; leading_dropped_ = false;
} }
@ -161,48 +153,46 @@ int LogReaderThread::FilterFirstPass(const LogBufferElement* element) {
++count_; ++count_;
} }
LogReaderThread::unlock(); return FlushToResult::kSkip;
return false;
} }
// A second pass to send the selected elements // A second pass to send the selected elements
int LogReaderThread::FilterSecondPass(const LogBufferElement* element) { FlushToResult LogReaderThread::FilterSecondPass(const LogBufferElement* element) {
LogReaderThread::wrlock(); auto lock = std::lock_guard{reader_list_.reader_threads_lock()};
start_ = element->getSequence(); start_ = element->getSequence();
if (skip_ahead_[element->getLogId()]) { if (skip_ahead_[element->getLogId()]) {
skip_ahead_[element->getLogId()]--; skip_ahead_[element->getLogId()]--;
goto skip; return FlushToResult::kSkip;
} }
if (leading_dropped_) { if (leading_dropped_) {
if (element->getDropped()) { if (element->getDropped()) {
goto skip; return FlushToResult::kSkip;
} }
leading_dropped_ = false; leading_dropped_ = false;
} }
// Truncate to close race between first and second pass // Truncate to close race between first and second pass
if (non_block_ && tail_ && index_ >= count_) { if (non_block_ && tail_ && index_ >= count_) {
goto stop; return FlushToResult::kStop;
} }
if (!IsWatching(element->getLogId())) { if (!IsWatching(element->getLogId())) {
goto skip; return FlushToResult::kSkip;
} }
if (pid_ && pid_ != element->getPid()) { if (pid_ && pid_ != element->getPid()) {
goto skip; return FlushToResult::kSkip;
} }
if (start_time_ != log_time::EPOCH && element->getRealTime() <= start_time_) { if (start_time_ != log_time::EPOCH && element->getRealTime() <= start_time_) {
goto skip; return FlushToResult::kSkip;
} }
if (release_) { if (release_) {
goto stop; return FlushToResult::kStop;
} }
if (!tail_) { if (!tail_) {
@ -212,7 +202,7 @@ int LogReaderThread::FilterSecondPass(const LogBufferElement* element) {
++index_; ++index_;
if (count_ > tail_ && index_ <= (count_ - tail_)) { if (count_ > tail_ && index_ <= (count_ - tail_)) {
goto skip; return FlushToResult::kSkip;
} }
if (!non_block_) { if (!non_block_) {
@ -221,18 +211,9 @@ int LogReaderThread::FilterSecondPass(const LogBufferElement* element) {
ok: ok:
if (!skip_ahead_[element->getLogId()]) { if (!skip_ahead_[element->getLogId()]) {
LogReaderThread::unlock(); return FlushToResult::kWrite;
return true;
} }
// FALLTHRU return FlushToResult::kSkip;
skip:
LogReaderThread::unlock();
return false;
stop:
LogReaderThread::unlock();
return -1;
} }
void LogReaderThread::cleanSkip_Locked(void) { void LogReaderThread::cleanSkip_Locked(void) {

40
logd/LogReaderThread.h
View file

@ -21,31 +21,31 @@
#include <sys/types.h> #include <sys/types.h>
#include <time.h> #include <time.h>
#include <chrono>
#include <condition_variable>
#include <list> #include <list>
#include <memory> #include <memory>
#include <log/log.h> #include <log/log.h>
#include <sysutils/SocketClient.h> #include <sysutils/SocketClient.h>
#include "LogBuffer.h"
class LogReader; class LogReader;
class LogBufferElement; class LogBufferElement;
class LogReaderList;
class LogReaderThread { class LogReaderThread {
static pthread_mutex_t timesLock;
public: public:
LogReaderThread(LogReader& reader, SocketClient* client, bool non_block, unsigned long tail, LogReaderThread(LogReader& reader, LogReaderList& reader_list, SocketClient* client,
unsigned int log_mask, pid_t pid, log_time start_time, uint64_t sequence, bool non_block, unsigned long tail, unsigned int log_mask, pid_t pid,
uint64_t timeout, bool privileged, bool can_read_security_logs); log_time start_time, uint64_t sequence,
std::chrono::steady_clock::time_point deadline, bool privileged,
// Protect List manipulations bool can_read_security_logs);
static void wrlock() { pthread_mutex_lock(&timesLock); }
static void rdlock() { pthread_mutex_lock(&timesLock); }
static void unlock() { pthread_mutex_unlock(&timesLock); }
bool startReader_Locked(); bool startReader_Locked();
void triggerReader_Locked() { pthread_cond_signal(&thread_triggered_condition_); } void triggerReader_Locked() { thread_triggered_condition_.notify_all(); }
void triggerSkip_Locked(log_id_t id, unsigned int skip) { skip_ahead_[id] = skip; } void triggerSkip_Locked(log_id_t id, unsigned int skip) { skip_ahead_[id] = skip; }
void cleanSkip_Locked(); void cleanSkip_Locked();
@ -54,7 +54,7 @@ class LogReaderThread {
// gracefully shut down the socket. // gracefully shut down the socket.
shutdown(client_->getSocket(), SHUT_RDWR); shutdown(client_->getSocket(), SHUT_RDWR);
release_ = true; release_ = true;
pthread_cond_signal(&thread_triggered_condition_); thread_triggered_condition_.notify_all();
} }
bool IsWatching(log_id_t id) const { return log_mask_ & (1 << id); } bool IsWatching(log_id_t id) const { return log_mask_ & (1 << id); }
@ -62,13 +62,13 @@ class LogReaderThread {
const SocketClient* client() const { return client_; } const SocketClient* client() const { return client_; }
uint64_t start() const { return start_; } uint64_t start() const { return start_; }
const timespec& timeout() const { return timeout_; } std::chrono::steady_clock::time_point deadline() const { return deadline_; }
private: private:
void ThreadFunction(); void ThreadFunction();
// flushTo filter callbacks // flushTo filter callbacks
int FilterFirstPass(const LogBufferElement* element); FlushToResult FilterFirstPass(const LogBufferElement* element);
int FilterSecondPass(const LogBufferElement* element); FlushToResult FilterSecondPass(const LogBufferElement* element);
// Set to true to cause the thread to end and the LogReaderThread to delete itself. // Set to true to cause the thread to end and the LogReaderThread to delete itself.
bool release_ = false; bool release_ = false;
@ -77,10 +77,12 @@ class LogReaderThread {
bool leading_dropped_; bool leading_dropped_;
// Condition variable for waking the reader thread if there are messages pending for its client. // Condition variable for waking the reader thread if there are messages pending for its client.
pthread_cond_t thread_triggered_condition_; std::condition_variable thread_triggered_condition_;
// Reference to the parent thread that manages log reader sockets. // Reference to the parent thread that manages log reader sockets.
LogReader& reader_; LogReader& reader_;
// Reference to the parent list that shares its lock with each instance
LogReaderList& reader_list_;
// A mask of the logs buffers that are read by this reader. // A mask of the logs buffers that are read by this reader.
const unsigned int log_mask_; const unsigned int log_mask_;
// If set to non-zero, only pids equal to this are read by the reader. // If set to non-zero, only pids equal to this are read by the reader.
@ -110,9 +112,9 @@ class LogReaderThread {
log_time start_time_; log_time start_time_;
// The point from which the reader will read logs once awoken. // The point from which the reader will read logs once awoken.
uint64_t start_; uint64_t start_;
// CLOCK_MONOTONIC based timeout used for log wrapping. If this timeout expires before logs // CLOCK_MONOTONIC based deadline used for log wrapping. If this deadline expires before logs
// wrap, then wake up and send the logs to the reader anyway. // wrap, then wake up and send the logs to the reader anyway.
timespec timeout_; std::chrono::steady_clock::time_point deadline_;
// If this reader is 'dumpAndClose' and will disconnect once it has read its intended logs. // If this reader is 'dumpAndClose' and will disconnect once it has read its intended logs.
const bool non_block_; const bool non_block_;
@ -122,5 +124,3 @@ class LogReaderThread {
// Whether or not this reader can read security logs. See CanReadSecurityLogs(). // Whether or not this reader can read security logs. See CanReadSecurityLogs().
bool can_read_security_logs_; bool can_read_security_logs_;
}; };
typedef std::list<std::unique_ptr<LogReaderThread>> LastLogTimes;

1
logd/fuzz/Android.bp
View file

@ -25,6 +25,7 @@ cc_fuzz {
"liblog", "liblog",
"liblogd", "liblogd",
"libcutils", "libcutils",
"libsysutils",
], ],
cflags: ["-Werror"], cflags: ["-Werror"],
} }

15
logd/fuzz/log_buffer_log_fuzzer.cpp
View file

@ -15,7 +15,8 @@
*/ */
#include <string> #include <string>
#include "../LogBuffer.h" #include "../ChattyLogBuffer.h"
#include "../LogReaderList.h"
#include "../LogReaderThread.h" #include "../LogReaderThread.h"
#include "../LogStatistics.h" #include "../LogStatistics.h"
@ -71,7 +72,7 @@ int write_log_messages(const uint8_t** pdata, size_t* data_left, LogBuffer* log_
// Other elements not in enum. // Other elements not in enum.
log_id_t log_id = static_cast<log_id_t>(unsigned(logInput->log_id) % (LOG_ID_MAX + 1)); log_id_t log_id = static_cast<log_id_t>(unsigned(logInput->log_id) % (LOG_ID_MAX + 1));
log_buffer->log(log_id, logInput->realtime, logInput->uid, logInput->pid, logInput->tid, msg, log_buffer->Log(log_id, logInput->realtime, logInput->uid, logInput->pid, logInput->tid, msg,
sizeof(uint32_t) + msg_length + 1); sizeof(uint32_t) + msg_length + 1);
stats->Format(logInput->uid, logInput->pid, logInput->log_mask); stats->Format(logInput->uid, logInput->pid, logInput->log_mask);
*pdata = data; *pdata = data;
@ -95,25 +96,25 @@ extern "C" int LLVMFuzzerTestOneInput(const uint8_t* data, size_t size) {
return 0; return 0;
} }
LastLogTimes times; LogReaderList reader_list;
LogTags tags; LogTags tags;
PruneList prune_list; PruneList prune_list;
LogStatistics stats(true); LogStatistics stats(true);
LogBuffer log_buffer(&times, &tags, &prune_list, &stats); LogBuffer* log_buffer = new ChattyLogBuffer(&reader_list, &tags, &prune_list, &stats);
size_t data_left = size; size_t data_left = size;
const uint8_t** pdata = &data; const uint8_t** pdata = &data;
prune_list.init(nullptr); prune_list.init(nullptr);
// We want to get pruning code to get called. // We want to get pruning code to get called.
log_id_for_each(i) { log_buffer.setSize(i, 10000); } log_id_for_each(i) { log_buffer->SetSize(i, 10000); }
while (data_left >= sizeof(LogInput) + 2 * sizeof(uint8_t)) { while (data_left >= sizeof(LogInput) + 2 * sizeof(uint8_t)) {
if (!write_log_messages(pdata, &data_left, &log_buffer, &stats)) { if (!write_log_messages(pdata, &data_left, log_buffer, &stats)) {
return 0; return 0;
} }
} }
log_id_for_each(i) { log_buffer.clear(i); } log_id_for_each(i) { log_buffer->Clear(i, 0); }
return 0; return 0;
} }
} // namespace android } // namespace android

30
logd/main.cpp
View file

@ -47,6 +47,7 @@
#include <processgroup/sched_policy.h> #include <processgroup/sched_policy.h>
#include <utils/threads.h> #include <utils/threads.h>
#include "ChattyLogBuffer.h"
#include "CommandListener.h" #include "CommandListener.h"
#include "LogAudit.h" #include "LogAudit.h"
#include "LogBuffer.h" #include "LogBuffer.h"
@ -271,8 +272,10 @@ int main(int argc, char* argv[]) {
// A cache of event log tags // A cache of event log tags
LogTags log_tags; LogTags log_tags;
// Pruning configuration. // Pruning configuration.
PruneList prune_list; PruneList prune_list;
// Partial (required for chatty) or full logging statistics. // Partial (required for chatty) or full logging statistics.
bool enable_full_log_statistics = __android_logger_property_get_bool( bool enable_full_log_statistics = __android_logger_property_get_bool(
"logd.statistics", BOOL_DEFAULT_TRUE | BOOL_DEFAULT_FLAG_PERSIST | "logd.statistics", BOOL_DEFAULT_TRUE | BOOL_DEFAULT_FLAG_PERSIST |
@ -282,18 +285,15 @@ int main(int argc, char* argv[]) {
// Serves the purpose of managing the last logs times read on a // Serves the purpose of managing the last logs times read on a
// socket connection, and as a reader lock on a range of log // socket connection, and as a reader lock on a range of log
// entries. // entries.
LogReaderList reader_list;
LastLogTimes* times = new LastLogTimes();
// LogBuffer is the object which is responsible for holding all // LogBuffer is the object which is responsible for holding all
// log entries. // log entries.
LogBuffer* logBuf = new ChattyLogBuffer(&reader_list, &log_tags, &prune_list, &log_statistics);
LogBuffer* logBuf = new LogBuffer(times, &log_tags, &prune_list, &log_statistics);
// LogReader listens on /dev/socket/logdr. When a client // LogReader listens on /dev/socket/logdr. When a client
// connects, log entries in the LogBuffer are written to the client. // connects, log entries in the LogBuffer are written to the client.
LogReader* reader = new LogReader(logBuf, &reader_list);
LogReader* reader = new LogReader(logBuf);
if (reader->startListener()) { if (reader->startListener()) {
return EXIT_FAILURE; return EXIT_FAILURE;
} }
@ -301,15 +301,13 @@ int main(int argc, char* argv[]) {
// LogListener listens on /dev/socket/logdw for client // LogListener listens on /dev/socket/logdw for client
// initiated log messages. New log entries are added to LogBuffer // initiated log messages. New log entries are added to LogBuffer
// and LogReader is notified to send updates to connected clients. // and LogReader is notified to send updates to connected clients.
LogListener* swl = new LogListener(logBuf);
LogListener* swl = new LogListener(logBuf, reader);
if (!swl->StartListener()) { if (!swl->StartListener()) {
return EXIT_FAILURE; return EXIT_FAILURE;
} }
// Command listener listens on /dev/socket/logd for incoming logd // Command listener listens on /dev/socket/logd for incoming logd
// administrative commands. // administrative commands.
CommandListener* cl = new CommandListener(logBuf, &log_tags, &prune_list, &log_statistics); CommandListener* cl = new CommandListener(logBuf, &log_tags, &prune_list, &log_statistics);
if (cl->startListener()) { if (cl->startListener()) {
return EXIT_FAILURE; return EXIT_FAILURE;
@ -318,26 +316,22 @@ int main(int argc, char* argv[]) {
// LogAudit listens on NETLINK_AUDIT socket for selinux // LogAudit listens on NETLINK_AUDIT socket for selinux
// initiated log messages. New log entries are added to LogBuffer // initiated log messages. New log entries are added to LogBuffer
// and LogReader is notified to send updates to connected clients. // and LogReader is notified to send updates to connected clients.
LogAudit* al = nullptr; LogAudit* al = nullptr;
if (auditd) { if (auditd) {
al = new LogAudit( int dmesg_fd = __android_logger_property_get_bool("ro.logd.auditd.dmesg", BOOL_DEFAULT_TRUE)
logBuf, reader, ? fdDmesg
__android_logger_property_get_bool("ro.logd.auditd.dmesg", BOOL_DEFAULT_TRUE) : -1;
? fdDmesg al = new LogAudit(logBuf, dmesg_fd, &log_statistics);
: -1,
&log_statistics);
} }
LogKlog* kl = nullptr; LogKlog* kl = nullptr;
if (klogd) { if (klogd) {
kl = new LogKlog(logBuf, reader, fdDmesg, fdPmesg, al != nullptr, &log_statistics); kl = new LogKlog(logBuf, fdDmesg, fdPmesg, al != nullptr, &log_statistics);
} }
readDmesg(al, kl); readDmesg(al, kl);
// failure is an option ... messages are in dmesg (required by standard) // failure is an option ... messages are in dmesg (required by standard)
if (kl && kl->startListener()) { if (kl && kl->startListener()) {
delete kl; delete kl;
} }