Reland "Add timing histograms and trace events to sql database ops"

This reverts commit da20bfc1dd.

Reason for revert: Fixed races in Compose tests, and changed other
instances of ScopedMockElapsedTimersForTest being initialized late
to instead be bound to the test class' scope.

Original change's description:
> Revert "Add timing histograms and trace events to sql database ops"
>
> This reverts commit 0fae0abfd2.
>
> Reason for revert: Race access to base::ScopedMockElapsedTimersForTest
> https://ci.chromium.org/ui/p/chromium/builders/ci/Linux%20TSan%20Tests/92754/overview
>
> Original change's description:
> > Add timing histograms and trace events to sql database ops
> >
> > This CL adds a few histograms:
> > - Sql.Statement.StepTime.{DatabaseTag}: time spent in each
> >   single `Step()` call
> > - Sql.Statement.ExecutionTime.{DatabaseTag}: total time
> >   spent in `Step()` within the lifetime of each statement
> > - Sql.Database.Success.OpenInternalTime.{DatabaseTag}: time
> >   spent in `Database::OpenInternal()`
> > - Sql.Database.Success.SqliteOpenTime.{DatabaseTag}: time taken
> >   by the `sqlite3_open_v2()` call within `Database`
> >
> > It also adds a few trace events:
> > - "Database::OpenInternal sqlite3_open_v2" directly around
> >   the `sqlite3_open_v2()` call
> > - "Database::Statement", spanning the time spent stepping for
> >   each statement. These are emitted in new tracks named
> >   "Database: {Tag}" parented on the track of the thread calling
> >   `Step()`. These events also contain the associated prepared
> >   statements (without bound parameters).
> >
> > Bug: 40949392
> > Change-Id: I2de4a0359e68961f58d5e7f0434b5c56292626d1
> > Reviewed-on: https://chromium-review.googlesource.com/c/chromium/src/+/6019886
> > Reviewed-by: Greg Thompson <grt@chromium.org>
> > Commit-Queue: Anthony Vallée-Dubois <anthonyvd@chromium.org>
> > Reviewed-by: Etienne Bergeron <etienneb@chromium.org>
> > Reviewed-by: Ayu Ishii <ayui@chromium.org>
> > Cr-Commit-Position: refs/heads/main@{#1385191}
>
> Bug: 40949392
> Change-Id: Ie5af7e4ef64d26e868d40cda803ed376b4c84763
> No-Presubmit: true
> No-Tree-Checks: true
> No-Try: true
> Reviewed-on: https://chromium-review.googlesource.com/c/chromium/src/+/6034678
> Bot-Commit: Rubber Stamper <rubber-stamper@appspot.gserviceaccount.com>
> Owners-Override: Mikihito Matsuura <mikt@google.com>
> Auto-Submit: Mikihito Matsuura <mikt@google.com>
> Commit-Queue: Mikihito Matsuura <mikt@google.com>
> Cr-Commit-Position: refs/heads/main@{#1385457}

Bug: 40949392
Change-Id: Id8218c6fc7c6d2a9aed187e94df26e6749003933
Reviewed-on: https://chromium-review.googlesource.com/c/chromium/src/+/6039012
Commit-Queue: Anthony Vallée-Dubois <anthonyvd@chromium.org>
Reviewed-by: Greg Thompson <grt@chromium.org>
Reviewed-by: Kouhei Ueno <kouhei@chromium.org>
Reviewed-by: Ayu Ishii <ayui@chromium.org>
Cr-Commit-Position: refs/heads/main@{#1386862}

chrome/browser/compose/chrome_compose_client_unittest.cc

@@ -244,8 +244,6 @@ class ChromeComposeClientTest : public BrowserWithTestWindowTest {
               metadata->SetAnyMetadataForTesting(compose_hint_metadata);
               return optimization_guide::OptimizationGuideDecision::kTrue;
             });
-
-    test_timer_ = std::make_unique<base::ScopedMockElapsedTimersForTest>();
   }
 
   void TearDown() override {
@@ -467,6 +465,7 @@ class ChromeComposeClientTest : public BrowserWithTestWindowTest {
   MockHatsService* mock_hats_service() { return mock_hats_service_; }
 
  private:
+  base::ScopedMockElapsedTimersForTest test_timer_;
   raw_ptr<ChromeComposeClient> client_;
   testing::NiceMock<optimization_guide::MockOptimizationGuideModelExecutor>
       model_executor_;
@@ -490,7 +489,6 @@ class ChromeComposeClientTest : public BrowserWithTestWindowTest {
       client_page_handler_;
   mojo::Remote<compose::mojom::ComposeSessionUntrustedPageHandler>
       page_handler_;
-  std::unique_ptr<base::ScopedMockElapsedTimersForTest> test_timer_;
   ComposeEnabling::ScopedOverride scoped_compose_enabled_;
   raw_ptr<MockHatsService> mock_hats_service_;
 };

chrome/browser/navigation_predictor/anchor_element_preloader_browsertest.cc

@@ -77,7 +77,6 @@ class AnchorElementPreloaderBrowserTest
     ukm_entry_builder_ =
         std::make_unique<content::test::PreloadingAttemptUkmEntryBuilder>(
             chrome_preloading_predictor::kPointerDownOnAnchor);
-    test_timer_ = std::make_unique<base::ScopedMockElapsedTimersForTest>();
     ASSERT_TRUE(loading_predictor);
     loading_predictor->preconnect_manager()->SetObserverForTesting(this);
   }
@@ -153,13 +152,13 @@ class AnchorElementPreloaderBrowserTest
   content::test::PreloadingConfigOverride preloading_config_override_;
 
  private:
+  base::ScopedMockElapsedTimersForTest test_timer_;
   std::unique_ptr<net::EmbeddedTestServer> https_server_;
   std::unique_ptr<base::RunLoop> run_loop_;
   std::unique_ptr<ukm::TestAutoSetUkmRecorder> test_ukm_recorder_;
   std::unique_ptr<base::HistogramTester> histogram_tester_;
   std::unique_ptr<content::test::PreloadingAttemptUkmEntryBuilder>
       ukm_entry_builder_;
-  std::unique_ptr<base::ScopedMockElapsedTimersForTest> test_timer_;
 };
 
 IN_PROC_BROWSER_TEST_F(AnchorElementPreloaderBrowserTest, OneAnchor) {

chrome/browser/predictors/autocomplete_action_predictor_unittest.cc

@@ -134,7 +134,6 @@ class AutocompleteActionPredictorTest : public testing::Test {
         std::make_unique<content::test::PreloadingPredictionUkmEntryBuilder>(
             chrome_preloading_predictor::kOmniboxDirectURLInput);
     test_ukm_recorder_ = std::make_unique<ukm::TestAutoSetUkmRecorder>();
-    test_timer_ = std::make_unique<base::ScopedMockElapsedTimersForTest>();
 
     predictor_ = std::make_unique<AutocompleteActionPredictor>(profile_.get());
     profile_->BlockUntilHistoryProcessesPendingRequests();
@@ -335,7 +334,7 @@ class AutocompleteActionPredictorTest : public testing::Test {
   std::unique_ptr<WebContents> web_contents_;
   content::RenderViewHostTestEnabler rvh_test_enabler_;
   std::unique_ptr<ukm::TestAutoSetUkmRecorder> test_ukm_recorder_;
-  std::unique_ptr<base::ScopedMockElapsedTimersForTest> test_timer_;
+  base::ScopedMockElapsedTimersForTest test_timer_;
 };
 
 

chrome/browser/preloading/prefetch/no_state_prefetch/prerender_nostate_prefetch_browsertest.cc

@@ -330,7 +330,6 @@ class NoStatePrefetchBrowserTest
     link_rel_attempt_entry_builder_ =
         std::make_unique<content::test::PreloadingAttemptUkmEntryBuilder>(
             content::preloading_predictor::kLinkRel);
-    test_timer_ = std::make_unique<base::ScopedMockElapsedTimersForTest>();
     host_resolver()->AddRule("*", "127.0.0.1");
   }
 
@@ -483,12 +482,12 @@ class NoStatePrefetchBrowserTest
   base::SimpleTestTickClock clock_;
 
  private:
+  base::ScopedMockElapsedTimersForTest test_timer_;
   // Disable sampling of UKM preloading logs.
   content::test::PreloadingConfigOverride preloading_config_override_;
   std::unique_ptr<ukm::TestAutoSetUkmRecorder> test_ukm_recorder_;
   std::unique_ptr<content::test::PreloadingAttemptUkmEntryBuilder>
       link_rel_attempt_entry_builder_;
-  std::unique_ptr<base::ScopedMockElapsedTimersForTest> test_timer_;
   base::test::ScopedFeatureList feature_list_;
 };
 

chrome/browser/preloading/prefetch/prefetch_browsertest.cc

@@ -53,7 +53,6 @@ class PrefetchBrowserTest : public PlatformBrowserTest {
     attempt_entry_builder_ =
         std::make_unique<content::test::PreloadingAttemptUkmEntryBuilder>(
             PredictorToExpectInUkm());
-    test_timer_ = std::make_unique<base::ScopedMockElapsedTimersForTest>();
   }
 
   void TearDownOnMainThread() override {
@@ -89,6 +88,7 @@ class PrefetchBrowserTest : public PlatformBrowserTest {
   }
 
  private:
+  base::ScopedMockElapsedTimersForTest test_timer_;
   net::test_server::EmbeddedTestServer ssl_server_{
       net::test_server::EmbeddedTestServer::TYPE_HTTPS};
   base::test::ScopedFeatureList feature_list_;
@@ -96,7 +96,6 @@ class PrefetchBrowserTest : public PlatformBrowserTest {
   std::unique_ptr<ukm::TestAutoSetUkmRecorder> test_ukm_recorder_;
   std::unique_ptr<content::test::PreloadingAttemptUkmEntryBuilder>
       attempt_entry_builder_;
-  std::unique_ptr<base::ScopedMockElapsedTimersForTest> test_timer_;
 };
 
 #if BUILDFLAG(IS_ANDROID)

chrome/browser/preloading/prefetch/search_prefetch/search_prefetch_service_browsertest.cc

@@ -360,8 +360,6 @@ class SearchPrefetchHoldbackBrowserTest : public SearchPrefetchBaseBrowserTest {
     attempt_entry_builder_ =
         std::make_unique<content::test::PreloadingAttemptUkmEntryBuilder>(
             chrome_preloading_predictor::kDefaultSearchEngine);
-    scoped_test_timer_ =
-        std::make_unique<base::ScopedMockElapsedTimersForTest>();
   }
 
   ukm::TestAutoSetUkmRecorder* test_ukm_recorder() {
@@ -374,11 +372,11 @@ class SearchPrefetchHoldbackBrowserTest : public SearchPrefetchBaseBrowserTest {
   }
 
  private:
+  base::ScopedMockElapsedTimersForTest scoped_test_timer_;
   base::test::ScopedFeatureList feature_list_;
   std::unique_ptr<ukm::TestAutoSetUkmRecorder> test_ukm_recorder_;
   std::unique_ptr<content::test::PreloadingAttemptUkmEntryBuilder>
       attempt_entry_builder_;
-  std::unique_ptr<base::ScopedMockElapsedTimersForTest> scoped_test_timer_;
 };
 
 IN_PROC_BROWSER_TEST_F(SearchPrefetchHoldbackBrowserTest,
@@ -452,8 +450,6 @@ class SearchPrefetchServiceEnabledBrowserTest
     attempt_entry_builder_ =
         std::make_unique<content::test::PreloadingAttemptUkmEntryBuilder>(
             chrome_preloading_predictor::kDefaultSearchEngine);
-    scoped_test_timer_ =
-        std::make_unique<base::ScopedMockElapsedTimersForTest>();
   }
 
   void AddCacheEntry(const GURL& search_url, const GURL& prefetch_url) {
@@ -484,11 +480,11 @@ class SearchPrefetchServiceEnabledBrowserTest
   }
 
  private:
+  base::ScopedMockElapsedTimersForTest scoped_test_timer_;
   base::test::ScopedFeatureList feature_list_;
   std::unique_ptr<ukm::TestAutoSetUkmRecorder> test_ukm_recorder_;
   std::unique_ptr<content::test::PreloadingAttemptUkmEntryBuilder>
       attempt_entry_builder_;
-  std::unique_ptr<base::ScopedMockElapsedTimersForTest> scoped_test_timer_;
 };
 
 IN_PROC_BROWSER_TEST_F(SearchPrefetchServiceEnabledBrowserTest,
@@ -3448,8 +3444,6 @@ class SearchPrefetchServiceNavigationPrefetchBrowserTest
     SearchPrefetchBaseBrowserTest::SetUpOnMainThread();
     // Initialize PreloadingAttempt for this test suite.
     test_ukm_recorder_ = std::make_unique<ukm::TestAutoSetUkmRecorder>();
-    scoped_test_timer_ =
-        std::make_unique<base::ScopedMockElapsedTimersForTest>();
   }
 
   std::unique_ptr<content::test::PreloadingAttemptUkmEntryBuilder>
@@ -3469,9 +3463,9 @@ class SearchPrefetchServiceNavigationPrefetchBrowserTest
   }
 
  private:
+  base::ScopedMockElapsedTimersForTest scoped_test_timer_;
   base::test::ScopedFeatureList feature_list_;
   std::unique_ptr<ukm::TestAutoSetUkmRecorder> test_ukm_recorder_;
-  std::unique_ptr<base::ScopedMockElapsedTimersForTest> scoped_test_timer_;
 };
 
 IN_PROC_BROWSER_TEST_F(SearchPrefetchServiceNavigationPrefetchBrowserTest,

chrome/browser/preloading/prefetch/search_prefetch/search_preload_unified_browsertest.cc

@@ -148,8 +148,6 @@ class SearchPreloadUnifiedBrowserTest : public PlatformBrowserTest,
     prediction_entry_builder_ =
         std::make_unique<content::test::PreloadingPredictionUkmEntryBuilder>(
             chrome_preloading_predictor::kDefaultSearchEngine);
-    scoped_test_timer_ =
-        std::make_unique<base::ScopedMockElapsedTimersForTest>();
 
     // Reset pointer position to avoid the pointer hover on the back button
     // that unintentionally triggers `kBackButtonHover` preloading, which may
@@ -441,6 +439,7 @@ class SearchPreloadUnifiedBrowserTest : public PlatformBrowserTest,
 
   constexpr static char kSearchDomain[] = "a.test";
   constexpr static char16_t kSearchDomain16[] = u"a.test";
+  base::ScopedMockElapsedTimersForTest scoped_test_timer_;
   raw_ptr<PrerenderManager, AcrossTasksDanglingUntriaged> prerender_manager_ =
       nullptr;
   raw_ptr<SearchPrefetchService, AcrossTasksDanglingUntriaged>
@@ -456,7 +455,6 @@ class SearchPreloadUnifiedBrowserTest : public PlatformBrowserTest,
 
   content::test::PrerenderTestHelper prerender_helper_;
   base::test::ScopedFeatureList scoped_feature_list_;
-  std::unique_ptr<base::ScopedMockElapsedTimersForTest> scoped_test_timer_;
 };
 
 // Tests that the SearchSuggestionService can trigger prerendering after the

chrome/browser/preloading/prerender/omnibox_prerender_browsertest.cc

@@ -78,7 +78,6 @@ class OmniboxPrerenderBrowserTest : public PlatformBrowserTest {
     ukm_entry_builder_ =
         std::make_unique<content::test::PreloadingAttemptUkmEntryBuilder>(
             chrome_preloading_predictor::kOmniboxDirectURLInput);
-    test_timer_ = std::make_unique<base::ScopedMockElapsedTimersForTest>();
     ASSERT_TRUE(embedded_test_server()->Start());
   }
 
@@ -117,11 +116,11 @@ class OmniboxPrerenderBrowserTest : public PlatformBrowserTest {
   }
 
  private:
+  base::ScopedMockElapsedTimersForTest test_timer_;
   content::test::PrerenderTestHelper prerender_helper_;
   std::unique_ptr<ukm::TestAutoSetUkmRecorder> test_ukm_recorder_;
   std::unique_ptr<content::test::PreloadingAttemptUkmEntryBuilder>
       ukm_entry_builder_;
-  std::unique_ptr<base::ScopedMockElapsedTimersForTest> test_timer_;
   // Disable sampling of UKM preloading logs.
   content::test::PreloadingConfigOverride preloading_config_override_;
 };

chrome/browser/preloading/prerender/prerender_browsertest.cc

@@ -690,7 +690,6 @@ class PrerenderNewTabPageBrowserTest
     attempt_entry_builder_ =
         std::make_unique<content::test::PreloadingAttemptUkmEntryBuilder>(
             chrome_preloading_predictor::kMouseHoverOrMouseDownOnNewTabPage);
-    test_timer_ = std::make_unique<base::ScopedMockElapsedTimersForTest>();
   }
 
   void SimulateNewTabNavigation(const GURL& url) {
@@ -739,11 +738,11 @@ class PrerenderNewTabPageBrowserTest
   }
 
  private:
+  // This timer is for making TimeToNextNavigation in UKM consistent.
+  base::ScopedMockElapsedTimersForTest test_timer_;
   std::unique_ptr<ukm::TestAutoSetUkmRecorder> test_ukm_recorder_;
   std::unique_ptr<content::test::PreloadingAttemptUkmEntryBuilder>
       attempt_entry_builder_;
-  // This timer is for making TimeToNextNavigation in UKM consistent.
-  std::unique_ptr<base::ScopedMockElapsedTimersForTest> test_timer_;
 };
 
 IN_PROC_BROWSER_TEST_F(PrerenderNewTabPageBrowserTest,

chrome/browser/preloading/prerender/prerender_omnibox_ui_browsertest.cc

@@ -130,8 +130,6 @@ class PrerenderOmniboxUIBrowserTest : public InProcessBrowserTest,
             chrome_preloading_predictor::kOmniboxDirectURLInput);
 
     ASSERT_TRUE(embedded_test_server()->Start());
-    scoped_test_timer_ =
-        std::make_unique<base::ScopedMockElapsedTimersForTest>();
   }
 
   void TearDownOnMainThread() override {
@@ -248,13 +246,13 @@ class PrerenderOmniboxUIBrowserTest : public InProcessBrowserTest,
     is_prerendering_page_ = navigation_handle->IsPrerenderedPageActivation();
   }
 
+  base::ScopedMockElapsedTimersForTest scoped_test_timer_;
   content::test::PrerenderTestHelper prerender_helper_;
   ui::PageTransition last_finished_page_transition_type_;
   std::unique_ptr<ukm::TestAutoSetUkmRecorder> test_ukm_recorder_;
   std::unique_ptr<content::test::PreloadingAttemptUkmEntryBuilder>
       ukm_entry_builder_;
   bool is_prerendering_page_;
-  std::unique_ptr<base::ScopedMockElapsedTimersForTest> scoped_test_timer_;
 };
 
 // This test covers the path from starting a omnibox triggered prerendering
@@ -661,8 +659,6 @@ class PrerenderOmniboxSearchSuggestionUIBrowserTest
     prediction_entry_builder_ =
         std::make_unique<content::test::PreloadingPredictionUkmEntryBuilder>(
             chrome_preloading_predictor::kDefaultSearchEngine);
-    scoped_test_timer_ =
-        std::make_unique<base::ScopedMockElapsedTimersForTest>();
   }
 
   void SetUp() override {
@@ -826,6 +822,7 @@ class PrerenderOmniboxSearchSuggestionUIBrowserTest
   constexpr static char kSearchDomain[] = "a.test";
   constexpr static char kSuggestDomain[] = "b.test";
   constexpr static char16_t kSearchDomain16[] = u"a.test";
+  base::ScopedMockElapsedTimersForTest scoped_test_timer_;
   content::test::PrerenderTestHelper prerender_helper_;
   base::test::ScopedFeatureList scoped_feature_list_;
   net::test_server::EmbeddedTestServer search_engine_server_{
@@ -837,7 +834,6 @@ class PrerenderOmniboxSearchSuggestionUIBrowserTest
       attempt_entry_builder_;
   std::unique_ptr<content::test::PreloadingPredictionUkmEntryBuilder>
       prediction_entry_builder_;
-  std::unique_ptr<base::ScopedMockElapsedTimersForTest> scoped_test_timer_;
 };
 
 // Tests that prerender is cancelled if a different prerendering starts.

chrome/browser/ui/views/bookmarks/bookmark_bar_view_browsertest.cc

@@ -379,8 +379,6 @@ class PrerenderBookmarkBarNavigationTestBase
   void SetUpOnMainThread() override {
     BookmarkBarNavigationTest::SetUpOnMainThread();
     test_ukm_recorder_ = std::make_unique<ukm::TestAutoSetUkmRecorder>();
-    scoped_test_timer_ =
-        std::make_unique<base::ScopedMockElapsedTimersForTest>();
   }
 
   ukm::TestAutoSetUkmRecorder* test_ukm_recorder() {
@@ -432,9 +430,9 @@ class PrerenderBookmarkBarNavigationTestBase
   }
 
  private:
+  base::ScopedMockElapsedTimersForTest scoped_test_timer_;
   content::test::PrerenderTestHelper prerender_helper_;
   std::unique_ptr<ukm::TestAutoSetUkmRecorder> test_ukm_recorder_;
-  std::unique_ptr<base::ScopedMockElapsedTimersForTest> scoped_test_timer_;
 };
 
 // Following definitions are equal to content::PrerenderFinalStatus.

content/browser/preloading/prefetch/nav_prefetch_browsertest.cc

@@ -39,7 +39,6 @@ class NavPrefetchBrowserTest : public ContentBrowserTest {
     attempt_ukm_entry_builder_ =
         std::make_unique<test::PreloadingAttemptUkmEntryBuilder>(
             content_preloading_predictor::kSpeculationRules);
-    test_timer_ = std::make_unique<base::ScopedMockElapsedTimersForTest>();
   }
 
   void StartPrefetch(const GURL& url) {
@@ -88,13 +87,13 @@ class NavPrefetchBrowserTest : public ContentBrowserTest {
   }
 
  private:
+  base::ScopedMockElapsedTimersForTest test_timer_;
   std::map<std::string, int> request_count_by_path_ GUARDED_BY(lock_);
   std::unique_ptr<ukm::TestAutoSetUkmRecorder> ukm_recorder_;
   std::unique_ptr<test::PreloadingAttemptUkmEntryBuilder>
       attempt_ukm_entry_builder_;
   // Disable sampling for UKM preloading logs.
   test::PreloadingConfigOverride preloading_config_override_;
-  std::unique_ptr<base::ScopedMockElapsedTimersForTest> test_timer_;
 
   base::Lock lock_;
 };

content/browser/preloading/prefetch/prefetch_service_unittest.cc

@@ -281,9 +281,6 @@ class PrefetchServiceTestBase : public RenderViewHostTestHarness {
     attempt_entry_builder_ =
         std::make_unique<test::PreloadingAttemptUkmEntryBuilder>(
             content_preloading_predictor::kSpeculationRules);
-
-    scoped_test_timer_ =
-        std::make_unique<base::ScopedMockElapsedTimersForTest>();
   }
 
   void TearDown() override {
@@ -1239,6 +1236,8 @@ class PrefetchServiceTestBase : public RenderViewHostTestHarness {
     test_url_loader_factory_.ClearResponses();
   }
 
+  base::ScopedMockElapsedTimersForTest scoped_test_timer_;
+
   std::unique_ptr<PrefetchFakeServiceWorkerContext> service_worker_context_;
   mojo::Remote<network::mojom::CookieManager> cookie_manager_;
 
@@ -1263,8 +1262,6 @@ class PrefetchServiceTestBase : public RenderViewHostTestHarness {
   std::unique_ptr<test::PreloadingAttemptUkmEntryBuilder>
       attempt_entry_builder_;
 
-  std::unique_ptr<base::ScopedMockElapsedTimersForTest> scoped_test_timer_;
-
   std::vector<PrefetchRequestHandler> request_handler_keep_alive_;
 
   variations::ScopedVariationsIdsProvider scoped_variations_ids_provider_{

content/browser/preloading/prefetch/prefetch_url_loader_interceptor_unittest.cc

@@ -270,9 +270,6 @@ class PrefetchURLLoaderInterceptorTestBase : public RenderViewHostTestHarness {
     attempt_entry_builder_ =
         std::make_unique<test::PreloadingAttemptUkmEntryBuilder>(
             content_preloading_predictor::kSpeculationRules);
-
-    scoped_test_timer_ =
-        std::make_unique<base::ScopedMockElapsedTimersForTest>();
   }
 
   void TearDown() override {
@@ -515,6 +512,8 @@ class PrefetchURLLoaderInterceptorTestBase : public RenderViewHostTestHarness {
   base::test::ScopedFeatureList scoped_feature_list_for_new_wait_loop_;
 
  private:
+  base::ScopedMockElapsedTimersForTest scoped_test_timer_;
+
   std::unique_ptr<PrefetchURLLoaderInterceptor> interceptor_;
 
   base::HistogramTester histogram_tester_;
@@ -529,7 +528,6 @@ class PrefetchURLLoaderInterceptorTestBase : public RenderViewHostTestHarness {
   std::unique_ptr<test::PreloadingAttemptUkmEntryBuilder>
       attempt_entry_builder_;
 
-  std::unique_ptr<base::ScopedMockElapsedTimersForTest> scoped_test_timer_;
   // Disable sampling of UKM preloading logs.
   content::test::PreloadingConfigOverride preloading_config_override_;
 

content/browser/preloading/prerender/prerender_browsertest.cc

@@ -377,8 +377,6 @@ class PrerenderBrowserTest : public ContentBrowserTest,
     WebContentsObserver::Observe(shell()->web_contents());
 
     ukm_recorder_ = std::make_unique<ukm::TestAutoSetUkmRecorder>();
-    scoped_test_timer_ =
-        std::make_unique<base::ScopedMockElapsedTimersForTest>();
   }
 
   void TearDownOnMainThread() override {
@@ -844,6 +842,8 @@ class PrerenderBrowserTest : public ContentBrowserTest,
     navigation_ids_.push_back(handle->GetNavigationId());
   }
 
+  base::ScopedMockElapsedTimersForTest scoped_test_timer_;
+
   net::test_server::EmbeddedTestServer ssl_server_{
       net::test_server::EmbeddedTestServer::TYPE_HTTPS};
 
@@ -860,7 +860,6 @@ class PrerenderBrowserTest : public ContentBrowserTest,
   std::unique_ptr<PreloadingPredictionPreviousPrimaryPageUkmEntryBuilder>
       prediction_previous_ukm_entry_builder_;
   base::test::ScopedFeatureList feature_list_;
-  std::unique_ptr<base::ScopedMockElapsedTimersForTest> scoped_test_timer_;
 };
 
 class NoVarySearchPrerenderBrowserTest : public PrerenderBrowserTest {

sql/database.cc

@@ -34,6 +34,7 @@
 #include "base/memory/raw_ptr.h"
 #include "base/memory/scoped_refptr.h"
 #include "base/memory/weak_ptr.h"
+#include "base/metrics/histogram_functions.h"
 #include "base/no_destructor.h"
 #include "base/notimplemented.h"
 #include "base/notreached.h"
@@ -48,6 +49,7 @@
 #include "base/synchronization/lock.h"
 #include "base/threading/scoped_blocking_call.h"
 #include "base/time/time.h"
+#include "base/timer/elapsed_timer.h"
 #include "base/trace_event/memory_dump_manager.h"
 #include "base/trace_event/trace_event.h"
 #include "base/tracing/protos/chrome_track_event.pbzero.h"  // IWYU pragma: keep
@@ -319,7 +321,9 @@ void DatabaseDiagnostics::WriteIntoTrace(
 Database::Database() : Database(DatabaseOptions{}) {}
 
 Database::Database(DatabaseOptions options)
-    : options_(options), mmap_disabled_(!enable_mmap_by_default_) {
+    : options_(options),
+      mmap_disabled_(!enable_mmap_by_default_),
+      tracing_track_name_("Database: NoTag") {
   DCHECK_GE(options.page_size, 512);
   DCHECK_LE(options.page_size, 65536);
   DCHECK(!(options.page_size & (options.page_size - 1)))
@@ -995,6 +999,24 @@ sqlite3_file* Database::GetSqliteVfsFile() {
   return result;
 }
 
+void Database::RecordTimingHistogram(std::string_view name_prefix,
+                                     base::TimeDelta timing) const {
+  std::string_view tag("NoTag");
+  if (!histogram_tag().empty()) {
+    tag = histogram_tag();
+  }
+  base::UmaHistogramCustomMicrosecondsTimes(base::StrCat({name_prefix, tag}),
+                                            timing, base::Microseconds(0),
+                                            base::Minutes(1), 100);
+}
+
+perfetto::NamedTrack Database::GetTracingNamedTrack() const {
+  DCHECK_CALLED_ON_VALID_SEQUENCE(sequence_checker_);
+  return perfetto::NamedTrack(perfetto::DynamicString(tracing_track_name_),
+                              reinterpret_cast<uint64_t>(this),
+                              perfetto::ThreadTrack::Current());
+}
+
 void Database::TrimMemory() {
   TRACE_EVENT0("sql", "Database::TrimMemory");
 
@@ -1859,6 +1881,7 @@ const char* Database::GetErrorMessage() const {
 bool Database::OpenInternal(const std::string& db_file_path) {
   DCHECK_CALLED_ON_VALID_SEQUENCE(sequence_checker_);
   TRACE_EVENT1("sql", "Database::OpenInternal", "path", db_file_path);
+  base::ElapsedTimer timer;
 
   if (is_open()) {
     DLOG(FATAL) << "sql::Database is already open.";
@@ -1907,8 +1930,16 @@ bool Database::OpenInternal(const std::string& db_file_path) {
   }
 
   sqlite3* db = nullptr;
-  auto sqlite_result_code = ToSqliteResultCode(sqlite3_open_v2(
-      uri_file_path.c_str(), &db, open_flags, /*zVfs=*/nullptr));
+  SqliteResultCode sqlite_result_code;
+  {
+    TRACE_EVENT1("sql", "Database::OpenInternal sqlite3_open_v2", "path",
+                 db_file_path);
+    base::ElapsedTimer library_call_timer;
+    sqlite_result_code = ToSqliteResultCode(sqlite3_open_v2(
+        uri_file_path.c_str(), &db, open_flags, /*zVfs=*/nullptr));
+    RecordTimingHistogram("Sql.Database.Success.SqliteOpenTime.",
+                          library_call_timer.Elapsed());
+  }
   if (sqlite_result_code == SqliteResultCode::kOk) {
     db_ = db;
   } else {
@@ -2101,6 +2132,9 @@ bool Database::OpenInternal(const std::string& db_file_path) {
   base::trace_event::MemoryDumpManager::GetInstance()->RegisterDumpProvider(
       memory_dump_provider_.get(), "sql::Database", /*task_runner=*/nullptr);
 
+  RecordTimingHistogram("Sql.Database.Success.OpenInternalTime.",
+                        timer.Elapsed());
+
   return true;
 }
 

sql/database.h

@@ -33,6 +33,7 @@
 #include "base/strings/cstring_view.h"
 #include "base/threading/scoped_blocking_call.h"
 #include "base/time/time.h"
+#include "base/trace_event/base_tracing.h"
 #include "base/types/pass_key.h"
 #include "sql/internal_api_token.h"
 #include "sql/sql_features.h"
@@ -336,6 +337,7 @@ class COMPONENT_EXPORT(SQL) Database {
   void set_histogram_tag(const std::string& histogram_tag) {
     DCHECK(!is_open());
     histogram_tag_ = histogram_tag;
+    tracing_track_name_ = "Database: " + histogram_tag;
   }
 
   const std::string& histogram_tag() const { return histogram_tag_; }
@@ -944,6 +946,19 @@ class COMPONENT_EXPORT(SQL) Database {
   // This method must only be called while the database is successfully opened.
   sqlite3_file* GetSqliteVfsFile();
 
+  // Records a histogram named `name_prefix` suffixed with this database's
+  // histogram tag (or "NoTag" if the tag isn't set). For instance,
+  // `RecordTimingHistogram("Foo.", ...)` called on a database with the tag
+  // "Bar" will record into "Foo.Bar". This function chooses reasonable
+  // bucketing parameters for typical database operations timing and reports in
+  // microseconds.
+  void RecordTimingHistogram(std::string_view name_prefix,
+                             base::TimeDelta timing) const;
+
+  // Returns the name of the track in which to record this database's events
+  // based on its histogram tag.
+  perfetto::NamedTrack GetTracingNamedTrack() const;
+
   void SetEnableVirtualTablesForTesting(bool enable) {
     enable_virtual_tables_ = enable;
   }
@@ -1018,6 +1033,10 @@ class COMPONENT_EXPORT(SQL) Database {
   // Developer-friendly database ID used in logging output and memory dumps.
   std::string histogram_tag_;
 
+  // Persist the track name as a member since perfetto needs the original string
+  // for the name to remain alive (without taking ownership of it).
+  std::string tracing_track_name_;
+
   // Stores the dump provider object when db is open.
   std::unique_ptr<DatabaseMemoryDumpProvider> memory_dump_provider_;
 

sql/statement.cc

@@ -32,6 +32,8 @@
 #include "base/strings/utf_string_conversions.h"
 #include "base/threading/scoped_blocking_call.h"
 #include "base/time/time.h"
+#include "base/timer/elapsed_timer.h"
+#include "base/trace_event/base_tracing.h"
 #include "sql/database.h"
 #include "sql/sqlite_result_code.h"
 #include "sql/sqlite_result_code_values.h"
@@ -94,10 +96,24 @@ SqliteResultCode Statement::StepInternal() {
   if (!CheckValid())
     return SqliteResultCode::kError;
 
+  base::ElapsedTimer timer;
+  if (!time_spent_stepping_) {
+    time_spent_stepping_ = base::TimeDelta();
+    TRACE_EVENT_BEGIN("sql", "Database::Statement",
+                      ref_->database()->GetTracingNamedTrack(),
+                      timer.start_time(), "statement",
+                      std::string(sqlite3_sql(ref_->stmt())));
+  }
+
   std::optional<base::ScopedBlockingCall> scoped_blocking_call;
   ref_->InitScopedBlockingCall(FROM_HERE, &scoped_blocking_call);
 
   auto sqlite_result_code = ToSqliteResultCode(sqlite3_step(ref_->stmt()));
+
+  auto elapsed = timer.Elapsed();
+  ref_->database()->RecordTimingHistogram("Sql.Statement.StepTime.", elapsed);
+  *time_spent_stepping_ += elapsed;
+
   return CheckSqliteResultCode(sqlite_result_code);
 }
 
@@ -110,13 +126,18 @@ void Statement::ReportQueryExecutionMetrics() const {
   const int kResetVMStepsToZero = 1;
   const int vm_steps = sqlite3_stmt_status(
       ref_->stmt(), SQLITE_STMTSTATUS_VM_STEP, kResetVMStepsToZero);
-  if (vm_steps > 0) {
-    const Database* database = ref_->database();
-    if (!database->histogram_tag().empty()) {
-      const std::string histogram_name =
-          "Sql.Statement." + database->histogram_tag() + ".VMSteps";
-      base::UmaHistogramCounts10000(histogram_name, vm_steps);
-    }
+  const Database* database = ref_->database();
+  if (vm_steps > 0 && !database->histogram_tag().empty()) {
+    const std::string histogram_name =
+        "Sql.Statement." + database->histogram_tag() + ".VMSteps";
+    base::UmaHistogramCounts10000(histogram_name, vm_steps);
+  }
+
+  if (time_spent_stepping_) {
+    TRACE_EVENT_END("sql", database->GetTracingNamedTrack(), "statement",
+                    std::string(sqlite3_sql(ref_->stmt())));
+    database->RecordTimingHistogram("Sql.Statement.ExecutionTime.",
+                                    *time_spent_stepping_);
   }
 }
 
@@ -170,6 +191,8 @@ void Statement::Reset(bool clear_bound_vars) {
   run_called_ = false;
   step_called_ = false;
 #endif  // DCHECK_IS_ON()
+
+  time_spent_stepping_ = std::nullopt;
 }
 
 bool Statement::Succeeded() const {

sql/statement.h

@@ -7,6 +7,7 @@
 
 #include <stdint.h>
 
+#include <optional>
 #include <string>
 #include <string_view>
 #include <vector>
@@ -309,6 +310,8 @@ class COMPONENT_EXPORT(SQL) Statement {
   bool run_called_ GUARDED_BY_CONTEXT(sequence_checker_) = false;
 #endif  // DCHECK_IS_ON()
 
+  std::optional<base::TimeDelta> time_spent_stepping_ = std::nullopt;
+
   SEQUENCE_CHECKER(sequence_checker_);
 };
 

tools/metrics/histograms/metadata/storage/histograms.xml

@@ -471,6 +471,32 @@ chromium-metrics-reviews@google.com.
   </summary>
 </histogram>
 
+<histogram name="Sql.Database.Success.OpenInternalTime.{DatabaseTag}"
+    units="microseconds" expires_after="2025-11-15">
+  <owner>anthonyvd@chromium.org</owner>
+  <owner>etienneb@chromium.org</owner>
+  <summary>
+    Reports the time spent in OpenInternal, in microseconds, when opening the
+    {DatabaseTag} database.
+
+    Only reported for clients with high-resolution clocks.
+  </summary>
+  <token key="DatabaseTag" variants="DatabaseTag"/>
+</histogram>
+
+<histogram name="Sql.Database.Success.SqliteOpenTime.{DatabaseTag}"
+    units="microseconds" expires_after="2025-11-15">
+  <owner>anthonyvd@chromium.org</owner>
+  <owner>etienneb@chromium.org</owner>
+  <summary>
+    Reports the time spent in the sqlite3_open_v2 library call, in microseconds,
+    when opening the {DatabaseTag} database.
+
+    Only reported for clients with high-resolution clocks.
+  </summary>
+  <token key="DatabaseTag" variants="DatabaseTag"/>
+</histogram>
+
 <histogram name="Sql.Recovery.Result" enum="SqlRecoveryResult"
     expires_after="2025-09-15">
   <owner>asully@chromium.org</owner>
@@ -518,6 +544,34 @@ chromium-metrics-reviews@google.com.
   <token key="DatabaseTag" variants="DatabaseTag"/>
 </histogram>
 
+<histogram name="Sql.Statement.ExecutionTime.{DatabaseTag}"
+    units="microseconds" expires_after="2025-11-15">
+  <owner>anthonyvd@chromium.org</owner>
+  <owner>etienneb@chromium.org</owner>
+  <summary>
+    Reports the total time spent stepping for a given statement in database
+    {DatabaseTag}, in microseconds. Recorded when the statement is
+    reset/destructed, but only includes the time spent in `StepInternal` since
+    the statement's last reset.
+
+    Only reported for clients with high-resolution clocks.
+  </summary>
+  <token key="DatabaseTag" variants="DatabaseTag"/>
+</histogram>
+
+<histogram name="Sql.Statement.StepTime.{DatabaseTag}" units="microseconds"
+    expires_after="2025-11-15">
+  <owner>anthonyvd@chromium.org</owner>
+  <owner>etienneb@chromium.org</owner>
+  <summary>
+    Reports the time of a single step of a statement running against
+    {DatabaseTag}, in microseconds. Recorded every time `Step` is called.
+
+    Only reported for clients with high-resolution clocks.
+  </summary>
+  <token key="DatabaseTag" variants="DatabaseTag"/>
+</histogram>
+
 <histogram name="Sql.Statement.{DatabaseTag}.VMSteps" units="count"
     expires_after="2025-04-13">
   <owner>etienneb@chromium.org</owner>