init: ro.boottime.init.modules
Add a property ro.boottime.init.modules to provide kernel modules
loading time in milliseconds. Also add corresponding log to show in init
log along with loaded module count.
Test: boot test
Bug: 178143513
Change-Id: I77e3939c2a271da6841350a8c2a34ad32f637377
diff --git a/init/README.md b/init/README.md
index 67d55e1..bb1a1a0 100644
--- a/init/README.md
+++ b/init/README.md
@@ -795,6 +795,9 @@
`ro.boottime.init.selinux`
> How long in ns it took to run SELinux stage.
+`ro.boottime.init.modules`
+> How long in ms it took to load kernel modules.
+
`ro.boottime.init.cold_boot_wait`
> How long init waited for ueventd's coldboot phase to end.
diff --git a/init/first_stage_init.cpp b/init/first_stage_init.cpp
index 6954c03..83d2b6d 100644
--- a/init/first_stage_init.cpp
+++ b/init/first_stage_init.cpp
@@ -122,7 +122,7 @@
}
#define MODULE_BASE_DIR "/lib/modules"
-bool LoadKernelModules(bool recovery, bool want_console) {
+bool LoadKernelModules(bool recovery, bool want_console, int& modules_loaded) {
struct utsname uts;
if (uname(&uts)) {
LOG(FATAL) << "Failed to get kernel version.";
@@ -164,7 +164,7 @@
dir_path.append(module_dir);
Modprobe m({dir_path}, GetModuleLoadList(recovery, dir_path));
bool retval = m.LoadListedModules(!want_console);
- int modules_loaded = m.GetModuleCount();
+ modules_loaded = m.GetModuleCount();
if (modules_loaded > 0) {
return retval;
}
@@ -172,7 +172,7 @@
Modprobe m({MODULE_BASE_DIR}, GetModuleLoadList(recovery, MODULE_BASE_DIR));
bool retval = m.LoadListedModules(!want_console);
- int modules_loaded = m.GetModuleCount();
+ modules_loaded = m.GetModuleCount();
if (modules_loaded > 0) {
return retval;
}
@@ -278,13 +278,23 @@
auto want_console = ALLOW_FIRST_STAGE_CONSOLE ? FirstStageConsole(cmdline) : 0;
- if (!LoadKernelModules(IsRecoveryMode() && !ForceNormalBoot(cmdline), want_console)) {
+ boot_clock::time_point module_start_time = boot_clock::now();
+ int module_count = 0;
+ if (!LoadKernelModules(IsRecoveryMode() && !ForceNormalBoot(cmdline), want_console,
+ module_count)) {
if (want_console != FirstStageConsoleParam::DISABLED) {
LOG(ERROR) << "Failed to load kernel modules, starting console";
} else {
LOG(FATAL) << "Failed to load kernel modules";
}
}
+ if (module_count > 0) {
+ auto module_elapse_time = std::chrono::duration_cast<std::chrono::milliseconds>(
+ boot_clock::now() - module_start_time);
+ setenv(kEnvInitModuleDurationMs, std::to_string(module_elapse_time.count()).c_str(), 1);
+ LOG(INFO) << "Loaded " << module_count << " kernel modules took "
+ << module_elapse_time.count() << " ms";
+ }
if (want_console == FirstStageConsoleParam::CONSOLE_ON_FAILURE) {
StartConsole(cmdline);
diff --git a/init/first_stage_init.h b/init/first_stage_init.h
index 7de816f..1211f29 100644
--- a/init/first_stage_init.h
+++ b/init/first_stage_init.h
@@ -22,6 +22,7 @@
int FirstStageMain(int argc, char** argv);
static constexpr char kEnvFirstStageStartedAt[] = "FIRST_STAGE_STARTED_AT";
+static constexpr char kEnvInitModuleDurationMs[] = "INIT_MODULE_DURATION_MS";
} // namespace init
} // namespace android
diff --git a/init/init.cpp b/init/init.cpp
index b08037a..70d6809 100644
--- a/init/init.cpp
+++ b/init/init.cpp
@@ -713,6 +713,10 @@
SetProperty("ro.boottime.init.selinux",
std::to_string(second_stage_start_time.time_since_epoch().count() -
selinux_start_time_ns));
+ if (auto init_module_time_str = getenv(kEnvInitModuleDurationMs); init_module_time_str) {
+ SetProperty("ro.boottime.init.modules", init_module_time_str);
+ unsetenv(kEnvInitModuleDurationMs);
+ }
}
void SendLoadPersistentPropertiesMessage() {