Fix performance degradation from BootSequence atom

(partial cherry pick from commit fe3e762b6d)

Adding the boot sequence reported atom in ag/3518079 caused the duration
of bootstat to increase, as seen in b/72864061. I isolated the cause
down to calling BootReasonStrToReason. However, this function also gets
called in ReportBootReason, so I created another function that does the
parsing and sets the system boot reason property, and made
RecordBootReason and statsd logging get that property.

Bug: 72864061
Test: rebooted phone, verified boot events were received in adb shell
logcat -b stats and verified adb shell bootstat -p printed correct
values. Ran timing tests as well on walleye with 20 boots: before this
change, the average was ~150-160ms. After, it was ~80ms.
Change-Id: I92dbc9880328835647be7d9d50c7861b42f27bdb
Merged-In: I92dbc9880328835647be7d9d50c7861b42f27bdb
This commit is contained in:
Tej Singh 2018-02-06 15:57:38 -08:00 committed by Mark Salyzyn
parent dc17e9efa0
commit 993f65619e
2 changed files with 23 additions and 13 deletions

View file

@ -1129,6 +1129,13 @@ android::base::boot_clock::duration GetUptime() {
return android::base::boot_clock::now().time_since_epoch() - GetBootTimeOffset();
}
void SetSystemBootReason() {
const std::string bootloader_boot_reason(GetProperty(bootloader_reboot_reason_property));
const std::string system_boot_reason(BootReasonStrToReason(bootloader_boot_reason));
// Record the scrubbed system_boot_reason to the property
SetProperty(system_reboot_reason_property, system_boot_reason);
}
// Records several metrics related to the time it takes to boot the device,
// including disambiguating boot time on encrypted or non-encrypted devices.
void RecordBootComplete() {
@ -1208,12 +1215,10 @@ void RecordBootReason() {
boot_event_store.AddBootEventWithValue("boot_reason", boot_reason);
// Log the scrubbed system_boot_reason.
const std::string system_reason(BootReasonStrToReason(reason));
const std::string system_reason(GetProperty(system_reboot_reason_property));
int32_t system_boot_reason = BootReasonStrToEnum(system_reason);
boot_event_store.AddBootEventWithValue("system_boot_reason", system_boot_reason);
// Record the scrubbed system_boot_reason to the property
SetProperty(system_reboot_reason_property, system_reason);
if (reason == "") {
SetProperty(bootloader_reboot_reason_property, system_reason);
}
@ -1279,20 +1284,22 @@ int main(int argc, char** argv) {
int option_index = 0;
static const char value_str[] = "value";
static const char system_boot_reason_str[] = "set_system_boot_reason";
static const char boot_complete_str[] = "record_boot_complete";
static const char boot_reason_str[] = "record_boot_reason";
static const char factory_reset_str[] = "record_time_since_factory_reset";
static const struct option long_options[] = {
// clang-format off
{ "help", no_argument, NULL, 'h' },
{ "log", no_argument, NULL, 'l' },
{ "print", no_argument, NULL, 'p' },
{ "record", required_argument, NULL, 'r' },
{ value_str, required_argument, NULL, 0 },
{ boot_complete_str, no_argument, NULL, 0 },
{ boot_reason_str, no_argument, NULL, 0 },
{ factory_reset_str, no_argument, NULL, 0 },
{ NULL, 0, NULL, 0 }
{ "help", no_argument, NULL, 'h' },
{ "log", no_argument, NULL, 'l' },
{ "print", no_argument, NULL, 'p' },
{ "record", required_argument, NULL, 'r' },
{ value_str, required_argument, NULL, 0 },
{ system_boot_reason_str, no_argument, NULL, 0 },
{ boot_complete_str, no_argument, NULL, 0 },
{ boot_reason_str, no_argument, NULL, 0 },
{ factory_reset_str, no_argument, NULL, 0 },
{ NULL, 0, NULL, 0 }
// clang-format on
};
@ -1308,6 +1315,8 @@ int main(int argc, char** argv) {
// |optarg| is an external variable set by getopt representing
// the option argument.
value = optarg;
} else if (option_name == system_boot_reason_str) {
SetSystemBootReason();
} else if (option_name == boot_complete_str) {
RecordBootComplete();
} else if (option_name == boot_reason_str) {

View file

@ -68,8 +68,9 @@ on property:init.svc.zygote=stopping
# Record boot complete metrics.
on property:sys.boot_completed=1 && property:sys.logbootcomplete=1
# Converts bootloader boot reason to system boot reason
# Record boot_complete and related stats (decryption, etc).
# Record the boot reason.
# Record time since factory reset.
# Log all boot events.
exec_background - system log -- /system/bin/bootstat --record_boot_complete --record_boot_reason --record_time_since_factory_reset -l
exec_background - system log -- /system/bin/bootstat --set_system_boot_reason --record_boot_complete --record_boot_reason --record_time_since_factory_reset -l