diff --git a/metricflow-semantics/metricflow_semantics/model/semantics/linkable_spec_resolver.py b/metricflow-semantics/metricflow_semantics/model/semantics/linkable_spec_resolver.py index 6928efdcef..77d0fbcd9f 100644 --- a/metricflow-semantics/metricflow_semantics/model/semantics/linkable_spec_resolver.py +++ b/metricflow-semantics/metricflow_semantics/model/semantics/linkable_spec_resolver.py @@ -186,6 +186,7 @@ def __init__( # Populate storage dicts with linkable metrics. This loop must happen after the one above so that # _metric_to_linkable_element_sets is populated with entities and dimensions. + linkable_metrics_start_time = time.time() for metric in self._semantic_manifest.metrics: # Cumulative metrics and time offset metrics require grouping by metric_time, which is not yet available for # linkable metrics. So skip those. @@ -218,13 +219,17 @@ def __init__( # If no metrics are specified, the query interface supports querying distinct values for dimensions, entities, # and group by metrics. linkable_element_sets_for_no_metrics_queries: List[LinkableElementSet] = [] + # Temp: separate loop to track latency for linkable metrics. TODO: combine with loop below. for semantic_model in semantic_manifest.semantic_models: - linkable_element_sets_for_no_metrics_queries.append(self._get_elements_in_semantic_model(semantic_model)) linkable_element_sets_for_no_metrics_queries.append( self.get_joinable_metrics_for_semantic_model( semantic_model, SemanticModelJoinPath(left_semantic_model_reference=semantic_model.reference) ) ) + logger.info(f"Building valid linkable metrics took: {time.time() - linkable_metrics_start_time:.2f}s") + + for semantic_model in semantic_manifest.semantic_models: + linkable_element_sets_for_no_metrics_queries.append(self._get_elements_in_semantic_model(semantic_model)) metric_time_elements_for_no_metrics = self._get_metric_time_elements(measure_reference=None) self._no_metric_linkable_element_set = LinkableElementSet.merge_by_path_key( diff --git a/metricflow-semantics/metricflow_semantics/model/semantics/metric_lookup.py b/metricflow-semantics/metricflow_semantics/model/semantics/metric_lookup.py index 51c95ab88c..35ce7c45be 100644 --- a/metricflow-semantics/metricflow_semantics/model/semantics/metric_lookup.py +++ b/metricflow-semantics/metricflow_semantics/model/semantics/metric_lookup.py @@ -1,6 +1,7 @@ from __future__ import annotations import logging +import time from typing import Dict, FrozenSet, Optional, Sequence, Set from dbt_semantic_interfaces.enum_extension import assert_values_exhausted @@ -53,11 +54,17 @@ def linkable_elements_for_measure( frozen_with_any_of = LinkableElementProperty.all_properties() if with_any_of is None else frozenset(with_any_of) frozen_without_any_of = frozenset() if without_any_of is None else frozenset(without_any_of) - return self._linkable_spec_resolver.get_linkable_element_set_for_measure( + start_time = time.time() + linkable_element_set = self._linkable_spec_resolver.get_linkable_element_set_for_measure( measure_reference=measure_reference, with_any_of=frozen_with_any_of, without_any_of=frozen_without_any_of, ) + logger.info( + f"Getting valid linkable elements for measure '{measure_reference.element_name}' took: {time.time() - start_time:.2f}s" + ) + + return linkable_element_set def linkable_elements_for_no_metrics_query( self, diff --git a/metricflow-semantics/metricflow_semantics/query/group_by_item/candidate_push_down/push_down_visitor.py b/metricflow-semantics/metricflow_semantics/query/group_by_item/candidate_push_down/push_down_visitor.py index d44180783e..53da4b6706 100644 --- a/metricflow-semantics/metricflow_semantics/query/group_by_item/candidate_push_down/push_down_visitor.py +++ b/metricflow-semantics/metricflow_semantics/query/group_by_item/candidate_push_down/push_down_visitor.py @@ -1,6 +1,7 @@ from __future__ import annotations import logging +import time from contextlib import contextmanager from dataclasses import dataclass from typing import Dict, Iterator, List, Optional, Sequence, Set, Tuple @@ -189,9 +190,11 @@ def visit_measure_node(self, node: MeasureGroupByItemSourceNode) -> PushDownResu else: assert_values_exhausted(metric.type) + start_time = time.time() matching_items = items_available_for_measure.filter_by_spec_patterns( patterns_to_apply + self._source_spec_patterns ) + logger.info(f"Filtering valid linkable elements took: {time.time() - start_time:.2f}s") if logger.isEnabledFor(logging.DEBUG): logger.debug(