Lazy format additional log lines (#1434)

This PR updates additional log lines to use `LazyFormat` as they were
missed during the initial migration.

metricflow/dataflow/optimizer/predicate_pushdown_optimizer.py

@@ -7,6 +7,7 @@
 from dbt_semantic_interfaces.references import SemanticModelReference
 from metricflow_semantics.dag.id_prefix import StaticIdPrefix
 from metricflow_semantics.dag.mf_dag import DagId
+from metricflow_semantics.mf_logging.lazy_formattable import LazyFormat
 from metricflow_semantics.specs.where_filter.where_filter_spec import WhereFilterSpec
 from metricflow_semantics.sql.sql_join_type import SqlJoinType
 
@@ -176,12 +177,13 @@ def __init__(self, node_data_set_resolver: DataflowPlanNodeOutputDataSetResolver
     def optimize(self, dataflow_plan: DataflowPlan) -> DataflowPlan:  # noqa: D102
         optimized_result: OptimizeBranchResult = dataflow_plan.sink_node.accept(self)
 
-        logger.log(
-            level=self._log_level,
-            msg=f"Optimized:\n\n"
-            f"{dataflow_plan.sink_node.structure_text()}\n\n"
-            f"to:\n\n"
-            f"{optimized_result.optimized_branch.structure_text()}",
+        logger.debug(
+            LazyFormat(
+                lambda: f"Optimized:\n\n"
+                f"{dataflow_plan.sink_node.structure_text()}\n\n"
+                f"to:\n\n"
+                f"{optimized_result.optimized_branch.structure_text()}",
+            ),
         )
 
         return DataflowPlan(
@@ -190,9 +192,11 @@ def optimize(self, dataflow_plan: DataflowPlan) -> DataflowPlan:  # noqa: D102
         )
 
     def _log_visit_node_type(self, node: DataflowPlanNode) -> None:
-        logger.log(
-            level=self._log_level,
-            msg=f"Visiting {node} with initial pushdown state {self._predicate_pushdown_tracker.last_pushdown_state}",
+        logger.debug(
+            LazyFormat(
+                lambda: f"Visiting {node} with initial pushdown state "
+                f"{self._predicate_pushdown_tracker.last_pushdown_state}",
+            ),
         )
 
     def _default_handler(
@@ -300,7 +304,8 @@ def _push_down_where_filters(
             else:
                 filters_left_over.append(filter_spec)
 
-        logger.log(level=self._log_level, msg=f"Filter specs to add:\n{filters_to_apply}")
+        logger.debug(LazyFormat(lambda: f"Filter specs to add:\n{filters_to_apply}"))
+
         applied_filters = frozenset.union(
             *[frozenset(current_pushdown_state.applied_where_filter_specs), frozenset(filters_to_apply)]
         )
@@ -377,20 +382,19 @@ def visit_where_constraint_node(self, node: WhereConstraintNode) -> OptimizeBran
                         pushdown_applied_where_filter_specs=updated_specs,
                     )
                 )
-                logger.log(
-                    level=self._log_level,
-                    msg=(
-                        f"Added applied specs to pushdown state. Added specs:\n\n{node.input_where_specs}\n\n"
+                logger.debug(
+                    LazyFormat(
+                        lambda: f"Added applied specs to pushdown state. Added specs:\n\n{node.input_where_specs}\n\n"
                         + f"Updated pushdown state:\n\n{self._predicate_pushdown_tracker.last_pushdown_state}"
                     ),
                 )
 
             if node.always_apply:
-                logger.log(
-                    level=self._log_level,
-                    msg=(
-                        "Applying original filter spec set based on node-level override directive. Additional specs "
-                        + f"appled:\n{[spec for spec in node.input_where_specs if spec not in filter_specs_to_apply]}"
+                logger.debug(
+                    LazyFormat(
+                        lambda: f"Applying original filter spec set based on node-level override directive. "
+                        f"Additional specs "
+                        f"appled:\n{[spec for spec in node.input_where_specs if spec not in filter_specs_to_apply]}"
                     ),
                 )
                 optimized_node = OptimizeBranchResult(

metricflow/dataflow/optimizer/source_scan/source_scan_optimizer.py

@@ -6,6 +6,7 @@
 
 from metricflow_semantics.dag.id_prefix import StaticIdPrefix
 from metricflow_semantics.dag.mf_dag import DagId
+from metricflow_semantics.mf_logging.lazy_formattable import LazyFormat
 
 from metricflow.dataflow.dataflow_plan import (
     DataflowPlan,
@@ -109,11 +110,8 @@ class SourceScanOptimizer(
     parents.
     """
 
-    def __init__(self) -> None:  # noqa: D107
-        self._log_level = logging.DEBUG
-
     def _log_visit_node_type(self, node: DataflowPlanNode) -> None:
-        logger.log(level=self._log_level, msg=f"Visiting {node}")
+        logger.debug(LazyFormat(lambda: "Visiting {node}"))
 
     def _default_base_output_handler(
         self,
@@ -226,7 +224,7 @@ def visit_combine_aggregated_outputs_node(  # noqa: D102
 
         # Stores the result of running this optimizer on each parent branch separately.
         optimized_parent_branches = []
-        logger.log(level=self._log_level, msg=f"{node} has {len(node.parent_nodes)} parent branches")
+        logger.debug(LazyFormat(lambda: f"{node} has {len(node.parent_nodes)} parent branches"))
 
         # Run the optimizer on the parent branch to handle derived metrics, which are defined recursively in the DAG.
         for parent_branch in node.parent_nodes:
@@ -256,7 +254,7 @@ def visit_combine_aggregated_outputs_node(  # noqa: D102
                     for branch_combination_result in combination_results
                 ]
 
-        logger.log(level=self._log_level, msg=f"Got {len(combined_parent_branches)} branches after combination")
+        logger.debug(lambda: f"Got {len(combined_parent_branches)} branches after combination")
         assert len(combined_parent_branches) > 0
 
         # If we were able to reduce the parent branches of the CombineAggregatedOutputsNode into a single one, there's no need
@@ -289,12 +287,13 @@ def visit_metric_time_dimension_transform_node(  # noqa: D102
     def optimize(self, dataflow_plan: DataflowPlan) -> DataflowPlan:  # noqa: D102
         optimized_result: OptimizeBranchResult = dataflow_plan.sink_node.accept(self)
 
-        logger.log(
-            level=self._log_level,
-            msg=f"Optimized:\n\n"
-            f"{dataflow_plan.sink_node.structure_text()}\n\n"
-            f"to:\n\n"
-            f"{optimized_result.optimized_branch.structure_text()}",
+        logger.debug(
+            LazyFormat(
+                lambda: f"Optimized:\n\n"
+                f"{dataflow_plan.sink_node.structure_text()}\n\n"
+                f"to:\n\n"
+                f"{optimized_result.optimized_branch.structure_text()}",
+            ),
         )
 
         return DataflowPlan(