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

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

 // Copyright (c) 2012 The Chromium Authors. All rights reserved.
 // Use of this source code is governed by a BSD-style license that can be
 // found in the LICENSE file.
 
 #include "ash/common/system/chromeos/power/power_status_view.h"
 
 #include "ash/common/material_design/material_design_controller.h"
 #include "ash/common/strings/grit/ash_strings.h"
 #include "ash/common/system/chromeos/power/power_status.h"
 #include "ash/common/system/chromeos/power/tray_power.h"
 #include "ash/common/system/tray/fixed_sized_image_view.h"
 #include "ash/common/system/tray/tray_constants.h"
 #include "ash/common/system/tray/tray_popup_item_style.h"
 #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"
 #include "ui/native_theme/native_theme.h"
 #include "ui/views/controls/image_view.h"
 #include "ui/views/controls/label.h"
 #include "ui/views/layout/box_layout.h"
 #include "ui/views/layout/grid_layout.h"
 
 namespace ash {
@@ skipping 88 matching lines @@
     if (status.IsUsbChargerConnected()) {
       battery_time_status = l10n_util::GetStringUTF16(
           IDS_ASH_STATUS_TRAY_BATTERY_CHARGING_UNRELIABLE);
     } else if (status.IsBatteryTimeBeingCalculated()) {
       battery_time_status =
           l10n_util::GetStringUTF16(IDS_ASH_STATUS_TRAY_BATTERY_CALCULATING);
     } else {
       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(
             status.IsBatteryCharging()
                 ? 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();
       }
     }
   }
   percentage_label_->SetVisible(!battery_percentage.empty());
   percentage_label_->SetText(battery_percentage);
   separator_label_->SetVisible(!battery_percentage.empty() &&
                                !battery_time_status.empty());
   time_status_label_->SetVisible(!battery_time_status.empty());
   time_status_label_->SetText(battery_time_status);
 
@@ skipping 13 matching lines @@
 
 void PowerStatusView::Layout() {
   views::View::Layout();
 
   // Move the time_status_label_, separator_label_, and percentage_label_
   // closer to each other.
   if (percentage_label_ && separator_label_ && time_status_label_ &&
       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();
+    }
   }
 }
 
 void PowerStatusView::GetAccessibleNodeData(ui::AXNodeData* node_data) {
   if (!MaterialDesignController::IsSystemTrayMenuMaterial())
     return;
 
   node_data->role = ui::AX_ROLE_LABEL_TEXT;
   node_data->SetName(accessible_name_);
 }
 
 }  // namespace ash