platform_system_core/logd/LogTimes.cpp
TraianX Schiau da6495d06f logd: Fix pruning
In a scenario in which an on-line (blocking) client is running and
a clean is attempted (logcat -c), the following can be observed:

1) the on-line logger seems to freeze
2) any other clear attempt will have no effect

What is actually happening:

In this case prune function will "instruct" the oldest timeEntry
to skip a huge number (very close to ULONG_MAX) of messages, this
being the cause of 1.

Since the consumer thread will skip all the log entries, mStart
updating will also be skipped. So a new cleaning attempt will have
the same oldest entry, nothing will be done.

Fix description:
a. keep a separated skipAhead count for individual log buffers (log_id_t)
      LogTimeEntry::LogTimeEntry
      LogTimeEntry::FilterSecondPass
      LogTimeEntry::skipAhead
      LogTimeEntry::riggerSkip_Locked

b. update LogTimeEntry::mStart even if the current message is skipped
      LogTimeEntry::FilterSecondPass

c. while pruning, only take into account the LogTimeEntrys that are monitoring
   the log_id in question, and provide a public method of checking this.
      LogTimeEntry::isWatching
      LogTimeEntry::FilterFirstPass
      LogTimeEntry::FilterSecondPass

d. Reset the skip cont befor the client thtread starts to sleep, at this point
   we should be up to date.
      LogTimeEntry::cleanSkip_Locked
      LogTimeEntry::threadStart

Change-Id: I1b369dc5b02476e633e52578266a644e37e188a5
Signed-off-by: TraianX Schiau <traianx.schiau@intel.com>
2015-01-14 19:12:47 +00:00

243 lines
5.7 KiB
C++

/*
* Copyright (C) 2014 The Android Open Source Project
*
* Licensed under the Apache License, Version 2.0 (the "License");
* you may not use this file except in compliance with the License.
* You may obtain a copy of the License at
*
* http://www.apache.org/licenses/LICENSE-2.0
*
* Unless required by applicable law or agreed to in writing, software
* distributed under the License is distributed on an "AS IS" BASIS,
* WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
* See the License for the specific language governing permissions and
* limitations under the License.
*/
#include <sys/prctl.h>
#include "FlushCommand.h"
#include "LogBuffer.h"
#include "LogTimes.h"
#include "LogReader.h"
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)
: mRefCount(1)
, mRelease(false)
, mError(false)
, threadRunning(false)
, mReader(reader)
, mLogMask(logMask)
, mPid(pid)
, mCount(0)
, mTail(tail)
, mIndex(0)
, mClient(client)
, mStart(start)
, mNonBlock(nonBlock)
, mEnd(CLOCK_MONOTONIC)
{
pthread_cond_init(&threadTriggeredCondition, NULL);
cleanSkip_Locked();
}
void LogTimeEntry::startReader_Locked(void) {
pthread_attr_t attr;
threadRunning = true;
if (!pthread_attr_init(&attr)) {
if (!pthread_attr_setdetachstate(&attr, PTHREAD_CREATE_DETACHED)) {
if (!pthread_create(&mThread, &attr,
LogTimeEntry::threadStart, this)) {
pthread_attr_destroy(&attr);
return;
}
}
pthread_attr_destroy(&attr);
}
threadRunning = false;
if (mClient) {
mClient->decRef();
}
decRef_Locked();
}
void LogTimeEntry::threadStop(void *obj) {
LogTimeEntry *me = reinterpret_cast<LogTimeEntry *>(obj);
lock();
if (me->mNonBlock) {
me->error_Locked();
}
SocketClient *client = me->mClient;
if (me->isError_Locked()) {
LogReader &reader = me->mReader;
LastLogTimes &times = reader.logbuf().mTimes;
LastLogTimes::iterator it = times.begin();
while(it != times.end()) {
if (*it == me) {
times.erase(it);
me->release_Locked();
break;
}
it++;
}
me->mClient = NULL;
reader.release(client);
}
if (client) {
client->decRef();
}
me->threadRunning = false;
me->decRef_Locked();
unlock();
}
void *LogTimeEntry::threadStart(void *obj) {
prctl(PR_SET_NAME, "logd.reader.per");
LogTimeEntry *me = reinterpret_cast<LogTimeEntry *>(obj);
pthread_cleanup_push(threadStop, obj);
SocketClient *client = me->mClient;
if (!client) {
me->error();
return NULL;
}
LogBuffer &logbuf = me->mReader.logbuf();
bool privileged = FlushCommand::hasReadLogs(client);
lock();
while (me->threadRunning && !me->isError_Locked()) {
log_time start = me->mStart;
unlock();
if (me->mTail) {
logbuf.flushTo(client, start, privileged, FilterFirstPass, me);
}
start = logbuf.flushTo(client, start, privileged, FilterSecondPass, me);
lock();
if (start == LogBufferElement::FLUSH_ERROR) {
me->error_Locked();
}
if (me->mNonBlock || !me->threadRunning || me->isError_Locked()) {
break;
}
me->cleanSkip_Locked();
pthread_cond_wait(&me->threadTriggeredCondition, &timesLock);
}
unlock();
pthread_cleanup_pop(true);
return NULL;
}
// A first pass to count the number of elements
bool LogTimeEntry::FilterFirstPass(const LogBufferElement *element, void *obj) {
LogTimeEntry *me = reinterpret_cast<LogTimeEntry *>(obj);
LogTimeEntry::lock();
if (me->mCount == 0) {
me->mStart = element->getMonotonicTime();
}
if ((!me->mPid || (me->mPid == element->getPid()))
&& (me->isWatching(element->getLogId()))) {
++me->mCount;
}
LogTimeEntry::unlock();
return false;
}
// A second pass to send the selected elements
bool LogTimeEntry::FilterSecondPass(const LogBufferElement *element, void *obj) {
LogTimeEntry *me = reinterpret_cast<LogTimeEntry *>(obj);
LogTimeEntry::lock();
me->mStart = element->getMonotonicTime();
if (me->skipAhead[element->getLogId()]) {
me->skipAhead[element->getLogId()]--;
goto skip;
}
// Truncate to close race between first and second pass
if (me->mNonBlock && me->mTail && (me->mIndex >= me->mCount)) {
goto skip;
}
if (!me->isWatching(element->getLogId())) {
goto skip;
}
if (me->mPid && (me->mPid != element->getPid())) {
goto skip;
}
if (me->isError_Locked()) {
goto skip;
}
if (!me->mTail) {
goto ok;
}
++me->mIndex;
if ((me->mCount > me->mTail) && (me->mIndex <= (me->mCount - me->mTail))) {
goto skip;
}
if (!me->mNonBlock) {
me->mTail = 0;
}
ok:
if (!me->skipAhead[element->getLogId()]) {
LogTimeEntry::unlock();
return true;
}
// FALLTHRU
skip:
LogTimeEntry::unlock();
return false;
}
void LogTimeEntry::cleanSkip_Locked(void) {
for (log_id_t i = LOG_ID_MIN; i < LOG_ID_MAX; i = (log_id_t) (i + 1)) {
skipAhead[i] = 0;
}
}