Add UKM audibility timer in AudioContextManagerImpl

This CL implements the audibility timer for multiple AudioContexts
in AudioContextManagerImpl. The "started" event triggers the
tracking and the "stopped" event triggers the calculation of
elapsed time followed by UKM data record.

Bug: 896944
Change-Id: Id1f635df4783247aca3656d07c02af907ffd72e4
Reviewed-on: https://chromium-review.googlesource.com/c/1289695
Commit-Queue: Mounir Lamouri <mlamouri@chromium.org>
Reviewed-by: Steven Holte <holte@chromium.org>
Reviewed-by: Mounir Lamouri <mlamouri@chromium.org>
Cr-Commit-Position: refs/heads/master@{#601446}

content/browser/media/webaudio/audio_context_manager_browsertest.cc

@@ -2,11 +2,14 @@
 // Use of this source code is governed by a BSD-style license that can be
 // found in the LICENSE file.
 
+#include "components/ukm/test_ukm_recorder.h"
 #include "content/public/browser/web_contents_observer.h"
 #include "content/public/test/browser_test_utils.h"
 #include "content/public/test/content_browser_test.h"
 #include "content/public/test/content_browser_test_utils.h"
 #include "content/shell/browser/shell.h"
+#include "net/dns/mock_host_resolver.h"
+#include "services/metrics/public/cpp/ukm_builders.h"
 
 namespace content {
 
@@ -51,7 +54,14 @@ class WaitForAudioContextSilent : WebContentsObserver {
 
 }  // namespace
 
-class AudioContextManagerTest : public ContentBrowserTest {};
+class AudioContextManagerTest : public ContentBrowserTest {
+ public:
+  void SetUpOnMainThread() override {
+    host_resolver()->AddRule("*", "127.0.0.1");
+    content::SetupCrossSiteRedirector(embedded_test_server());
+    ASSERT_TRUE(embedded_test_server()->Start());
+  }
+};
 
 IN_PROC_BROWSER_TEST_F(AudioContextManagerTest, AudioContextPlaybackRecorded) {
   NavigateToURL(shell(),
@@ -72,4 +82,57 @@ IN_PROC_BROWSER_TEST_F(AudioContextManagerTest, AudioContextPlaybackRecorded) {
   }
 }
 
+IN_PROC_BROWSER_TEST_F(AudioContextManagerTest, AudioContextPlaybackTimeUkm) {
+  ukm::TestAutoSetUkmRecorder test_ukm_recorder;
+  using Entry = ukm::builders::Media_WebAudio_AudioContext_AudibleTime;
+
+  GURL url = embedded_test_server()->GetURL(
+      "example.com", "/media/webaudio/playback-test.html");
+  NavigateToURL(shell(), url);
+
+  EXPECT_EQ(0u, test_ukm_recorder.GetEntriesByName(Entry::kEntryName).size());
+
+  // Play/pause something audible, it should lead to new Ukm entry.
+  {
+    ASSERT_TRUE(ExecuteScript(shell()->web_contents(), "gain.gain.value = 1;"));
+    WaitForAudioContextAudible wait_audible(shell()->web_contents());
+
+    ASSERT_TRUE(ExecuteScript(shell()->web_contents(), "gain.gain.value = 0;"));
+    WaitForAudioContextSilent wait_silent(shell()->web_contents());
+  }
+
+  EXPECT_EQ(1u, test_ukm_recorder.GetEntriesByName(Entry::kEntryName).size());
+
+  // Playback must have been recorded.
+  {
+    auto ukm_entries = test_ukm_recorder.GetEntriesByName(Entry::kEntryName);
+
+    ASSERT_EQ(1u, ukm_entries.size());
+    auto* entry = ukm_entries[0];
+
+    // The test doesn't check the URL because not the full Ukm stack is running
+    // in //content.
+
+    EXPECT_TRUE(
+        test_ukm_recorder.EntryHasMetric(entry, Entry::kAudibleTimeName));
+    EXPECT_GE(*test_ukm_recorder.GetEntryMetric(entry, Entry::kAudibleTimeName),
+              0);
+
+    EXPECT_TRUE(
+        test_ukm_recorder.EntryHasMetric(entry, Entry::kIsMainFrameName));
+    test_ukm_recorder.ExpectEntryMetric(entry, Entry::kIsMainFrameName, true);
+  }
+
+  // Play/pause again and check that there is a new entry.
+  {
+    ASSERT_TRUE(ExecuteScript(shell()->web_contents(), "gain.gain.value = 1;"));
+    WaitForAudioContextAudible wait_audible(shell()->web_contents());
+
+    ASSERT_TRUE(ExecuteScript(shell()->web_contents(), "gain.gain.value = 0;"));
+    WaitForAudioContextSilent wait_silent(shell()->web_contents());
+  }
+
+  EXPECT_EQ(2u, test_ukm_recorder.GetEntriesByName(Entry::kEntryName).size());
+}
+
 }  // namespace content

content/browser/media/webaudio/audio_context_manager_impl.cc

@@ -4,14 +4,30 @@
 
 #include "content/browser/media/webaudio/audio_context_manager_impl.h"
 
+#include "base/time/default_tick_clock.h"
 #include "content/browser/frame_host/render_frame_host_impl.h"
 #include "content/browser/web_contents/web_contents_impl.h"
 #include "content/public/browser/render_frame_host.h"
 #include "content/public/browser/web_contents.h"
 #include "mojo/public/cpp/bindings/strong_binding.h"
+#include "services/metrics/public/cpp/ukm_builders.h"
+#include "services/metrics/public/cpp/ukm_recorder.h"
 
 namespace content {
 
+namespace {
+
+// Returns the time in milleseconds following these rules:
+//  - if the time is below 10 seconds, return the raw value;
+//  - otherwise, return the value rounded to the closes second.
+int64_t GetBucketedTimeInMilliseconds(const base::TimeDelta& time) {
+  if (time.InMilliseconds() < 10 * base::Time::kMillisecondsPerSecond)
+    return time.InMilliseconds();
+  return time.InSeconds() * base::Time::kMillisecondsPerSecond;
+}
+
+}  // namespace
+
 void AudioContextManagerImpl::Create(
     RenderFrameHost* render_frame_host,
     blink::mojom::AudioContextManagerRequest request) {
@@ -27,24 +43,56 @@ AudioContextManagerImpl::AudioContextManagerImpl(
     blink::mojom::AudioContextManagerRequest request)
     : FrameServiceBase(render_frame_host, std::move(request)),
       render_frame_host_impl_(
-          static_cast<RenderFrameHostImpl*>(render_frame_host)) {
+          static_cast<RenderFrameHostImpl*>(render_frame_host)),
+      clock_(base::DefaultTickClock::GetInstance()) {
   DCHECK(render_frame_host);
 }
 
-AudioContextManagerImpl::~AudioContextManagerImpl() = default;
+AudioContextManagerImpl::~AudioContextManagerImpl() {
+  // Takes care pending "audible start" times.
+  base::TimeTicks now = clock_->NowTicks();
+  for (const auto& entry : pending_audible_durations_) {
+    if (!entry.second.is_null())
+      RecordAudibleTime(now - entry.second);
+  }
+  pending_audible_durations_.clear();
+}
 
 void AudioContextManagerImpl::AudioContextAudiblePlaybackStarted(
     int32_t audio_context_id) {
-  // Notify observers that audible audio started playing from a WebAudio
-  // AudioContext.
+  DCHECK(pending_audible_durations_[audio_context_id].is_null());
+
+  // Keeps track of the start audible time for this context.
+  pending_audible_durations_[audio_context_id] = clock_->NowTicks();
+
   render_frame_host_impl_->AudioContextPlaybackStarted(audio_context_id);
 }
 
 void AudioContextManagerImpl::AudioContextAudiblePlaybackStopped(
     int32_t audio_context_id) {
-  // Notify observers that audible audio stopped playing from a WebAudio
-  // AudioContext.
+  base::TimeTicks then = pending_audible_durations_[audio_context_id];
+  DCHECK(!then.is_null());
+
+  RecordAudibleTime(clock_->NowTicks() - then);
+
+  // Resets the context slot because the context is not audible.
+  pending_audible_durations_[audio_context_id] = base::TimeTicks();
+
   render_frame_host_impl_->AudioContextPlaybackStopped(audio_context_id);
 }
 
+void AudioContextManagerImpl::RecordAudibleTime(base::TimeDelta audible_time) {
+  DCHECK(!audible_time.is_zero());
+
+  ukm::UkmRecorder* ukm_recorder = ukm::UkmRecorder::Get();
+  DCHECK(ukm_recorder);
+
+  ukm::builders::Media_WebAudio_AudioContext_AudibleTime(
+      static_cast<WebContentsImpl*>(web_contents())
+          ->GetUkmSourceIdForLastCommittedSource())
+      .SetIsMainFrame(web_contents()->GetMainFrame() == render_frame_host_impl_)
+      .SetAudibleTime(GetBucketedTimeInMilliseconds(audible_time))
+      .Record(ukm_recorder);
+}
+
 }  // namespace content

content/browser/media/webaudio/audio_context_manager_impl.h

@@ -17,7 +17,10 @@ class RenderFrameHostImpl;
 
 // Implements the mojo interface between WebAudio and the browser so that
 // WebAudio can report when audible sounds from an AudioContext starts and
-// stops.
+// stops. A manager instance can be associated with multiple AudioContexts.
+//
+// We do not expect to see more than 3~4 AudioContexts per render frame, so
+// handling multiple contexts would not be a significant bottle neck.
 class CONTENT_EXPORT AudioContextManagerImpl final
     : public content::FrameServiceBase<blink::mojom::AudioContextManager> {
  public:
@@ -29,13 +32,28 @@ class CONTENT_EXPORT AudioContextManagerImpl final
   static void Create(RenderFrameHost* render_frame_host,
                      blink::mojom::AudioContextManagerRequest request);
 
-  // Called when AudioContext starts or stops playing audible audio.
+  // Notify observers that audible audio started/stopped playing from an
+  // AudioContext.
   void AudioContextAudiblePlaybackStarted(int32_t audio_context_id) final;
   void AudioContextAudiblePlaybackStopped(int32_t audio_context_id) final;
 
+  void set_clock_for_testing(base::TickClock* clock) { clock_ = clock; }
+
  private:
+  // Send measured audible duration to UKM database.
+  void RecordAudibleTime(base::TimeDelta);
+
   RenderFrameHostImpl* const render_frame_host_impl_;
 
+  // To track pending audible time. Stores ID of AudioContext (int32_t) and
+  // the start time of audible period (base::TimeTicks).
+  base::flat_map<int32_t, base::TimeTicks> pending_audible_durations_;
+
+  // Clock used to calculate time between start and stop event. Can be override
+  // by tests.
+  // It is not owned by the implementation.
+  const base::TickClock* clock_;
+
   DISALLOW_COPY_AND_ASSIGN(AudioContextManagerImpl);
 };
 

content/browser/media/webaudio/audio_context_manager_impl_unittest.cc

+// Copyright 2018 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/media/webaudio/audio_context_manager_impl.h"
+
+#include "base/test/simple_test_tick_clock.h"
+#include "components/ukm/test_ukm_recorder.h"
+#include "content/public/test/test_renderer_host.h"
+#include "services/metrics/public/cpp/ukm_builders.h"
+
+namespace content {
+
+class AudioContextManagerImplTest : public RenderViewHostTestHarness {
+ public:
+  using UkmEntry = ukm::builders::Media_WebAudio_AudioContext_AudibleTime;
+
+  void SetUp() override {
+    RenderViewHostTestHarness::SetUp();
+
+    clock_.SetNowTicks(base::TimeTicks::Now());
+
+    blink::mojom::AudioContextManagerPtr service_ptr;
+    audio_context_manager_ = new AudioContextManagerImpl(
+        main_rfh(), mojo::MakeRequest(&service_ptr));
+    audio_context_manager_->set_clock_for_testing(&clock_);
+  }
+
+  AudioContextManagerImpl* audio_context_manager() {
+    return audio_context_manager_;
+  }
+
+  const ukm::TestAutoSetUkmRecorder& test_ukm_recorder() const {
+    return test_ukm_recorder_;
+  }
+
+  base::SimpleTestTickClock& clock() { return clock_; }
+
+ private:
+  AudioContextManagerImpl* audio_context_manager_ = nullptr;
+  ukm::TestAutoSetUkmRecorder test_ukm_recorder_;
+  base::SimpleTestTickClock clock_;
+};
+
+TEST_F(AudioContextManagerImplTest, TimeBelow10SecondsIsRaw) {
+  // Entry for 42 milliseconds.
+  audio_context_manager()->AudioContextAudiblePlaybackStarted(0);
+  clock().Advance(base::TimeDelta::FromMilliseconds(42));
+  audio_context_manager()->AudioContextAudiblePlaybackStopped(0);
+
+  // Entry for 4242 milliseconds.
+  audio_context_manager()->AudioContextAudiblePlaybackStarted(0);
+  clock().Advance(base::TimeDelta::FromMilliseconds(4242));
+  audio_context_manager()->AudioContextAudiblePlaybackStopped(0);
+
+  // Entry for 9999 milliseconds.
+  audio_context_manager()->AudioContextAudiblePlaybackStarted(0);
+  clock().Advance(base::TimeDelta::FromMilliseconds(9999));
+  audio_context_manager()->AudioContextAudiblePlaybackStopped(0);
+
+  auto ukm_entries = test_ukm_recorder().GetEntriesByName(UkmEntry::kEntryName);
+  EXPECT_EQ(3u, ukm_entries.size());
+
+  const std::vector<int> expected = {42, 4242, 9999};
+  for (size_t i = 0; i < expected.size(); ++i) {
+    EXPECT_EQ(expected[i], *test_ukm_recorder().GetEntryMetric(
+                               ukm_entries[i], UkmEntry::kAudibleTimeName));
+  }
+}
+
+TEST_F(AudioContextManagerImplTest, TimeGreater10SecondsIsRoundedDown) {
+  // Entry for 42 seconds.
+  audio_context_manager()->AudioContextAudiblePlaybackStarted(0);
+  clock().Advance(base::TimeDelta::FromSeconds(42));
+  audio_context_manager()->AudioContextAudiblePlaybackStopped(0);
+
+  // Entry for 42.42 seconds.
+  audio_context_manager()->AudioContextAudiblePlaybackStarted(0);
+  clock().Advance(base::TimeDelta::FromSecondsD(42.42));
+  audio_context_manager()->AudioContextAudiblePlaybackStopped(0);
+
+  // Entry for 10.01 seconds.
+  audio_context_manager()->AudioContextAudiblePlaybackStarted(0);
+  clock().Advance(base::TimeDelta::FromSecondsD(10.01));
+  audio_context_manager()->AudioContextAudiblePlaybackStopped(0);
+
+  // Entry for 10.99 seconds.
+  audio_context_manager()->AudioContextAudiblePlaybackStarted(0);
+  clock().Advance(base::TimeDelta::FromSecondsD(10.99));
+  audio_context_manager()->AudioContextAudiblePlaybackStopped(0);
+
+  auto ukm_entries = test_ukm_recorder().GetEntriesByName(UkmEntry::kEntryName);
+  EXPECT_EQ(4u, ukm_entries.size());
+
+  const std::vector<int> expected = {42000, 42000, 10000, 10000};
+  for (size_t i = 0; i < expected.size(); ++i) {
+    EXPECT_EQ(expected[i], *test_ukm_recorder().GetEntryMetric(
+                               ukm_entries[i], UkmEntry::kAudibleTimeName));
+  }
+}
+
+}  // namespace content

content/test/BUILD.gn

@@ -1467,6 +1467,7 @@ test("content_unittests") {
     "../browser/media/session/media_session_impl_uma_unittest.cc",
     "../browser/media/session/media_session_impl_unittest.cc",
     "../browser/media/session/media_session_uma_helper_unittest.cc",
+    "../browser/media/webaudio/audio_context_manager_impl_unittest.cc",
     "../browser/memory/memory_coordinator_impl_unittest.cc",
     "../browser/memory/memory_monitor_android_unittest.cc",
     "../browser/memory/memory_monitor_win_unittest.cc",

tools/metrics/ukm/ukm.xml

@@ -1972,6 +1972,26 @@ be describing additional metrics about the same event.
   <metric name="AudioVideo.SRC"/>
 </event>
 
+<event name="Media.WebAudio.AudioContext.AudibleTime">
+  <owner>hongchan@chromium.org</owner>
+  <owner>rtoy@chromium.org</owner>
+  <owner>webaudio-dev@chromium.org</owner>
+  <summary>
+    Records the AudioContext audible time information.
+  </summary>
+  <metric name="AudibleTime">
+    <summary>
+      The number of seconds of audio that were audible during the entire
+      lifetime of the AudioContext.
+    </summary>
+  </metric>
+  <metric name="IsMainFrame">
+    <summary>
+      Indicates whether the event is fired from main frame.
+    </summary>
+  </metric>
+</event>
+
 <event name="Media.WebMediaPlayerState">
   <owner>dalecurtis@chromium.org</owner>
   <owner>media-dev@chromium.org</owner>