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

logd: remove SocketClient from LogBuffer and LogBufferElement

Browse source 
In the future, we'll want to be able to write to outputs that are not
necessarily a libsysutils SocketClient, for example host tests of
LogBuffer.  Therefore, we add a LogWriter class to be used instead of
SocketClient.

Test: logging unit tests
Change-Id: I4385be65e14e83a635691a7ba79e9bf060e49484
This commit is contained in:
Tom Cherry 2020-05-14 19:25:05 -07:00
parent 0b3f9567c5
commit 283c9a1c00
14 changed files with 169 additions and 133 deletions
Show stats Download patch file Download diff file Expand all files Collapse all files

29
logd/ChattyLogBuffer.cpp
View file

@ -34,8 +34,6 @@
#include <cutils/properties.h>
#include <private/android_logger.h>
#include "LogKlog.h"
#include "LogReader.h"
#include "LogUtils.h"
#ifndef __predict_false
@ -494,8 +492,8 @@ void ChattyLogBuffer::kickMe(LogReaderThread* me, log_id_t id, unsigned long pru
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 ChattyLogBuffer::kickMe()\n",
me->client()->getPid());
android::prdebug("Kicking blocked reader, %s, from ChattyLogBuffer::kickMe()\n",
me->name().c_str());
me->release_Locked();
} else if (me->deadline().time_since_epoch().count() != 0) {
// Allow a blocked WRAP deadline reader to trigger and start reporting the log data.
@ -503,8 +501,8 @@ void ChattyLogBuffer::kickMe(LogReaderThread* me, log_id_t id, unsigned long pru
} else {
// tell slow reader to skip entries to catch up
android::prdebug(
"Skipping %lu entries from slow reader, pid %d, from ChattyLogBuffer::kickMe()\n",
pruneRows, me->client()->getPid());
"Skipping %lu entries from slow reader, %s, from ChattyLogBuffer::kickMe()\n",
pruneRows, me->name().c_str());
me->triggerSkip_Locked(id, pruneRows);
}
}
@ -872,8 +870,8 @@ bool ChattyLogBuffer::Clear(log_id_t id, uid_t uid) {
for (const auto& reader_thread : reader_list_->reader_threads()) {
if (reader_thread->IsWatching(id)) {
android::prdebug(
"Kicking blocked reader, pid %d, from ChattyLogBuffer::clear()\n",
reader_thread->client()->getPid());
"Kicking blocked reader, %s, from ChattyLogBuffer::clear()\n",
reader_thread->name().c_str());
reader_thread->release_Locked();
}
}
@ -911,10 +909,10 @@ unsigned long ChattyLogBuffer::GetSize(log_id_t id) {
}
uint64_t ChattyLogBuffer::FlushTo(
SocketClient* reader, uint64_t start, pid_t* lastTid, bool privileged, bool security,
LogWriter* writer, uint64_t start, pid_t* lastTid,
const std::function<FlushToResult(const LogBufferElement* element)>& filter) {
LogBufferElementCollection::iterator it;
uid_t uid = reader->getUid();
uid_t uid = writer->uid();
rdlock();
@ -940,11 +938,11 @@ uint64_t ChattyLogBuffer::FlushTo(
for (; it != mLogElements.end(); ++it) {
LogBufferElement* element = *it;
if (!privileged && (element->getUid() != uid)) {
if (!writer->privileged() && element->getUid() != uid) {
continue;
}
if (!security && (element->getLogId() == LOG_ID_SECURITY)) {
if (!writer->can_read_security_logs() && element->getLogId() == LOG_ID_SECURITY) {
continue;
}
@ -973,11 +971,10 @@ uint64_t ChattyLogBuffer::FlushTo(
unlock();
curr = element->getSequence();
// range locking in LastLogTimes looks after us
curr = element->flushTo(reader, stats_, sameTid);
if (curr == element->FLUSH_ERROR) {
return curr;
if (!element->FlushTo(writer, stats_, sameTid)) {
return FLUSH_ERROR;
}
rdlock();

8
logd/ChattyLogBuffer.h
View file

@ -28,15 +28,15 @@
#include "LogBuffer.h"
#include "LogBufferElement.h"
#include "LogReaderList.h"
#include "LogReaderThread.h"
#include "LogStatistics.h"
#include "LogTags.h"
#include "LogWhiteBlackList.h"
#include "LogWriter.h"
typedef std::list<LogBufferElement*> LogBufferElementCollection;
class LogReaderList;
class LogReaderThread;
class ChattyLogBuffer : public LogBuffer {
LogBufferElementCollection mLogElements;
pthread_rwlock_t mLogElementsLock;
@ -63,7 +63,7 @@ class ChattyLogBuffer : public LogBuffer {
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,
LogWriter* writer, uint64_t start, pid_t* lastTid,
const std::function<FlushToResult(const LogBufferElement* element)>& filter) override;
bool Clear(log_id_t id, uid_t uid = AID_ROOT) override;

1
logd/CommandListener.h
View file

@ -21,7 +21,6 @@
#include "LogBuffer.h"
#include "LogCommand.h"
#include "LogListener.h"
#include "LogReader.h"
#include "LogStatistics.h"
#include "LogTags.h"
#include "LogWhiteBlackList.h"

6
logd/LogBuffer.h
View file

@ -25,6 +25,8 @@
#include "LogBufferElement.h"
class LogWriter;
enum class FlushToResult {
kSkip,
kStop,
@ -42,10 +44,10 @@ class LogBuffer {
// lastTid is an optional context to help detect if the last previous
// valid message was from the same source so we can differentiate chatty
// filter types (identical or expired)
static const uint64_t FLUSH_ERROR = 0;
virtual uint64_t FlushTo(
SocketClient* writer, uint64_t start,
LogWriter* writer, uint64_t start,
pid_t* last_tid, // nullable
bool privileged, bool security,
const std::function<FlushToResult(const LogBufferElement* element)>& filter) = 0;
virtual bool Clear(log_id_t id, uid_t uid) = 0;

19
logd/LogBufferElement.cpp
View file

@ -28,11 +28,9 @@
#include <private/android_logger.h>
#include "LogCommand.h"
#include "LogReader.h"
#include "LogStatistics.h"
#include "LogUtils.h"
const uint64_t LogBufferElement::FLUSH_ERROR(0);
atomic_int_fast64_t LogBufferElement::sequence(1);
LogBufferElement::LogBufferElement(log_id_t log_id, log_time realtime, uid_t uid, pid_t pid,
@ -243,7 +241,7 @@ size_t LogBufferElement::populateDroppedMessage(char*& buffer, LogStatistics* st
return retval;
}
uint64_t LogBufferElement::flushTo(SocketClient* reader, LogStatistics* stats, bool lastSame) {
bool LogBufferElement::FlushTo(LogWriter* writer, LogStatistics* stats, bool lastSame) {
struct logger_entry entry = {};
entry.hdr_size = sizeof(struct logger_entry);
@ -254,23 +252,18 @@ uint64_t LogBufferElement::flushTo(SocketClient* reader, LogStatistics* stats, b
entry.sec = mRealTime.tv_sec;
entry.nsec = mRealTime.tv_nsec;
struct iovec iovec[2];
iovec[0].iov_base = &entry;
iovec[0].iov_len = entry.hdr_size;
char* buffer = nullptr;
const char* msg;
if (mDropped) {
entry.len = populateDroppedMessage(buffer, stats, lastSame);
if (!entry.len) return mSequence;
iovec[1].iov_base = buffer;
if (!entry.len) return true;
msg = buffer;
} else {
msg = mMsg;
entry.len = mMsgLen;
iovec[1].iov_base = mMsg;
}
iovec[1].iov_len = entry.len;
uint64_t retval = reader->sendDatav(iovec, 1 + (entry.len != 0)) ? FLUSH_ERROR : mSequence;
bool retval = writer->Write(entry, msg);
if (buffer) free(buffer);

6
logd/LogBufferElement.h
View file

@ -22,7 +22,8 @@
#include <sys/types.h>
#include <log/log.h>
#include <sysutils/SocketClient.h>
#include "LogWriter.h"
class LogStatistics;
@ -94,6 +95,5 @@ class __attribute__((packed)) LogBufferElement {
return mRealTime;
}
static const uint64_t FLUSH_ERROR;
uint64_t flushTo(SocketClient* writer, LogStatistics* parent, bool lastSame);
bool FlushTo(LogWriter* writer, LogStatistics* parent, bool lastSame);
};

3
logd/LogKlog.h
View file

@ -19,10 +19,9 @@
#include <private/android_logger.h>
#include <sysutils/SocketListener.h>
#include "LogBuffer.h"
#include "LogStatistics.h"
class LogBuffer;
class LogKlog : public SocketListener {
LogBuffer* logbuf;
const log_time signature;

1
logd/LogListener.h
View file

@ -17,7 +17,6 @@
#pragma once
#include "LogBuffer.h"
#include "LogReader.h"
class LogListener {
public:

84
logd/LogReader.cpp
View file

@ -23,6 +23,7 @@
#include <chrono>
#include <android-base/stringprintf.h>
#include <cutils/sockets.h>
#include <private/android_filesystem_config.h>
#include <private/android_logger.h>
@ -31,11 +32,48 @@
#include "LogBufferElement.h"
#include "LogReader.h"
#include "LogUtils.h"
#include "LogWriter.h"
static bool CanReadSecurityLogs(SocketClient* client) {
return client->getUid() == AID_SYSTEM || client->getGid() == AID_SYSTEM;
}
static std::string SocketClientToName(SocketClient* client) {
return android::base::StringPrintf("pid %d, fd %d", client->getPid(), client->getSocket());
}
class SocketLogWriter : public LogWriter {
public:
SocketLogWriter(LogReader* reader, SocketClient* client, bool privileged,
bool can_read_security_logs)
: LogWriter(client->getUid(), privileged, can_read_security_logs),
reader_(reader),
client_(client) {}
bool Write(const logger_entry& entry, const char* msg) override {
struct iovec iovec[2];
iovec[0].iov_base = const_cast<logger_entry*>(&entry);
iovec[0].iov_len = entry.hdr_size;
iovec[1].iov_base = const_cast<char*>(msg);
iovec[1].iov_len = entry.len;
return client_->sendDatav(iovec, 1 + (entry.len != 0)) == 0;
}
void Release() override {
reader_->release(client_);
client_->decRef();
}
void Shutdown() override { shutdown(client_->getSocket(), SHUT_RDWR); }
std::string name() const override { return SocketClientToName(client_); }
private:
LogReader* reader_;
SocketClient* client_;
};
LogReader::LogReader(LogBuffer* logbuf, LogReaderList* reader_list)
: SocketListener(getLogSocket(), true), log_buffer_(logbuf), reader_list_(reader_list) {}
@ -51,21 +89,14 @@ bool LogReader::onDataAvailable(SocketClient* cli) {
int len = read(cli->getSocket(), buffer, sizeof(buffer) - 1);
if (len <= 0) {
doSocketDelete(cli);
DoSocketDelete(cli);
return false;
}
buffer[len] = '\0';
// Clients are only allowed to send one command, disconnect them if they
// send another.
{
auto lock = std::lock_guard{reader_list_->reader_threads_lock()};
for (const auto& entry : reader_list_->reader_threads()) {
if (entry->client() == cli) {
entry->release_Locked();
return false;
}
}
// Clients are only allowed to send one command, disconnect them if they send another.
if (DoSocketDelete(cli)) {
return false;
}
unsigned long tail = 0;
@ -131,6 +162,9 @@ bool LogReader::onDataAvailable(SocketClient* cli) {
bool privileged = clientHasLogCredentials(cli);
bool can_read_security = CanReadSecurityLogs(cli);
std::unique_ptr<LogWriter> socket_log_writer(
new SocketLogWriter(this, cli, privileged, can_read_security));
uint64_t sequence = 1;
// Convert realtime to sequence number
if (start != log_time::EPOCH) {
@ -159,11 +193,10 @@ bool LogReader::onDataAvailable(SocketClient* cli) {
return FlushToResult::kSkip;
};
log_buffer_->FlushTo(cli, sequence, nullptr, privileged, can_read_security, log_find_start);
log_buffer_->FlushTo(socket_log_writer.get(), sequence, nullptr, log_find_start);
if (!start_time_set) {
if (nonBlock) {
doSocketDelete(cli);
return false;
}
sequence = LogBufferElement::getCurrentSequence();
@ -181,13 +214,9 @@ bool LogReader::onDataAvailable(SocketClient* cli) {
}
auto lock = std::lock_guard{reader_list_->reader_threads_lock()};
auto entry = std::make_unique<LogReaderThread>(*this, *reader_list_, cli, nonBlock, tail,
logMask, pid, start, sequence, deadline,
privileged, can_read_security);
if (!entry->startReader_Locked()) {
return false;
}
auto entry = std::make_unique<LogReaderThread>(log_buffer_, reader_list_,
std::move(socket_log_writer), nonBlock, tail,
logMask, pid, start, sequence, deadline);
// release client and entry reference counts once done
cli->incRef();
reader_list_->reader_threads().emplace_front(std::move(entry));
@ -200,17 +229,16 @@ bool LogReader::onDataAvailable(SocketClient* cli) {
return true;
}
void LogReader::doSocketDelete(SocketClient* cli) {
bool LogReader::DoSocketDelete(SocketClient* cli) {
auto cli_name = SocketClientToName(cli);
auto lock = std::lock_guard{reader_list_->reader_threads_lock()};
auto it = reader_list_->reader_threads().begin();
while (it != reader_list_->reader_threads().end()) {
LogReaderThread* entry = it->get();
if (entry->client() == cli) {
entry->release_Locked();
break;
for (const auto& reader : reader_list_->reader_threads()) {
if (reader->name() == cli_name) {
reader->release_Locked();
return true;
}
it++;
}
return false;
}
int LogReader::getLogSocket() {

7
logd/LogReader.h
View file

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

51
logd/LogReaderThread.cpp
View file

@ -23,50 +23,40 @@
#include <thread>
#include "LogBuffer.h"
#include "LogReader.h"
#include "LogReaderList.h"
using namespace std::placeholders;
LogReaderThread::LogReaderThread(LogReader& reader, LogReaderList& reader_list,
SocketClient* client, bool non_block, unsigned long tail,
unsigned int log_mask, pid_t pid, log_time start_time,
uint64_t start, std::chrono::steady_clock::time_point deadline,
bool privileged, bool can_read_security_logs)
: leading_dropped_(false),
reader_(reader),
LogReaderThread::LogReaderThread(LogBuffer* log_buffer, LogReaderList* reader_list,
std::unique_ptr<LogWriter> writer, bool non_block,
unsigned long tail, unsigned int log_mask, pid_t pid,
log_time start_time, uint64_t start,
std::chrono::steady_clock::time_point deadline)
: log_buffer_(log_buffer),
reader_list_(reader_list),
writer_(std::move(writer)),
leading_dropped_(false),
log_mask_(log_mask),
pid_(pid),
tail_(tail),
count_(0),
index_(0),
client_(client),
start_time_(start_time),
start_(start),
deadline_(deadline),
non_block_(non_block),
privileged_(privileged),
can_read_security_logs_(can_read_security_logs) {
non_block_(non_block) {
memset(last_tid_, 0, sizeof(last_tid_));
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_.log_buffer();
leading_dropped_ = true;
auto lock = std::unique_lock{reader_list_.reader_threads_lock()};
auto lock = std::unique_lock{reader_list_->reader_threads_lock()};
uint64_t start = start_;
@ -84,14 +74,14 @@ void LogReaderThread::ThreadFunction() {
lock.unlock();
if (tail_) {
logbuf.FlushTo(client, start, nullptr, privileged_, can_read_security_logs_,
std::bind(&LogReaderThread::FilterFirstPass, this, _1));
log_buffer_->FlushTo(writer_.get(), start, nullptr,
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));
start = log_buffer_->FlushTo(writer_.get(), start, last_tid_,
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
@ -104,7 +94,7 @@ void LogReaderThread::ThreadFunction() {
lock.lock();
if (start == LogBufferElement::FLUSH_ERROR) {
if (start == LogBuffer::FLUSH_ERROR) {
break;
}
@ -121,10 +111,9 @@ void LogReaderThread::ThreadFunction() {
}
}
reader_.release(client);
client->decRef();
writer_->Release();
auto& log_reader_threads = reader_list_.reader_threads();
auto& log_reader_threads = reader_list_->reader_threads();
auto it = std::find_if(log_reader_threads.begin(), log_reader_threads.end(),
[this](const auto& other) { return other.get() == this; });
@ -135,7 +124,7 @@ void LogReaderThread::ThreadFunction() {
// A first pass to count the number of elements
FlushToResult LogReaderThread::FilterFirstPass(const LogBufferElement* element) {
auto lock = std::lock_guard{reader_list_.reader_threads_lock()};
auto lock = std::lock_guard{reader_list_->reader_threads_lock()};
if (leading_dropped_) {
if (element->getDropped()) {
@ -158,7 +147,7 @@ FlushToResult LogReaderThread::FilterFirstPass(const LogBufferElement* element)
// A second pass to send the selected elements
FlushToResult LogReaderThread::FilterSecondPass(const LogBufferElement* element) {
auto lock = std::lock_guard{reader_list_.reader_threads_lock()};
auto lock = std::lock_guard{reader_list_->reader_threads_lock()};
start_ = element->getSequence();

40
logd/LogReaderThread.h
View file

@ -30,21 +30,17 @@
#include <sysutils/SocketClient.h>
#include "LogBuffer.h"
#include "LogBufferElement.h"
#include "LogWriter.h"
class LogReader;
class LogBufferElement;
class LogReaderList;
class LogReaderThread {
public:
LogReaderThread(LogReader& reader, LogReaderList& reader_list, SocketClient* client,
bool non_block, unsigned long tail, unsigned int log_mask, pid_t pid,
log_time start_time, uint64_t sequence,
std::chrono::steady_clock::time_point deadline, bool privileged,
bool can_read_security_logs);
bool startReader_Locked();
LogReaderThread(LogBuffer* log_buffer, LogReaderList* reader_list,
std::unique_ptr<LogWriter> writer, bool non_block, unsigned long tail,
unsigned int log_mask, pid_t pid, log_time start_time, uint64_t sequence,
std::chrono::steady_clock::time_point deadline);
void triggerReader_Locked() { thread_triggered_condition_.notify_all(); }
void triggerSkip_Locked(log_id_t id, unsigned int skip) { skip_ahead_[id] = skip; }
@ -52,7 +48,7 @@ class LogReaderThread {
void release_Locked() {
// gracefully shut down the socket.
shutdown(client_->getSocket(), SHUT_RDWR);
writer_->Shutdown();
release_ = true;
thread_triggered_condition_.notify_all();
}
@ -60,7 +56,7 @@ class LogReaderThread {
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_; }
std::string name() const { return writer_->name(); }
uint64_t start() const { return start_; }
std::chrono::steady_clock::time_point deadline() const { return deadline_; }
@ -70,19 +66,17 @@ class LogReaderThread {
FlushToResult FilterFirstPass(const LogBufferElement* element);
FlushToResult FilterSecondPass(const LogBufferElement* element);
std::condition_variable thread_triggered_condition_;
LogBuffer* log_buffer_;
LogReaderList* reader_list_;
std::unique_ptr<LogWriter> writer_;
// 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.
std::condition_variable thread_triggered_condition_;
// Reference to the parent thread that manages log reader sockets.
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.
const unsigned int log_mask_;
// If set to non-zero, only pids equal to this are read by the reader.
@ -105,8 +99,6 @@ class LogReaderThread {
// 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_;
@ -117,10 +109,4 @@ class LogReaderThread {
std::chrono::steady_clock::time_point deadline_;
// 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_;
};

46
logd/LogWriter.h Normal file
View file

@ -0,0 +1,46 @@
/*
* 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 <string>
#include <log/log_read.h>
// An interface for writing logs to a reader.
class LogWriter {
public:
LogWriter(uid_t uid, bool privileged, bool can_read_security_logs)
: uid_(uid), privileged_(privileged), can_read_security_logs_(can_read_security_logs) {}
virtual ~LogWriter() {}
virtual bool Write(const logger_entry& entry, const char* msg) = 0;
virtual void Shutdown() {}
virtual void Release() {}
virtual std::string name() const = 0;
uid_t uid() const { return uid_; }
bool privileged() const { return privileged_; }
bool can_read_security_logs() const { return can_read_security_logs_; }
private:
uid_t uid_;
// If this writer sees logs from all UIDs or only its own UID. See clientHasLogCredentials().
bool privileged_;
bool can_read_security_logs_; // If this writer sees security logs. See CanReadSecurityLogs().
};

1
logd/main.cpp
View file

@ -53,6 +53,7 @@
#include "LogBuffer.h"
#include "LogKlog.h"
#include "LogListener.h"
#include "LogReader.h"
#include "LogStatistics.h"
#include "LogTags.h"
#include "LogUtils.h"