Donate to e Foundation | Murena handsets with /e/OS | Own a part of Murena! Learn more

Commit 1c855127 authored by Rhed Jao's avatar Rhed Jao
Browse files

Faster bugreports (2/n)

- Having a system property to disable parallel run function.
- Post 'DumpTraces' to the thread pool. 3% is
  improved compared with single thread run.

Bug: 136262402
Test: atest dumpstate_test
Test: atest dumpstate_smoke_test
Test: Manual enable and disable parallel run
Test: Manual trigger report using hardware key
Test: Manual trigger using bugreport shortcut
Change-Id: I2185cc3e2f429a150605d6268324c52d137db385
Merged-In: I2185cc3e2f429a150605d6268324c52d137db385
(cherry picked from commit 5377d797)
parent 27077b13
Loading
Loading
Loading
Loading
+22 −1
Original line number Original line Diff line number Diff line
@@ -33,7 +33,8 @@ namespace dumpstate {


const std::string DumpPool::PREFIX_TMPFILE_NAME = "dump-tmp.";
const std::string DumpPool::PREFIX_TMPFILE_NAME = "dump-tmp.";


DumpPool::DumpPool(const std::string& tmp_root) : tmp_root_(tmp_root), shutdown_(false) {
DumpPool::DumpPool(const std::string& tmp_root) : tmp_root_(tmp_root), shutdown_(false),
        log_duration_(true) {
    assert(!tmp_root.empty());
    assert(!tmp_root.empty());
    deleteTempFiles(tmp_root_);
    deleteTempFiles(tmp_root_);
}
}
@@ -99,6 +100,26 @@ void DumpPool::waitForTask(const std::string& task_name, const std::string& titl
    }
    }
}
}


void DumpPool::setLogDuration(bool log_duration) {
    log_duration_ = log_duration;
}

template <>
void DumpPool::invokeTask<std::function<void()>>(std::function<void()> dump_func,
        const std::string& duration_title, int out_fd) {
    DurationReporter duration_reporter(duration_title, /*logcat_only =*/!log_duration_,
            /*verbose =*/false, out_fd);
    std::invoke(dump_func);
}

template <>
void DumpPool::invokeTask<std::function<void(int)>>(std::function<void(int)> dump_func,
        const std::string& duration_title, int out_fd) {
    DurationReporter duration_reporter(duration_title, /*logcat_only =*/!log_duration_,
            /*verbose =*/false, out_fd);
    std::invoke(dump_func, out_fd);
}

std::unique_ptr<DumpPool::TmpFile> DumpPool::createTempFile() {
std::unique_ptr<DumpPool::TmpFile> DumpPool::createTempFile() {
    auto tmp_file_ptr = std::make_unique<TmpFile>();
    auto tmp_file_ptr = std::make_unique<TmpFile>();
    std::string file_name_format = "%s/" + PREFIX_TMPFILE_NAME + "XXXXXX";
    std::string file_name_format = "%s/" + PREFIX_TMPFILE_NAME + "XXXXXX";
+58 −18
Original line number Original line Diff line number Diff line
@@ -29,26 +29,32 @@ namespace android {
namespace os {
namespace os {
namespace dumpstate {
namespace dumpstate {


class DumpPoolTest;

/*
/*
 * A thread pool with the fixed number of threads to execute multiple dump tasks
 * A thread pool with the fixed number of threads to execute multiple dump tasks
 * simultaneously for the dumpstate. The dump task is a callable function
 * simultaneously for the dumpstate. The dump task is a callable function. It
 * included a file descriptor as a parameter, and the task could dump results to
 * could include a file descriptor as a parameter to redirect dump results, if
 * that fd. For example:
 * it needs to output results to the bugreport. This can avoid messing up
 * bugreport's results when multiple dump tasks are running at the same time.
 * Takes an example below for the usage of the DumpPool:
 *
 *
 * void DumpXXXX(int out_fd) {
 * void DumpFoo(int out_fd) {
 *     dprintf(out_fd, "Dump result to out_fd ...");
 *     dprintf(out_fd, "Dump result to out_fd ...");
 * }
 * }
 * ...
 * ...
 * DumpPool pool(tmp_root);
 * DumpPool pool(tmp_root);
 * pool.enqueueTask("TaskName", &DumpXXXX, std::placeholders::_1);
 * pool.enqueueTaskWithFd("TaskName", &DumpFoo, std::placeholders::_1);
 * ...
 * ...
 * pool.waitForTask("TaskName");
 * pool.waitForTask("TaskName");
 *
 *
 * DumpXXXX is a callable function included a out_fd parameter. Using the
 * DumpFoo is a callable function included a out_fd parameter. Using the
 * enqueueTask method in DumpPool to enqueue the task to the pool. The
 * enqueueTaskWithFd method in DumpPool to enqueue the task to the pool. The
 * std::placeholders::_1 is placeholder for DumpPool to pass a fd argument.
 * std::placeholders::_1 is a placeholder for DumpPool to pass a fd argument.
 */
 */
class DumpPool {
class DumpPool {
  friend class android::os::dumpstate::DumpPoolTest;

  public:
  public:
    /*
    /*
     * Creates a thread pool.
     * Creates a thread pool.
@@ -72,17 +78,40 @@ class DumpPool {
    void shutdown();
    void shutdown();


    /*
    /*
     * Adds a task with a task name into the queue of the thread pool.
     * Adds a task into the queue of the thread pool.
     *
     *
     * |task_name| The name of the task.
     * |task_name| The name of the task. It's also the title of the
     * |f| Callable function to execute the task. This function must
     * DurationReporter log.
     *     include a parameter of file descriptor to output dump result.
     * |f| Callable function to execute the task.
     * |args| A list of arguments.
     * |args| A list of arguments.
     *
     * TODO(b/164369078): remove this api to have just one enqueueTask for consistency.
     */
     */
    template<class F, class... Args> void enqueueTask(const std::string& task_name,
    template<class F, class... Args> void enqueueTask(const std::string& task_name, F&& f,
            F&& f, Args&&... args) {
            Args&&... args) {
        auto func = std::bind(std::forward<F>(f), std::forward<Args>(args)...);
        std::function<void(void)> func = std::bind(std::forward<F>(f),
        futures_map_[task_name] = post(func);
                std::forward<Args>(args)...);
        futures_map_[task_name] = post(task_name, func);
        if (threads_.empty()) {
            start();
        }
    }

    /*
     * Adds a task into the queue of the thread pool. The task takes a file
     * descriptor as a parameter to redirect dump results to a temporary file.
     *
     * |task_name| The name of the task. It's also the title of the
     * DurationReporter log.
     * |f| Callable function to execute the task.
     * |args| A list of arguments. A placeholder std::placeholders::_1 as a fd
     * argument needs to be included here.
     */
    template<class F, class... Args> void enqueueTaskWithFd(const std::string& task_name, F&& f,
            Args&&... args) {
        std::function<void(int)> func = std::bind(std::forward<F>(f),
                std::forward<Args>(args)...);
        futures_map_[task_name] = post(task_name, func);
        if (threads_.empty()) {
        if (threads_.empty()) {
            start();
            start();
        }
        }
@@ -111,13 +140,15 @@ class DumpPool {
    using Task = std::packaged_task<std::string()>;
    using Task = std::packaged_task<std::string()>;
    using Future = std::shared_future<std::string>;
    using Future = std::shared_future<std::string>;


    template<class T> Future post(T dump_func) {
    template<class T> void invokeTask(T dump_func, const std::string& duration_title, int out_fd);

    template<class T> Future post(const std::string& task_name, T dump_func) {
        Task packaged_task([=]() {
        Task packaged_task([=]() {
            std::unique_ptr<TmpFile> tmp_file_ptr = createTempFile();
            std::unique_ptr<TmpFile> tmp_file_ptr = createTempFile();
            if (!tmp_file_ptr) {
            if (!tmp_file_ptr) {
                return std::string("");
                return std::string("");
            }
            }
            std::invoke(dump_func, tmp_file_ptr->fd.get());
            invokeTask(dump_func, task_name, tmp_file_ptr->fd.get());
            fsync(tmp_file_ptr->fd.get());
            fsync(tmp_file_ptr->fd.get());
            return std::string(tmp_file_ptr->path);
            return std::string(tmp_file_ptr->path);
        });
        });
@@ -138,12 +169,21 @@ class DumpPool {
    void setThreadName(const pthread_t thread, int id);
    void setThreadName(const pthread_t thread, int id);
    void loop();
    void loop();


    /*
     * For test purpose only. Enables or disables logging duration of the task.
     *
     * |log_duration| if true, DurationReporter is initiated to log duration of
     * the task.
     */
    void setLogDuration(bool log_duration);

  private:
  private:
    static const int MAX_THREAD_COUNT = 4;
    static const int MAX_THREAD_COUNT = 4;


    /* A path to a temporary folder for threads to create temporary files. */
    /* A path to a temporary folder for threads to create temporary files. */
    std::string tmp_root_;
    std::string tmp_root_;
    bool shutdown_;
    bool shutdown_;
    bool log_duration_; // For test purpose only, the default value is true.
    std::mutex lock_;  // A lock for the tasks_.
    std::mutex lock_;  // A lock for the tasks_.
    std::condition_variable condition_variable_;
    std::condition_variable condition_variable_;


+9 −0
Original line number Original line Diff line number Diff line
@@ -180,6 +180,7 @@ CommandOptions::CommandOptionsBuilder CommandOptions::WithTimeoutInMs(int64_t ti
std::string PropertiesHelper::build_type_ = "";
std::string PropertiesHelper::build_type_ = "";
int PropertiesHelper::dry_run_ = -1;
int PropertiesHelper::dry_run_ = -1;
int PropertiesHelper::unroot_ = -1;
int PropertiesHelper::unroot_ = -1;
int PropertiesHelper::parallel_run_ = -1;


bool PropertiesHelper::IsUserBuild() {
bool PropertiesHelper::IsUserBuild() {
    if (build_type_.empty()) {
    if (build_type_.empty()) {
@@ -202,6 +203,14 @@ bool PropertiesHelper::IsUnroot() {
    return unroot_ == 1;
    return unroot_ == 1;
}
}


bool PropertiesHelper::IsParallelRun() {
    if (parallel_run_ == -1) {
        parallel_run_ = android::base::GetBoolProperty("dumpstate.parallel_run",
                /* default_value = */true) ? 1 : 0;
    }
    return parallel_run_ == 1;
}

int DumpFileToFd(int out_fd, const std::string& title, const std::string& path) {
int DumpFileToFd(int out_fd, const std::string& title, const std::string& path) {
    android::base::unique_fd fd(TEMP_FAILURE_RETRY(open(path.c_str(), O_RDONLY | O_NONBLOCK | O_CLOEXEC)));
    android::base::unique_fd fd(TEMP_FAILURE_RETRY(open(path.c_str(), O_RDONLY | O_NONBLOCK | O_CLOEXEC)));
    if (fd.get() < 0) {
    if (fd.get() < 0) {
+8 −0
Original line number Original line Diff line number Diff line
@@ -176,10 +176,18 @@ class PropertiesHelper {
     */
     */
    static bool IsUnroot();
    static bool IsUnroot();


    /*
     * Whether or not the parallel run is enabled. Setting the system property
     * 'dumpstate.parallel_run' to false to disable it, otherwise it returns
     * true by default.
     */
    static bool IsParallelRun();

  private:
  private:
    static std::string build_type_;
    static std::string build_type_;
    static int dry_run_;
    static int dry_run_;
    static int unroot_;
    static int unroot_;
    static int parallel_run_;
};
};


/*
/*
+74 −8
Original line number Original line Diff line number Diff line
@@ -95,6 +95,7 @@ using ::android::hardware::dumpstate::V1_1::DumpstateStatus;
using ::android::hardware::dumpstate::V1_1::toString;
using ::android::hardware::dumpstate::V1_1::toString;
using ::std::literals::chrono_literals::operator""ms;
using ::std::literals::chrono_literals::operator""ms;
using ::std::literals::chrono_literals::operator""s;
using ::std::literals::chrono_literals::operator""s;
using ::std::placeholders::_1;


// TODO: remove once moved to namespace
// TODO: remove once moved to namespace
using android::defaultServiceManager;
using android::defaultServiceManager;
@@ -113,6 +114,7 @@ using android::base::StringPrintf;
using android::os::IDumpstateListener;
using android::os::IDumpstateListener;
using android::os::dumpstate::CommandOptions;
using android::os::dumpstate::CommandOptions;
using android::os::dumpstate::DumpFileToFd;
using android::os::dumpstate::DumpFileToFd;
using android::os::dumpstate::DumpPool;
using android::os::dumpstate::PropertiesHelper;
using android::os::dumpstate::PropertiesHelper;


// Keep in sync with
// Keep in sync with
@@ -196,8 +198,26 @@ static const std::string ANR_FILE_PREFIX = "anr_";
    func_ptr(__VA_ARGS__);                                  \
    func_ptr(__VA_ARGS__);                                  \
    RETURN_IF_USER_DENIED_CONSENT();
    RETURN_IF_USER_DENIED_CONSENT();


// Runs func_ptr, and logs a duration report after it's finished.
#define RUN_SLOW_FUNCTION_AND_LOG(log_title, func_ptr, ...)      \
    {                                                            \
        DurationReporter duration_reporter_in_macro(log_title);  \
        func_ptr(__VA_ARGS__);                                   \
    }

// Similar with RUN_SLOW_FUNCTION_WITH_CONSENT_CHECK, an additional duration report
// is output after a slow function is finished.
#define RUN_SLOW_FUNCTION_WITH_CONSENT_CHECK_AND_LOG(log_title, func_ptr, ...) \
    RETURN_IF_USER_DENIED_CONSENT();                                           \
    RUN_SLOW_FUNCTION_AND_LOG(log_title, func_ptr, __VA_ARGS__);               \
    RETURN_IF_USER_DENIED_CONSENT();

static const char* WAKE_LOCK_NAME = "dumpstate_wakelock";
static const char* WAKE_LOCK_NAME = "dumpstate_wakelock";


// Names of parallel tasks, they are used for the DumpPool to identify the dump
// task and the log title of the duration report.
static const std::string DUMP_TRACES_TASK = "DUMP TRACES";

namespace android {
namespace android {
namespace os {
namespace os {
namespace {
namespace {
@@ -762,8 +782,9 @@ void Dumpstate::PrintHeader() const {
    RunCommandToFd(STDOUT_FILENO, "", {"uptime", "-p"},
    RunCommandToFd(STDOUT_FILENO, "", {"uptime", "-p"},
                   CommandOptions::WithTimeout(1).Always().Build());
                   CommandOptions::WithTimeout(1).Always().Build());
    printf("Bugreport format version: %s\n", version_.c_str());
    printf("Bugreport format version: %s\n", version_.c_str());
    printf("Dumpstate info: id=%d pid=%d dry_run=%d args=%s bugreport_mode=%s\n", id_, pid_,
    printf("Dumpstate info: id=%d pid=%d dry_run=%d parallel_run=%d args=%s bugreport_mode=%s\n",
           PropertiesHelper::IsDryRun(), options_->args.c_str(), options_->bugreport_mode.c_str());
           id_, pid_, PropertiesHelper::IsDryRun(), PropertiesHelper::IsParallelRun(),
           options_->args.c_str(), options_->bugreport_mode.c_str());
    printf("\n");
    printf("\n");
}
}


@@ -1682,7 +1703,18 @@ Dumpstate::RunStatus Dumpstate::DumpstateDefaultAfterCritical() {
    time_t logcat_ts = time(nullptr);
    time_t logcat_ts = time(nullptr);


    /* collect stack traces from Dalvik and native processes (needs root) */
    /* collect stack traces from Dalvik and native processes (needs root) */
    RUN_SLOW_FUNCTION_WITH_CONSENT_CHECK(ds.DumpTraces, &dump_traces_path);
    if (dump_pool_) {
        RETURN_IF_USER_DENIED_CONSENT();
        // One thread is enough since we only need to enqueue DumpTraces here.
        dump_pool_->start(/* thread_counts = */1);

        // DumpTraces takes long time, post it to the another thread in the
        // pool, if pool is available
        dump_pool_->enqueueTask(DUMP_TRACES_TASK, &Dumpstate::DumpTraces, &ds, &dump_traces_path);
    } else {
        RUN_SLOW_FUNCTION_WITH_CONSENT_CHECK_AND_LOG(DUMP_TRACES_TASK, ds.DumpTraces,
                &dump_traces_path);
    }


    /* Run some operations that require root. */
    /* Run some operations that require root. */
    ds.tombstone_data_ = GetDumpFds(TOMBSTONE_DIR, TOMBSTONE_FILE_PREFIX, !ds.IsZipping());
    ds.tombstone_data_ = GetDumpFds(TOMBSTONE_DIR, TOMBSTONE_FILE_PREFIX, !ds.IsZipping());
@@ -1725,6 +1757,15 @@ Dumpstate::RunStatus Dumpstate::DumpstateDefaultAfterCritical() {
    DumpFile("PSI memory", "/proc/pressure/memory");
    DumpFile("PSI memory", "/proc/pressure/memory");
    DumpFile("PSI io", "/proc/pressure/io");
    DumpFile("PSI io", "/proc/pressure/io");


    if (dump_pool_) {
        RETURN_IF_USER_DENIED_CONSENT();
        dump_pool_->waitForTask(DUMP_TRACES_TASK);

        // Current running thread in the pool is the root user also. Shutdown
        // the pool and restart later to ensure all threads in the pool could
        // drop the root user.
        dump_pool_->shutdown();
    }
    if (!DropRootUser()) {
    if (!DropRootUser()) {
        return Dumpstate::RunStatus::ERROR;
        return Dumpstate::RunStatus::ERROR;
    }
    }
@@ -1883,8 +1924,6 @@ static void DumpstateWifiOnly() {
}
}


Dumpstate::RunStatus Dumpstate::DumpTraces(const char** path) {
Dumpstate::RunStatus Dumpstate::DumpTraces(const char** path) {
    DurationReporter duration_reporter("DUMP TRACES");

    const std::string temp_file_pattern = "/data/anr/dumptrace_XXXXXX";
    const std::string temp_file_pattern = "/data/anr/dumptrace_XXXXXX";
    const size_t buf_size = temp_file_pattern.length() + 1;
    const size_t buf_size = temp_file_pattern.length() + 1;
    std::unique_ptr<char[]> file_name_buf(new char[buf_size]);
    std::unique_ptr<char[]> file_name_buf(new char[buf_size]);
@@ -2556,6 +2595,7 @@ void Dumpstate::Cancel() {
 */
 */
Dumpstate::RunStatus Dumpstate::RunInternal(int32_t calling_uid,
Dumpstate::RunStatus Dumpstate::RunInternal(int32_t calling_uid,
                                            const std::string& calling_package) {
                                            const std::string& calling_package) {
    DurationReporter duration_reporter("RUN INTERNAL", /* logcat_only = */true);
    LogDumpOptions(*options_);
    LogDumpOptions(*options_);
    if (!options_->ValidateOptions()) {
    if (!options_->ValidateOptions()) {
        MYLOGE("Invalid options specified\n");
        MYLOGE("Invalid options specified\n");
@@ -2717,6 +2757,13 @@ Dumpstate::RunStatus Dumpstate::RunInternal(int32_t calling_uid,
    // Don't buffer stdout
    // Don't buffer stdout
    setvbuf(stdout, nullptr, _IONBF, 0);
    setvbuf(stdout, nullptr, _IONBF, 0);


    // Enable the parallel run if the client requests to output to a file.
    EnableParallelRunIfNeeded();
    // Using scope guard to make sure the dump pool can be shut down correctly.
    auto scope_guard_to_shutdown_pool = android::base::make_scope_guard([=]() {
        ShutdownDumpPool();
    });

    // NOTE: there should be no stdout output until now, otherwise it would break the header.
    // NOTE: there should be no stdout output until now, otherwise it would break the header.
    // In particular, DurationReport objects should be created passing 'title, NULL', so their
    // In particular, DurationReport objects should be created passing 'title, NULL', so their
    // duration is logged into MYLOG instead.
    // duration is logged into MYLOG instead.
@@ -2883,6 +2930,23 @@ void Dumpstate::CleanupTmpFiles() {
    android::os::UnlinkAndLogOnError(path_);
    android::os::UnlinkAndLogOnError(path_);
}
}


void Dumpstate::EnableParallelRunIfNeeded() {
    // The thread pool needs to create temporary files to receive dump results.
    // That's why we only enable it when the bugreport client chooses to output
    // to a file.
    if (!PropertiesHelper::IsParallelRun() || !options_->OutputToFile()) {
        return;
    }
    dump_pool_ = std::make_unique<DumpPool>(bugreport_internal_dir_);
}

void Dumpstate::ShutdownDumpPool() {
    if (dump_pool_) {
        dump_pool_->shutdown();
        dump_pool_ = nullptr;
    }
}

Dumpstate::RunStatus Dumpstate::HandleUserConsentDenied() {
Dumpstate::RunStatus Dumpstate::HandleUserConsentDenied() {
    MYLOGD("User denied consent; deleting files and returning\n");
    MYLOGD("User denied consent; deleting files and returning\n");
    CleanupTmpFiles();
    CleanupTmpFiles();
@@ -3001,8 +3065,9 @@ Dumpstate& Dumpstate::GetInstance() {
    return singleton_;
    return singleton_;
}
}


DurationReporter::DurationReporter(const std::string& title, bool logcat_only, bool verbose)
DurationReporter::DurationReporter(const std::string& title, bool logcat_only, bool verbose,
    : title_(title), logcat_only_(logcat_only), verbose_(verbose) {
        int duration_fd) : title_(title), logcat_only_(logcat_only), verbose_(verbose),
        duration_fd_(duration_fd) {
    if (!title_.empty()) {
    if (!title_.empty()) {
        started_ = Nanotime();
        started_ = Nanotime();
    }
    }
@@ -3016,7 +3081,8 @@ DurationReporter::~DurationReporter() {
        }
        }
        if (!logcat_only_) {
        if (!logcat_only_) {
            // Use "Yoda grammar" to make it easier to grep|sort sections.
            // Use "Yoda grammar" to make it easier to grep|sort sections.
            printf("------ %.3fs was the duration of '%s' ------\n", elapsed, title_.c_str());
            dprintf(duration_fd_, "------ %.3fs was the duration of '%s' ------\n",
                    elapsed, title_.c_str());
        }
        }
    }
    }
}
}
Loading