diff --git a/include/android/log.h b/include/android/log.h index de5502a8f..5f20f8c5a 100644 --- a/include/android/log.h +++ b/include/android/log.h @@ -803,10 +803,12 @@ int android_log_destroy(android_log_context *ctx); */ #if LOG_NDEBUG /* Production */ #define android_testLog(prio, tag) \ - (__android_log_is_loggable(prio, tag, ANDROID_LOG_DEBUG) != 0) + (__android_log_is_loggable_len(prio, tag, (tag && *tag) ? strlen(tag) : 0, \ + ANDROID_LOG_DEBUG) != 0) #else #define android_testLog(prio, tag) \ - (__android_log_is_loggable(prio, tag, ANDROID_LOG_VERBOSE) != 0) + (__android_log_is_loggable_len(prio, tag, (tag && *tag) ? strlen(tag) : 0, \ + ANDROID_LOG_VERBOSE) != 0) #endif /* @@ -816,6 +818,7 @@ int android_log_destroy(android_log_context *ctx); * any other value. */ int __android_log_is_loggable(int prio, const char *tag, int default_prio); +int __android_log_is_loggable_len(int prio, const char *tag, size_t len, int default_prio); int __android_log_security(); /* Device Owner is present */ diff --git a/include/log/event_tag_map.h b/include/log/event_tag_map.h index 7ee0a7ca0..69774bacd 100644 --- a/include/log/event_tag_map.h +++ b/include/log/event_tag_map.h @@ -41,7 +41,14 @@ void android_closeEventTagMap(EventTagMap* map); /* * Look up a tag by index. Returns the tag string, or NULL if not found. */ -const char* android_lookupEventTag(const EventTagMap* map, unsigned int tag); +const char* android_lookupEventTag(const EventTagMap* map, unsigned int tag) + __attribute__((deprecated("use android_lookupEventTag_len() instead to minimize MAP_PRIVATE copy-on-write memory impact"))); + +/* + * Look up a tag by index. Returns the tag string & string length, or NULL if + * not found. Returned string is not guaranteed to be nul terminated. + */ +const char* android_lookupEventTag_len(const EventTagMap* map, size_t* len, unsigned int tag); #ifdef __cplusplus } diff --git a/include/log/logprint.h b/include/log/logprint.h index b8d8d4ccb..f70633d43 100644 --- a/include/log/logprint.h +++ b/include/log/logprint.h @@ -59,6 +59,7 @@ typedef struct AndroidLogEntry_t { int32_t pid; int32_t tid; const char * tag; + size_t tagLen; size_t messageLen; const char * message; } AndroidLogEntry; diff --git a/liblog/event_tag_map.c b/liblog/event_tag_map.c index c2dc74cd4..6705fb285 100644 --- a/liblog/event_tag_map.c +++ b/liblog/event_tag_map.c @@ -34,8 +34,9 @@ * Single entry. */ typedef struct EventTag { - uint32_t tagIndex; - const char* tagStr; + uint32_t tagIndex; + char* tagStr; + size_t tagLen; } EventTag; /* @@ -139,8 +140,9 @@ LIBLOG_ABI_PUBLIC void android_closeEventTagMap(EventTagMap* map) * * The entries are sorted by tag number, so we can do a binary search. */ -LIBLOG_ABI_PUBLIC const char* android_lookupEventTag(const EventTagMap* map, - unsigned int tag) +LIBLOG_ABI_PUBLIC const char* android_lookupEventTag_len(const EventTagMap* map, + size_t *len, + unsigned int tag) { int lo = 0; int hi = map->numTags - 1; @@ -157,14 +159,36 @@ LIBLOG_ABI_PUBLIC const char* android_lookupEventTag(const EventTagMap* map, hi = mid - 1; } else { /* found */ + if (len) *len = map->tagArray[mid].tagLen; + /* + * b/31456426 to check if gTest can detect copy-on-write issue + * add the following line to break us: + * map->tagArray[mid].tagStr[map->tagArray[mid].tagLen] = '\0'; + * or explicitly use deprecated android_lookupEventTag(). + */ return map->tagArray[mid].tagStr; } } errno = ENOENT; + if (len) *len = 0; return NULL; } +LIBLOG_ABI_PUBLIC const char* android_lookupEventTag(const EventTagMap* map, + unsigned int tag) +{ + size_t len; + const char* tagStr = android_lookupEventTag_len(map, &len, tag); + char* cp; + + if (!tagStr) return tagStr; + cp = (char*)tagStr; + cp += len; + if (*cp) *cp = '\0'; /* Trigger copy on write :-( */ + return tagStr; +} + /* * Crunch through the file, parsing the contents and creating a tag index. */ @@ -337,19 +361,13 @@ static int scanTagLine(char** pData, EventTag* tag, int lineNum) /* Determine whether "c" is a valid tag char. */ while (isalnum(*++cp) || (*cp == '_')) { } + tag->tagLen = cp - tag->tagStr; - if (*cp == '\n') { - /* null terminate and return */ - *cp = '\0'; - } else if (isspace(*cp)) { - /* CRLF or trailin spaces; zap this char, then scan for the '\n' */ - *cp = '\0'; - + if (isspace(*cp)) { /* just ignore the rest of the line till \n TODO: read the tag description that follows the tag name */ - while (*++cp != '\n') { - } + while (*cp != '\n') ++cp; } else { fprintf(stderr, "%s: invalid tag chars on line %d\n", OUT_TAG, lineNum); errno = EINVAL; @@ -387,10 +405,12 @@ static int sortTags(EventTagMap* map) for (i = 1; i < map->numTags; i++) { if (map->tagArray[i].tagIndex == map->tagArray[i - 1].tagIndex) { fprintf(stderr, - "%s: duplicate tag entries (%" PRIu32 ":%s and %" PRIu32 ":%s)\n", + "%s: duplicate tag entries (%" PRIu32 ":%.*s and %" PRIu32 ":%.*s)\n", OUT_TAG, - map->tagArray[i].tagIndex, map->tagArray[i].tagStr, - map->tagArray[i - 1].tagIndex, map->tagArray[i - 1].tagStr); + map->tagArray[i].tagIndex, (int)map->tagArray[i].tagLen, + map->tagArray[i].tagStr, + map->tagArray[i - 1].tagIndex, (int)map->tagArray[i - 1].tagLen, + map->tagArray[i - 1].tagStr); errno = EMLINK; return -1; } diff --git a/liblog/fake_log_device.c b/liblog/fake_log_device.c index 1b57e7550..7bd1f83d4 100644 --- a/liblog/fake_log_device.c +++ b/liblog/fake_log_device.c @@ -718,3 +718,12 @@ LIBLOG_ABI_PUBLIC int __android_log_is_loggable(int prio, int logLevel = def; return logLevel >= 0 && prio >= logLevel; } + +LIBLOG_ABI_PUBLIC int __android_log_is_loggable_len(int prio, + const char *tag __unused, + size_t len __unused, + int def) +{ + int logLevel = def; + return logLevel >= 0 && prio >= logLevel; +} diff --git a/liblog/log_is_loggable.c b/liblog/log_is_loggable.c index bd8d5af95..4af8507a2 100644 --- a/liblog/log_is_loggable.c +++ b/liblog/log_is_loggable.c @@ -85,13 +85,13 @@ static void refresh_cache(struct cache *cache, const char *key) } } -static int __android_log_level(const char *tag, int default_prio) +static int __android_log_level(const char *tag, size_t len, int default_prio) { /* sizeof() is used on this array below */ static const char log_namespace[] = "persist.log.tag."; static const size_t base_offset = 8; /* skip "persist." */ /* calculate the size of our key temporary buffer */ - const size_t taglen = (tag && *tag) ? strlen(tag) : 0; + const size_t taglen = tag ? len : 0; /* sizeof(log_namespace) = strlen(log_namespace) + 1 */ char key[sizeof(log_namespace) + taglen]; /* may be > PROPERTY_KEY_MAX */ char *kp; @@ -147,7 +147,11 @@ static int __android_log_level(const char *tag, int default_prio) if (!not_locked) { if (!last_tag[0] || (last_tag[0] != tag[0]) - || strncmp(last_tag + 1, tag + 1, sizeof(last_tag) - 1)) { + || strncmp(last_tag + 1, tag + 1, + (len < sizeof(last_tag)) ? + (len - 1) : + (sizeof(last_tag) - 1)) + || ((len < sizeof(last_tag)) && last_tag[len])) { /* invalidate log.tag. cache */ for (i = 0; i < (sizeof(tag_cache) / sizeof(tag_cache[0])); ++i) { tag_cache[i].pinfo = NULL; @@ -157,10 +161,16 @@ static int __android_log_level(const char *tag, int default_prio) local_change_detected = 1; } if (!last_tag[0]) { - strncpy(last_tag, tag, sizeof(last_tag)); + if (len < sizeof(last_tag)) { + strncpy(last_tag, tag, len); + last_tag[len] = '\0'; + } else { + strncpy(last_tag, tag, sizeof(last_tag)); + } } } - strcpy(key + sizeof(log_namespace) - 1, tag); + strncpy(key + sizeof(log_namespace) - 1, tag, len); + key[sizeof(log_namespace) - 1 + len] = '\0'; kp = key; for (i = 0; i < (sizeof(tag_cache) / sizeof(tag_cache[0])); ++i) { @@ -246,10 +256,21 @@ static int __android_log_level(const char *tag, int default_prio) return default_prio; } -LIBLOG_ABI_PUBLIC int __android_log_is_loggable(int prio, const char *tag, +LIBLOG_ABI_PUBLIC int __android_log_is_loggable_len(int prio, + const char *tag, size_t len, + int default_prio) +{ + int logLevel = __android_log_level(tag, len, default_prio); + return logLevel >= 0 && prio >= logLevel; +} + +LIBLOG_ABI_PUBLIC int __android_log_is_loggable(int prio, + const char *tag, int default_prio) { - int logLevel = __android_log_level(tag, default_prio); + int logLevel = __android_log_level(tag, + (tag && *tag) ? strlen(tag) : 0, + default_prio); return logLevel >= 0 && prio >= logLevel; } diff --git a/liblog/logd_writer.c b/liblog/logd_writer.c index ebf8b3e46..e8e392d24 100644 --- a/liblog/logd_writer.c +++ b/liblog/logd_writer.c @@ -181,9 +181,9 @@ static int logdWrite(log_id_t logId, struct timespec *ts, } } snapshot = atomic_exchange_explicit(&dropped, 0, memory_order_relaxed); - if (snapshot && __android_log_is_loggable(ANDROID_LOG_INFO, - "liblog", - ANDROID_LOG_VERBOSE)) { + if (snapshot && __android_log_is_loggable_len(ANDROID_LOG_INFO, + "liblog", strlen("liblog"), + ANDROID_LOG_VERBOSE)) { android_log_event_int_t buffer; header.id = LOG_ID_EVENTS; diff --git a/liblog/logger_write.c b/liblog/logger_write.c index 4999aef0d..1e56b270b 100644 --- a/liblog/logger_write.c +++ b/liblog/logger_write.c @@ -279,6 +279,7 @@ static int __write_to_log_daemon(log_id_t log_id, struct iovec *vec, size_t nr) } } else if (log_id == LOG_ID_EVENTS) { const char *tag; + size_t len; EventTagMap *m, *f; if (vec[0].iov_len < 4) { @@ -286,6 +287,7 @@ static int __write_to_log_daemon(log_id_t log_id, struct iovec *vec, size_t nr) } tag = NULL; + len = 0; f = NULL; m = (EventTagMap *)atomic_load(&tagMap); @@ -308,11 +310,11 @@ static int __write_to_log_daemon(log_id_t log_id, struct iovec *vec, size_t nr) } } if (m && (m != (EventTagMap *)(uintptr_t)-1LL)) { - tag = android_lookupEventTag(m, get4LE(vec[0].iov_base)); + tag = android_lookupEventTag_len(m, &len, get4LE(vec[0].iov_base)); } - ret = __android_log_is_loggable(ANDROID_LOG_INFO, - tag, - ANDROID_LOG_VERBOSE); + ret = __android_log_is_loggable_len(ANDROID_LOG_INFO, + tag, len, + ANDROID_LOG_VERBOSE); if (f) { /* local copy marked for close */ android_closeEventTagMap(f); } @@ -345,7 +347,9 @@ static int __write_to_log_daemon(log_id_t log_id, struct iovec *vec, size_t nr) tag = NULL; } - if (!__android_log_is_loggable(prio, tag, ANDROID_LOG_VERBOSE)) { + if (!__android_log_is_loggable_len(prio, + tag, len - 1, + ANDROID_LOG_VERBOSE)) { return -EPERM; } } diff --git a/liblog/logprint.c b/liblog/logprint.c index d857090ef..2c4e619e4 100644 --- a/liblog/logprint.c +++ b/liblog/logprint.c @@ -539,6 +539,7 @@ LIBLOG_ABI_PUBLIC int android_log_processLogBuffer( entry->priority = msg[0]; entry->tag = msg + 1; + entry->tagLen = msgStart - 1; entry->message = msg + msgStart; entry->messageLen = (msgEnd < msgStart) ? 0 : (msgEnd - msgStart); @@ -801,8 +802,9 @@ LIBLOG_ABI_PUBLIC int android_log_processBinaryLogBuffer( eventData += 4; inCount -= 4; + entry->tagLen = 0; if (map != NULL) { - entry->tag = android_lookupEventTag(map, tagIndex); + entry->tag = android_lookupEventTag_len(map, &entry->tagLen, tagIndex); } else { entry->tag = NULL; } @@ -813,12 +815,16 @@ LIBLOG_ABI_PUBLIC int android_log_processBinaryLogBuffer( * shift the buffer pointers down. */ if (entry->tag == NULL) { - int tagLen; + size_t tagLen; tagLen = snprintf(messageBuf, messageBufLen, "[%d]", tagIndex); + if (tagLen >= (size_t)messageBufLen) { + tagLen = messageBufLen - 1; + } entry->tag = messageBuf; - messageBuf += tagLen+1; - messageBufLen -= tagLen+1; + entry->tagLen = tagLen; + messageBuf += tagLen + 1; + messageBufLen -= tagLen + 1; } /* @@ -1386,13 +1392,13 @@ LIBLOG_ABI_PUBLIC char *android_log_formatLogLine ( switch (p_format->format) { case FORMAT_TAG: len = snprintf(prefixBuf + prefixLen, sizeof(prefixBuf) - prefixLen, - "%c/%-8s: ", priChar, entry->tag); + "%c/%-8.*s: ", priChar, (int)entry->tagLen, entry->tag); strcpy(suffixBuf + suffixLen, "\n"); ++suffixLen; break; case FORMAT_PROCESS: len = snprintf(suffixBuf + suffixLen, sizeof(suffixBuf) - suffixLen, - " (%s)\n", entry->tag); + " (%.*s)\n", (int)entry->tagLen, entry->tag); suffixLen += MIN(len, sizeof(suffixBuf) - suffixLen); len = snprintf(prefixBuf + prefixLen, sizeof(prefixBuf) - prefixLen, "%c(%s%5d) ", priChar, uid, entry->pid); @@ -1411,8 +1417,8 @@ LIBLOG_ABI_PUBLIC char *android_log_formatLogLine ( break; case FORMAT_TIME: len = snprintf(prefixBuf + prefixLen, sizeof(prefixBuf) - prefixLen, - "%s %c/%-8s(%s%5d): ", timeBuf, priChar, entry->tag, - uid, entry->pid); + "%s %c/%-8.*s(%s%5d): ", timeBuf, priChar, + (int)entry->tagLen, entry->tag, uid, entry->pid); strcpy(suffixBuf + suffixLen, "\n"); ++suffixLen; break; @@ -1422,15 +1428,16 @@ LIBLOG_ABI_PUBLIC char *android_log_formatLogLine ( *ret = ' '; } len = snprintf(prefixBuf + prefixLen, sizeof(prefixBuf) - prefixLen, - "%s %s%5d %5d %c %-8s: ", timeBuf, - uid, entry->pid, entry->tid, priChar, entry->tag); + "%s %s%5d %5d %c %-8.*s: ", timeBuf, uid, entry->pid, + entry->tid, priChar, (int)entry->tagLen, entry->tag); strcpy(suffixBuf + suffixLen, "\n"); ++suffixLen; break; case FORMAT_LONG: len = snprintf(prefixBuf + prefixLen, sizeof(prefixBuf) - prefixLen, - "[ %s %s%5d:%5d %c/%-8s ]\n", - timeBuf, uid, entry->pid, entry->tid, priChar, entry->tag); + "[ %s %s%5d:%5d %c/%-8.*s ]\n", + timeBuf, uid, entry->pid, entry->tid, priChar, + (int)entry->tagLen, entry->tag); strcpy(suffixBuf + suffixLen, "\n\n"); suffixLen += 2; prefixSuffixIsHeaderFooter = 1; @@ -1438,7 +1445,8 @@ LIBLOG_ABI_PUBLIC char *android_log_formatLogLine ( case FORMAT_BRIEF: default: len = snprintf(prefixBuf + prefixLen, sizeof(prefixBuf) - prefixLen, - "%c/%-8s(%s%5d): ", priChar, entry->tag, uid, entry->pid); + "%c/%-8.*s(%s%5d): ", priChar, (int)entry->tagLen, entry->tag, + uid, entry->pid); strcpy(suffixBuf + suffixLen, "\n"); ++suffixLen; break; diff --git a/liblog/tests/Android.mk b/liblog/tests/Android.mk index 8229859a2..a755b980c 100644 --- a/liblog/tests/Android.mk +++ b/liblog/tests/Android.mk @@ -40,7 +40,7 @@ include $(CLEAR_VARS) LOCAL_MODULE := $(test_module_prefix)benchmarks LOCAL_MODULE_TAGS := $(test_tags) LOCAL_CFLAGS += $(benchmark_c_flags) -LOCAL_SHARED_LIBRARIES += liblog libm +LOCAL_SHARED_LIBRARIES += liblog libm libbase LOCAL_SRC_FILES := $(benchmark_src_files) include $(BUILD_NATIVE_TEST) @@ -73,6 +73,6 @@ include $(CLEAR_VARS) LOCAL_MODULE := $(test_module_prefix)unit-tests LOCAL_MODULE_TAGS := $(test_tags) LOCAL_CFLAGS += $(test_c_flags) -LOCAL_SHARED_LIBRARIES := liblog libcutils +LOCAL_SHARED_LIBRARIES := liblog libcutils libbase LOCAL_SRC_FILES := $(test_src_files) include $(BUILD_NATIVE_TEST) diff --git a/liblog/tests/liblog_benchmark.cpp b/liblog/tests/liblog_benchmark.cpp index 7561d8f0d..cd012ce69 100644 --- a/liblog/tests/liblog_benchmark.cpp +++ b/liblog/tests/liblog_benchmark.cpp @@ -650,10 +650,14 @@ BENCHMARK(BM_log_delay); * Measure the time it takes for __android_log_is_loggable. */ static void BM_is_loggable(int iters) { + static const char logd[] = "logd"; + StartBenchmarkTiming(); for (int i = 0; i < iters; ++i) { - __android_log_is_loggable(ANDROID_LOG_WARN, "logd", ANDROID_LOG_VERBOSE); + __android_log_is_loggable_len(ANDROID_LOG_WARN, + logd, strlen(logd), + ANDROID_LOG_VERBOSE); } StopBenchmarkTiming(); diff --git a/liblog/tests/liblog_test.cpp b/liblog/tests/liblog_test.cpp index 6e709a948..b1dae9ebe 100644 --- a/liblog/tests/liblog_test.cpp +++ b/liblog/tests/liblog_test.cpp @@ -14,6 +14,8 @@ * limitations under the License. */ +#include +#include #include #include #include @@ -22,7 +24,11 @@ #include #include +#include + #include +#include +#include #include #include #include @@ -1337,8 +1343,8 @@ TEST(liblog, is_loggable) { continue; } fprintf(stderr, "i=%zu j=%zu\r", i, j); - bool android_log_is_loggable = __android_log_is_loggable( - levels[i].level, tag, levels[j].level); + bool android_log_is_loggable = __android_log_is_loggable_len( + levels[i].level, tag, strlen(tag), levels[j].level); if ((levels[i].level < levels[j].level) || (levels[j].level == -1)) { if (android_log_is_loggable) { @@ -1346,8 +1352,8 @@ TEST(liblog, is_loggable) { } EXPECT_FALSE(android_log_is_loggable); for(size_t k = 10; k; --k) { - EXPECT_FALSE(__android_log_is_loggable( - levels[i].level, tag, levels[j].level)); + EXPECT_FALSE(__android_log_is_loggable_len( + levels[i].level, tag, strlen(tag), levels[j].level)); } } else { if (!android_log_is_loggable) { @@ -1355,8 +1361,8 @@ TEST(liblog, is_loggable) { } EXPECT_TRUE(android_log_is_loggable); for(size_t k = 10; k; --k) { - EXPECT_TRUE(__android_log_is_loggable( - levels[i].level, tag, levels[j].level)); + EXPECT_TRUE(__android_log_is_loggable_len( + levels[i].level, tag, strlen(tag), levels[j].level)); } } } @@ -1377,8 +1383,8 @@ TEST(liblog, is_loggable) { i, j, key, buf); usleep(20000); property_set(key, buf); - bool android_log_is_loggable = __android_log_is_loggable( - levels[i].level, tag, ANDROID_LOG_DEBUG); + bool android_log_is_loggable = __android_log_is_loggable_len( + levels[i].level, tag, strlen(tag), ANDROID_LOG_DEBUG); if ((levels[i].level < levels[j].level) || (levels[j].level == -1) || ((levels[i].level < ANDROID_LOG_DEBUG) @@ -1388,8 +1394,8 @@ TEST(liblog, is_loggable) { } EXPECT_FALSE(android_log_is_loggable); for(size_t k = 10; k; --k) { - EXPECT_FALSE(__android_log_is_loggable( - levels[i].level, tag, ANDROID_LOG_DEBUG)); + EXPECT_FALSE(__android_log_is_loggable_len( + levels[i].level, tag, strlen(tag), ANDROID_LOG_DEBUG)); } } else { if (!android_log_is_loggable) { @@ -1397,8 +1403,8 @@ TEST(liblog, is_loggable) { } EXPECT_TRUE(android_log_is_loggable); for(size_t k = 10; k; --k) { - EXPECT_TRUE(__android_log_is_loggable( - levels[i].level, tag, ANDROID_LOG_DEBUG)); + EXPECT_TRUE(__android_log_is_loggable_len( + levels[i].level, tag, strlen(tag), ANDROID_LOG_DEBUG)); } } usleep(20000); @@ -1407,8 +1413,8 @@ TEST(liblog, is_loggable) { fprintf(stderr, "i=%zu j=%zu property_set(\"%s\",\"%s\")\r", i, j, key + base_offset, buf); property_set(key + base_offset, buf); - android_log_is_loggable = __android_log_is_loggable( - levels[i].level, tag, ANDROID_LOG_DEBUG); + android_log_is_loggable = __android_log_is_loggable_len( + levels[i].level, tag, strlen(tag), ANDROID_LOG_DEBUG); if ((levels[i].level < levels[j].level) || (levels[j].level == -1) || ((levels[i].level < ANDROID_LOG_DEBUG) @@ -1418,8 +1424,8 @@ TEST(liblog, is_loggable) { } EXPECT_FALSE(android_log_is_loggable); for(size_t k = 10; k; --k) { - EXPECT_FALSE(__android_log_is_loggable( - levels[i].level, tag, ANDROID_LOG_DEBUG)); + EXPECT_FALSE(__android_log_is_loggable_len( + levels[i].level, tag, strlen(tag), ANDROID_LOG_DEBUG)); } } else { if (!android_log_is_loggable) { @@ -1427,8 +1433,8 @@ TEST(liblog, is_loggable) { } EXPECT_TRUE(android_log_is_loggable); for(size_t k = 10; k; --k) { - EXPECT_TRUE(__android_log_is_loggable( - levels[i].level, tag, ANDROID_LOG_DEBUG)); + EXPECT_TRUE(__android_log_is_loggable_len( + levels[i].level, tag, strlen(tag), ANDROID_LOG_DEBUG)); } } usleep(20000); @@ -1439,8 +1445,8 @@ TEST(liblog, is_loggable) { fprintf(stderr, "i=%zu j=%zu property_set(\"%s\",\"%s\")\r", i, j, key, buf); property_set(key, buf); - android_log_is_loggable = __android_log_is_loggable( - levels[i].level, tag, ANDROID_LOG_DEBUG); + android_log_is_loggable = __android_log_is_loggable_len( + levels[i].level, tag, strlen(tag), ANDROID_LOG_DEBUG); if ((levels[i].level < levels[j].level) || (levels[j].level == -1) || ((levels[i].level < ANDROID_LOG_DEBUG) @@ -1450,8 +1456,8 @@ TEST(liblog, is_loggable) { } EXPECT_FALSE(android_log_is_loggable); for(size_t k = 10; k; --k) { - EXPECT_FALSE(__android_log_is_loggable( - levels[i].level, tag, ANDROID_LOG_DEBUG)); + EXPECT_FALSE(__android_log_is_loggable_len( + levels[i].level, tag, strlen(tag), ANDROID_LOG_DEBUG)); } } else { if (!android_log_is_loggable) { @@ -1459,8 +1465,8 @@ TEST(liblog, is_loggable) { } EXPECT_TRUE(android_log_is_loggable); for(size_t k = 10; k; --k) { - EXPECT_TRUE(__android_log_is_loggable( - levels[i].level, tag, ANDROID_LOG_DEBUG)); + EXPECT_TRUE(__android_log_is_loggable_len( + levels[i].level, tag, strlen(tag), ANDROID_LOG_DEBUG)); } } usleep(20000); @@ -1469,8 +1475,8 @@ TEST(liblog, is_loggable) { fprintf(stderr, "i=%zu j=%zu property_set(\"%s\",\"%s\")\r", i, j, key + base_offset, buf); property_set(key + base_offset, buf); - android_log_is_loggable = __android_log_is_loggable( - levels[i].level, tag, ANDROID_LOG_DEBUG); + android_log_is_loggable = __android_log_is_loggable_len( + levels[i].level, tag, strlen(tag), ANDROID_LOG_DEBUG); if ((levels[i].level < levels[j].level) || (levels[j].level == -1) || ((levels[i].level < ANDROID_LOG_DEBUG) @@ -1480,8 +1486,8 @@ TEST(liblog, is_loggable) { } EXPECT_FALSE(android_log_is_loggable); for(size_t k = 10; k; --k) { - EXPECT_FALSE(__android_log_is_loggable( - levels[i].level, tag, ANDROID_LOG_DEBUG)); + EXPECT_FALSE(__android_log_is_loggable_len( + levels[i].level, tag, strlen(tag), ANDROID_LOG_DEBUG)); } } else { if (!android_log_is_loggable) { @@ -1489,8 +1495,8 @@ TEST(liblog, is_loggable) { } EXPECT_TRUE(android_log_is_loggable); for(size_t k = 10; k; --k) { - EXPECT_TRUE(__android_log_is_loggable( - levels[i].level, tag, ANDROID_LOG_DEBUG)); + EXPECT_TRUE(__android_log_is_loggable_len( + levels[i].level, tag, strlen(tag), ANDROID_LOG_DEBUG)); } } usleep(20000); @@ -1517,8 +1523,8 @@ TEST(liblog, is_loggable) { i, j, key, buf); usleep(20000); property_set(key, buf); - bool android_log_is_loggable = __android_log_is_loggable( - levels[i].level, tag, ANDROID_LOG_DEBUG); + bool android_log_is_loggable = __android_log_is_loggable_len( + levels[i].level, tag, strlen(tag), ANDROID_LOG_DEBUG); if ((levels[i].level < levels[j].level) || (levels[j].level == -1) || ((levels[i].level < ANDROID_LOG_INFO) // Yes INFO @@ -1528,8 +1534,8 @@ TEST(liblog, is_loggable) { } EXPECT_FALSE(android_log_is_loggable); for(size_t k = 10; k; --k) { - EXPECT_FALSE(__android_log_is_loggable( - levels[i].level, tag, ANDROID_LOG_DEBUG)); + EXPECT_FALSE(__android_log_is_loggable_len( + levels[i].level, tag, strlen(tag), ANDROID_LOG_DEBUG)); } } else { if (!android_log_is_loggable) { @@ -1537,8 +1543,8 @@ TEST(liblog, is_loggable) { } EXPECT_TRUE(android_log_is_loggable); for(size_t k = 10; k; --k) { - EXPECT_TRUE(__android_log_is_loggable( - levels[i].level, tag, ANDROID_LOG_DEBUG)); + EXPECT_TRUE(__android_log_is_loggable_len( + levels[i].level, tag, strlen(tag), ANDROID_LOG_DEBUG)); } } usleep(20000); @@ -1547,8 +1553,8 @@ TEST(liblog, is_loggable) { fprintf(stderr, "i=%zu j=%zu property_set(\"%s\",\"%s\")\r", i, j, key + base_offset, buf); property_set(key + base_offset, buf); - android_log_is_loggable = __android_log_is_loggable( - levels[i].level, tag, ANDROID_LOG_DEBUG); + android_log_is_loggable = __android_log_is_loggable_len( + levels[i].level, tag, strlen(tag), ANDROID_LOG_DEBUG); if ((levels[i].level < levels[j].level) || (levels[j].level == -1) || ((levels[i].level < ANDROID_LOG_INFO) // Yes INFO @@ -1558,8 +1564,8 @@ TEST(liblog, is_loggable) { } EXPECT_FALSE(android_log_is_loggable); for(size_t k = 10; k; --k) { - EXPECT_FALSE(__android_log_is_loggable( - levels[i].level, tag, ANDROID_LOG_DEBUG)); + EXPECT_FALSE(__android_log_is_loggable_len( + levels[i].level, tag, strlen(tag), ANDROID_LOG_DEBUG)); } } else { if (!android_log_is_loggable) { @@ -1567,8 +1573,8 @@ TEST(liblog, is_loggable) { } EXPECT_TRUE(android_log_is_loggable); for(size_t k = 10; k; --k) { - EXPECT_TRUE(__android_log_is_loggable( - levels[i].level, tag, ANDROID_LOG_DEBUG)); + EXPECT_TRUE(__android_log_is_loggable_len( + levels[i].level, tag, strlen(tag), ANDROID_LOG_DEBUG)); } } usleep(20000); @@ -2617,3 +2623,83 @@ TEST(liblog, __android_log_pmsg_file_read) { EXPECT_LT(0, ret); EXPECT_EQ(1U, signaled); } + +// meant to be handed to ASSERT_TRUE / EXPECT_TRUE only to expand the message +static testing::AssertionResult IsOk(bool ok, std::string &message) { + return ok ? + testing::AssertionSuccess() : + (testing::AssertionFailure() << message); +} + +static void event_log_tags_test_smap(pid_t pid) { + std::string filename = android::base::StringPrintf("/proc/%d/smaps", pid); + + std::string content; + if (!android::base::ReadFileToString(filename, &content)) return; + + bool shared_ok = false; + bool anonymous_ok = false; + bool pass_ok = false; + + static const char event_log_tags[] = "event-log-tags"; + std::string::size_type pos = 0; + while ((pos = content.find(event_log_tags, pos)) != std::string::npos) { + pos += strlen(event_log_tags); + + // must not be: 'Shared_Clean: 0 kB' + static const char shared_clean[] = "Shared_Clean:"; + std::string::size_type clean = content.find(shared_clean, pos); + bool ok = (clean != std::string::npos) && + ((clean = content.find_first_not_of(" \t", clean + + strlen(shared_clean))) != std::string::npos) && + (content.find_first_not_of("123456789", clean) != clean); + if (ok && !pass_ok) { + shared_ok = true; + } else if (!ok) { + shared_ok = false; + } + + // must be: 'Anonymous: 0 kB' + static const char anonymous[] = "Anonymous:"; + std::string::size_type anon = content.find(anonymous, pos); + ok = (anon != std::string::npos) && + ((anon = content.find_first_not_of(" \t", anon + + strlen(anonymous))) != std::string::npos) && + (content.find_first_not_of("0", anon) != anon); + if (ok && !pass_ok) { + anonymous_ok = true; + } else if (!ok) { + anonymous_ok = false; + } + + pass_ok = true; + } + content = ""; + + if (!pass_ok) return; + if (shared_ok && anonymous_ok) return; + + filename = android::base::StringPrintf("/proc/%d/comm", pid); + android::base::ReadFileToString(filename, &content); + content = android::base::StringPrintf("%d:%s", + pid, content.substr(0, content.find("\n")).c_str()); + + EXPECT_TRUE(IsOk(shared_ok, content)); + EXPECT_TRUE(IsOk(anonymous_ok, content)); +} + +TEST(liblog, event_log_tags) { + std::unique_ptr proc_dir(opendir("/proc"), closedir); + ASSERT_FALSE(!proc_dir); + + dirent* e; + while ((e = readdir(proc_dir.get()))) { + if (e->d_type != DT_DIR) continue; + if (!isdigit(e->d_name[0])) continue; + long long id = atoll(e->d_name); + if (id <= 0) continue; + pid_t pid = id; + if (id != pid) continue; + event_log_tags_test_smap(pid); + } +} diff --git a/logd/LogBuffer.cpp b/logd/LogBuffer.cpp index 1ecf99c98..7f5fe4f8f 100644 --- a/logd/LogBuffer.cpp +++ b/logd/LogBuffer.cpp @@ -211,13 +211,15 @@ int LogBuffer::log(log_id_t log_id, log_time realtime, if (log_id != LOG_ID_SECURITY) { int prio = ANDROID_LOG_INFO; const char *tag = NULL; + size_t len = 0; if (log_id == LOG_ID_EVENTS) { - tag = android::tagToName(elem->getTag()); + tag = android::tagToName(&len, elem->getTag()); } else { prio = *msg; tag = msg + 1; + len = strlen(tag); } - if (!__android_log_is_loggable(prio, tag, ANDROID_LOG_VERBOSE)) { + if (!__android_log_is_loggable_len(prio, tag, len, ANDROID_LOG_VERBOSE)) { // Log traffic received to total pthread_mutex_lock(&mLogElementsLock); stats.add(elem); diff --git a/logd/LogBufferElement.cpp b/logd/LogBufferElement.cpp index 3e6e5864f..e5de11d92 100644 --- a/logd/LogBufferElement.cpp +++ b/logd/LogBufferElement.cpp @@ -110,7 +110,9 @@ size_t LogBufferElement::populateDroppedMessage(char *&buffer, LogBuffer *parent) { static const char tag[] = "chatty"; - if (!__android_log_is_loggable(ANDROID_LOG_INFO, tag, ANDROID_LOG_VERBOSE)) { + if (!__android_log_is_loggable_len(ANDROID_LOG_INFO, + tag, strlen(tag), + ANDROID_LOG_VERBOSE)) { return 0; } diff --git a/logd/LogStatistics.cpp b/logd/LogStatistics.cpp index 86d33b26d..c6ebd52dc 100644 --- a/logd/LogStatistics.cpp +++ b/logd/LogStatistics.cpp @@ -436,11 +436,12 @@ std::string TagEntry::format(const LogStatistics & /* stat */, log_id_t /* id */ name = android::base::StringPrintf("%7u/%u", getKey(), uid); } - const char *nameTmp = getName(); + size_t len = 0; + const char *nameTmp = getName(len); if (nameTmp) { name += android::base::StringPrintf( - "%*s%s", (int)std::max(14 - name.length(), (size_t)1), - "", nameTmp); + "%*s%.*s", (int)std::max(14 - name.length(), (size_t)1), + "", (int)len, nameTmp); } std::string size = android::base::StringPrintf("%zu", diff --git a/logd/LogStatistics.h b/logd/LogStatistics.h index e81195343..bfaafa461 100644 --- a/logd/LogStatistics.h +++ b/logd/LogStatistics.h @@ -385,7 +385,7 @@ struct TagEntry : public EntryBaseDropped { const uint32_t&getKey() const { return tag; } const pid_t&getPid() const { return pid; } const uid_t&getUid() const { return uid; } - const char*getName() const { return android::tagToName(tag); } + const char*getName(size_t &len) const { return android::tagToName(&len, tag); } inline void add(LogBufferElement *element) { if (uid != element->getUid()) { diff --git a/logd/LogUtils.h b/logd/LogUtils.h index 939515e9c..6db4c51d2 100644 --- a/logd/LogUtils.h +++ b/logd/LogUtils.h @@ -37,7 +37,7 @@ char *pidToName(pid_t pid); char *tidToName(pid_t tid); // Furnished in main.cpp. Thread safe. -const char *tagToName(uint32_t tag); +const char *tagToName(size_t *len, uint32_t tag); } diff --git a/logd/main.cpp b/logd/main.cpp index 77a69730d..a0cea25cf 100644 --- a/logd/main.cpp +++ b/logd/main.cpp @@ -302,7 +302,7 @@ void reinit_signal_handler(int /*signal*/) { } // tagToName converts an events tag into a name -const char *android::tagToName(uint32_t tag) { +const char *android::tagToName(size_t *len, uint32_t tag) { static const EventTagMap *map; if (!map) { @@ -312,10 +312,11 @@ const char *android::tagToName(uint32_t tag) { } sem_post(&sem_name); if (!map) { + if (len) len = 0; return NULL; } } - return android_lookupEventTag(map, tag); + return android_lookupEventTag_len(map, len, tag); } static void readDmesg(LogAudit *al, LogKlog *kl) {