Night Light: Add some logging to help debug edge cases

We started getting some feedback reports about Night Light not
working properly but they're not useful since Night Light doesn't
log anything at all.

This CL adds some logs in the potential areas where problems are
more likely to occur, such as geolocation.

BUG=768902

Change-Id: If836f856126f4d2a9f2179873b217b944ca42674
Reviewed-on: https://chromium-review.googlesource.com/696191
Commit-Queue: Ahmed Fakhry <afakhry@chromium.org>
Reviewed-by: James Cook <jamescook@chromium.org>
Cr-Commit-Position: refs/heads/master@{#505904}

ash/system/night_light/night_light_controller.cc

@@ -11,6 +11,8 @@
 #include "ash/session/session_controller.h"
 #include "ash/shell.h"
 #include "base/command_line.h"
+#include "base/i18n/time_formatting.h"
+#include "base/logging.h"
 #include "base/metrics/histogram_macros.h"
 #include "base/time/time.h"
 #include "components/prefs/pref_registry_simple.h"
@@ -24,10 +26,10 @@ namespace ash {
 namespace {
 
 // Default start time at 6:00 PM as an offset from 00:00.
-const int kDefaultStartTimeOffsetMinutes = 18 * 60;
+constexpr int kDefaultStartTimeOffsetMinutes = 18 * 60;
 
 // Default end time at 6:00 AM as an offset from 00:00.
-const int kDefaultEndTimeOffsetMinutes = 6 * 60;
+constexpr int kDefaultEndTimeOffsetMinutes = 6 * 60;
 
 constexpr float kDefaultColorTemperature = 0.5f;
 
@@ -57,6 +59,8 @@ class NightLightControllerDelegateImpl : public NightLightController::Delegate {
  private:
   base::Time GetSunRiseSet(bool sunrise) const {
     if (!ValidatePosition()) {
+      LOG(ERROR) << "Invalid geoposition. Using default time for "
+                 << (sunrise ? "sunrise." : "sunset.");
       return sunrise ? TimeOfDay(kDefaultEndTimeOffsetMinutes).ToTimeToday()
                      : TimeOfDay(kDefaultStartTimeOffsetMinutes).ToTimeToday();
     }
@@ -255,6 +259,7 @@ void NightLightController::OnActiveUserPrefServiceChanged(
 
 void NightLightController::SetCurrentGeoposition(
     mojom::SimpleGeopositionPtr position) {
+  VLOG(1) << "Received new geoposition.";
   delegate_->SetGeoposition(std::move(position));
 
   // If the schedule type is sunset to sunrise, then a potential change in the
@@ -479,10 +484,14 @@ void NightLightController::RefreshScheduleTimer(base::Time start_time,
 }
 
 void NightLightController::ScheduleNextToggle(base::TimeDelta delay) {
+  const bool new_status = !GetEnabled();
+  VLOG(1) << "Setting Night Light to toggle to "
+          << (new_status ? "enabled" : "disabled") << " at "
+          << base::TimeFormatTimeOfDay(delegate_->GetNow() + delay);
   timer_.Start(
       FROM_HERE, delay,
       base::Bind(&NightLightController::SetEnabled, base::Unretained(this),
-                 !GetEnabled(), AnimationDuration::kLong));
+                 new_status, AnimationDuration::kLong));
 }
 
 }  // namespace ash

chrome/browser/chromeos/night_light/night_light_client.cc

@@ -7,6 +7,7 @@
 #include <algorithm>
 
 #include "ash/public/interfaces/constants.mojom.h"
+#include "base/logging.h"
 #include "base/time/clock.h"
 #include "content/public/common/service_manager_connection.h"
 #include "services/service_manager/public/cpp/connector.h"
@@ -66,6 +67,8 @@ void NightLightClient::OnScheduleTypeChanged(
   base::Time now = GetNow();
   if ((now - last_successful_geo_request_time_) <
       kNextRequestDelayAfterSuccess) {
+    VLOG(1) << "Already has a recent valid geoposition. Using it instead of "
+            << "requesting a new one.";
     // Use the current valid position to update NightLightController.
     SendCurrentGeoposition();
   }
@@ -112,6 +115,7 @@ void NightLightClient::OnGeoposition(const chromeos::Geoposition& position,
 
   if (server_error || !position.Valid() ||
       elapsed > kGeolocationRequestTimeout) {
+    VLOG(1) << "Failed to get a valid geoposition. Trying again later.";
     // Don't send invalid positions to ash.
     // On failure, we schedule another request after the current backoff delay.
     ScheduleNextRequest(backoff_delay_);
@@ -147,6 +151,7 @@ void NightLightClient::ScheduleNextRequest(base::TimeDelta delay) {
 }
 
 void NightLightClient::RequestGeoposition() {
+  VLOG(1) << "Requesting a new geoposition";
   provider_.RequestGeolocation(
       kGeolocationRequestTimeout, false /* send_wifi_access_points */,
       false /* send_cell_towers */,