logging: update from upstream
Followed instructions from go/nnapi-dep-instructions.
Deleted extra OWNERS files to fix CQ
$ git merge cros/upstream/master --no-ff
$ repo upload --cbr . --no-verify
BUG=b:197814725
TEST=FEATURES=test emerge-amd64-generic nnapi aosp-frameworks-ml-nn
Exempt-From-Owner-Approval: This is a forked repo
Change-Id: I18ad40d0171cee558dc36f6a4b0646db6ae03123
diff --git a/TEST_MAPPING b/TEST_MAPPING
index 5e72035..1a9c2e0 100644
--- a/TEST_MAPPING
+++ b/TEST_MAPPING
@@ -7,12 +7,7 @@
"name": "CtsLogdTestCases"
},
{
- "name": "liblog-host-test",
- "host": true
- },
- {
- "name": "logd-unit-tests",
- "host": true
+ "name": "MicrodroidHostTestCases"
}
]
}
diff --git a/liblog/Android.bp b/liblog/Android.bp
index 32bdde0..bf89903 100644
--- a/liblog/Android.bp
+++ b/liblog/Android.bp
@@ -14,6 +14,22 @@
// limitations under the License.
//
+package {
+ default_applicable_licenses: ["system_logging_liblog_license"],
+}
+
+// Added automatically by a large-scale-change
+license {
+ name: "system_logging_liblog_license",
+ visibility: [":__subpackages__"],
+ license_kinds: [
+ "SPDX-license-identifier-Apache-2.0",
+ ],
+ license_text: [
+ "NOTICE",
+ ],
+}
+
liblog_sources = [
"log_event_list.cpp",
"log_event_write.cpp",
@@ -75,7 +91,10 @@
vendor_ramdisk_available: true,
recovery_available: true,
native_bridge_supported: true,
- llndk_stubs: "liblog.llndk",
+ llndk: {
+ symbol_file: "liblog.map.txt",
+ override_export_include_dirs: ["include_vndk"],
+ },
srcs: liblog_sources,
target: {
@@ -119,6 +138,7 @@
"-Wall",
"-Werror",
"-Wextra",
+ "-Wexit-time-destructors",
// This is what we want to do:
// liblog_cflags := $(shell \
// sed -n \
@@ -159,9 +179,30 @@
unversioned_until: "current",
}
-llndk_library {
- name: "liblog.llndk",
- native_bridge_supported: true,
- symbol_file: "liblog.map.txt",
- export_include_dirs: ["include_vndk"],
+rust_bindgen {
+ name: "liblog_event_list_bindgen",
+ wrapper_src: "rust/liblog_wrapper.h",
+ crate_name: "log_event_list_bindgen",
+ source_stem: "bindings",
+
+ bindgen_flags: [
+ "--size_t-is-usize",
+ "--allowlist-function=create_android_logger",
+ "--allowlist-function=android_log_destroy",
+ "--allowlist-function=android_log_write_int32",
+ "--allowlist-function=android_log_write_string8_len",
+ "--allowlist-function=android_log_write_list",
+ "--allowlist-function=__android_log_security",
+ "--allowlist-type=log_id",
+ ],
+}
+
+rust_test {
+ name: "liblog_event_list_bindgen_test",
+ srcs: [":liblog_event_list_bindgen"],
+ crate_name: "log_event_list_bindgen_test",
+ test_suites: ["general-tests"],
+ auto_gen_config: true,
+ clippy_lints: "none",
+ lints: "none",
}
diff --git a/liblog/include/android/log.h b/liblog/include/android/log.h
index 8a0ebf2..5dc365a 100644
--- a/liblog/include/android/log.h
+++ b/liblog/include/android/log.h
@@ -217,7 +217,6 @@
*/
typedef void (*__android_aborter_function)(const char* abort_message);
-#if !defined(__ANDROID__) || __ANDROID_API__ >= 30
/**
* Writes the log message specified by log_message. log_message includes additional file name and
* line number information that a logger may use. log_message is versioned for backwards
@@ -371,7 +370,6 @@
* Available since API level 30.
*/
void __android_log_set_default_tag(const char* tag) __INTRODUCED_IN(30);
-#endif
#ifdef __cplusplus
}
diff --git a/liblog/include/log/log_main.h b/liblog/include/log/log_main.h
index 1bd1c8a..799a8e2 100644
--- a/liblog/include/log/log_main.h
+++ b/liblog/include/log/log_main.h
@@ -364,13 +364,11 @@
int __android_log_is_loggable_len(int prio, const char* tag, size_t len, int default_prio);
#if LOG_NDEBUG /* Production */
-#define android_testLog(prio, tag) \
- (__android_log_is_loggable_len(prio, tag, ((tag) && *(tag)) ? strlen(tag) : 0, \
- ANDROID_LOG_DEBUG) != 0)
+#define android_testLog(prio, tag) \
+ (__android_log_is_loggable_len(prio, tag, (tag) ? strlen(tag) : 0, ANDROID_LOG_DEBUG) != 0)
#else
-#define android_testLog(prio, tag) \
- (__android_log_is_loggable_len(prio, tag, ((tag) && *(tag)) ? strlen(tag) : 0, \
- ANDROID_LOG_VERBOSE) != 0)
+#define android_testLog(prio, tag) \
+ (__android_log_is_loggable_len(prio, tag, (tag) ? strlen(tag) : 0, ANDROID_LOG_VERBOSE) != 0)
#endif
#if defined(__clang__)
diff --git a/liblog/logger_write.cpp b/liblog/logger_write.cpp
index 22c7eca..08ab6e2 100644
--- a/liblog/logger_write.cpp
+++ b/liblog/logger_write.cpp
@@ -108,11 +108,10 @@
#endif
}
-#if defined(__GLIBC__) || defined(_WIN32)
+// BSD-based systems like Android/macOS have getprogname(). Others need us to provide one.
+#if !defined(__APPLE__) && !defined(__BIONIC__)
static const char* getprogname() {
-#if defined(__GLIBC__)
- return program_invocation_short_name;
-#elif defined(_WIN32)
+#ifdef _WIN32
static bool first = true;
static char progname[MAX_PATH] = {};
@@ -129,16 +128,18 @@
}
return progname;
+#else
+ return program_invocation_short_name;
#endif
}
#endif
// It's possible for logging to happen during static initialization before our globals are
// initialized, so we place this std::string in a function such that it is initialized on the first
-// call.
+// call. We use a pointer to avoid exit time destructors.
std::string& GetDefaultTag() {
- static std::string default_tag = getprogname();
- return default_tag;
+ static std::string* default_tag = new std::string(getprogname());
+ return *default_tag;
}
void __android_log_set_default_tag(const char* tag) {
@@ -267,7 +268,7 @@
log_message->tag ? log_message->tag : "nullptr", priority_char, timestamp, getpid(),
tid, log_message->file, log_message->line, log_message->message);
} else {
- fprintf(stderr, "%s %c %s %5d %5" PRIu64 " %s\n",
+ fprintf(stderr, "%s %c %s %5d %5" PRIu64 "] %s\n",
log_message->tag ? log_message->tag : "nullptr", priority_char, timestamp, getpid(),
tid, log_message->message);
}
diff --git a/liblog/logprint.cpp b/liblog/logprint.cpp
index a5c5edd..639b8d9 100644
--- a/liblog/logprint.cpp
+++ b/liblog/logprint.cpp
@@ -15,10 +15,6 @@
** limitations under the License.
*/
-#ifndef __MINGW32__
-#define HAVE_STRSEP
-#endif
-
#include <log/logprint.h>
#include <assert.h>
@@ -38,6 +34,8 @@
#include <cutils/list.h>
+#include <algorithm>
+
#include <log/log.h>
#include <log/log_read.h>
#include <private/android_logger.h>
@@ -45,10 +43,6 @@
#define MS_PER_NSEC 1000000
#define US_PER_NSEC 1000
-#ifndef MIN
-#define MIN(a, b) (((a) < (b)) ? (a) : (b))
-#endif
-
typedef struct FilterInfo_t {
char* mTag;
android_LogPriority mPri;
@@ -292,72 +286,71 @@
return 1;
}
-#ifndef __MINGW32__
-static const char tz[] = "TZ";
-static const char utc[] = "UTC";
+#if !defined(__MINGW32__)
+// Sets $TZ, but allows it to be optionally reset.
+class TzSetter {
+ public:
+ TzSetter(const char* new_tz) {
+ old_tz_ = getenv("TZ");
+ if (old_tz_) old_tz_ = strdup(old_tz_);
+
+ setenv("TZ", new_tz, 1);
+ tzset();
+ }
+
+ ~TzSetter() { free(old_tz_); }
+
+ void Reset() {
+ if (old_tz_) {
+ setenv("TZ", old_tz_, 1);
+ } else {
+ unsetenv("TZ");
+ }
+ tzset();
+ }
+
+ private:
+ char* old_tz_;
+};
#endif
-/**
- * Returns FORMAT_OFF on invalid string
- */
AndroidLogPrintFormat android_log_formatFromString(const char* formatString) {
- static AndroidLogPrintFormat format;
-
/* clang-format off */
- if (!strcmp(formatString, "brief")) format = FORMAT_BRIEF;
- else if (!strcmp(formatString, "process")) format = FORMAT_PROCESS;
- else if (!strcmp(formatString, "tag")) format = FORMAT_TAG;
- else if (!strcmp(formatString, "thread")) format = FORMAT_THREAD;
- else if (!strcmp(formatString, "raw")) format = FORMAT_RAW;
- else if (!strcmp(formatString, "time")) format = FORMAT_TIME;
- else if (!strcmp(formatString, "threadtime")) format = FORMAT_THREADTIME;
- else if (!strcmp(formatString, "long")) format = FORMAT_LONG;
- else if (!strcmp(formatString, "color")) format = FORMAT_MODIFIER_COLOR;
- else if (!strcmp(formatString, "colour")) format = FORMAT_MODIFIER_COLOR;
- else if (!strcmp(formatString, "usec")) format = FORMAT_MODIFIER_TIME_USEC;
- else if (!strcmp(formatString, "nsec")) format = FORMAT_MODIFIER_TIME_NSEC;
- else if (!strcmp(formatString, "printable")) format = FORMAT_MODIFIER_PRINTABLE;
- else if (!strcmp(formatString, "year")) format = FORMAT_MODIFIER_YEAR;
- else if (!strcmp(formatString, "zone")) format = FORMAT_MODIFIER_ZONE;
- else if (!strcmp(formatString, "epoch")) format = FORMAT_MODIFIER_EPOCH;
- else if (!strcmp(formatString, "monotonic")) format = FORMAT_MODIFIER_MONOTONIC;
- else if (!strcmp(formatString, "uid")) format = FORMAT_MODIFIER_UID;
- else if (!strcmp(formatString, "descriptive")) format = FORMAT_MODIFIER_DESCRIPT;
+ if (!strcmp(formatString, "brief")) return FORMAT_BRIEF;
+ if (!strcmp(formatString, "process")) return FORMAT_PROCESS;
+ if (!strcmp(formatString, "tag")) return FORMAT_TAG;
+ if (!strcmp(formatString, "thread")) return FORMAT_THREAD;
+ if (!strcmp(formatString, "raw")) return FORMAT_RAW;
+ if (!strcmp(formatString, "time")) return FORMAT_TIME;
+ if (!strcmp(formatString, "threadtime")) return FORMAT_THREADTIME;
+ if (!strcmp(formatString, "long")) return FORMAT_LONG;
+ if (!strcmp(formatString, "color")) return FORMAT_MODIFIER_COLOR;
+ if (!strcmp(formatString, "colour")) return FORMAT_MODIFIER_COLOR;
+ if (!strcmp(formatString, "usec")) return FORMAT_MODIFIER_TIME_USEC;
+ if (!strcmp(formatString, "nsec")) return FORMAT_MODIFIER_TIME_NSEC;
+ if (!strcmp(formatString, "printable")) return FORMAT_MODIFIER_PRINTABLE;
+ if (!strcmp(formatString, "year")) return FORMAT_MODIFIER_YEAR;
+ if (!strcmp(formatString, "zone")) return FORMAT_MODIFIER_ZONE;
+ if (!strcmp(formatString, "epoch")) return FORMAT_MODIFIER_EPOCH;
+ if (!strcmp(formatString, "monotonic")) return FORMAT_MODIFIER_MONOTONIC;
+ if (!strcmp(formatString, "uid")) return FORMAT_MODIFIER_UID;
+ if (!strcmp(formatString, "descriptive")) return FORMAT_MODIFIER_DESCRIPT;
/* clang-format on */
-#ifndef __MINGW32__
- else {
- extern char* tzname[2];
- static const char gmt[] = "GMT";
- char* cp = getenv(tz);
- if (cp) {
- cp = strdup(cp);
- }
- setenv(tz, formatString, 1);
- /*
- * Run tzset here to determine if the timezone is legitimate. If the
- * zone is GMT, check if that is what was asked for, if not then
- * did not match any on the system; report an error to caller.
- */
- tzset();
- if (!tzname[0] ||
- ((!strcmp(tzname[0], utc) || !strcmp(tzname[0], gmt)) /* error? */
- && strcasecmp(formatString, utc) && strcasecmp(formatString, gmt))) { /* ok */
- if (cp) {
- setenv(tz, cp, 1);
- } else {
- unsetenv(tz);
- }
- tzset();
- format = FORMAT_OFF;
- } else {
- format = FORMAT_MODIFIER_ZONE;
- }
- free(cp);
+#if !defined(__MINGW32__)
+ // Check whether the format string is actually a time zone. If tzname[0]
+ // is the empty string, that's tzset() signalling that it doesn't know
+ // the requested timezone.
+ TzSetter tz(formatString);
+ if (!*tzname[0]) {
+ tz.Reset();
+ } else {
+ // We keep the new time zone as a side effect!
+ return FORMAT_MODIFIER_ZONE;
}
#endif
- return format;
+ return FORMAT_OFF;
}
/**
@@ -433,8 +426,7 @@
return -1;
}
-#ifndef HAVE_STRSEP
-/* KISS replacement helper for below */
+#if defined(__MINGW32__) // Windows doesn't have strsep(3).
static char* strsep(char** stringp, const char* delim) {
char* token;
char* ret = *stringp;
@@ -1282,17 +1274,9 @@
if (!cp) {
continue;
}
- cp = getenv(tz);
- if (cp) {
- cp = strdup(cp);
- }
- setenv(tz, utc, 1);
- time.tv_sec = mktime(&tm);
- if (cp) {
- setenv(tz, cp, 1);
- free(cp);
- } else {
- unsetenv(tz);
+ {
+ TzSetter tz(cp);
+ time.tv_sec = mktime(&tm);
}
list = static_cast<conversionList*>(calloc(1, sizeof(conversionList)));
list_init(&list->node);
@@ -1503,7 +1487,7 @@
if (p_format->colored_output) {
prefixLen =
snprintf(prefixBuf, sizeof(prefixBuf), "\x1B[%dm", colorFromPri(entry->priority));
- prefixLen = MIN(prefixLen, sizeof(prefixBuf));
+ prefixLen = std::min(prefixLen, sizeof(prefixBuf));
const char suffixContents[] = "\x1B[0m";
strcpy(suffixBuf, suffixContents);
@@ -1543,7 +1527,7 @@
case FORMAT_PROCESS:
len = snprintf(suffixBuf + suffixLen, sizeof(suffixBuf) - suffixLen, " (%.*s)\n",
(int)entry->tagLen, entry->tag);
- suffixLen += MIN(len, sizeof(suffixBuf) - suffixLen);
+ suffixLen += std::min(len, sizeof(suffixBuf) - suffixLen);
len = snprintf(prefixBuf + prefixLen, sizeof(prefixBuf) - prefixLen, "%c(%s%5d) ", priChar,
uid, entry->pid);
break;
diff --git a/liblog/properties.cpp b/liblog/properties.cpp
index 88f0bf1..bd5f5e7 100644
--- a/liblog/properties.cpp
+++ b/liblog/properties.cpp
@@ -24,6 +24,8 @@
#include <algorithm>
+#include <android-base/macros.h>
+
#include <private/android_logger.h>
#include "logger_write.h"
@@ -34,7 +36,7 @@
static pthread_mutex_t lock_loggable = PTHREAD_MUTEX_INITIALIZER;
-static int lock() {
+static bool trylock() {
/*
* If we trigger a signal handler in the middle of locked activity and the
* signal handler logs a message, we could get into a deadlock state.
@@ -44,7 +46,7 @@
* in less time than the system call associated with a mutex to deal with
* the contention.
*/
- return pthread_mutex_trylock(&lock_loggable);
+ return pthread_mutex_trylock(&lock_loggable) == 0;
}
static void unlock() {
@@ -93,22 +95,13 @@
}
}
-static int __android_log_level(const char* tag, size_t len) {
- /* sizeof() is used on this array below */
- static const char log_namespace[] = "persist.log.tag.";
- static const size_t base_offset = 8; /* skip "persist." */
-
- if (tag == nullptr || len == 0) {
+static int __android_log_level(const char* tag, size_t tag_len) {
+ if (tag == nullptr || tag_len == 0) {
auto& tag_string = GetDefaultTag();
tag = tag_string.c_str();
- len = tag_string.size();
+ tag_len = tag_string.size();
}
- /* sizeof(log_namespace) = strlen(log_namespace) + 1 */
- char key[sizeof(log_namespace) + len];
- char* kp;
- size_t i;
- char c = 0;
/*
* Single layer cache of four properties. Priorities are:
* log.tag.<tag>
@@ -118,95 +111,73 @@
* Where the missing tag matches all tags and becomes the
* system global default. We do not support ro.log.tag* .
*/
- static char* last_tag;
- static size_t last_tag_len;
+ static std::string* last_tag = new std::string;
static uint32_t global_serial;
- /* some compilers erroneously see uninitialized use. !not_locked */
- uint32_t current_global_serial = 0;
- static struct cache_char tag_cache[2];
- static struct cache_char global_cache[2];
- int change_detected;
- int global_change_detected;
- int not_locked;
+ uint32_t current_global_serial;
+ static cache_char tag_cache[2];
+ static cache_char global_cache[2];
+ static const char* log_namespace = "persist.log.tag.";
+ char key[strlen(log_namespace) + tag_len + 1];
strcpy(key, log_namespace);
- global_change_detected = change_detected = not_locked = lock();
+ bool locked = trylock();
+ bool change_detected, global_change_detected;
+ global_change_detected = change_detected = !locked;
- if (!not_locked) {
- /*
- * check all known serial numbers to changes.
- */
- for (i = 0; i < (sizeof(tag_cache) / sizeof(tag_cache[0])); ++i) {
+ char c = 0;
+ if (locked) {
+ // Check all known serial numbers for changes.
+ for (size_t i = 0; i < arraysize(tag_cache); ++i) {
if (check_cache(&tag_cache[i].cache)) {
- change_detected = 1;
+ change_detected = true;
}
}
- for (i = 0; i < (sizeof(global_cache) / sizeof(global_cache[0])); ++i) {
+ for (size_t i = 0; i < arraysize(global_cache); ++i) {
if (check_cache(&global_cache[i].cache)) {
- global_change_detected = 1;
+ global_change_detected = true;
}
}
current_global_serial = __system_property_area_serial();
if (current_global_serial != global_serial) {
- change_detected = 1;
- global_change_detected = 1;
+ global_change_detected = change_detected = true;
}
}
- if (len) {
- int local_change_detected = change_detected;
- if (!not_locked) {
- if (!last_tag || !last_tag[0] || (last_tag[0] != tag[0]) ||
- strncmp(last_tag + 1, tag + 1, last_tag_len - 1)) {
- /* invalidate log.tag.<tag> cache */
- for (i = 0; i < (sizeof(tag_cache) / sizeof(tag_cache[0])); ++i) {
+ if (tag_len != 0) {
+ bool local_change_detected = change_detected;
+ if (locked) {
+ // compare() rather than == because tag isn't guaranteed 0-terminated.
+ if (last_tag->compare(0, last_tag->size(), tag, tag_len) != 0) {
+ // Invalidate log.tag.<tag> cache.
+ for (size_t i = 0; i < arraysize(tag_cache); ++i) {
tag_cache[i].cache.pinfo = NULL;
tag_cache[i].c = '\0';
}
- if (last_tag) last_tag[0] = '\0';
- local_change_detected = 1;
- }
- if (!last_tag || !last_tag[0]) {
- if (!last_tag) {
- last_tag = static_cast<char*>(calloc(1, len + 1));
- last_tag_len = 0;
- if (last_tag) last_tag_len = len + 1;
- } else if (len >= last_tag_len) {
- last_tag = static_cast<char*>(realloc(last_tag, len + 1));
- last_tag_len = 0;
- if (last_tag) last_tag_len = len + 1;
- }
- if (last_tag) {
- strncpy(last_tag, tag, len);
- last_tag[len] = '\0';
- }
+ last_tag->assign(tag, tag_len);
+ local_change_detected = true;
}
}
- strncpy(key + sizeof(log_namespace) - 1, tag, len);
- key[sizeof(log_namespace) - 1 + len] = '\0';
+ *stpncpy(key + strlen(log_namespace), tag, tag_len) = '\0';
- kp = key;
- for (i = 0; i < (sizeof(tag_cache) / sizeof(tag_cache[0])); ++i) {
- struct cache_char* cache = &tag_cache[i];
- struct cache_char temp_cache;
+ for (size_t i = 0; i < arraysize(tag_cache); ++i) {
+ cache_char* cache = &tag_cache[i];
+ cache_char temp_cache;
- if (not_locked) {
+ if (!locked) {
temp_cache.cache.pinfo = NULL;
temp_cache.c = '\0';
cache = &temp_cache;
}
if (local_change_detected) {
- refresh_cache(cache, kp);
+ refresh_cache(cache, i == 0 ? key : key + strlen("persist."));
}
if (cache->c) {
c = cache->c;
break;
}
-
- kp = key + base_offset;
}
}
@@ -223,36 +194,33 @@
break;
default:
/* clear '.' after log.tag */
- key[sizeof(log_namespace) - 2] = '\0';
+ key[strlen(log_namespace) - 1] = '\0';
- kp = key;
- for (i = 0; i < (sizeof(global_cache) / sizeof(global_cache[0])); ++i) {
- struct cache_char* cache = &global_cache[i];
- struct cache_char temp_cache;
+ for (size_t i = 0; i < arraysize(global_cache); ++i) {
+ cache_char* cache = &global_cache[i];
+ cache_char temp_cache;
- if (not_locked) {
+ if (!locked) {
temp_cache = *cache;
- if (temp_cache.cache.pinfo != cache->cache.pinfo) { /* check atomic */
+ if (temp_cache.cache.pinfo != cache->cache.pinfo) { // check atomic
temp_cache.cache.pinfo = NULL;
temp_cache.c = '\0';
}
cache = &temp_cache;
}
if (global_change_detected) {
- refresh_cache(cache, kp);
+ refresh_cache(cache, i == 0 ? key : key + strlen("persist."));
}
if (cache->c) {
c = cache->c;
break;
}
-
- kp = key + base_offset;
}
break;
}
- if (!not_locked) {
+ if (locked) {
global_serial = current_global_serial;
unlock();
}
diff --git a/liblog/rust/liblog_wrapper.h b/liblog/rust/liblog_wrapper.h
new file mode 100644
index 0000000..e6680fe
--- /dev/null
+++ b/liblog/rust/liblog_wrapper.h
@@ -0,0 +1,4 @@
+#pragma once
+
+#include <log/log_event_list.h>
+#include <private/android_logger.h>
diff --git a/liblog/tests/Android.bp b/liblog/tests/Android.bp
index 7524750..8b07400 100644
--- a/liblog/tests/Android.bp
+++ b/liblog/tests/Android.bp
@@ -20,6 +20,13 @@
// Build benchmarks for the device. Run with:
// adb shell liblog-benchmarks
+package {
+ // A large-scale-change added 'default_applicable_licenses' to import
+ // the below license kinds from "system_logging_liblog_license":
+ // SPDX-license-identifier-Apache-2.0
+ default_applicable_licenses: ["system_logging_liblog_license"],
+}
+
cc_benchmark {
name: "liblog-benchmarks",
cflags: [
@@ -112,7 +119,4 @@
"liblog_global_state.cpp",
],
isolated: true,
- test_suites: [
- "general-tests",
- ],
}
diff --git a/liblog/tests/logprint_test.cpp b/liblog/tests/logprint_test.cpp
index 72e53f9..e13934d 100644
--- a/liblog/tests/logprint_test.cpp
+++ b/liblog/tests/logprint_test.cpp
@@ -29,7 +29,7 @@
auto output_size = convertPrintable(nullptr, input, strlen(input));
EXPECT_EQ(output_size, strlen(input));
- char output[output_size];
+ char output[output_size + 1];
output_size = convertPrintable(output, input, strlen(input));
EXPECT_EQ(output_size, strlen(input));
@@ -43,7 +43,7 @@
auto output_size = convertPrintable(nullptr, input, strlen(input));
EXPECT_EQ(output_size, strlen(expected_output));
- char output[output_size];
+ char output[output_size + 1];
output_size = convertPrintable(output, input, strlen(input));
EXPECT_EQ(output_size, strlen(expected_output));
@@ -55,7 +55,7 @@
auto output_size = convertPrintable(nullptr, input, strlen(input));
EXPECT_EQ(output_size, strlen(input));
- char output[output_size];
+ char output[output_size + 1];
output_size = convertPrintable(output, input, strlen(input));
EXPECT_EQ(output_size, strlen(input));
@@ -69,7 +69,7 @@
auto output_size = convertPrintable(nullptr, input, strlen(input));
EXPECT_EQ(output_size, strlen(expected_output));
- char output[output_size];
+ char output[output_size + 1];
output_size = convertPrintable(output, input, strlen(input));
EXPECT_EQ(output_size, strlen(expected_output));
@@ -85,7 +85,7 @@
auto output_size = convertPrintable(nullptr, input, strlen(input));
EXPECT_EQ(output_size, strlen(expected_output));
- char output[output_size];
+ char output[output_size + 1];
output_size = convertPrintable(output, input, strlen(input));
EXPECT_EQ(output_size, strlen(expected_output));
diff --git a/logcat/Android.bp b/logcat/Android.bp
index 61fba59..13b9c4e 100644
--- a/logcat/Android.bp
+++ b/logcat/Android.bp
@@ -14,6 +14,22 @@
// limitations under the License.
//
+package {
+ default_applicable_licenses: ["system_logging_logcat_license"],
+}
+
+// Added automatically by a large-scale-change
+license {
+ name: "system_logging_logcat_license",
+ visibility: [":__subpackages__"],
+ license_kinds: [
+ "SPDX-license-identifier-Apache-2.0",
+ ],
+ license_text: [
+ "NOTICE",
+ ],
+}
+
cc_defaults {
name: "logcat_defaults",
diff --git a/logcat/logcat.cpp b/logcat/logcat.cpp
index 67ee676..25fda5d 100644
--- a/logcat/logcat.cpp
+++ b/logcat/logcat.cpp
@@ -98,7 +98,7 @@
std::unique_ptr<std::regex> regex_;
size_t max_count_ = 0; // 0 means "infinite"
size_t print_count_ = 0;
- bool print_it_anyways_ = false;
+ bool print_it_anyway_ = false;
// For PrintDividers()
bool print_dividers_ = false;
@@ -215,7 +215,7 @@
std::regex_search(entry.message, entry.message + entry.messageLen, *regex_);
print_count_ += match;
- if (match || print_it_anyways_) {
+ if (match || print_it_anyway_) {
PrintDividers(buf->id(), print_dividers_);
bytesWritten = android_log_printLogLine(logformat_.get(), output_fd_.get(), &entry);
@@ -632,7 +632,7 @@
break;
}
if (long_options[option_index].name == print_str) {
- print_it_anyways_ = true;
+ print_it_anyway_ = true;
break;
}
if (long_options[option_index].name == debug_str) {
@@ -794,91 +794,6 @@
}
break;
- case 'Q':
-#define LOGCAT_FILTER "androidboot.logcat="
-#define CONSOLE_PIPE_OPTION "androidboot.consolepipe="
-#define CONSOLE_OPTION "androidboot.console="
-#define QEMU_PROPERTY "ro.kernel.qemu"
-#define QEMU_CMDLINE "qemu.cmdline"
- // This is a *hidden* option used to start a version of logcat
- // in an emulated device only. It basically looks for
- // androidboot.logcat= on the kernel command line. If
- // something is found, it extracts a log filter and uses it to
- // run the program. The logcat output will go to consolepipe if
- // androiboot.consolepipe (e.g. qemu_pipe) is given, otherwise,
- // it goes to androidboot.console (e.g. tty)
- {
- // if not in emulator, exit quietly
- if (false == android::base::GetBoolProperty(QEMU_PROPERTY, false)) {
- return EXIT_SUCCESS;
- }
-
- std::string cmdline = android::base::GetProperty(QEMU_CMDLINE, "");
- if (cmdline.empty()) {
- android::base::ReadFileToString("/proc/cmdline", &cmdline);
- }
-
- const char* logcatFilter = strstr(cmdline.c_str(), LOGCAT_FILTER);
- // if nothing found or invalid filters, exit quietly
- if (!logcatFilter) {
- return EXIT_SUCCESS;
- }
-
- const char* p = logcatFilter + strlen(LOGCAT_FILTER);
- const char* q = strpbrk(p, " \t\n\r");
- if (!q) q = p + strlen(p);
- forceFilters = std::string(p, q);
-
- // redirect our output to the emulator console pipe or console
- const char* consolePipe =
- strstr(cmdline.c_str(), CONSOLE_PIPE_OPTION);
- const char* console =
- strstr(cmdline.c_str(), CONSOLE_OPTION);
-
- if (consolePipe) {
- p = consolePipe + strlen(CONSOLE_PIPE_OPTION);
- } else if (console) {
- p = console + strlen(CONSOLE_OPTION);
- } else {
- return EXIT_FAILURE;
- }
-
- q = strpbrk(p, " \t\n\r");
- int len = q ? q - p : strlen(p);
- std::string devname = "/dev/" + std::string(p, len);
- std::string pipePurpose("pipe:logcat");
- if (consolePipe) {
- // example: "qemu_pipe,pipe:logcat"
- // upon opening of /dev/qemu_pipe, the "pipe:logcat"
- // string with trailing '\0' should be written to the fd
- size_t pos = devname.find(',');
- if (pos != std::string::npos) {
- pipePurpose = devname.substr(pos + 1);
- devname = devname.substr(0, pos);
- }
- }
-
- fprintf(stderr, "logcat using %s\n", devname.c_str());
-
- int fd = open(devname.c_str(), O_WRONLY | O_CLOEXEC);
- if (fd < 0) {
- break;
- }
-
- if (consolePipe) {
- // need the trailing '\0'
- if (!WriteFully(fd, pipePurpose.c_str(), pipePurpose.size() + 1)) {
- close(fd);
- return EXIT_FAILURE;
- }
- }
- // close output and error channels, replace with console
- dup2(fd, output_fd_.get());
- dup2(fd, STDERR_FILENO);
- close(fd);
- }
- break;
-
case 'S':
printStatistics = true;
break;
@@ -904,7 +819,7 @@
if (max_count_ && got_t) {
error(EXIT_FAILURE, 0, "Cannot use -m (--max-count) and -t together.");
}
- if (print_it_anyways_ && (!regex_ || !max_count_)) {
+ if (print_it_anyway_ && (!regex_ || !max_count_)) {
// One day it would be nice if --print -v color and --regex <expr>
// could play with each other and show regex highlighted content.
fprintf(stderr,
@@ -912,7 +827,7 @@
"--print ignored, to be used in combination with\n"
" "
"--regex <expr> and --max-count <N>\n");
- print_it_anyways_ = false;
+ print_it_anyway_ = false;
}
// If no buffers are specified, default to using these buffers.
diff --git a/logcat/tests/Android.bp b/logcat/tests/Android.bp
index ab84150..e53e282 100644
--- a/logcat/tests/Android.bp
+++ b/logcat/tests/Android.bp
@@ -14,6 +14,13 @@
// limitations under the License.
//
+package {
+ // A large-scale-change added 'default_applicable_licenses' to import
+ // the below license kinds from "system_logging_logcat_license":
+ // SPDX-license-identifier-Apache-2.0
+ default_applicable_licenses: ["system_logging_logcat_license"],
+}
+
cc_defaults {
name: "logcat-tests-defaults",
cflags: [
diff --git a/logcat/tests/logcat_test.cpp b/logcat/tests/logcat_test.cpp
index 735fd94..b835bd5 100644
--- a/logcat/tests/logcat_test.cpp
+++ b/logcat/tests/logcat_test.cpp
@@ -143,8 +143,8 @@
pclose(fp);
- // logcat, liblogcat and logcatd test instances result in the progression
- // of 3, 6 and 9 for our counts as each round is performed.
+ // logcat and logcatd test instances result in the progression
+ // of 3, 6, and 9 for our counts as each round is performed.
EXPECT_GE(count, 3);
EXPECT_LE(count, 9);
EXPECT_EQ(count % 3, 0);
@@ -1673,7 +1673,7 @@
EXPECT_GT(logcatHelpTextSize, 4096UL);
size_t logcatLastHelpTextSize =
commandOutputSize(logcat_executable " -L -h 2>&1");
-#ifdef USING_LOGCAT_EXECUTABLE_DEFAULT // logcat and liblogcat
+#ifdef USING_LOGCAT_EXECUTABLE_DEFAULT
EXPECT_EQ(logcatHelpTextSize, logcatLastHelpTextSize);
#else
// logcatd -L -h prints the help twice, as designed.
diff --git a/logd/Android.bp b/logd/Android.bp
index 63bd505..6f23808 100644
--- a/logd/Android.bp
+++ b/logd/Android.bp
@@ -21,6 +21,10 @@
// event_flag += $(call event_logtags,logd)
// event_flag += $(call event_logtags,tag_def)
// so make sure we do not regret hard-coding it as follows:
+package {
+ default_applicable_licenses: ["Android-Apache-2.0"],
+}
+
event_flag = [
"-DAUDITD_LOG_TAG=1003",
"-DCHATTY_LOG_TAG=1004",
@@ -48,7 +52,6 @@
sanitize: {
cfi: true,
},
- cpp_std: "experimental",
}
cc_library_static {
@@ -150,6 +153,7 @@
"ChattyLogBufferTest.cpp",
"logd_test.cpp",
"LogBufferTest.cpp",
+ "SerializedLogBufferTest.cpp",
"SerializedLogChunkTest.cpp",
"SerializedFlushToStateTest.cpp",
],
diff --git a/logd/LogAudit.cpp b/logd/LogAudit.cpp
index 0e17476..13284cd 100644
--- a/logd/LogAudit.cpp
+++ b/logd/LogAudit.cpp
@@ -40,6 +40,8 @@
#include "LogUtils.h"
#include "libaudit.h"
+using namespace std::string_literals;
+
using android::base::GetBoolProperty;
#define KMSG_PRIORITY(PRI) \
@@ -140,10 +142,10 @@
return "";
}
-void LogAudit::auditParse(const std::string& string, uid_t uid,
- std::string* bug_num) {
+std::string LogAudit::auditParse(const std::string& string, uid_t uid) {
static std::map<std::string, std::string> denial_to_bug =
populateDenialMap();
+ std::string result;
std::string scontext = denialParse(string, ':', "scontext=u:object_r:");
std::string tcontext = denialParse(string, ':', "tcontext=u:object_r:");
std::string tclass = denialParse(string, ' ', "tclass=");
@@ -155,20 +157,18 @@
}
auto search = denial_to_bug.find(scontext + tcontext + tclass);
if (search != denial_to_bug.end()) {
- bug_num->assign(" " + search->second);
- } else {
- bug_num->assign("");
+ result = " bug=" + search->second;
}
// Ensure the uid name is not null before passing it to the bug string.
if (uid >= AID_APP_START && uid <= AID_APP_END) {
char* uidname = android::uidToName(uid);
if (uidname) {
- bug_num->append(" app=");
- bug_num->append(uidname);
+ result.append(" app="s + uidname);
free(uidname);
}
}
+ return result;
}
int LogAudit::logPrint(const char* fmt, ...) {
@@ -222,7 +222,7 @@
static const char log_warning[] = { KMSG_PRIORITY(LOG_WARNING) };
static const char newline[] = "\n";
- auditParse(str, uid, &denial_metadata);
+ denial_metadata = auditParse(str, uid);
iov[0].iov_base = info ? const_cast<char*>(log_info) : const_cast<char*>(log_warning);
iov[0].iov_len = info ? sizeof(log_info) : sizeof(log_warning);
iov[1].iov_base = str;
@@ -256,7 +256,7 @@
size_t str_len = strnlen(str, LOGGER_ENTRY_MAX_PAYLOAD);
if (((fdDmesg < 0) || !initialized) && !hasMetadata(str, str_len))
- auditParse(str, uid, &denial_metadata);
+ denial_metadata = auditParse(str, uid);
str_len = (str_len + denial_metadata.length() <= LOGGER_ENTRY_MAX_PAYLOAD)
? str_len + denial_metadata.length()
: LOGGER_ENTRY_MAX_PAYLOAD;
diff --git a/logd/LogAudit.h b/logd/LogAudit.h
index 181920e..e7dd6b4 100644
--- a/logd/LogAudit.h
+++ b/logd/LogAudit.h
@@ -42,7 +42,7 @@
std::map<std::string, std::string> populateDenialMap();
std::string denialParse(const std::string& denial, char terminator,
const std::string& search_term);
- void auditParse(const std::string& string, uid_t uid, std::string* bug_num);
+ std::string auditParse(const std::string& string, uid_t uid);
int logPrint(const char* fmt, ...)
__attribute__((__format__(__printf__, 2, 3)));
diff --git a/logd/LogKlog.cpp b/logd/LogKlog.cpp
index d6c7d25..ab4f815 100644
--- a/logd/LogKlog.cpp
+++ b/logd/LogKlog.cpp
@@ -367,27 +367,6 @@
if (((ssize_t)strnlen(cp, len) == len) && cp[len]) {
return 0;
}
- // HTC kernels with modified printk "c0 1648 "
- if ((len > 9) && (cp[0] == 'c') && isdigit(cp[1]) &&
- (isdigit(cp[2]) || (cp[2] == ' ')) && (cp[3] == ' ')) {
- bool gotDigit = false;
- int i;
- for (i = 4; i < 9; ++i) {
- if (isdigit(cp[i])) {
- gotDigit = true;
- } else if (gotDigit || (cp[i] != ' ')) {
- break;
- }
- }
- if ((i == 9) && (cp[i] == ' ')) {
- int pid = 0;
- char placeholder;
- if (sscanf(cp + 4, "%d%c", &pid, &placeholder) == 2) {
- buf = cp + 10; // skip-it-all
- return pid;
- }
- }
- }
while (len) {
// Mediatek kernels with modified printk
if (*cp == '[') {
@@ -401,6 +380,25 @@
++cp;
--len;
}
+ if (len > 8 && cp[0] == '[' && cp[7] == ']' && isdigit(cp[6])) {
+ // Linux 5.10 and above, e.g. "[ T1] init: init first stage started!"
+ int i = 5;
+ while (i > 1 && isdigit(cp[i])) {
+ --i;
+ }
+ int pos = i + 1;
+ if (cp[i] != 'T') {
+ return 0;
+ }
+ while (i > 1) {
+ --i;
+ if (cp[i] != ' ') {
+ return 0;
+ }
+ }
+ buf = cp + 8;
+ return atoi(cp + pos);
+ }
return 0;
}
diff --git a/logd/OWNERS b/logd/OWNERS
deleted file mode 100644
index 6f7e4a3..0000000
--- a/logd/OWNERS
+++ /dev/null
@@ -1 +0,0 @@
-cferris@google.com
diff --git a/logd/SerializedLogBuffer.cpp b/logd/SerializedLogBuffer.cpp
index 7446813..0101c17 100644
--- a/logd/SerializedLogBuffer.cpp
+++ b/logd/SerializedLogBuffer.cpp
@@ -27,6 +27,70 @@
#include "LogStatistics.h"
#include "SerializedFlushToState.h"
+static SerializedLogEntry* LogToLogBuffer(std::list<SerializedLogChunk>& log_buffer,
+ size_t max_size, uint64_t sequence, log_time realtime,
+ uid_t uid, pid_t pid, pid_t tid, const char* msg,
+ uint16_t len) {
+ if (log_buffer.empty()) {
+ log_buffer.push_back(SerializedLogChunk(max_size / SerializedLogBuffer::kChunkSizeDivisor));
+ }
+
+ auto total_len = sizeof(SerializedLogEntry) + len;
+ if (!log_buffer.back().CanLog(total_len)) {
+ log_buffer.back().FinishWriting();
+ log_buffer.push_back(SerializedLogChunk(max_size / SerializedLogBuffer::kChunkSizeDivisor));
+ }
+
+ return log_buffer.back().Log(sequence, realtime, uid, pid, tid, msg, len);
+}
+
+// Clear all logs from a particular UID by iterating through all existing logs for a log_id, and
+// write all logs that don't match the UID into a new log buffer, then swapping the log buffers.
+// There is an optimization that chunks are copied as-is until a log message from the UID is found,
+// to ensure that back-to-back clears of the same UID do not require reflowing the entire buffer.
+void ClearLogsByUid(std::list<SerializedLogChunk>& log_buffer, uid_t uid, size_t max_size,
+ log_id_t log_id, LogStatistics* stats) REQUIRES(logd_lock) {
+ bool contains_uid_logs = false;
+ std::list<SerializedLogChunk> new_logs;
+ auto it = log_buffer.begin();
+ while (it != log_buffer.end()) {
+ auto chunk = it++;
+ chunk->NotifyReadersOfPrune(log_id);
+ chunk->IncReaderRefCount();
+
+ if (!contains_uid_logs) {
+ for (const auto& entry : *chunk) {
+ if (entry.uid() == uid) {
+ contains_uid_logs = true;
+ break;
+ }
+ }
+ if (!contains_uid_logs) {
+ chunk->DecReaderRefCount();
+ new_logs.splice(new_logs.end(), log_buffer, chunk);
+ continue;
+ }
+ // We found a UID log, so push a writable chunk to prepare for the next loop.
+ new_logs.push_back(
+ SerializedLogChunk(max_size / SerializedLogBuffer::kChunkSizeDivisor));
+ }
+
+ for (const auto& entry : *chunk) {
+ if (entry.uid() == uid) {
+ if (stats != nullptr) {
+ stats->Subtract(entry.ToLogStatisticsElement(log_id));
+ }
+ } else {
+ LogToLogBuffer(new_logs, max_size, entry.sequence(), entry.realtime(), entry.uid(),
+ entry.pid(), entry.tid(), entry.msg(), entry.msg_len());
+ }
+ }
+ chunk->DecReaderRefCount();
+ log_buffer.erase(chunk);
+ }
+ std::swap(new_logs, log_buffer);
+}
+
SerializedLogBuffer::SerializedLogBuffer(LogReaderList* reader_list, LogTags* tags,
LogStatistics* stats)
: reader_list_(reader_list), tags_(tags), stats_(stats) {
@@ -87,18 +151,8 @@
auto sequence = sequence_.fetch_add(1, std::memory_order_relaxed);
auto lock = std::lock_guard{logd_lock};
-
- if (logs_[log_id].empty()) {
- logs_[log_id].push_back(SerializedLogChunk(max_size_[log_id] / 4));
- }
-
- auto total_len = sizeof(SerializedLogEntry) + len;
- if (!logs_[log_id].back().CanLog(total_len)) {
- logs_[log_id].back().FinishWriting();
- logs_[log_id].push_back(SerializedLogChunk(max_size_[log_id] / 4));
- }
-
- auto entry = logs_[log_id].back().Log(sequence, realtime, uid, pid, tid, msg, len);
+ auto entry = LogToLogBuffer(logs_[log_id], max_size_[log_id], sequence, realtime, uid, pid, tid,
+ msg, len);
stats_->Add(entry->ToLogStatisticsElement(log_id));
MaybePrune(log_id);
@@ -111,7 +165,7 @@
size_t total_size = GetSizeUsed(log_id);
size_t after_size = total_size;
if (total_size > max_size_[log_id]) {
- Prune(log_id, total_size - max_size_[log_id], 0);
+ Prune(log_id, total_size - max_size_[log_id]);
after_size = GetSizeUsed(log_id);
LOG(VERBOSE) << "Pruned Logs from log_id: " << log_id << ", previous size: " << total_size
<< " after size: " << after_size;
@@ -122,16 +176,13 @@
void SerializedLogBuffer::RemoveChunkFromStats(log_id_t log_id, SerializedLogChunk& chunk) {
chunk.IncReaderRefCount();
- int read_offset = 0;
- while (read_offset < chunk.write_offset()) {
- auto* entry = chunk.log_entry(read_offset);
- stats_->Subtract(entry->ToLogStatisticsElement(log_id));
- read_offset += entry->total_len();
+ for (const auto& entry : chunk) {
+ stats_->Subtract(entry.ToLogStatisticsElement(log_id));
}
chunk.DecReaderRefCount();
}
-void SerializedLogBuffer::Prune(log_id_t log_id, size_t bytes_to_free, uid_t uid) {
+void SerializedLogBuffer::Prune(log_id_t log_id, size_t bytes_to_free) {
auto& log_buffer = logs_[log_id];
auto it = log_buffer.begin();
while (it != log_buffer.end()) {
@@ -168,22 +219,28 @@
// Notify them to delete the reference.
it_to_prune->NotifyReadersOfPrune(log_id);
- if (uid != 0) {
- // Reorder the log buffer to remove logs from the given UID. If there are no logs left
- // in the buffer after the removal, delete it.
- if (it_to_prune->ClearUidLogs(uid, log_id, stats_)) {
- log_buffer.erase(it_to_prune);
- }
- } else {
- size_t buffer_size = it_to_prune->PruneSize();
- RemoveChunkFromStats(log_id, *it_to_prune);
- log_buffer.erase(it_to_prune);
- if (buffer_size >= bytes_to_free) {
- return;
- }
- bytes_to_free -= buffer_size;
+ size_t buffer_size = it_to_prune->PruneSize();
+ RemoveChunkFromStats(log_id, *it_to_prune);
+ log_buffer.erase(it_to_prune);
+ if (buffer_size >= bytes_to_free) {
+ return;
+ }
+ bytes_to_free -= buffer_size;
+ }
+}
+
+void SerializedLogBuffer::UidClear(log_id_t log_id, uid_t uid) {
+ // Wake all readers; see comment in Prune().
+ for (const auto& reader_thread : reader_list_->reader_threads()) {
+ if (!reader_thread->IsWatching(log_id)) {
+ continue;
+ }
+
+ if (reader_thread->deadline().time_since_epoch().count() != 0) {
+ reader_thread->TriggerReader();
}
}
+ ClearLogsByUid(logs_[log_id], uid, max_size_[log_id], log_id, stats_);
}
std::unique_ptr<FlushToState> SerializedLogBuffer::CreateFlushToState(uint64_t start,
@@ -243,7 +300,11 @@
bool SerializedLogBuffer::Clear(log_id_t id, uid_t uid) {
auto lock = std::lock_guard{logd_lock};
- Prune(id, ULONG_MAX, uid);
+ if (uid == 0) {
+ Prune(id, ULONG_MAX);
+ } else {
+ UidClear(id, uid);
+ }
// Clearing SerializedLogBuffer never waits for readers and therefore is always successful.
return true;
diff --git a/logd/SerializedLogBuffer.h b/logd/SerializedLogBuffer.h
index 4ce7a3b..ca78c42 100644
--- a/logd/SerializedLogBuffer.h
+++ b/logd/SerializedLogBuffer.h
@@ -36,6 +36,9 @@
class SerializedLogBuffer final : public LogBuffer {
public:
+ // Create SerializedLogChunk's with size = max_size_[log_id] / kChunkSizeDivisor.
+ static constexpr size_t kChunkSizeDivisor = 4;
+
SerializedLogBuffer(LogReaderList* reader_list, LogTags* tags, LogStatistics* stats);
void Init() override;
@@ -57,7 +60,8 @@
private:
bool ShouldLog(log_id_t log_id, const char* msg, uint16_t len);
void MaybePrune(log_id_t log_id) REQUIRES(logd_lock);
- void Prune(log_id_t log_id, size_t bytes_to_free, uid_t uid) REQUIRES(logd_lock);
+ void Prune(log_id_t log_id, size_t bytes_to_free) REQUIRES(logd_lock);
+ void UidClear(log_id_t log_id, uid_t uid) REQUIRES(logd_lock);
void RemoveChunkFromStats(log_id_t log_id, SerializedLogChunk& chunk);
size_t GetSizeUsed(log_id_t id) REQUIRES(logd_lock);
@@ -70,3 +74,7 @@
std::atomic<uint64_t> sequence_ = 1;
};
+
+// Exposed for testing.
+void ClearLogsByUid(std::list<SerializedLogChunk>& log_buffer, uid_t uid, size_t max_size,
+ log_id_t log_id, LogStatistics* stats);
\ No newline at end of file
diff --git a/logd/SerializedLogBufferTest.cpp b/logd/SerializedLogBufferTest.cpp
new file mode 100644
index 0000000..dbbe2f2
--- /dev/null
+++ b/logd/SerializedLogBufferTest.cpp
@@ -0,0 +1,398 @@
+/*
+ * Copyright (C) 2021 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.
+ */
+
+#include "SerializedLogBuffer.h"
+
+#include <gtest/gtest.h>
+#include <log/log.h>
+
+#include "LogReaderList.h"
+#include "LogSize.h"
+#include "LogStatistics.h"
+#include "LogTags.h"
+#include "SerializedLogChunk.h"
+#include "SerializedLogEntry.h"
+
+// b/188858988 - Previously, if clearing UID logs erased the back-most chunk, then a chunk that has
+// previously been closed for writing will be the back-most chunk in the list. Subsequent calls to
+// SerializedLogBuffer::Log() will call SerializedLogChunk::FinishWriting(), which triggered a
+// CHECK().
+TEST(SerializedLogBuffer, uid_prune_deletes_last_chunk) {
+ LogReaderList reader_list;
+ LogTags tags;
+ LogStatistics stats(false, true);
+ SerializedLogBuffer log_buffer(&reader_list, &tags, &stats);
+
+ log_buffer.SetSize(LOG_ID_MAIN, kLogBufferMinSize);
+ log_buffer.Clear(LOG_ID_MAIN, 0);
+
+ const uid_t kNonClearUid = 123;
+ const std::string kDontClearMessage = "this message is not cleared";
+ log_buffer.Log(LOG_ID_MAIN, log_time(0, 1), kNonClearUid, 1, 1, kDontClearMessage.data(),
+ kDontClearMessage.size());
+
+ // Fill at least one chunk with a message with the UID that we'll clear
+ const uid_t kClearUid = 555;
+ const std::string kClearMessage(1024, 'c');
+ size_t size_written = 0;
+ while (size_written < kLogBufferMinSize / 2) {
+ log_buffer.Log(LOG_ID_MAIN, log_time(1, size_written), kClearUid, 1, 1,
+ kClearMessage.data(), kClearMessage.size());
+ size_written += kClearMessage.size();
+ }
+
+ log_buffer.Clear(LOG_ID_MAIN, kClearUid);
+
+ // This previously would trigger a CHECK() in SerializedLogChunk::FinishWriting().
+ log_buffer.Log(LOG_ID_MAIN, log_time(0, 2), kNonClearUid, 1, 1, kDontClearMessage.data(),
+ kDontClearMessage.size());
+}
+
+struct TestEntry {
+ uint32_t uid;
+ uint32_t pid;
+ uint32_t tid;
+ uint64_t sequence;
+ log_time realtime;
+ std::string msg;
+};
+
+SerializedLogChunk CreateChunk(size_t max_size, const std::vector<TestEntry>& entries,
+ bool finish_writing) {
+ SerializedLogChunk chunk(max_size / SerializedLogBuffer::kChunkSizeDivisor);
+
+ for (const auto& entry : entries) {
+ if (!chunk.CanLog(sizeof(SerializedLogEntry) + entry.msg.size())) {
+ EXPECT_TRUE(false) << "Test set up failure, entries don't fit in chunks";
+ return chunk;
+ }
+ chunk.Log(entry.sequence, entry.realtime, entry.uid, entry.pid, entry.tid, entry.msg.data(),
+ entry.msg.size());
+ }
+ if (finish_writing) {
+ chunk.FinishWriting();
+ }
+ return chunk;
+}
+
+void VerifyChunks(const std::list<SerializedLogChunk>& expected,
+ const std::list<SerializedLogChunk>& chunks) {
+ int chunk = 0;
+ auto expected_it = expected.begin();
+ auto it = chunks.begin();
+ for (; expected_it != expected.end() && it != chunks.end(); ++expected_it, ++it, ++chunk) {
+ EXPECT_EQ(expected_it->reader_ref_count_, it->reader_ref_count_) << "chunk #" << chunk;
+ EXPECT_EQ(expected_it->writer_active_, it->writer_active_) << "chunk #" << chunk;
+ EXPECT_EQ(expected_it->highest_sequence_number_, it->highest_sequence_number_)
+ << "chunk #" << chunk;
+ EXPECT_EQ(expected_it->readers_, it->readers_) << "chunk #" << chunk;
+
+ ASSERT_EQ(expected_it->contents_.size(), it->contents_.size()) << "chunk #" << chunk;
+ ASSERT_EQ(expected_it->write_offset_, it->write_offset_) << "chunk #" << chunk;
+ if (expected_it->contents_.size() > 0) {
+ for (int i = 0; i < it->write_offset_; ++i) {
+ EXPECT_EQ(expected_it->contents_.data()[i], it->contents_.data()[i])
+ << "chunk #" << chunk;
+ }
+ }
+
+ ASSERT_EQ(expected_it->compressed_log_.size(), it->compressed_log_.size())
+ << "chunk #" << chunk;
+ if (expected_it->compressed_log_.size() > 0) {
+ for (size_t i = 0; i < it->compressed_log_.size(); ++i) {
+ EXPECT_EQ(expected_it->compressed_log_.data()[i], it->compressed_log_.data()[i])
+ << "chunk #" << chunk;
+ }
+ }
+ }
+ EXPECT_EQ(expected.end(), expected_it);
+ EXPECT_EQ(chunks.end(), it);
+}
+
+// If no blocks are present before ClearLogsByUid() then no blocks should be output.
+TEST(SerializedLogBuffer, uid_prune_no_blocks) {
+ const uid_t kClearUid = 555;
+ const size_t kMaxSize = kLogBufferMinSize;
+
+ std::list<SerializedLogChunk> chunks;
+ std::list<SerializedLogChunk> expected_chunks;
+
+ ClearLogsByUid(chunks, kClearUid, kMaxSize, LOG_ID_MAIN, nullptr);
+ VerifyChunks(expected_chunks, chunks);
+
+ ClearLogsByUid(chunks, kClearUid, kMaxSize, LOG_ID_MAIN, nullptr);
+ VerifyChunks(expected_chunks, chunks);
+}
+
+// If no UIDs to be cleared are found, then the _same exact_ block is returned.
+TEST(SerializedLogBuffer, uid_prune_one_block_no_uid) {
+ const uid_t kNonClearUid = 123;
+ const uid_t kClearUid = 555;
+ const size_t kMaxSize = kLogBufferMinSize;
+
+ std::vector<TestEntry> entries = {
+ {.uid = kNonClearUid,
+ .pid = 10,
+ .tid = 10,
+ .sequence = 1,
+ .realtime = log_time(0, 1),
+ .msg = "some message"},
+ };
+
+ std::list<SerializedLogChunk> chunks;
+ chunks.emplace_back(CreateChunk(kMaxSize, entries, false));
+ void* original_chunk_address = reinterpret_cast<void*>(&chunks.front());
+
+ std::list<SerializedLogChunk> expected_chunks;
+ expected_chunks.push_back(CreateChunk(kMaxSize, entries, false));
+
+ ClearLogsByUid(chunks, kClearUid, kMaxSize, LOG_ID_MAIN, nullptr);
+ VerifyChunks(expected_chunks, chunks);
+ void* after_clear_chunk_address = reinterpret_cast<void*>(&chunks.front());
+ EXPECT_EQ(original_chunk_address, after_clear_chunk_address);
+
+ ClearLogsByUid(chunks, kClearUid, kMaxSize, LOG_ID_MAIN, nullptr);
+ VerifyChunks(expected_chunks, chunks);
+ after_clear_chunk_address = reinterpret_cast<void*>(&chunks.front());
+ EXPECT_EQ(original_chunk_address, after_clear_chunk_address);
+}
+
+std::vector<TestEntry> FilterEntries(const std::vector<TestEntry>& entries, uid_t uid_to_remove) {
+ std::vector<TestEntry> filtered_entries;
+ for (const auto& entry : entries) {
+ if (entry.uid == uid_to_remove) {
+ continue;
+ }
+ filtered_entries.emplace_back(entry);
+ }
+ return filtered_entries;
+}
+
+TEST(SerializedLogBuffer, uid_prune_one_block_some_uid) {
+ const uid_t kNonClearUid = 123;
+ const uid_t kClearUid = 555;
+ const size_t kMaxSize = kLogBufferMinSize;
+
+ std::list<SerializedLogChunk> chunks;
+ std::vector<TestEntry> entries = {
+ {.uid = kNonClearUid,
+ .pid = 10,
+ .tid = 10,
+ .sequence = 1,
+ .realtime = log_time(0, 1),
+ .msg = "some message"},
+ {.uid = kClearUid,
+ .pid = 10,
+ .tid = 10,
+ .sequence = 2,
+ .realtime = log_time(0, 1),
+ .msg = "some cleared message"},
+ };
+ chunks.emplace_back(CreateChunk(kMaxSize, entries, false));
+
+ std::list<SerializedLogChunk> expected_chunks;
+ expected_chunks.emplace_back(CreateChunk(kMaxSize, FilterEntries(entries, kClearUid), false));
+
+ ClearLogsByUid(chunks, kClearUid, kMaxSize, LOG_ID_MAIN, nullptr);
+ VerifyChunks(expected_chunks, chunks);
+
+ ClearLogsByUid(chunks, kClearUid, kMaxSize, LOG_ID_MAIN, nullptr);
+ VerifyChunks(expected_chunks, chunks);
+}
+
+TEST(SerializedLogBuffer, uid_prune_one_block_all_uid) {
+ const uid_t kClearUid = 555;
+ const size_t kMaxSize = kLogBufferMinSize;
+
+ std::list<SerializedLogChunk> chunks;
+ std::vector<TestEntry> entries = {
+ {.uid = kClearUid,
+ .pid = 10,
+ .tid = 10,
+ .sequence = 1,
+ .realtime = log_time(0, 1),
+ .msg = "some message"},
+ {.uid = kClearUid,
+ .pid = 10,
+ .tid = 10,
+ .sequence = 2,
+ .realtime = log_time(0, 1),
+ .msg = "some cleared message"},
+ };
+ chunks.emplace_back(CreateChunk(kMaxSize, entries, false));
+
+ std::list<SerializedLogChunk> expected_chunks;
+ expected_chunks.emplace_back(CreateChunk(kMaxSize, {}, false));
+
+ ClearLogsByUid(chunks, kClearUid, kMaxSize, LOG_ID_MAIN, nullptr);
+ VerifyChunks(expected_chunks, chunks);
+
+ ClearLogsByUid(chunks, kClearUid, kMaxSize, LOG_ID_MAIN, nullptr);
+ VerifyChunks(expected_chunks, chunks);
+}
+
+TEST(SerializedLogBuffer, uid_prune_first_middle_last_chunks) {
+ const uid_t kNonClearUid = 123;
+ const uid_t kClearUid = 555;
+ const std::string kMsg = "constant log message";
+ const size_t kMaxSize =
+ (sizeof(SerializedLogEntry) + kMsg.size()) * SerializedLogBuffer::kChunkSizeDivisor;
+
+ std::list<SerializedLogChunk> chunks;
+ std::vector<TestEntry> entries0 = {
+ {.uid = kClearUid,
+ .pid = 10,
+ .tid = 10,
+ .sequence = 1,
+ .realtime = log_time(0, 1),
+ .msg = kMsg},
+ };
+ chunks.emplace_back(CreateChunk(kMaxSize, entries0, true));
+ std::vector<TestEntry> entries1 = {
+ {.uid = kNonClearUid,
+ .pid = 10,
+ .tid = 10,
+ .sequence = 2,
+ .realtime = log_time(0, 1),
+ .msg = kMsg},
+ };
+ chunks.emplace_back(CreateChunk(kMaxSize, entries1, true));
+ std::vector<TestEntry> entries2 = {
+ {.uid = kClearUid,
+ .pid = 10,
+ .tid = 10,
+ .sequence = 3,
+ .realtime = log_time(0, 1),
+ .msg = kMsg},
+ };
+ chunks.emplace_back(CreateChunk(kMaxSize, entries2, true));
+ std::vector<TestEntry> entries3 = {
+ {.uid = kNonClearUid,
+ .pid = 10,
+ .tid = 10,
+ .sequence = 4,
+ .realtime = log_time(0, 1),
+ .msg = kMsg},
+ };
+ chunks.emplace_back(CreateChunk(kMaxSize, entries3, true));
+ std::vector<TestEntry> entries4 = {
+ {.uid = kClearUid,
+ .pid = 10,
+ .tid = 10,
+ .sequence = 5,
+ .realtime = log_time(0, 1),
+ .msg = kMsg},
+ };
+ chunks.emplace_back(CreateChunk(kMaxSize, entries4, false));
+
+ std::list<SerializedLogChunk> expected_chunks;
+ expected_chunks.emplace_back(CreateChunk(kMaxSize, entries1, true));
+ expected_chunks.emplace_back(CreateChunk(kMaxSize, entries3, false));
+
+ ClearLogsByUid(chunks, kClearUid, kMaxSize, LOG_ID_MAIN, nullptr);
+ VerifyChunks(expected_chunks, chunks);
+
+ ClearLogsByUid(chunks, kClearUid, kMaxSize, LOG_ID_MAIN, nullptr);
+ VerifyChunks(expected_chunks, chunks);
+}
+
+TEST(SerializedLogBuffer, uid_prune_coalesce) {
+ const uid_t kNonClearUid = 123;
+ const uid_t kClearUid = 555;
+ const std::string kMsg = "constant log message";
+ const size_t kMaxSize =
+ (sizeof(SerializedLogEntry) + kMsg.size()) * SerializedLogBuffer::kChunkSizeDivisor * 2;
+
+ std::list<SerializedLogChunk> chunks;
+ std::vector<TestEntry> entries0 = {
+ {.uid = kNonClearUid,
+ .pid = 10,
+ .tid = 10,
+ .sequence = 1,
+ .realtime = log_time(0, 1),
+ .msg = kMsg},
+ {.uid = kNonClearUid,
+ .pid = 10,
+ .tid = 10,
+ .sequence = 2,
+ .realtime = log_time(0, 1),
+ .msg = kMsg},
+ };
+ chunks.emplace_back(CreateChunk(kMaxSize, entries0, true));
+ std::vector<TestEntry> entries1 = {
+ {.uid = kNonClearUid,
+ .pid = 10,
+ .tid = 10,
+ .sequence = 3,
+ .realtime = log_time(0, 1),
+ .msg = kMsg},
+ {.uid = kClearUid,
+ .pid = 10,
+ .tid = 10,
+ .sequence = 4,
+ .realtime = log_time(0, 1),
+ .msg = kMsg},
+ };
+ chunks.emplace_back(CreateChunk(kMaxSize, entries1, true));
+ std::vector<TestEntry> entries2 = {
+ {.uid = kClearUid,
+ .pid = 10,
+ .tid = 10,
+ .sequence = 5,
+ .realtime = log_time(0, 1),
+ .msg = kMsg},
+ {.uid = kClearUid,
+ .pid = 10,
+ .tid = 10,
+ .sequence = 6,
+ .realtime = log_time(0, 1),
+ .msg = kMsg},
+ };
+ chunks.emplace_back(CreateChunk(kMaxSize, entries2, true));
+ std::vector<TestEntry> entries3 = {
+ {.uid = kNonClearUid,
+ .pid = 10,
+ .tid = 10,
+ .sequence = 7,
+ .realtime = log_time(0, 1),
+ .msg = kMsg},
+ {.uid = kNonClearUid,
+ .pid = 10,
+ .tid = 10,
+ .sequence = 8,
+ .realtime = log_time(0, 1),
+ .msg = kMsg},
+ };
+ chunks.emplace_back(CreateChunk(kMaxSize, entries3, false));
+
+ std::list<SerializedLogChunk> expected_chunks;
+ expected_chunks.emplace_back(CreateChunk(kMaxSize, entries0, true));
+
+ std::vector<TestEntry> expected_entries_1;
+ expected_entries_1.emplace_back(entries1[0]);
+ expected_entries_1.emplace_back(entries3[0]);
+ expected_chunks.emplace_back(CreateChunk(kMaxSize, expected_entries_1, true));
+
+ std::vector<TestEntry> expected_entries_2;
+ expected_entries_2.emplace_back(entries3[1]);
+ expected_chunks.emplace_back(CreateChunk(kMaxSize, expected_entries_2, false));
+
+ ClearLogsByUid(chunks, kClearUid, kMaxSize, LOG_ID_MAIN, nullptr);
+ VerifyChunks(expected_chunks, chunks);
+
+ ClearLogsByUid(chunks, kClearUid, kMaxSize, LOG_ID_MAIN, nullptr);
+ VerifyChunks(expected_chunks, chunks);
+}
diff --git a/logd/SerializedLogChunk.cpp b/logd/SerializedLogChunk.cpp
index a512bf3..e6b4f50 100644
--- a/logd/SerializedLogChunk.cpp
+++ b/logd/SerializedLogChunk.cpp
@@ -25,12 +25,16 @@
CHECK_EQ(reader_ref_count_, 0U);
}
-void SerializedLogChunk::Compress() {
+void SerializedLogChunk::FinishWriting() {
+ writer_active_ = false;
CHECK_EQ(compressed_log_.size(), 0U);
CompressionEngine::GetInstance().Compress(contents_, write_offset_, compressed_log_);
LOG(VERBOSE) << "Compressed Log, buffer max size: " << contents_.size()
<< " size used: " << write_offset_
<< " compressed size: " << compressed_log_.size();
+ if (reader_ref_count_ == 0) {
+ contents_.Resize(0);
+ }
}
// TODO: Develop a better reference counting strategy to guard against the case where the writer is
@@ -73,54 +77,6 @@
}
}
-bool SerializedLogChunk::ClearUidLogs(uid_t uid, log_id_t log_id, LogStatistics* stats) {
- CHECK_EQ(reader_ref_count_, 0U);
- if (write_offset_ == 0) {
- return true;
- }
-
- IncReaderRefCount();
-
- int read_offset = 0;
- int new_write_offset = 0;
- while (read_offset < write_offset_) {
- const auto* entry = log_entry(read_offset);
- if (entry->uid() == uid) {
- read_offset += entry->total_len();
- if (stats != nullptr) {
- stats->Subtract(entry->ToLogStatisticsElement(log_id));
- }
- continue;
- }
- size_t entry_total_len = entry->total_len();
- if (read_offset != new_write_offset) {
- memmove(contents_.data() + new_write_offset, contents_.data() + read_offset,
- entry_total_len);
- }
- read_offset += entry_total_len;
- new_write_offset += entry_total_len;
- }
-
- if (new_write_offset == 0) {
- DecReaderRefCount();
- return true;
- }
-
- // Clear the old compressed logs and set write_offset_ appropriately to compress the new
- // partially cleared log.
- if (new_write_offset != write_offset_) {
- write_offset_ = new_write_offset;
- if (!writer_active_) {
- compressed_log_.Resize(0);
- Compress();
- }
- }
-
- DecReaderRefCount();
-
- return false;
-}
-
bool SerializedLogChunk::CanLog(size_t len) {
return write_offset_ + len <= contents_.size();
}
diff --git a/logd/SerializedLogChunk.h b/logd/SerializedLogChunk.h
index 2318a2d..eb41674 100644
--- a/logd/SerializedLogChunk.h
+++ b/logd/SerializedLogChunk.h
@@ -18,6 +18,7 @@
#include <sys/types.h>
+#include <list>
#include <vector>
#include <android-base/logging.h>
@@ -31,11 +32,34 @@
class SerializedLogChunk {
public:
+ friend void VerifyChunks(const std::list<SerializedLogChunk>& expected,
+ const std::list<SerializedLogChunk>& chunks);
+
+ class LogEntryIterator {
+ public:
+ LogEntryIterator(SerializedLogChunk& chunk, int read_offset_)
+ : chunk_(chunk), read_offset_(read_offset_) {}
+
+ LogEntryIterator& operator++() {
+ read_offset_ += chunk_.log_entry(read_offset_)->total_len();
+ return *this;
+ }
+
+ bool operator!=(const LogEntryIterator& other) const {
+ return read_offset_ != other.read_offset_;
+ }
+ const SerializedLogEntry& operator*() const { return *chunk_.log_entry(read_offset_); }
+
+ private:
+ SerializedLogChunk& chunk_;
+ int read_offset_;
+ };
+
explicit SerializedLogChunk(size_t size) : contents_(size) {}
SerializedLogChunk(SerializedLogChunk&& other) noexcept = default;
~SerializedLogChunk();
- void Compress();
+ void FinishWriting();
void IncReaderRefCount();
void DecReaderRefCount();
void AttachReader(SerializedFlushToState* reader);
@@ -43,9 +67,6 @@
void NotifyReadersOfPrune(log_id_t log_id) REQUIRES(logd_lock);
- // Must have no readers referencing this. Return true if there are no logs left in this chunk.
- bool ClearUidLogs(uid_t uid, log_id_t log_id, LogStatistics* stats);
-
bool CanLog(size_t len);
SerializedLogEntry* Log(uint64_t sequence, log_time realtime, uid_t uid, pid_t pid, pid_t tid,
const char* msg, uint16_t len);
@@ -57,14 +78,6 @@
return sizeof(*this) + (compressed_log_.size() ?: contents_.size());
}
- void FinishWriting() {
- writer_active_ = false;
- Compress();
- if (reader_ref_count_ == 0) {
- contents_.Resize(0);
- }
- }
-
const SerializedLogEntry* log_entry(int offset) const {
CHECK(writer_active_ || reader_ref_count_ > 0);
return reinterpret_cast<const SerializedLogEntry*>(data() + offset);
@@ -73,6 +86,10 @@
int write_offset() const { return write_offset_; }
uint64_t highest_sequence_number() const { return highest_sequence_number_; }
+ LogEntryIterator begin() { return LogEntryIterator(*this, 0); }
+
+ LogEntryIterator end() { return LogEntryIterator(*this, write_offset_); }
+
// Exposed for testing
uint32_t reader_ref_count() const { return reader_ref_count_; }
diff --git a/logd/SerializedLogChunkTest.cpp b/logd/SerializedLogChunkTest.cpp
index 862c3fe..8e53365 100644
--- a/logd/SerializedLogChunkTest.cpp
+++ b/logd/SerializedLogChunkTest.cpp
@@ -18,10 +18,13 @@
#include <limits>
+#include <android-base/silent_death_test.h>
#include <android-base/stringprintf.h>
#include <android/log.h>
#include <gtest/gtest.h>
+using SerializedLogChunk_DeathTest = SilentDeathTest;
+
using android::base::StringPrintf;
TEST(SerializedLogChunk, smoke) {
@@ -99,205 +102,16 @@
"\xFF\xFF\xFF\xFF\xFF\xFF\xFF\xFF" // Timestamp
"\x0C\x00last message"; // msg_len + message
- for (size_t i = 0; i < sizeof(expected_buffer_data); ++i) {
+ for (size_t i = 0; i < sizeof(expected_buffer_data) - 1; ++i) {
EXPECT_EQ(static_cast<uint8_t>(expected_buffer_data[i]), chunk.data()[i])
<< "position: " << i;
}
}
// Check that the CHECK() in DecReaderRefCount() if the ref count goes bad is caught.
-TEST(SerializedLogChunk, catch_DecCompressedRef_CHECK) {
+TEST_F(SerializedLogChunk_DeathTest, catch_DecCompressedRef_CHECK) {
size_t chunk_size = 10 * 4096;
auto chunk = SerializedLogChunk{chunk_size};
EXPECT_DEATH({ chunk.DecReaderRefCount(); }, "");
}
-// Check that the CHECK() in ClearUidLogs() if the ref count is greater than 0 is caught.
-TEST(SerializedLogChunk, catch_ClearUidLogs_CHECK) {
- size_t chunk_size = 10 * 4096;
- auto chunk = SerializedLogChunk{chunk_size};
- chunk.IncReaderRefCount();
- EXPECT_DEATH({ chunk.ClearUidLogs(1000, LOG_ID_MAIN, nullptr); }, "");
- chunk.DecReaderRefCount();
-}
-
-class UidClearTest : public testing::TestWithParam<bool> {
- protected:
- template <typename Write, typename Check>
- void Test(const Write& write, const Check& check, bool expected_result) {
- write(chunk_);
-
- bool finish_writing = GetParam();
- if (finish_writing) {
- chunk_.FinishWriting();
- }
- EXPECT_EQ(expected_result, chunk_.ClearUidLogs(kUidToClear, LOG_ID_MAIN, nullptr));
- if (finish_writing) {
- chunk_.IncReaderRefCount();
- }
-
- check(chunk_);
-
- if (finish_writing) {
- chunk_.DecReaderRefCount();
- }
- }
-
- static constexpr size_t kChunkSize = 10 * 4096;
- static constexpr uid_t kUidToClear = 1000;
- static constexpr uid_t kOtherUid = 1234;
-
- SerializedLogChunk chunk_{kChunkSize};
-};
-
-// Test that ClearUidLogs() is a no-op if there are no logs of that UID in the buffer.
-TEST_P(UidClearTest, no_logs_in_chunk) {
- auto write = [](SerializedLogChunk&) {};
- auto check = [](SerializedLogChunk&) {};
-
- Test(write, check, true);
-}
-
-// Test that ClearUidLogs() is a no-op if there are no logs of that UID in the buffer.
-TEST_P(UidClearTest, no_logs_from_uid) {
- static const char msg[] = "this is a log message";
- auto write = [](SerializedLogChunk& chunk) {
- chunk.Log(1, log_time(), kOtherUid, 1, 2, msg, sizeof(msg));
- };
-
- auto check = [](SerializedLogChunk& chunk) {
- auto* entry = chunk.log_entry(0);
- EXPECT_STREQ(msg, entry->msg());
- };
-
- Test(write, check, false);
-}
-
-// Test that ClearUidLogs() returns true if all logs in a given buffer correspond to the given UID.
-TEST_P(UidClearTest, all_single) {
- static const char msg[] = "this is a log message";
- auto write = [](SerializedLogChunk& chunk) {
- chunk.Log(1, log_time(), kUidToClear, 1, 2, msg, sizeof(msg));
- };
- auto check = [](SerializedLogChunk&) {};
-
- Test(write, check, true);
-}
-
-// Test that ClearUidLogs() returns true if all logs in a given buffer correspond to the given UID.
-TEST_P(UidClearTest, all_multiple) {
- static const char msg[] = "this is a log message";
- auto write = [](SerializedLogChunk& chunk) {
- chunk.Log(2, log_time(), kUidToClear, 1, 2, msg, sizeof(msg));
- chunk.Log(3, log_time(), kUidToClear, 1, 2, msg, sizeof(msg));
- chunk.Log(4, log_time(), kUidToClear, 1, 2, msg, sizeof(msg));
- };
- auto check = [](SerializedLogChunk&) {};
-
- Test(write, check, true);
-}
-
-static std::string MakePrintable(const uint8_t* in, size_t length) {
- std::string result;
- for (size_t i = 0; i < length; ++i) {
- uint8_t c = in[i];
- if (isprint(c)) {
- result.push_back(c);
- } else {
- result.append(StringPrintf("\\%02x", static_cast<int>(c) & 0xFF));
- }
- }
- return result;
-}
-
-// This test clears UID logs at the beginning and end of the buffer, as well as two back to back
-// logs in the interior.
-TEST_P(UidClearTest, clear_beginning_and_end) {
- static const char msg1[] = "this is a log message";
- static const char msg2[] = "non-cleared message";
- static const char msg3[] = "back to back cleared messages";
- static const char msg4[] = "second in a row gone";
- static const char msg5[] = "but we save this one";
- static const char msg6[] = "and this 1!";
- static const char msg7[] = "the last one goes too";
- auto write = [](SerializedLogChunk& chunk) {
- ASSERT_NE(nullptr, chunk.Log(1, log_time(), kUidToClear, 1, 2, msg1, sizeof(msg1)));
- ASSERT_NE(nullptr, chunk.Log(2, log_time(), kOtherUid, 1, 2, msg2, sizeof(msg2)));
- ASSERT_NE(nullptr, chunk.Log(3, log_time(), kUidToClear, 1, 2, msg3, sizeof(msg3)));
- ASSERT_NE(nullptr, chunk.Log(4, log_time(), kUidToClear, 1, 2, msg4, sizeof(msg4)));
- ASSERT_NE(nullptr, chunk.Log(5, log_time(), kOtherUid, 1, 2, msg5, sizeof(msg5)));
- ASSERT_NE(nullptr, chunk.Log(6, log_time(), kOtherUid, 1, 2, msg6, sizeof(msg6)));
- ASSERT_NE(nullptr, chunk.Log(7, log_time(), kUidToClear, 1, 2, msg7, sizeof(msg7)));
- };
-
- auto check = [](SerializedLogChunk& chunk) {
- size_t read_offset = 0;
- auto* entry = chunk.log_entry(read_offset);
- EXPECT_STREQ(msg2, entry->msg());
- read_offset += entry->total_len();
-
- entry = chunk.log_entry(read_offset);
- EXPECT_STREQ(msg5, entry->msg());
- read_offset += entry->total_len();
-
- entry = chunk.log_entry(read_offset);
- EXPECT_STREQ(msg6, entry->msg()) << MakePrintable(chunk.data(), chunk.write_offset());
- read_offset += entry->total_len();
-
- EXPECT_EQ(static_cast<int>(read_offset), chunk.write_offset());
- };
- Test(write, check, false);
-}
-
-// This tests the opposite case of beginning_and_end, in which we don't clear the beginning or end
-// logs. There is a single log pruned in the middle instead of back to back logs.
-TEST_P(UidClearTest, save_beginning_and_end) {
- static const char msg1[] = "saved first message";
- static const char msg2[] = "cleared interior message";
- static const char msg3[] = "last message stays";
- auto write = [](SerializedLogChunk& chunk) {
- ASSERT_NE(nullptr, chunk.Log(1, log_time(), kOtherUid, 1, 2, msg1, sizeof(msg1)));
- ASSERT_NE(nullptr, chunk.Log(2, log_time(), kUidToClear, 1, 2, msg2, sizeof(msg2)));
- ASSERT_NE(nullptr, chunk.Log(3, log_time(), kOtherUid, 1, 2, msg3, sizeof(msg3)));
- };
-
- auto check = [](SerializedLogChunk& chunk) {
- size_t read_offset = 0;
- auto* entry = chunk.log_entry(read_offset);
- EXPECT_STREQ(msg1, entry->msg());
- read_offset += entry->total_len();
-
- entry = chunk.log_entry(read_offset);
- EXPECT_STREQ(msg3, entry->msg());
- read_offset += entry->total_len();
-
- EXPECT_EQ(static_cast<int>(read_offset), chunk.write_offset());
- };
- Test(write, check, false);
-}
-
-INSTANTIATE_TEST_CASE_P(UidClearTests, UidClearTest, testing::Values(true, false));
-
-// b/166187079: ClearUidLogs() should not compress the log if writer_active_ is true
-TEST(SerializedLogChunk, ClearUidLogs_then_FinishWriting) {
- static constexpr size_t kChunkSize = 10 * 4096;
- static constexpr uid_t kUidToClear = 1000;
- static constexpr uid_t kOtherUid = 1234;
-
- SerializedLogChunk chunk{kChunkSize};
- static const char msg1[] = "saved first message";
- static const char msg2[] = "cleared interior message";
- static const char msg3[] = "last message stays";
- ASSERT_NE(nullptr, chunk.Log(1, log_time(), kOtherUid, 1, 2, msg1, sizeof(msg1)));
- ASSERT_NE(nullptr, chunk.Log(2, log_time(), kUidToClear, 1, 2, msg2, sizeof(msg2)));
- ASSERT_NE(nullptr, chunk.Log(3, log_time(), kOtherUid, 1, 2, msg3, sizeof(msg3)));
-
- chunk.ClearUidLogs(kUidToClear, LOG_ID_MAIN, nullptr);
-
- ASSERT_NE(nullptr, chunk.Log(4, log_time(), kOtherUid, 1, 2, msg3, sizeof(msg3)));
-
- chunk.FinishWriting();
- // The next line would violate a CHECK() during decompression with the faulty code.
- chunk.IncReaderRefCount();
- chunk.DecReaderRefCount();
-}
diff --git a/logd/fuzz/Android.bp b/logd/fuzz/Android.bp
index d346cd7..cc5b3af 100644
--- a/logd/fuzz/Android.bp
+++ b/logd/fuzz/Android.bp
@@ -14,6 +14,10 @@
* limitations under the License.
*/
+package {
+ default_applicable_licenses: ["Android-Apache-2.0"],
+}
+
cc_defaults {
name: "log_fuzzer_defaults",
static_libs: [
diff --git a/logd/logd_test.cpp b/logd/logd_test.cpp
index ec09cd7..e2223b6 100644
--- a/logd/logd_test.cpp
+++ b/logd/logd_test.cpp
@@ -15,6 +15,7 @@
*/
#include <ctype.h>
+#include <errno.h>
#include <fcntl.h>
#include <inttypes.h>
#include <poll.h>
@@ -46,198 +47,89 @@
using android::base::unique_fd;
#ifdef __ANDROID__
-static void send_to_control(char* buf, size_t len) {
- int sock = socket_local_client("logd", ANDROID_SOCKET_NAMESPACE_RESERVED,
- SOCK_STREAM);
- if (sock >= 0) {
- if (write(sock, buf, strlen(buf) + 1) > 0) {
- ssize_t ret;
- while ((ret = read(sock, buf, len)) > 0) {
- if (((size_t)ret == len) || (len < PAGE_SIZE)) {
- break;
- }
- len -= ret;
- buf += ret;
-
- struct pollfd p = {.fd = sock, .events = POLLIN, .revents = 0 };
-
- ret = poll(&p, 1, 20);
- if ((ret <= 0) || !(p.revents & POLLIN)) {
- break;
- }
- }
+static bool write_command(int sock, const char* command) {
+ // The command sent to logd must include the '\0' character at the end.
+ size_t command_length = strlen(command) + 1;
+ ssize_t bytes_written = TEMP_FAILURE_RETRY(write(sock, command, command_length));
+ if (bytes_written != static_cast<ssize_t>(command_length)) {
+ if (bytes_written == -1) {
+ printf("Failed to send '%s' command: %s\n", command, strerror(errno));
+ } else {
+ printf("Failed to send '%s' command: bytes written %zd, expected written %zu\n",
+ command, bytes_written, command_length);
}
- close(sock);
+ return false;
}
+ return true;
}
-/*
- * returns statistics
- */
-static void my_android_logger_get_statistics(char* buf, size_t len) {
- snprintf(buf, len, "getStatistics 0 1 2 3 4");
- send_to_control(buf, len);
+static bool write_command(int sock, const std::string& command) {
+ return write_command(sock, command.c_str());
}
-static void alloc_statistics(char** buffer, size_t* length) {
- size_t len = 8192;
- char* buf;
+static void send_to_control(const char* command, std::string& result) {
+ unique_fd sock(socket_local_client("logd", ANDROID_SOCKET_NAMESPACE_RESERVED, SOCK_STREAM));
+ ASSERT_LT(0, sock) << "Failed to open logd: " << strerror(errno);
+ ASSERT_TRUE(write_command(sock, command));
+ result.clear();
+ while (true) {
+ struct pollfd p = {.fd = sock, .events = POLLIN, .revents = 0};
+ // Timeout after 20 seconds.
+ int ret = TEMP_FAILURE_RETRY(poll(&p, 1, 20000));
+ ASSERT_TRUE(ret != -1) << "Poll call failed for command '" << command
+ << "': " << strerror(errno);
+ ASSERT_NE(0, ret) << "Timeout sending command '" << command << "'";
+ ASSERT_TRUE(p.revents & POLLIN)
+ << "Command socket not readable for command '" << command << "'";
- for (int retry = 32; (retry >= 0); delete[] buf, --retry) {
- buf = new char[len];
- my_android_logger_get_statistics(buf, len);
-
- buf[len - 1] = '\0';
- size_t ret = atol(buf) + 1;
- if (ret < 4) {
- delete[] buf;
- buf = nullptr;
- break;
+ char buffer[256];
+ ssize_t bytes_read = TEMP_FAILURE_RETRY(read(sock, buffer, sizeof(buffer)));
+ ASSERT_GE(bytes_read, 0) << "Read failed for command '" << command
+ << "': " << strerror(errno);
+ result += std::string(buffer, bytes_read);
+ if (bytes_read == 0 || static_cast<size_t>(bytes_read) < sizeof(buffer)) {
+ return;
}
- bool check = ret <= len;
- len = ret;
- if (check) {
- break;
- }
- len += len / 8; // allow for some slop
}
- *buffer = buf;
- *length = len;
-}
-
-static char* find_benchmark_spam(char* cp) {
- // liblog_benchmarks has been run designed to SPAM. The signature of
- // a noisiest UID statistics is:
- //
- // Chattiest UIDs in main log buffer: Size Pruned
- // UID PACKAGE BYTES LINES
- // 0 root 54164 147569
- //
- char* benchmark = nullptr;
- do {
- static const char signature[] = "\n0 root ";
-
- benchmark = strstr(cp, signature);
- if (!benchmark) {
- break;
- }
- cp = benchmark + sizeof(signature);
- while (isspace(*cp)) {
- ++cp;
- }
- benchmark = cp;
-#ifdef DEBUG
- char* end = strstr(benchmark, "\n");
- if (end == nullptr) {
- end = benchmark + strlen(benchmark);
- }
- fprintf(stderr, "parse for spam counter in \"%.*s\"\n",
- (int)(end - benchmark), benchmark);
-#endif
- // content
- while (isdigit(*cp)) {
- ++cp;
- }
- while (isspace(*cp)) {
- ++cp;
- }
- // optional +/- field?
- if ((*cp == '-') || (*cp == '+')) {
- while (isdigit(*++cp) || (*cp == '.') || (*cp == '%') ||
- (*cp == 'X')) {
- ;
- }
- while (isspace(*cp)) {
- ++cp;
- }
- }
- // number of entries pruned
- unsigned long value = 0;
- while (isdigit(*cp)) {
- value = value * 10ULL + *cp - '0';
- ++cp;
- }
- if (value > 10UL) {
- break;
- }
- benchmark = nullptr;
- } while (*cp);
- return benchmark;
}
#endif
#ifdef LOGD_ENABLE_FLAKY_TESTS
TEST(logd, statistics) {
#ifdef __ANDROID__
- size_t len;
- char* buf;
-
// Drop cache so that any access problems can be discovered.
if (!android::base::WriteStringToFile("3\n", "/proc/sys/vm/drop_caches")) {
GTEST_LOG_(INFO) << "Could not open trigger dropping inode cache";
}
- alloc_statistics(&buf, &len);
+ std::string result;
+ send_to_control("getStatistics 0 1 2 3 4", result);
+ ASSERT_FALSE(result.empty());
- ASSERT_TRUE(nullptr != buf);
+ EXPECT_NE(std::string::npos, result.find("\nChattiest UIDs in main "));
- // remove trailing FF
- char* cp = buf + len - 1;
- *cp = '\0';
- bool truncated = *--cp != '\f';
- if (!truncated) {
- *cp = '\0';
- }
+ EXPECT_NE(std::string::npos, result.find("\nChattiest UIDs in radio "));
- // squash out the byte count
- cp = buf;
- if (!truncated) {
- while (isdigit(*cp) || (*cp == '\n')) {
- ++cp;
- }
- }
+ EXPECT_NE(std::string::npos, result.find("\nChattiest UIDs in system "));
- fprintf(stderr, "%s", cp);
+ EXPECT_NE(std::string::npos, result.find("\nChattiest UIDs in events "));
- EXPECT_LT((size_t)64, strlen(cp));
-
- EXPECT_EQ(0, truncated);
-
- char* main_logs = strstr(cp, "\nChattiest UIDs in main ");
- EXPECT_TRUE(nullptr != main_logs);
-
- char* radio_logs = strstr(cp, "\nChattiest UIDs in radio ");
- if (!radio_logs)
- GTEST_LOG_(INFO) << "Value of: nullptr != radio_logs\n"
- "Actual: false\n"
- "Expected: false\n";
-
- char* system_logs = strstr(cp, "\nChattiest UIDs in system ");
- EXPECT_TRUE(nullptr != system_logs);
-
- char* events_logs = strstr(cp, "\nChattiest UIDs in events ");
- EXPECT_TRUE(nullptr != events_logs);
-
- // Check if there is any " u0_a#### " as this means packagelistparser broken
- char* used_getpwuid = nullptr;
- int used_getpwuid_len;
- char* uid_name = cp;
+ // Look for any u0_a or u0_a[0-9]+ values. If found, it indicates the
+ // libpackagelistparser failed.
static const char getpwuid_prefix[] = " u0_a";
- while ((uid_name = strstr(uid_name, getpwuid_prefix)) != nullptr) {
- used_getpwuid = uid_name + 1;
- uid_name += strlen(getpwuid_prefix);
- while (isdigit(*uid_name)) ++uid_name;
- used_getpwuid_len = uid_name - used_getpwuid;
- if (isspace(*uid_name)) break;
- used_getpwuid = nullptr;
- }
- EXPECT_TRUE(nullptr == used_getpwuid);
- if (used_getpwuid) {
- fprintf(stderr, "libpackagelistparser failed to pick up %.*s\n",
- used_getpwuid_len, used_getpwuid);
- }
+ size_t pos = 0;
+ while ((pos = result.find(getpwuid_prefix, pos)) != std::string::npos) {
+ // Check to see if the value following u0_a is all digits, or empty.
+ size_t uid_name_pos = pos + strlen(getpwuid_prefix);
+ size_t i = 0;
+ while (isdigit(result[uid_name_pos + i])) {
+ i++;
+ }
+ ASSERT_FALSE(isspace(result[uid_name_pos + i]))
+ << "libpackagelistparser failed to pick up " << result.substr(uid_name_pos, i);
- delete[] buf;
+ pos = uid_name_pos + i;
+ }
#else
GTEST_LOG_(INFO) << "This test does nothing.\n";
#endif
@@ -327,177 +219,6 @@
}
#endif
-#ifdef __ANDROID__
-// BAD ROBOT
-// Benchmark threshold are generally considered bad form unless there is
-// is some human love applied to the continued maintenance and whether the
-// thresholds are tuned on a per-target basis. Here we check if the values
-// are more than double what is expected. Doubling will not prevent failure
-// on busy or low-end systems that could have a tendency to stretch values.
-//
-// The primary goal of this test is to simulate a spammy app (benchmark
-// being the worst) and check to make sure the logger can deal with it
-// appropriately by checking all the statistics are in an expected range.
-//
-TEST(logd, benchmark) {
- size_t len;
- char* buf;
-
- alloc_statistics(&buf, &len);
- bool benchmark_already_run = buf && find_benchmark_spam(buf);
- delete[] buf;
-
- if (benchmark_already_run) {
- fprintf(stderr,
- "WARNING: spam already present and too much history\n"
- " false OK for prune by worst UID check\n");
- }
-
- FILE* fp;
-
- // Introduce some extreme spam for the worst UID filter
- ASSERT_TRUE(
- nullptr !=
- (fp = popen("/data/nativetest/liblog-benchmarks/liblog-benchmarks"
- " BM_log_maximum_retry"
- " BM_log_maximum"
- " BM_clock_overhead"
- " BM_log_print_overhead"
- " BM_log_latency"
- " BM_log_delay",
- "r")));
-
- char buffer[5120];
-
- static const char* benchmarks[] = {
- "BM_log_maximum_retry ", "BM_log_maximum ", "BM_clock_overhead ",
- "BM_log_print_overhead ", "BM_log_latency ", "BM_log_delay "
- };
- static const unsigned int log_maximum_retry = 0;
- static const unsigned int log_maximum = 1;
- static const unsigned int clock_overhead = 2;
- static const unsigned int log_print_overhead = 3;
- static const unsigned int log_latency = 4;
- static const unsigned int log_delay = 5;
-
- unsigned long ns[arraysize(benchmarks)];
-
- memset(ns, 0, sizeof(ns));
-
- while (fgets(buffer, sizeof(buffer), fp)) {
- for (unsigned i = 0; i < arraysize(ns); ++i) {
- char* cp = strstr(buffer, benchmarks[i]);
- if (!cp) {
- continue;
- }
- sscanf(cp, "%*s %lu %lu", &ns[i], &ns[i]);
- fprintf(stderr, "%-22s%8lu\n", benchmarks[i], ns[i]);
- }
- }
- int ret = pclose(fp);
-
- if (!WIFEXITED(ret) || (WEXITSTATUS(ret) == 127)) {
- fprintf(stderr,
- "WARNING: "
- "/data/nativetest/liblog-benchmarks/liblog-benchmarks missing\n"
- " can not perform test\n");
- return;
- }
-
- EXPECT_GE(200000UL, ns[log_maximum_retry]); // 104734 user
- EXPECT_NE(0UL, ns[log_maximum_retry]); // failure to parse
-
- EXPECT_GE(90000UL, ns[log_maximum]); // 46913 user
- EXPECT_NE(0UL, ns[log_maximum]); // failure to parse
-
- EXPECT_GE(4096UL, ns[clock_overhead]); // 4095
- EXPECT_NE(0UL, ns[clock_overhead]); // failure to parse
-
- EXPECT_GE(250000UL, ns[log_print_overhead]); // 126886 user
- EXPECT_NE(0UL, ns[log_print_overhead]); // failure to parse
-
- EXPECT_GE(10000000UL,
- ns[log_latency]); // 1453559 user space (background cgroup)
- EXPECT_NE(0UL, ns[log_latency]); // failure to parse
-
- EXPECT_GE(20000000UL, ns[log_delay]); // 10500289 user
- EXPECT_NE(0UL, ns[log_delay]); // failure to parse
-
- alloc_statistics(&buf, &len);
-
- bool collected_statistics = !!buf;
- EXPECT_EQ(true, collected_statistics);
-
- ASSERT_TRUE(nullptr != buf);
-
- char* benchmark_statistics_found = find_benchmark_spam(buf);
- ASSERT_TRUE(benchmark_statistics_found != nullptr);
-
- // Check how effective the SPAM filter is, parse out Now size.
- // 0 root 54164 147569
- // ^-- benchmark_statistics_found
-
- unsigned long nowSpamSize = atol(benchmark_statistics_found);
-
- delete[] buf;
-
- ASSERT_NE(0UL, nowSpamSize);
-
- // Determine if we have the spam filter enabled
- int sock = socket_local_client("logd", ANDROID_SOCKET_NAMESPACE_RESERVED,
- SOCK_STREAM);
-
- ASSERT_TRUE(sock >= 0);
-
- static const char getPruneList[] = "getPruneList";
- if (write(sock, getPruneList, sizeof(getPruneList)) > 0) {
- char buffer[80];
- memset(buffer, 0, sizeof(buffer));
- read(sock, buffer, sizeof(buffer));
- char* cp = strchr(buffer, '\n');
- if (!cp || (cp[1] != '~') || (cp[2] != '!')) {
- close(sock);
- fprintf(stderr,
- "WARNING: "
- "Logger has SPAM filtration turned off \"%s\"\n",
- buffer);
- return;
- }
- } else {
- int save_errno = errno;
- close(sock);
- FAIL() << "Can not send " << getPruneList << " to logger -- "
- << strerror(save_errno);
- }
-
- static const unsigned long expected_absolute_minimum_log_size = 65536UL;
- unsigned long totalSize = expected_absolute_minimum_log_size;
- static const char getSize[] = { 'g', 'e', 't', 'L', 'o', 'g',
- 'S', 'i', 'z', 'e', ' ', LOG_ID_MAIN + '0',
- '\0' };
- if (write(sock, getSize, sizeof(getSize)) > 0) {
- char buffer[80];
- memset(buffer, 0, sizeof(buffer));
- read(sock, buffer, sizeof(buffer));
- totalSize = atol(buffer);
- if (totalSize < expected_absolute_minimum_log_size) {
- fprintf(stderr,
- "WARNING: "
- "Logger had unexpected referenced size \"%s\"\n",
- buffer);
- totalSize = expected_absolute_minimum_log_size;
- }
- }
- close(sock);
-
- // logd allows excursions to 110% of total size
- totalSize = (totalSize * 11) / 10;
-
- // 50% threshold for SPAM filter (<20% typical, lots of engineering margin)
- ASSERT_GT(totalSize, nowSpamSize * 2);
-}
-#endif
-
// b/26447386 confirm fixed
void timeout_negative(const char* command) {
#ifdef __ANDROID__
@@ -509,11 +230,9 @@
int i = 3;
while (--i) {
- int fd = socket_local_client("logdr", ANDROID_SOCKET_NAMESPACE_RESERVED,
- SOCK_SEQPACKET);
- ASSERT_LT(0, fd);
-
- std::string ask(command);
+ unique_fd fd(
+ socket_local_client("logdr", ANDROID_SOCKET_NAMESPACE_RESERVED, SOCK_SEQPACKET));
+ ASSERT_LT(0, fd) << "Failed to open logdr: " << strerror(errno);
struct sigaction ignore, old_sigaction;
memset(&ignore, 0, sizeof(ignore));
@@ -522,25 +241,23 @@
sigaction(SIGALRM, &ignore, &old_sigaction);
unsigned int old_alarm = alarm(3);
- size_t len = ask.length() + 1;
- written = write(fd, ask.c_str(), len) == (ssize_t)len;
+ written = write_command(fd, command);
if (!written) {
alarm(old_alarm);
sigaction(SIGALRM, &old_sigaction, nullptr);
- close(fd);
continue;
}
// alarm triggers at 50% of the --wrap time out
- content_wrap = recv(fd, msg_wrap.buf, sizeof(msg_wrap), 0) > 0;
+ content_wrap = TEMP_FAILURE_RETRY(recv(fd, msg_wrap.buf, sizeof(msg_wrap), 0)) > 0;
alarm_wrap = alarm(5);
// alarm triggers at 133% of the --wrap time out
- content_timeout = recv(fd, msg_timeout.buf, sizeof(msg_timeout), 0) > 0;
+ content_timeout = TEMP_FAILURE_RETRY(recv(fd, msg_timeout.buf, sizeof(msg_timeout), 0)) > 0;
if (!content_timeout) { // make sure we hit dumpAndClose
content_timeout =
- recv(fd, msg_timeout.buf, sizeof(msg_timeout), 0) > 0;
+ TEMP_FAILURE_RETRY(recv(fd, msg_timeout.buf, sizeof(msg_timeout), 0)) > 0;
}
if (old_alarm > 0) {
@@ -554,8 +271,6 @@
alarm_timeout = alarm(old_alarm);
sigaction(SIGALRM, &old_sigaction, nullptr);
- close(fd);
-
if (content_wrap && alarm_wrap && content_timeout && alarm_timeout) {
break;
}
@@ -589,7 +304,7 @@
"dumpAndClose lids=0,1,2,3,4,5 timeout=6 start=0.000000000");
}
-#ifdef ENABLE_FLAKY_TESTS
+#ifdef LOGD_ENABLE_FLAKY_TESTS
// b/26447386 refined behavior
TEST(logd, timeout) {
#ifdef __ANDROID__
@@ -616,14 +331,9 @@
start.tv_sec -= 30; // reach back a moderate period of time
while (--i) {
- int fd = socket_local_client("logdr", ANDROID_SOCKET_NAMESPACE_RESERVED,
- SOCK_SEQPACKET);
- int save_errno = errno;
- if (fd < 0) {
- fprintf(stderr, "failed to open /dev/socket/logdr %s\n",
- strerror(save_errno));
- _exit(fd);
- }
+ unique_fd fd(
+ socket_local_client("logdr", ANDROID_SOCKET_NAMESPACE_RESERVED, SOCK_SEQPACKET));
+ ASSERT_LT(0, fd) << "Failed to open logdr: " << strerror(errno);
std::string ask = android::base::StringPrintf(
"dumpAndClose lids=0,1,2,3,4,5 timeout=6 start=%" PRIu32
@@ -637,25 +347,23 @@
sigaction(SIGALRM, &ignore, &old_sigaction);
unsigned int old_alarm = alarm(3);
- size_t len = ask.length() + 1;
- written = write(fd, ask.c_str(), len) == (ssize_t)len;
+ written = write_command(fd, ask);
if (!written) {
alarm(old_alarm);
sigaction(SIGALRM, &old_sigaction, nullptr);
- close(fd);
continue;
}
// alarm triggers at 50% of the --wrap time out
- content_wrap = recv(fd, msg_wrap.buf, sizeof(msg_wrap), 0) > 0;
+ content_wrap = TEMP_FAILURE_RETRY(recv(fd, msg_wrap.buf, sizeof(msg_wrap), 0)) > 0;
alarm_wrap = alarm(5);
// alarm triggers at 133% of the --wrap time out
- content_timeout = recv(fd, msg_timeout.buf, sizeof(msg_timeout), 0) > 0;
+ content_timeout = TEMP_FAILURE_RETRY(recv(fd, msg_timeout.buf, sizeof(msg_timeout), 0)) > 0;
if (!content_timeout) { // make sure we hit dumpAndClose
content_timeout =
- recv(fd, msg_timeout.buf, sizeof(msg_timeout), 0) > 0;
+ TEMP_FAILURE_RETRY(recv(fd, msg_timeout.buf, sizeof(msg_timeout), 0)) > 0;
}
if (old_alarm > 0) {
@@ -669,8 +377,6 @@
alarm_timeout = alarm(old_alarm);
sigaction(SIGALRM, &old_sigaction, nullptr);
- close(fd);
-
if (!content_wrap && !alarm_wrap && content_timeout && alarm_timeout) {
break;
}
@@ -735,11 +441,8 @@
static const unsigned sleep_time = sndtimeo + 3;
static const unsigned alarm_time = sleep_time + 5;
- int fd;
-
- ASSERT_TRUE(
- (fd = socket_local_client("logdr", ANDROID_SOCKET_NAMESPACE_RESERVED,
- SOCK_SEQPACKET)) > 0);
+ unique_fd fd(socket_local_client("logdr", ANDROID_SOCKET_NAMESPACE_RESERVED, SOCK_SEQPACKET));
+ ASSERT_LT(0, fd) << "Failed to open logdr: " << strerror(errno);
struct sigaction ignore, old_sigaction;
memset(&ignore, 0, sizeof(ignore));
@@ -748,13 +451,11 @@
sigaction(SIGALRM, &ignore, &old_sigaction);
unsigned int old_alarm = alarm(alarm_time);
- static const char ask[] = "stream lids=0,1,2,3,4,5,6"; // all sources
- bool reader_requested = write(fd, ask, sizeof(ask)) == sizeof(ask);
- EXPECT_TRUE(reader_requested);
+ // Stream all sources.
+ ASSERT_TRUE(write_command(fd, "stream lids=0,1,2,3,4,5,6"));
log_msg msg;
- bool read_one = recv(fd, msg.buf, sizeof(msg), 0) > 0;
-
+ bool read_one = TEMP_FAILURE_RETRY(recv(fd, msg.buf, sizeof(msg), 0)) > 0;
EXPECT_TRUE(read_one);
if (read_one) {
dump_log_msg("user", &msg, -1);
@@ -766,7 +467,7 @@
// flush will block if we did not trigger. if it did, last entry returns 0
int recv_ret;
do {
- recv_ret = recv(fd, msg.buf, sizeof(msg), 0);
+ recv_ret = TEMP_FAILURE_RETRY(recv(fd, msg.buf, sizeof(msg), 0));
} while (recv_ret > 0);
int save_errno = (recv_ret < 0) ? errno : 0;
@@ -778,8 +479,6 @@
dump_log_msg("user", &msg, -1);
}
EXPECT_EQ(0, save_errno);
-
- close(fd);
#else
GTEST_LOG_(INFO) << "This test does nothing.\n";
#endif
@@ -788,14 +487,13 @@
TEST(logd, getEventTag_list) {
#ifdef __ANDROID__
- char buffer[256];
- memset(buffer, 0, sizeof(buffer));
- snprintf(buffer, sizeof(buffer), "getEventTag name=*");
- send_to_control(buffer, sizeof(buffer));
- buffer[sizeof(buffer) - 1] = '\0';
+ std::string result;
+ send_to_control("getEventTag name=*", result);
+ ASSERT_FALSE(result.empty());
+
char* cp;
- long ret = strtol(buffer, &cp, 10);
- EXPECT_GT(ret, 4096);
+ long ret = strtol(result.c_str(), &cp, 10);
+ EXPECT_GT(ret, 4096) << "Command result: " << result;
#else
GTEST_LOG_(INFO) << "This test does nothing.\n";
#endif
@@ -803,16 +501,16 @@
TEST(logd, getEventTag_42) {
#ifdef __ANDROID__
- char buffer[256];
- memset(buffer, 0, sizeof(buffer));
- snprintf(buffer, sizeof(buffer), "getEventTag id=42");
- send_to_control(buffer, sizeof(buffer));
- buffer[sizeof(buffer) - 1] = '\0';
+ std::string result;
+ send_to_control("getEventTag id=42", result);
+ ASSERT_FALSE(result.empty());
+
char* cp;
- long ret = strtol(buffer, &cp, 10);
- EXPECT_GT(ret, 16);
- EXPECT_TRUE(strstr(buffer, "\t(to life the universe etc|3)") != nullptr);
- EXPECT_TRUE(strstr(buffer, "answer") != nullptr);
+ long ret = strtol(result.c_str(), &cp, 10);
+ EXPECT_GT(ret, 16) << "Command result: " << result;
+ EXPECT_NE(std::string::npos, result.find("\t(to life the universe etc|3)"))
+ << "Command result: " << result;
+ EXPECT_NE(std::string::npos, result.find("answer")) << "Command result: " << result;
#else
GTEST_LOG_(INFO) << "This test does nothing.\n";
#endif
@@ -820,20 +518,22 @@
TEST(logd, getEventTag_newentry) {
#ifdef __ANDROID__
- char buffer[256];
- memset(buffer, 0, sizeof(buffer));
log_time now(CLOCK_MONOTONIC);
- char name[64];
- snprintf(name, sizeof(name), "a%" PRIu64, now.nsec());
- snprintf(buffer, sizeof(buffer), "getEventTag name=%s format=\"(new|1)\"",
- name);
- send_to_control(buffer, sizeof(buffer));
- buffer[sizeof(buffer) - 1] = '\0';
+ std::string name;
+ name = android::base::StringPrintf("a%" PRIu64, now.nsec());
+
+ std::string command;
+ command = android::base::StringPrintf("getEventTag name=%s format=\"(new|1)\"", name.c_str());
+
+ std::string result;
+ send_to_control(command.c_str(), result);
+ ASSERT_FALSE(result.empty());
+
char* cp;
- long ret = strtol(buffer, &cp, 10);
- EXPECT_GT(ret, 16);
- EXPECT_TRUE(strstr(buffer, "\t(new|1)") != nullptr);
- EXPECT_TRUE(strstr(buffer, name) != nullptr);
+ long ret = strtol(result.c_str(), &cp, 10);
+ EXPECT_GT(ret, 16) << "Command result: " << result;
+ EXPECT_NE(std::string::npos, result.find("\t(new|1)")) << "Command result: " << result;
+ EXPECT_NE(std::string::npos, result.find(name)) << "Command result: " << result;
// ToDo: also look for this in /data/misc/logd/event-log-tags and
// /dev/event-log-tags.
#else
@@ -849,20 +549,19 @@
for (int i = 0; i < 5; ++i) {
unique_fd sock1(
socket_local_client("logd", ANDROID_SOCKET_NAMESPACE_RESERVED, SOCK_STREAM));
- ASSERT_GT(sock1, 0);
+ ASSERT_LT(0, sock1) << "Failed to open logd: " << strerror(errno);
unique_fd sock2(
socket_local_client("logd", ANDROID_SOCKET_NAMESPACE_RESERVED, SOCK_STREAM));
- ASSERT_GT(sock2, 0);
+ ASSERT_LT(0, sock2) << "Failed to open logd: " << strerror(errno);
std::string message = "getStatistics 0 1 2 3 4 5 6 7";
-
- ASSERT_GT(write(sock1, message.c_str(), message.length()), 0);
+ ASSERT_TRUE(write_command(sock1, message));
sock1.reset();
- ASSERT_GT(write(sock2, message.c_str(), message.length()), 0);
+ ASSERT_TRUE(write_command(sock2, message));
struct pollfd p = {.fd = sock2, .events = POLLIN, .revents = 0};
- int ret = poll(&p, 1, 1000);
+ int ret = TEMP_FAILURE_RETRY(poll(&p, 1, 1000));
EXPECT_EQ(ret, 1);
EXPECT_TRUE(p.revents & POLLIN);
EXPECT_FALSE(p.revents & POLL_ERR);
@@ -902,7 +601,6 @@
};
ASSERT_EXIT(child_main(), testing::ExitedWithCode(0), "");
-
#else
GTEST_LOG_(INFO) << "This test does nothing.\n";
#endif
diff --git a/logwrapper/Android.bp b/logwrapper/Android.bp
index 8851a47..5b456ac 100644
--- a/logwrapper/Android.bp
+++ b/logwrapper/Android.bp
@@ -1,3 +1,19 @@
+package {
+ default_applicable_licenses: ["system_logging_logwrapper_license"],
+}
+
+// Added automatically by a large-scale-change
+license {
+ name: "system_logging_logwrapper_license",
+ visibility: [":__subpackages__"],
+ license_kinds: [
+ "SPDX-license-identifier-Apache-2.0",
+ ],
+ license_text: [
+ "NOTICE",
+ ],
+}
+
cc_defaults {
name: "logwrapper_defaults",
cflags: [
@@ -12,6 +28,8 @@
cc_library {
name: "liblogwrap",
defaults: ["logwrapper_defaults"],
+ ramdisk_available: true,
+ vendor_ramdisk_available: true,
recovery_available: true,
srcs: ["logwrap.cpp"],
shared_libs: [
diff --git a/rust/Android.bp b/rust/Android.bp
new file mode 100644
index 0000000..0292da1
--- /dev/null
+++ b/rust/Android.bp
@@ -0,0 +1,106 @@
+package {
+ default_applicable_licenses: ["Android-Apache-2.0"],
+}
+
+rust_library {
+ name: "liblogger",
+ host_supported: true,
+ crate_name: "logger",
+ srcs: ["logger.rs"],
+ rustlibs: [
+ "libenv_logger",
+ "liblog_rust",
+ ],
+ target: {
+ android: {
+ rustlibs: [
+ "libandroid_logger",
+ ]
+ },
+ },
+}
+
+rust_library {
+ name: "liblog_event_list",
+ crate_name: "log_event_list",
+ srcs: ["liblog_event_list.rs"],
+ rustlibs: ["liblog_event_list_bindgen"],
+ shared_libs: ["liblog"],
+}
+
+rust_defaults {
+ name: "liblogger_test_defaults",
+ crate_name: "logger",
+ test_suites: ["general-tests"],
+ auto_gen_config: true,
+ rustlibs: [
+ "liblogger",
+ "liblog_rust",
+ ]
+}
+
+rust_test {
+ name: "logger_device_unit_tests",
+ defaults: ["liblogger_test_defaults"],
+ srcs: ["logger.rs"],
+ rustlibs: [
+ "libenv_logger",
+ "libandroid_logger"
+ ]
+}
+
+rust_test_host {
+ name: "logger_host_unit_tests",
+ defaults: ["liblogger_test_defaults"],
+ srcs: ["logger.rs"],
+ rustlibs: ["libenv_logger"]
+}
+
+// The following tests are each run as separate targets because they all require a clean init state.
+rust_test {
+ name: "logger_device_test_default_init",
+ defaults: ["liblogger_test_defaults"],
+ srcs: ["tests/default_init.rs"],
+}
+
+rust_test_host {
+ name: "logger_host_test_default_init",
+ defaults: ["liblogger_test_defaults"],
+ srcs: ["tests/default_init.rs"],
+}
+
+rust_test {
+ name: "logger_device_test_env_log_level",
+ defaults: ["liblogger_test_defaults"],
+ srcs: ["tests/env_log_level.rs"],
+}
+
+rust_test_host {
+ name: "logger_host_test_env_log_level",
+ defaults: ["liblogger_test_defaults"],
+ srcs: ["tests/env_log_level.rs"],
+}
+
+rust_test {
+ name: "logger_device_test_config_log_level",
+ defaults: ["liblogger_test_defaults"],
+ srcs: ["tests/config_log_level.rs"],
+}
+
+rust_test_host {
+ name: "logger_host_test_config_log_level",
+ defaults: ["liblogger_test_defaults"],
+ srcs: ["tests/config_log_level.rs"],
+}
+
+rust_test {
+ name: "logger_device_test_multiple_init",
+ defaults: ["liblogger_test_defaults"],
+ srcs: ["tests/multiple_init.rs"],
+}
+
+rust_test_host {
+ name: "logger_host_test_multiple_init",
+ defaults: ["liblogger_test_defaults"],
+ srcs: ["tests/multiple_init.rs"],
+}
diff --git a/rust/PREUPLOAD.cfg b/rust/PREUPLOAD.cfg
new file mode 100644
index 0000000..68b351e
--- /dev/null
+++ b/rust/PREUPLOAD.cfg
@@ -0,0 +1,5 @@
+[Builtin Hooks]
+rustfmt = true
+
+[Builtin Hooks Options]
+rustfmt = --config-path=rustfmt.toml
\ No newline at end of file
diff --git a/rust/TEST_MAPPING b/rust/TEST_MAPPING
new file mode 100644
index 0000000..6f4be05
--- /dev/null
+++ b/rust/TEST_MAPPING
@@ -0,0 +1,21 @@
+// Host tests are run automatically in presubmit.
+// This file includes all device tests, as they test different behavior.
+{
+ "presubmit": [
+ {
+ "name": "logger_device_unit_tests"
+ },
+ {
+ "name": "logger_device_test_default_init"
+ },
+ {
+ "name": "logger_device_test_env_log_level"
+ },
+ {
+ "name": "logger_device_test_config_log_level"
+ },
+ {
+ "name": "logger_device_test_multiple_init"
+ }
+ ]
+}
\ No newline at end of file
diff --git a/rust/liblog_event_list.rs b/rust/liblog_event_list.rs
new file mode 100644
index 0000000..ed36e20
--- /dev/null
+++ b/rust/liblog_event_list.rs
@@ -0,0 +1,90 @@
+// Copyright 2021, 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.
+
+//! Provides interface for logging events to binary log buffers.
+
+use log_event_list_bindgen as log_bindgen;
+use std::os::raw::c_char;
+
+pub use log_bindgen::log_id_LOG_ID_SECURITY as LogIdSecurity;
+
+/// Whether security logging is enabled.
+fn security_log_enabled() -> bool {
+ // The call doesn't require any preconditions and only returns an int, so must be safe.
+ unsafe {
+ log_bindgen::__android_log_security() != 0
+ }
+}
+
+/// Event log context.
+pub struct LogContext {
+ ctx: log_bindgen::android_log_context,
+ log_type: log_bindgen::log_id
+}
+
+/// Log context is essentially a buffer with some associated state. All data that is appended to
+/// the context is copied into the buffers, no references are ever stored.
+unsafe impl Send for LogContext {}
+
+impl LogContext {
+ /// Creates a context for a given event tag.
+ pub fn new(log_type: log_bindgen::log_id, tag: u32) -> Option<LogContext> {
+ if log_type == log_bindgen::log_id_LOG_ID_SECURITY && !security_log_enabled() {
+ return None;
+ }
+
+ // The method returns a pointer that is stored and always freed exactly once via Drop below.
+ let ctx = unsafe { log_bindgen::create_android_logger(tag) };
+ if !ctx.is_null() {
+ Some(LogContext{ ctx, log_type })
+ } else {
+ None
+ }
+ }
+
+ /// Appends an i32 to the context.
+ pub fn append_i32(self, data: i32) -> Self {
+ // This will only be called on a non-null pointer returned from create_android_logger
+ // previously, so should be safe.
+ unsafe { log_bindgen::android_log_write_int32(self.ctx, data) };
+ self
+ }
+
+ /// Append a string to the context.
+ pub fn append_str(self, data: &str) -> Self {
+ // This will only be called on a non-null pointer returned from create_android_logger
+ // previously, and the function will only read data.len() characters from the str, the
+ // pointer itself won't be stored, so should be safe.
+ unsafe {
+ log_bindgen::android_log_write_string8_len(
+ self.ctx, data.as_ptr() as *const c_char, data.len())
+ };
+ self
+ }
+
+ /// Writes the context to a given buffer type and consumes the context.
+ pub fn write(self) {
+ // This will only be called on a non-null pointer returned from create_android_logger
+ // previously, so should be safe.
+ unsafe { log_bindgen::android_log_write_list(self.ctx, self.log_type) };
+ }
+}
+
+impl Drop for LogContext {
+ fn drop(&mut self) {
+ // This will only be called on a non-null pointer returned from create_android_logger
+ // previously, so should be safe.
+ unsafe { log_bindgen::android_log_destroy(&mut self.ctx) };
+ }
+}
diff --git a/rust/logger.rs b/rust/logger.rs
new file mode 100644
index 0000000..19deda1
--- /dev/null
+++ b/rust/logger.rs
@@ -0,0 +1,176 @@
+// Copyright 2021, 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.
+
+//! Provides a universal logger interface that allows logging both on-device (using android_logger)
+//! and on-host (using env_logger).
+//! On-host, this allows the use of the RUST_LOG environment variable as documented in
+//! https://docs.rs/env_logger.
+use std::ffi::CString;
+use std::sync::atomic::{AtomicBool, Ordering};
+
+static LOGGER_INITIALIZED: AtomicBool = AtomicBool::new(false);
+
+type FormatFn = Box<dyn Fn(&log::Record) -> String + Sync + Send>;
+
+/// Logger configuration, opportunistically mapped to configuration parameters for android_logger
+/// or env_logger where available.
+#[derive(Default)]
+pub struct Config<'a> {
+ log_level: Option<log::Level>,
+ custom_format: Option<FormatFn>,
+ filter: Option<&'a str>,
+ #[allow(dead_code)] // Field is only used on device, and ignored on host.
+ tag: Option<CString>,
+}
+
+/// Based on android_logger::Config
+impl<'a> Config<'a> {
+ /// Change the minimum log level.
+ ///
+ /// All values above the set level are logged. For example, if
+ /// `Warn` is set, the `Error` is logged too, but `Info` isn't.
+ pub fn with_min_level(mut self, level: log::Level) -> Self {
+ self.log_level = Some(level);
+ self
+ }
+
+ /// Set a log tag. Only used on device.
+ pub fn with_tag_on_device<S: Into<Vec<u8>>>(mut self, tag: S) -> Self {
+ self.tag = Some(CString::new(tag).expect("Can't convert tag to CString"));
+ self
+ }
+
+ /// Set the format function for formatting the log output.
+ /// ```
+ /// # use universal_logger::Config;
+ /// universal_logger::init(
+ /// Config::default()
+ /// .with_min_level(log::Level::Trace)
+ /// .format(|record| format!("my_app: {}", record.args()))
+ /// )
+ /// ```
+ pub fn format<F>(mut self, format: F) -> Self
+ where
+ F: Fn(&log::Record) -> String + Sync + Send + 'static,
+ {
+ self.custom_format = Some(Box::new(format));
+ self
+ }
+
+ /// Set a filter, using the format specified in https://docs.rs/env_logger.
+ pub fn with_filter(mut self, filter: &'a str) -> Self {
+ self.filter = Some(filter);
+ self
+ }
+}
+
+/// Initializes logging on host. Returns false if logging is already initialized.
+/// Config values take precedence over environment variables for host logging.
+#[cfg(not(target_os = "android"))]
+pub fn init(config: Config) -> bool {
+ // Return immediately if the logger is already initialized.
+ if LOGGER_INITIALIZED.fetch_or(true, Ordering::SeqCst) {
+ return false;
+ }
+
+ let mut builder = env_logger::Builder::from_default_env();
+ if let Some(log_level) = config.log_level {
+ builder.filter_level(log_level.to_level_filter());
+ }
+ if let Some(custom_format) = config.custom_format {
+ use std::io::Write; // Trait used by write!() macro, but not in Android code
+
+ builder.format(move |f, r| {
+ let formatted = custom_format(r);
+ writeln!(f, "{}", formatted)
+ });
+ }
+ if let Some(filter_str) = config.filter {
+ builder.parse_filters(filter_str);
+ }
+
+ builder.init();
+ true
+}
+
+/// Initializes logging on device. Returns false if logging is already initialized.
+#[cfg(target_os = "android")]
+pub fn init(config: Config) -> bool {
+ // Return immediately if the logger is already initialized.
+ if LOGGER_INITIALIZED.fetch_or(true, Ordering::SeqCst) {
+ return false;
+ }
+
+ // We do not have access to the private variables in android_logger::Config, so we have to use
+ // the builder instead.
+ let mut builder = android_logger::Config::default();
+ if let Some(log_level) = config.log_level {
+ builder = builder.with_min_level(log_level);
+ }
+ if let Some(custom_format) = config.custom_format {
+ builder = builder.format(move |f, r| {
+ let formatted = custom_format(r);
+ write!(f, "{}", formatted)
+ });
+ }
+ if let Some(filter_str) = config.filter {
+ let filter = env_logger::filter::Builder::new().parse(filter_str).build();
+ builder = builder.with_filter(filter);
+ }
+ if let Some(tag) = config.tag {
+ builder = builder.with_tag(tag);
+ }
+
+ android_logger::init_once(builder);
+ true
+}
+
+/// Note that the majority of tests checking behavior are under the tests/ folder, as they all
+/// require independent initialization steps. The local test module just performs some basic crash
+/// testing without performing initialization.
+#[cfg(test)]
+mod tests {
+ use super::*;
+
+ #[test]
+ fn test_with_min_level() {
+ let config = Config::default()
+ .with_min_level(log::Level::Trace)
+ .with_min_level(log::Level::Error);
+
+ assert_eq!(config.log_level, Some(log::Level::Error));
+ }
+
+ #[test]
+ fn test_with_filter() {
+ let filter = "debug,hello::crate=trace";
+ let config = Config::default().with_filter(filter);
+
+ assert_eq!(config.filter.unwrap(), filter)
+ }
+
+ #[test]
+ fn test_with_tag_on_device() {
+ let config = Config::default().with_tag_on_device("my_app");
+
+ assert_eq!(config.tag.unwrap(), CString::new("my_app").unwrap());
+ }
+
+ #[test]
+ fn test_format() {
+ let config = Config::default().format(|record| format!("my_app: {}", record.args()));
+
+ assert!(config.custom_format.is_some());
+ }
+}
diff --git a/rust/rustfmt.toml b/rust/rustfmt.toml
new file mode 100644
index 0000000..475ba8f
--- /dev/null
+++ b/rust/rustfmt.toml
@@ -0,0 +1 @@
+../../../build/soong/scripts/rustfmt.toml
\ No newline at end of file
diff --git a/rust/tests/config_log_level.rs b/rust/tests/config_log_level.rs
new file mode 100644
index 0000000..c4ff2d1
--- /dev/null
+++ b/rust/tests/config_log_level.rs
@@ -0,0 +1,17 @@
+use std::env;
+
+#[test]
+fn config_log_level() {
+ // Environment variables should be overwritten by config values.
+ env::set_var("RUST_LOG", "debug");
+
+ let init_result = logger::init(
+ logger::Config::default()
+ .with_min_level(log::Level::Trace));
+
+ assert!(init_result);
+ // Setting the level through the Config struct should impact both host and device
+ assert_eq!(log::max_level(), log::LevelFilter::Trace);
+
+ env::remove_var("RUST_LOG");
+}
\ No newline at end of file
diff --git a/rust/tests/default_init.rs b/rust/tests/default_init.rs
new file mode 100644
index 0000000..837677c
--- /dev/null
+++ b/rust/tests/default_init.rs
@@ -0,0 +1,12 @@
+#[test]
+fn default_init() {
+ assert!(logger::init(Default::default()));
+
+ if cfg!(target_os = "android") {
+ // android_logger has default log level "off"
+ assert_eq!(log::max_level(), log::LevelFilter::Off);
+ } else {
+ // env_logger has default log level "error"
+ assert_eq!(log::max_level(), log::LevelFilter::Error);
+ }
+}
\ No newline at end of file
diff --git a/rust/tests/env_log_level.rs b/rust/tests/env_log_level.rs
new file mode 100644
index 0000000..0534be3
--- /dev/null
+++ b/rust/tests/env_log_level.rs
@@ -0,0 +1,16 @@
+use std::env;
+
+#[test]
+fn env_log_level() {
+ env::set_var("RUST_LOG", "debug");
+ assert!(logger::init(Default::default()));
+
+ if cfg!(target_os = "android") {
+ // android_logger does not read from environment variables
+ assert_eq!(log::max_level(), log::LevelFilter::Off);
+ } else {
+ // env_logger reads its log level from the "RUST_LOG" environment variable
+ assert_eq!(log::max_level(), log::LevelFilter::Debug);
+ }
+ env::remove_var("RUST_LOG");
+}
\ No newline at end of file
diff --git a/rust/tests/multiple_init.rs b/rust/tests/multiple_init.rs
new file mode 100644
index 0000000..7928dcf
--- /dev/null
+++ b/rust/tests/multiple_init.rs
@@ -0,0 +1,8 @@
+#[test]
+fn multiple_init() {
+ let first_init = logger::init(Default::default());
+ let second_init = logger::init(Default::default());
+
+ assert!(first_init);
+ assert!(!second_init);
+}
\ No newline at end of file