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

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

BUG=677043

[bruthig, 2017-03-02 05:01:42]

The CQ bit was checked by bruthig@chromium.org to run a CQ dry run

[bruthig, 2017-03-02 05:02:13]

bruthig@chromium.org changed reviewers:
+ derat@chromium.org

[bruthig, 2017-03-02 05:02:14]

derat@, can you PTAL?

[commit-bot: I haz the power, 2017-03-02 05:03:15]

Dry run: CQ is trying da patch. Follow status at
 
https://chromium-cq-status.appspot.com/v2/patch-status/codereview.chromium.or...

[bruthig, 2017-03-02 05:08:07]

https://codereview.chromium.org/2731463002/diff/1/ash/common/system/chromeos/...
File ash/common/system/chromeos/power/power_status_view.cc (right):

https://codereview.chromium.org/2731463002/diff/1/ash/common/system/chromeos/...
ash/common/system/chromeos/power/power_status_view.cc:141: DCHECK(false)
This might be a little too aggressive given it is a valid else case above.

[commit-bot: I haz the power, 2017-03-02 05:39:48]

The CQ bit was unchecked by commit-bot@chromium.org

[commit-bot: I haz the power, 2017-03-02 05:39:49]

Dry run: Try jobs failed on following builders:
  linux_chromium_chromeos_ozone_rel_ng on master.tryserver.chromium.linux
(JOB_FAILED,
http://build.chromium.org/p/tryserver.chromium.linux/builders/linux_chromium_...)

[Daniel Erat, 2017-03-02 14:38:12]

https://codereview.chromium.org/2731463002/diff/1/ash/common/system/chromeos/...
File ash/common/system/chromeos/power/power_status_view.cc (right):

https://codereview.chromium.org/2731463002/diff/1/ash/common/system/chromeos/...
ash/common/system/chromeos/power/power_status_view.cc:137: should_warn = true;
why do you want to warn in this case?

https://codereview.chromium.org/2731463002/diff/1/ash/common/system/chromeos/...
ash/common/system/chromeos/power/power_status_view.cc:148: LOG(WARNING) << "Time
to empty: " << time.InMilliseconds();
can't we already see the values that powerd sent to chrome here?

[bruthig, 2017-03-02 15:23:36]

https://codereview.chromium.org/2731463002/diff/1/ash/common/system/chromeos/...
File ash/common/system/chromeos/power/power_status_view.cc (right):

https://codereview.chromium.org/2731463002/diff/1/ash/common/system/chromeos/...
ash/common/system/chromeos/power/power_status_view.cc:137: should_warn = true;
On 2017/03/02 14:38:11, Daniel Erat wrote:
> why do you want to warn in this case?

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

https://codereview.chromium.org/2731463002/diff/1/ash/common/system/chromeos/...
ash/common/system/chromeos/power/power_status_view.cc:148: LOG(WARNING) << "Time
to empty: " << time.InMilliseconds();
On 2017/03/02 14:38:11, Daniel Erat wrote:
> can't we already see the values that powerd sent to chrome here?

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?

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

my hunch is that the problem is happening within ICU. base::TimeDurationFormat()
looks like it doesn't do any error-checking. you might want to consider adding
some logging there on error.

(really, the methods in time_formatting.h should probably return bool values and
take string16 out-params instead.)

https://codereview.chromium.org/2731463002/diff/1/ash/common/system/chromeos/...
File ash/common/system/chromeos/power/power_status_view.cc (right):

https://codereview.chromium.org/2731463002/diff/1/ash/common/system/chromeos/...
ash/common/system/chromeos/power/power_status_view.cc:133:
TimeDurationFormat(time, base::DURATION_WIDTH_NUMERIC));
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(...);

https://codereview.chromium.org/2731463002/diff/1/ash/common/system/chromeos/...
ash/common/system/chromeos/power/power_status_view.cc:137: should_warn = true;
On 2017/03/02 15:23:35, bruthig wrote:
> On 2017/03/02 14:38:11, Daniel Erat wrote:
> > why do you want to warn in this case?
> 
> I thought just showing the '%', like in comment #28 was also not WAI or at the
> very least suspicious.

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.

https://codereview.chromium.org/2731463002/diff/1/ash/common/system/chromeos/...
ash/common/system/chromeos/power/power_status_view.cc:141: DCHECK(false)
On 2017/03/02 05:08:06, bruthig wrote:
> This might be a little too aggressive given it is a valid else case above.

definitely too aggressive. :-)

[bruthig, 2017-03-22 18:29:49]

Closing as root issue appears to have been found -
https://bugs.chromium.org/p/chromium/issues/detail?id=677043#c64

[bruthig, 2017-03-22 18:29:59]

Description was changed from

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

BUG=677043
==========

to

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

BUG=677043
==========