Adding logging to help determine why System Menu battery time isn't shown sometimes.

ash/common/system/chromeos/power/power_status_view.cc

Index: ash/common/system/chromeos/power/power_status_view.cc
diff --git a/ash/common/system/chromeos/power/power_status_view.cc b/ash/common/system/chromeos/power/power_status_view.cc
index 12e904958321129d5b9592ea7fa505cc4c4140a8..7a19e7e13016e0bbeac57ae2cdb93751602f168a 100644
--- a/ash/common/system/chromeos/power/power_status_view.cc
+++ b/ash/common/system/chromeos/power/power_status_view.cc
@@ -14,6 +14,7 @@
 #include "ash/common/system/tray/tray_popup_utils.h"
 #include "base/i18n/number_formatting.h"
 #include "base/i18n/time_formatting.h"
+#include "base/logging.h"
 #include "base/strings/utf_string_conversions.h"
 #include "ui/accessibility/ax_node_data.h"
 #include "ui/base/l10n/l10n_util.h"
@@ -122,6 +123,7 @@ void PowerStatusView::UpdateText() {
       base::TimeDelta time = status.IsBatteryCharging()
                                  ? status.GetBatteryTimeToFull()
                                  : status.GetBatteryTimeToEmpty();
+      bool should_warn = false;
       if (PowerStatus::ShouldDisplayBatteryTime(time) &&
           !status.IsBatteryDischargingOnLinePower()) {
         battery_time_status = l10n_util::GetStringFUTF16(
@@ -129,6 +131,25 @@ void PowerStatusView::UpdateText() {
                 ? IDS_ASH_STATUS_TRAY_BATTERY_TIME_UNTIL_FULL_SHORT
                 : IDS_ASH_STATUS_TRAY_BATTERY_TIME_LEFT_SHORT,
             TimeDurationFormat(time, base::DURATION_WIDTH_NUMERIC));

[Daniel Erat, 2017/03/02 17:07:09]

since (i think) what we really want to figure out is why we're logging " left",
i'd probably recommend instead changing the code in this block to:

  const base::string16 duration =
       TimeDurationFormat(time, base::DURATION_WIDTH_NUMERIC);
  if (duration.empty()) {
    LOG(WARNING) << "Got empty battery time string for time "
                 << time.InMilliseconds() << " (see https://crbug.com/677043)";
  }
  battery_time_status = l10n_util::GetStringFUTF16(...);

+
+        should_warn = battery_time_status.empty();
+      } else {
+        should_warn = true;

[Daniel Erat, 2017/03/02 14:38:11]

why do you want to warn in this case?

[bruthig, 2017/03/02 15:23:35]

I thought just showing the '%', like in comment #28 was also not WAI or at the
very least suspicious.

[Daniel Erat, 2017/03/02 17:07:09]

hmm... it's definitely expected to happen when the battery will take a long time
to charge or empty, due to either a low-power charger being used or the charging
and discharging rates being close.

+      }
+
+      if (should_warn) {
+        DCHECK(false)

[bruthig, 2017/03/02 05:08:06]

This might be a little too aggressive given it is a valid else case above.

[Daniel Erat, 2017/03/02 17:07:09]

definitely too aggressive. :-)

+            << "Please submit feedback, including logs for issue 677043.";
+        // Capturing more info to determine why the remaining battery time is
+        // sometimes not visible, see https://crbug.com/677043.
+        if (status.IsBatteryCharging())
+          LOG(WARNING) << "Time to full: " << time.InMilliseconds();
+        else
+          LOG(WARNING) << "Time to empty: " << time.InMilliseconds();

[Daniel Erat, 2017/03/02 14:38:11]

can't we already see the values that powerd sent to chrome here?

[bruthig, 2017/03/02 15:23:35]

I'm not familiar with the other logging, but we probably do, although if I
understand correctly having an inconsistent |status| instance is an potential
candidate that we may want to rule out.  Does the other logging also log the
IsBatteryCharging() value? and does it affect which time is logged?

+        LOG(WARNING) << "ShouldDisplayBatteryTime(time)="
+                     << PowerStatus::ShouldDisplayBatteryTime(time);
+        LOG(WARNING) << "IsBatteryDischargingOnLinePower()="
+                     << status.IsBatteryDischargingOnLinePower();
       }
     }
   }
@@ -162,6 +183,13 @@ void PowerStatusView::Layout() {
       percentage_label_->visible() && time_status_label_->visible()) {
     separator_label_->SetX(percentage_label_->bounds().right() + 1);
     time_status_label_->SetX(separator_label_->bounds().right() + 1);
+
+    // Capturing more info to determine why the remaining battery time infos
+    // sometimes not visible, see https://crbug.com/677043.
+    if (time_status_label_->x() < 0 ||
+        time_status_label_->x() > bounds().right()) {
+      LOG(WARNING) << "time_status_label_.x(): " << time_status_label_->x();
+    }
   }
 }