logd: wakeup on wrap or timeout
If a timeout is specified for the reader, then go to sleep
with the socket open. If the start time is about to get
pruned in the specified log buffers, then wakeup and dump
the logs; or wakeup on timeout, whichever comes first.
Bug: 25929746
Change-Id: I7d2421c2c5083b33747b84f74d9a560d3ba645df
diff --git a/logd/FlushCommand.cpp b/logd/FlushCommand.cpp
index 823a842..bf650cd 100644
--- a/logd/FlushCommand.cpp
+++ b/logd/FlushCommand.cpp
@@ -27,13 +27,15 @@
unsigned long tail,
unsigned int logMask,
pid_t pid,
- uint64_t start) :
+ uint64_t start,
+ uint64_t timeout) :
mReader(reader),
mNonBlock(nonBlock),
mTail(tail),
mLogMask(logMask),
mPid(pid),
- mStart(start) {
+ mStart(start),
+ mTimeout(timeout) {
}
// runSocketCommand is called once for every open client on the
@@ -54,6 +56,10 @@
while(it != times.end()) {
entry = (*it);
if (entry->mClient == client) {
+ if (entry->mTimeout.tv_sec || entry->mTimeout.tv_nsec) {
+ LogTimeEntry::unlock();
+ return;
+ }
entry->triggerReader_Locked();
if (entry->runningReader_Locked()) {
LogTimeEntry::unlock();
@@ -71,7 +77,8 @@
LogTimeEntry::unlock();
return;
}
- entry = new LogTimeEntry(mReader, client, mNonBlock, mTail, mLogMask, mPid, mStart);
+ entry = new LogTimeEntry(mReader, client, mNonBlock, mTail, mLogMask,
+ mPid, mStart, mTimeout);
times.push_front(entry);
}
diff --git a/logd/FlushCommand.h b/logd/FlushCommand.h
index 61c6858..e0f2212 100644
--- a/logd/FlushCommand.h
+++ b/logd/FlushCommand.h
@@ -32,6 +32,7 @@
unsigned int mLogMask;
pid_t mPid;
uint64_t mStart;
+ uint64_t mTimeout;
public:
FlushCommand(LogReader &mReader,
@@ -39,7 +40,8 @@
unsigned long tail = -1,
unsigned int logMask = -1,
pid_t pid = 0,
- uint64_t start = 1);
+ uint64_t start = 1,
+ uint64_t timeout = 0);
virtual void runSocketCommand(SocketClient *client);
static bool hasReadLogs(SocketClient *client);
diff --git a/logd/LogBuffer.cpp b/logd/LogBuffer.cpp
index c8127c3..6770bb7 100644
--- a/logd/LogBuffer.cpp
+++ b/logd/LogBuffer.cpp
@@ -129,41 +129,57 @@
}
bool lastMonotonic = monotonic;
monotonic = android_log_clockid() == CLOCK_MONOTONIC;
- if (lastMonotonic == monotonic) {
- return;
+ if (lastMonotonic != monotonic) {
+ //
+ // Fixup all timestamps, may not be 100% accurate, but better than
+ // throwing what we have away when we get 'surprised' by a change.
+ // In-place element fixup so no need to check reader-lock. Entries
+ // should already be in timestamp order, but we could end up with a
+ // few out-of-order entries if new monotonics come in before we
+ // are notified of the reinit change in status. A Typical example would
+ // be:
+ // --------- beginning of system
+ // 10.494082 184 201 D Cryptfs : Just triggered post_fs_data
+ // --------- beginning of kernel
+ // 0.000000 0 0 I : Initializing cgroup subsys
+ // as the act of mounting /data would trigger persist.logd.timestamp to
+ // be corrected. 1/30 corner case YMMV.
+ //
+ pthread_mutex_lock(&mLogElementsLock);
+ LogBufferElementCollection::iterator it = mLogElements.begin();
+ while((it != mLogElements.end())) {
+ LogBufferElement *e = *it;
+ if (monotonic) {
+ if (!android::isMonotonic(e->mRealTime)) {
+ LogKlog::convertRealToMonotonic(e->mRealTime);
+ }
+ } else {
+ if (android::isMonotonic(e->mRealTime)) {
+ LogKlog::convertMonotonicToReal(e->mRealTime);
+ }
+ }
+ ++it;
+ }
+ pthread_mutex_unlock(&mLogElementsLock);
}
+ // We may have been triggered by a SIGHUP. Release any sleeping reader
+ // threads to dump their current content.
//
- // Fixup all timestamps, may not be 100% accurate, but better than
- // throwing what we have away when we get 'surprised' by a change.
- // In-place element fixup so no need to check reader-lock. Entries
- // should already be in timestamp order, but we could end up with a
- // few out-of-order entries if new monotonics come in before we
- // are notified of the reinit change in status. A Typical example would
- // be:
- // --------- beginning of system
- // 10.494082 184 201 D Cryptfs : Just triggered post_fs_data
- // --------- beginning of kernel
- // 0.000000 0 0 I : Initializing cgroup subsys cpuacct
- // as the act of mounting /data would trigger persist.logd.timestamp to
- // be corrected. 1/30 corner case YMMV.
- //
- pthread_mutex_lock(&mLogElementsLock);
- LogBufferElementCollection::iterator it = mLogElements.begin();
- while((it != mLogElements.end())) {
- LogBufferElement *e = *it;
- if (monotonic) {
- if (!android::isMonotonic(e->mRealTime)) {
- LogKlog::convertRealToMonotonic(e->mRealTime);
- }
- } else {
- if (android::isMonotonic(e->mRealTime)) {
- LogKlog::convertMonotonicToReal(e->mRealTime);
- }
+ // NB: this is _not_ performed in the context of a SIGHUP, it is
+ // performed during startup, and in context of reinit administrative thread
+ LogTimeEntry::lock();
+
+ LastLogTimes::iterator times = mTimes.begin();
+ while(times != mTimes.end()) {
+ LogTimeEntry *entry = (*times);
+ if (entry->owned_Locked()) {
+ entry->triggerReader_Locked();
}
- ++it;
+ times++;
}
- pthread_mutex_unlock(&mLogElementsLock);
+
+ LogTimeEntry::unlock();
}
LogBuffer::LogBuffer(LastLogTimes *times):
@@ -429,7 +445,10 @@
while(t != mTimes.end()) {
LogTimeEntry *entry = (*t);
if (entry->owned_Locked() && entry->isWatching(id)
- && (!oldest || (oldest->mStart > entry->mStart))) {
+ && (!oldest ||
+ (oldest->mStart > entry->mStart) ||
+ ((oldest->mStart == entry->mStart) &&
+ (entry->mTimeout.tv_sec || entry->mTimeout.tv_nsec)))) {
oldest = entry;
}
t++;
@@ -448,8 +467,12 @@
}
if (oldest && (oldest->mStart <= e->getSequence())) {
- oldest->triggerSkip_Locked(id, pruneRows);
busy = true;
+ if (oldest->mTimeout.tv_sec || oldest->mTimeout.tv_nsec) {
+ oldest->triggerReader_Locked();
+ } else {
+ oldest->triggerSkip_Locked(id, pruneRows);
+ }
break;
}
@@ -523,6 +546,9 @@
if (oldest && (oldest->mStart <= e->getSequence())) {
busy = true;
+ if (oldest->mTimeout.tv_sec || oldest->mTimeout.tv_nsec) {
+ oldest->triggerReader_Locked();
+ }
break;
}
@@ -648,6 +674,8 @@
if (stats.sizes(id) > (2 * log_buffer_size(id))) {
// kick a misbehaving log reader client off the island
oldest->release_Locked();
+ } else if (oldest->mTimeout.tv_sec || oldest->mTimeout.tv_nsec) {
+ oldest->triggerReader_Locked();
} else {
oldest->triggerSkip_Locked(id, pruneRows);
}
@@ -680,6 +708,8 @@
if (stats.sizes(id) > (2 * log_buffer_size(id))) {
// kick a misbehaving log reader client off the island
oldest->release_Locked();
+ } else if (oldest->mTimeout.tv_sec || oldest->mTimeout.tv_nsec) {
+ oldest->triggerReader_Locked();
} else {
oldest->triggerSkip_Locked(id, pruneRows);
}
diff --git a/logd/LogReader.cpp b/logd/LogReader.cpp
index 06135dd..c2d65b6 100644
--- a/logd/LogReader.cpp
+++ b/logd/LogReader.cpp
@@ -67,6 +67,14 @@
start.strptime(cp + sizeof(_start) - 1, "%s.%q");
}
+ uint64_t timeout = 0;
+ static const char _timeout[] = " timeout=";
+ cp = strstr(buffer, _timeout);
+ if (cp) {
+ timeout = atol(cp + sizeof(_timeout) - 1) * NS_PER_SEC +
+ log_time(CLOCK_REALTIME).nsec();
+ }
+
unsigned int logMask = -1;
static const char _logIds[] = " lids=";
cp = strstr(buffer, _logIds);
@@ -166,7 +174,7 @@
}
}
- FlushCommand command(*this, nonBlock, tail, logMask, pid, sequence);
+ FlushCommand command(*this, nonBlock, tail, logMask, pid, sequence, timeout);
command.runSocketCommand(cli);
return true;
}
diff --git a/logd/LogTimes.cpp b/logd/LogTimes.cpp
index 229be3c..b4c97a9 100644
--- a/logd/LogTimes.cpp
+++ b/logd/LogTimes.cpp
@@ -14,6 +14,7 @@
* limitations under the License.
*/
+#include <errno.h>
#include <sys/prctl.h>
#include "FlushCommand.h"
@@ -26,7 +27,7 @@
LogTimeEntry::LogTimeEntry(LogReader &reader, SocketClient *client,
bool nonBlock, unsigned long tail,
unsigned int logMask, pid_t pid,
- uint64_t start) :
+ uint64_t start, uint64_t timeout) :
mRefCount(1),
mRelease(false),
mError(false),
@@ -42,6 +43,8 @@
mStart(start),
mNonBlock(nonBlock),
mEnd(LogBufferElement::getCurrentSequence()) {
+ mTimeout.tv_sec = timeout / NS_PER_SEC;
+ mTimeout.tv_nsec = timeout % NS_PER_SEC;
pthread_cond_init(&threadTriggeredCondition, NULL);
cleanSkip_Locked();
}
@@ -131,6 +134,19 @@
uint64_t start = me->mStart;
while (me->threadRunning && !me->isError_Locked()) {
+
+ if (me->mTimeout.tv_sec || me->mTimeout.tv_nsec) {
+ if (pthread_cond_timedwait(&me->threadTriggeredCondition,
+ ×Lock,
+ &me->mTimeout) == ETIMEDOUT) {
+ me->mTimeout.tv_sec = 0;
+ me->mTimeout.tv_nsec = 0;
+ }
+ if (!me->threadRunning || me->isError_Locked()) {
+ break;
+ }
+ }
+
unlock();
if (me->mTail) {
@@ -154,7 +170,9 @@
me->cleanSkip_Locked();
- pthread_cond_wait(&me->threadTriggeredCondition, ×Lock);
+ if (!me->mTimeout.tv_sec && !me->mTimeout.tv_nsec) {
+ pthread_cond_wait(&me->threadTriggeredCondition, ×Lock);
+ }
}
unlock();
diff --git a/logd/LogTimes.h b/logd/LogTimes.h
index 39bcdd4..1117088 100644
--- a/logd/LogTimes.h
+++ b/logd/LogTimes.h
@@ -50,10 +50,11 @@
public:
LogTimeEntry(LogReader &reader, SocketClient *client, bool nonBlock,
unsigned long tail, unsigned int logMask, pid_t pid,
- uint64_t start);
+ uint64_t start, uint64_t timeout);
SocketClient *mClient;
uint64_t mStart;
+ struct timespec mTimeout;
const bool mNonBlock;
const uint64_t mEnd; // only relevant if mNonBlock