Record UKM for Renderer OOM

Records the time since last main frame navigation when a renderer OOM is
detected. On Android record only foreground OOMs.

BUG=736892

Change-Id: I71424844a7bfc9528a6ec865249b046e65275e07
Reviewed-on: https://chromium-review.googlesource.com/769234
Commit-Queue: Maria Khomenko <mariakhomenko@chromium.org>
Reviewed-by: Alexei Svitkine <asvitkine@chromium.org>
Reviewed-by: Charlie Harrison <csharrison@chromium.org>
Cr-Commit-Position: refs/heads/master@{#519498}

chrome/browser/metrics/oom/out_of_memory_reporter.cc

@@ -4,11 +4,16 @@
 
 #include "chrome/browser/metrics/oom/out_of_memory_reporter.h"
 
+#include <utility>
+
 #include "base/logging.h"
+#include "base/time/default_tick_clock.h"
 #include "content/public/browser/navigation_handle.h"
 #include "content/public/browser/render_frame_host.h"
 #include "content/public/browser/render_process_host.h"
 #include "content/public/browser/web_contents.h"
+#include "services/metrics/public/cpp/ukm_builders.h"
+#include "services/metrics/public/cpp/ukm_recorder.h"
 
 DEFINE_WEB_CONTENTS_USER_DATA_KEY(OutOfMemoryReporter);
 
@@ -23,7 +28,8 @@ void OutOfMemoryReporter::RemoveObserver(Observer* observer) {
 }
 
 OutOfMemoryReporter::OutOfMemoryReporter(content::WebContents* web_contents)
-    : content::WebContentsObserver(web_contents)
+    : content::WebContentsObserver(web_contents),
+      tick_clock_(std::make_unique<base::DefaultTickClock>())
 #if defined(OS_ANDROID)
       ,
       scoped_observer_(this) {
@@ -40,11 +46,23 @@ OutOfMemoryReporter::OutOfMemoryReporter(content::WebContents* web_contents)
 
 void OutOfMemoryReporter::OnForegroundOOMDetected(const GURL& url,
                                                   ukm::SourceId source_id) {
+  DCHECK(!last_navigation_timestamp_.is_null());
+  base::TimeDelta time_since_last_navigation =
+      tick_clock_->NowTicks() - last_navigation_timestamp_;
+  ukm::builders::Tab_RendererOOM(source_id)
+      .SetTimeSinceLastNavigation(time_since_last_navigation.InMilliseconds())
+      .Record(ukm::UkmRecorder::Get());
   for (auto& observer : observers_) {
     observer.OnForegroundOOMDetected(url, source_id);
   }
 }
 
+void OutOfMemoryReporter::SetTickClockForTest(
+    std::unique_ptr<base::TickClock> tick_clock) {
+  DCHECK(tick_clock_);
+  tick_clock_ = std::move(tick_clock);
+}
+
 void OutOfMemoryReporter::DidFinishNavigation(
     content::NavigationHandle* handle) {
   // Only care about main frame navigations that commit to another document.
@@ -53,6 +71,7 @@ void OutOfMemoryReporter::DidFinishNavigation(
     return;
   }
   last_committed_source_id_.reset();
+  last_navigation_timestamp_ = tick_clock_->NowTicks();
   crashed_render_process_id_ = content::ChildProcessHost::kInvalidUniqueID;
   if (handle->IsErrorPage())
     return;

chrome/browser/metrics/oom/out_of_memory_reporter.h

@@ -5,9 +5,13 @@
 #ifndef CHROME_BROWSER_METRICS_OOM_OUT_OF_MEMORY_REPORTER_H_
 #define CHROME_BROWSER_METRICS_OOM_OUT_OF_MEMORY_REPORTER_H_
 
+#include <memory>
+
 #include "base/macros.h"
 #include "base/observer_list.h"
 #include "base/scoped_observer.h"
+#include "base/time/tick_clock.h"
+#include "base/time/time.h"
 #include "build/build_config.h"
 #include "content/public/browser/web_contents_observer.h"
 #include "content/public/browser/web_contents_user_data.h"
@@ -19,6 +23,8 @@
 #include "components/crash/content/browser/crash_dump_manager_android.h"
 #endif
 
+class OutOfMemoryReporterTest;
+
 // This class listens for OOM notifications from WebContentsObserver and
 // breakpad::CrashDumpManager::Observer methods. It forwards foreground OOM
 // notifications to observers.
@@ -43,29 +49,36 @@ class OutOfMemoryReporter
 
  private:
   friend class content::WebContentsUserData<OutOfMemoryReporter>;
+  friend class OutOfMemoryReporterTest;
 
   OutOfMemoryReporter(content::WebContents* web_contents);
   void OnForegroundOOMDetected(const GURL& url, ukm::SourceId source_id);
 
+  // Used by tests to deterministically control time.
+  void SetTickClockForTest(std::unique_ptr<base::TickClock> tick_clock);
+
   // content::WebContentsObserver:
   void DidFinishNavigation(content::NavigationHandle* handle) override;
   void RenderProcessGone(base::TerminationStatus termination_status) override;
 
-// breakpad::CrashDumpManager::Observer:
 #if defined(OS_ANDROID)
+  // breakpad::CrashDumpManager::Observer:
   void OnCrashDumpProcessed(
       const breakpad::CrashDumpManager::CrashDumpDetails& details) override;
-
-  ScopedObserver<breakpad::CrashDumpManager,
-                 breakpad::CrashDumpManager::Observer>
-      scoped_observer_;
 #endif  // defined(OS_ANDROID)
 
   base::ObserverList<Observer> observers_;
 
   base::Optional<ukm::SourceId> last_committed_source_id_;
+  base::TimeTicks last_navigation_timestamp_;
+  std::unique_ptr<base::TickClock> tick_clock_;
   int crashed_render_process_id_ = content::ChildProcessHost::kInvalidUniqueID;
 
+#if defined(OS_ANDROID)
+  ScopedObserver<breakpad::CrashDumpManager,
+                 breakpad::CrashDumpManager::Observer>
+      scoped_observer_;
+#endif
   DISALLOW_COPY_AND_ASSIGN(OutOfMemoryReporter);
 };
 

chrome/browser/metrics/oom/out_of_memory_reporter_unittest.cc

@@ -17,13 +17,18 @@
 #include "base/process/kill.h"
 #include "base/run_loop.h"
 #include "base/task_scheduler/post_task.h"
+#include "base/test/simple_test_tick_clock.h"
 #include "build/build_config.h"
 #include "chrome/test/base/chrome_render_view_host_test_harness.h"
+#include "components/ukm/content/source_url_recorder.h"
+#include "components/ukm/test_ukm_recorder.h"
+#include "components/ukm/ukm_source.h"
 #include "content/public/browser/web_contents.h"
 #include "content/public/test/mock_render_process_host.h"
 #include "content/public/test/navigation_simulator.h"
 #include "content/public/test/test_renderer_host.h"
 #include "net/base/net_errors.h"
+#include "services/metrics/public/cpp/ukm_builders.h"
 #include "testing/gtest/include/gtest/gtest.h"
 #include "url/gurl.h"
 
@@ -89,7 +94,17 @@ class OutOfMemoryReporterTest : public ChromeRenderViewHostTestHarness,
                    process()->GetID()));
 #endif
     OutOfMemoryReporter::CreateForWebContents(web_contents());
-    OutOfMemoryReporter::FromWebContents(web_contents())->AddObserver(this);
+    OutOfMemoryReporter* reporter =
+        OutOfMemoryReporter::FromWebContents(web_contents());
+    reporter->AddObserver(this);
+    auto tick_clock = std::make_unique<base::SimpleTestTickClock>();
+    test_tick_clock_ = tick_clock.get();
+    reporter->SetTickClockForTest(std::move(tick_clock));
+    // Ensure clock is set to something that's not 0 to begin.
+    test_tick_clock_->Advance(base::TimeDelta::FromSeconds(1));
+
+    test_ukm_recorder_ = std::make_unique<ukm::TestAutoSetUkmRecorder>();
+    ukm::InitializeSourceUrlRecorderForWebContents(web_contents());
   }
 
   // OutOfMemoryReporter::Observer:
@@ -101,6 +116,7 @@ class OutOfMemoryReporterTest : public ChromeRenderViewHostTestHarness,
   }
 
   void SimulateOOM() {
+    test_tick_clock_->Advance(base::TimeDelta::FromSeconds(3));
 #if defined(OS_ANDROID)
     process()->SimulateRenderProcessExit(base::TERMINATION_STATUS_OOM_PROTECTED,
                                          0);
@@ -135,13 +151,26 @@ class OutOfMemoryReporterTest : public ChromeRenderViewHostTestHarness,
         &OutOfMemoryReporterTest::SimulateOOM, base::Unretained(this)));
   }
 
+  void CheckUkmMetricRecorded(const GURL& url, int64_t time_delta) {
+    const ukm::UkmSource* source =
+        *test_ukm_recorder_->GetSourcesForUrl(url.spec().c_str()).begin();
+    std::vector<int64_t> metrics = test_ukm_recorder_->GetMetricValues(
+        source->id(), ukm::builders::Tab_RendererOOM::kEntryName,
+        ukm::builders::Tab_RendererOOM::kTimeSinceLastNavigationName);
+    EXPECT_EQ(1u, metrics.size());
+    EXPECT_EQ(time_delta, metrics.at(0));
+  }
+
  protected:
   base::ShadowingAtExitManager at_exit_;
 
   base::Optional<GURL> last_oom_url_;
   base::OnceClosure oom_closure_;
+  std::unique_ptr<ukm::TestAutoSetUkmRecorder> test_ukm_recorder_;
 
  private:
+  base::SimpleTestTickClock* test_tick_clock_;
+
   DISALLOW_COPY_AND_ASSIGN(OutOfMemoryReporterTest);
 };
 
@@ -151,6 +180,7 @@ TEST_F(OutOfMemoryReporterTest, SimpleOOM) {
 
   SimulateOOMAndWait();
   EXPECT_EQ(url, last_oom_url_.value());
+  CheckUkmMetricRecorded(url, 3000);
 }
 
 TEST_F(OutOfMemoryReporterTest, NormalCrash_NoOOM) {
@@ -161,6 +191,9 @@ TEST_F(OutOfMemoryReporterTest, NormalCrash_NoOOM) {
                      base::Unretained(process()),
                      base::TERMINATION_STATUS_ABNORMAL_TERMINATION, 0));
   EXPECT_FALSE(last_oom_url_.has_value());
+  EXPECT_FALSE(
+      test_ukm_recorder_->HasEntry(*test_ukm_recorder_->GetSourceForUrl(url),
+                                   ukm::builders::Tab_RendererOOM::kEntryName));
 }
 
 TEST_F(OutOfMemoryReporterTest, SubframeNavigation_IsNotLogged) {
@@ -176,7 +209,8 @@ TEST_F(OutOfMemoryReporterTest, SubframeNavigation_IsNotLogged) {
   EXPECT_TRUE(subframe);
 
   SimulateOOMAndWait();
-  EXPECT_EQ(last_oom_url_.value(), url);
+  EXPECT_EQ(url, last_oom_url_.value());
+  CheckUkmMetricRecorded(url, 3000);
 }
 
 TEST_F(OutOfMemoryReporterTest, OOMOnPreviousPage) {
@@ -191,6 +225,7 @@ TEST_F(OutOfMemoryReporterTest, OOMOnPreviousPage) {
                                                            net::ERR_ABORTED);
   SimulateOOMAndWait();
   EXPECT_EQ(url2, last_oom_url_.value());
+  CheckUkmMetricRecorded(url2, 3000);
 
   last_oom_url_.reset();
   NavigateAndCommit(url1);
@@ -201,4 +236,7 @@ TEST_F(OutOfMemoryReporterTest, OOMOnPreviousPage) {
   // Don't report OOMs on error pages.
   SimulateOOMAndWait();
   EXPECT_FALSE(last_oom_url_.has_value());
+  // Only the first OOM is recorded.
+  EXPECT_EQ(1u, test_ukm_recorder_->entries_count());
+  CheckUkmMetricRecorded(url2, 3000);
 }

tools/metrics/ukm/ukm.xml

@@ -446,6 +446,34 @@ be describing additional metrics about the same event.
   </metric>
 </event>
 
+<event name="CPUUsageMeasurement">
+  <owner>matthalp@google.com</owner>
+  <owner>oysteine@chromium.org</owner>
+  <summary>
+    A CPU usage measurement that corresponds to a tick in a CPU usage
+    time-series The tick interval is set as a FieldTrial parameter, which can be
+    obtained by cross referencing the UKM entry with the FieldTrial it was
+    launched with. There is also some metadata stored to determine how faitful
+    the CPU usage measurement is (e.g. NumberOfCoresidentTabs).
+  </summary>
+  <metric name="CPUUsage">
+    <summary>
+      CPU usage measurement.
+    </summary>
+  </metric>
+  <metric name="NumberOfCoresidentTabs">
+    <summary>
+      Number of co-resident tabs in all of the render processes a tab is
+      associated with when the CPU usage measurement is taken.
+    </summary>
+  </metric>
+  <metric name="Tick">
+    <summary>
+      Tick CPU Usage measurement was taken at.
+    </summary>
+  </metric>
+</event>
+
 <event name="Event.ScrollUpdate.Touch">
   <owner>nzolghadr@chromium.org</owner>
   <summary>
@@ -1543,6 +1571,21 @@ be describing additional metrics about the same event.
   </metric>
 </event>
 
+<event name="Tab.RendererOOM">
+  <owner>ssid@chromium.org</owner>
+  <summary>
+    Metrics about renderer OOM, recorded for each detected OOM of renderer
+    process.
+  </summary>
+  <metric name="TimeSinceLastNavigation">
+    <summary>
+      Duration in MS from when the main frame navigation was triggered to when
+      the tab crashed with OOM. Recorded only on Windows, Android and Chrome OS.
+      We do not have a way to detect OOMs reliably on Linux and Mac.
+    </summary>
+  </metric>
+</event>
+
 <event name="Translate">
   <owner>hamelphi@chromium.org</owner>
   <summary>
@@ -1560,34 +1603,6 @@ be describing additional metrics about the same event.
   <metric name="TargetLanguage" semantic_type="ST_DEMOGRAPHIC_INFO"/>
 </event>
 
-<event name="CPUUsageMeasurement">
-  <owner>matthalp@google.com</owner>
-  <owner>oysteine@chromium.org</owner>
-  <summary>
-    A CPU usage measurement that corresponds to a tick in a CPU usage
-    time-series The tick interval is set as a FieldTrial parameter, which can be
-    obtained by cross referencing the UKM entry with the FieldTrial it was
-    launched with. There is also some metadata stored to determine how faitful
-    the CPU usage measurement is (e.g. NumberOfCoresidentTabs).
-  </summary>
-  <metric name="CPUUsage">
-    <summary>
-      CPU usage measurement.
-    </summary>
-  </metric>
-  <metric name="NumberOfCoresidentTabs">
-    <summary>
-      Number of co-resident tabs in all of the render processes a tab is
-      associated with when the CPU usage measurement is taken.
-    </summary>
-  </metric>
-  <metric name="Tick">
-    <summary>
-      Tick CPU Usage measurement was taken at.
-    </summary>
-  </metric>
-</event>
-
 <event name="TabManager.Background.FirstAlertFired">
   <owner>chrisha@chromium.org</owner>
   <owner>lpy@chromium.org</owner>