Merge "Replace the "coldboot" timeout with a property."
diff --git a/init/action.cpp b/init/action.cpp
index 0ea7e14..65bf292 100644
--- a/init/action.cpp
+++ b/init/action.cpp
@@ -121,7 +121,7 @@
Timer t;
int result = command.InvokeFunc();
- double duration_ms = t.duration() * 1000;
+ double duration_ms = t.duration_s() * 1000;
// Any action longer than 50ms will be warned to user as slow operation
if (duration_ms > 50.0 ||
android::base::GetMinimumLogSeverity() <= android::base::DEBUG) {
diff --git a/init/builtins.cpp b/init/builtins.cpp
index 6d58754..76e3d6e 100644
--- a/init/builtins.cpp
+++ b/init/builtins.cpp
@@ -146,8 +146,7 @@
LOG(ERROR) << "failed to set bootloader message: " << err;
return -1;
}
- android_reboot(ANDROID_RB_RESTART2, 0, "recovery");
- while (1) { pause(); } // never reached
+ reboot("recovery");
}
static void unmount_and_fsck(const struct mntent *entry) {
@@ -727,7 +726,7 @@
ServiceManager::GetInstance().ForEachService(
[] (Service* s) { s->Terminate(); });
- while (t.duration() < delay) {
+ while (t.duration_s() < delay) {
ServiceManager::GetInstance().ReapAnyOutstandingChildren();
int service_count = 0;
@@ -751,11 +750,10 @@
// Wait a bit before recounting the number or running services.
std::this_thread::sleep_for(50ms);
}
- LOG(VERBOSE) << "Terminating running services took " << t.duration() << " seconds";
+ LOG(VERBOSE) << "Terminating running services took " << t;
}
- return android_reboot_with_callback(cmd, 0, reboot_target,
- callback_on_ro_remount);
+ return android_reboot_with_callback(cmd, 0, reboot_target, callback_on_ro_remount);
}
static int do_trigger(const std::vector<std::string>& args) {
diff --git a/init/devices.cpp b/init/devices.cpp
index 2db24b7..6af237c 100644
--- a/init/devices.cpp
+++ b/init/devices.cpp
@@ -868,7 +868,7 @@
if (pid == 0) {
Timer t;
process_firmware_event(uevent);
- LOG(INFO) << "loading " << uevent->path << " took " << t.duration() << "s";
+ LOG(INFO) << "loading " << uevent->path << " took " << t;
_exit(EXIT_SUCCESS);
} else if (pid == -1) {
PLOG(ERROR) << "could not fork to process firmware event for " << uevent->firmware;
@@ -1043,7 +1043,7 @@
coldboot("/sys/block");
coldboot("/sys/devices");
close(open(COLDBOOT_DONE, O_WRONLY|O_CREAT|O_CLOEXEC, 0000));
- LOG(INFO) << "Coldboot took " << t.duration() << "s.";
+ LOG(INFO) << "Coldboot took " << t;
}
int get_device_fd() {
diff --git a/init/init.cpp b/init/init.cpp
index ef6f37c..95cb62f 100644
--- a/init/init.cpp
+++ b/init/init.cpp
@@ -43,7 +43,6 @@
#include <android-base/file.h>
#include <android-base/stringprintf.h>
#include <android-base/strings.h>
-#include <cutils/android_reboot.h>
#include <cutils/fs.h>
#include <cutils/iosched_policy.h>
#include <cutils/list.h>
@@ -163,14 +162,21 @@
Timer t;
LOG(VERBOSE) << "Waiting for " COLDBOOT_DONE "...";
- // Any longer than 1s is an unreasonable length of time to delay booting.
- // If you're hitting this timeout, check that you didn't make your
- // sepolicy regular expressions too expensive (http://b/19899875).
- if (wait_for_file(COLDBOOT_DONE, 1s)) {
+
+ // Historically we had a 1s timeout here because we weren't otherwise
+ // tracking boot time, and many OEMs made their sepolicy regular
+ // expressions too expensive (http://b/19899875).
+
+ // Now we're tracking boot time, just log the time taken to a system
+ // property. We still panic if it takes more than a minute though,
+ // because any build that slow isn't likely to boot at all, and we'd
+ // rather any test lab devices fail back to the bootloader.
+ if (wait_for_file(COLDBOOT_DONE, 60s) < 0) {
LOG(ERROR) << "Timed out waiting for " COLDBOOT_DONE;
+ panic();
}
- LOG(VERBOSE) << "Waiting for " COLDBOOT_DONE " took " << t.duration() << "s.";
+ property_set("ro.boottime.init.cold_boot_wait", std::to_string(t.duration_ns()).c_str());
return 0;
}
@@ -409,9 +415,8 @@
}
static void security_failure() {
- LOG(ERROR) << "Security failure; rebooting into recovery mode...";
- android_reboot(ANDROID_RB_RESTART2, 0, "recovery");
- while (true) { pause(); } // never reached
+ LOG(ERROR) << "Security failure...";
+ panic();
}
static void selinux_initialize(bool in_kernel_domain) {
@@ -443,8 +448,8 @@
security_failure();
}
- LOG(INFO) << "(Initializing SELinux " << (is_enforcing ? "enforcing" : "non-enforcing")
- << " took " << t.duration() << "s.)";
+ // init's first stage can't set properties, so pass the time to the second stage.
+ setenv("INIT_SELINUX_TOOK", std::to_string(t.duration_ns()).c_str(), 1);
} else {
selinux_init_all_handles();
}
@@ -650,7 +655,13 @@
export_kernel_boot_props();
// Make the time that init started available for bootstat to log.
- property_set("init.start", getenv("INIT_STARTED_AT"));
+ property_set("ro.boottime.init", getenv("INIT_STARTED_AT"));
+ property_set("ro.boottime.init.selinux", getenv("INIT_SELINUX_TOOK"));
+
+ // Clean up our environment.
+ unsetenv("INIT_SECOND_STAGE");
+ unsetenv("INIT_STARTED_AT");
+ unsetenv("INIT_SELINUX_TOOK");
// Now set up SELinux for second stage.
selinux_initialize(false);
diff --git a/init/init_parser.cpp b/init/init_parser.cpp
index d017390..406b339 100644
--- a/init/init_parser.cpp
+++ b/init/init_parser.cpp
@@ -110,7 +110,7 @@
// Nexus 9 boot time, so it's disabled by default.
if (false) DumpState();
- LOG(VERBOSE) << "(Parsing " << path << " took " << t.duration() << "s.)";
+ LOG(VERBOSE) << "(Parsing " << path << " took " << t << ".)";
return true;
}
diff --git a/init/property_service.cpp b/init/property_service.cpp
index e198297..aed8438 100644
--- a/init/property_service.cpp
+++ b/init/property_service.cpp
@@ -169,11 +169,18 @@
return true;
}
-static int property_set_impl(const char* name, const char* value) {
+int property_set(const char* name, const char* value) {
size_t valuelen = strlen(value);
- if (!is_legal_property_name(name)) return -1;
- if (valuelen >= PROP_VALUE_MAX) return -1;
+ if (!is_legal_property_name(name)) {
+ LOG(ERROR) << "property_set(\"" << name << "\", \"" << value << "\") failed: bad name";
+ return -1;
+ }
+ if (valuelen >= PROP_VALUE_MAX) {
+ LOG(ERROR) << "property_set(\"" << name << "\", \"" << value << "\") failed: "
+ << "value too long";
+ return -1;
+ }
if (strcmp("selinux.restorecon_recursive", name) == 0 && valuelen > 0) {
if (restorecon(value, SELINUX_ANDROID_RESTORECON_RECURSE) != 0) {
@@ -182,49 +189,42 @@
}
prop_info* pi = (prop_info*) __system_property_find(name);
-
- if(pi != 0) {
- /* ro.* properties may NEVER be modified once set */
- if(!strncmp(name, "ro.", 3)) return -1;
+ if (pi != nullptr) {
+ // ro.* properties are actually "write-once".
+ if (!strncmp(name, "ro.", 3)) {
+ LOG(ERROR) << "property_set(\"" << name << "\", \"" << value << "\") failed: "
+ << "property already set";
+ return -1;
+ }
__system_property_update(pi, value, valuelen);
} else {
int rc = __system_property_add(name, strlen(name), value, valuelen);
if (rc < 0) {
+ LOG(ERROR) << "property_set(\"" << name << "\", \"" << value << "\") failed: "
+ << "__system_property_add failed";
return rc;
}
}
- /* If name starts with "net." treat as a DNS property. */
+
+ // If name starts with "net." treat as a DNS property.
if (strncmp("net.", name, strlen("net.")) == 0) {
if (strcmp("net.change", name) == 0) {
return 0;
}
- /*
- * The 'net.change' property is a special property used track when any
- * 'net.*' property name is updated. It is _ONLY_ updated here. Its value
- * contains the last updated 'net.*' property.
- */
+ // The 'net.change' property is a special property used track when any
+ // 'net.*' property name is updated. It is _ONLY_ updated here. Its value
+ // contains the last updated 'net.*' property.
property_set("net.change", name);
- } else if (persistent_properties_loaded &&
- strncmp("persist.", name, strlen("persist.")) == 0) {
- /*
- * Don't write properties to disk until after we have read all default properties
- * to prevent them from being overwritten by default values.
- */
+ } else if (persistent_properties_loaded && strncmp("persist.", name, strlen("persist.")) == 0) {
+ // Don't write properties to disk until after we have read all default properties
+ // to prevent them from being overwritten by default values.
write_persistent_property(name, value);
}
property_changed(name, value);
return 0;
}
-int property_set(const char* name, const char* value) {
- int rc = property_set_impl(name, value);
- if (rc == -1) {
- LOG(ERROR) << "property_set(\"" << name << "\", \"" << value << "\") failed";
- }
- return rc;
-}
-
static void handle_property_set_fd()
{
prop_msg msg;
@@ -388,7 +388,7 @@
}
data.push_back('\n');
load_properties(&data[0], filter);
- LOG(VERBOSE) << "(Loading properties from " << filename << " took " << t.duration() << "s.)";
+ LOG(VERBOSE) << "(Loading properties from " << filename << " took " << t << ".)";
}
static void load_persistent_properties() {
diff --git a/init/readme.txt b/init/readme.txt
index 7e9d21b..7549e3c 100644
--- a/init/readme.txt
+++ b/init/readme.txt
@@ -440,16 +440,27 @@
Init provides information about the services that it is responsible
for via the below properties.
-init.start
- Time after boot in ns (via the CLOCK_BOOTTIME clock) at which the first
- stage of init started.
-
init.svc.<name>
State of a named service ("stopped", "stopping", "running", "restarting")
-init.svc.<name>.start
+
+Boot timing
+-----------
+Init records some boot timing information in system properties.
+
+ro.boottime.init
+ Time after boot in ns (via the CLOCK_BOOTTIME clock) at which the first
+ stage of init started.
+
+ro.boottime.init.selinux
+ How long it took the first stage to initialize SELinux.
+
+ro.boottime.init.cold_boot_wait
+ How long init waited for ueventd's coldboot phase to end.
+
+ro.boottime.<service-name>
Time after boot in ns (via the CLOCK_BOOTTIME clock) that the service was
- most recently started.
+ first started.
Bootcharting
diff --git a/init/service.cpp b/init/service.cpp
index 1f53a1b..4b9724d 100644
--- a/init/service.cpp
+++ b/init/service.cpp
@@ -36,7 +36,6 @@
#include <android-base/parseint.h>
#include <android-base/stringprintf.h>
#include <android-base/strings.h>
-#include <cutils/android_reboot.h>
#include <system/thread_defs.h>
#include <processgroup/processgroup.h>
@@ -190,9 +189,9 @@
property_set(prop_name.c_str(), new_state.c_str());
if (new_state == "running") {
- prop_name += ".start";
uint64_t start_ns = time_started_.time_since_epoch().count();
- property_set(prop_name.c_str(), StringPrintf("%" PRIu64, start_ns).c_str());
+ property_set(StringPrintf("ro.boottime.%s", name_.c_str()).c_str(),
+ StringPrintf("%" PRIu64, start_ns).c_str());
}
}
@@ -283,10 +282,8 @@
if ((flags_ & SVC_CRITICAL) && !(flags_ & SVC_RESTART)) {
if (now < time_crashed_ + 4min) {
if (++crash_count_ > 4) {
- LOG(ERROR) << "critical process '" << name_ << "' exited 4 times in 4 minutes; "
- << "rebooting into recovery mode";
- android_reboot(ANDROID_RB_RESTART2, 0, "recovery");
- return false;
+ LOG(ERROR) << "critical process '" << name_ << "' exited 4 times in 4 minutes";
+ panic();
}
} else {
time_crashed_ = now;
diff --git a/init/signal_handler.cpp b/init/signal_handler.cpp
index 0dea3e0..1041b82 100644
--- a/init/signal_handler.cpp
+++ b/init/signal_handler.cpp
@@ -24,7 +24,6 @@
#include <unistd.h>
#include <android-base/stringprintf.h>
-#include <cutils/android_reboot.h>
#include <cutils/list.h>
#include <cutils/sockets.h>
diff --git a/init/util.cpp b/init/util.cpp
index 5205ea0..38e3b8d 100644
--- a/init/util.cpp
+++ b/init/util.cpp
@@ -41,6 +41,8 @@
#include <android-base/stringprintf.h>
#include <android-base/strings.h>
#include <android-base/unique_fd.h>
+
+#include <cutils/android_reboot.h>
/* for ANDROID_SOCKET_* */
#include <cutils/sockets.h>
@@ -472,3 +474,22 @@
return true;
}
+
+void reboot(const char* destination) {
+ android_reboot(ANDROID_RB_RESTART2, 0, destination);
+ // We're init, so android_reboot will actually have been a syscall so there's nothing
+ // to wait for. If android_reboot returns, just abort so that the kernel will reboot
+ // itself when init dies.
+ PLOG(FATAL) << "reboot failed";
+ abort();
+}
+
+void panic() {
+ LOG(ERROR) << "panic: rebooting to bootloader";
+ reboot("bootloader");
+}
+
+std::ostream& operator<<(std::ostream& os, const Timer& t) {
+ os << t.duration_s() << " seconds";
+ return os;
+}
diff --git a/init/util.h b/init/util.h
index d56da39..4b54361 100644
--- a/init/util.h
+++ b/init/util.h
@@ -21,8 +21,9 @@
#include <sys/types.h>
#include <chrono>
-#include <string>
#include <functional>
+#include <ostream>
+#include <string>
#define COLDBOOT_DONE "/dev/.coldboot_done"
@@ -51,15 +52,21 @@
Timer() : start_(boot_clock::now()) {
}
- double duration() {
+ double duration_s() const {
typedef std::chrono::duration<double> double_duration;
return std::chrono::duration_cast<double_duration>(boot_clock::now() - start_).count();
}
+ int64_t duration_ns() const {
+ return (boot_clock::now() - start_).count();
+ }
+
private:
boot_clock::time_point start_;
};
+std::ostream& operator<<(std::ostream& os, const Timer& t);
+
unsigned int decode_uid(const char *s);
int mkdir_recursive(const char *pathname, mode_t mode);
@@ -72,4 +79,8 @@
std::string bytes_to_hex(const uint8_t *bytes, size_t bytes_len);
bool is_dir(const char* pathname);
bool expand_props(const std::string& src, std::string* dst);
+
+void reboot(const char* destination) __attribute__((__noreturn__));
+void panic() __attribute__((__noreturn__));
+
#endif