Write "logout-started" event on next boot.

chrome/browser/chromeos/boot_times_loader.cc

Index: chrome/browser/chromeos/boot_times_loader.cc
diff --git a/chrome/browser/chromeos/boot_times_loader.cc b/chrome/browser/chromeos/boot_times_loader.cc
index 94a675de5433dbcf712824ddd5fa02b548b1c978..26d8a3ce10ac8942e0d69a27f9738b1efcf944b0 100644
--- a/chrome/browser/chromeos/boot_times_loader.cc
+++ b/chrome/browser/chromeos/boot_times_loader.cc
@@ -10,11 +10,14 @@
 #include "base/command_line.h"
 #include "base/file_util.h"
 #include "base/files/file_path.h"
+#include "base/json/json_reader.h"
+#include "base/json/json_writer.h"
 #include "base/lazy_instance.h"
 #include "base/location.h"
 #include "base/message_loop/message_loop.h"
 #include "base/message_loop/message_loop_proxy.h"
 #include "base/metrics/histogram.h"
+#include "base/prefs/pref_service.h"
 #include "base/strings/string_number_conversions.h"
 #include "base/strings/string_util.h"
 #include "base/strings/stringprintf.h"
@@ -29,6 +32,7 @@
 #include "chrome/browser/ui/browser_iterator.h"
 #include "chrome/browser/ui/tabs/tab_strip_model.h"
 #include "chrome/common/chrome_switches.h"
+#include "chrome/common/pref_names.h"
 #include "content/public/browser/browser_thread.h"
 #include "content/public/browser/navigation_controller.h"
 #include "content/public/browser/notification_service.h"
@@ -43,6 +47,9 @@ using content::WebContents;
 
 namespace {
 
+const char kUptime[] = "uptime";
+const char kDisk[] = "disk";
+
 RenderWidgetHost* GetRenderWidgetHost(NavigationController* tab) {
   WebContents* web_contents = tab->GetWebContents();
   if (web_contents) {
@@ -70,6 +77,19 @@ const std::string GetTabUrl(RenderWidgetHost* rwh) {
   return std::string();
 }
 
+// Appends the given buffer into the file. Returns the number of bytes
+// written, or -1 on error.
+// TODO(satorux): Move this to file_util.
+int AppendFile(const base::FilePath& file_path, const char* data, int size) {
+  FILE* file = base::OpenFile(file_path, "a");
+  if (!file)
+    return -1;
+
+  const int num_bytes_written = fwrite(data, 1, size, file);
+  base::CloseFile(file);
+  return num_bytes_written;
+}
+
 }  // namespace
 
 namespace chromeos {
@@ -112,40 +132,98 @@ static const char kLogoutTimes[] = "logout-times";
 static base::LazyInstance<BootTimesLoader> g_boot_times_loader =
     LAZY_INSTANCE_INITIALIZER;
 
-BootTimesLoader::BootTimesLoader()
-    : backend_(new Backend()),
-      have_registered_(false),
-      login_done_(false),
-      restart_requested_(false) {
-  login_time_markers_.reserve(30);
-  logout_time_markers_.reserve(30);
+// static
+BootTimesLoader::Stats BootTimesLoader::Stats::GetCurrentStats() {
+  const base::FilePath kProcUptime(FPL("/proc/uptime"));
+  const base::FilePath kDiskStat(FPL("/sys/block/sda/stat"));
+  Stats stats;
+  // Callers of this method expect synchronous behavior.
+  // It's safe to allow IO here, because only virtual FS are accessed.
+  base::ThreadRestrictions::ScopedAllowIO allow_io;
+  base::ReadFileToString(kProcUptime, &stats.uptime_);
+  base::ReadFileToString(kDiskStat, &stats.disk_);
+  return stats;
 }
 
-BootTimesLoader::~BootTimesLoader() {}
+std::string BootTimesLoader::Stats::SerializeToString() const {
+  if (uptime_.empty() || disk_.empty())
+    return std::string();
+  base::DictionaryValue dictionary;
+  dictionary.SetString(kUptime, uptime_);
+  dictionary.SetString(kDisk, disk_);
+
+  std::string result;
+  if (!base::JSONWriter::Write(&dictionary, &result)) {
+    LOG(WARNING) << "BootTimesLoader::Stats::SerializeToString(): failed.";
+    return result;

[stevenjb, 2014/06/02 19:11:38]

nit: don't return here ('return result' occurs below which was what I meant to
suggest), or explicitly return std::string() as before if you prefer.

[Alexander Alekseev, 2014/06/02 19:18:45]

Done.

+  }
 
-// static
-BootTimesLoader* BootTimesLoader::Get() {
-  return g_boot_times_loader.Pointer();
+  return result;
 }
 
-// Appends the given buffer into the file. Returns the number of bytes
-// written, or -1 on error.
-// TODO(satorux): Move this to file_util.
-static int AppendFile(const base::FilePath& file_path,
-                      const char* data,
-                      int size) {
-  FILE* file = base::OpenFile(file_path, "a");
-  if (!file) {
-    return -1;
+// static
+BootTimesLoader::Stats BootTimesLoader::Stats::DeserializeFromString(
+    const std::string& source) {
+  if (source.empty())
+    return Stats();
+
+  scoped_ptr<base::Value> value(base::JSONReader::Read(source));
+  base::DictionaryValue* dictionary;
+  if (!value || !value->GetAsDictionary(&dictionary)) {
+    LOG(ERROR) << "BootTimesLoader::Stats::DeserializeFromString(): not a "
+                  "dictionary: '" << source << "'";
+    return Stats();
   }
-  const int num_bytes_written = fwrite(data, 1, size, file);
-  base::CloseFile(file);
-  return num_bytes_written;
+
+  Stats result;
+  if (!dictionary->GetString(kUptime, &result.uptime_) ||
+      !dictionary->GetString(kDisk, &result.disk_)) {
+    LOG(ERROR)
+        << "BootTimesLoader::Stats::DeserializeFromString(): format error: '"
+        << source << "'";
+    return Stats();

[stevenjb, 2014/06/02 19:11:38]

nit: Here also, explicit return isn't necessary.

[Alexander Alekseev, 2014/06/02 19:18:45]

It is dangerous, because if first call succeeds, but second fails, the returned
object will be half-initialized.

[stevenjb, 2014/06/02 19:26:33]

Good point, looks good.

+  }
+
+  return result;
+}
+
+bool BootTimesLoader::Stats::UptimeDouble(double* result) const {
+  std::string uptime = uptime_;
+  const size_t space_at = uptime.find_first_of(' ');
+  if (space_at == std::string::npos)
+    return false;
+
+  uptime.resize(space_at);
+
+  if (base::StringToDouble(uptime, result))
+    return true;
+
+  return false;
+}
+
+void BootTimesLoader::Stats::RecordStats(const std::string& name) const {
+  BrowserThread::PostBlockingPoolTask(
+      FROM_HERE,
+      base::Bind(&BootTimesLoader::Stats::RecordStatsImpl,
+                 base::Owned(new Stats(*this)),
+                 name));
 }
 
-static void RecordStatsDelayed(const base::FilePath::StringType& name,
-                               const std::string& uptime,
-                               const std::string& disk) {
+void BootTimesLoader::Stats::RecordStatsWithCallback(
+    const std::string& name,
+    const base::Closure& callback) const {
+  BrowserThread::PostBlockingPoolTaskAndReply(
+      FROM_HERE,
+      base::Bind(&BootTimesLoader::Stats::RecordStatsImpl,
+                 base::Owned(new Stats(*this)),
+                 name),
+      callback);
+}
+
+void BootTimesLoader::Stats::RecordStatsImpl(
+    const base::FilePath::StringType& name) const {
+  DCHECK(content::BrowserThread::GetBlockingPool()->RunsTasksOnCurrentThread());
+
   const base::FilePath log_path(kLogPath);
   const base::FilePath uptime_output =
       log_path.Append(base::FilePath(kUptimePrefix + name));
@@ -153,8 +231,25 @@ static void RecordStatsDelayed(const base::FilePath::StringType& name,
       log_path.Append(base::FilePath(kDiskPrefix + name));
 
   // Append numbers to the files.
-  AppendFile(uptime_output, uptime.data(), uptime.size());
-  AppendFile(disk_output, disk.data(), disk.size());
+  AppendFile(uptime_output, uptime_.data(), uptime_.size());
+  AppendFile(disk_output, disk_.data(), disk_.size());
+}
+
+BootTimesLoader::BootTimesLoader()
+    : backend_(new Backend()),
+      have_registered_(false),
+      login_done_(false),
+      restart_requested_(false) {
+  login_time_markers_.reserve(30);
+  logout_time_markers_.reserve(30);
+}
+
+BootTimesLoader::~BootTimesLoader() {
+}
+
+// static
+BootTimesLoader* BootTimesLoader::Get() {
+  return g_boot_times_loader.Pointer();
 }
 
 // static
@@ -265,32 +360,63 @@ void BootTimesLoader::WriteLogoutTimes() {
              logout_time_markers_);
 }
 
-void BootTimesLoader::RecordStats(const std::string& name, const Stats& stats) {
-  BrowserThread::PostTask(
-      BrowserThread::FILE, FROM_HERE,
-      base::Bind(&RecordStatsDelayed, name, stats.uptime, stats.disk));
+// static
+void BootTimesLoader::ClearLogoutStartedLastPreference() {
+  PrefService* local_state = g_browser_process->local_state();
+  local_state->ClearPref(prefs::kLogoutStartedLast);
 }
 
-BootTimesLoader::Stats BootTimesLoader::GetCurrentStats() {
-  const base::FilePath kProcUptime(FPL("/proc/uptime"));
-  const base::FilePath kDiskStat(FPL("/sys/block/sda/stat"));
-  Stats stats;
-  base::ThreadRestrictions::ScopedAllowIO allow_io;
-  base::ReadFileToString(kProcUptime, &stats.uptime);
-  base::ReadFileToString(kDiskStat, &stats.disk);
-  return stats;
+void BootTimesLoader::OnChromeProcessStart() {
+  PrefService* local_state = g_browser_process->local_state();
+  const std::string logout_started_last_str =
+      local_state->GetString(prefs::kLogoutStartedLast);
+  if (logout_started_last_str.empty())
+    return;
+
+  // Note that kLogoutStartedLast is not cleared on format error to stay in
+  // logs in case of other fatal system errors.
+
+  const Stats logout_started_last_stats =
+      Stats::DeserializeFromString(logout_started_last_str);
+  if (logout_started_last_stats.uptime().empty())
+    return;
+
+  double logout_started_last;
+  double uptime;
+  if (!logout_started_last_stats.UptimeDouble(&logout_started_last) ||
+      !Stats::GetCurrentStats().UptimeDouble(&uptime)) {
+    return;
+  }
+
+  if (logout_started_last >= uptime) {
+    // Reboot happened.
+    ClearLogoutStartedLastPreference();
+    return;
+  }
+
+  // Write /tmp/uptime-logout-started as well.
+  const char kLogoutStarted[] = "logout-started";
+  logout_started_last_stats.RecordStatsWithCallback(
+      kLogoutStarted,
+      base::Bind(&BootTimesLoader::ClearLogoutStartedLastPreference));
+}
+
+void BootTimesLoader::OnLogoutStarted(PrefService* state) {
+  const std::string uptime = Stats::GetCurrentStats().SerializeToString();
+  if (!uptime.empty())
+    state->SetString(prefs::kLogoutStartedLast, uptime);
 }
 
 void BootTimesLoader::RecordCurrentStats(const std::string& name) {
-  RecordStats(name, GetCurrentStats());
+  Stats::GetCurrentStats().RecordStats(name);
 }
 
 void BootTimesLoader::SaveChromeMainStats() {
-  chrome_main_stats_ = GetCurrentStats();
+  chrome_main_stats_ = Stats::GetCurrentStats();
 }
 
 void BootTimesLoader::RecordChromeMainStats() {
-  RecordStats(kChromeMain, chrome_main_stats_);
+  chrome_main_stats_.RecordStats(kChromeMain);
 }
 
 void BootTimesLoader::RecordLoginAttempted() {