diff --git a/logd/LogBuffer.cpp b/logd/LogBuffer.cpp index cc65d4758..820ff64d1 100644 --- a/logd/LogBuffer.cpp +++ b/logd/LogBuffer.cpp @@ -1100,6 +1100,10 @@ uint64_t LogBuffer::flushTo( } } + // Help detect if the valid message before is from the same source so + // we can differentiate chatty filter types. + pid_t lastTid[LOG_ID_MAX] = { 0 }; + for (; it != mLogElements.end(); ++it) { LogBufferElement *element = *it; @@ -1126,10 +1130,19 @@ uint64_t LogBuffer::flushTo( } } + bool sameTid = lastTid[element->getLogId()] == element->getTid(); + // Dropped (chatty) immediately following a valid log from the + // same source in the same log buffer indicates we have a + // multiple identical squash. chatty that differs source + // is due to spam filter. chatty to chatty of different + // source is also due to spam filter. + lastTid[element->getLogId()] = (element->getDropped() && !sameTid) ? + 0 : element->getTid(); + pthread_mutex_unlock(&mLogElementsLock); // range locking in LastLogTimes looks after us - max = element->flushTo(reader, this, privileged); + max = element->flushTo(reader, this, privileged, sameTid); if (max == element->FLUSH_ERROR) { return max; diff --git a/logd/LogBufferElement.cpp b/logd/LogBufferElement.cpp index 5e37a30e8..a651fd4be 100644 --- a/logd/LogBufferElement.cpp +++ b/logd/LogBufferElement.cpp @@ -113,8 +113,8 @@ char *android::tidToName(pid_t tid) { } // assumption: mMsg == NULL -size_t LogBufferElement::populateDroppedMessage(char *&buffer, - LogBuffer *parent) { +size_t LogBufferElement::populateDroppedMessage(char*& buffer, + LogBuffer* parent, bool lastSame) { static const char tag[] = "chatty"; if (!__android_log_is_loggable_len(ANDROID_LOG_INFO, @@ -123,7 +123,7 @@ size_t LogBufferElement::populateDroppedMessage(char *&buffer, return 0; } - static const char format_uid[] = "uid=%u%s%s expire %u line%s"; + static const char format_uid[] = "uid=%u%s%s %s %u line%s"; parent->lock(); const char *name = parent->uidToName(mUid); parent->unlock(); @@ -165,8 +165,9 @@ size_t LogBufferElement::populateDroppedMessage(char *&buffer, } } // identical to below to calculate the buffer size required + const char* type = lastSame ? "identical" : "expire"; size_t len = snprintf(NULL, 0, format_uid, mUid, name ? name : "", - commName ? commName : "", + commName ? commName : "", type, mDropped, (mDropped > 1) ? "s" : ""); size_t hdrLen; @@ -198,7 +199,7 @@ size_t LogBufferElement::populateDroppedMessage(char *&buffer, } snprintf(buffer + hdrLen, len + 1, format_uid, mUid, name ? name : "", - commName ? commName : "", + commName ? commName : "", type, mDropped, (mDropped > 1) ? "s" : ""); free(const_cast(name)); free(const_cast(commName)); @@ -206,8 +207,8 @@ size_t LogBufferElement::populateDroppedMessage(char *&buffer, return retval; } -uint64_t LogBufferElement::flushTo(SocketClient *reader, LogBuffer *parent, - bool privileged) { +uint64_t LogBufferElement::flushTo(SocketClient* reader, LogBuffer* parent, + bool privileged, bool lastSame) { struct logger_entry_v4 entry; memset(&entry, 0, sizeof(struct logger_entry_v4)); @@ -229,7 +230,7 @@ uint64_t LogBufferElement::flushTo(SocketClient *reader, LogBuffer *parent, char *buffer = NULL; if (!mMsg) { - entry.len = populateDroppedMessage(buffer, parent); + entry.len = populateDroppedMessage(buffer, parent, lastSame); if (!entry.len) { return mSequence; } diff --git a/logd/LogBufferElement.h b/logd/LogBufferElement.h index f8ffacd7e..bd98b9c4b 100644 --- a/logd/LogBufferElement.h +++ b/logd/LogBufferElement.h @@ -53,8 +53,9 @@ class LogBufferElement { static atomic_int_fast64_t sequence; // assumption: mMsg == NULL - size_t populateDroppedMessage(char *&buffer, - LogBuffer *parent); + size_t populateDroppedMessage(char*& buffer, + LogBuffer* parent, + bool lastSame); public: LogBufferElement(log_id_t log_id, log_time realtime, uid_t uid, pid_t pid, pid_t tid, @@ -86,7 +87,8 @@ public: log_time getRealTime(void) const { return mRealTime; } static const uint64_t FLUSH_ERROR; - uint64_t flushTo(SocketClient *writer, LogBuffer *parent, bool privileged); + uint64_t flushTo(SocketClient* writer, LogBuffer* parent, + bool privileged, bool lastSame); }; #endif diff --git a/logd/tests/logd_test.cpp b/logd/tests/logd_test.cpp index 13a792286..2a6cdc8f5 100644 --- a/logd/tests/logd_test.cpp +++ b/logd/tests/logd_test.cpp @@ -853,11 +853,13 @@ void __android_log_btwrite_multiple__helper(int count) { int expected_count = (count < 2) ? count : 2; int expected_chatty_count = (count <= 2) ? 0 : 1; - int expected_expire_count = (count < 2) ? 0 : (count - 2); + int expected_identical_count = (count < 2) ? 0 : (count - 2); + static const int expected_expire_count = 0; count = 0; int second_count = 0; int chatty_count = 0; + int identical_count = 0; int expire_count = 0; for (;;) { @@ -887,11 +889,16 @@ void __android_log_btwrite_multiple__helper(int count) { ++chatty_count; // int len = get4LE(eventData + 4 + 1); log_msg.buf[LOGGER_ENTRY_MAX_LEN] = '\0'; - const char *cp = strstr(eventData + 4 + 1 + 4, " expire "); - if (!cp) continue; - unsigned val = 0; - sscanf(cp, " expire %u lines", &val); - expire_count += val; + const char *cp; + if ((cp = strstr(eventData + 4 + 1 + 4, " identical "))) { + unsigned val = 0; + sscanf(cp, " identical %u lines", &val); + identical_count += val; + } else if ((cp = strstr(eventData + 4 + 1 + 4, " expire "))) { + unsigned val = 0; + sscanf(cp, " expire %u lines", &val); + expire_count += val; + } } } @@ -900,6 +907,7 @@ void __android_log_btwrite_multiple__helper(int count) { EXPECT_EQ(expected_count, count); EXPECT_EQ(1, second_count); EXPECT_EQ(expected_chatty_count, chatty_count); + EXPECT_EQ(expected_identical_count, identical_count); EXPECT_EQ(expected_expire_count, expire_count); }