From c249794628d4ebf721cf74065a75ece696398802 Mon Sep 17 00:00:00 2001 From: Elliott Hughes Date: Fri, 16 Dec 2016 14:45:17 -0800 Subject: [PATCH] Move init bootcharting onto its own thread. This reduces the overhead when bootcharting is on (obviously), but also removes the "do we need to do anything for bootcharting?" check in cases where we're not bootcharting. Bug: http://b/23478578 Bug: http://b/33450491 Test: rebooted with bootcharting on/off Change-Id: Id8746b5023b17d7615679eba0bcd02aee048ef1a --- init/bootchart.cpp | 269 ++++++++++++++++++++------------------------- init/bootchart.h | 1 - init/init.cpp | 2 - 3 files changed, 121 insertions(+), 151 deletions(-) diff --git a/init/bootchart.cpp b/init/bootchart.cpp index 7a8a3d53f..4a9c32e2c 100644 --- a/init/bootchart.cpp +++ b/init/bootchart.cpp @@ -15,7 +15,7 @@ */ #include "bootchart.h" -#include "log.h" + #include "property_service.h" #include @@ -29,197 +29,170 @@ #include #include +#include +#include #include +#include #include +#include #include #include +#include #include using android::base::StringPrintf; +using namespace std::chrono_literals; -static constexpr const char* LOG_STAT = "/data/bootchart/proc_stat.log"; -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"; +static std::thread* g_bootcharting_thread; -// Polling period in ms. -static constexpr int BOOTCHART_POLLING_MS = 200; - -static long long g_last_bootchart_time; - -static bool g_bootcharting = false; - -static FILE* g_stat_log; -static FILE* g_proc_log; -static FILE* g_disk_log; +static std::mutex g_bootcharting_finished_mutex; +static std::condition_variable g_bootcharting_finished_cv; +static bool g_bootcharting_finished; static long long get_uptime_jiffies() { - std::string uptime; - if (!android::base::ReadFileToString("/proc/uptime", &uptime)) { - return 0; - } - return 100LL * strtod(uptime.c_str(), NULL); + std::string uptime; + if (!android::base::ReadFileToString("/proc/uptime", &uptime)) return 0; + return 100LL * strtod(uptime.c_str(), NULL); +} + +static std::unique_ptr fopen_unique(const char* filename, + const char* mode) { + std::unique_ptr result(fopen(filename, mode), fclose); + if (!result) PLOG(ERROR) << "bootchart: failed to open " << filename; + return result; } static void log_header() { - char date[32]; - time_t now_t = time(NULL); - struct tm now = *localtime(&now_t); - strftime(date, sizeof(date), "%F %T", &now); + char date[32]; + time_t now_t = time(NULL); + struct tm now = *localtime(&now_t); + strftime(date, sizeof(date), "%F %T", &now); - utsname uts; - if (uname(&uts) == -1) { - return; - } + utsname uts; + if (uname(&uts) == -1) return; - std::string fingerprint = property_get("ro.build.fingerprint"); - if (fingerprint.empty()) { - return; - } + std::string fingerprint = property_get("ro.build.fingerprint"); + if (fingerprint.empty()) return; - std::string kernel_cmdline; - android::base::ReadFileToString("/proc/cmdline", &kernel_cmdline); + std::string kernel_cmdline; + android::base::ReadFileToString("/proc/cmdline", &kernel_cmdline); - FILE* out = fopen(LOG_HEADER, "we"); - if (out == NULL) { - return; - } - fprintf(out, "version = Android init 0.8\n"); - fprintf(out, "title = Boot chart for Android (%s)\n", date); - fprintf(out, "system.uname = %s %s %s %s\n", uts.sysname, uts.release, uts.version, uts.machine); - fprintf(out, "system.release = %s\n", fingerprint.c_str()); - // TODO: use /proc/cpuinfo "model name" line for x86, "Processor" line for arm. - fprintf(out, "system.cpu = %s\n", uts.machine); - fprintf(out, "system.kernel.options = %s\n", kernel_cmdline.c_str()); - fclose(out); + auto fp = fopen_unique("/data/bootchart/header", "we"); + if (!fp) return; + fprintf(&*fp, "version = Android init 0.8\n"); + fprintf(&*fp, "title = Boot chart for Android (%s)\n", date); + fprintf(&*fp, "system.uname = %s %s %s %s\n", uts.sysname, uts.release, uts.version, uts.machine); + fprintf(&*fp, "system.release = %s\n", fingerprint.c_str()); + // TODO: use /proc/cpuinfo "model name" line for x86, "Processor" line for arm. + fprintf(&*fp, "system.cpu = %s\n", uts.machine); + fprintf(&*fp, "system.kernel.options = %s\n", kernel_cmdline.c_str()); } static void log_uptime(FILE* log) { - fprintf(log, "%lld\n", get_uptime_jiffies()); + fprintf(log, "%lld\n", get_uptime_jiffies()); } static void log_file(FILE* log, const char* procfile) { - log_uptime(log); + log_uptime(log); - std::string content; - if (android::base::ReadFileToString(procfile, &content)) { - fprintf(log, "%s\n", content.c_str()); - } + std::string content; + if (android::base::ReadFileToString(procfile, &content)) { + fprintf(log, "%s\n", content.c_str()); + } } -static void log_processes() { - log_uptime(g_proc_log); +static void log_processes(FILE* log) { + log_uptime(log); - std::unique_ptr dir(opendir("/proc"), closedir); - struct dirent* entry; - while ((entry = readdir(dir.get())) != NULL) { - // Only match numeric values. - int pid = atoi(entry->d_name); - if (pid == 0) continue; + std::unique_ptr dir(opendir("/proc"), closedir); + struct dirent* entry; + while ((entry = readdir(dir.get())) != NULL) { + // Only match numeric values. + int pid = atoi(entry->d_name); + if (pid == 0) continue; - // /proc//stat only has truncated task names, so get the full - // name from /proc//cmdline. - std::string cmdline; - android::base::ReadFileToString(StringPrintf("/proc/%d/cmdline", pid), &cmdline); - const char* full_name = cmdline.c_str(); // So we stop at the first NUL. + // /proc//stat only has truncated task names, so get the full + // name from /proc//cmdline. + std::string cmdline; + android::base::ReadFileToString(StringPrintf("/proc/%d/cmdline", pid), &cmdline); + const char* full_name = cmdline.c_str(); // So we stop at the first NUL. - // Read process stat line. - std::string stat; - if (android::base::ReadFileToString(StringPrintf("/proc/%d/stat", pid), &stat)) { - if (!cmdline.empty()) { - // Substitute the process name with its real name. - size_t open = stat.find('('); - size_t close = stat.find_last_of(')'); - if (open != std::string::npos && close != std::string::npos) { - stat.replace(open + 1, close - open - 1, full_name); - } - } - fputs(stat.c_str(), g_proc_log); + // Read process stat line. + std::string stat; + if (android::base::ReadFileToString(StringPrintf("/proc/%d/stat", pid), &stat)) { + if (!cmdline.empty()) { + // Substitute the process name with its real name. + size_t open = stat.find('('); + size_t close = stat.find_last_of(')'); + if (open != std::string::npos && close != std::string::npos) { + stat.replace(open + 1, close - open - 1, full_name); } + } + fputs(stat.c_str(), log); + } + } + + fputc('\n', log); +} + +static void bootchart_thread_main() { + LOG(INFO) << "Bootcharting started"; + + // Open log files. + auto stat_log = fopen_unique("/data/bootchart/proc_stat.log", "we"); + if (!stat_log) return; + auto proc_log = fopen_unique("/data/bootchart/proc_ps.log", "we"); + if (!proc_log) return; + auto disk_log = fopen_unique("/data/bootchart/proc_diskstats.log", "we"); + if (!disk_log) return; + + log_header(); + + while (true) { + { + std::unique_lock lock(g_bootcharting_finished_mutex); + g_bootcharting_finished_cv.wait_for(lock, 200ms); + if (g_bootcharting_finished) break; } - fputc('\n', g_proc_log); + log_file(&*stat_log, "/proc/stat"); + log_file(&*disk_log, "/proc/diskstats"); + log_processes(&*proc_log); + } + + LOG(INFO) << "Bootcharting finished"; } static int do_bootchart_start() { - // We don't care about the content, but we do care that /data/bootchart/enabled actually exists. - std::string start; - if (!android::base::ReadFileToString("/data/bootchart/enabled", &start)) { - LOG(VERBOSE) << "Not bootcharting"; - return 0; - } - - // Open log files. - std::unique_ptr stat_log(fopen(LOG_STAT, "we"), fclose); - if (!stat_log) { - PLOG(ERROR) << "Bootcharting couldn't open " << LOG_STAT; - return -1; - } - std::unique_ptr proc_log(fopen(LOG_PROC, "we"), fclose); - if (!proc_log) { - PLOG(ERROR) << "Bootcharting couldn't open " << LOG_PROC; - return -1; - } - std::unique_ptr disk_log(fopen(LOG_DISK, "we"), fclose); - if (!disk_log) { - PLOG(ERROR) << "Bootcharting couldn't open " << LOG_DISK; - return -1; - } - - LOG(INFO) << "Bootcharting started"; - g_stat_log = stat_log.release(); - g_proc_log = proc_log.release(); - g_disk_log = disk_log.release(); - g_bootcharting = true; - log_header(); - + // We don't care about the content, but we do care that /data/bootchart/enabled actually exists. + std::string start; + if (!android::base::ReadFileToString("/data/bootchart/enabled", &start)) { + LOG(VERBOSE) << "Not bootcharting"; return 0; -} + } -static void do_bootchart_step() { - log_file(g_stat_log, "/proc/stat"); - log_file(g_disk_log, "/proc/diskstats"); - log_processes(); + g_bootcharting_thread = new std::thread(bootchart_thread_main); + return 0; } static int do_bootchart_stop() { - if (!g_bootcharting) return 0; + if (!g_bootcharting_thread) return 0; - LOG(INFO) << "Bootcharting finished"; - g_bootcharting = false; - fclose(g_stat_log); - fclose(g_disk_log); - fclose(g_proc_log); - return 0; + // Tell the worker thread it's time to quit. + { + std::lock_guard lock(g_bootcharting_finished_mutex); + g_bootcharting_finished = true; + g_bootcharting_finished_cv.notify_one(); + } + + g_bootcharting_thread->join(); + delete g_bootcharting_thread; + g_bootcharting_thread = nullptr; + return 0; } int do_bootchart(const std::vector& args) { - if (args[1] == "start") return do_bootchart_start(); - return do_bootchart_stop(); -} - -void bootchart_sample(int* timeout) { - // Do we have any more bootcharting to do? - if (!g_bootcharting) return; - - long long current_time = 10LL * get_uptime_jiffies(); - int elapsed_time = current_time - g_last_bootchart_time; - - if (elapsed_time >= BOOTCHART_POLLING_MS) { - while (elapsed_time >= BOOTCHART_POLLING_MS) { - elapsed_time -= BOOTCHART_POLLING_MS; - } - - g_last_bootchart_time = current_time; - do_bootchart_step(); - } - - // Schedule another? - if (g_bootcharting) { - int remaining_time = BOOTCHART_POLLING_MS - elapsed_time; - if (*timeout < 0 || *timeout > remaining_time) { - *timeout = remaining_time; - } - } + if (args[1] == "start") return do_bootchart_start(); + return do_bootchart_stop(); } diff --git a/init/bootchart.h b/init/bootchart.h index 1e8d0f865..0e3593d8c 100644 --- a/init/bootchart.h +++ b/init/bootchart.h @@ -21,6 +21,5 @@ #include int do_bootchart(const std::vector& args); -void bootchart_sample(int* timeout); #endif /* _BOOTCHART_H */ diff --git a/init/init.cpp b/init/init.cpp index 2d474c730..60eac4818 100644 --- a/init/init.cpp +++ b/init/init.cpp @@ -850,8 +850,6 @@ int main(int argc, char** argv) { // If there's more work to do, wake up again immediately. if (am.HasMoreCommands()) epoll_timeout_ms = 0; - bootchart_sample(&epoll_timeout_ms); - epoll_event ev; int nr = TEMP_FAILURE_RETRY(epoll_wait(epoll_fd, &ev, 1, epoll_timeout_ms)); if (nr == -1) {