From 4eacd3836629bb7ae4e008d92ca2e0a62a88311c Mon Sep 17 00:00:00 2001 From: Tej Singh Date: Thu, 25 Jan 2018 17:59:57 -0800 Subject: Atom: BootSequenceReported Logs information about boot time and reason to statsd. Specifically: bootloader boot reason, system boot reason, bootloader boot time, total boot time, time that the boot finished, and time since last boot. Test: booted the phone and verified "adb logcat -b stats" received the event Change-Id: I769df9a09263ed3667f7085c81b3d072e868cbda --- bootstat/Android.bp | 5 +++- bootstat/bootstat.cpp | 64 +++++++++++++++++++++++++++++++++++++++++++-------- 2 files changed, 59 insertions(+), 10 deletions(-) (limited to 'bootstat') diff --git a/bootstat/Android.bp b/bootstat/Android.bp index 2c870182c..e530774d4 100644 --- a/bootstat/Android.bp +++ b/bootstat/Android.bp @@ -63,7 +63,10 @@ cc_binary { name: "bootstat", defaults: ["bootstat_defaults"], static_libs: ["libbootstat"], - shared_libs: ["liblogcat"], + shared_libs: [ + "liblogcat", + "libstatslog" + ], init_rc: ["bootstat.rc"], product_variables: { debuggable: { diff --git a/bootstat/bootstat.cpp b/bootstat/bootstat.cpp index ae0a401ed..d8d7e4ab2 100644 --- a/bootstat/bootstat.cpp +++ b/bootstat/bootstat.cpp @@ -42,6 +42,7 @@ #include #include #include +#include #include "boot_event_record_store.h" @@ -877,6 +878,16 @@ const BootloaderTimingMap GetBootLoaderTimings() { return timings; } +// Returns the total bootloader boot time from the ro.boot.boottime system property. +int32_t GetBootloaderTime(const BootloaderTimingMap& bootloader_timings) { + int32_t total_time = 0; + for (const auto& timing : bootloader_timings) { + total_time += timing.second; + } + + return total_time; +} + // Parses and records the set of bootloader stages and associated boot times // from the ro.boot.boottime system property. void RecordBootloaderTimings(BootEventRecordStore* boot_event_store, @@ -890,11 +901,10 @@ void RecordBootloaderTimings(BootEventRecordStore* boot_event_store, boot_event_store->AddBootEventWithValue("boottime.bootloader.total", total_time); } -// Records the closest estimation to the absolute device boot time, i.e., +// Returns the closest estimation to the absolute device boot time, i.e., // from power on to boot_complete, including bootloader times. -void RecordAbsoluteBootTime(BootEventRecordStore* boot_event_store, - const BootloaderTimingMap& bootloader_timings, - std::chrono::milliseconds uptime) { +std::chrono::milliseconds GetAbsoluteBootTime(const BootloaderTimingMap& bootloader_timings, + std::chrono::milliseconds uptime) { int32_t bootloader_time_ms = 0; for (const auto& timing : bootloader_timings) { @@ -904,9 +914,36 @@ void RecordAbsoluteBootTime(BootEventRecordStore* boot_event_store, } auto bootloader_duration = std::chrono::milliseconds(bootloader_time_ms); - auto absolute_total = - std::chrono::duration_cast(bootloader_duration + uptime); - boot_event_store->AddBootEventWithValue("absolute_boot_time", absolute_total.count()); + return bootloader_duration + uptime; +} + +// Records the closest estimation to the absolute device boot time in seconds. +// i.e. from power on to boot_complete, including bootloader times. +void RecordAbsoluteBootTime(BootEventRecordStore* boot_event_store, + std::chrono::milliseconds absolute_total) { + auto absolute_total_sec = std::chrono::duration_cast(absolute_total); + boot_event_store->AddBootEventWithValue("absolute_boot_time", absolute_total_sec.count()); +} + +// Logs the total boot time and reason to statsd. +void LogBootInfoToStatsd(std::chrono::milliseconds end_time, + std::chrono::milliseconds total_duration, int32_t bootloader_duration_ms, + double time_since_last_boot_sec) { + const std::string reason(GetProperty(bootloader_reboot_reason_property)); + + if (reason.empty()) { + android::util::stats_write(android::util::BOOT_SEQUENCE_REPORTED, "", "", + end_time.count(), total_duration.count(), + (int64_t)bootloader_duration_ms, + (int64_t)time_since_last_boot_sec * 1000); + return; + } + + const std::string system_reason(BootReasonStrToReason(reason)); + android::util::stats_write(android::util::BOOT_SEQUENCE_REPORTED, reason.c_str(), + system_reason.c_str(), end_time.count(), total_duration.count(), + (int64_t)bootloader_duration_ms, + (int64_t)time_since_last_boot_sec * 1000); } // Records several metrics related to the time it takes to boot the device, @@ -918,10 +955,11 @@ void RecordBootComplete() { auto time_since_epoch = android::base::boot_clock::now().time_since_epoch(); auto uptime = std::chrono::duration_cast(time_since_epoch); time_t current_time_utc = time(nullptr); + time_t time_since_last_boot = 0; if (boot_event_store.GetBootEvent("last_boot_time_utc", &record)) { time_t last_boot_time_utc = record.second; - time_t time_since_last_boot = difftime(current_time_utc, last_boot_time_utc); + time_since_last_boot = difftime(current_time_utc, last_boot_time_utc); boot_event_store.AddBootEventWithValue("time_since_last_boot", time_since_last_boot); } @@ -960,10 +998,18 @@ void RecordBootComplete() { RecordInitBootTimeProp(&boot_event_store, "ro.boottime.init.cold_boot_wait"); const BootloaderTimingMap bootloader_timings = GetBootLoaderTimings(); + int32_t bootloader_boot_duration = GetBootloaderTime(bootloader_timings); RecordBootloaderTimings(&boot_event_store, bootloader_timings); auto uptime_ms = std::chrono::duration_cast(time_since_epoch); - RecordAbsoluteBootTime(&boot_event_store, bootloader_timings, uptime_ms); + auto absolute_boot_time = GetAbsoluteBootTime(bootloader_timings, uptime_ms); + RecordAbsoluteBootTime(&boot_event_store, absolute_boot_time); + + auto boot_end_time_point = std::chrono::system_clock::now().time_since_epoch(); + auto boot_end_time = std::chrono::duration_cast(boot_end_time_point); + + LogBootInfoToStatsd(boot_end_time, absolute_boot_time, bootloader_boot_duration, + time_since_last_boot); } // Records the boot_reason metric by querying the ro.boot.bootreason system -- cgit v1.2.3