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..cf82e0f26 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 } @@ -311,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(); 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 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");