bootstat: Disambiguate boot time on encrypted devices. (c08e996a) · Commits · e / os / android_system_core

bootstat/Android.mk

+8 −7

Original line number	Diff line number	Diff line
		@@ -20,32 +20,33 @@ bootstat_c_includes := external/gtest/include

		bootstat_lib_src_files := \
		boot_event_record_store.cpp \
		event_log_list_builder.cpp
		event_log_list_builder.cpp \
		uptime_parser.cpp \

		bootstat_src_files := \
		bootstat.cpp
		bootstat.cpp \

		bootstat_test_src_files := \
		boot_event_record_store_test.cpp \
		event_log_list_builder_test.cpp \
		testrunner.cpp
		testrunner.cpp \

		bootstat_shared_libs := \
		libbase \
		libcutils \
		liblog
		liblog \

		bootstat_cflags := \
		-Wall \
		-Wextra \
		-Werror
		-Werror \

		bootstat_cppflags := \
		-Wno-non-virtual-dtor
		-Wno-non-virtual-dtor \

		bootstat_debug_cflags := \
		$(bootstat_cflags) \
		-UNDEBUG
		-UNDEBUG \

		# 524291 corresponds to sysui_histogram, from
		# frameworks/base/core/java/com/android/internal/logging/EventLogTags.logtags

bootstat/boot_event_record_store.cpp

+2 −8

Original line number	Diff line number	Diff line
		@@ -24,6 +24,7 @@
		#include <utility>
		#include <android-base/file.h>
		#include <android-base/logging.h>
		#include "uptime_parser.h"

		namespace {

		@@ -51,14 +52,7 @@ BootEventRecordStore::BootEventRecordStore() {
		}

		void BootEventRecordStore::AddBootEvent(const std::string& event) {
		std::string uptime_str;
		if (!android::base::ReadFileToString("/proc/uptime", &uptime_str)) {
		LOG(ERROR) << "Failed to read /proc/uptime";
		}

		// Cast intentionally rounds down.
		int32_t uptime = static_cast<int32_t>(strtod(uptime_str.c_str(), NULL));
		AddBootEventWithValue(event, uptime);
		AddBootEventWithValue(event, bootstat::ParseUptime());
		}

		// The implementation of AddBootEventValue makes use of the mtime file

bootstat/boot_event_record_store_test.cpp

+3 −13

Original line number	Diff line number	Diff line
		@@ -25,6 +25,7 @@
		#include <android-base/test_utils.h>
		#include <gtest/gtest.h>
		#include <gmock/gmock.h>
		#include "uptime_parser.h"

		using testing::UnorderedElementsAreArray;

		@@ -38,17 +39,6 @@ bool FuzzUptimeEquals(int32_t a, int32_t b) {
		return (abs(a - b) <= FUZZ_SECONDS);
		}

		// Returns the uptime as read from /proc/uptime, rounded down to an integer.
		int32_t ReadUptime() {
		std::string uptime_str;
		if (!android::base::ReadFileToString("/proc/uptime", &uptime_str)) {
		return -1;
		}

		// Cast to int to round down.
		return static_cast<int32_t>(strtod(uptime_str.c_str(), NULL));
		}

		// Recursively deletes the directory at \|path\|.
		void DeleteDirectory(const std::string& path) {
		typedef std::unique_ptr<DIR, decltype(&closedir)> ScopedDIR;
		@@ -110,7 +100,7 @@ TEST_F(BootEventRecordStoreTest, AddSingleBootEvent) {
		BootEventRecordStore store;
		store.SetStorePath(GetStorePathForTesting());

		int32_t uptime = ReadUptime();
		time_t uptime = bootstat::ParseUptime();
		ASSERT_NE(-1, uptime);

		store.AddBootEvent("cenozoic");
		@@ -125,7 +115,7 @@ TEST_F(BootEventRecordStoreTest, AddMultipleBootEvents) {
		BootEventRecordStore store;
		store.SetStorePath(GetStorePathForTesting());

		int32_t uptime = ReadUptime();
		time_t uptime = bootstat::ParseUptime();
		ASSERT_NE(-1, uptime);

		store.AddBootEvent("cretaceous");

bootstat/bootstat.cpp

+37 −1

Original line number	Diff line number	Diff line
		@@ -32,6 +32,7 @@
		#include <log/log.h>
		#include "boot_event_record_store.h"
		#include "event_log_list_builder.h"
		#include "uptime_parser.h"

		namespace {

		@@ -174,6 +175,37 @@ int32_t BootReasonStrToEnum(const std::string& boot_reason) {
		return kUnknownBootReason;
		}

		// 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() {
		BootEventRecordStore boot_event_store;
		time_t uptime = bootstat::ParseUptime();

		BootEventRecordStore::BootEventRecord record;

		// post_decrypt_time_elapsed is only logged on encrypted devices.
		if (boot_event_store.GetBootEvent("post_decrypt_time_elapsed", &record)) {
		// Log the amount of time elapsed until the device is decrypted, which
		// includes the variable amount of time the user takes to enter the
		// decryption password.
		boot_event_store.AddBootEventWithValue("boot_decryption_complete", uptime);

		// Subtract the decryption time to normalize the boot cycle timing.
		time_t boot_complete = uptime - record.second;
		boot_event_store.AddBootEventWithValue("boot_complete_post_decrypt",
		boot_complete);


		} else {
		boot_event_store.AddBootEventWithValue("boot_complete_no_encryption",
		uptime);
		}

		// Record the total time from device startup to boot complete, regardless of
		// encryption state.
		boot_event_store.AddBootEventWithValue("boot_complete", uptime);
		}

		// Records the boot_reason metric by querying the ro.boot.bootreason system
		// property.
		void RecordBootReason() {
		@@ -229,6 +261,7 @@ int main(int argc, char **argv) {
		LOG(INFO) << "Service started: " << cmd_line;

		int option_index = 0;
		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[] = {
		@@ -236,6 +269,7 @@ int main(int argc, char **argv) {
		{ "log", no_argument, NULL, 'l' },
		{ "print", no_argument, NULL, 'p' },
		{ "record", required_argument, NULL, 'r' },
		{ 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 }
		@@ -247,7 +281,9 @@ int main(int argc, char **argv) {
		// This case handles long options which have no single-character mapping.
		case 0: {
		const std::string option_name = long_options[option_index].name;
		if (option_name == boot_reason_str) {
		if (option_name == boot_complete_str) {
		RecordBootComplete();
		} else if (option_name == boot_reason_str) {
		RecordBootReason();
		} else if (option_name == factory_reset_str) {
		RecordFactoryReset();

bootstat/bootstat.rc

+10 −2

Original line number	Diff line number	Diff line
		@@ -3,6 +3,14 @@
		on post-fs-data
		mkdir /data/misc/bootstat 0700 root root

		# Record the time at which the user has successfully entered the pin to decrypt
		# the device, /data is decrypted, and the system is entering the main boot phase.
		#
		# post-fs-data: /data is writable
		# property:init.svc.bootanim=running: The boot animation is running
		on post-fs-data && property:init.svc.bootanim=running
		exec - root root -- /system/bin/bootstat -r post_decrypt_time_elapsed

		# The first marker, boot animation stopped, is considered the point at which
		# the user may interact with the device, so it is a good proxy for the boot
		# complete signal.
		@@ -10,8 +18,8 @@ on post-fs-data
		# The second marker ensures an encrypted device is decrypted before logging
		# boot time data.
		on property:init.svc.bootanim=stopped && property:vold.decrypt=trigger_restart_framework
		# Record boot_complete timing event.
		exec - root root -- /system/bin/bootstat -r boot_complete
		# Record boot_complete and related stats (decryption, etc).
		exec - root root -- /system/bin/bootstat --record_boot_complete

		# Record the boot reason.
		exec - root root -- /system/bin/bootstat --record_boot_reason