Merge changes I303549ae,Ia36e0d2e,Ibdea2961 am: 20610c3082 am: 24808cdee0

Change-Id: Ie4edb2496a9524ba95185274c48c803026cba2d3
This commit is contained in:
Automerger Merge Worker 2020-01-29 16:38:55 +00:00
commit 4d2fe3f9d0
11 changed files with 144 additions and 697 deletions

View file

@ -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,

View file

@ -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 <ctype.h>
#include <errno.h>
#include <fcntl.h>
#include <stdint.h>
#include <stdio.h>
#include <stdlib.h>
#include <string.h>
#include <time.h>
#include <mutex>
#include <android-base/no_destructor.h>
#include <android/log.h>
#include <log/log_id.h>
#include <log/logprint.h>
#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<std::mutex> 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;
}

View file

@ -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 <sys/cdefs.h>
#include <sys/types.h>
#include <android/log.h>
__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

View file

@ -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 {

View file

@ -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();

View file

@ -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);

View file

@ -20,8 +20,6 @@
#include <pthread.h>
#include <stdlib.h>
#include <string.h>
#define _REALLY_INCLUDE_SYS__SYSTEM_PROPERTIES_H_
#include <sys/_system_properties.h>
#include <unistd.h>
#include <algorithm>
@ -31,6 +29,10 @@
#include "logger_write.h"
#ifdef __ANDROID__
#define _REALLY_INCLUDE_SYS__SYSTEM_PROPERTIES_H_
#include <sys/_system_properties.h>
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

View file

@ -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,
}

View file

@ -22,10 +22,17 @@
#include <android-base/file.h>
#include <android-base/logging.h>
#include <android-base/properties.h>
#include <android-base/scopeguard.h>
#include <android/log.h>
#include <gtest/gtest.h>
#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.<getprogname()> 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
}

View file

@ -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
}

View file

@ -20,15 +20,37 @@
#include <stdlib.h>
#include <unistd.h>
#include <regex>
#include <string>
#include <android-base/logging.h>
#include <android-base/macros.h>
#include <android-base/stringprintf.h>
#include <android-base/strings.h>
#include <android-base/test_utils.h>
#include <gtest/gtest.h>
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 (<pid>): info main
E/tag (<pid>): error main
I/tag (<pid>): info radio
E/tag (<pid>): error radio
I/tag (<pid>): info system
E/tag (<pid>): error system
I/tag (<pid>): info crash
E/tag (<pid>): error crash
)init",
"<pid>", 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(<pid>) info main (tag)
E(<pid>) error main (tag)
I(<pid>) info radio (tag)
E(<pid>) error radio (tag)
I(<pid>) info system (tag)
E(<pid>) error system (tag)
I(<pid>) info crash (tag)
E(<pid>) error crash (tag)
)init",
"<pid>", 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 (<pid>): info main
E/tag (<pid>): error main
I/tag (<pid>): info radio
E/tag (<pid>): error radio
I/tag (<pid>): info system
E/tag (<pid>): error system
I/tag (<pid>): info crash
E/tag (<pid>): error crash
)init",
"<pid>", 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(<pid>): verbose verbose_tag
E/verbose_tag(<pid>): error verbose_tag
D/debug_tag(<pid>): debug debug_tag
E/debug_tag(<pid>): error debug_tag
W/default_tag(<pid>): warn default_tag
E/default_tag(<pid>): error default_tag
)init",
"<pid>", 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(<pid>): error verbose_tag
E/debug_tag(<pid>): error debug_tag
E/default_tag(<pid>): error default_tag
)init",
"<pid>", 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");