dummy PR for perf benchmark with powerBI

google/cloud/odbc/bq_driver/internal/odbc_internal_commons.cc

@@ -827,7 +827,17 @@ StatusRecordOr<PostQueryResults> PostQueryWithoutResults(
   }
   // For now , we use default options.
   // We can set timeout here as needed later.
+
+  // --- BENCHMARK START: PostQuery (Client Library Call) ---
+  auto start_post_query = std::chrono::high_resolution_clock::now();
+
   auto pq_status = bq_client->PostQuery(post_query_request, options);
+
+  // --- BENCHMARK END: PostQuery (Client Library Call) ---
+  auto end_post_query = std::chrono::high_resolution_clock::now();
+  auto elapsed_post_query = std::chrono::duration_cast<std::chrono::milliseconds>(end_post_query - start_post_query);
+  std::cout << "[BENCHMARK] PostQueryWithoutResults -> bq_client->PostQuery: " << elapsed_post_query.count() << " ms\n";
+
   if (!pq_status) {
     LOG(ERROR) << "PostQueryWithoutResults::PostQuery:: "
                << pq_status.GetStatusRecord().message;

google/cloud/odbc/bq_driver/internal/odbc_sql_columns.cc

@@ -417,15 +417,24 @@ StatusRecordOr<std::vector<Table>> FetchBQTablesData(
         SQLStates::k_HY000(),
         "Invalid or null BQ Client within the connection handle"};
   }
+
+  // --- BENCHMARK START: GetFilteredDatasetIds ---
+  auto start_datasets = std::chrono::high_resolution_clock::now();
+
   // Get Datasets based on search pattern in the dataset argument
   StatusRecordOr<std::vector<std::string>> datasets_status =
       GetFilteredDatasetIds(*bq_client, catalog, dataset_pattern, metadata_id);
+
+  // --- BENCHMARK END: GetFilteredDatasetIds ---
+  auto end_datasets = std::chrono::high_resolution_clock::now();
+  auto elapsed_datasets = std::chrono::duration_cast<std::chrono::milliseconds>(end_datasets - start_datasets);
+  std::cout << "[BENCHMARK] FetchBQTablesData -> GetFilteredDatasetIds: " << elapsed_datasets.count() << " ms\n";
+
   if (!datasets_status) {
     LOG(ERROR) << "FetchBQTablesData::GetFilteredDatasetIds:: "
                << datasets_status.GetStatusRecord().message;
     return datasets_status.GetStatusRecord();
   }
-
   struct TableTaskInput {
     std::size_t index;
     std::string dataset;
@@ -440,13 +449,11 @@ StatusRecordOr<std::vector<Table>> FetchBQTablesData(
     std::string dataset;
     std::vector<std::string> table_names;
   };
-
   std::vector<DatasetTaskInput> dataset_tasks;
   dataset_tasks.reserve(datasets_status->size());
   for (std::size_t i = 0; i < datasets_status->size(); ++i) {
     dataset_tasks.push_back({i, datasets_status->at(i)});
   }
-
   // Run broad SQLColumns discovery in parallel: first table listing per
   // dataset, then table metadata retrieval.
   auto trace_option = TraceOptions::GetTraceOption();
@@ -455,18 +462,26 @@ StatusRecordOr<std::vector<Table>> FetchBQTablesData(
                         "MaxThreads must be configured with a positive value"};
   }
   int max_threads = trace_option->max_threads;
-
   auto fetch_tables_for_dataset_task = [&](DatasetTaskInput const& dataset_task)
       -> StatusRecordOr<DatasetTablesBatch> {
+
+    // --- BENCHMARK START: Individual GetFilteredTables Task ---
+    auto start_single_listing = std::chrono::high_resolution_clock::now();
+
     StatusRecordOr<std::vector<FilteredTableResponse>> tables_status =
         GetFilteredTables(stmt_handle, catalog, dataset_task.dataset,
                           table_pattern, kTableAndViewTypes, metadata_id);
+
+    // --- BENCHMARK END: Individual GetFilteredTables Task ---
+    auto end_single_listing = std::chrono::high_resolution_clock::now();
+    auto elapsed_single = std::chrono::duration_cast<std::chrono::milliseconds>(end_single_listing - start_single_listing);
+    std::cout << "[BENCHMARK] Task: GetFilteredTables for dataset '" << dataset_task.dataset << "': " << elapsed_single.count() << " ms\n";
+
     if (!tables_status) {
       LOG(ERROR) << "FetchBQTablesData::GetFilteredTables:: "
                  << tables_status.GetStatusRecord().message;
       return tables_status.GetStatusRecord();
     }
-
     DatasetTablesBatch batch{
         dataset_task.dataset_index, dataset_task.dataset, {}};
     batch.table_names.reserve(tables_status->size());
@@ -476,35 +491,40 @@ StatusRecordOr<std::vector<Table>> FetchBQTablesData(
     return batch;
   };
 
+  // --- BENCHMARK START: GetFilteredTables (Parallel) ---
+  auto start_listing_tables = std::chrono::high_resolution_clock::now();
+
   auto dataset_tables_results_or =
       ExecuteParallelTasks<DatasetTaskInput, DatasetTablesBatch>(
           max_threads, dataset_tasks, fetch_tables_for_dataset_task);
+
+  // --- BENCHMARK END: GetFilteredTables (Parallel) ---
+  auto end_listing_tables = std::chrono::high_resolution_clock::now();
+  auto elapsed_listing = std::chrono::duration_cast<std::chrono::milliseconds>(end_listing_tables - start_listing_tables);
+  std::cout << "[BENCHMARK] FetchBQTablesData -> ExecuteParallelTasks(GetFilteredTables): " << elapsed_listing.count() << " ms\n";
+
   if (!dataset_tables_results_or) {
     LOG(ERROR)
         << "FetchBQTablesData::ExecuteParallelTasks(GetFilteredTables):: "
         << dataset_tables_results_or.GetStatusRecord().message;
     return dataset_tables_results_or.GetStatusRecord();
   }
-
   auto dataset_tables_batches = std::move(*dataset_tables_results_or);
   std::sort(dataset_tables_batches.begin(), dataset_tables_batches.end(),
             [](DatasetTablesBatch const& lhs, DatasetTablesBatch const& rhs) {
               return lhs.dataset_index < rhs.dataset_index;
             });
-
   std::vector<TableTaskInput> table_tasks;
   for (auto const& dataset_batch : dataset_tables_batches) {
     for (auto const& table_name : dataset_batch.table_names) {
       table_tasks.push_back(
           {table_tasks.size(), dataset_batch.dataset, table_name});
     }
   }
-
   struct IndexedTable {
     std::size_t index;
     Table table;
   };
-
   auto fetch_table_task = [&](TableTaskInput const& task_input)
       -> StatusRecordOr<optional<IndexedTable>> {
     auto bq_table_status = FetchBQTableData(
@@ -524,15 +544,23 @@ StatusRecordOr<std::vector<Table>> FetchBQTablesData(
         IndexedTable{task_input.index, std::move(*bq_table_status)});
   };
 
+  // --- BENCHMARK START: FetchBQTableData (Parallel) ---
+  auto start_fetching_metadata = std::chrono::high_resolution_clock::now();
+
   auto table_results_or =
       ExecuteParallelTasks<TableTaskInput, optional<IndexedTable>>(
           max_threads, table_tasks, fetch_table_task);
+
+  // --- BENCHMARK END: FetchBQTableData (Parallel) ---
+  auto end_fetching_metadata = std::chrono::high_resolution_clock::now();
+  auto elapsed_metadata = std::chrono::duration_cast<std::chrono::milliseconds>(end_fetching_metadata - start_fetching_metadata);
+  std::cout << "[BENCHMARK] FetchBQTablesData -> ExecuteParallelTasks(FetchBQTableData): " << elapsed_metadata.count() << " ms\n";
+
   if (!table_results_or) {
     LOG(ERROR) << "FetchBQTablesData::ExecuteParallelTasks:: "
                << table_results_or.GetStatusRecord().message;
     return table_results_or.GetStatusRecord();
   }
-
   std::vector<IndexedTable> indexed_tables;
   std::size_t skipped_table_count = 0;
   indexed_tables.reserve(table_results_or->size());
@@ -547,7 +575,6 @@ StatusRecordOr<std::vector<Table>> FetchBQTablesData(
             [](IndexedTable const& lhs, IndexedTable const& rhs) {
               return lhs.index < rhs.index;
             });
-
   result.reserve(indexed_tables.size());
   for (auto& indexed_table : indexed_tables) {
     result.push_back(std::move(indexed_table.table));

google/cloud/odbc/bq_driver/internal/odbc_sql_tables.cc

@@ -99,19 +99,39 @@ StatusRecordOr<std::vector<std::string>> GetFilteredDatasetIds(
   Options options;
   DatasetFilter filter;
   filter.all = false;
+
+  // --- BENCHMARK START: FilterDatasets (Client Library Call) ---
+  auto start_client_call = std::chrono::high_resolution_clock::now();
+
   StatusRecordOr<std::vector<ListFormatDataset>> datasets =
       bq_client.FilterDatasets(project_id, filter, options);
+
+  // --- BENCHMARK END: FilterDatasets (Client Library Call) ---
+  auto end_client_call = std::chrono::high_resolution_clock::now();
+  auto elapsed_client = std::chrono::duration_cast<std::chrono::milliseconds>(end_client_call - start_client_call);
+  std::cout << "[BENCHMARK] GetFilteredDatasetIds -> bq_client.FilterDatasets: " << elapsed_client.count() << " ms\n";
+
   if (!datasets) {
     LOG(ERROR) << "GetFilteredDatasetIds::FilterDatasets:: "
                << datasets.GetStatusRecord().message;
     return datasets.GetStatusRecord();
   }
+
+  // --- BENCHMARK START: Regex Matching Loop ---
+  auto start_regex = std::chrono::high_resolution_clock::now();
+
   for (auto const& dataset : *datasets) {
     if ((!metadata_id && datasets_filter == "%") ||
         std::regex_match(dataset.dataset_reference.dataset_id, filter_regex)) {
       dataset_ids.push_back(dataset.dataset_reference.dataset_id);
     }
   }
+
+  // --- BENCHMARK END: Regex Matching Loop ---
+  auto end_regex = std::chrono::high_resolution_clock::now();
+  auto elapsed_regex = std::chrono::duration_cast<std::chrono::milliseconds>(end_regex - start_regex);
+  std::cout << "[BENCHMARK] GetFilteredDatasetIds -> Regex matching loop: " << elapsed_regex.count() << " ms\n";
+
   return dataset_ids;
 }
 
@@ -220,29 +240,68 @@ StatusRecordOr<std::vector<FilteredTableResponse>> GetFilteredTables(
     std::string const& dataset_id, std::string const& tables_filter,
     std::string const& table_types_filter, SQLULEN metadata_id) {
   std::vector<QueryParameter> named_query_params;
+
+  // --- BENCHMARK START: ProcessTableTypes ---
+  auto start_process_types = std::chrono::high_resolution_clock::now();
+
   // Normalize table type: client-library accepts type "BASE TABLE"
   std::string normalized_table_type_filter =
       ProcessTableTypes(table_types_filter);
+
+  // --- BENCHMARK END: ProcessTableTypes ---
+  auto end_process_types = std::chrono::high_resolution_clock::now();
+  auto elapsed_process_types = std::chrono::duration_cast<std::chrono::milliseconds>(end_process_types - start_process_types);
+  std::cout << "[BENCHMARK] GetFilteredTables -> ProcessTableTypes: " << elapsed_process_types.count() << " ms\n";
+
+
+  // --- BENCHMARK START: ConstructQuery ---
+  auto start_construct_query = std::chrono::high_resolution_clock::now();
+
   auto query_tables =
       ConstructQuery(tables_filter, normalized_table_type_filter, metadata_id,
                      named_query_params);
+
+  // --- BENCHMARK END: ConstructQuery ---
+  auto end_construct_query = std::chrono::high_resolution_clock::now();
+  auto elapsed_construct_query = std::chrono::duration_cast<std::chrono::milliseconds>(end_construct_query - start_construct_query);
+  std::cout << "[BENCHMARK] GetFilteredTables -> ConstructQuery: " << elapsed_construct_query.count() << " ms\n";
+
   if (!query_tables) {
     LOG(ERROR) << "GetFilteredTables::ConstructQuery:: "
                << query_tables.GetStatusRecord().message;
     return query_tables.GetStatusRecord();
   }
 
+
+  // --- BENCHMARK START: ConstructNamedParametersPostQueryRequest ---
+  auto start_construct_req = std::chrono::high_resolution_clock::now();
+
   auto post_query_request_status = ConstructNamedParametersPostQueryRequest(
       project_id, dataset_id, *query_tables, named_query_params);
+
+  // --- BENCHMARK END: ConstructNamedParametersPostQueryRequest ---
+  auto end_construct_req = std::chrono::high_resolution_clock::now();
+  auto elapsed_construct_req = std::chrono::duration_cast<std::chrono::milliseconds>(end_construct_req - start_construct_req);
+  std::cout << "[BENCHMARK] GetFilteredTables -> ConstructNamedParametersPostQueryRequest: " << elapsed_construct_req.count() << " ms\n";
+
   if (!post_query_request_status) {
     LOG(ERROR)
         << "GetFilteredTables::ConstructNamedParametersPostQueryRequest:: "
         << post_query_request_status.GetStatusRecord().message;
     return post_query_request_status.GetStatusRecord();
   }
 
+  // --- BENCHMARK START: FetchBQData ---
+  auto start_fetch_bq = std::chrono::high_resolution_clock::now();
+
   auto fetch_status_record_or =
       FetchBQData(stmt_handle, *post_query_request_status);
+
+  // --- BENCHMARK END: FetchBQData ---
+  auto end_fetch_bq = std::chrono::high_resolution_clock::now();
+  auto elapsed_fetch_bq = std::chrono::duration_cast<std::chrono::milliseconds>(end_fetch_bq - start_fetch_bq);
+  std::cout << "[BENCHMARK] GetFilteredTables -> FetchBQData: " << elapsed_fetch_bq.count() << " ms\n";
+
   if (!fetch_status_record_or) {
     LOG(ERROR) << "GetFilteredTables::FetchBQData:: "
                << fetch_status_record_or.GetStatusRecord().message;