bootstat: Migrate to StatsLog for metrics

- All events are migrated to StatsLog atoms.
- Still keep the string based name for BootEvent logging as that makes it
  easier for debugging purpose.

Bug: 132691841
Test: check boot related stats are pushed after boot up
      $ adb shell cmd stats print-stats

Change-Id: I33313695a8a2d0a3c74f7705c0843c8c4bad2133
Merged-In: I33313695a8a2d0a3c74f7705c0843c8c4bad2133
This commit is contained in:
Keun young Park 2020-01-15 10:09:03 -08:00
parent e6211eb978
commit 606af6dfff

View file

@ -32,6 +32,8 @@
#include <memory>
#include <regex>
#include <string>
#include <string_view>
#include <unordered_map>
#include <utility>
#include <vector>
@ -50,16 +52,133 @@
namespace {
struct AtomInfo {
int32_t atom;
int32_t event;
};
// Maps BootEvent used inside bootstat into statsd atom defined in
// frameworks/base/cmds/statsd/src/atoms.proto.
const std::unordered_map<std::string_view, AtomInfo> kBootEventToAtomInfo = {
// ELAPSED_TIME
{"ro.boottime.init",
{android::util::BOOT_TIME_EVENT_ELAPSED_TIME_REPORTED,
android::util::BOOT_TIME_EVENT_ELAPSED_TIME__EVENT__ANDROID_INIT_STAGE_1}},
{"boot_complete",
{android::util::BOOT_TIME_EVENT_ELAPSED_TIME_REPORTED,
android::util::BOOT_TIME_EVENT_ELAPSED_TIME__EVENT__BOOT_COMPLETE}},
{"boot_decryption_complete",
{android::util::BOOT_TIME_EVENT_ELAPSED_TIME_REPORTED,
android::util::BOOT_TIME_EVENT_ELAPSED_TIME__EVENT__BOOT_COMPLETE_ENCRYPTION}},
{"boot_complete_no_encryption",
{android::util::BOOT_TIME_EVENT_ELAPSED_TIME_REPORTED,
android::util::BOOT_TIME_EVENT_ELAPSED_TIME__EVENT__BOOT_COMPLETE_NO_ENCRYPTION}},
{"boot_complete_post_decrypt",
{android::util::BOOT_TIME_EVENT_ELAPSED_TIME_REPORTED,
android::util::BOOT_TIME_EVENT_ELAPSED_TIME__EVENT__BOOT_COMPLETE_POST_DECRYPT}},
{"factory_reset_boot_complete",
{android::util::BOOT_TIME_EVENT_ELAPSED_TIME_REPORTED,
android::util::BOOT_TIME_EVENT_ELAPSED_TIME__EVENT__FACTORY_RESET_BOOT_COMPLETE}},
{"factory_reset_boot_complete_no_encryption",
{android::util::BOOT_TIME_EVENT_ELAPSED_TIME_REPORTED,
android::util::
BOOT_TIME_EVENT_ELAPSED_TIME__EVENT__FACTORY_RESET_BOOT_COMPLETE_NO_ENCRYPTION}},
{"factory_reset_boot_complete_post_decrypt",
{android::util::BOOT_TIME_EVENT_ELAPSED_TIME_REPORTED,
android::util::
BOOT_TIME_EVENT_ELAPSED_TIME__EVENT__FACTORY_RESET_BOOT_COMPLETE_POST_DECRYPT}},
{"ota_boot_complete",
{android::util::BOOT_TIME_EVENT_ELAPSED_TIME_REPORTED,
android::util::BOOT_TIME_EVENT_ELAPSED_TIME__EVENT__OTA_BOOT_COMPLETE}},
{"ota_boot_complete_no_encryption",
{android::util::BOOT_TIME_EVENT_ELAPSED_TIME_REPORTED,
android::util::BOOT_TIME_EVENT_ELAPSED_TIME__EVENT__OTA_BOOT_COMPLETE_NO_ENCRYPTION}},
{"ota_boot_complete_post_decrypt",
{android::util::BOOT_TIME_EVENT_ELAPSED_TIME_REPORTED,
android::util::BOOT_TIME_EVENT_ELAPSED_TIME__EVENT__OTA_BOOT_COMPLETE_POST_DECRYPT}},
{"post_decrypt_time_elapsed",
{android::util::BOOT_TIME_EVENT_ELAPSED_TIME_REPORTED,
android::util::BOOT_TIME_EVENT_ELAPSED_TIME__EVENT__POST_DECRYPT}},
// DURATION
{"absolute_boot_time",
{android::util::BOOT_TIME_EVENT_DURATION_REPORTED,
android::util::BOOT_TIME_EVENT_DURATION__EVENT__ABSOLUTE_BOOT_TIME}},
{"boottime.bootloader.1BLE",
{android::util::BOOT_TIME_EVENT_DURATION_REPORTED,
android::util::BOOT_TIME_EVENT_DURATION__EVENT__BOOTLOADER_FIRST_STAGE_EXEC}},
{"boottime.bootloader.1BLL",
{android::util::BOOT_TIME_EVENT_DURATION_REPORTED,
android::util::BOOT_TIME_EVENT_DURATION__EVENT__BOOTLOADER_FIRST_STAGE_LOAD}},
{"boottime.bootloader.KL",
{android::util::BOOT_TIME_EVENT_DURATION_REPORTED,
android::util::BOOT_TIME_EVENT_DURATION__EVENT__BOOTLOADER_KERNEL_LOAD}},
{"boottime.bootloader.2BLE",
{android::util::BOOT_TIME_EVENT_DURATION_REPORTED,
android::util::BOOT_TIME_EVENT_DURATION__EVENT__BOOTLOADER_SECOND_STAGE_EXEC}},
{"boottime.bootloader.2BLL",
{android::util::BOOT_TIME_EVENT_DURATION_REPORTED,
android::util::BOOT_TIME_EVENT_DURATION__EVENT__BOOTLOADER_SECOND_STAGE_LOAD}},
{"boottime.bootloader.SW",
{android::util::BOOT_TIME_EVENT_DURATION_REPORTED,
android::util::BOOT_TIME_EVENT_DURATION__EVENT__BOOTLOADER_UI_WAIT}},
{"boottime.bootloader.total",
{android::util::BOOT_TIME_EVENT_DURATION_REPORTED,
android::util::BOOT_TIME_EVENT_DURATION__EVENT__BOOTLOADER_TOTAL}},
{"boottime.init.cold_boot_wait",
{android::util::BOOT_TIME_EVENT_DURATION_REPORTED,
android::util::BOOT_TIME_EVENT_DURATION__EVENT__COLDBOOT_WAIT}},
{"time_since_factory_reset",
{android::util::BOOT_TIME_EVENT_DURATION_REPORTED,
android::util::BOOT_TIME_EVENT_DURATION__EVENT__FACTORY_RESET_TIME_SINCE_RESET}},
{"ro.boottime.init.first_stage",
{android::util::BOOT_TIME_EVENT_DURATION_REPORTED,
android::util::BOOT_TIME_EVENT_DURATION__EVENT__ANDROID_INIT_STAGE_1}},
{"ro.boottime.init.selinux",
{android::util::BOOT_TIME_EVENT_DURATION_REPORTED,
android::util::BOOT_TIME_EVENT_DURATION__EVENT__SELINUX_INIT}},
// UTC_TIME
{"factory_reset",
{android::util::BOOT_TIME_EVENT_UTC_TIME_REPORTED,
android::util::BOOT_TIME_EVENT_UTC_TIME__EVENT__FACTORY_RESET_RESET_TIME}},
{"factory_reset_current_time",
{android::util::BOOT_TIME_EVENT_UTC_TIME_REPORTED,
android::util::BOOT_TIME_EVENT_UTC_TIME__EVENT__FACTORY_RESET_CURRENT_TIME}},
{"factory_reset_record_value",
{android::util::BOOT_TIME_EVENT_UTC_TIME_REPORTED,
android::util::BOOT_TIME_EVENT_UTC_TIME__EVENT__FACTORY_RESET_RECORD_VALUE}},
// ERROR_CODE
{"factory_reset_current_time_failure",
{android::util::BOOT_TIME_EVENT_ERROR_CODE_REPORTED,
android::util::BOOT_TIME_EVENT_ERROR_CODE__EVENT__FACTORY_RESET_CURRENT_TIME_FAILURE}},
};
// Scans the boot event record store for record files and logs each boot event
// via EventLog.
void LogBootEvents() {
BootEventRecordStore boot_event_store;
auto events = boot_event_store.GetAllBootEvents();
// TODO(b/148575354): Replace with statsd.
// for (auto i = events.cbegin(); i != events.cend(); ++i) {
// android::metricslogger::LogHistogram(i->first, i->second);
// }
std::vector<std::string_view> notSupportedEvents;
for (const auto& event : events) {
const auto& name = event.first;
const auto& info = kBootEventToAtomInfo.find(name);
if (info != kBootEventToAtomInfo.end()) {
if (info->second.atom == android::util::BOOT_TIME_EVENT_ERROR_CODE_REPORTED) {
android::util::stats_write(static_cast<int32_t>(info->second.atom),
static_cast<int32_t>(info->second.event),
static_cast<int32_t>(event.second));
} else {
android::util::stats_write(static_cast<int32_t>(info->second.atom),
static_cast<int32_t>(info->second.event),
static_cast<int64_t>(event.second));
}
} else {
notSupportedEvents.push_back(name);
}
}
if (!notSupportedEvents.empty()) {
LOG(WARNING) << "LogBootEvents, atomInfo not defined for events:"
<< android::base::Join(notSupportedEvents, ',');
}
}
// Records the named boot |event| to the record store. If |value| is non-empty
@ -1250,10 +1369,13 @@ void RecordFactoryReset() {
time_t current_time_utc = time(nullptr);
if (current_time_utc < 0) {
// TODO(b/148575354): Replace with statsd.
// UMA does not display negative values in buckets, so convert to positive.
// android::metricslogger::LogHistogram("factory_reset_current_time_failure",
// std::abs(current_time_utc));
// Logging via BootEventRecordStore.
android::util::stats_write(
static_cast<int32_t>(android::util::BOOT_TIME_EVENT_ERROR_CODE_REPORTED),
static_cast<int32_t>(
android::util::BOOT_TIME_EVENT_ERROR_CODE__EVENT__FACTORY_RESET_CURRENT_TIME_FAILURE),
static_cast<int32_t>(std::abs(current_time_utc)));
// Logging via BootEventRecordStore to see if using android::metricslogger::LogHistogram
// is losing records somehow.
@ -1261,8 +1383,11 @@ void RecordFactoryReset() {
std::abs(current_time_utc));
return;
} else {
// TODO(b/148575354): Replace with statsd.
// android::metricslogger::LogHistogram("factory_reset_current_time", current_time_utc);
android::util::stats_write(
static_cast<int32_t>(android::util::BOOT_TIME_EVENT_UTC_TIME_REPORTED),
static_cast<int32_t>(
android::util::BOOT_TIME_EVENT_UTC_TIME__EVENT__FACTORY_RESET_CURRENT_TIME),
static_cast<int64_t>(current_time_utc));
// Logging via BootEventRecordStore to see if using android::metricslogger::LogHistogram
// is losing records somehow.
@ -1282,8 +1407,11 @@ void RecordFactoryReset() {
// Calculate and record the difference in time between now and the
// factory_reset time.
time_t factory_reset_utc = record.second;
// TODO(b/148575354): Replace with statsd.
// android::metricslogger::LogHistogram("factory_reset_record_value", factory_reset_utc);
android::util::stats_write(
static_cast<int32_t>(android::util::BOOT_TIME_EVENT_UTC_TIME_REPORTED),
static_cast<int32_t>(
android::util::BOOT_TIME_EVENT_UTC_TIME__EVENT__FACTORY_RESET_RECORD_VALUE),
static_cast<int64_t>(factory_reset_utc));
// Logging via BootEventRecordStore to see if using android::metricslogger::LogHistogram
// is losing records somehow.