From e2187bfbbc647938fdde72f97149957145026a18 Mon Sep 17 00:00:00 2001 From: Tom Cherry Date: Mon, 27 Jan 2020 15:45:52 -0800 Subject: [PATCH 1/3] liblog: remove fake_log_device This is now dead code as __android_log_stderr_logger() has superseded it. Bug: 147496863 Test: build Change-Id: Ibdea2961ec4fc093bf9e35581dc1c46db2cff06a --- liblog/Android.bp | 9 +- liblog/fake_log_device.cpp | 533 ------------------------------------- liblog/fake_log_device.h | 33 --- liblog/logger_read.cpp | 4 +- liblog/logger_write.cpp | 8 +- liblog/logprint.cpp | 7 +- liblog/properties.cpp | 26 +- 7 files changed, 30 insertions(+), 590 deletions(-) delete mode 100644 liblog/fake_log_device.cpp delete mode 100644 liblog/fake_log_device.h diff --git a/liblog/Android.bp b/liblog/Android.bp index 2e87b5b28..2cf60e03e 100644 --- a/liblog/Android.bp +++ b/liblog/Android.bp @@ -21,14 +21,11 @@ liblog_sources = [ "logger_read.cpp", "logger_write.cpp", "logprint.cpp", -] -liblog_host_sources = [ - "fake_log_device.cpp", + "properties.cpp", ] liblog_target_sources = [ "event_tag_map.cpp", "log_time.cpp", - "properties.cpp", "pmsg_reader.cpp", "pmsg_writer.cpp", "logd_reader.cpp", @@ -69,10 +66,6 @@ cc_library { srcs: liblog_sources, target: { - host: { - srcs: liblog_host_sources, - cflags: ["-DFAKE_LOG_DEVICE=1"], - }, android: { version_script: "liblog.map.txt", srcs: liblog_target_sources, diff --git a/liblog/fake_log_device.cpp b/liblog/fake_log_device.cpp deleted file mode 100644 index cd4c11e6f..000000000 --- a/liblog/fake_log_device.cpp +++ /dev/null @@ -1,533 +0,0 @@ -/* - * Copyright (C) 2008-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. - */ -/* - * Intercepts log messages intended for the Android log device. - * Messages are printed to stderr. - */ - -#include "fake_log_device.h" - -#include -#include -#include -#include -#include -#include -#include -#include - -#include - -#include -#include -#include -#include - -#include "logger.h" - -#define kMaxTagLen 16 /* from the long-dead utils/Log.cpp */ - -#define kTagSetSize 16 /* arbitrary */ - -#if 0 -#define TRACE(...) printf("fake_log_device: " __VA_ARGS__) -#else -#define TRACE(...) ((void)0) -#endif - -typedef struct LogState { - bool initialized = false; - /* global minimum priority */ - int global_min_priority; - - /* output format */ - AndroidLogPrintFormat output_format; - - /* tags and priorities */ - struct { - char tag[kMaxTagLen]; - int minPriority; - } tagSet[kTagSetSize]; -} LogState; - -static LogState log_state; -static android::base::NoDestructor fake_log_mutex; - -/* - * Configure logging based on ANDROID_LOG_TAGS environment variable. We - * need to parse a string that looks like - * - * *:v jdwp:d dalvikvm:d dalvikvm-gc:i dalvikvmi:i - * - * The tag (or '*' for the global level) comes first, followed by a colon - * and a letter indicating the minimum priority level we're expected to log. - * This can be used to reveal or conceal logs with specific tags. - * - * We also want to check ANDROID_PRINTF_LOG to determine how the output - * will look. - */ -void InitializeLogStateLocked() { - log_state.initialized = true; - - /* global min priority defaults to "info" level */ - log_state.global_min_priority = ANDROID_LOG_INFO; - - /* - * This is based on the the long-dead utils/Log.cpp code. - */ - const char* tags = getenv("ANDROID_LOG_TAGS"); - TRACE("Found ANDROID_LOG_TAGS='%s'\n", tags); - if (tags != NULL) { - int entry = 0; - - while (*tags != '\0') { - char tagName[kMaxTagLen]; - int i, minPrio; - - while (isspace(*tags)) tags++; - - i = 0; - while (*tags != '\0' && !isspace(*tags) && *tags != ':' && i < kMaxTagLen) { - tagName[i++] = *tags++; - } - if (i == kMaxTagLen) { - TRACE("ERROR: env tag too long (%d chars max)\n", kMaxTagLen - 1); - return; - } - tagName[i] = '\0'; - - /* default priority, if there's no ":" part; also zero out '*' */ - minPrio = ANDROID_LOG_VERBOSE; - if (tagName[0] == '*' && tagName[1] == '\0') { - minPrio = ANDROID_LOG_DEBUG; - tagName[0] = '\0'; - } - - if (*tags == ':') { - tags++; - if (*tags >= '0' && *tags <= '9') { - if (*tags >= ('0' + ANDROID_LOG_SILENT)) - minPrio = ANDROID_LOG_VERBOSE; - else - minPrio = *tags - '\0'; - } else { - switch (*tags) { - case 'v': - minPrio = ANDROID_LOG_VERBOSE; - break; - case 'd': - minPrio = ANDROID_LOG_DEBUG; - break; - case 'i': - minPrio = ANDROID_LOG_INFO; - break; - case 'w': - minPrio = ANDROID_LOG_WARN; - break; - case 'e': - minPrio = ANDROID_LOG_ERROR; - break; - case 'f': - minPrio = ANDROID_LOG_FATAL; - break; - case 's': - minPrio = ANDROID_LOG_SILENT; - break; - default: - minPrio = ANDROID_LOG_DEFAULT; - break; - } - } - - tags++; - if (*tags != '\0' && !isspace(*tags)) { - TRACE("ERROR: garbage in tag env; expected whitespace\n"); - TRACE(" env='%s'\n", tags); - return; - } - } - - if (tagName[0] == 0) { - log_state.global_min_priority = minPrio; - TRACE("+++ global min prio %d\n", logState->globalMinPriority); - } else { - log_state.tagSet[entry].minPriority = minPrio; - strcpy(log_state.tagSet[entry].tag, tagName); - TRACE("+++ entry %d: %s:%d\n", entry, logState->tagSet[entry].tag, - logState->tagSet[entry].minPriority); - entry++; - } - } - } - - /* - * Taken from the long-dead utils/Log.cpp - */ - const char* fstr = getenv("ANDROID_PRINTF_LOG"); - AndroidLogPrintFormat format; - if (fstr == NULL) { - format = FORMAT_BRIEF; - } else { - if (strcmp(fstr, "brief") == 0) - format = FORMAT_BRIEF; - else if (strcmp(fstr, "process") == 0) - format = FORMAT_PROCESS; - else if (strcmp(fstr, "tag") == 0) - format = FORMAT_PROCESS; - else if (strcmp(fstr, "thread") == 0) - format = FORMAT_PROCESS; - else if (strcmp(fstr, "raw") == 0) - format = FORMAT_PROCESS; - else if (strcmp(fstr, "time") == 0) - format = FORMAT_PROCESS; - else if (strcmp(fstr, "long") == 0) - format = FORMAT_PROCESS; - else - format = (AndroidLogPrintFormat)atoi(fstr); // really?! - } - - log_state.output_format = format; -} - -/* - * Return a human-readable string for the priority level. Always returns - * a valid string. - */ -static const char* getPriorityString(int priority) { - /* the first character of each string should be unique */ - static const char* priorityStrings[] = {"Verbose", "Debug", "Info", "Warn", "Error", "Assert"}; - int idx; - - idx = (int)priority - (int)ANDROID_LOG_VERBOSE; - if (idx < 0 || idx >= (int)(sizeof(priorityStrings) / sizeof(priorityStrings[0]))) - return "?unknown?"; - return priorityStrings[idx]; -} - -#if defined(_WIN32) -/* - * WIN32 does not have writev(). - * Make up something to replace it. - */ -static ssize_t fake_writev(int fd, const struct iovec* iov, int iovcnt) { - ssize_t result = 0; - const struct iovec* end = iov + iovcnt; - for (; iov < end; iov++) { - ssize_t w = write(fd, iov->iov_base, iov->iov_len); - if (w != (ssize_t)iov->iov_len) { - if (w < 0) return w; - return result + w; - } - result += w; - } - return result; -} - -#define writev fake_writev -#endif - -/* - * Write a filtered log message to stderr. - * - * Log format parsing taken from the long-dead utils/Log.cpp. - */ -static void ShowLog(int logPrio, const char* tag, const char* msg) { -#if !defined(_WIN32) - struct tm tmBuf; -#endif - struct tm* ptm; - char timeBuf[32]; - char prefixBuf[128], suffixBuf[128]; - char priChar; - time_t when; -#if !defined(_WIN32) - pid_t pid, tid; -#else - uint32_t pid, tid; -#endif - - TRACE("LOG %d: %s %s", logPrio, tag, msg); - - priChar = getPriorityString(logPrio)[0]; - when = time(NULL); - pid = tid = getpid(); // find gettid()? - -/* - * Get the current date/time in pretty form - * - * It's often useful when examining a log with "less" to jump to - * a specific point in the file by searching for the date/time stamp. - * For this reason it's very annoying to have regexp meta characters - * in the time stamp. Don't use forward slashes, parenthesis, - * brackets, asterisks, or other special chars here. - */ -#if !defined(_WIN32) - ptm = localtime_r(&when, &tmBuf); -#else - ptm = localtime(&when); -#endif - // strftime(timeBuf, sizeof(timeBuf), "%Y-%m-%d %H:%M:%S", ptm); - strftime(timeBuf, sizeof(timeBuf), "%m-%d %H:%M:%S", ptm); - - /* - * Construct a buffer containing the log header and log message. - */ - size_t prefixLen, suffixLen; - - switch (log_state.output_format) { - case FORMAT_TAG: - prefixLen = snprintf(prefixBuf, sizeof(prefixBuf), "%c/%-8s: ", priChar, tag); - strcpy(suffixBuf, "\n"); - suffixLen = 1; - break; - case FORMAT_PROCESS: - prefixLen = snprintf(prefixBuf, sizeof(prefixBuf), "%c(%5d) ", priChar, pid); - suffixLen = snprintf(suffixBuf, sizeof(suffixBuf), " (%s)\n", tag); - break; - case FORMAT_THREAD: - prefixLen = snprintf(prefixBuf, sizeof(prefixBuf), "%c(%5d:%5d) ", priChar, pid, tid); - strcpy(suffixBuf, "\n"); - suffixLen = 1; - break; - case FORMAT_RAW: - prefixBuf[0] = 0; - prefixLen = 0; - strcpy(suffixBuf, "\n"); - suffixLen = 1; - break; - case FORMAT_TIME: - prefixLen = snprintf(prefixBuf, sizeof(prefixBuf), "%s %-8s\n\t", timeBuf, tag); - strcpy(suffixBuf, "\n"); - suffixLen = 1; - break; - case FORMAT_THREADTIME: - prefixLen = snprintf(prefixBuf, sizeof(prefixBuf), "%s %5d %5d %c %-8s \n\t", timeBuf, pid, - tid, priChar, tag); - strcpy(suffixBuf, "\n"); - suffixLen = 1; - break; - case FORMAT_LONG: - prefixLen = snprintf(prefixBuf, sizeof(prefixBuf), "[ %s %5d:%5d %c/%-8s ]\n", timeBuf, pid, - tid, priChar, tag); - strcpy(suffixBuf, "\n\n"); - suffixLen = 2; - break; - default: - prefixLen = snprintf(prefixBuf, sizeof(prefixBuf), "%c/%-8s(%5d): ", priChar, tag, pid); - strcpy(suffixBuf, "\n"); - suffixLen = 1; - break; - } - - /* - * Figure out how many lines there will be. - */ - const char* end = msg + strlen(msg); - size_t numLines = 0; - const char* p = msg; - while (p < end) { - if (*p++ == '\n') numLines++; - } - if (p > msg && *(p - 1) != '\n') { - numLines++; - } - - /* - * Create an array of iovecs large enough to write all of - * the lines with a prefix and a suffix. - */ - const size_t INLINE_VECS = 64; - const size_t MAX_LINES = ((size_t)~0) / (3 * sizeof(struct iovec*)); - struct iovec stackVec[INLINE_VECS]; - struct iovec* vec = stackVec; - size_t numVecs; - - if (numLines > MAX_LINES) numLines = MAX_LINES; - - numVecs = numLines * 3; // 3 iovecs per line. - if (numVecs > INLINE_VECS) { - vec = (struct iovec*)malloc(sizeof(struct iovec) * numVecs); - if (vec == NULL) { - msg = "LOG: write failed, no memory"; - numVecs = INLINE_VECS; - numLines = numVecs / 3; - vec = stackVec; - } - } - - /* - * Fill in the iovec pointers. - */ - p = msg; - struct iovec* v = vec; - int totalLen = 0; - while (numLines > 0 && p < end) { - if (prefixLen > 0) { - v->iov_base = prefixBuf; - v->iov_len = prefixLen; - totalLen += prefixLen; - v++; - } - const char* start = p; - while (p < end && *p != '\n') { - p++; - } - if ((p - start) > 0) { - v->iov_base = (void*)start; - v->iov_len = p - start; - totalLen += p - start; - v++; - } - if (*p == '\n') p++; - if (suffixLen > 0) { - v->iov_base = suffixBuf; - v->iov_len = suffixLen; - totalLen += suffixLen; - v++; - } - numLines -= 1; - } - - /* - * Write the entire message to the log file with a single writev() call. - * We need to use this rather than a collection of printf()s on a FILE* - * because of multi-threading and multi-process issues. - * - * If the file was not opened with O_APPEND, this will produce interleaved - * output when called on the same file from multiple processes. - * - * If the file descriptor is actually a network socket, the writev() - * call may return with a partial write. Putting the writev() call in - * a loop can result in interleaved data. This can be alleviated - * somewhat by wrapping the writev call in the Mutex. - */ - - for (;;) { - int cc = writev(fileno(stderr), vec, v - vec); - - if (cc == totalLen) break; - - if (cc < 0) { - if (errno == EINTR) continue; - - /* can't really log the failure; for now, throw out a stderr */ - fprintf(stderr, "+++ LOG: write failed (errno=%d)\n", errno); - break; - } else { - /* shouldn't happen when writing to file or tty */ - fprintf(stderr, "+++ LOG: write partial (%d of %d)\n", cc, totalLen); - break; - } - } - - /* if we allocated storage for the iovecs, free it */ - if (vec != stackVec) free(vec); -} - -/* - * Receive a log message. We happen to know that "vector" has three parts: - * - * priority (1 byte) - * tag (N bytes -- null-terminated ASCII string) - * message (N bytes -- null-terminated ASCII string) - */ -int FakeWrite(log_id_t log_id, struct timespec*, struct iovec* vector, size_t count) { - /* Make sure that no-one frees the LogState while we're using it. - * Also guarantees that only one thread is in showLog() at a given - * time (if it matters). - */ - auto lock = std::lock_guard{*fake_log_mutex}; - - if (!log_state.initialized) { - InitializeLogStateLocked(); - } - - if (log_id == LOG_ID_EVENTS || log_id == LOG_ID_STATS || log_id == LOG_ID_SECURITY) { - TRACE("%s: ignoring binary log\n", android_log_id_to_name(log_id)); - int len = 0; - for (size_t i = 0; i < count; ++i) { - len += vector[i].iov_len; - } - return len; - } - - if (count != 3) { - TRACE("%s: writevLog with count=%d not expected\n", android_log_id_to_name(log_id), count); - return -1; - } - - /* pull out the three fields */ - int logPrio = *(const char*)vector[0].iov_base; - const char* tag = (const char*)vector[1].iov_base; - const char* msg = (const char*)vector[2].iov_base; - - /* see if this log tag is configured */ - int minPrio = log_state.global_min_priority; - for (size_t i = 0; i < kTagSetSize; i++) { - if (log_state.tagSet[i].minPriority == ANDROID_LOG_UNKNOWN) - break; /* reached end of configured values */ - - if (strcmp(log_state.tagSet[i].tag, tag) == 0) { - minPrio = log_state.tagSet[i].minPriority; - break; - } - } - - if (logPrio >= minPrio) { - ShowLog(logPrio, tag, msg); - } - - int len = 0; - for (size_t i = 0; i < count; ++i) { - len += vector[i].iov_len; - } - return len; -} - -/* - * Reset out state. - * - * The logger API has no means or need to 'stop' or 'close' using the logs, - * and as such, there is no way for that 'stop' or 'close' to translate into - * a close operation to the fake log handler. fakeLogClose is provided for - * completeness only. - * - * We have no intention of adding a log close operation as it would complicate - * every user of the logging API with no gain since the only valid place to - * call is in the exit handler. Logging can continue in the exit handler to - * help debug HOST tools ... - */ -void FakeClose() { - auto lock = std::lock_guard{*fake_log_mutex}; - - memset(&log_state, 0, sizeof(log_state)); -} - -int __android_log_is_loggable(int prio, const char*, int) { - int minimum_priority = __android_log_get_minimum_priority(); - if (minimum_priority == ANDROID_LOG_DEFAULT) { - minimum_priority = ANDROID_LOG_INFO; - } - return prio >= minimum_priority; -} - -int __android_log_is_loggable_len(int prio, const char*, size_t, int def) { - return __android_log_is_loggable(prio, nullptr, def); -} - -int __android_log_is_debuggable() { - return 1; -} diff --git a/liblog/fake_log_device.h b/liblog/fake_log_device.h deleted file mode 100644 index 53f1b4176..000000000 --- a/liblog/fake_log_device.h +++ /dev/null @@ -1,33 +0,0 @@ -/* - * Copyright (C) 2013 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. - */ - -#pragma once - -#include -#include - -#include - -__BEGIN_DECLS - -void FakeClose(); -int FakeWrite(log_id_t log_id, struct timespec* ts, struct iovec* vec, size_t nr); - -int __android_log_is_loggable(int prio, const char*, int def); -int __android_log_is_loggable_len(int prio, const char*, size_t, int def); -int __android_log_is_debuggable(); - -__END_DECLS diff --git a/liblog/logger_read.cpp b/liblog/logger_read.cpp index e0598de58..a0c526bef 100644 --- a/liblog/logger_read.cpp +++ b/liblog/logger_read.cpp @@ -97,7 +97,7 @@ int android_logger_list_read(struct logger_list* logger_list, struct log_msg* lo int ret = 0; -#if (FAKE_LOG_DEVICE == 0) +#ifdef __ANDROID__ if (logger_list->mode & ANDROID_LOG_PSTORE) { ret = PmsgRead(logger_list, log_msg); } else { @@ -135,7 +135,7 @@ void android_logger_list_free(struct logger_list* logger_list) { return; } -#if (FAKE_LOG_DEVICE == 0) +#ifdef __ANDROID__ if (logger_list->mode & ANDROID_LOG_PSTORE) { PmsgClose(logger_list); } else { diff --git a/liblog/logger_write.cpp b/liblog/logger_write.cpp index ca6829663..3ee705b7d 100644 --- a/liblog/logger_write.cpp +++ b/liblog/logger_write.cpp @@ -40,11 +40,9 @@ #include "rwlock.h" #include "uio.h" -#if (FAKE_LOG_DEVICE == 0) +#ifdef __ANDROID__ #include "logd_writer.h" #include "pmsg_writer.h" -#else -#include "fake_log_device.h" #endif #if defined(__APPLE__) @@ -105,11 +103,9 @@ static int check_log_uid_permissions() { * Release any logger resources. A new log write will immediately re-acquire. */ void __android_log_close() { -#if (FAKE_LOG_DEVICE == 0) +#ifdef __ANDROID__ LogdClose(); PmsgClose(); -#else - FakeClose(); #endif } diff --git a/liblog/logprint.cpp b/liblog/logprint.cpp index 0745a1e2b..e32878acf 100644 --- a/liblog/logprint.cpp +++ b/liblog/logprint.cpp @@ -1520,12 +1520,7 @@ char* android_log_formatLogLine(AndroidLogFormat* p_format, char* defaultBuffer, * This code is Android specific, bionic guarantees that * calls to non-reentrant getpwuid() are thread safe. */ -#if !defined(__MINGW32__) -#if (FAKE_LOG_DEVICE == 0) -#ifndef __BIONIC__ -#warning "This code assumes that getpwuid is thread safe, only true with Bionic!" -#endif -#endif +#ifdef __ANDROID__ struct passwd* pwd = getpwuid(entry->uid); if (pwd && (strlen(pwd->pw_name) <= 5)) { snprintf(uid, sizeof(uid), "%5s:", pwd->pw_name); diff --git a/liblog/properties.cpp b/liblog/properties.cpp index b13662fa0..f30058a41 100644 --- a/liblog/properties.cpp +++ b/liblog/properties.cpp @@ -20,8 +20,6 @@ #include #include #include -#define _REALLY_INCLUDE_SYS__SYSTEM_PROPERTIES_H_ -#include #include #include @@ -31,6 +29,10 @@ #include "logger_write.h" +#ifdef __ANDROID__ +#define _REALLY_INCLUDE_SYS__SYSTEM_PROPERTIES_H_ +#include + static pthread_mutex_t lock_loggable = PTHREAD_MUTEX_INITIALIZER; static int lock() { @@ -647,3 +649,23 @@ unsigned long __android_logger_get_buffer_size(log_id_t logId) { return property_size; } + +#else + +int __android_log_is_loggable(int prio, const char*, int) { + int minimum_priority = __android_log_get_minimum_priority(); + if (minimum_priority == ANDROID_LOG_DEFAULT) { + minimum_priority = ANDROID_LOG_INFO; + } + return prio >= minimum_priority; +} + +int __android_log_is_loggable_len(int prio, const char*, size_t, int def) { + return __android_log_is_loggable(prio, nullptr, def); +} + +int __android_log_is_debuggable() { + return 1; +} + +#endif \ No newline at end of file From f48f685e60346c25a292e0a05f7016a73ea91a5d Mon Sep 17 00:00:00 2001 From: Tom Cherry Date: Tue, 28 Jan 2020 13:06:29 -0800 Subject: [PATCH 2/3] liblog: do not allow loggers to write to binary buffers Do not write to binary buffers, this was already done for logd, but wasn't explicitly done for other loggers, so do that too. Test: unit tests Change-Id: Ia36e0d2e1b6c833780239a5ef459abea99bc4a1f --- liblog/logger_write.cpp | 6 ++++++ 1 file changed, 6 insertions(+) diff --git a/liblog/logger_write.cpp b/liblog/logger_write.cpp index 3ee705b7d..cf82e0f26 100644 --- a/liblog/logger_write.cpp +++ b/liblog/logger_write.cpp @@ -307,6 +307,12 @@ int __android_log_write(int prio, const char* tag, const char* msg) { void __android_log_write_logger_data(__android_logger_data* logger_data, const char* msg) { ErrnoRestorer errno_restorer; + if (logger_data->buffer_id != LOG_ID_DEFAULT && logger_data->buffer_id != LOG_ID_MAIN && + logger_data->buffer_id != LOG_ID_SYSTEM && logger_data->buffer_id != LOG_ID_RADIO && + logger_data->buffer_id != LOG_ID_CRASH) { + return; + } + auto tag_lock = std::shared_lock{default_tag_lock, std::defer_lock}; if (logger_data->tag == nullptr) { tag_lock.lock(); From 5676f3d9168b2d76ef4a798a5939f7a4375f6171 Mon Sep 17 00:00:00 2001 From: Tom Cherry Date: Mon, 27 Jan 2020 16:20:35 -0800 Subject: [PATCH 3/3] liblog: fix host tests 1) Fix up the host tests for new logging format 2) Add recently added tests to the host test 3) Ensure that properties are cleaned up by liblog-unit-tests Test: unit tests Change-Id: I303549aecc26d11ec87e59d48758ced4c198b72c --- liblog/tests/Android.bp | 7 +- liblog/tests/liblog_default_tag.cpp | 17 +++ liblog/tests/liblog_global_state.cpp | 8 ++ liblog/tests/liblog_host_test.cpp | 183 +++++++++++---------------- 4 files changed, 108 insertions(+), 107 deletions(-) diff --git a/liblog/tests/Android.bp b/liblog/tests/Android.bp index b3364f9ea..b4bb77f66 100644 --- a/liblog/tests/Android.bp +++ b/liblog/tests/Android.bp @@ -104,6 +104,11 @@ cc_test_host { name: "liblog-host-test", static_libs: ["liblog"], shared_libs: ["libbase"], - srcs: ["liblog_host_test.cpp"], + srcs: [ + "liblog_host_test.cpp", + "liblog_default_tag.cpp", + "liblog_global_state.cpp", + "rwlock_test.cpp", + ], isolated: true, } diff --git a/liblog/tests/liblog_default_tag.cpp b/liblog/tests/liblog_default_tag.cpp index 5643f6377..31b746708 100644 --- a/liblog/tests/liblog_default_tag.cpp +++ b/liblog/tests/liblog_default_tag.cpp @@ -22,10 +22,17 @@ #include #include #include +#include #include #include +#ifndef __ANDROID__ +static const char* getprogname() { + return program_invocation_short_name; +} +#endif + TEST(liblog_default_tag, no_default_tag_libbase_write_first) { using namespace android::base; bool message_seen = false; @@ -99,6 +106,7 @@ TEST(liblog_default_tag, liblog_sets_default_tag) { } TEST(liblog_default_tag, default_tag_plus_log_severity) { +#ifdef __ANDROID__ using namespace android::base; bool message_seen = false; std::string expected_tag = "liblog_test_tag"; @@ -110,6 +118,7 @@ TEST(liblog_default_tag, default_tag_plus_log_severity) { auto log_tag_property = "log.tag." + expected_tag; SetProperty(log_tag_property, "V"); + auto reset_tag_property_guard = make_scope_guard([=] { SetProperty(log_tag_property, ""); }); __android_log_buf_write(LOG_ID_MAIN, ANDROID_LOG_VERBOSE, nullptr, "message"); EXPECT_TRUE(message_seen); @@ -117,9 +126,13 @@ TEST(liblog_default_tag, default_tag_plus_log_severity) { LOG(VERBOSE) << "message"; EXPECT_TRUE(message_seen); +#else + GTEST_SKIP() << "No log tag properties on host"; +#endif } TEST(liblog_default_tag, generated_default_tag_plus_log_severity) { +#ifdef __ANDROID__ using namespace android::base; bool message_seen = false; std::string expected_tag = getprogname(); @@ -133,6 +146,7 @@ TEST(liblog_default_tag, generated_default_tag_plus_log_severity) { // case checks that we can log a Verbose message when log.tag. is set to 'V'. auto log_tag_property = "log.tag." + expected_tag; SetProperty(log_tag_property, "V"); + auto reset_tag_property_guard = make_scope_guard([=] { SetProperty(log_tag_property, ""); }); __android_log_buf_write(LOG_ID_MAIN, ANDROID_LOG_VERBOSE, nullptr, "message"); EXPECT_TRUE(message_seen); @@ -140,4 +154,7 @@ TEST(liblog_default_tag, generated_default_tag_plus_log_severity) { LOG(VERBOSE) << "message"; EXPECT_TRUE(message_seen); +#else + GTEST_SKIP() << "No log tag properties on host"; +#endif } \ No newline at end of file diff --git a/liblog/tests/liblog_global_state.cpp b/liblog/tests/liblog_global_state.cpp index 8d73bb886..9a181ef62 100644 --- a/liblog/tests/liblog_global_state.cpp +++ b/liblog/tests/liblog_global_state.cpp @@ -188,6 +188,7 @@ TEST(liblog_global_state, is_loggable_minimum_log_priority_only) { } TEST(liblog_global_state, is_loggable_tag_log_priority_only) { +#ifdef __ANDROID__ EXPECT_EQ(0, __android_log_is_loggable(ANDROID_LOG_DEBUG, LOG_TAG, ANDROID_LOG_INFO)); EXPECT_EQ(1, __android_log_is_loggable(ANDROID_LOG_INFO, LOG_TAG, ANDROID_LOG_INFO)); EXPECT_EQ(1, __android_log_is_loggable(ANDROID_LOG_WARN, LOG_TAG, ANDROID_LOG_INFO)); @@ -204,9 +205,13 @@ TEST(liblog_global_state, is_loggable_tag_log_priority_only) { EXPECT_EQ(1, __android_log_is_loggable(ANDROID_LOG_WARN, LOG_TAG, ANDROID_LOG_INFO)); android::base::SetProperty(log_tag_property, ""); +#else + GTEST_SKIP() << "No log tag properties on host"; +#endif } TEST(liblog_global_state, is_loggable_both_set) { +#ifdef __ANDROID__ EXPECT_EQ(0, __android_log_is_loggable(ANDROID_LOG_DEBUG, LOG_TAG, ANDROID_LOG_INFO)); EXPECT_EQ(1, __android_log_is_loggable(ANDROID_LOG_INFO, LOG_TAG, ANDROID_LOG_INFO)); EXPECT_EQ(1, __android_log_is_loggable(ANDROID_LOG_WARN, LOG_TAG, ANDROID_LOG_INFO)); @@ -240,4 +245,7 @@ TEST(liblog_global_state, is_loggable_both_set) { EXPECT_EQ(1, __android_log_is_loggable(ANDROID_LOG_WARN, LOG_TAG, ANDROID_LOG_INFO)); android::base::SetProperty(log_tag_property, ""); +#else + GTEST_SKIP() << "No log tag properties on host"; +#endif } diff --git a/liblog/tests/liblog_host_test.cpp b/liblog/tests/liblog_host_test.cpp index 377550ff7..ec186d4ac 100644 --- a/liblog/tests/liblog_host_test.cpp +++ b/liblog/tests/liblog_host_test.cpp @@ -20,15 +20,37 @@ #include #include +#include +#include + +#include +#include #include -#include #include #include +using android::base::InitLogging; +using android::base::StderrLogger; using android::base::StringPrintf; -using android::base::StringReplace; -void GenerateLogContent() { +static std::string MakeLogPattern(int priority, const char* tag, const char* message) { + static const char log_characters[] = "XXVDIWEF"; + static_assert(arraysize(log_characters) - 1 == ANDROID_LOG_SILENT, + "Mismatch in size of log_characters and values in android_LogPriority"); + priority = priority > ANDROID_LOG_SILENT ? ANDROID_LOG_FATAL : priority; + char log_char = log_characters[priority]; + + return StringPrintf("%s %c \\d+-\\d+ \\d+:\\d+:\\d+ \\s*\\d+ \\s*\\d+ %s", tag, log_char, + message); +} + +static void CheckMessage(bool expected, const std::string& output, int priority, const char* tag, + const char* message) { + std::regex message_regex(MakeLogPattern(priority, tag, message)); + EXPECT_EQ(expected, std::regex_search(output, message_regex)) << message; +} + +static void GenerateLogContent() { __android_log_buf_print(LOG_ID_MAIN, ANDROID_LOG_VERBOSE, "tag", "verbose main"); __android_log_buf_print(LOG_ID_MAIN, ANDROID_LOG_INFO, "tag", "info main"); __android_log_buf_print(LOG_ID_MAIN, ANDROID_LOG_ERROR, "tag", "error main"); @@ -52,137 +74,86 @@ std::string GetPidString() { } TEST(liblog, default_write) { - setenv("ANDROID_PRINTF_LOG", "brief", true); CapturedStderr captured_stderr; + InitLogging(nullptr, StderrLogger); GenerateLogContent(); - std::string expected_output = StringReplace(R"init(I/tag (): info main -E/tag (): error main -I/tag (): info radio -E/tag (): error radio -I/tag (): info system -E/tag (): error system -I/tag (): info crash -E/tag (): error crash -)init", - "", GetPidString(), true); + CheckMessage(false, captured_stderr.str(), ANDROID_LOG_VERBOSE, "tag", "verbose main"); + CheckMessage(true, captured_stderr.str(), ANDROID_LOG_INFO, "tag", "info main"); + CheckMessage(true, captured_stderr.str(), ANDROID_LOG_ERROR, "tag", "error main"); - EXPECT_EQ(expected_output, captured_stderr.str()); + CheckMessage(false, captured_stderr.str(), ANDROID_LOG_VERBOSE, "tag", "verbose radio"); + CheckMessage(true, captured_stderr.str(), ANDROID_LOG_INFO, "tag", "info radio"); + CheckMessage(true, captured_stderr.str(), ANDROID_LOG_ERROR, "tag", "error radio"); + + CheckMessage(false, captured_stderr.str(), ANDROID_LOG_VERBOSE, "tag", "verbose system"); + CheckMessage(true, captured_stderr.str(), ANDROID_LOG_INFO, "tag", "info system"); + CheckMessage(true, captured_stderr.str(), ANDROID_LOG_ERROR, "tag", "error system"); + + CheckMessage(false, captured_stderr.str(), ANDROID_LOG_VERBOSE, "tag", "verbose crash"); + CheckMessage(true, captured_stderr.str(), ANDROID_LOG_INFO, "tag", "info crash"); + CheckMessage(true, captured_stderr.str(), ANDROID_LOG_ERROR, "tag", "error crash"); } -TEST(liblog, format) { - setenv("ANDROID_PRINTF_LOG", "process", true); +TEST(liblog, verbose_write) { + setenv("ANDROID_LOG_TAGS", "*:v", true); CapturedStderr captured_stderr; + InitLogging(nullptr, StderrLogger); GenerateLogContent(); - std::string expected_output = StringReplace(R"init(I() info main (tag) -E() error main (tag) -I() info radio (tag) -E() error radio (tag) -I() info system (tag) -E() error system (tag) -I() info crash (tag) -E() error crash (tag) -)init", - "", GetPidString(), true); + CheckMessage(true, captured_stderr.str(), ANDROID_LOG_VERBOSE, "tag", "verbose main"); + CheckMessage(true, captured_stderr.str(), ANDROID_LOG_INFO, "tag", "info main"); + CheckMessage(true, captured_stderr.str(), ANDROID_LOG_ERROR, "tag", "error main"); - EXPECT_EQ(expected_output, captured_stderr.str()); - captured_stderr.Stop(); - captured_stderr.Reset(); - captured_stderr.Start(); + CheckMessage(true, captured_stderr.str(), ANDROID_LOG_VERBOSE, "tag", "verbose radio"); + CheckMessage(true, captured_stderr.str(), ANDROID_LOG_INFO, "tag", "info radio"); + CheckMessage(true, captured_stderr.str(), ANDROID_LOG_ERROR, "tag", "error radio"); - // Changing the environment after starting writing doesn't change the format. - setenv("ANDROID_PRINTF_LOG", "brief", true); - GenerateLogContent(); - EXPECT_EQ(expected_output, captured_stderr.str()); - captured_stderr.Stop(); - captured_stderr.Reset(); - captured_stderr.Start(); + CheckMessage(true, captured_stderr.str(), ANDROID_LOG_VERBOSE, "tag", "verbose system"); + CheckMessage(true, captured_stderr.str(), ANDROID_LOG_INFO, "tag", "info system"); + CheckMessage(true, captured_stderr.str(), ANDROID_LOG_ERROR, "tag", "error system"); - // However calling __android_log_close() does reset logging and allow changing the format. - __android_log_close(); - GenerateLogContent(); - - expected_output = StringReplace(R"init(I/tag (): info main -E/tag (): error main -I/tag (): info radio -E/tag (): error radio -I/tag (): info system -E/tag (): error system -I/tag (): info crash -E/tag (): error crash -)init", - "", GetPidString(), true); - - EXPECT_EQ(expected_output, captured_stderr.str()); + CheckMessage(true, captured_stderr.str(), ANDROID_LOG_VERBOSE, "tag", "verbose crash"); + CheckMessage(true, captured_stderr.str(), ANDROID_LOG_INFO, "tag", "info crash"); + CheckMessage(true, captured_stderr.str(), ANDROID_LOG_ERROR, "tag", "error crash"); } -TEST(liblog, filter) { - setenv("ANDROID_PRINTF_LOG", "brief", true); - setenv("ANDROID_LOG_TAGS", "*:w verbose_tag:v debug_tag:d", true); - CapturedStderr captured_stderr; - - auto generate_logs = [](log_id_t log_id) { - // Check that we show verbose logs when requesting for a given tag. - __android_log_buf_print(log_id, ANDROID_LOG_VERBOSE, "verbose_tag", "verbose verbose_tag"); - __android_log_buf_print(log_id, ANDROID_LOG_ERROR, "verbose_tag", "error verbose_tag"); - - // Check that we don't show verbose logs when explicitly requesting debug+ for a given tag. - __android_log_buf_print(log_id, ANDROID_LOG_VERBOSE, "debug_tag", "verbose debug_tag"); - __android_log_buf_print(log_id, ANDROID_LOG_DEBUG, "debug_tag", "debug debug_tag"); - __android_log_buf_print(log_id, ANDROID_LOG_ERROR, "debug_tag", "error debug_tag"); - - // Check that we don't show info logs when requesting globally warn+. - __android_log_buf_print(log_id, ANDROID_LOG_INFO, "default_tag", "info default_tag"); - __android_log_buf_print(log_id, ANDROID_LOG_WARN, "default_tag", "warn default_tag"); - __android_log_buf_print(log_id, ANDROID_LOG_ERROR, "default_tag", "error default_tag"); - }; - - auto expected_output = StringReplace(R"init(V/verbose_tag(): verbose verbose_tag -E/verbose_tag(): error verbose_tag -D/debug_tag(): debug debug_tag -E/debug_tag(): error debug_tag -W/default_tag(): warn default_tag -E/default_tag(): error default_tag -)init", - "", GetPidString(), true); - - auto test_all_logs = [&] { - for (auto log_id : {LOG_ID_MAIN, LOG_ID_SYSTEM, LOG_ID_RADIO, LOG_ID_CRASH}) { - generate_logs(log_id); - EXPECT_EQ(expected_output, captured_stderr.str()); - captured_stderr.Stop(); - captured_stderr.Reset(); - captured_stderr.Start(); - } - }; - - test_all_logs(); - - // Changing the environment after starting writing doesn't change the filter. +TEST(liblog, error_write) { setenv("ANDROID_LOG_TAGS", "*:e", true); - test_all_logs(); + CapturedStderr captured_stderr; + InitLogging(nullptr, StderrLogger); - // However calling __android_log_close() does reset logging and allow changing the format. - __android_log_close(); - expected_output = StringReplace(R"init(E/verbose_tag(): error verbose_tag -E/debug_tag(): error debug_tag -E/default_tag(): error default_tag -)init", - "", GetPidString(), true); - test_all_logs(); + GenerateLogContent(); + + CheckMessage(false, captured_stderr.str(), ANDROID_LOG_VERBOSE, "tag", "verbose main"); + CheckMessage(false, captured_stderr.str(), ANDROID_LOG_INFO, "tag", "info main"); + CheckMessage(true, captured_stderr.str(), ANDROID_LOG_ERROR, "tag", "error main"); + + CheckMessage(false, captured_stderr.str(), ANDROID_LOG_VERBOSE, "tag", "verbose radio"); + CheckMessage(false, captured_stderr.str(), ANDROID_LOG_INFO, "tag", "info radio"); + CheckMessage(true, captured_stderr.str(), ANDROID_LOG_ERROR, "tag", "error radio"); + + CheckMessage(false, captured_stderr.str(), ANDROID_LOG_VERBOSE, "tag", "verbose system"); + CheckMessage(false, captured_stderr.str(), ANDROID_LOG_INFO, "tag", "info system"); + CheckMessage(true, captured_stderr.str(), ANDROID_LOG_ERROR, "tag", "error system"); + + CheckMessage(false, captured_stderr.str(), ANDROID_LOG_VERBOSE, "tag", "verbose crash"); + CheckMessage(false, captured_stderr.str(), ANDROID_LOG_INFO, "tag", "info crash"); + CheckMessage(true, captured_stderr.str(), ANDROID_LOG_ERROR, "tag", "error crash"); } TEST(liblog, kernel_no_write) { CapturedStderr captured_stderr; + InitLogging(nullptr, StderrLogger); __android_log_buf_print(LOG_ID_KERNEL, ANDROID_LOG_ERROR, "tag", "kernel error"); EXPECT_EQ("", captured_stderr.str()); } TEST(liblog, binary_no_write) { CapturedStderr captured_stderr; + InitLogging(nullptr, StderrLogger); __android_log_buf_print(LOG_ID_EVENTS, ANDROID_LOG_ERROR, "tag", "error events"); __android_log_buf_print(LOG_ID_STATS, ANDROID_LOG_ERROR, "tag", "error stats"); __android_log_buf_print(LOG_ID_SECURITY, ANDROID_LOG_ERROR, "tag", "error security");