Merge "Improve init bootcharting." am: 4ee7861ee1 am: a6532b4717

am: 1a947725b8

Change-Id: I7c2316e103f3610fbb0f7233f108f4a0b6891045
This commit is contained in:
Elliott Hughes 2016-12-16 17:55:40 +00:00 committed by android-build-merger
commit 352b9c6282
6 changed files with 99 additions and 153 deletions

View file

@ -34,29 +34,25 @@
#include <vector> #include <vector>
#include <android-base/file.h> #include <android-base/file.h>
#include <android-base/stringprintf.h>
#define LOG_ROOT "/data/bootchart" using android::base::StringPrintf;
#define LOG_STAT LOG_ROOT"/proc_stat.log"
#define LOG_PROCS LOG_ROOT"/proc_ps.log"
#define LOG_DISK LOG_ROOT"/proc_diskstats.log"
#define LOG_HEADER LOG_ROOT"/header"
#define LOG_ACCT LOG_ROOT"/kernel_pacct"
#define LOG_STARTFILE LOG_ROOT"/start" static constexpr const char* LOG_STAT = "/data/bootchart/proc_stat.log";
#define LOG_STOPFILE LOG_ROOT"/stop" static constexpr const char* LOG_PROC = "/data/bootchart/proc_ps.log";
static constexpr const char* LOG_DISK = "/data/bootchart/proc_diskstats.log";
static constexpr const char* LOG_HEADER = "/data/bootchart/header";
// Polling period in ms. // Polling period in ms.
static const int BOOTCHART_POLLING_MS = 200; static constexpr int BOOTCHART_POLLING_MS = 200;
// Max polling time in seconds.
static const int BOOTCHART_MAX_TIME_SEC = 10*60;
static long long g_last_bootchart_time; static long long g_last_bootchart_time;
static int g_remaining_samples;
static FILE* log_stat; static bool g_bootcharting = false;
static FILE* log_procs;
static FILE* log_disks; static FILE* g_stat_log;
static FILE* g_proc_log;
static FILE* g_disk_log;
static long long get_uptime_jiffies() { static long long get_uptime_jiffies() {
std::string uptime; std::string uptime;
@ -99,12 +95,12 @@ static void log_header() {
fclose(out); fclose(out);
} }
static void do_log_uptime(FILE* log) { static void log_uptime(FILE* log) {
fprintf(log, "%lld\n", get_uptime_jiffies()); fprintf(log, "%lld\n", get_uptime_jiffies());
} }
static void do_log_file(FILE* log, const char* procfile) { static void log_file(FILE* log, const char* procfile) {
do_log_uptime(log); log_uptime(log);
std::string content; std::string content;
if (android::base::ReadFileToString(procfile, &content)) { if (android::base::ReadFileToString(procfile, &content)) {
@ -112,29 +108,25 @@ static void do_log_file(FILE* log, const char* procfile) {
} }
} }
static void do_log_procs(FILE* log) { static void log_processes() {
do_log_uptime(log); log_uptime(g_proc_log);
std::unique_ptr<DIR, int(*)(DIR*)> dir(opendir("/proc"), closedir); std::unique_ptr<DIR, int(*)(DIR*)> dir(opendir("/proc"), closedir);
struct dirent* entry; struct dirent* entry;
while ((entry = readdir(dir.get())) != NULL) { while ((entry = readdir(dir.get())) != NULL) {
// Only match numeric values. // Only match numeric values.
char* end; int pid = atoi(entry->d_name);
int pid = strtol(entry->d_name, &end, 10); if (pid == 0) continue;
if (end != NULL && end > entry->d_name && *end == 0) {
char filename[32];
// /proc/<pid>/stat only has truncated task names, so get the full // /proc/<pid>/stat only has truncated task names, so get the full
// name from /proc/<pid>/cmdline. // name from /proc/<pid>/cmdline.
snprintf(filename, sizeof(filename), "/proc/%d/cmdline", pid);
std::string cmdline; std::string cmdline;
android::base::ReadFileToString(filename, &cmdline); android::base::ReadFileToString(StringPrintf("/proc/%d/cmdline", pid), &cmdline);
const char* full_name = cmdline.c_str(); // So we stop at the first NUL. const char* full_name = cmdline.c_str(); // So we stop at the first NUL.
// Read process stat line. // Read process stat line.
snprintf(filename, sizeof(filename), "/proc/%d/stat", pid);
std::string stat; std::string stat;
if (android::base::ReadFileToString(filename, &stat)) { if (android::base::ReadFileToString(StringPrintf("/proc/%d/stat", pid), &stat)) {
if (!cmdline.empty()) { if (!cmdline.empty()) {
// Substitute the process name with its real name. // Substitute the process name with its real name.
size_t open = stat.find('('); size_t open = stat.find('(');
@ -143,130 +135,88 @@ static void do_log_procs(FILE* log) {
stat.replace(open + 1, close - open - 1, full_name); stat.replace(open + 1, close - open - 1, full_name);
} }
} }
fputs(stat.c_str(), log); fputs(stat.c_str(), g_proc_log);
}
} }
} }
fputc('\n', log); fputc('\n', g_proc_log);
} }
static int bootchart_init() { static int do_bootchart_start() {
int timeout = 0; // We don't care about the content, but we do care that /data/bootchart/enabled actually exists.
std::string start; std::string start;
android::base::ReadFileToString(LOG_STARTFILE, &start); if (!android::base::ReadFileToString("/data/bootchart/enabled", &start)) {
if (!start.empty()) { LOG(VERBOSE) << "Not bootcharting";
timeout = atoi(start.c_str());
} else {
// When running with emulator, androidboot.bootchart=<timeout>
// might be passed by as kernel parameters to specify the bootchart
// timeout. this is useful when using -wipe-data since the /data
// partition is fresh.
std::string cmdline;
const char* s;
android::base::ReadFileToString("/proc/cmdline", &cmdline);
#define KERNEL_OPTION "androidboot.bootchart="
if ((s = strstr(cmdline.c_str(), KERNEL_OPTION)) != NULL) {
timeout = atoi(s + sizeof(KERNEL_OPTION) - 1);
}
}
if (timeout == 0)
return 0; return 0;
}
if (timeout > BOOTCHART_MAX_TIME_SEC) // Open log files.
timeout = BOOTCHART_MAX_TIME_SEC; std::unique_ptr<FILE, decltype(&fclose)> stat_log(fopen(LOG_STAT, "we"), fclose);
if (!stat_log) {
int count = (timeout*1000 + BOOTCHART_POLLING_MS-1)/BOOTCHART_POLLING_MS; PLOG(ERROR) << "Bootcharting couldn't open " << LOG_STAT;
log_stat = fopen(LOG_STAT, "we");
if (log_stat == NULL) {
return -1; return -1;
} }
log_procs = fopen(LOG_PROCS, "we"); std::unique_ptr<FILE, decltype(&fclose)> proc_log(fopen(LOG_PROC, "we"), fclose);
if (log_procs == NULL) { if (!proc_log) {
fclose(log_stat); PLOG(ERROR) << "Bootcharting couldn't open " << LOG_PROC;
return -1; return -1;
} }
log_disks = fopen(LOG_DISK, "we"); std::unique_ptr<FILE, decltype(&fclose)> disk_log(fopen(LOG_DISK, "we"), fclose);
if (log_disks == NULL) { if (!disk_log) {
fclose(log_stat); PLOG(ERROR) << "Bootcharting couldn't open " << LOG_DISK;
fclose(log_procs);
return -1; return -1;
} }
// Create kernel process accounting file. LOG(INFO) << "Bootcharting started";
close(open(LOG_ACCT, O_WRONLY | O_CREAT | O_TRUNC | O_CLOEXEC, 0644)); g_stat_log = stat_log.release();
acct(LOG_ACCT); g_proc_log = proc_log.release();
g_disk_log = disk_log.release();
g_bootcharting = true;
log_header(); log_header();
return count;
}
int do_bootchart_init(const std::vector<std::string>& args) {
g_remaining_samples = bootchart_init();
if (g_remaining_samples < 0) {
PLOG(ERROR) << "Bootcharting initialization failed";
} else if (g_remaining_samples > 0) {
LOG(INFO) << "Bootcharting started (will run for "
<< ((g_remaining_samples * BOOTCHART_POLLING_MS) / 1000) << " s).";
} else {
LOG(VERBOSE) << "Not bootcharting.";
}
return 0;
}
static int bootchart_step() {
do_log_file(log_stat, "/proc/stat");
do_log_file(log_disks, "/proc/diskstats");
do_log_procs(log_procs);
// Stop if /data/bootchart/stop contains 1.
std::string stop;
if (android::base::ReadFileToString(LOG_STOPFILE, &stop) && stop == "1") {
return -1;
}
return 0; return 0;
} }
/* called to get time (in ms) used by bootchart */ static void do_bootchart_step() {
static long long bootchart_gettime() { log_file(g_stat_log, "/proc/stat");
return 10LL*get_uptime_jiffies(); log_file(g_disk_log, "/proc/diskstats");
log_processes();
} }
static void bootchart_finish() { static int do_bootchart_stop() {
unlink(LOG_STOPFILE); if (!g_bootcharting) return 0;
fclose(log_stat);
fclose(log_disks);
fclose(log_procs);
acct(NULL);
LOG(INFO) << "Bootcharting finished"; LOG(INFO) << "Bootcharting finished";
g_bootcharting = false;
fclose(g_stat_log);
fclose(g_disk_log);
fclose(g_proc_log);
return 0;
}
int do_bootchart(const std::vector<std::string>& args) {
if (args[1] == "start") return do_bootchart_start();
return do_bootchart_stop();
} }
void bootchart_sample(int* timeout) { void bootchart_sample(int* timeout) {
// Do we have any more bootcharting to do? // Do we have any more bootcharting to do?
if (g_remaining_samples <= 0) { if (!g_bootcharting) return;
return;
}
long long current_time = bootchart_gettime(); long long current_time = 10LL * get_uptime_jiffies();
int elapsed_time = current_time - g_last_bootchart_time; int elapsed_time = current_time - g_last_bootchart_time;
if (elapsed_time >= BOOTCHART_POLLING_MS) { if (elapsed_time >= BOOTCHART_POLLING_MS) {
// Count missed samples.
while (elapsed_time >= BOOTCHART_POLLING_MS) { while (elapsed_time >= BOOTCHART_POLLING_MS) {
elapsed_time -= BOOTCHART_POLLING_MS; elapsed_time -= BOOTCHART_POLLING_MS;
g_remaining_samples--;
} }
// Count may be negative, take a sample anyway.
g_last_bootchart_time = current_time; g_last_bootchart_time = current_time;
if (bootchart_step() < 0 || g_remaining_samples <= 0) { do_bootchart_step();
bootchart_finish();
g_remaining_samples = 0;
} }
}
if (g_remaining_samples > 0) { // Schedule another?
if (g_bootcharting) {
int remaining_time = BOOTCHART_POLLING_MS - elapsed_time; int remaining_time = BOOTCHART_POLLING_MS - elapsed_time;
if (*timeout < 0 || *timeout > remaining_time) { if (*timeout < 0 || *timeout > remaining_time) {
*timeout = remaining_time; *timeout = remaining_time;

View file

@ -20,7 +20,7 @@
#include <string> #include <string>
#include <vector> #include <vector>
int do_bootchart_init(const std::vector<std::string>& args); int do_bootchart(const std::vector<std::string>& args);
void bootchart_sample(int* timeout); void bootchart_sample(int* timeout);
#endif /* _BOOTCHART_H */ #endif /* _BOOTCHART_H */

View file

@ -1028,7 +1028,7 @@ static int do_init_user0(const std::vector<std::string>& args) {
BuiltinFunctionMap::Map& BuiltinFunctionMap::map() const { BuiltinFunctionMap::Map& BuiltinFunctionMap::map() const {
constexpr std::size_t kMax = std::numeric_limits<std::size_t>::max(); constexpr std::size_t kMax = std::numeric_limits<std::size_t>::max();
static const Map builtin_functions = { static const Map builtin_functions = {
{"bootchart_init", {0, 0, do_bootchart_init}}, {"bootchart", {1, 1, do_bootchart}},
{"chmod", {2, 2, do_chmod}}, {"chmod", {2, 2, do_chmod}},
{"chown", {2, 3, do_chown}}, {"chown", {2, 3, do_chown}},
{"class_reset", {1, 1, do_class_reset}}, {"class_reset", {1, 1, do_class_reset}},

View file

@ -11,7 +11,7 @@ mkdir -p $TMPDIR
LOGROOT=/data/bootchart LOGROOT=/data/bootchart
TARBALL=bootchart.tgz TARBALL=bootchart.tgz
FILES="header proc_stat.log proc_ps.log proc_diskstats.log kernel_pacct" FILES="header proc_stat.log proc_ps.log proc_diskstats.log"
for f in $FILES; do for f in $FILES; do
adb "${@}" pull $LOGROOT/$f $TMPDIR/$f 2>&1 > /dev/null adb "${@}" pull $LOGROOT/$f $TMPDIR/$f 2>&1 > /dev/null

View file

@ -253,9 +253,10 @@ at three times,
Commands Commands
-------- --------
bootchart_init bootchart [start|stop]
Start bootcharting if configured (see below). Start/stop bootcharting. These are present in the default init.rc files,
This is included in the default init.rc. but bootcharting is only active if the file /data/bootchart/enabled exists;
otherwise bootchart start/stop are no-ops.
chmod <octal-mode> <path> chmod <octal-mode> <path>
Change file access permissions. Change file access permissions.
@ -471,19 +472,11 @@ files that can be later processed by the tools provided by www.bootchart.org.
On the emulator, use the -bootchart <timeout> option to boot with bootcharting On the emulator, use the -bootchart <timeout> option to boot with bootcharting
activated for <timeout> seconds. activated for <timeout> seconds.
On a device, create /data/bootchart/start with a command like the following: On a device:
adb shell 'echo $TIMEOUT > /data/bootchart/start' adb shell 'touch /data/bootchart/enabled'
Where the value of $TIMEOUT corresponds to the desired bootcharted period in Don't forget to delete this file when you're done collecting data!
seconds. Bootcharting will stop after that many seconds have elapsed.
You can also stop the bootcharting at any moment by doing the following:
adb shell 'echo 1 > /data/bootchart/stop'
Note that /data/bootchart/stop is deleted automatically by init at the end of
the bootcharting. This is not the case with /data/bootchart/start, so don't
forget to delete it when you're done collecting data.
The log files are written to /data/bootchart/. A script is provided to The log files are written to /data/bootchart/. A script is provided to
retrieve them and create a bootchart.tgz file that can be used with the retrieve them and create a bootchart.tgz file that can be used with the

View file

@ -366,7 +366,7 @@ on post-fs-data
# Start bootcharting as soon as possible after the data partition is # Start bootcharting as soon as possible after the data partition is
# mounted to collect more data. # mounted to collect more data.
mkdir /data/bootchart 0755 shell shell mkdir /data/bootchart 0755 shell shell
bootchart_init bootchart start
# Avoid predictable entropy pool. Carry over entropy from previous boot. # Avoid predictable entropy pool. Carry over entropy from previous boot.
copy /data/system/entropy.dat /dev/urandom copy /data/system/entropy.dat /dev/urandom
@ -624,6 +624,9 @@ on property:vold.decrypt=trigger_shutdown_framework
on property:sys.powerctl=* on property:sys.powerctl=*
powerctl ${sys.powerctl} powerctl ${sys.powerctl}
on property:sys.boot_completed=1
bootchart stop
# system server cannot write to /proc/sys files, # system server cannot write to /proc/sys files,
# and chown/chmod does not work for /proc/sys/ entries. # and chown/chmod does not work for /proc/sys/ entries.
# So proxy writes through init. # So proxy writes through init.