summaryrefslogtreecommitdiffstats
path: root/logd
diff options
context:
space:
mode:
Diffstat (limited to 'logd')
-rw-r--r--logd/Android.mk11
-rw-r--r--logd/CommandListener.cpp16
-rw-r--r--logd/CommandListener.h11
-rw-r--r--logd/FlushCommand.cpp2
-rw-r--r--logd/FlushCommand.h4
-rw-r--r--logd/LogAudit.cpp41
-rw-r--r--logd/LogBuffer.cpp70
-rw-r--r--logd/LogBuffer.h11
-rw-r--r--logd/LogBufferElement.cpp9
-rw-r--r--logd/LogBufferElement.h11
-rw-r--r--logd/LogReader.cpp38
-rw-r--r--logd/LogStatistics.cpp109
-rw-r--r--logd/LogStatistics.h5
-rw-r--r--logd/LogTimes.cpp24
-rw-r--r--logd/LogTimes.h11
-rw-r--r--logd/README.property6
-rw-r--r--logd/main.cpp139
-rw-r--r--logd/tests/logd_test.cpp158
18 files changed, 263 insertions, 413 deletions
diff --git a/logd/Android.mk b/logd/Android.mk
index 188511f..127a66b 100644
--- a/logd/Android.mk
+++ b/logd/Android.mk
@@ -26,7 +26,16 @@ LOCAL_SHARED_LIBRARIES := \
libcutils \
libutils
-LOCAL_CFLAGS := -Werror $(shell sed -n 's/^\([0-9]*\)[ \t]*auditd[ \t].*/-DAUDITD_LOG_TAG=\1/p' $(LOCAL_PATH)/event.logtags)
+# This is what we want to do:
+# event_logtags = $(shell \
+# sed -n \
+# "s/^\([0-9]*\)[ \t]*$1[ \t].*/-D`echo $1 | tr a-z A-Z`_LOG_TAG=\1/p" \
+# $(LOCAL_PATH)/$2/event.logtags)
+# event_flag := $(call event_logtags,auditd)
+# so make sure we do not regret hard-coding it as follows:
+event_flag := -DAUDITD_LOG_TAG=1003
+
+LOCAL_CFLAGS := -Werror $(event_flag)
include $(BUILD_EXECUTABLE)
diff --git a/logd/CommandListener.cpp b/logd/CommandListener.cpp
index d7088b4..561ea3e 100644
--- a/logd/CommandListener.cpp
+++ b/logd/CommandListener.cpp
@@ -44,6 +44,7 @@ CommandListener::CommandListener(LogBuffer *buf, LogReader * /*reader*/,
registerCmd(new GetStatisticsCmd(buf));
registerCmd(new SetPruneListCmd(buf));
registerCmd(new GetPruneListCmd(buf));
+ registerCmd(new ReinitCmd());
}
CommandListener::ShutdownCmd::ShutdownCmd(LogBuffer *buf, LogReader *reader,
@@ -296,6 +297,21 @@ int CommandListener::SetPruneListCmd::runCommand(SocketClient *cli,
return 0;
}
+CommandListener::ReinitCmd::ReinitCmd()
+ : LogCommand("reinit")
+{ }
+
+int CommandListener::ReinitCmd::runCommand(SocketClient *cli,
+ int /*argc*/, char ** /*argv*/) {
+ setname();
+
+ reinit_signal_handler(SIGHUP);
+
+ cli->sendMsg("success");
+
+ return 0;
+}
+
int CommandListener::getLogSocket() {
static const char socketName[] = "logd";
int sock = android_get_control_socket(socketName);
diff --git a/logd/CommandListener.h b/logd/CommandListener.h
index cd1c306..83e06b4 100644
--- a/logd/CommandListener.h
+++ b/logd/CommandListener.h
@@ -23,6 +23,9 @@
#include "LogReader.h"
#include "LogListener.h"
+// See main.cpp for implementation
+void reinit_signal_handler(int /*signal*/);
+
class CommandListener : public FrameworkListener {
LogBuffer &mBuf;
@@ -60,6 +63,14 @@ private:
LogBufferCmd(GetStatistics)
LogBufferCmd(GetPruneList)
LogBufferCmd(SetPruneList)
+
+ class ReinitCmd : public LogCommand {
+ public:
+ ReinitCmd();
+ virtual ~ReinitCmd() {}
+ int runCommand(SocketClient *c, int argc, char ** argv);
+ };
+
};
#endif
diff --git a/logd/FlushCommand.cpp b/logd/FlushCommand.cpp
index 3be07c0..26a1861 100644
--- a/logd/FlushCommand.cpp
+++ b/logd/FlushCommand.cpp
@@ -27,7 +27,7 @@ FlushCommand::FlushCommand(LogReader &reader,
unsigned long tail,
unsigned int logMask,
pid_t pid,
- log_time start)
+ uint64_t start)
: mReader(reader)
, mNonBlock(nonBlock)
, mTail(tail)
diff --git a/logd/FlushCommand.h b/logd/FlushCommand.h
index f34c06a..61c6858 100644
--- a/logd/FlushCommand.h
+++ b/logd/FlushCommand.h
@@ -31,7 +31,7 @@ class FlushCommand : public SocketClientCommand {
unsigned long mTail;
unsigned int mLogMask;
pid_t mPid;
- log_time mStart;
+ uint64_t mStart;
public:
FlushCommand(LogReader &mReader,
@@ -39,7 +39,7 @@ public:
unsigned long tail = -1,
unsigned int logMask = -1,
pid_t pid = 0,
- log_time start = LogTimeEntry::EPOCH);
+ uint64_t start = 1);
virtual void runSocketCommand(SocketClient *client);
static bool hasReadLogs(SocketClient *client);
diff --git a/logd/LogAudit.cpp b/logd/LogAudit.cpp
index c7c0249..6b3e637 100644
--- a/logd/LogAudit.cpp
+++ b/logd/LogAudit.cpp
@@ -15,6 +15,7 @@
*/
#include <ctype.h>
+#include <endian.h>
#include <errno.h>
#include <limits.h>
#include <stdarg.h>
@@ -23,13 +24,15 @@
#include <sys/uio.h>
#include <syslog.h>
+#include <private/android_logger.h>
+
#include "libaudit.h"
#include "LogAudit.h"
-#define KMSG_PRIORITY(PRI) \
- '<', \
- '0' + (LOG_AUTH | (PRI)) / 10, \
- '0' + (LOG_AUTH | (PRI)) % 10, \
+#define KMSG_PRIORITY(PRI) \
+ '<', \
+ '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)
@@ -138,29 +141,23 @@ int LogAudit::logPrint(const char *fmt, ...) {
// log to events
size_t l = strlen(str);
- size_t n = l + sizeof(uint32_t) + sizeof(uint8_t) + sizeof(uint32_t);
+ size_t n = l + sizeof(android_log_event_string_t);
bool notify = false;
- char *newstr = reinterpret_cast<char *>(malloc(n));
- if (!newstr) {
+ android_log_event_string_t *event = static_cast<android_log_event_string_t *>(malloc(n));
+ if (!event) {
rc = -ENOMEM;
} else {
- cp = newstr;
- *cp++ = AUDITD_LOG_TAG & 0xFF;
- *cp++ = (AUDITD_LOG_TAG >> 8) & 0xFF;
- *cp++ = (AUDITD_LOG_TAG >> 16) & 0xFF;
- *cp++ = (AUDITD_LOG_TAG >> 24) & 0xFF;
- *cp++ = EVENT_TYPE_STRING;
- *cp++ = l & 0xFF;
- *cp++ = (l >> 8) & 0xFF;
- *cp++ = (l >> 16) & 0xFF;
- *cp++ = (l >> 24) & 0xFF;
- memcpy(cp, str, l);
-
- logbuf->log(LOG_ID_EVENTS, now, uid, pid, tid, newstr,
+ event->header.tag = htole32(AUDITD_LOG_TAG);
+ event->payload.type = EVENT_TYPE_STRING;
+ event->payload.length = htole32(l);
+ memcpy(event->payload.data, str, l);
+
+ logbuf->log(LOG_ID_EVENTS, now, uid, pid, tid,
+ reinterpret_cast<char *>(event),
(n <= USHRT_MAX) ? (unsigned short) n : USHRT_MAX);
- free(newstr);
+ free(event);
notify = true;
}
@@ -190,7 +187,7 @@ int LogAudit::logPrint(const char *fmt, ...) {
}
n = (estr - str) + strlen(ecomm) + l + 2;
- newstr = reinterpret_cast<char *>(malloc(n));
+ char *newstr = static_cast<char *>(malloc(n));
if (!newstr) {
rc = -ENOMEM;
} else {
diff --git a/logd/LogBuffer.cpp b/logd/LogBuffer.cpp
index 3d0b38f..2693583 100644
--- a/logd/LogBuffer.cpp
+++ b/logd/LogBuffer.cpp
@@ -92,11 +92,7 @@ static unsigned long property_get_size(const char *key) {
return value;
}
-LogBuffer::LogBuffer(LastLogTimes *times)
- : dgramQlenStatistics(false)
- , mTimes(*times) {
- pthread_mutex_init(&mLogElementsLock, NULL);
-
+void LogBuffer::init() {
static const char global_tuneable[] = "persist.logd.size"; // Settings App
static const char global_default[] = "ro.logd.size"; // BoardConfig.mk
@@ -132,6 +128,13 @@ LogBuffer::LogBuffer(LastLogTimes *times)
}
}
+LogBuffer::LogBuffer(LastLogTimes *times)
+ : mTimes(*times) {
+ pthread_mutex_init(&mLogElementsLock, NULL);
+
+ init();
+}
+
void LogBuffer::log(log_id_t log_id, log_time realtime,
uid_t uid, pid_t pid, pid_t tid,
const char *msg, unsigned short len) {
@@ -150,23 +153,6 @@ void LogBuffer::log(log_id_t log_id, log_time realtime,
while (last != mLogElements.begin()) {
--it;
if ((*it)->getRealTime() <= realtime) {
- // halves the peak performance, use with caution
- if (dgramQlenStatistics) {
- LogBufferElementCollection::iterator ib = it;
- unsigned short buckets, num = 1;
- for (unsigned short i = 0; (buckets = stats.dgramQlen(i)); ++i) {
- buckets -= num;
- num += buckets;
- while (buckets && (--ib != mLogElements.begin())) {
- --buckets;
- }
- if (buckets) {
- break;
- }
- stats.recordDiff(
- elem->getRealTime() - (*ib)->getRealTime(), i);
- }
- }
break;
}
last = it;
@@ -175,7 +161,7 @@ void LogBuffer::log(log_id_t log_id, log_time realtime,
if (last == mLogElements.end()) {
mLogElements.push_back(elem);
} else {
- log_time end = log_time::EPOCH;
+ uint64_t end = 1;
bool end_set = false;
bool end_always = false;
@@ -198,7 +184,7 @@ void LogBuffer::log(log_id_t log_id, log_time realtime,
}
if (end_always
- || (end_set && (end >= (*last)->getMonotonicTime()))) {
+ || (end_set && (end >= (*last)->getSequence()))) {
mLogElements.push_back(elem);
} else {
mLogElements.insert(last,elem);
@@ -255,7 +241,7 @@ void LogBuffer::prune(log_id_t id, unsigned long pruneRows, uid_t caller_uid) {
for(it = mLogElements.begin(); it != mLogElements.end();) {
LogBufferElement *e = *it;
- if (oldest && (oldest->mStart <= e->getMonotonicTime())) {
+ if (oldest && (oldest->mStart <= e->getSequence())) {
break;
}
@@ -307,7 +293,7 @@ void LogBuffer::prune(log_id_t id, unsigned long pruneRows, uid_t caller_uid) {
for(it = mLogElements.begin(); it != mLogElements.end();) {
LogBufferElement *e = *it;
- if (oldest && (oldest->mStart <= e->getMonotonicTime())) {
+ if (oldest && (oldest->mStart <= e->getSequence())) {
break;
}
@@ -348,7 +334,7 @@ void LogBuffer::prune(log_id_t id, unsigned long pruneRows, uid_t caller_uid) {
while((pruneRows > 0) && (it != mLogElements.end())) {
LogBufferElement *e = *it;
if (e->getLogId() == id) {
- if (oldest && (oldest->mStart <= e->getMonotonicTime())) {
+ if (oldest && (oldest->mStart <= e->getSequence())) {
if (!whitelist) {
if (stats.sizes(id) > (2 * log_buffer_size(id))) {
// kick a misbehaving log reader client off the island
@@ -380,7 +366,7 @@ void LogBuffer::prune(log_id_t id, unsigned long pruneRows, uid_t caller_uid) {
while((it != mLogElements.end()) && (pruneRows > 0)) {
LogBufferElement *e = *it;
if (e->getLogId() == id) {
- if (oldest && (oldest->mStart <= e->getMonotonicTime())) {
+ if (oldest && (oldest->mStart <= e->getSequence())) {
if (stats.sizes(id) > (2 * log_buffer_size(id))) {
// kick a misbehaving log reader client off the island
oldest->release_Locked();
@@ -437,16 +423,16 @@ unsigned long LogBuffer::getSize(log_id_t id) {
return retval;
}
-log_time LogBuffer::flushTo(
- SocketClient *reader, const log_time start, bool privileged,
- bool (*filter)(const LogBufferElement *element, void *arg), void *arg) {
+uint64_t LogBuffer::flushTo(
+ SocketClient *reader, const uint64_t start, bool privileged,
+ int (*filter)(const LogBufferElement *element, void *arg), void *arg) {
LogBufferElementCollection::iterator it;
- log_time max = start;
+ uint64_t max = start;
uid_t uid = reader->getUid();
pthread_mutex_lock(&mLogElementsLock);
- if (start == LogTimeEntry::EPOCH) {
+ if (start <= 1) {
// client wants to start from the beginning
it = mLogElements.begin();
} else {
@@ -455,7 +441,7 @@ log_time LogBuffer::flushTo(
for (it = mLogElements.end(); it != mLogElements.begin(); /* do nothing */) {
--it;
LogBufferElement *element = *it;
- if (element->getMonotonicTime() <= start) {
+ if (element->getSequence() <= start) {
it++;
break;
}
@@ -469,13 +455,19 @@ log_time LogBuffer::flushTo(
continue;
}
- if (element->getMonotonicTime() <= start) {
+ if (element->getSequence() <= start) {
continue;
}
// NB: calling out to another object with mLogElementsLock held (safe)
- if (filter && !(*filter)(element, arg)) {
- continue;
+ if (filter) {
+ int ret = (*filter)(element, arg);
+ if (ret == false) {
+ continue;
+ }
+ if (ret != true) {
+ break;
+ }
}
pthread_mutex_unlock(&mLogElementsLock);
@@ -495,7 +487,7 @@ log_time LogBuffer::flushTo(
}
void LogBuffer::formatStatistics(char **strp, uid_t uid, unsigned int logMask) {
- log_time oldest(CLOCK_MONOTONIC);
+ uint64_t oldest = UINT64_MAX;
pthread_mutex_lock(&mLogElementsLock);
@@ -505,7 +497,7 @@ void LogBuffer::formatStatistics(char **strp, uid_t uid, unsigned int logMask) {
LogBufferElement *element = *it;
if ((logMask & (1 << element->getLogId()))) {
- oldest = element->getMonotonicTime();
+ oldest = element->getSequence();
break;
}
}
diff --git a/logd/LogBuffer.h b/logd/LogBuffer.h
index 879baea..13e6aa8 100644
--- a/logd/LogBuffer.h
+++ b/logd/LogBuffer.h
@@ -37,7 +37,6 @@ class LogBuffer {
pthread_mutex_t mLogElementsLock;
LogStatistics stats;
- bool dgramQlenStatistics;
PruneList mPrune;
@@ -47,13 +46,14 @@ public:
LastLogTimes &mTimes;
LogBuffer(LastLogTimes *times);
+ void init();
void log(log_id_t log_id, log_time realtime,
uid_t uid, pid_t pid, pid_t tid,
const char *msg, unsigned short len);
- log_time flushTo(SocketClient *writer, const log_time start,
+ uint64_t flushTo(SocketClient *writer, const uint64_t start,
bool privileged,
- bool (*filter)(const LogBufferElement *element, void *arg) = NULL,
+ int (*filter)(const LogBufferElement *element, void *arg) = NULL,
void *arg = NULL);
void clear(log_id_t id, uid_t uid = AID_ROOT);
@@ -63,11 +63,6 @@ public:
// *strp uses malloc, use free to release.
void formatStatistics(char **strp, uid_t uid, unsigned int logMask);
- void enableDgramQlenStatistics() {
- stats.enableDgramQlenStatistics();
- dgramQlenStatistics = true;
- }
-
void enableStatistics() {
stats.enableStatistics();
}
diff --git a/logd/LogBufferElement.cpp b/logd/LogBufferElement.cpp
index d959ceb..5e780b5 100644
--- a/logd/LogBufferElement.cpp
+++ b/logd/LogBufferElement.cpp
@@ -24,7 +24,8 @@
#include "LogBufferElement.h"
#include "LogReader.h"
-const log_time LogBufferElement::FLUSH_ERROR((uint32_t)0, (uint32_t)0);
+const uint64_t LogBufferElement::FLUSH_ERROR(0);
+atomic_int_fast64_t LogBufferElement::sequence;
LogBufferElement::LogBufferElement(log_id_t log_id, log_time realtime,
uid_t uid, pid_t pid, pid_t tid,
@@ -34,7 +35,7 @@ LogBufferElement::LogBufferElement(log_id_t log_id, log_time realtime,
, mPid(pid)
, mTid(tid)
, mMsgLen(len)
- , mMonotonicTime(CLOCK_MONOTONIC)
+ , mSequence(sequence.fetch_add(1, memory_order_relaxed))
, mRealTime(realtime) {
mMsg = new char[len];
memcpy(mMsg, msg, len);
@@ -44,7 +45,7 @@ LogBufferElement::~LogBufferElement() {
delete [] mMsg;
}
-log_time LogBufferElement::flushTo(SocketClient *reader) {
+uint64_t LogBufferElement::flushTo(SocketClient *reader) {
struct logger_entry_v3 entry;
memset(&entry, 0, sizeof(struct logger_entry_v3));
entry.hdr_size = sizeof(struct logger_entry_v3);
@@ -64,5 +65,5 @@ log_time LogBufferElement::flushTo(SocketClient *reader) {
return FLUSH_ERROR;
}
- return mMonotonicTime;
+ return mSequence;
}
diff --git a/logd/LogBufferElement.h b/logd/LogBufferElement.h
index fdca973..25f1450 100644
--- a/logd/LogBufferElement.h
+++ b/logd/LogBufferElement.h
@@ -18,6 +18,7 @@
#define _LOGD_LOG_BUFFER_ELEMENT_H__
#include <sys/types.h>
+#include <stdatomic.h>
#include <sysutils/SocketClient.h>
#include <log/log.h>
#include <log/log_read.h>
@@ -29,8 +30,9 @@ class LogBufferElement {
const pid_t mTid;
char *mMsg;
const unsigned short mMsgLen;
- const log_time mMonotonicTime;
+ const uint64_t mSequence;
const log_time mRealTime;
+ static atomic_int_fast64_t sequence;
public:
LogBufferElement(log_id_t log_id, log_time realtime,
@@ -43,11 +45,12 @@ public:
pid_t getPid(void) const { return mPid; }
pid_t getTid(void) const { return mTid; }
unsigned short getMsgLen() const { return mMsgLen; }
- log_time getMonotonicTime(void) const { return mMonotonicTime; }
+ uint64_t getSequence(void) const { return mSequence; }
+ static uint64_t getCurrentSequence(void) { return sequence.load(memory_order_relaxed); }
log_time getRealTime(void) const { return mRealTime; }
- static const log_time FLUSH_ERROR;
- log_time flushTo(SocketClient *writer);
+ static const uint64_t FLUSH_ERROR;
+ uint64_t flushTo(SocketClient *writer);
};
#endif
diff --git a/logd/LogReader.cpp b/logd/LogReader.cpp
index 26df087..f7df275 100644
--- a/logd/LogReader.cpp
+++ b/logd/LogReader.cpp
@@ -100,50 +100,51 @@ bool LogReader::onDataAvailable(SocketClient *cli) {
nonBlock = true;
}
- // Convert realtime to monotonic time
- if (start == log_time::EPOCH) {
- start = LogTimeEntry::EPOCH;
- } else {
+ uint64_t sequence = 1;
+ // Convert realtime to sequence number
+ if (start != log_time::EPOCH) {
class LogFindStart {
const pid_t mPid;
const unsigned mLogMask;
bool startTimeSet;
log_time &start;
- log_time last;
+ uint64_t &sequence;
+ uint64_t last;
public:
- LogFindStart(unsigned logMask, pid_t pid, log_time &start)
+ LogFindStart(unsigned logMask, pid_t pid, log_time &start, uint64_t &sequence)
: mPid(pid)
, mLogMask(logMask)
, startTimeSet(false)
, start(start)
- , last(LogTimeEntry::EPOCH)
+ , sequence(sequence)
+ , last(sequence)
{ }
- static bool callback(const LogBufferElement *element, void *obj) {
+ static int callback(const LogBufferElement *element, void *obj) {
LogFindStart *me = reinterpret_cast<LogFindStart *>(obj);
- if (!me->startTimeSet
- && (!me->mPid || (me->mPid == element->getPid()))
+ if ((!me->mPid || (me->mPid == element->getPid()))
&& (me->mLogMask & (1 << element->getLogId()))) {
if (me->start == element->getRealTime()) {
- me->start = element->getMonotonicTime();
+ me->sequence = element->getSequence();
me->startTimeSet = true;
+ return -1;
} else {
if (me->start < element->getRealTime()) {
- me->start = me->last;
+ me->sequence = me->last;
me->startTimeSet = true;
+ return -1;
}
- me->last = element->getMonotonicTime();
+ me->last = element->getSequence();
}
}
return false;
}
bool found() { return startTimeSet; }
- } logFindStart(logMask, pid, start);
+ } logFindStart(logMask, pid, start, sequence);
- logbuf().flushTo(cli, LogTimeEntry::EPOCH,
- FlushCommand::hasReadLogs(cli),
+ logbuf().flushTo(cli, sequence, FlushCommand::hasReadLogs(cli),
logFindStart.callback, &logFindStart);
if (!logFindStart.found()) {
@@ -151,12 +152,11 @@ bool LogReader::onDataAvailable(SocketClient *cli) {
doSocketDelete(cli);
return false;
}
- log_time now(CLOCK_MONOTONIC);
- start = now;
+ sequence = LogBufferElement::getCurrentSequence();
}
}
- FlushCommand command(*this, nonBlock, tail, logMask, pid, start);
+ FlushCommand command(*this, nonBlock, tail, logMask, pid, sequence);
command.runSocketCommand(cli);
return true;
}
diff --git a/logd/LogStatistics.cpp b/logd/LogStatistics.cpp
index 53036e6..5a70689 100644
--- a/logd/LogStatistics.cpp
+++ b/logd/LogStatistics.cpp
@@ -395,71 +395,11 @@ size_t LidStatistics::elementsTotal(uid_t uid, pid_t pid) {
LogStatistics::LogStatistics()
: mStatistics(false)
- , dgramQlenStatistics(false)
, start(CLOCK_MONOTONIC) {
log_id_for_each(i) {
mSizes[i] = 0;
mElements[i] = 0;
}
-
- for(unsigned short bucket = 0; dgramQlen(bucket); ++bucket) {
- mMinimum[bucket].tv_sec = mMinimum[bucket].tv_sec_max;
- mMinimum[bucket].tv_nsec = mMinimum[bucket].tv_nsec_max;
- }
-}
-
-// Each bucket below represents a dgramQlen of log messages. By
-// finding the minimum period of time from start to finish
-// of each dgramQlen, we can get a performance expectation for
-// the user space logger. The net result is that the period
-// of time divided by the dgramQlen will give us the average time
-// between log messages; at the point where the average time
-// is greater than the throughput capability of the logger
-// we will not longer require the benefits of the FIFO formed
-// by max_dgram_qlen. We will also expect to see a very visible
-// knee in the average time between log messages at this point,
-// so we do not necessarily have to compare the rate against the
-// measured performance (BM_log_maximum_retry) of the logger.
-//
-// for example (reformatted):
-//
-// Minimum time between log events per dgramQlen:
-// 1 2 3 5 10 20 30 50 100 200 300 400 500 600
-// 5u2 12u 13u 15u 16u 27u 30u 36u 407u 3m1 3m3 3m9 3m9 5m5
-//
-// demonstrates a clear knee rising at 100, so this means that for this
-// case max_dgram_qlen = 100 would be more than sufficient to handle the
-// worst that the system could stuff into the logger. The
-// BM_log_maximum_retry performance (derated by the log collection) on the
-// same system was 33.2us so we would almost be fine with max_dgram_qlen = 50.
-// BM_log_maxumum_retry with statistics off is roughly 20us, so
-// max_dgram_qlen = 20 would work. We will be more than willing to have
-// a large engineering margin so the rule of thumb that lead us to 100 is
-// fine.
-//
-// bucket dgramQlen are tuned for /proc/sys/net/unix/max_dgram_qlen = 300
-const unsigned short LogStatistics::mBuckets[] = {
- 1, 2, 3, 5, 10, 20, 30, 50, 100, 200, 300, 400, 500, 600
-};
-
-unsigned short LogStatistics::dgramQlen(unsigned short bucket) {
- if (bucket >= sizeof(mBuckets) / sizeof(mBuckets[0])) {
- return 0;
- }
- return mBuckets[bucket];
-}
-
-unsigned long long LogStatistics::minimum(unsigned short bucket) {
- if (mMinimum[bucket].tv_sec == mMinimum[bucket].tv_sec_max) {
- return 0;
- }
- return mMinimum[bucket].nsec();
-}
-
-void LogStatistics::recordDiff(log_time diff, unsigned short bucket) {
- if ((diff.tv_sec || diff.tv_nsec) && (mMinimum[bucket] > diff)) {
- mMinimum[bucket] = diff;
- }
}
void LogStatistics::add(unsigned short size,
@@ -709,55 +649,6 @@ void LogStatistics::format(char **buf,
pids.clear();
}
- if (dgramQlenStatistics) {
- const unsigned short spaces_time = 6;
- const unsigned long long max_seconds = 100000;
- spaces = 0;
- string.append("\n\nMinimum time between log events per max_dgram_qlen:\n");
- for(unsigned short i = 0; dgramQlen(i); ++i) {
- oldLength = string.length();
- if (spaces < 0) {
- spaces = 0;
- }
- string.appendFormat("%*s%u", spaces, "", dgramQlen(i));
- spaces += spaces_time + oldLength - string.length();
- }
- string.append("\n");
- spaces = 0;
- unsigned short n;
- for(unsigned short i = 0; (n = dgramQlen(i)); ++i) {
- unsigned long long duration = minimum(i);
- if (duration) {
- duration /= n;
- if (duration >= (NS_PER_SEC * max_seconds)) {
- duration = NS_PER_SEC * (max_seconds - 1);
- }
- oldLength = string.length();
- if (spaces < 0) {
- spaces = 0;
- }
- string.appendFormat("%*s", spaces, "");
- if (duration >= (NS_PER_SEC * 10)) {
- string.appendFormat("%llu",
- (duration + (NS_PER_SEC / 2))
- / NS_PER_SEC);
- } else if (duration >= (NS_PER_SEC / (1000 / 10))) {
- string.appendFormat("%llum",
- (duration + (NS_PER_SEC / 2 / 1000))
- / (NS_PER_SEC / 1000));
- } else if (duration >= (NS_PER_SEC / (1000000 / 10))) {
- string.appendFormat("%lluu",
- (duration + (NS_PER_SEC / 2 / 1000000))
- / (NS_PER_SEC / 1000000));
- } else {
- string.appendFormat("%llun", duration);
- }
- spaces -= string.length() - oldLength;
- }
- spaces += spaces_time;
- }
- }
-
log_id_for_each(i) {
if (!(logMask & (1 << i))) {
continue;
diff --git a/logd/LogStatistics.h b/logd/LogStatistics.h
index f6c4329..f892cd0 100644
--- a/logd/LogStatistics.h
+++ b/logd/LogStatistics.h
@@ -145,7 +145,6 @@ class LogStatistics {
size_t mElements[LOG_ID_MAX];
bool mStatistics;
- bool dgramQlenStatistics;
static const unsigned short mBuckets[14];
log_time mMinimum[sizeof(mBuckets) / sizeof(mBuckets[0])];
@@ -157,11 +156,7 @@ public:
LidStatistics &id(log_id_t log_id) { return LogIds[log_id]; }
- void enableDgramQlenStatistics() { dgramQlenStatistics = true; }
void enableStatistics() { mStatistics = true; }
- static unsigned short dgramQlen(unsigned short bucket);
- unsigned long long minimum(unsigned short bucket);
- void recordDiff(log_time diff, unsigned short bucket);
void add(unsigned short size, log_id_t log_id, uid_t uid, pid_t pid);
void subtract(unsigned short size, log_id_t log_id, uid_t uid, pid_t pid);
diff --git a/logd/LogTimes.cpp b/logd/LogTimes.cpp
index 5f9db8d..1b60b7e 100644
--- a/logd/LogTimes.cpp
+++ b/logd/LogTimes.cpp
@@ -23,12 +23,10 @@
pthread_mutex_t LogTimeEntry::timesLock = PTHREAD_MUTEX_INITIALIZER;
-const struct timespec LogTimeEntry::EPOCH = { 0, 1 };
-
LogTimeEntry::LogTimeEntry(LogReader &reader, SocketClient *client,
bool nonBlock, unsigned long tail,
unsigned int logMask, pid_t pid,
- log_time start)
+ uint64_t start)
: mRefCount(1)
, mRelease(false)
, mError(false)
@@ -42,7 +40,7 @@ LogTimeEntry::LogTimeEntry(LogReader &reader, SocketClient *client,
, mClient(client)
, mStart(start)
, mNonBlock(nonBlock)
- , mEnd(CLOCK_MONOTONIC)
+ , mEnd(LogBufferElement::getCurrentSequence())
{
pthread_cond_init(&threadTriggeredCondition, NULL);
cleanSkip_Locked();
@@ -129,7 +127,7 @@ void *LogTimeEntry::threadStart(void *obj) {
lock();
while (me->threadRunning && !me->isError_Locked()) {
- log_time start = me->mStart;
+ uint64_t start = me->mStart;
unlock();
@@ -161,13 +159,13 @@ void *LogTimeEntry::threadStart(void *obj) {
}
// A first pass to count the number of elements
-bool LogTimeEntry::FilterFirstPass(const LogBufferElement *element, void *obj) {
+int LogTimeEntry::FilterFirstPass(const LogBufferElement *element, void *obj) {
LogTimeEntry *me = reinterpret_cast<LogTimeEntry *>(obj);
LogTimeEntry::lock();
if (me->mCount == 0) {
- me->mStart = element->getMonotonicTime();
+ me->mStart = element->getSequence();
}
if ((!me->mPid || (me->mPid == element->getPid()))
@@ -181,12 +179,12 @@ bool LogTimeEntry::FilterFirstPass(const LogBufferElement *element, void *obj) {
}
// A second pass to send the selected elements
-bool LogTimeEntry::FilterSecondPass(const LogBufferElement *element, void *obj) {
+int LogTimeEntry::FilterSecondPass(const LogBufferElement *element, void *obj) {
LogTimeEntry *me = reinterpret_cast<LogTimeEntry *>(obj);
LogTimeEntry::lock();
- me->mStart = element->getMonotonicTime();
+ me->mStart = element->getSequence();
if (me->skipAhead[element->getLogId()]) {
me->skipAhead[element->getLogId()]--;
@@ -195,7 +193,7 @@ bool LogTimeEntry::FilterSecondPass(const LogBufferElement *element, void *obj)
// Truncate to close race between first and second pass
if (me->mNonBlock && me->mTail && (me->mIndex >= me->mCount)) {
- goto skip;
+ goto stop;
}
if (!me->isWatching(element->getLogId())) {
@@ -207,7 +205,7 @@ bool LogTimeEntry::FilterSecondPass(const LogBufferElement *element, void *obj)
}
if (me->isError_Locked()) {
- goto skip;
+ goto stop;
}
if (!me->mTail) {
@@ -234,6 +232,10 @@ ok:
skip:
LogTimeEntry::unlock();
return false;
+
+stop:
+ LogTimeEntry::unlock();
+ return -1;
}
void LogTimeEntry::cleanSkip_Locked(void) {
diff --git a/logd/LogTimes.h b/logd/LogTimes.h
index 81aedfb..ae2f92b 100644
--- a/logd/LogTimes.h
+++ b/logd/LogTimes.h
@@ -47,13 +47,12 @@ class LogTimeEntry {
public:
LogTimeEntry(LogReader &reader, SocketClient *client, bool nonBlock,
unsigned long tail, unsigned int logMask, pid_t pid,
- log_time start);
+ uint64_t start);
SocketClient *mClient;
- static const struct timespec EPOCH;
- log_time mStart;
+ uint64_t mStart;
const bool mNonBlock;
- const log_time mEnd; // only relevant if mNonBlock
+ const uint64_t mEnd; // only relevant if mNonBlock
// Protect List manipulations
static void lock(void) { pthread_mutex_lock(&timesLock); }
@@ -103,8 +102,8 @@ public:
}
bool isWatching(log_id_t id) { return (mLogMask & (1<<id)) != 0; }
// flushTo filter callbacks
- static bool FilterFirstPass(const LogBufferElement *element, void *me);
- static bool FilterSecondPass(const LogBufferElement *element, void *me);
+ static int FilterFirstPass(const LogBufferElement *element, void *me);
+ static int FilterSecondPass(const LogBufferElement *element, void *me);
};
typedef android::List<LogTimeEntry *> LastLogTimes;
diff --git a/logd/README.property b/logd/README.property
index b7fcece..60542b2 100644
--- a/logd/README.property
+++ b/logd/README.property
@@ -7,12 +7,6 @@ logd.auditd.dmesg bool true selinux audit messages duplicated and
logd.statistics bool depends Enable logcat -S statistics.
ro.config.low_ram bool false if true, logd.statistics default false
ro.build.type string if user, logd.statistics default false
-logd.statistics.dgram_qlen bool false Record dgram_qlen statistics. This
- represents a performance impact and
- is used to determine the platform's
- minimum domain socket network FIFO
- size (see source for details) based
- on typical load (logcat -S to view)
persist.logd.size number 256K default size of the buffer for all
log ids at initial startup, at runtime
use: logcat -b all -G <value>
diff --git a/logd/main.cpp b/logd/main.cpp
index 7a1ae54..a61beff 100644
--- a/logd/main.cpp
+++ b/logd/main.cpp
@@ -17,7 +17,10 @@
#include <dirent.h>
#include <errno.h>
#include <fcntl.h>
+#include <poll.h>
#include <sched.h>
+#include <semaphore.h>
+#include <signal.h>
#include <stdio.h>
#include <stdlib.h>
#include <string.h>
@@ -26,10 +29,12 @@
#include <sys/prctl.h>
#include <sys/stat.h>
#include <sys/types.h>
+#include <syslog.h>
#include <unistd.h>
#include <cutils/properties.h>
#include <cutils/sched_policy.h>
+#include <cutils/sockets.h>
#include "private/android_filesystem_config.h"
#include "CommandListener.h"
@@ -37,6 +42,12 @@
#include "LogListener.h"
#include "LogAudit.h"
+#define KMSG_PRIORITY(PRI) \
+ '<', \
+ '0' + LOG_MAKEPRI(LOG_DAEMON, LOG_PRI(PRI)) / 10, \
+ '0' + LOG_MAKEPRI(LOG_DAEMON, LOG_PRI(PRI)) % 10, \
+ '>'
+
//
// The service is designed to be run by init, it does not respond well
// to starting up manually. When starting up manually the sockets will
@@ -127,17 +138,107 @@ static bool property_get_bool(const char *key, bool def) {
return def;
}
-// Foreground waits for exit of the three main persistent threads that
-// are started here. The three threads are created to manage UNIX
-// domain client sockets for writing, reading and controlling the user
-// space logger. Additional transitory per-client threads are created
-// for each reader once they register.
-int main() {
- bool auditd = property_get_bool("logd.auditd", true);
+// Remove the static, and use this variable
+// globally for debugging if necessary. eg:
+// write(fdDmesg, "I am here\n", 10);
+static int fdDmesg = -1;
+
+static sem_t reinit;
+static bool reinit_running = false;
+static LogBuffer *logBuf = NULL;
+
+static void *reinit_thread_start(void * /*obj*/) {
+ prctl(PR_SET_NAME, "logd.daemon");
+ set_sched_policy(0, SP_BACKGROUND);
+
+ setgid(AID_LOGD);
+ setuid(AID_LOGD);
+
+ while (reinit_running && !sem_wait(&reinit) && reinit_running) {
+ if (fdDmesg >= 0) {
+ static const char reinit_message[] = { KMSG_PRIORITY(LOG_INFO),
+ 'l', 'o', 'g', 'd', '.', 'd', 'a', 'e', 'm', 'o', 'n', ':',
+ ' ', 'r', 'e', 'i', 'n', 'i', 't', '\n' };
+ write(fdDmesg, reinit_message, sizeof(reinit_message));
+ }
+
+ // Anything that reads persist.<property>
+ if (logBuf) {
+ logBuf->init();
+ }
+ }
+
+ return NULL;
+}
+
+// Serves as a global method to trigger reinitialization
+// and as a function that can be provided to signal().
+void reinit_signal_handler(int /*signal*/) {
+ sem_post(&reinit);
+}
+
+// Foreground waits for exit of the main persistent threads
+// that are started here. The threads are created to manage
+// UNIX domain client sockets for writing, reading and
+// controlling the user space logger, and for any additional
+// logging plugins like auditd and restart control. Additional
+// transitory per-client threads are created for each reader.
+int main(int argc, char *argv[]) {
+ fdDmesg = open("/dev/kmsg", O_WRONLY);
+
+ // issue reinit command. KISS argument parsing.
+ if ((argc > 1) && argv[1] && !strcmp(argv[1], "--reinit")) {
+ int sock = TEMP_FAILURE_RETRY(
+ socket_local_client("logd",
+ ANDROID_SOCKET_NAMESPACE_RESERVED,
+ SOCK_STREAM));
+ if (sock < 0) {
+ return -errno;
+ }
+ static const char reinit[] = "reinit";
+ ssize_t ret = TEMP_FAILURE_RETRY(write(sock, reinit, sizeof(reinit)));
+ if (ret < 0) {
+ return -errno;
+ }
+ struct pollfd p;
+ memset(&p, 0, sizeof(p));
+ p.fd = sock;
+ p.events = POLLIN;
+ ret = TEMP_FAILURE_RETRY(poll(&p, 1, 100));
+ if (ret < 0) {
+ return -errno;
+ }
+ if ((ret == 0) || !(p.revents & POLLIN)) {
+ return -ETIME;
+ }
+ static const char success[] = "success";
+ char buffer[sizeof(success) - 1];
+ memset(buffer, 0, sizeof(buffer));
+ ret = TEMP_FAILURE_RETRY(read(sock, buffer, sizeof(buffer)));
+ if (ret < 0) {
+ return -errno;
+ }
+ return strncmp(buffer, success, sizeof(success) - 1) != 0;
+ }
- int fdDmesg = -1;
- if (auditd && property_get_bool("logd.auditd.dmesg", true)) {
- fdDmesg = open("/dev/kmsg", O_WRONLY);
+ // Reinit Thread
+ sem_init(&reinit, 0, 0);
+ pthread_attr_t attr;
+ if (!pthread_attr_init(&attr)) {
+ struct sched_param param;
+
+ memset(&param, 0, sizeof(param));
+ pthread_attr_setschedparam(&attr, &param);
+ pthread_attr_setschedpolicy(&attr, SCHED_BATCH);
+ if (!pthread_attr_setdetachstate(&attr,
+ PTHREAD_CREATE_DETACHED)) {
+ pthread_t thread;
+ reinit_running = true;
+ if (pthread_create(&thread, &attr, reinit_thread_start, NULL)) {
+ reinit_running = false;
+ }
+ }
+ pthread_attr_destroy(&attr);
}
if (drop_privs() != 0) {
@@ -153,11 +254,10 @@ int main() {
// LogBuffer is the object which is responsible for holding all
// log entries.
- LogBuffer *logBuf = new LogBuffer(times);
+ logBuf = new LogBuffer(times);
+
+ signal(SIGHUP, reinit_signal_handler);
- if (property_get_bool("logd.statistics.dgram_qlen", false)) {
- logBuf->enableDgramQlenStatistics();
- }
{
char property[PROPERTY_VALUE_MAX];
property_get("ro.build.type", property, "");
@@ -198,9 +298,13 @@ int main() {
// initiated log messages. New log entries are added to LogBuffer
// and LogReader is notified to send updates to connected clients.
+ bool auditd = property_get_bool("logd.auditd", true);
+
if (auditd) {
+ bool dmesg = property_get_bool("logd.auditd.dmesg", true);
+
// failure is an option ... messages are in dmesg (required by standard)
- LogAudit *al = new LogAudit(logBuf, reader, fdDmesg);
+ LogAudit *al = new LogAudit(logBuf, reader, dmesg ? fdDmesg : -1);
int len = klogctl(KLOG_SIZE_BUFFER, NULL, 0);
if (len > 0) {
@@ -220,11 +324,10 @@ int main() {
if (al->startListener()) {
delete al;
- close(fdDmesg);
}
}
- pause();
+ TEMP_FAILURE_RETRY(pause());
+
exit(0);
}
-
diff --git a/logd/tests/logd_test.cpp b/logd/tests/logd_test.cpp
index 96877a9..46bd9c0 100644
--- a/logd/tests/logd_test.cpp
+++ b/logd/tests/logd_test.cpp
@@ -192,164 +192,6 @@ TEST(logd, statistics) {
EXPECT_TRUE(NULL != events_logs);
#endif
- // Parse timing stats
-
- cp = strstr(cp, "Minimum time between log events per dgram_qlen:");
-
- if (cp) {
- while (*cp && (*cp != '\n')) {
- ++cp;
- }
- if (*cp == '\n') {
- ++cp;
- }
-
- char *list_of_spans = cp;
- EXPECT_NE('\0', *list_of_spans);
-
- unsigned short number_of_buckets = 0;
- unsigned short *dgram_qlen = NULL;
- unsigned short bucket = 0;
- while (*cp && (*cp != '\n')) {
- bucket = 0;
- while (isdigit(*cp)) {
- bucket = bucket * 10 + *cp - '0';
- ++cp;
- }
- while (*cp == ' ') {
- ++cp;
- }
- if (!bucket) {
- break;
- }
- unsigned short *new_dgram_qlen = new unsigned short[number_of_buckets + 1];
- EXPECT_TRUE(new_dgram_qlen != NULL);
- if (dgram_qlen) {
- memcpy(new_dgram_qlen, dgram_qlen, sizeof(*dgram_qlen) * number_of_buckets);
- delete [] dgram_qlen;
- }
-
- dgram_qlen = new_dgram_qlen;
- dgram_qlen[number_of_buckets++] = bucket;
- }
-
- char *end_of_spans = cp;
- EXPECT_NE('\0', *end_of_spans);
-
- EXPECT_LT(5, number_of_buckets);
-
- unsigned long long *times = new unsigned long long [number_of_buckets];
- ASSERT_TRUE(times != NULL);
-
- memset(times, 0, sizeof(*times) * number_of_buckets);
-
- while (*cp == '\n') {
- ++cp;
- }
-
- unsigned short number_of_values = 0;
- unsigned long long value;
- while (*cp && (*cp != '\n')) {
- EXPECT_GE(number_of_buckets, number_of_values);
-
- value = 0;
- while (isdigit(*cp)) {
- value = value * 10ULL + *cp - '0';
- ++cp;
- }
-
- switch(*cp) {
- case ' ':
- case '\n':
- value *= 1000ULL;
- /* FALLTHRU */
- case 'm':
- value *= 1000ULL;
- /* FALLTHRU */
- case 'u':
- value *= 1000ULL;
- /* FALLTHRU */
- case 'n':
- default:
- break;
- }
- while (*++cp == ' ');
-
- if (!value) {
- break;
- }
-
- times[number_of_values] = value;
- ++number_of_values;
- }
-
-#ifdef TARGET_USES_LOGD
- EXPECT_EQ(number_of_values, number_of_buckets);
-#endif
-
- FILE *fp;
- ASSERT_TRUE(NULL != (fp = fopen("/proc/sys/net/unix/max_dgram_qlen", "r")));
-
- unsigned max_dgram_qlen = 0;
- fscanf(fp, "%u", &max_dgram_qlen);
-
- fclose(fp);
-
- // Find launch point
- unsigned short launch = 0;
- unsigned long long total = 0;
- do {
- total += times[launch];
- } while (((++launch < number_of_buckets)
- && ((total / launch) >= (times[launch] / 8ULL)))
- || (launch == 1)); // too soon
-
- bool failure = number_of_buckets <= launch;
- if (!failure) {
- unsigned short l = launch;
- if (l >= number_of_buckets) {
- l = number_of_buckets - 1;
- }
- failure = max_dgram_qlen < dgram_qlen[l];
- }
-
- // We can get failure if at any time liblog_benchmarks has been run
- // because designed to overload /proc/sys/net/unix/max_dgram_qlen even
- // at excessive values like 20000. It does so to measure the raw processing
- // performance of logd.
- if (failure) {
- cp = find_benchmark_spam(cp);
- }
-
- if (cp) {
- // Fake a failure, but without the failure code
- if (number_of_buckets <= launch) {
- printf ("Expected: number_of_buckets > launch, actual: %u vs %u\n",
- number_of_buckets, launch);
- }
- if (launch >= number_of_buckets) {
- launch = number_of_buckets - 1;
- }
- if (max_dgram_qlen < dgram_qlen[launch]) {
- printf ("Expected: max_dgram_qlen >= dgram_qlen[%d],"
- " actual: %u vs %u\n",
- launch, max_dgram_qlen, dgram_qlen[launch]);
- }
- } else
-#ifndef TARGET_USES_LOGD
- if (total)
-#endif
- {
- EXPECT_GT(number_of_buckets, launch);
- if (launch >= number_of_buckets) {
- launch = number_of_buckets - 1;
- }
- EXPECT_GE(max_dgram_qlen, dgram_qlen[launch]);
- }
-
- delete [] dgram_qlen;
- delete [] times;
- }
delete [] buf;
}
generated by cgit v1.1 at 2025-08-15 04:57:24 +0000