Battery impact UMA

content/browser/power_usage_monitor_impl.cc

+// Copyright 2014 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 "content/browser/power_usage_monitor_impl.h"
+
+#include "base/bind.h"
+#include "base/logging.h"
+#include "base/macros.h"
+#include "base/message_loop/message_loop.h"
+#include "base/metrics/histogram.h"
+#include "base/strings/stringprintf.h"
+#include "base/time/time.h"
+#include "content/common/battery_status_messages.h"
+#include "content/public/browser/browser_thread.h"
+#include "content/public/browser/notification_service.h"
+#include "content/public/browser/notification_source.h"
+#include "content/public/browser/notification_types.h"
+#include "content/public/browser/power_usage_monitor.h"
+#include "content/public/browser/render_process_host.h"
+
+namespace content {
+
+void StartPowerUsageMonitor() {
+  static PowerUsageMonitor* monitor_ = new PowerUsageMonitor();

[Daniel Erat, 2014/10/21 16:01:21]

why static?

do you need to annotate this as being leaky?

[jeremy, 2014/10/23 14:32:46]

I originally had this as a singleton but I wanted this to be testable.
I've marked this as leaky.

+  monitor_->Start();
+}
+
+PowerUsageMonitor::SystemInterface::SystemInterface()
+    : power_usage_monitor_(nullptr), weak_ptr_factory_(this) {

[Daniel Erat, 2014/10/21 16:01:21]

nit: one per line since they don't all fit on the same line as the signature

[jeremy, 2014/10/23 14:32:46]

Done.

+}
+
+PowerUsageMonitor::SystemInterface::~SystemInterface() {
+}
+
+void PowerUsageMonitor::SystemInterface::CancelPendingHistgramReports() {
+  weak_ptr_factory_.InvalidateWeakPtrs();
+}
+
+base::Time PowerUsageMonitor::SystemInterface::Now() {
+  return base::Time::Now();
+}
+
+void PowerUsageMonitor::SystemInterface::ScheduleHistogramReport(
+    base::TimeDelta delay) {
+  BrowserThread::PostDelayedTask(
+      BrowserThread::IO,
+      FROM_HERE,
+      base::Bind(&SystemInterface::ReportBatteryLevelHistogram,
+                 weak_ptr_factory_.GetWeakPtr(),
+                 delay),
+      delay);
+}
+
+void PowerUsageMonitor::SystemInterface::ReportBatteryLevelHistogram(
+    base::TimeDelta discharge_time) {
+  CHECK(BrowserThread::CurrentlyOn(BrowserThread::IO));
+  const std::string histogram_name = base::StringPrintf(
+      "Power.BatteryDischarge_%d", discharge_time.InMinutes());
+  base::HistogramBase* histogram = base::Histogram::FactoryGet(
+      histogram_name, 0, 100, 102, base::Histogram::kUmaTargetedHistogramFlag);
+  double discharge_amount = power_usage_monitor_->DischargeAmount();
+  histogram->Add(discharge_amount * 100);
+
+  power_usage_monitor_->BatteryLevelReported();
+}
+
+PowerUsageMonitor::PowerUsageMonitor()
+    : system_interface_(new SystemInterface()),
+      was_on_battery_power_(false),
+      initial_battery_level_(0),
+      current_battery_level_(0),
+      num_live_renderers_(0) {
+  system_interface_->SetPowerUsageMonitor(this);
+  // PowerUsageMonitor gets battery level information.
+  callback_ = base::Bind(&PowerUsageMonitor::OnBatteryStatusUpdate,
+                         base::Unretained(this));
+}
+
+PowerUsageMonitor::~PowerUsageMonitor() {
+  if (base::PowerMonitor::Get())

[Daniel Erat, 2014/10/21 16:01:21]

why are you checking this here but not in Start()? what's the lifetime of this
class relative to PowerMonitor?

[jeremy, 2014/10/23 14:32:46]

PowerMonitor is started on Chrome startup and hangs around until exit, as
mentioned above I originally implemented it as a singleton but then made changes
so I could instantiate it freely in unit tests.

When executed from a unit tests Start() is not called.

+    base::PowerMonitor::Get()->RemoveObserver(this);
+}
+
+void PowerUsageMonitor::Start() {
+  // Power Monitor used to get suspend/resume notifications.
+  base::PowerMonitor::Get()->AddObserver(this);

[Daniel Erat, 2014/10/21 16:01:21]

if a PowerUsageMonitor gets constructed and destroyed without Start() being
called, you have an unbalanced call to RemoveObserver(). please keep track of
whether the object was initialized so the calls are balanced.

[jeremy, 2014/10/23 14:32:45]

Done.

+
+  registrar_.Add(this,
+                 NOTIFICATION_RENDERER_PROCESS_CREATED,
+                 NotificationService::AllBrowserContextsAndSources());
+
+  registrar_.Add(this,
+                 NOTIFICATION_RENDERER_PROCESS_TERMINATED,
+                 NotificationService::AllBrowserContextsAndSources());
+  registrar_.Add(this,
+                 NOTIFICATION_RENDERER_PROCESS_CLOSED,
+                 NotificationService::AllBrowserContextsAndSources());
+
+  const base::TimeDelta delay = base::TimeDelta::FromSeconds(1);

[Daniel Erat, 2014/10/21 16:01:20]

what's the significance of this 1-second delay?

also, please just inline this in the PostDelayedTask() call below; it's not used
anywhere else.

[jeremy, 2014/10/23 14:32:46]

Delay removed, it's not needed.

+
+  BrowserThread::PostDelayedTask(
+      BrowserThread::IO,
+      FROM_HERE,
+      base::Bind(&PowerUsageMonitor::StartOnIOThread, base::Unretained(this)),
+      delay);
+}
+
+void PowerUsageMonitor::StartOnIOThread() {
+  CHECK(BrowserThread::CurrentlyOn(BrowserThread::IO));
+  subscription_ = BatteryStatusService::GetInstance()->AddCallback(callback_);

[Daniel Erat, 2014/10/21 16:01:21]

do you need to remove the callback in e.g. the d'tor?

[jeremy, 2014/10/23 14:32:46]

My understanding is that when we hit the destructor for subscription_ then the
callback will be removed?

+}
+
+void PowerUsageMonitor::DischargeStarted(double battery_level) {
+  // Called on IO thread.

[Avi (use Gerrit), 2014/10/21 15:12:49]

DCHECK it then.

[jeremy, 2014/10/23 14:32:46]

Added, I didn't know about TestBrowserThreadBundle :o/

+
+  // Cancel any in-progress ReportBatteryLevelHistogram() calls.
+  system_interface_->CancelPendingHistgramReports();
+
+  // Rate-limit power recording to once every 24 hours.
+  if (!first_histogram_report_timestamp_.is_null()) {
+    base::TimeDelta time_since_last_report =
+        system_interface_->Now() - first_histogram_report_timestamp_;
+    if (time_since_last_report.InHours() < 24)
+      return;
+
+    // More than 24 hours have passed, reset timestamp.
+    first_histogram_report_timestamp_ = base::Time();

[Daniel Erat, 2014/10/21 16:01:20]

why isn't this using system_interface_->Now()?

[jeremy, 2014/10/23 14:32:46]

This is on purpose, I want a NULL time here.

+  }
+
+  was_on_battery_power_ = true;
+  initial_battery_level_ = battery_level;
+  current_battery_level_ = battery_level;
+  start_discharge_time_ = system_interface_->Now();
+
+  const int kBatteryReportingIntervalMinutes[] = {5, 15, 30};
+
+  for (size_t i = 0; i < arraysize(kBatteryReportingIntervalMinutes); ++i) {
+    base::TimeDelta delay =
+        base::TimeDelta::FromMinutes(kBatteryReportingIntervalMinutes[i]);

[Avi (use Gerrit), 2014/10/21 15:12:49]

for (auto reporting_interval : kBatteryReportingIntervalMinutes) {
  base::TimeDelta delay = base::TimeDelta::FromMinutes(reporting_interval);
  // ...

[jeremy, 2014/10/23 14:32:46]

Done.

+    system_interface_->ScheduleHistogramReport(delay);

[Daniel Erat, 2014/10/21 16:01:21]

scheduling multiple future reports like this seems odd; it also means there are
a bunch of tasks floating around with invalidated weak pointers whenever the
power source changes. at the very least, couldn't this loop live in
SystemInterface instead of PowerUsageMonitor?

[jeremy, 2014/10/23 14:32:46]

When the power source changes or all renders die, all these tasks are cancelled.

The way I envisioned SystemInterface I'm trying to keep it as thin as possible
with all the logic here, on the other hand moving the loop in there seems fine -
wdyt?

+  }
+}
+
+void PowerUsageMonitor::WallPowerConnected(double battery_level) {
+  // Called on IO thread.

[Daniel Erat, 2014/10/21 16:01:21]

assert this instead of commenting it

[jeremy, 2014/10/23 14:32:46]

Done.

+
+  // Cancel any in-progress ReportBatteryLevelHistogram() calls.
+  system_interface_->CancelPendingHistgramReports();
+
+  if (!start_discharge_time_.is_null()) {
+    base::TimeDelta discharge_time =
+        system_interface_->Now() - start_discharge_time_;
+    double discharge_percent = initial_battery_level_ - battery_level;
+    double discharge_rate = discharge_percent / discharge_time.InMinutes();
+
+    if (discharge_time.InMinutes() > 30)
+      UMA_HISTOGRAM_PERCENTAGE("Power.BatteryDischargeRateWhenUnplugged",
+                               discharge_rate * 100.0);
+  }
+
+  was_on_battery_power_ = false;
+  initial_battery_level_ = 0;
+  current_battery_level_ = 0;
+  start_discharge_time_ = base::Time();
+}
+
+void PowerUsageMonitor::OnBatteryStatusUpdate(
+    const blink::WebBatteryStatus& status) {
+  // Called on IO thread.

[Daniel Erat, 2014/10/21 16:01:21]

assert this instead of commenting it

[jeremy, 2014/10/23 14:32:46]

Done.

+
+  bool now_on_battery_power = (status.charging == 0);
+  double battery_level = status.level;

[Daniel Erat, 2014/10/21 16:01:20]

what are the units of this level? WebBatteryStatus.h doesn't have any comments.
if it's not uniform across all systems, i don't see how these metrics can be
interpreted in a meaningful way.

[jeremy, 2014/10/23 14:32:46]

This is unitless, stated as a fraction between 0-1.0 - this object uses the
mechanics that back our implementation of http://www.w3.org/TR/battery-status/ .

This is not uniform across systems, I'm not sure how we could get something that
is uniform without hardware support (Even MSR power registers on Intel CPUs are
documented as not being comparable across systems).  If we filter the UMA
numbers for a specific machine model and OS we should be able to see power
trends e.g. the number will go up for MacBook Pros running a given OS version if
we regress power.

+
+  if (now_on_battery_power == was_on_battery_power_) {
+    if (now_on_battery_power)
+      current_battery_level_ = battery_level;
+    return;
+  } else if (now_on_battery_power) {  // Wall power disconnected.
+    if (num_live_renderers_ > 0)

[Daniel Erat, 2014/10/21 16:01:20]

what's the significance of this check? when are there 0 live renderers?

[jeremy, 2014/10/23 14:32:46]

Comment added.

+      DischargeStarted(battery_level);
+  } else {  // Wall power connected.
+    WallPowerConnected(battery_level);
+  }
+}
+
+void PowerUsageMonitor::BatteryLevelReported() {
+  if (first_histogram_report_timestamp_.is_null()) {
+    // Record timestamp of first histogram report.
+    first_histogram_report_timestamp_ = system_interface_->Now();
+  }
+}
+
+void PowerUsageMonitor::SetSystemInterfaceForTest(
+    scoped_ptr<SystemInterface> recorder) {
+  system_interface_ = recorder.Pass();
+  system_interface_->SetPowerUsageMonitor(this);
+}
+
+void PowerUsageMonitor::SetNumLiveRenderersForTest(int num_renderers) {
+  num_live_renderers_ = num_renderers;
+}
+
+void PowerUsageMonitor::OnSuspend() {

[Daniel Erat, 2014/10/21 16:01:20]

is this guaranteed to get run before the system suspends? iirc, it isn't. will
this cause problems?

[jeremy, 2014/10/23 14:32:46]

Thanks for bringing this up! I don't know, on Mac and Win at least it appears it
will always run but I'm not sure about other platforms.
The PostTask() to Cancel can conceivably race the delayed tasks regardless.
I've added a mitigation in ReportBatteryLevelHistogram() including an UMA that
will hopefully tell us how often we're hitting this.

+  BrowserThread::PostTask(
+      BrowserThread::IO,
+      FROM_HERE,
+      base::Bind(&PowerUsageMonitor::CancelPendingHistogramRecordingOnIOThread,
+                 base::Unretained(this)));
+}
+
+void PowerUsageMonitor::Observe(int type,
+                                const NotificationSource& source,
+                                const NotificationDetails& details) {
+  CHECK(BrowserThread::CurrentlyOn(BrowserThread::UI));
+
+  RenderProcessHost* rph = Source<RenderProcessHost>(source).ptr();
+
+  size_t previous_num_live_renderers = live_renderer_ids_.size();
+
+  if (type == NOTIFICATION_RENDERER_PROCESS_CREATED) {
+    live_renderer_ids_.insert(rph->GetID());
+  } else if (type == NOTIFICATION_RENDERER_PROCESS_TERMINATED ||
+             type == NOTIFICATION_RENDERER_PROCESS_CLOSED) {
+    live_renderer_ids_.erase(rph->GetID());
+  }
+
+  num_live_renderers_ = live_renderer_ids_.size();
+  if (num_live_renderers_ == 0 && previous_num_live_renderers != 0) {
+    // All render processes have died.
+    BrowserThread::PostTask(
+        BrowserThread::IO,
+        FROM_HERE,
+        base::Bind(
+            &PowerUsageMonitor::CancelPendingHistogramRecordingOnIOThread,
+            base::Unretained(this)));
+  }
+}
+
+void PowerUsageMonitor::CancelPendingHistogramRecordingOnIOThread() {
+  CHECK(BrowserThread::CurrentlyOn(BrowserThread::IO));
+
+  // Cancel any in-progress histogram reports and reporting of discharge UMA.
+  system_interface_->CancelPendingHistgramReports();
+  start_discharge_time_ = base::Time();
+}
+
+}  // namespace content