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
This commit is contained in:
Mark Salyzyn 2017-04-03 09:30:20 -07:00
parent e74e51ded7
commit a073c39616
6 changed files with 169 additions and 62 deletions

View file

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

View file

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

71
logcat/logcatd_main.cpp Normal file
View file

@ -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 <signal.h>
#include <stdlib.h>
#include <string.h>
#include <string>
#include <vector>
#include <log/logcat.h>
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<std::string> 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<const char*> 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<const char*>::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;
}

View file

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

View file

@ -20,6 +20,7 @@
#include <stdio.h>
#include <stdlib.h>
#include <string.h>
#include <sys/cdefs.h>
#include <sys/stat.h>
#include <sys/types.h>
#include <sys/wait.h>
@ -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
}

View file

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