Add logging to AutomaticRebootManager.

There is currently no logging for any events in AutomaticRebootManager
and due to that it's hard to investigate issues with non-rebooting
devices.
These logs will be triggered on Chrome OS devices only:
 * on AutomaticRebootManager initialization
 * when reboot policies "UpdateLimit" or "RebootAfterUpdate" change
 * reboot is required due to an update

BUG=b/69546724

Change-Id: I488bb3b1b398d390f8ff2e5613a532e8494449bf
Reviewed-on: https://chromium-review.googlesource.com/808886Reviewed-by: Bartosz Fabianowski <bartfab@chromium.org>
Reviewed-by: Xiyuan Xia <xiyuan@chromium.org>
Commit-Queue: Sergey Poromov <poromov@chromium.org>
Cr-Commit-Position: refs/heads/master@{#522084}

chrome/browser/chromeos/system/automatic_reboot_manager.cc

@@ -307,6 +307,7 @@ void AutomaticRebootManager::Init(const SystemEventTimes& system_event_times) {
 }
 
 void AutomaticRebootManager::Reschedule() {
+  VLOG(1) << "Rescheduling reboot";
   // Safeguard against reboot loops under error conditions: If the boot time is
   // unavailable because /proc/uptime could not be read, do nothing.
   if (!have_boot_time_)
@@ -334,6 +335,7 @@ void AutomaticRebootManager::Reschedule() {
       local_state_registrar_.prefs()->GetBoolean(prefs::kRebootAfterUpdate) &&
       (!have_reboot_request_time ||
        update_reboot_needed_time_ < reboot_request_time)) {
+    VLOG(1) << "Scheduling reboot because of OS update";
     reboot_request_time = update_reboot_needed_time_;
     have_reboot_request_time = true;
     reboot_reason_ = AutomaticRebootManagerObserver::REBOOT_REASON_OS_UPDATE;
@@ -357,6 +359,7 @@ void AutomaticRebootManager::Reschedule() {
   // started in the past, the timer is still used with its delay set to zero.
   if (!grace_start_timer_)
     grace_start_timer_.reset(new base::OneShotTimer);
+  VLOG(1) << "Scheduling reboot attempt in " << (grace_start_time - now);
   grace_start_timer_->Start(FROM_HERE,
                             std::max(grace_start_time - now, kZeroTimeDelta),
                             base::Bind(&AutomaticRebootManager::RequestReboot,
@@ -368,6 +371,7 @@ void AutomaticRebootManager::Reschedule() {
   // in the past, the timer is still used with its delay set to zero.
   if (!grace_end_timer_)
     grace_end_timer_.reset(new base::OneShotTimer);
+  VLOG(1) << "Scheduling unconditional reboot in " << (grace_end_time - now);
   grace_end_timer_->Start(FROM_HERE,
                           std::max(grace_end_time - now, kZeroTimeDelta),
                           base::Bind(&AutomaticRebootManager::Reboot,
@@ -375,6 +379,7 @@ void AutomaticRebootManager::Reschedule() {
 }
 
 void AutomaticRebootManager::RequestReboot() {
+  VLOG(1) << "Reboot requested, reason: " << reboot_reason_;
   reboot_requested_ = true;
   DCHECK_NE(AutomaticRebootManagerObserver::REBOOT_REASON_UNKNOWN,
             reboot_reason_);
@@ -402,12 +407,14 @@ void AutomaticRebootManager::Reboot() {
   if (user_manager::UserManager::Get()->IsUserLoggedIn() &&
       !user_manager::UserManager::Get()->IsLoggedInAsKioskApp() &&
       !user_manager::UserManager::Get()->IsLoggedInAsArcKioskApp()) {
+    VLOG(1) << "Skipping reboot because non-kiosk session is active";
     return;
   }
 
   login_screen_idle_timer_.reset();
   grace_start_timer_.reset();
   grace_end_timer_.reset();
+  VLOG(1) << "Rebooting immediately.";
   DBusThreadManager::Get()->GetPowerManagerClient()->RequestRestart(
       power_manager::REQUEST_RESTART_OTHER, "automatic reboot manager");
 }