Move SetLogger and SetAborter from libbase to liblog
libbase is copied into each APEX module which requires it, meaning
that there may be multiple instances of libbase running within a
single process with their own copy of libbase's globals. This means
that SetLogger() and SetAborter() will only impact logs from the
instance of libbase that calls it. This change moves this state to
liblog, since it will only ever have one instance in a single
process.
One major side-effect here is that now both ALOGE style and LOG(...)
style logs will be handled through the same logger function. For
example, a logger specified through libbase's SetLogger() will now see
logs sent to liblog through ALOGE(). This is intended behavior.
A second side-effect is that libbase's stderr logger is used for all
host logging now. It's simply a better logging default than the
fake_log_device logger in liblog currently and makes ALOGE and
LOG(...) logs on host follow the same format.
Bug: 119867234
Test: libbase and liblog unit tests; logging works
Change-Id: Ib52cbfb4e43749e50910ed19a993dffae19ace86
diff --git a/liblog/include/android/log.h b/liblog/include/android/log.h
index 7290789..39f885c 100644
--- a/liblog/include/android/log.h
+++ b/liblog/include/android/log.h
@@ -55,6 +55,7 @@
*/
#include <stdarg.h>
+#include <stddef.h>
#ifdef __cplusplus
extern "C" {
@@ -152,6 +153,12 @@
} log_id_t;
/**
+ * Let the logging function choose the best log target.
+ * This is not part of the enum since adding either -1 or 0xFFFFFFFF forces the enum to be signed or
+ * unsigned, which breaks unfortunately common arithmetic against LOG_ID_MIN and LOG_ID_MAX. */
+#define LOG_ID_DEFAULT -1
+
+/**
* Writes the constant string `text` to the log buffer `id`,
* with priority `prio` and tag `tag`.
*
@@ -170,6 +177,73 @@
int __android_log_buf_print(int bufID, int prio, const char* tag, const char* fmt, ...)
__attribute__((__format__(printf, 4, 5)));
+/**
+ * Logger data struct used for writing log messages to liblog via __android_log_write_logger_data()
+ * and sending log messages to user defined loggers specified in __android_log_set_logger().
+ */
+struct __android_logger_data {
+ size_t struct_size; /* Must be set to sizeof(__android_logger_data) and is used for versioning. */
+ int buffer_id; /* log_id_t or -1 to represent 'default'. */
+ int priority; /* android_LogPriority values. */
+ const char* tag;
+ const char* file; /* Optional file name, may be set to nullptr. */
+ unsigned int line; /* Optional line number, ignore if file is nullptr. */
+};
+
+/**
+ * Writes the log message specified with logger_data and msg to the log. logger_data includes
+ * additional file name and line number information that a logger may use. logger_data is versioned
+ * for backwards compatibility.
+ */
+void __android_log_write_logger_data(struct __android_logger_data* logger_data, const char* msg);
+
+/**
+ * Prototype for the 'logger' function that is called for every log message.
+ */
+typedef void (*__android_logger_function)(const struct __android_logger_data* logger_data,
+ const char* message);
+
+/**
+ * Sets a user defined logger function. All log messages sent to liblog will be set to the
+ * function pointer specified by logger for processing.
+ */
+void __android_log_set_logger(__android_logger_function logger);
+
+/**
+ * Writes the log message to logd. This is an __android_logger_function and can be provided to
+ * __android_log_set_logger(). It is the default logger when running liblog on a device.
+ */
+void __android_log_logd_logger(const struct __android_logger_data* logger_data, const char* msg);
+
+/**
+ * Writes the log message to stderr. This is an __android_logger_function and can be provided to
+ * __android_log_set_logger(). It is the default logger when running liblog on host.
+ */
+void __android_log_stderr_logger(const struct __android_logger_data* logger_data,
+ const char* message);
+
+/**
+ * Prototype for the 'abort' function that is called when liblog will abort due to
+ * __android_log_assert() failures.
+ */
+typedef void (*__android_aborter_function)(const char* abort_message);
+
+/**
+ * Sets a user defined aborter function that is called for __android_log_assert() failures.
+ */
+void __android_log_set_aborter(__android_aborter_function aborter);
+
+/**
+ * Calls the stored aborter function. This allows for other logging libraries to use the same
+ * aborter function by calling this function in liblog.
+ */
+void __android_log_call_aborter(const char* abort_message);
+
+/**
+ * Sets android_set_abort_message() on device then aborts(). This is the default aborter.
+ */
+void __android_log_default_aborter(const char* abort_message);
+
#ifdef __cplusplus
}
#endif
diff --git a/liblog/liblog.map.txt b/liblog/liblog.map.txt
index 65194ce..ae2a891 100644
--- a/liblog/liblog.map.txt
+++ b/liblog/liblog.map.txt
@@ -67,7 +67,14 @@
LIGLOG_R { # introduced=30
global:
+ __android_log_call_aborter;
+ __android_log_default_aborter;
+ __android_log_logd_logger;
__android_log_security_bswrite; # apex
+ __android_log_set_aborter;
+ __android_log_set_logger;
+ __android_log_stderr_logger;
+ __android_log_write_logger_data;
};
LIBLOG_PRIVATE {
diff --git a/liblog/logger_write.cpp b/liblog/logger_write.cpp
index d6ef951..abc24ce 100644
--- a/liblog/logger_write.cpp
+++ b/liblog/logger_write.cpp
@@ -15,6 +15,7 @@
*/
#include <errno.h>
+#include <inttypes.h>
#include <stdlib.h>
#include <string.h>
#include <sys/time.h>
@@ -23,11 +24,15 @@
#include <android/set_abort_message.h>
#endif
+#include <shared_mutex>
+
#include <android-base/macros.h>
#include <private/android_filesystem_config.h>
#include <private/android_logger.h>
+#include "android/log.h"
#include "logger.h"
+#include "rwlock.h"
#include "uio.h"
#if (FAKE_LOG_DEVICE == 0)
@@ -37,6 +42,14 @@
#include "fake_log_device.h"
#endif
+#if defined(__APPLE__)
+#include <pthread.h>
+#elif defined(__linux__) && !defined(__ANDROID__)
+#include <syscall.h>
+#elif defined(_WIN32)
+#include <windows.h>
+#endif
+
#define LOG_BUF_SIZE 1024
#if defined(__ANDROID__)
@@ -93,6 +106,41 @@
#endif
}
+#ifdef __ANDROID__
+static __android_logger_function logger_function = __android_log_logd_logger;
+#else
+static __android_logger_function logger_function = __android_log_stderr_logger;
+#endif
+static RwLock logger_function_lock;
+
+void __android_log_set_logger(__android_logger_function logger) {
+ auto lock = std::unique_lock{logger_function_lock};
+ logger_function = logger;
+}
+
+void __android_log_default_aborter(const char* abort_message) {
+#ifdef __ANDROID__
+ android_set_abort_message(abort_message);
+#else
+ UNUSED(abort_message);
+#endif
+ abort();
+}
+
+static __android_aborter_function aborter_function = __android_log_default_aborter;
+static RwLock aborter_function_lock;
+
+void __android_log_set_aborter(__android_aborter_function aborter) {
+ auto lock = std::unique_lock{aborter_function_lock};
+ aborter_function = aborter;
+}
+
+void __android_log_call_aborter(const char* abort_message) {
+ auto lock = std::shared_lock{aborter_function_lock};
+ aborter_function(abort_message);
+}
+
+#ifdef __ANDROID__
static int write_to_log(log_id_t log_id, struct iovec* vec, size_t nr) {
int ret, save_errno;
struct timespec ts;
@@ -103,7 +151,6 @@
return -EINVAL;
}
-#if defined(__ANDROID__)
clock_gettime(android_log_clockid(), &ts);
if (log_id == LOG_ID_SECURITY) {
@@ -137,51 +184,106 @@
return -EPERM;
}
}
-#else
- /* simulate clock_gettime(CLOCK_REALTIME, &ts); */
- {
- struct timeval tv;
- gettimeofday(&tv, NULL);
- ts.tv_sec = tv.tv_sec;
- ts.tv_nsec = tv.tv_usec * 1000;
- }
-#endif
- ret = 0;
-
-#if (FAKE_LOG_DEVICE == 0)
ret = LogdWrite(log_id, &ts, vec, nr);
PmsgWrite(log_id, &ts, vec, nr);
-#else
- ret = FakeWrite(log_id, &ts, vec, nr);
-#endif
errno = save_errno;
return ret;
}
+#else
+static int write_to_log(log_id_t, struct iovec*, size_t) {
+ // Non-Android text logs should go to __android_log_stderr_logger, not here.
+ // Non-Android binary logs are always dropped.
+ return 1;
+}
+#endif
+
+// Copied from base/threads.cpp
+static uint64_t GetThreadId() {
+#if defined(__BIONIC__)
+ return gettid();
+#elif defined(__APPLE__)
+ uint64_t tid;
+ pthread_threadid_np(NULL, &tid);
+ return tid;
+#elif defined(__linux__)
+ return syscall(__NR_gettid);
+#elif defined(_WIN32)
+ return GetCurrentThreadId();
+#endif
+}
+
+void __android_log_stderr_logger(const struct __android_logger_data* logger_data,
+ const char* message) {
+ struct tm now;
+ time_t t = time(nullptr);
+
+#if defined(_WIN32)
+ localtime_s(&now, &t);
+#else
+ localtime_r(&t, &now);
+#endif
+
+ char timestamp[32];
+ strftime(timestamp, sizeof(timestamp), "%m-%d %H:%M:%S", &now);
+
+ 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");
+ int priority =
+ logger_data->priority > ANDROID_LOG_SILENT ? ANDROID_LOG_FATAL : logger_data->priority;
+ char priority_char = log_characters[priority];
+ uint64_t tid = GetThreadId();
+
+ if (logger_data->file != nullptr) {
+ fprintf(stderr, "%s %c %s %5d %5" PRIu64 " %s:%u] %s\n",
+ logger_data->tag ? logger_data->tag : "nullptr", priority_char, timestamp, getpid(),
+ tid, logger_data->file, logger_data->line, message);
+ } else {
+ fprintf(stderr, "%s %c %s %5d %5" PRIu64 " %s\n",
+ logger_data->tag ? logger_data->tag : "nullptr", priority_char, timestamp, getpid(),
+ tid, message);
+ }
+}
+
+void __android_log_logd_logger(const struct __android_logger_data* logger_data,
+ const char* message) {
+ int buffer_id = logger_data->buffer_id == LOG_ID_DEFAULT ? LOG_ID_MAIN : logger_data->buffer_id;
+
+ struct iovec vec[3];
+ vec[0].iov_base =
+ const_cast<unsigned char*>(reinterpret_cast<const unsigned char*>(&logger_data->priority));
+ vec[0].iov_len = 1;
+ vec[1].iov_base = const_cast<void*>(static_cast<const void*>(logger_data->tag));
+ vec[1].iov_len = strlen(logger_data->tag) + 1;
+ vec[2].iov_base = const_cast<void*>(static_cast<const void*>(message));
+ vec[2].iov_len = strlen(message) + 1;
+
+ write_to_log(static_cast<log_id_t>(buffer_id), vec, 3);
+}
int __android_log_write(int prio, const char* tag, const char* msg) {
return __android_log_buf_write(LOG_ID_MAIN, prio, tag, msg);
}
-int __android_log_buf_write(int bufID, int prio, const char* tag, const char* msg) {
- if (!tag) tag = "";
+void __android_log_write_logger_data(__android_logger_data* logger_data, const char* msg) {
+ if (logger_data->tag == nullptr) logger_data->tag = "";
#if __BIONIC__
- if (prio == ANDROID_LOG_FATAL) {
+ if (logger_data->priority == ANDROID_LOG_FATAL) {
android_set_abort_message(msg);
}
#endif
- struct iovec vec[3];
- vec[0].iov_base = (unsigned char*)&prio;
- vec[0].iov_len = 1;
- vec[1].iov_base = (void*)tag;
- vec[1].iov_len = strlen(tag) + 1;
- vec[2].iov_base = (void*)msg;
- vec[2].iov_len = strlen(msg) + 1;
+ auto lock = std::shared_lock{logger_function_lock};
+ logger_function(logger_data, msg);
+}
- return write_to_log(static_cast<log_id_t>(bufID), vec, 3);
+int __android_log_buf_write(int bufID, int prio, const char* tag, const char* msg) {
+ __android_logger_data logger_data = {sizeof(__android_logger_data), bufID, prio, tag, nullptr, 0};
+ __android_log_write_logger_data(&logger_data, msg);
+ return 1;
}
int __android_log_vprint(int prio, const char* tag, const char* fmt, va_list ap) {
@@ -239,8 +341,8 @@
TEMP_FAILURE_RETRY(write(2, "\n", 1));
__android_log_write(ANDROID_LOG_FATAL, tag, buf);
- abort(); /* abort so we have a chance to debug the situation */
- /* NOTREACHED */
+ __android_log_call_aborter(buf);
+ abort();
}
int __android_log_bwrite(int32_t tag, const void* payload, size_t len) {
diff --git a/liblog/tests/Android.bp b/liblog/tests/Android.bp
index f58c524..3288954 100644
--- a/liblog/tests/Android.bp
+++ b/liblog/tests/Android.bp
@@ -54,6 +54,7 @@
],
srcs: [
"libc_test.cpp",
+ "liblog_global_state.cpp",
"liblog_test.cpp",
"log_id_test.cpp",
"log_radio_test.cpp",
diff --git a/liblog/tests/liblog_global_state.cpp b/liblog/tests/liblog_global_state.cpp
new file mode 100644
index 0000000..23e8758
--- /dev/null
+++ b/liblog/tests/liblog_global_state.cpp
@@ -0,0 +1,155 @@
+/*
+ * Copyright (C) 2020 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.
+ */
+
+#define LOG_TAG "global_state_test_tag"
+
+#include <android-base/file.h>
+#include <android-base/logging.h>
+#include <android/log.h>
+
+#include <gtest/gtest.h>
+
+TEST(liblog_global_state, libbase_logs_with_libbase_SetLogger) {
+ using namespace android::base;
+ bool message_seen = false;
+ LogSeverity expected_severity = WARNING;
+ std::string expected_file = Basename(__FILE__);
+ unsigned int expected_line;
+ std::string expected_message = "libbase test message";
+
+ auto LoggerFunction = [&](LogId log_id, LogSeverity severity, const char* tag, const char* file,
+ unsigned int line, const char* message) {
+ message_seen = true;
+ EXPECT_EQ(DEFAULT, log_id);
+ EXPECT_EQ(expected_severity, severity);
+ EXPECT_STREQ(LOG_TAG, tag);
+ EXPECT_EQ(expected_file, file);
+ EXPECT_EQ(expected_line, line);
+ EXPECT_EQ(expected_message, message);
+ };
+
+ SetLogger(LoggerFunction);
+
+ expected_line = __LINE__ + 1;
+ LOG(expected_severity) << expected_message;
+ EXPECT_TRUE(message_seen);
+}
+
+TEST(liblog_global_state, libbase_logs_with_liblog_set_logger) {
+ using namespace android::base;
+ // These must be static since they're used by the liblog logger function, which only accepts
+ // lambdas without captures. The items used by the libbase logger are explicitly not static, to
+ // ensure that lambdas with captures do work there.
+ static bool message_seen = false;
+ static std::string expected_file = Basename(__FILE__);
+ static unsigned int expected_line;
+ static std::string expected_message = "libbase test message";
+
+ auto liblog_logger_function = [](const struct __android_logger_data* logger_data,
+ const char* message) {
+ message_seen = true;
+ EXPECT_EQ(sizeof(__android_logger_data), logger_data->struct_size);
+ EXPECT_EQ(LOG_ID_DEFAULT, logger_data->buffer_id);
+ EXPECT_EQ(ANDROID_LOG_WARN, logger_data->priority);
+ EXPECT_STREQ(LOG_TAG, logger_data->tag);
+ EXPECT_EQ(expected_file, logger_data->file);
+ EXPECT_EQ(expected_line, logger_data->line);
+ EXPECT_EQ(expected_message, message);
+ };
+
+ __android_log_set_logger(liblog_logger_function);
+
+ expected_line = __LINE__ + 1;
+ LOG(WARNING) << expected_message;
+ EXPECT_TRUE(message_seen);
+}
+
+TEST(liblog_global_state, liblog_logs_with_libbase_SetLogger) {
+ using namespace android::base;
+ bool message_seen = false;
+ std::string expected_message = "libbase test message";
+
+ auto LoggerFunction = [&](LogId log_id, LogSeverity severity, const char* tag, const char* file,
+ unsigned int line, const char* message) {
+ message_seen = true;
+ EXPECT_EQ(MAIN, log_id);
+ EXPECT_EQ(WARNING, severity);
+ EXPECT_STREQ(LOG_TAG, tag);
+ EXPECT_EQ(nullptr, file);
+ EXPECT_EQ(0U, line);
+ EXPECT_EQ(expected_message, message);
+ };
+
+ SetLogger(LoggerFunction);
+
+ __android_log_buf_write(LOG_ID_MAIN, ANDROID_LOG_WARN, LOG_TAG, expected_message.c_str());
+ EXPECT_TRUE(message_seen);
+ message_seen = false;
+}
+
+TEST(liblog_global_state, liblog_logs_with_liblog_set_logger) {
+ using namespace android::base;
+ // These must be static since they're used by the liblog logger function, which only accepts
+ // lambdas without captures. The items used by the libbase logger are explicitly not static, to
+ // ensure that lambdas with captures do work there.
+ static bool message_seen = false;
+ static int expected_buffer_id = LOG_ID_MAIN;
+ static int expected_priority = ANDROID_LOG_WARN;
+ static std::string expected_message = "libbase test message";
+
+ auto liblog_logger_function = [](const struct __android_logger_data* logger_data,
+ const char* message) {
+ message_seen = true;
+ EXPECT_EQ(sizeof(__android_logger_data), logger_data->struct_size);
+ EXPECT_EQ(expected_buffer_id, logger_data->buffer_id);
+ EXPECT_EQ(expected_priority, logger_data->priority);
+ EXPECT_STREQ(LOG_TAG, logger_data->tag);
+ EXPECT_STREQ(nullptr, logger_data->file);
+ EXPECT_EQ(0U, logger_data->line);
+ EXPECT_EQ(expected_message, message);
+ };
+
+ __android_log_set_logger(liblog_logger_function);
+
+ __android_log_buf_write(expected_buffer_id, expected_priority, LOG_TAG, expected_message.c_str());
+ EXPECT_TRUE(message_seen);
+}
+
+TEST(liblog_global_state, SetAborter_with_liblog) {
+ using namespace android::base;
+
+ std::string expected_message = "libbase test message";
+ static bool message_seen = false;
+ auto aborter_function = [&](const char* message) {
+ message_seen = true;
+ EXPECT_EQ(expected_message, message);
+ };
+
+ SetAborter(aborter_function);
+ LOG(FATAL) << expected_message;
+ EXPECT_TRUE(message_seen);
+ message_seen = false;
+
+ static std::string expected_message_static = "libbase test message";
+ auto liblog_aborter_function = [](const char* message) {
+ message_seen = true;
+ EXPECT_EQ(expected_message_static, message);
+ };
+ __android_log_set_aborter(liblog_aborter_function);
+ LOG(FATAL) << expected_message_static;
+ EXPECT_TRUE(message_seen);
+ message_seen = false;
+}
diff --git a/liblog/tests/liblog_test.cpp b/liblog/tests/liblog_test.cpp
index c402e20..9cae702 100644
--- a/liblog/tests/liblog_test.cpp
+++ b/liblog/tests/liblog_test.cpp
@@ -1074,7 +1074,6 @@
// Once we've found our expected entry, break.
if (len == LOGGER_ENTRY_MAX_PAYLOAD - sizeof(big_payload_tag)) {
- EXPECT_EQ(ret, len + static_cast<ssize_t>(sizeof(big_payload_tag)));
*found = true;
}
};