Add watch time metrics for HTML5 media playback.

media/blink/watch_time_reporter.cc

+// Copyright 2016 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 "media/blink/watch_time_reporter.h"
+
+#include "base/metrics/histogram_macros.h"
+#include "base/power_monitor/power_monitor.h"
+
+namespace media {
+
+// The minimum amount of media playback which can elapse before we'll report
+// watch time metrics for a playback.
+constexpr base::TimeDelta kMinimumElapsedWatchTime =
+    base::TimeDelta::FromSeconds(7);
+
+// The minimum width and height of videos to report watch time metrics for.
+constexpr gfx::Size kMinimumVideoSize = gfx::Size(200, 200);
+
+// Histogram names exported for testing.
+const char WatchTimeReporter::kHistogramAudioVideoAll[] =
+    "Media.WatchTime.AudioVideo.All";
+const char WatchTimeReporter::kHistogramAudioVideoMse[] =
+    "Media.WatchTime.AudioVideo.MSE";
+const char WatchTimeReporter::kHistogramAudioVideoEme[] =
+    "Media.WatchTime.AudioVideo.EME";
+const char WatchTimeReporter::kHistogramAudioVideoSrc[] =
+    "Media.WatchTime.AudioVideo.SRC";
+const char WatchTimeReporter::kHistogramAudioVideoBattery[] =
+    "Media.WatchTime.AudioVideo.Battery";
+const char WatchTimeReporter::kHistogramAudioVideoAc[] =
+    "Media.WatchTime.AudioVideo.AC";
+
+WatchTimeReporter::WatchTimeReporter(bool has_audio,
+                                     bool has_video,
+                                     bool is_mse,
+                                     bool is_encrypted,
+                                     const gfx::Size& initial_video_size,
+                                     const GetMediaTimeCB& get_media_time_cb)
+    : has_audio_(has_audio),
+      has_video_(has_video),
+      is_mse_(is_mse),
+      is_encrypted_(is_encrypted),
+      initial_video_size_(initial_video_size),
+      get_media_time_cb_(get_media_time_cb) {
+  DCHECK(!get_media_time_cb_.is_null());
+  DCHECK(has_audio_ || has_video_);
+  if (has_video_)
+    DCHECK(!initial_video_size_.IsEmpty());
+  base::PowerMonitor::Get()->AddObserver(this);
+}
+
+WatchTimeReporter::~WatchTimeReporter() {
+  // If the timer is still running, finalize immediately, this is our last
+  // chance to capture metrics.
+  if (reporting_timer_.IsRunning())
+    FinalizeWatchTime(FinalizeTime::IMMEDIATELY);
+
+  base::PowerMonitor::Get()->RemoveObserver(this);
+}
+
+void WatchTimeReporter::OnPlaying() {
+  is_playing_ = true;
+  StartReportingTimer(get_media_time_cb_.Run());
+}
+
+void WatchTimeReporter::OnPaused() {
+  is_playing_ = false;
+  FinalizeWatchTime(FinalizeTime::ON_NEXT_UPDATE);
+}
+
+void WatchTimeReporter::OnSeeking(base::TimeDelta seek_timestamp) {
+  // Seek is a special case that does not have hysteresis, when this is called
+  // the seek is imminent, so finalize the previous playback immediately.
+  if (reporting_timer_.IsRunning()) {
+    // Don't trample an existing end timestamp.
+    if (end_timestamp_ != kNoTimestamp)
+      end_timestamp_ = get_media_time_cb_.Run();
+    UpdateWatchTime();
+  }
+
+  // Start the reporting timer at the target seek time; no watch time will be
+  // reported until |kMinimumElapsedWatchTime| after the seek time.
+  StartReportingTimer(seek_timestamp);
+}
+
+void WatchTimeReporter::OnVolumeChange(double volume) {
+  const double old_volume = volume_;
+  volume_ = volume;
+
+  // We're only interesting in transitions in and out of the muted state.
+  if (!old_volume && volume)
+    StartReportingTimer(get_media_time_cb_.Run());
+  else if (old_volume && !volume_)
+    FinalizeWatchTime(FinalizeTime::ON_NEXT_UPDATE);
+}
+
+void WatchTimeReporter::OnShown() {
+  is_visible_ = true;
+  StartReportingTimer(get_media_time_cb_.Run());
+}
+
+void WatchTimeReporter::OnHidden() {
+  is_visible_ = false;
+  FinalizeWatchTime(FinalizeTime::ON_NEXT_UPDATE);
+}
+
+void WatchTimeReporter::OnPowerStateChange(bool on_battery_power) {
+  if (!reporting_timer_.IsRunning())
+    return;
+
+  // Defer changing |is_on_battery_power_| until the next watch time report to
+  // avoid momentary power changes from affecting the results.
+  if (is_on_battery_power_ != on_battery_power) {
+    end_timestamp_for_power_ = get_media_time_cb_.Run();
+
+    // Restart the reporting timer so the full hysteresis is afforded.
+    reporting_timer_.Start(FROM_HERE, reporting_interval_, this,
+                           &WatchTimeReporter::UpdateWatchTime);
+    return;
+  }
+
+  end_timestamp_for_power_ = kNoTimestamp;
+}
+
+bool WatchTimeReporter::ShouldReportWatchTime() {
+  // Only report watch time for media of sufficient size with both audio and
+  // video tracks present.
+  return has_audio_ && has_video_ &&
+         initial_video_size_.height() >= kMinimumVideoSize.height() &&
+         initial_video_size_.width() >= kMinimumVideoSize.width();
+}
+
+void WatchTimeReporter::StartReportingTimer(base::TimeDelta start_timestamp) {
+  // Don't start the timer if any of our state indicates we shouldn't; this
+  // check is important since the various event handlers do not have to care
+  // about the state of other events.
+  if (!ShouldReportWatchTime() || !is_playing_ || !volume_ || !is_visible_) {
+    // If we reach this point the timer should already have been stopped or
+    // there is a pending finalize in flight.
+    DCHECK(!reporting_timer_.IsRunning() || end_timestamp_ != kNoTimestamp);
+    return;
+  }
+
+  // If we haven't finalized the last watch time metrics yet, count this
+  // playback as a continuation of the previous metrics.
+  if (end_timestamp_ != kNoTimestamp) {
+    DCHECK(reporting_timer_.IsRunning());
+    end_timestamp_ = kNoTimestamp;
+    return;
+  }
+
+  // Don't restart the timer if it's already running.
+  if (reporting_timer_.IsRunning())
+    return;
+
+  last_media_timestamp_ = end_timestamp_for_power_ = kNoTimestamp;
+  is_on_battery_power_ = base::PowerMonitor::Get()->IsOnBatteryPower();
+  start_timestamp_ = start_timestamp_for_power_ = start_timestamp;
+  reporting_timer_.Start(FROM_HERE, reporting_interval_, this,
+                         &WatchTimeReporter::UpdateWatchTime);
+}
+
+void WatchTimeReporter::FinalizeWatchTime(FinalizeTime finalize_time) {
+  // Don't finalize if the timer is already stopped.
+  if (!reporting_timer_.IsRunning())
+    return;
+
+  // Don't trample an existing finalize; the first takes precedence.
+  if (end_timestamp_ == kNoTimestamp)
+    end_timestamp_ = get_media_time_cb_.Run();
+
+  if (finalize_time == FinalizeTime::IMMEDIATELY) {
+    UpdateWatchTime();
+    return;
+  }
+
+  // Always restart the timer when finalizing, so that we allow for the full
+  // length of |kReportingInterval| to elapse for hysteresis purposes.
+  DCHECK_EQ(finalize_time, FinalizeTime::ON_NEXT_UPDATE);
+  reporting_timer_.Start(FROM_HERE, reporting_interval_, this,
+                         &WatchTimeReporter::UpdateWatchTime);
+}
+
+void WatchTimeReporter::UpdateWatchTime() {
+  DCHECK(ShouldReportWatchTime());
+
+  const bool is_finalizing = end_timestamp_ != kNoTimestamp;
+  const bool is_power_change_pending = end_timestamp_for_power_ != kNoTimestamp;
+
+  // If we're finalizing the histogram, use the media time value at the time of
+  // finalization.
+  const base::TimeDelta current_timestamp =
+      is_finalizing ? end_timestamp_ : get_media_time_cb_.Run();
+  const base::TimeDelta elapsed = current_timestamp - start_timestamp_;
+
+  // Only report watch time after some minimum amount has elapsed. Don't update
+  // watch time if media time hasn't changed since the last run; this may occur
+  // if a seek is taking some time to complete or the playback is stalled for
+  // some reason.
+  if (elapsed >= kMinimumElapsedWatchTime &&
+      last_media_timestamp_ != current_timestamp) {
+    last_media_timestamp_ = current_timestamp;
+
+    UMA_HISTOGRAM_LONG_TIMES(kHistogramAudioVideoAll, elapsed);

[sandersd (OOO until July 31), 2016/08/04 23:06:26]

It looks like this will report repeatedly, with a growing 'elapsed'. What does
the actual data in the reported UMA looks like? Is there code somewhere that is
coalescing these?

[DaleCurtis, 2016/08/04 23:34:21]

No coalescing, we end up with categories like the following:

50% watched 1hr,
30% watched 2hr,
20% watched 3hr,
10% watched 4hr,

We're only able to make relative statements about the data using this model.
I.e. we can only say that some percentage watched at least x hours. We won't get
an absolute watch time number with this approach. To get that we have to move
this to MediaInternals and record the data in the browser process like we do
with pipeline status.

I thought this would be fine, but I need to check with the PM side to see
exactly what type of data they'd like to see here.

[sandersd (OOO until July 31), 2016/08/04 23:57:18]

holte@: It's not obvious that we can get the above information from
UMA_HISTOGRAM_LONG_TIMES(), because we can't be sure that we can compare the
differently-sized buckets without a lot of post-processing. If we want to record
this kind of data, are there UMA design patterns that are known to work?

+    if (is_mse_)
+      UMA_HISTOGRAM_LONG_TIMES(kHistogramAudioVideoMse, elapsed);
+    else
+      UMA_HISTOGRAM_LONG_TIMES(kHistogramAudioVideoSrc, elapsed);
+    if (is_encrypted_)
+      UMA_HISTOGRAM_LONG_TIMES(kHistogramAudioVideoEme, elapsed);
+
+    // Record watch time using the last known value for |is_on_battery_power_|;
+    // if there's a |pending_power_change_| use that to accurately finalize the
+    // last bits of time in the previous bucket.
+    const base::TimeDelta elapsed_power =
+        (is_power_change_pending ? end_timestamp_for_power_
+                                 : current_timestamp) -
+        start_timestamp_for_power_;
+
+    // Again, only update watch time if enough time has elapsed; we need to
+    // recheck the elapsed time here since the power source can change anytime.
+    if (elapsed_power >= kMinimumElapsedWatchTime) {
+      if (is_on_battery_power_) {
+        UMA_HISTOGRAM_LONG_TIMES(kHistogramAudioVideoBattery, elapsed_power);
+      } else {
+        UMA_HISTOGRAM_LONG_TIMES(kHistogramAudioVideoAc, elapsed_power);
+      }
+    }
+  }
+
+  if (is_power_change_pending) {
+    // Invert battery power status here instead of using the value returned by
+    // the PowerObserver since there may be a pending OnPowerStateChange().
+    is_on_battery_power_ = !is_on_battery_power_;
+
+    start_timestamp_for_power_ = end_timestamp_for_power_;
+    end_timestamp_for_power_ = kNoTimestamp;
+  }
+
+  // Stop the timer if this is supposed to be our last tick.
+  if (is_finalizing) {
+    end_timestamp_ = kNoTimestamp;
+    reporting_timer_.Stop();
+  }
+}
+
+}  // namespace media