Support optional performance measuring in SubresourceFilter.

The purpose of this CL is to provide a mechanism for enabling or
disabling SubresourceFilter's performance measuring on a per-page basis,
i.e. consistently for all DocumentSubresourceFilter instances of a page.

A decision on whether to measure performance (currently always true)
originates in ContentSubresourceFilterDriverFactory. It is distributed
to SubresourceFilterAgents first in the ActivateForProvisionalLoad
message, and eventually reaches individual DocumentSubresourceFilter
instances corresponding to each subframe document.

BUG=672519

Review-Url: https://codereview.chromium.org/2556433003
Cr-Commit-Position: refs/heads/master@{#437837}

chrome/browser/safe_browsing/safe_browsing_service_browsertest.cc

@@ -112,8 +112,8 @@ class MockSubresourceFilterDriver
 
   ~MockSubresourceFilterDriver() override = default;
 
-  MOCK_METHOD2(ActivateForProvisionalLoad,
-               void(subresource_filter::ActivationState, const GURL&));
+  MOCK_METHOD3(ActivateForProvisionalLoad,
+               void(subresource_filter::ActivationState, const GURL&, bool));
 
  private:
   DISALLOW_COPY_AND_ASSIGN(MockSubresourceFilterDriver);
@@ -958,7 +958,8 @@ IN_PROC_BROWSER_TEST_F(SafeBrowsingServiceTest,
 
   EXPECT_CALL(observer_, OnSafeBrowsingHit(IsUnsafeResourceFor(bad_url)))
       .Times(1);
-  EXPECT_CALL(*driver(), ActivateForProvisionalLoad(::testing::_, ::testing::_))
+  EXPECT_CALL(*driver(), ActivateForProvisionalLoad(::testing::_, ::testing::_,
+                                                    ::testing::_))
       .Times(0);
   ui_test_utils::NavigateToURL(browser(), bad_url);
   Mock::VerifyAndClearExpectations(&observer_);
@@ -967,7 +968,8 @@ IN_PROC_BROWSER_TEST_F(SafeBrowsingServiceTest,
   content::WaitForInterstitialAttach(main_contents);
   EXPECT_TRUE(ShowingInterstitialPage());
   testing::Mock::VerifyAndClearExpectations(driver());
-  EXPECT_CALL(*driver(), ActivateForProvisionalLoad(::testing::_, ::testing::_))
+  EXPECT_CALL(*driver(), ActivateForProvisionalLoad(::testing::_, ::testing::_,
+                                                    ::testing::_))
       .Times(1);
   InterstitialPage* interstitial_page = main_contents->GetInterstitialPage();
   ASSERT_TRUE(interstitial_page);
@@ -998,7 +1000,8 @@ IN_PROC_BROWSER_TEST_F(SafeBrowsingServiceTest, SocEngReportingBlacklistEmpty) {
 
   EXPECT_CALL(observer_, OnSafeBrowsingHit(IsUnsafeResourceFor(bad_url)))
       .Times(1);
-  EXPECT_CALL(*driver(), ActivateForProvisionalLoad(::testing::_, ::testing::_))
+  EXPECT_CALL(*driver(), ActivateForProvisionalLoad(::testing::_, ::testing::_,
+                                                    ::testing::_))
       .Times(0);
   ui_test_utils::NavigateToURL(browser(), bad_url);
   testing::Mock::VerifyAndClearExpectations(driver());
@@ -1007,7 +1010,8 @@ IN_PROC_BROWSER_TEST_F(SafeBrowsingServiceTest, SocEngReportingBlacklistEmpty) {
   content::WaitForInterstitialAttach(main_contents);
   EXPECT_TRUE(ShowingInterstitialPage());
   testing::Mock::VerifyAndClearExpectations(driver());
-  EXPECT_CALL(*driver(), ActivateForProvisionalLoad(::testing::_, ::testing::_))
+  EXPECT_CALL(*driver(), ActivateForProvisionalLoad(::testing::_, ::testing::_,
+                                                    ::testing::_))
       .Times(0);
   InterstitialPage* interstitial_page = main_contents->GetInterstitialPage();
   ASSERT_TRUE(interstitial_page);

components/subresource_filter/content/browser/content_subresource_filter_driver.cc

@@ -17,11 +17,13 @@ ContentSubresourceFilterDriver::~ContentSubresourceFilterDriver() {}
 
 void ContentSubresourceFilterDriver::ActivateForProvisionalLoad(
     ActivationState activation_state,
-    const GURL& url) {
+    const GURL& url,
+    bool measure_performance) {
   // Must use legacy IPC to ensure the activation message arrives in-order, i.e.
   // before the load is committed on the renderer side.
   render_frame_host_->Send(new SubresourceFilterMsg_ActivateForProvisionalLoad(
-      render_frame_host_->GetRoutingID(), activation_state, url));
+      render_frame_host_->GetRoutingID(), activation_state, url,
+      measure_performance));
 }
 
 }  // namespace subresource_filter

components/subresource_filter/content/browser/content_subresource_filter_driver.h

@@ -27,7 +27,8 @@ class ContentSubresourceFilterDriver {
   // Instructs the agent on the renderer to set up the subresource filter for
   // the currently ongoing provisional document load in the frame.
   virtual void ActivateForProvisionalLoad(ActivationState activation_state,
-                                          const GURL& url);
+                                          const GURL& url,
+                                          bool measure_performance);
 
  private:
   // The RenderFrameHost that this driver belongs to.

components/subresource_filter/content/browser/content_subresource_filter_driver_factory.cc

@@ -122,8 +122,14 @@ void ContentSubresourceFilterDriverFactory::ActivateForFrameHostIfNeeded(
     content::RenderFrameHost* render_frame_host,
     const GURL& url) {
   if (activation_state_ != ActivationState::DISABLED) {
-    DriverFromFrameHost(render_frame_host)
-        ->ActivateForProvisionalLoad(GetMaximumActivationState(), url);
+    // TODO(pkalinnikov): Introduce a variation parameter controlling how often
+    // the |measure_performance| bit is set. crbug/672519
+    constexpr bool measure_performance = true;
+
+    auto* driver = DriverFromFrameHost(render_frame_host);
+    DCHECK(driver);
+    driver->ActivateForProvisionalLoad(GetMaximumActivationState(), url,
+                                       measure_performance);
   }
 }
 

components/subresource_filter/content/browser/content_subresource_filter_driver_factory_unittest.cc

@@ -142,7 +142,8 @@ class MockSubresourceFilterDriver : public ContentSubresourceFilterDriver {
 
   ~MockSubresourceFilterDriver() override = default;
 
-  MOCK_METHOD2(ActivateForProvisionalLoad, void(ActivationState, const GURL&));
+  MOCK_METHOD3(ActivateForProvisionalLoad,
+               void(ActivationState, const GURL&, bool));
 
  private:
   DISALLOW_COPY_AND_ASSIGN(MockSubresourceFilterDriver);
@@ -233,7 +234,7 @@ class ContentSubresourceFilterDriverFactoryTest
       rfh_tester->SimulateRedirect(url);
     }
     EXPECT_CALL(*driver(),
-                ActivateForProvisionalLoad(::testing::_, ::testing::_))
+                ActivateForProvisionalLoad(::testing::_, ::testing::_, true))
         .Times(expected_activation);
     if (!content::IsBrowserSideNavigationEnabled()) {
       factory()->ReadyToCommitNavigationInternal(main_rfh(),
@@ -260,7 +261,7 @@ class ContentSubresourceFilterDriverFactoryTest
 
   void NavigateAndCommitSubframe(const GURL& url, bool expected_activation) {
     EXPECT_CALL(*subframe_driver(),
-                ActivateForProvisionalLoad(::testing::_, ::testing::_))
+                ActivateForProvisionalLoad(::testing::_, ::testing::_, true))
         .Times(expected_activation);
     EXPECT_CALL(*client(), ToggleNotificationVisibility(::testing::_)).Times(0);
 
@@ -307,8 +308,8 @@ class ContentSubresourceFilterDriverFactoryTest
 
     NavigateAndExpectActivation(blacklisted_urls, {GURL(kExampleUrl)},
                                 extected_pattern, expected_activation);
-    EXPECT_CALL(*driver(),
-                ActivateForProvisionalLoad(::testing::_, ::testing::_))
+    EXPECT_CALL(*driver(), ActivateForProvisionalLoad(
+                               ::testing::_, ::testing::_, ::testing::_))
         .Times(0);
     EXPECT_CALL(*client(), ToggleNotificationVisibility(::testing::_)).Times(1);
     content::RenderFrameHostTester::For(main_rfh())

components/subresource_filter/content/common/subresource_filter_messages.h

@@ -30,9 +30,10 @@ IPC_MESSAGE_CONTROL1(SubresourceFilterMsg_SetRulesetForProcess,
 // ongoing provisional document load in a frame. The message must arrive after
 // the provisional load starts, but before it is committed on the renderer side.
 // If no message arrives, the default behavior is ActivationState::DISABLED.
-IPC_MESSAGE_ROUTED2(SubresourceFilterMsg_ActivateForProvisionalLoad,
+IPC_MESSAGE_ROUTED3(SubresourceFilterMsg_ActivateForProvisionalLoad,
                     subresource_filter::ActivationState /* activation_state */,
-                    GURL /* url */);
+                    GURL /* url */,
+                    bool /* measure_performance */);
 
 // ----------------------------------------------------------------------------
 // Messages sent from the renderer to the browser.

components/subresource_filter/content/renderer/document_subresource_filter.cc

@@ -77,10 +77,12 @@ proto::ElementType ToElementType(
 
 DocumentSubresourceFilter::DocumentSubresourceFilter(
     ActivationState activation_state,
+    bool measure_performance,
     const scoped_refptr<const MemoryMappedRuleset>& ruleset,
     const std::vector<GURL>& ancestor_document_urls,
     const base::Closure& first_disallowed_load_callback)
     : activation_state_(activation_state),
+      measure_performance_(measure_performance),
       ruleset_(ruleset),
       ruleset_matcher_(ruleset_->data(), ruleset_->length()),
       first_disallowed_load_callback_(first_disallowed_load_callback) {
@@ -132,13 +134,14 @@ bool DocumentSubresourceFilter::allowLoad(
                resourceUrl.string().utf8());
 
   auto wall_duration_timer = ScopedTimers::StartIf(
-      ScopedThreadTimers::IsSupported(), [this](base::TimeDelta delta) {
+      measure_performance_ && ScopedThreadTimers::IsSupported(),
+      [this](base::TimeDelta delta) {
         statistics_.evaluation_total_wall_duration += delta;
         UMA_HISTOGRAM_MICRO_TIMES(
             "SubresourceFilter.SubresourceLoad.Evaluation.WallDuration", delta);
       });
-  auto cpu_duration_timer =
-      ScopedThreadTimers::Start([this](base::TimeDelta delta) {
+  auto cpu_duration_timer = ScopedThreadTimers::StartIf(
+      measure_performance_, [this](base::TimeDelta delta) {
         statistics_.evaluation_total_cpu_duration += delta;
         UMA_HISTOGRAM_MICRO_TIMES(
             "SubresourceFilter.SubresourceLoad.Evaluation.CPUDuration", delta);

components/subresource_filter/content/renderer/document_subresource_filter.h

@@ -58,6 +58,7 @@ class DocumentSubresourceFilter
   //     first disallowed subresource load.
   DocumentSubresourceFilter(
       ActivationState activation_state,
+      bool measure_performance,
       const scoped_refptr<const MemoryMappedRuleset>& ruleset,
       const std::vector<GURL>& ancestor_document_urls,
       const base::Closure& first_disallowed_load_callback);
@@ -70,7 +71,9 @@ class DocumentSubresourceFilter
                  blink::WebURLRequest::RequestContext) override;
 
  private:
-  ActivationState activation_state_;
+  const ActivationState activation_state_;
+  const bool measure_performance_;
+
   scoped_refptr<const MemoryMappedRuleset> ruleset_;
   IndexedRulesetMatcher ruleset_matcher_;
 

components/subresource_filter/content/renderer/document_subresource_filter_unittest.cc

@@ -79,7 +79,7 @@ TEST_F(DocumentSubresourceFilterTest, DryRun) {
       blink::WebURLRequest::RequestContextImage;
   TestCallbackReceiver first_disallowed_load_callback_receiver;
   DocumentSubresourceFilter filter(
-      ActivationState::DRYRUN, ruleset(), std::vector<GURL>(),
+      ActivationState::DRYRUN, true, ruleset(), std::vector<GURL>(),
       first_disallowed_load_callback_receiver.closure());
   EXPECT_TRUE(filter.allowLoad(GURL(kTestAlphaURL), request_context));
   EXPECT_TRUE(filter.allowLoad(GURL(kTestAlphaDataURI), request_context));
@@ -95,19 +95,32 @@ TEST_F(DocumentSubresourceFilterTest, DryRun) {
 }
 
 TEST_F(DocumentSubresourceFilterTest, Enabled) {
-  blink::WebURLRequest::RequestContext request_context =
-      blink::WebURLRequest::RequestContextImage;
-  DocumentSubresourceFilter filter(ActivationState::ENABLED, ruleset(),
-                                   std::vector<GURL>(), base::Closure());
-  EXPECT_FALSE(filter.allowLoad(GURL(kTestAlphaURL), request_context));
-  EXPECT_TRUE(filter.allowLoad(GURL(kTestAlphaDataURI), request_context));
-  EXPECT_TRUE(filter.allowLoad(GURL(kTestBetaURL), request_context));
-
-  const auto& statistics = filter.statistics();
-  EXPECT_EQ(3u, statistics.num_loads_total);
-  EXPECT_EQ(2u, statistics.num_loads_evaluated);
-  EXPECT_EQ(1u, statistics.num_loads_matching_rules);
-  EXPECT_EQ(1u, statistics.num_loads_disallowed);
+  auto test_impl = [this](bool measure_performance) {
+    blink::WebURLRequest::RequestContext request_context =
+        blink::WebURLRequest::RequestContextImage;
+    DocumentSubresourceFilter filter(ActivationState::ENABLED,
+                                     measure_performance, ruleset(),
+                                     std::vector<GURL>(), base::Closure());
+    EXPECT_FALSE(filter.allowLoad(GURL(kTestAlphaURL), request_context));
+    EXPECT_TRUE(filter.allowLoad(GURL(kTestAlphaDataURI), request_context));
+    EXPECT_TRUE(filter.allowLoad(GURL(kTestBetaURL), request_context));
+
+    const auto& statistics = filter.statistics();
+    EXPECT_EQ(3u, statistics.num_loads_total);
+    EXPECT_EQ(2u, statistics.num_loads_evaluated);
+    EXPECT_EQ(1u, statistics.num_loads_matching_rules);
+    EXPECT_EQ(1u, statistics.num_loads_disallowed);
+
+    if (!measure_performance) {
+      EXPECT_TRUE(statistics.evaluation_total_cpu_duration.is_zero());
+      EXPECT_TRUE(statistics.evaluation_total_wall_duration.is_zero());
+    }
+    // Otherwise, don't expect |total_duration| to be non-zero, although it
+    // practically is (when timer is supported).
+  };
+
+  test_impl(true /* measure_performance */);
+  test_impl(false /* measure_performance */);
 }
 
 TEST_F(DocumentSubresourceFilterTest,
@@ -116,7 +129,7 @@ TEST_F(DocumentSubresourceFilterTest,
       blink::WebURLRequest::RequestContextImage;
   TestCallbackReceiver first_disallowed_load_callback_receiver;
   DocumentSubresourceFilter filter(
-      ActivationState::ENABLED, ruleset(), std::vector<GURL>(),
+      ActivationState::ENABLED, true, ruleset(), std::vector<GURL>(),
       first_disallowed_load_callback_receiver.closure());
   EXPECT_TRUE(filter.allowLoad(GURL(kTestAlphaDataURI), request_context));
   EXPECT_EQ(0u, first_disallowed_load_callback_receiver.callback_count());

components/subresource_filter/content/renderer/subresource_filter_agent.cc

@@ -62,9 +62,11 @@ void SubresourceFilterAgent::
 
 void SubresourceFilterAgent::OnActivateForProvisionalLoad(
     ActivationState activation_state,
-    const GURL& url) {
+    const GURL& url,
+    bool measure_performance) {
   activation_state_for_provisional_load_ = activation_state;
   url_for_provisional_load_ = url;
+  measure_performance_ = measure_performance;
 }
 
 void SubresourceFilterAgent::RecordHistogramsOnLoadCommitted() {
@@ -96,9 +98,9 @@ void SubresourceFilterAgent::RecordHistogramsOnLoadFinished() {
       "SubresourceFilter.DocumentLoad.NumSubresourceLoads.Disallowed",
       statistics.num_loads_disallowed);
 
-  // If ThreadTicks is not supported, then no CPU time measurements have been
-  // collected. Don't report both CPU and wall duration to be consistent.
-  if (ScopedThreadTimers::IsSupported()) {
+  // If ThreadTicks is not supported or performance measuring is switched off,
+  // then no time measurements have been collected.
+  if (measure_performance_ && ScopedThreadTimers::IsSupported()) {
     UMA_HISTOGRAM_CUSTOM_MICRO_TIMES(
         "SubresourceFilter.DocumentLoad.SubresourceEvaluation."
         "TotalWallDuration",
@@ -131,6 +133,7 @@ void SubresourceFilterAgent::DidStartProvisionalLoad() {
       (!ds ||
        static_cast<GURL>(ds->request().url()) != url_for_provisional_load_)) {
     activation_state_for_provisional_load_ = ActivationState::DISABLED;
+    measure_performance_ = false;
   } else {
     url_for_provisional_load_ = GURL();
   }
@@ -149,10 +152,10 @@ void SubresourceFilterAgent::DidCommitProvisionalLoad(
                        SignalFirstSubresourceDisallowedForCommittedLoad,
                    AsWeakPtr()));
     std::unique_ptr<DocumentSubresourceFilter> filter(
-        new DocumentSubresourceFilter(activation_state_for_provisional_load_,
-                                      ruleset_dealer_->GetRuleset(),
-                                      ancestor_document_urls,
-                                      first_disallowed_load_callback));
+        new DocumentSubresourceFilter(
+            activation_state_for_provisional_load_, measure_performance_,
+            ruleset_dealer_->GetRuleset(), ancestor_document_urls,
+            first_disallowed_load_callback));
     filter_for_last_committed_load_ = filter->AsWeakPtr();
     SetSubresourceFilterForCommittedLoad(std::move(filter));
   }

components/subresource_filter/content/renderer/subresource_filter_agent.h

@@ -58,7 +58,8 @@ class SubresourceFilterAgent
 
  private:
   void OnActivateForProvisionalLoad(ActivationState activation_state,
-                                    const GURL& url);
+                                    const GURL& url,
+                                    bool measure_performance);
   void RecordHistogramsOnLoadCommitted();
   void RecordHistogramsOnLoadFinished();
 
@@ -75,6 +76,7 @@ class SubresourceFilterAgent
 
   ActivationState activation_state_for_provisional_load_;
   GURL url_for_provisional_load_;
+  bool measure_performance_ = false;
   base::WeakPtr<DocumentSubresourceFilter> filter_for_last_committed_load_;
 
   DISALLOW_COPY_AND_ASSIGN(SubresourceFilterAgent);

components/subresource_filter/content/renderer/subresource_filter_agent_unittest.cc

@@ -121,11 +121,12 @@ class SubresourceFilterAgentTest : public ::testing::Test {
         true /* is_new_navigation */, false /* is_same_page_navigation */);
   }
 
-  void StartLoadAndSetActivationState(ActivationState activation_state) {
+  void StartLoadAndSetActivationState(ActivationState activation_state,
+                                      bool measure_performance = false) {
     agent_as_rfo()->DidStartProvisionalLoad();
     EXPECT_TRUE(agent_as_rfo()->OnMessageReceived(
-        SubresourceFilterMsg_ActivateForProvisionalLoad(0, activation_state,
-                                                        GURL())));
+        SubresourceFilterMsg_ActivateForProvisionalLoad(
+            0, activation_state, GURL(), measure_performance)));
     agent_as_rfo()->DidCommitProvisionalLoad(
         true /* is_new_navigation */, false /* is_same_page_navigation */);
   }
@@ -252,7 +253,7 @@ TEST_F(SubresourceFilterAgentTest,
   agent_as_rfo()->DidStartProvisionalLoad();
   EXPECT_TRUE(agent_as_rfo()->OnMessageReceived(
       SubresourceFilterMsg_ActivateForProvisionalLoad(
-          0, ActivationState::ENABLED, GURL())));
+          0, ActivationState::ENABLED, GURL(), true)));
   agent_as_rfo()->DidStartProvisionalLoad();
   agent_as_rfo()->DidCommitProvisionalLoad(true /* is_new_navigation */,
                                            false /* is_same_page_navigation */);
@@ -388,9 +389,37 @@ TEST_F(SubresourceFilterAgentTest, Enabled_HistogramSamples) {
   EXPECT_THAT(histogram_tester.GetAllSamples(kSubresourcesDisallowed),
               ::testing::ElementsAre(base::Bucket(1, 1), base::Bucket(2, 1)));
 
-  histogram_tester.ExpectTotalCount(kEvaluationTotalWallDuration, 2);
+  // Performance measurement is switched off.
+  histogram_tester.ExpectTotalCount(kEvaluationTotalWallDuration, 0);
+  histogram_tester.ExpectTotalCount(kEvaluationTotalCPUDuration, 0);
+}
+
+TEST_F(SubresourceFilterAgentTest, Enabled_PerformanceMeasurementSamples) {
+  base::HistogramTester histogram_tester;
+  ASSERT_NO_FATAL_FAILURE(
+      SetTestRulesetToDisallowURLsWithPathSuffix(kTestFirstURLPathSuffix));
+  ExpectSubresourceFilterGetsInjected();
+  StartLoadAndSetActivationState(ActivationState::ENABLED, true);
+  ASSERT_TRUE(::testing::Mock::VerifyAndClearExpectations(agent()));
+
+  ExpectSignalAboutFirstSubresourceDisallowed();
+  ExpectLoadAllowed(kTestFirstURL, false);
+  ExpectLoadAllowed(kTestFirstURL, false);
+  ExpectLoadAllowed(kTestSecondURL, true);
+  FinishLoad();
+
+  ExpectSubresourceFilterGetsInjected();
+  StartLoadAndSetActivationState(ActivationState::ENABLED, true);
+  ASSERT_TRUE(::testing::Mock::VerifyAndClearExpectations(agent()));
+
+  ExpectSignalAboutFirstSubresourceDisallowed();
+  ExpectLoadAllowed(kTestFirstURL, false);
+  ExpectLoadAllowed(kTestSecondURL, true);
+  FinishLoad();
+
   const base::HistogramBase::Count total_count =
       base::ThreadTicks::IsSupported() ? 2 : 0;
+  histogram_tester.ExpectTotalCount(kEvaluationTotalWallDuration, total_count);
   histogram_tester.ExpectTotalCount(kEvaluationTotalCPUDuration, total_count);
 }
 
@@ -420,10 +449,9 @@ TEST_F(SubresourceFilterAgentTest, DryRun_HistogramSamples) {
   histogram_tester.ExpectUniqueSample(kSubresourcesMatchedRules, 2, 1);
   histogram_tester.ExpectUniqueSample(kSubresourcesDisallowed, 0, 1);
 
-  histogram_tester.ExpectTotalCount(kEvaluationTotalWallDuration, 1);
-  const base::HistogramBase::Count total_count =
-      base::ThreadTicks::IsSupported() ? 1 : 0;
-  histogram_tester.ExpectTotalCount(kEvaluationTotalCPUDuration, total_count);
+  // Performance measurement is switched off.
+  histogram_tester.ExpectTotalCount(kEvaluationTotalWallDuration, 0);
+  histogram_tester.ExpectTotalCount(kEvaluationTotalCPUDuration, 0);
 }
 
 }  // namespace subresource_filter