From 8bb039073fa97f380d03392002a3a5bc542f5ace Mon Sep 17 00:00:00 2001 From: Josh Gao Date: Tue, 30 May 2017 15:31:02 -0700 Subject: [PATCH] crash_dump: add tracing. Add some tracing to figure out where time is going during a dump. Bug: http://b/62112103 Test: systrace.py sched freq idle bionic Change-Id: Ic2a212beeb0bb0350b4d9c2cd7a4e70adc97752d --- debuggerd/crash_dump.cpp | 86 +++++++++++++++++++++++++++------------- 1 file changed, 58 insertions(+), 28 deletions(-) diff --git a/debuggerd/crash_dump.cpp b/debuggerd/crash_dump.cpp index 558bc721a..df7201df3 100644 --- a/debuggerd/crash_dump.cpp +++ b/debuggerd/crash_dump.cpp @@ -44,6 +44,9 @@ #include #include +#define ATRACE_TAG ATRACE_TAG_BIONIC +#include + #include "backtrace.h" #include "tombstone.h" #include "utility.h" @@ -101,6 +104,7 @@ static bool ptrace_seize_thread(int pid_proc_fd, pid_t tid, std::string* error) } static bool activity_manager_notify(pid_t pid, int signal, const std::string& amfd_data) { + ATRACE_CALL(); android::base::unique_fd amfd(socket_local_client( "/data/system/ndebugsocket", ANDROID_SOCKET_NAMESPACE_FILESYSTEM, SOCK_STREAM)); if (amfd.get() == -1) { @@ -176,6 +180,7 @@ static void abort_handler(pid_t target, const bool tombstoned_connected, } static void drop_capabilities() { + ATRACE_CALL(); __user_cap_header_struct capheader; memset(&capheader, 0, sizeof(capheader)); capheader.version = _LINUX_CAPABILITY_VERSION_3; @@ -194,6 +199,8 @@ static void drop_capabilities() { } int main(int argc, char** argv) { + atrace_begin(ATRACE_TAG, "before reparent"); + pid_t target = getppid(); bool tombstoned_connected = false; unique_fd tombstoned_socket; @@ -261,6 +268,8 @@ int main(int argc, char** argv) { PLOG(FATAL) << "parent died"; } + atrace_end(ATRACE_TAG); + // Reparent ourselves to init, so that the signal handler can waitpid on the // original process to avoid leaving a zombie for non-fatal dumps. pid_t forkpid = fork(); @@ -270,47 +279,60 @@ int main(int argc, char** argv) { exit(0); } + ATRACE_NAME("after reparent"); + // Die if we take too long. alarm(2); std::string attach_error; - // Seize the main thread. - if (!ptrace_seize_thread(target_proc_fd, main_tid, &attach_error)) { - LOG(FATAL) << attach_error; - } - - // Seize the siblings. std::map threads; + { - std::set siblings; - if (!android::procinfo::GetProcessTids(target, &siblings)) { - PLOG(FATAL) << "failed to get process siblings"; + ATRACE_NAME("ptrace"); + // Seize the main thread. + if (!ptrace_seize_thread(target_proc_fd, main_tid, &attach_error)) { + LOG(FATAL) << attach_error; } - // but not the already attached main thread. - siblings.erase(main_tid); - // or the handler pseudothread. - siblings.erase(pseudothread_tid); + // Seize the siblings. + { + std::set siblings; + if (!android::procinfo::GetProcessTids(target, &siblings)) { + PLOG(FATAL) << "failed to get process siblings"; + } - for (pid_t sibling_tid : siblings) { - if (!ptrace_seize_thread(target_proc_fd, sibling_tid, &attach_error)) { - LOG(WARNING) << attach_error; - } else { - threads.emplace(sibling_tid, get_thread_name(sibling_tid)); + // but not the already attached main thread. + siblings.erase(main_tid); + // or the handler pseudothread. + siblings.erase(pseudothread_tid); + + for (pid_t sibling_tid : siblings) { + if (!ptrace_seize_thread(target_proc_fd, sibling_tid, &attach_error)) { + LOG(WARNING) << attach_error; + } else { + threads.emplace(sibling_tid, get_thread_name(sibling_tid)); + } } } } // Collect the backtrace map, open files, and process/thread names, while we still have caps. - std::unique_ptr backtrace_map(BacktraceMap::Create(main_tid)); - if (!backtrace_map) { - LOG(FATAL) << "failed to create backtrace map"; + std::unique_ptr backtrace_map; + { + ATRACE_NAME("backtrace map"); + backtrace_map.reset(BacktraceMap::Create(main_tid)); + if (!backtrace_map) { + LOG(FATAL) << "failed to create backtrace map"; + } } // Collect the list of open files. OpenFilesList open_files; - populate_open_files_list(target, &open_files); + { + ATRACE_NAME("open files"); + populate_open_files_list(target, &open_files); + } std::string process_name = get_process_name(main_tid); threads.emplace(main_tid, get_thread_name(main_tid)); @@ -318,9 +340,12 @@ int main(int argc, char** argv) { // Drop our capabilities now that we've attached to the threads we care about. drop_capabilities(); - const DebuggerdDumpType dump_type_enum = static_cast(dump_type); - LOG(INFO) << "obtaining output fd from tombstoned, type: " << dump_type_enum; - tombstoned_connected = tombstoned_connect(target, &tombstoned_socket, &output_fd, dump_type_enum); + { + ATRACE_NAME("tombstoned_connect"); + const DebuggerdDumpType dump_type_enum = static_cast(dump_type); + LOG(INFO) << "obtaining output fd from tombstoned, type: " << dump_type_enum; + tombstoned_connected = tombstoned_connect(target, &tombstoned_socket, &output_fd, dump_type_enum); + } // Write a '\1' to stdout to tell the crashing process to resume. // It also restores the value of PR_SET_DUMPABLE at this point. @@ -349,9 +374,12 @@ int main(int argc, char** argv) { } siginfo_t siginfo = {}; - if (!wait_for_signal(main_tid, &siginfo)) { - printf("failed to wait for signal in tid %d: %s\n", main_tid, strerror(errno)); - exit(1); + { + ATRACE_NAME("wait_for_signal"); + if (!wait_for_signal(main_tid, &siginfo)) { + printf("failed to wait for signal in tid %d: %s\n", main_tid, strerror(errno)); + exit(1); + } } int signo = siginfo.si_signo; @@ -373,8 +401,10 @@ int main(int argc, char** argv) { std::string amfd_data; if (backtrace) { + ATRACE_NAME("dump_backtrace"); dump_backtrace(output_fd.get(), backtrace_map.get(), target, main_tid, process_name, threads, 0); } else { + ATRACE_NAME("engrave_tombstone"); engrave_tombstone(output_fd.get(), backtrace_map.get(), &open_files, target, main_tid, process_name, threads, abort_address, fatal_signal ? &amfd_data : nullptr); }