From a073c3961602518d96cab1f4ec58ad75aee81b24 Mon Sep 17 00:00:00 2001 From: Mark Salyzyn Date: Mon, 3 Apr 2017 09:30:20 -0700 Subject: [PATCH] logcatd: introduce logcatd executable logcatd is the same as logcat, except that the -L flag, if supplied, runs once, then the command re-runs itself without the -L flag with the same argument set. By introducing a logcatd daemon executable we can solve the problem of the longish reads from pstore that sometimes occur when the system is excessively busy, starving this background cgroup daemon as we absorb the delay in a backgrounded init "service", rather than in a forgrounded init "exec". This would not have been efficiently possible without the introduction of liblogcat. There are no doubt many flags that make no sense to run twice with, and without, the -L flag. In the general sense we expect the caller to perform the correct set of operations and not pick these nonsense operations. logcatd is only supplied on engineering and debug builds for logpersist, and is only an automated aid to triage. Test: gTest logcat-unit-tests Test: manual confirm logpersist functions as expected, required reboot Bug: 28788401 Bug: 30041146 Bug: 30612424 Bug: 35326290 Change-Id: I53ba31970749daf37eef42636f039f485932416f --- logcat/Android.mk | 10 +++ logcat/logcatd.rc | 5 +- logcat/logcatd_main.cpp | 71 +++++++++++++++++++ logcat/tests/Android.mk | 1 + logcat/tests/logcat_test.cpp | 124 ++++++++++++++++++---------------- logcat/tests/logcatd_test.cpp | 20 ++++++ 6 files changed, 169 insertions(+), 62 deletions(-) create mode 100644 logcat/logcatd_main.cpp create mode 100644 logcat/tests/logcatd_test.cpp diff --git a/logcat/Android.mk b/logcat/Android.mk index f564f0fc5..4e11ca909 100644 --- a/logcat/Android.mk +++ b/logcat/Android.mk @@ -15,6 +15,16 @@ include $(BUILD_EXECUTABLE) include $(CLEAR_VARS) +LOCAL_MODULE := logcatd +LOCAL_MODULE_TAGS := debug +LOCAL_SRC_FILES := logcatd_main.cpp event.logtags +LOCAL_SHARED_LIBRARIES := liblogcat $(logcatLibs) +LOCAL_CFLAGS := -Werror + +include $(BUILD_EXECUTABLE) + +include $(CLEAR_VARS) + LOCAL_MODULE := liblogcat LOCAL_SRC_FILES := logcat.cpp getopt_long.cpp logcat_system.cpp LOCAL_SHARED_LIBRARIES := $(logcatLibs) diff --git a/logcat/logcatd.rc b/logcat/logcatd.rc index b082a6421..06cc90d59 100644 --- a/logcat/logcatd.rc +++ b/logcat/logcatd.rc @@ -34,9 +34,6 @@ on load_persist_props_action on property:logd.logpersistd.enable=true && property:logd.logpersistd=logcatd # all exec/services are called with umask(077), so no gain beyond 0700 mkdir /data/misc/logd 0700 logd log - # logd for write to /data/misc/logd, log group for read from pstore (-L) - # b/28788401 b/30041146 b/30612424 - # exec - logd log -- /system/bin/logcat -L -b ${logd.logpersistd.buffer:-all} -v threadtime -v usec -v printable -D -f /data/misc/logd/logcat -r 1024 -n ${logd.logpersistd.size:-256} --id=${ro.build.id} start logcatd # stop logcatd service and clear data @@ -57,7 +54,7 @@ on property:logd.logpersistd.enable=false stop logcatd # logcatd service -service logcatd /system/bin/logcat -b ${logd.logpersistd.buffer:-all} -v threadtime -v usec -v printable -D -f /data/misc/logd/logcat -r 1024 -n ${logd.logpersistd.size:-256} --id=${ro.build.id} +service logcatd /system/bin/logcatd -L -b ${logd.logpersistd.buffer:-all} -v threadtime -v usec -v printable -D -f /data/misc/logd/logcat -r 1024 -n ${logd.logpersistd.size:-256} --id=${ro.build.id} class late_start disabled # logd for write to /data/misc/logd, log group for read from log daemon diff --git a/logcat/logcatd_main.cpp b/logcat/logcatd_main.cpp new file mode 100644 index 000000000..9109eb11c --- /dev/null +++ b/logcat/logcatd_main.cpp @@ -0,0 +1,71 @@ +/* + * Copyright (C) 2017 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 +#include +#include + +#include +#include + +#include + +int main(int argc, char** argv, char** envp) { + android_logcat_context ctx = create_android_logcat(); + if (!ctx) return -1; + + signal(SIGPIPE, exit); + + // Save and detect presence of -L or --last flag + std::vector args; + bool last = false; + for (int i = 0; i < argc; ++i) { + if (!argv[i]) continue; + args.push_back(std::string(argv[i])); + if (!strcmp(argv[i], "-L") || !strcmp(argv[i], "--last")) last = true; + } + + // Generate argv from saved content + std::vector argv_hold; + for (auto& str : args) argv_hold.push_back(str.c_str()); + argv_hold.push_back(nullptr); + + int ret = 0; + if (last) { + // Run logcat command with -L flag + ret = android_logcat_run_command(ctx, -1, -1, argv_hold.size() - 1, + (char* const*)&argv_hold[0], envp); + // Remove -L and --last flags from argument list + for (std::vector::iterator it = argv_hold.begin(); + it != argv_hold.end();) { + if (!*it || (strcmp(*it, "-L") && strcmp(*it, "--last"))) { + ++it; + } else { + it = argv_hold.erase(it); + } + } + // fall through to re-run the command regardless of the arguments + // passed in. For instance, we expect -h to report help stutter. + } + + // Run logcat command without -L flag + int retval = android_logcat_run_command(ctx, -1, -1, argv_hold.size() - 1, + (char* const*)&argv_hold[0], envp); + if (!ret) ret = retval; + retval = android_logcat_destroy(&ctx); + if (!ret) ret = retval; + return ret; +} diff --git a/logcat/tests/Android.mk b/logcat/tests/Android.mk index 22aca172a..defd3c490 100644 --- a/logcat/tests/Android.mk +++ b/logcat/tests/Android.mk @@ -50,6 +50,7 @@ include $(BUILD_NATIVE_BENCHMARK) test_src_files := \ logcat_test.cpp \ + logcatd_test.cpp \ liblogcat_test.cpp \ # Build tests for the device (with .so). Run with: diff --git a/logcat/tests/logcat_test.cpp b/logcat/tests/logcat_test.cpp index d802b2663..21868f2c7 100644 --- a/logcat/tests/logcat_test.cpp +++ b/logcat/tests/logcat_test.cpp @@ -20,6 +20,7 @@ #include #include #include +#include #include #include #include @@ -39,6 +40,10 @@ #define logcat_pclose(context, fp) pclose(fp) #define logcat_system(command) system(command) #endif +#ifndef logcat_executable +#define USING_LOGCAT_EXECUTABLE_DEFAULT +#define logcat_executable "logcat" +#endif #define BIG_BUFFER (5 * 1024) @@ -64,14 +69,13 @@ TEST(logcat, buckets) { #undef LOG_TAG #define LOG_TAG "inject" - RLOGE("logcat.buckets"); + RLOGE(logcat_executable ".buckets"); sleep(1); - ASSERT_TRUE( - NULL != - (fp = logcat_popen( - ctx, - "logcat -b radio -b events -b system -b main -d 2>/dev/null"))); + ASSERT_TRUE(NULL != + (fp = logcat_popen( + ctx, logcat_executable + " -b radio -b events -b system -b main -d 2>/dev/null"))); char buffer[BIG_BUFFER]; @@ -101,8 +105,8 @@ TEST(logcat, event_tag_filter) { logcat_define(ctx); ASSERT_TRUE(NULL != - (fp = logcat_popen(ctx, - "logcat -b events -d -s auditd " + (fp = logcat_popen(ctx, logcat_executable + " -b events -d -s auditd " "am_proc_start am_pss am_proc_bound " "dvm_lock_sample am_wtf 2>/dev/null"))); @@ -170,10 +174,9 @@ TEST(logcat, year) { #endif strftime(needle, sizeof(needle), "[ %Y-", ptm); - ASSERT_TRUE( - NULL != - (fp = logcat_popen( - ctx, "logcat -v long -v year -b all -t 3 2>/dev/null"))); + ASSERT_TRUE(NULL != (fp = logcat_popen( + ctx, logcat_executable + " -v long -v year -b all -t 3 2>/dev/null"))); char buffer[BIG_BUFFER]; @@ -237,8 +240,8 @@ TEST(logcat, tz) { logcat_define(ctx); ASSERT_TRUE(NULL != - (fp = logcat_popen(ctx, - "logcat -v long -v America/Los_Angeles " + (fp = logcat_popen(ctx, logcat_executable + " -v long -v America/Los_Angeles " "-b all -t 3 2>/dev/null"))); char buffer[BIG_BUFFER]; @@ -264,10 +267,9 @@ TEST(logcat, ntz) { FILE* fp; logcat_define(ctx); - ASSERT_TRUE(NULL != - (fp = logcat_popen(ctx, - "logcat -v long -v America/Los_Angeles -v " - "zone -b all -t 3 2>/dev/null"))); + ASSERT_TRUE(NULL != (fp = logcat_popen(ctx, logcat_executable + " -v long -v America/Los_Angeles -v " + "zone -b all -t 3 2>/dev/null"))); char buffer[BIG_BUFFER]; @@ -435,11 +437,11 @@ static void do_tail_time(const char* cmd) { } TEST(logcat, tail_time) { - do_tail_time("logcat -v long -v nsec -b all"); + do_tail_time(logcat_executable " -v long -v nsec -b all"); } TEST(logcat, tail_time_epoch) { - do_tail_time("logcat -v long -v nsec -v epoch -b all"); + do_tail_time(logcat_executable " -v long -v nsec -v epoch -b all"); } TEST(logcat, End_to_End) { @@ -452,8 +454,8 @@ TEST(logcat, End_to_End) { FILE* fp; logcat_define(ctx); ASSERT_TRUE(NULL != - (fp = logcat_popen( - ctx, "logcat -v brief -b events -t 100 2>/dev/null"))); + (fp = logcat_popen(ctx, logcat_executable + " -v brief -b events -t 100 2>/dev/null"))); char buffer[BIG_BUFFER]; @@ -492,8 +494,8 @@ TEST(logcat, End_to_End_multitude) { size_t num = 0; do { EXPECT_TRUE(NULL != - (fp[num] = logcat_popen( - ctx[num], "logcat -v brief -b events -t 100"))); + (fp[num] = logcat_popen(ctx[num], logcat_executable + " -v brief -b events -t 100"))); if (!fp[num]) { fprintf(stderr, "WARNING: limiting to %zu simultaneous logcat operations\n", @@ -604,22 +606,23 @@ static int get_groups(const char* cmd) { } TEST(logcat, get_size) { - ASSERT_EQ(4, get_groups("logcat -v brief -b radio -b events -b system -b " + ASSERT_EQ(4, get_groups(logcat_executable + " -v brief -b radio -b events -b system -b " "main -g 2>/dev/null")); } // duplicate test for get_size, but use comma-separated list of buffers TEST(logcat, multiple_buffer) { ASSERT_EQ( - 4, get_groups( - "logcat -v brief -b radio,events,system,main -g 2>/dev/null")); + 4, get_groups(logcat_executable + " -v brief -b radio,events,system,main -g 2>/dev/null")); } TEST(logcat, bad_buffer) { - ASSERT_EQ( - 0, - get_groups( - "logcat -v brief -b radio,events,bogo,system,main -g 2>/dev/null")); + ASSERT_EQ(0, + get_groups( + logcat_executable + " -v brief -b radio,events,bogo,system,main -g 2>/dev/null")); } #ifndef logcat @@ -774,8 +777,8 @@ TEST(logcat, logrotate) { char buf[sizeof(form)]; ASSERT_TRUE(NULL != mkdtemp(strcpy(buf, form))); - static const char comm[] = - "logcat -b radio -b events -b system -b main" + static const char comm[] = logcat_executable + " -b radio -b events -b system -b main" " -d -f %s/log.txt -n 7 -r 1"; char command[sizeof(buf) + sizeof(comm)]; snprintf(command, sizeof(command), comm, buf); @@ -820,8 +823,8 @@ TEST(logcat, logrotate_suffix) { char tmp_out_dir[sizeof(tmp_out_dir_form)]; ASSERT_TRUE(NULL != mkdtemp(strcpy(tmp_out_dir, tmp_out_dir_form))); - static const char logcat_cmd[] = - "logcat -b radio -b events -b system -b main" + static const char logcat_cmd[] = logcat_executable + " -b radio -b events -b system -b main" " -d -f %s/log.txt -n 10 -r 1"; char command[sizeof(tmp_out_dir) + sizeof(logcat_cmd)]; snprintf(command, sizeof(command), logcat_cmd, tmp_out_dir); @@ -880,7 +883,7 @@ TEST(logcat, logrotate_continue) { static const char log_filename[] = "log.txt"; static const char logcat_cmd[] = - "logcat -b all -v nsec -d -f %s/%s -n 256 -r 1024"; + logcat_executable " -b all -v nsec -d -f %s/%s -n 256 -r 1024"; static const char cleanup_cmd[] = "rm -rf %s"; char command[sizeof(tmp_out_dir) + sizeof(logcat_cmd) + sizeof(log_filename)]; snprintf(command, sizeof(command), logcat_cmd, tmp_out_dir, log_filename); @@ -1005,7 +1008,8 @@ TEST(logcat, logrotate_clear) { static const char log_filename[] = "log.txt"; static const unsigned num_val = 32; - static const char logcat_cmd[] = "logcat -b all -d -f %s/%s -n %d -r 1"; + static const char logcat_cmd[] = + logcat_executable " -b all -d -f %s/%s -n %d -r 1"; static const char clear_cmd[] = " -c"; static const char cleanup_cmd[] = "rm -rf %s"; char command[sizeof(tmp_out_dir) + sizeof(logcat_cmd) + @@ -1109,9 +1113,9 @@ static int logrotate_count_id(const char* logcat_cmd, const char* tmp_out_dir) { TEST(logcat, logrotate_id) { static const char logcat_cmd[] = - "logcat -b all -d -f %s/%s -n 32 -r 1 --id=test"; + logcat_executable " -b all -d -f %s/%s -n 32 -r 1 --id=test"; static const char logcat_short_cmd[] = - "logcat -b all -t 10 -f %s/%s -n 32 -r 1 --id=test"; + logcat_executable " -b all -t 10 -f %s/%s -n 32 -r 1 --id=test"; static const char tmp_out_dir_form[] = "/data/local/tmp/logcat.logrotate.XXXXXX"; static const char log_filename[] = "log.txt"; @@ -1155,8 +1159,8 @@ TEST(logcat, logrotate_id) { TEST(logcat, logrotate_nodir) { // expect logcat to error out on writing content and not exit(0) for nodir - static const char command[] = - "logcat -b all -d" + static const char command[] = logcat_executable + " -b all -d" " -f /das/nein/gerfingerpoken/logcat/log.txt" " -n 256 -r 1024"; EXPECT_FALSE(IsFalse(0 == logcat_system(command), command)); @@ -1292,7 +1296,7 @@ static bool get_white_black(char** list) { FILE* fp; logcat_define(ctx); - fp = logcat_popen(ctx, "logcat -p 2>/dev/null"); + fp = logcat_popen(ctx, logcat_executable " -p 2>/dev/null"); if (fp == NULL) { fprintf(stderr, "ERROR: logcat -p 2>/dev/null\n"); return false; @@ -1330,7 +1334,8 @@ static bool set_white_black(const char* list) { char buffer[BIG_BUFFER]; - snprintf(buffer, sizeof(buffer), "logcat -P '%s' 2>&1", list ? list : ""); + snprintf(buffer, sizeof(buffer), logcat_executable " -P '%s' 2>&1", + list ? list : ""); fp = logcat_popen(ctx, buffer); if (fp == NULL) { fprintf(stderr, "ERROR: %s\n", buffer); @@ -1392,15 +1397,11 @@ TEST(logcat, regex) { int count = 0; char buffer[BIG_BUFFER]; -// Have to make liblogcat data unique from logcat data injection -#ifdef logcat -#define logcat_regex_prefix "lolcat_test" -#else -#define logcat_regex_prefix "logcat_test" -#endif +#define logcat_regex_prefix ___STRING(logcat) "_test" snprintf(buffer, sizeof(buffer), - "logcat --pid %d -d -e " logcat_regex_prefix "_a+b", getpid()); + logcat_executable " --pid %d -d -e " logcat_regex_prefix "_a+b", + getpid()); LOG_FAILURE_RETRY(__android_log_print(ANDROID_LOG_WARN, logcat_regex_prefix, logcat_regex_prefix "_ab")); @@ -1437,8 +1438,8 @@ TEST(logcat, maxcount) { char buffer[BIG_BUFFER]; - snprintf(buffer, sizeof(buffer), "logcat --pid %d -d --max-count 3", - getpid()); + snprintf(buffer, sizeof(buffer), + logcat_executable " --pid %d -d --max-count 3", getpid()); LOG_FAILURE_RETRY( __android_log_print(ANDROID_LOG_WARN, "logcat_test", "logcat_test")); @@ -1663,10 +1664,11 @@ static bool reportedSecurity(const char* command) { } TEST(logcat, security) { - EXPECT_FALSE(reportedSecurity("logcat -b all -g 2>&1")); - EXPECT_TRUE(reportedSecurity("logcat -b security -g 2>&1")); - EXPECT_TRUE(reportedSecurity("logcat -b security -c 2>&1")); - EXPECT_TRUE(reportedSecurity("logcat -b security -G 256K 2>&1")); + EXPECT_FALSE(reportedSecurity(logcat_executable " -b all -g 2>&1")); + EXPECT_TRUE(reportedSecurity(logcat_executable " -b security -g 2>&1")); + EXPECT_TRUE(reportedSecurity(logcat_executable " -b security -c 2>&1")); + EXPECT_TRUE( + reportedSecurity(logcat_executable " -b security -G 256K 2>&1")); } static size_t commandOutputSize(const char* command) { @@ -1682,8 +1684,14 @@ static size_t commandOutputSize(const char* command) { } TEST(logcat, help) { - size_t logcatHelpTextSize = commandOutputSize("logcat -h 2>&1"); + size_t logcatHelpTextSize = commandOutputSize(logcat_executable " -h 2>&1"); EXPECT_LT(4096UL, logcatHelpTextSize); - size_t logcatLastHelpTextSize = commandOutputSize("logcat -L -h 2>&1"); + size_t logcatLastHelpTextSize = + commandOutputSize(logcat_executable " -L -h 2>&1"); +#ifdef USING_LOGCAT_EXECUTABLE_DEFAULT // logcat and liblogcat EXPECT_EQ(logcatHelpTextSize, logcatLastHelpTextSize); +#else + // logcatd -L -h prints the help twice, as designed. + EXPECT_EQ(logcatHelpTextSize * 2, logcatLastHelpTextSize); +#endif } diff --git a/logcat/tests/logcatd_test.cpp b/logcat/tests/logcatd_test.cpp new file mode 100644 index 000000000..bb7534e10 --- /dev/null +++ b/logcat/tests/logcatd_test.cpp @@ -0,0 +1,20 @@ +/* + * Copyright (C) 2017 The Android Open Source Project + * + * Licensed under the Apache License, Version 2.0 (the "License"); + * you may not use this file except in compliance with the License. + * You may obtain a copy of the License at + * + * http://www.apache.org/licenses/LICENSE-2.0 + * + * Unless required by applicable law or agreed to in writing, software + * distributed under the License is distributed on an "AS IS" BASIS, + * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. + * See the License for the specific language governing permissions and + * limitations under the License. + */ + +#define logcat logcatd +#define logcat_executable "logcatd" + +#include "logcat_test.cpp"