Merge changes Icc984f40,Ie4c46bc9,I0f238985,I63a729d2,I2b5900a2
* changes:
logd: clearAll by UID speedup
logd: clear return and deal with busy if readers locked
logd: update region lock after entry has passed to reader socket
logcat: do not exit buffer loop on error
logd: clientHasLogCredentials false negatives
diff --git a/logcat/logcat.cpp b/logcat/logcat.cpp
index 54cbc20..ddbfb3e 100644
--- a/logcat/logcat.cpp
+++ b/logcat/logcat.cpp
@@ -832,49 +832,66 @@
} else {
logger_list = android_logger_list_alloc(mode, tail_lines, 0);
}
+ const char *openDeviceFail = NULL;
+ const char *clearFail = NULL;
+ const char *setSizeFail = NULL;
+ const char *getSizeFail = NULL;
+ // We have three orthogonal actions below to clear, set log size and
+ // get log size. All sharing the same iteration loop.
while (dev) {
dev->logger_list = logger_list;
dev->logger = android_logger_open(logger_list,
android_name_to_log_id(dev->device));
if (!dev->logger) {
- logcat_panic(false, "Unable to open log device '%s'\n",
- dev->device);
+ openDeviceFail = openDeviceFail ?: dev->device;
+ dev = dev->next;
+ continue;
}
if (clearLog) {
- int ret;
- ret = android_logger_clear(dev->logger);
- if (ret) {
- logcat_panic(false, "failed to clear the log");
+ if (android_logger_clear(dev->logger)) {
+ clearFail = clearFail ?: dev->device;
}
}
- if (setLogSize && android_logger_set_log_size(dev->logger, setLogSize)) {
- logcat_panic(false, "failed to set the log size");
+ if (setLogSize) {
+ if (android_logger_set_log_size(dev->logger, setLogSize)) {
+ setSizeFail = setSizeFail ?: dev->device;
+ }
}
if (getLogSize) {
- long size, readable;
+ long size = android_logger_get_log_size(dev->logger);
+ long readable = android_logger_get_log_readable_size(dev->logger);
- size = android_logger_get_log_size(dev->logger);
- if (size < 0) {
- logcat_panic(false, "failed to get the log size");
+ if ((size < 0) || (readable < 0)) {
+ getSizeFail = getSizeFail ?: dev->device;
+ } else {
+ printf("%s: ring buffer is %ld%sb (%ld%sb consumed), "
+ "max entry is %db, max payload is %db\n", dev->device,
+ value_of_size(size), multiplier_of_size(size),
+ value_of_size(readable), multiplier_of_size(readable),
+ (int) LOGGER_ENTRY_MAX_LEN,
+ (int) LOGGER_ENTRY_MAX_PAYLOAD);
}
-
- readable = android_logger_get_log_readable_size(dev->logger);
- if (readable < 0) {
- logcat_panic(false, "failed to get the readable log size");
- }
-
- printf("%s: ring buffer is %ld%sb (%ld%sb consumed), "
- "max entry is %db, max payload is %db\n", dev->device,
- value_of_size(size), multiplier_of_size(size),
- value_of_size(readable), multiplier_of_size(readable),
- (int) LOGGER_ENTRY_MAX_LEN, (int) LOGGER_ENTRY_MAX_PAYLOAD);
}
dev = dev->next;
}
+ // report any errors in the above loop and exit
+ if (openDeviceFail) {
+ logcat_panic(false, "Unable to open log device '%s'\n", openDeviceFail);
+ }
+ if (clearFail) {
+ logcat_panic(false, "failed to clear the '%s' log\n", clearFail);
+ }
+ if (setSizeFail) {
+ logcat_panic(false, "failed to set the '%s' log size\n", setSizeFail);
+ }
+ if (getSizeFail) {
+ logcat_panic(false, "failed to get the readable '%s' log size",
+ getSizeFail);
+ }
if (setPruneList) {
size_t len = strlen(setPruneList);
diff --git a/logd/CommandListener.cpp b/logd/CommandListener.cpp
index 031c740..eafa28f 100644
--- a/logd/CommandListener.cpp
+++ b/logd/CommandListener.cpp
@@ -96,8 +96,7 @@
return 0;
}
- mBuf.clear((log_id_t) id, uid);
- cli->sendMsg("success");
+ cli->sendMsg(mBuf.clear((log_id_t) id, uid) ? "busy" : "success");
return 0;
}
diff --git a/logd/LogBuffer.cpp b/logd/LogBuffer.cpp
index c2f846e..5cfc02f 100644
--- a/logd/LogBuffer.cpp
+++ b/logd/LogBuffer.cpp
@@ -374,8 +374,10 @@
//
// mLogElementsLock must be held when this function is called.
//
-void LogBuffer::prune(log_id_t id, unsigned long pruneRows, uid_t caller_uid) {
+bool LogBuffer::prune(log_id_t id, unsigned long pruneRows, uid_t caller_uid) {
LogTimeEntry *oldest = NULL;
+ bool busy = false;
+ bool clearAll = pruneRows == ULONG_MAX;
LogTimeEntry::lock();
@@ -393,35 +395,31 @@
LogBufferElementCollection::iterator it;
if (caller_uid != AID_ROOT) {
+ // Only here if clearAll condition (pruneRows == ULONG_MAX)
for(it = mLogElements.begin(); it != mLogElements.end();) {
LogBufferElement *e = *it;
- if (oldest && (oldest->mStart <= e->getSequence())) {
- break;
- }
-
- if (e->getLogId() != id) {
+ if ((e->getLogId() != id) || (e->getUid() != caller_uid)) {
++it;
continue;
}
- if (e->getUid() == caller_uid) {
- it = erase(it);
- pruneRows--;
- if (pruneRows == 0) {
- break;
- }
- } else {
- ++it;
+ if (oldest && (oldest->mStart <= e->getSequence())) {
+ oldest->triggerSkip_Locked(id, pruneRows);
+ busy = true;
+ break;
}
+
+ it = erase(it);
+ pruneRows--;
}
LogTimeEntry::unlock();
- return;
+ return busy;
}
// prune by worst offender by uid
bool hasBlacklist = mPrune.naughty();
- while (pruneRows > 0) {
+ while (!clearAll && (pruneRows > 0)) {
// recalculate the worst offender on every batched pass
uid_t worst = (uid_t) -1;
size_t worst_sizes = 0;
@@ -478,6 +476,7 @@
LogBufferElement *e = *it;
if (oldest && (oldest->mStart <= e->getSequence())) {
+ busy = true;
break;
}
@@ -585,7 +584,7 @@
}
bool whitelist = false;
- bool hasWhitelist = mPrune.nice();
+ bool hasWhitelist = mPrune.nice() && !clearAll;
it = mLogElements.begin();
while((pruneRows > 0) && (it != mLogElements.end())) {
LogBufferElement *e = *it;
@@ -596,6 +595,8 @@
}
if (oldest && (oldest->mStart <= e->getSequence())) {
+ busy = true;
+
if (whitelist) {
break;
}
@@ -631,6 +632,7 @@
}
if (oldest && (oldest->mStart <= e->getSequence())) {
+ busy = true;
if (stats.sizes(id) > (2 * log_buffer_size(id))) {
// kick a misbehaving log reader client off the island
oldest->release_Locked();
@@ -646,13 +648,50 @@
}
LogTimeEntry::unlock();
+
+ return (pruneRows > 0) && busy;
}
// clear all rows of type "id" from the buffer.
-void LogBuffer::clear(log_id_t id, uid_t uid) {
- pthread_mutex_lock(&mLogElementsLock);
- prune(id, ULONG_MAX, uid);
- pthread_mutex_unlock(&mLogElementsLock);
+bool LogBuffer::clear(log_id_t id, uid_t uid) {
+ bool busy = true;
+ // If it takes more than 4 tries (seconds) to clear, then kill reader(s)
+ for (int retry = 4;;) {
+ if (retry == 1) { // last pass
+ // Check if it is still busy after the sleep, we say prune
+ // one entry, not another clear run, so we are looking for
+ // the quick side effect of the return value to tell us if
+ // we have a _blocked_ reader.
+ pthread_mutex_lock(&mLogElementsLock);
+ busy = prune(id, 1, uid);
+ pthread_mutex_unlock(&mLogElementsLock);
+ // It is still busy, blocked reader(s), lets kill them all!
+ // otherwise, lets be a good citizen and preserve the slow
+ // readers and let the clear run (below) deal with determining
+ // if we are still blocked and return an error code to caller.
+ if (busy) {
+ LogTimeEntry::lock();
+ LastLogTimes::iterator times = mTimes.begin();
+ while (times != mTimes.end()) {
+ LogTimeEntry *entry = (*times);
+ // Killer punch
+ if (entry->owned_Locked() && entry->isWatching(id)) {
+ entry->release_Locked();
+ }
+ times++;
+ }
+ LogTimeEntry::unlock();
+ }
+ }
+ pthread_mutex_lock(&mLogElementsLock);
+ busy = prune(id, ULONG_MAX, uid);
+ pthread_mutex_unlock(&mLogElementsLock);
+ if (!busy || !--retry) {
+ break;
+ }
+ sleep (1); // Let reader(s) catch up after notification
+ }
+ return busy;
}
// get the used space associated with "id".
diff --git a/logd/LogBuffer.h b/logd/LogBuffer.h
index de76693..d8e0b90 100644
--- a/logd/LogBuffer.h
+++ b/logd/LogBuffer.h
@@ -63,7 +63,7 @@
int (*filter)(const LogBufferElement *element, void *arg) = NULL,
void *arg = NULL);
- void clear(log_id_t id, uid_t uid = AID_ROOT);
+ bool clear(log_id_t id, uid_t uid = AID_ROOT);
unsigned long getSize(log_id_t id);
int setSize(log_id_t id, unsigned long size);
unsigned long getSizeUsed(log_id_t id);
@@ -86,7 +86,7 @@
private:
void maybePrune(log_id_t id);
- void prune(log_id_t id, unsigned long pruneRows, uid_t uid = AID_ROOT);
+ bool prune(log_id_t id, unsigned long pruneRows, uid_t uid = AID_ROOT);
LogBufferElementCollection::iterator erase(
LogBufferElementCollection::iterator it, bool engageStats = true);
};
diff --git a/logd/LogCommand.cpp b/logd/LogCommand.cpp
index 06d865c..6d0e92e 100644
--- a/logd/LogCommand.cpp
+++ b/logd/LogCommand.cpp
@@ -42,7 +42,6 @@
static bool groupIsLog(char *buf) {
char *ptr;
static const char ws[] = " \n";
- bool ret = false;
for (buf = strtok_r(buf, ws, &ptr); buf; buf = strtok_r(NULL, ws, &ptr)) {
errno = 0;
@@ -51,10 +50,10 @@
return false;
}
if (Gid == AID_LOG) {
- ret = true;
+ return true;
}
}
- return ret;
+ return false;
}
bool clientHasLogCredentials(SocketClient * cli) {
@@ -69,61 +68,79 @@
}
// FYI We will typically be here for 'adb logcat'
- bool ret = false;
+ char filename[256];
+ snprintf(filename, sizeof(filename), "/proc/%u/status", cli->getPid());
- char filename[1024];
- snprintf(filename, sizeof(filename), "/proc/%d/status", cli->getPid());
-
- FILE *file = fopen(filename, "r");
- if (!file) {
- return ret;
- }
-
+ bool ret;
+ bool foundLog = false;
bool foundGid = false;
bool foundUid = false;
- char line[1024];
- while (fgets(line, sizeof(line), file)) {
- static const char groups_string[] = "Groups:\t";
- static const char uid_string[] = "Uid:\t";
- static const char gid_string[] = "Gid:\t";
-
- if (strncmp(groups_string, line, strlen(groups_string)) == 0) {
- ret = groupIsLog(line + strlen(groups_string));
- if (!ret) {
- break;
- }
- } else if (strncmp(uid_string, line, strlen(uid_string)) == 0) {
- uid_t u[4] = { (uid_t) -1, (uid_t) -1, (uid_t) -1, (uid_t) -1};
-
- sscanf(line + strlen(uid_string), "%u\t%u\t%u\t%u",
- &u[0], &u[1], &u[2], &u[3]);
-
- // Protect against PID reuse by checking that the UID is the same
- if ((uid != u[0]) || (uid != u[1]) || (uid != u[2]) || (uid != u[3])) {
- ret = false;
- break;
- }
- foundUid = true;
- } else if (strncmp(gid_string, line, strlen(gid_string)) == 0) {
- gid_t g[4] = { (gid_t) -1, (gid_t) -1, (gid_t) -1, (gid_t) -1};
-
- sscanf(line + strlen(gid_string), "%u\t%u\t%u\t%u",
- &g[0], &g[1], &g[2], &g[3]);
-
- // Protect against PID reuse by checking that the GID is the same
- if ((gid != g[0]) || (gid != g[1]) || (gid != g[2]) || (gid != g[3])) {
- ret = false;
- break;
- }
- foundGid = true;
+ //
+ // Reading /proc/<pid>/status is rife with race conditions. All of /proc
+ // suffers from this and its use should be minimized. However, we have no
+ // choice.
+ //
+ // Notably the content from one 4KB page to the next 4KB page can be from a
+ // change in shape even if we are gracious enough to attempt to read
+ // atomically. getline can not even guarantee a page read is not split up
+ // and in effect can read from different vintages of the content.
+ //
+ // We are finding out in the field that a 'logcat -c' via adb occasionally
+ // is returned with permission denied when we did only one pass and thus
+ // breaking scripts. For security we still err on denying access if in
+ // doubt, but we expect the falses should be reduced significantly as
+ // three times is a charm.
+ //
+ for (int retry = 3;
+ !(ret = foundGid && foundUid && foundLog) && retry;
+ --retry) {
+ FILE *file = fopen(filename, "r");
+ if (!file) {
+ continue;
}
- }
- fclose(file);
+ char *line = NULL;
+ size_t len = 0;
+ while (getline(&line, &len, file) > 0) {
+ static const char groups_string[] = "Groups:\t";
+ static const char uid_string[] = "Uid:\t";
+ static const char gid_string[] = "Gid:\t";
- if (!foundGid || !foundUid) {
- ret = false;
+ if (strncmp(groups_string, line, sizeof(groups_string) - 1) == 0) {
+ if (groupIsLog(line + sizeof(groups_string) - 1)) {
+ foundLog = true;
+ }
+ } else if (strncmp(uid_string, line, sizeof(uid_string) - 1) == 0) {
+ uid_t u[4] = { (uid_t) -1, (uid_t) -1, (uid_t) -1, (uid_t) -1};
+
+ sscanf(line + sizeof(uid_string) - 1, "%u\t%u\t%u\t%u",
+ &u[0], &u[1], &u[2], &u[3]);
+
+ // Protect against PID reuse by checking that UID is the same
+ if ((uid == u[0])
+ && (uid == u[1])
+ && (uid == u[2])
+ && (uid == u[3])) {
+ foundUid = true;
+ }
+ } else if (strncmp(gid_string, line, sizeof(gid_string) - 1) == 0) {
+ gid_t g[4] = { (gid_t) -1, (gid_t) -1, (gid_t) -1, (gid_t) -1};
+
+ sscanf(line + sizeof(gid_string) - 1, "%u\t%u\t%u\t%u",
+ &g[0], &g[1], &g[2], &g[3]);
+
+ // Protect against PID reuse by checking that GID is the same
+ if ((gid == g[0])
+ && (gid == g[1])
+ && (gid == g[2])
+ && (gid == g[3])) {
+ foundGid = true;
+ }
+ }
+ }
+ free(line);
+ fclose(file);
}
return ret;
diff --git a/logd/LogTimes.cpp b/logd/LogTimes.cpp
index 68a0680..229be3c 100644
--- a/logd/LogTimes.cpp
+++ b/logd/LogTimes.cpp
@@ -128,9 +128,9 @@
lock();
- while (me->threadRunning && !me->isError_Locked()) {
- uint64_t start = me->mStart;
+ uint64_t start = me->mStart;
+ while (me->threadRunning && !me->isError_Locked()) {
unlock();
if (me->mTail) {
@@ -143,8 +143,11 @@
if (start == LogBufferElement::FLUSH_ERROR) {
me->error_Locked();
+ break;
}
+ me->mStart = start + 1;
+
if (me->mNonBlock || !me->threadRunning || me->isError_Locked()) {
break;
}