Move Timer from init to libbase

Test: boot bullhead
Test: new libbase unit tests

Change-Id: Ic398a1daa1fe92c10ea7bc1e6ac3f781cee9a5b5

base/chrono_utils.cpp

@@ -33,5 +33,10 @@ boot_clock::time_point boot_clock::now() {
 #endif  // __ANDROID__
 }
 
+std::ostream& operator<<(std::ostream& os, const Timer& t) {
+  os << t.duration().count() << "ms";
+  return os;
+}
+
 }  // namespace base
 }  // namespace android

base/chrono_utils_test.cpp

@@ -19,6 +19,9 @@
 #include <time.h>
 
 #include <chrono>
+#include <sstream>
+#include <string>
+#include <thread>
 
 #include <gtest/gtest.h>
 
@@ -42,5 +45,36 @@ TEST(ChronoUtilsTest, BootClockNowSeconds) {
   EXPECT_EQ(now, boot_seconds);
 }
 
+template <typename T>
+void ExpectAboutEqual(T expected, T actual) {
+  auto expected_upper_bound = expected * 1.05f;
+  auto expected_lower_bound = expected * .95;
+  EXPECT_GT(expected_upper_bound, actual);
+  EXPECT_LT(expected_lower_bound, actual);
+}
+
+TEST(ChronoUtilsTest, TimerDurationIsSane) {
+  auto start = boot_clock::now();
+  Timer t;
+  std::this_thread::sleep_for(50ms);
+  auto stop = boot_clock::now();
+  auto stop_timer = t.duration();
+
+  auto expected = std::chrono::duration_cast<std::chrono::milliseconds>(stop - start);
+  ExpectAboutEqual(expected, stop_timer);
+}
+
+TEST(ChronoUtilsTest, TimerOstream) {
+  Timer t;
+  std::this_thread::sleep_for(50ms);
+  auto stop_timer = t.duration().count();
+  std::stringstream os;
+  os << t;
+  decltype(stop_timer) stop_timer_from_stream;
+  os >> stop_timer_from_stream;
+  EXPECT_NE(0, stop_timer);
+  ExpectAboutEqual(stop_timer, stop_timer_from_stream);
+}
+
 }  // namespace base
-}  // namespace android
+}  // namespace android

base/include/android-base/chrono_utils.h

@@ -18,6 +18,9 @@
 #define ANDROID_BASE_CHRONO_UTILS_H
 
 #include <chrono>
+#include <sstream>
+
+using namespace std::chrono_literals;
 
 namespace android {
 namespace base {
@@ -31,6 +34,20 @@ class boot_clock {
   static time_point now();
 };
 
+class Timer {
+ public:
+  Timer() : start_(boot_clock::now()) {}
+
+  std::chrono::milliseconds duration() const {
+    return std::chrono::duration_cast<std::chrono::milliseconds>(boot_clock::now() - start_);
+  }
+
+ private:
+  boot_clock::time_point start_;
+};
+
+std::ostream& operator<<(std::ostream& os, const Timer& t);
+
 }  // namespace base
 }  // namespace android
 

init/action.cpp

@@ -16,6 +16,7 @@
 
 #include "action.h"
 
+#include <android-base/chrono_utils.h>
 #include <android-base/logging.h>
 #include <android-base/properties.h>
 #include <android-base/strings.h>
@@ -90,19 +91,18 @@ void Action::ExecuteAllCommands() const {
 }
 
 void Action::ExecuteCommand(const Command& command) const {
-    Timer t;
+    android::base::Timer t;
     int result = command.InvokeFunc();
 
-    double duration_ms = t.duration_s() * 1000;
+    auto duration = t.duration();
     // Any action longer than 50ms will be warned to user as slow operation
-    if (duration_ms > 50.0 ||
-        android::base::GetMinimumLogSeverity() <= android::base::DEBUG) {
+    if (duration > 50ms || android::base::GetMinimumLogSeverity() <= android::base::DEBUG) {
         std::string trigger_name = BuildTriggersString();
         std::string cmd_str = command.BuildCommandString();
 
         LOG(INFO) << "Command '" << cmd_str << "' action=" << trigger_name << " (" << filename_
-                  << ":" << command.line() << ") returned " << result << " took " << duration_ms
-                  << "ms.";
+                  << ":" << command.line() << ") returned " << result << " took "
+                  << duration.count() << "ms.";
     }
 }
 

init/builtins.cpp

@@ -39,6 +39,7 @@
 #include <sys/wait.h>
 #include <unistd.h>
 
+#include <android-base/chrono_utils.h>
 #include <android-base/file.h>
 #include <android-base/logging.h>
 #include <android-base/parseint.h>
@@ -538,9 +539,9 @@ static int do_mount_all(const std::vector<std::string>& args) {
     }
 
     std::string prop_name = "ro.boottime.init.mount_all."s + prop_post_fix;
-    Timer t;
+    android::base::Timer t;
     int ret =  mount_fstab(fstabfile, mount_mode);
-    property_set(prop_name, std::to_string(t.duration_ms()));
+    property_set(prop_name, std::to_string(t.duration().count()));
 
     if (import_rc) {
         /* Paths of .rc files are specified at the 2nd argument and beyond */

init/firmware_handler.cpp

@@ -24,12 +24,12 @@
 #include <string>
 #include <thread>
 
+#include <android-base/chrono_utils.h>
 #include <android-base/file.h>
 #include <android-base/logging.h>
 #include <android-base/unique_fd.h>
 
-#include "util.h"
-
+using android::base::Timer;
 using android::base::unique_fd;
 using android::base::WriteFully;
 

init/init.cpp

@@ -73,6 +73,7 @@ using namespace std::string_literals;
 
 using android::base::boot_clock;
 using android::base::GetProperty;
+using android::base::Timer;
 
 namespace android {
 namespace init {
@@ -232,7 +233,7 @@ static int wait_for_coldboot_done_action(const std::vector<std::string>& args) {
         panic();
     }
 
-    property_set("ro.boottime.init.cold_boot_wait", std::to_string(t.duration_ms()));
+    property_set("ro.boottime.init.cold_boot_wait", std::to_string(t.duration().count()));
     return 0;
 }
 
@@ -870,7 +871,7 @@ static void selinux_initialize(bool in_kernel_domain) {
         }
 
         // 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_ms()).c_str(), 1);
+        setenv("INIT_SELINUX_TOOK", std::to_string(t.duration().count()).c_str(), 1);
     } else {
         selinux_init_all_handles();
     }

init/init_first_stage.cpp

@@ -25,6 +25,7 @@
 #include <string>
 #include <vector>
 
+#include <android-base/chrono_utils.h>
 #include <android-base/file.h>
 #include <android-base/logging.h>
 #include <android-base/strings.h>
@@ -36,7 +37,7 @@
 #include "uevent_listener.h"
 #include "util.h"
 
-using namespace std::chrono_literals;
+using android::base::Timer;
 
 namespace android {
 namespace init {

init/init_parser.cpp

@@ -18,6 +18,7 @@
 
 #include <dirent.h>
 
+#include <android-base/chrono_utils.h>
 #include <android-base/logging.h>
 #include <android-base/stringprintf.h>
 #include <android-base/strings.h>
@@ -111,7 +112,7 @@ void Parser::ParseData(const std::string& filename, const std::string& data) {
 
 bool Parser::ParseConfigFile(const std::string& path) {
     LOG(INFO) << "Parsing file " << path << "...";
-    Timer t;
+    android::base::Timer t;
     std::string data;
     std::string err;
     if (!ReadFile(path, &data, &err)) {

init/init_parser_test.cpp

@@ -16,13 +16,14 @@
 
 #include "init_parser.h"
 
-#include "init.h"
-#include "service.h"
+#include <string>
+#include <vector>
 
 #include <gtest/gtest.h>
 
-#include <string>
-#include <vector>
+#include "init.h"
+#include "service.h"
+#include "util.h"
 
 namespace android {
 namespace init {

init/property_service.cpp

@@ -42,6 +42,7 @@
 #include <queue>
 #include <vector>
 
+#include <android-base/chrono_utils.h>
 #include <android-base/file.h>
 #include <android-base/logging.h>
 #include <android-base/properties.h>
@@ -55,6 +56,8 @@
 #include "init.h"
 #include "util.h"
 
+using android::base::Timer;
+
 #define PERSISTENT_PROPERTY_DIR  "/data/property"
 #define RECOVERY_MOUNT_POINT "/recovery"
 
@@ -350,7 +353,7 @@ class SocketConnection {
     while (*timeout_ms > 0) {
       Timer timer;
       int nr = poll(ufds, 1, *timeout_ms);
-      uint64_t millis = timer.duration_ms();
+      uint64_t millis = timer.duration().count();
       *timeout_ms = (millis > *timeout_ms) ? 0 : *timeout_ms - millis;
 
       if (nr > 0) {

init/reboot.cpp

@@ -35,6 +35,7 @@
 #include <thread>
 #include <vector>
 
+#include <android-base/chrono_utils.h>
 #include <android-base/file.h>
 #include <android-base/logging.h>
 #include <android-base/macros.h>
@@ -54,6 +55,7 @@
 #include "service.h"
 
 using android::base::StringPrintf;
+using android::base::Timer;
 
 namespace android {
 namespace init {
@@ -161,7 +163,8 @@ static void ShutdownVold() {
 }
 
 static void LogShutdownTime(UmountStat stat, Timer* t) {
-    LOG(WARNING) << "powerctl_shutdown_time_ms:" << std::to_string(t->duration_ms()) << ":" << stat;
+    LOG(WARNING) << "powerctl_shutdown_time_ms:" << std::to_string(t->duration().count()) << ":"
+                 << stat;
 }
 
 // Determines whether the system is capable of rebooting. This is conservative,
@@ -254,7 +257,7 @@ static void DumpUmountDebuggingInfo(bool dump_all) {
     }
 }
 
-static UmountStat UmountPartitions(int timeoutMs) {
+static UmountStat UmountPartitions(std::chrono::milliseconds timeout) {
     Timer t;
     UmountStat stat = UMOUNT_STAT_TIMEOUT;
     int retry = 0;
@@ -272,7 +275,7 @@ static UmountStat UmountPartitions(int timeoutMs) {
             stat = UMOUNT_STAT_SUCCESS;
             break;
         }
-        if ((timeoutMs < t.duration_ms()) && retry > 0) {  // try umount at least once
+        if ((timeout < t.duration()) && retry > 0) {  // try umount at least once
             stat = UMOUNT_STAT_TIMEOUT;
             break;
         }
@@ -301,7 +304,7 @@ static void KillAllProcesses() { android::base::WriteStringToFile("i", "/proc/sy
  *
  * return true when umount was successful. false when timed out.
  */
-static UmountStat TryUmountAndFsck(bool runFsck, int timeoutMs) {
+static UmountStat TryUmountAndFsck(bool runFsck, std::chrono::milliseconds timeout) {
     Timer t;
     std::vector<MountEntry> block_devices;
     std::vector<MountEntry> emulated_devices;
@@ -312,13 +315,13 @@ static UmountStat TryUmountAndFsck(bool runFsck, int timeoutMs) {
         return UMOUNT_STAT_ERROR;
     }
 
-    UmountStat stat = UmountPartitions(timeoutMs - t.duration_ms());
+    UmountStat stat = UmountPartitions(timeout - t.duration());
     if (stat != UMOUNT_STAT_SUCCESS) {
         LOG(INFO) << "umount timeout, last resort, kill all and try";
         if (DUMP_ON_UMOUNT_FAILURE) DumpUmountDebuggingInfo(false);
         KillAllProcesses();
         // even if it succeeds, still it is timeout and do not run fsck with all processes killed
-        UmountPartitions(0);
+        UmountPartitions(0ms);
         if (DUMP_ON_UMOUNT_FAILURE) DumpUmountDebuggingInfo(true);
     }
 
@@ -352,15 +355,14 @@ void DoReboot(unsigned int cmd, const std::string& reason, const std::string& re
         abort();
     }
 
-    constexpr unsigned int shutdownTimeoutDefault = 6;
-    unsigned int shutdownTimeout = shutdownTimeoutDefault;
-    if (SHUTDOWN_ZERO_TIMEOUT) {  // eng build
-        shutdownTimeout = 0;
-    } else {
-        shutdownTimeout =
-            android::base::GetUintProperty("ro.build.shutdown_timeout", shutdownTimeoutDefault);
+    auto shutdown_timeout = 0s;
+    if (!SHUTDOWN_ZERO_TIMEOUT) {
+        constexpr unsigned int shutdown_timeout_default = 6;
+        auto shutdown_timeout_property =
+            android::base::GetUintProperty("ro.build.shutdown_timeout", shutdown_timeout_default);
+        shutdown_timeout = std::chrono::seconds(shutdown_timeout_property);
     }
-    LOG(INFO) << "Shutdown timeout: " << shutdownTimeout;
+    LOG(INFO) << "Shutdown timeout: " << shutdown_timeout.count() << " seconds";
 
     // keep debugging tools until non critical ones are all gone.
     const std::set<std::string> kill_after_apps{"tombstoned", "logd", "adbd"};
@@ -387,7 +389,7 @@ void DoReboot(unsigned int cmd, const std::string& reason, const std::string& re
 
     // optional shutdown step
     // 1. terminate all services except shutdown critical ones. wait for delay to finish
-    if (shutdownTimeout > 0) {
+    if (shutdown_timeout > 0s) {
         LOG(INFO) << "terminating init services";
 
         // Ask all services to terminate except shutdown critical ones.
@@ -396,9 +398,9 @@ void DoReboot(unsigned int cmd, const std::string& reason, const std::string& re
         });
 
         int service_count = 0;
-        // Up to half as long as shutdownTimeout or 3 seconds, whichever is lower.
-        unsigned int terminationWaitTimeout = std::min<unsigned int>((shutdownTimeout + 1) / 2, 3);
-        while (t.duration_s() < terminationWaitTimeout) {
+        // Up to half as long as shutdown_timeout or 3 seconds, whichever is lower.
+        auto termination_wait_timeout = std::min((shutdown_timeout + 1s) / 2, 3s);
+        while (t.duration() < termination_wait_timeout) {
             ServiceManager::GetInstance().ReapAnyOutstandingChildren();
 
             service_count = 0;
@@ -446,7 +448,7 @@ void DoReboot(unsigned int cmd, const std::string& reason, const std::string& re
     });
     // 4. sync, try umount, and optionally run fsck for user shutdown
     sync();
-    UmountStat stat = TryUmountAndFsck(runFsck, shutdownTimeout * 1000 - t.duration_ms());
+    UmountStat stat = TryUmountAndFsck(runFsck, shutdown_timeout - t.duration());
     // Follow what linux shutdown is doing: one more sync with little bit delay
     sync();
     std::this_thread::sleep_for(100ms);

init/service.cpp

@@ -633,10 +633,10 @@ bool Service::ParseLine(const std::vector<std::string>& args, std::string* err)
     return (this->*parser)(args, err);
 }
 
-bool Service::ExecStart(std::unique_ptr<Timer>* exec_waiter) {
+bool Service::ExecStart(std::unique_ptr<android::base::Timer>* exec_waiter) {
     flags_ |= SVC_EXEC | SVC_ONESHOT;
 
-    exec_waiter->reset(new Timer);
+    exec_waiter->reset(new android::base::Timer);
 
     if (!Start()) {
         exec_waiter->reset();
@@ -1127,7 +1127,8 @@ bool ServiceManager::ReapOneProcess() {
     if (svc) {
         name = StringPrintf("Service '%s' (pid %d)", svc->name().c_str(), pid);
         if (svc->flags() & SVC_EXEC) {
-            wait_string = StringPrintf(" waiting took %f seconds", exec_waiter_->duration_s());
+            wait_string = StringPrintf(" waiting took %f seconds",
+                                       exec_waiter_->duration().count() / 1000.0f);
         }
     } else {
         name = StringPrintf("Untracked pid %d", pid);

init/service.h

@@ -32,7 +32,6 @@
 #include "descriptors.h"
 #include "init_parser.h"
 #include "keyword_map.h"
-#include "util.h"
 
 #define SVC_DISABLED 0x001        // do not autostart with class
 #define SVC_ONESHOT 0x002         // do not restart on exit
@@ -76,7 +75,7 @@ class Service {
 
     bool IsRunning() { return (flags_ & SVC_RUNNING) != 0; }
     bool ParseLine(const std::vector<std::string>& args, std::string* err);
-    bool ExecStart(std::unique_ptr<Timer>* exec_waiter);
+    bool ExecStart(std::unique_ptr<android::base::Timer>* exec_waiter);
     bool Start();
     bool StartIfNotDisabled();
     bool Enable();
@@ -218,7 +217,7 @@ class ServiceManager {
     bool ReapOneProcess();
 
     static int exec_count_; // Every service needs a unique name.
-    std::unique_ptr<Timer> exec_waiter_;
+    std::unique_ptr<android::base::Timer> exec_waiter_;
 
     std::vector<std::unique_ptr<Service>> services_;
 };

init/ueventd.cpp

@@ -27,6 +27,7 @@
 #include <set>
 #include <thread>
 
+#include <android-base/chrono_utils.h>
 #include <android-base/logging.h>
 #include <android-base/properties.h>
 #include <selinux/android.h>
@@ -198,7 +199,7 @@ void ColdBoot::WaitForSubProcesses() {
 }
 
 void ColdBoot::Run() {
-    Timer cold_boot_timer;
+    android::base::Timer cold_boot_timer;
 
     RegenerateUevents();
 
@@ -209,7 +210,7 @@ void ColdBoot::Run() {
     WaitForSubProcesses();
 
     close(open(COLDBOOT_DONE, O_WRONLY | O_CREAT | O_CLOEXEC, 0000));
-    LOG(INFO) << "Coldboot took " << cold_boot_timer;
+    LOG(INFO) << "Coldboot took " << cold_boot_timer.duration().count() / 1000.0f << " seconds";
 }
 
 DeviceHandler CreateDeviceHandler() {

init/util.cpp

@@ -374,11 +374,6 @@ void panic() {
     DoReboot(ANDROID_RB_RESTART2, "reboot", "bootloader", false);
 }
 
-std::ostream& operator<<(std::ostream& os, const Timer& t) {
-    os << t.duration_s() << " seconds";
-    return os;
-}
-
 // Reads the content of device tree file under kAndroidDtDir directory.
 // Returns true if the read is success, false otherwise.
 bool read_android_dt_file(const std::string& sub_path, std::string* dt_content) {

init/util.h

@@ -44,26 +44,6 @@ int CreateSocket(const char* name, int type, bool passcred, mode_t perm, uid_t u
 bool ReadFile(const std::string& path, std::string* content, std::string* err);
 bool WriteFile(const std::string& path, const std::string& content, std::string* err);
 
-class Timer {
-  public:
-    Timer() : start_(boot_clock::now()) {}
-
-    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_ms() const {
-        return std::chrono::duration_cast<std::chrono::milliseconds>(boot_clock::now() - start_)
-            .count();
-    }
-
-  private:
-    android::base::boot_clock::time_point start_;
-};
-
-std::ostream& operator<<(std::ostream& os, const Timer& t);
-
 bool DecodeUid(const std::string& name, uid_t* uid, std::string* err);
 
 int mkdir_recursive(const std::string& pathname, mode_t mode, selabel_handle* sehandle);