Fix(dbt): Use the info to control logging for dbt log builtin (#5140)

Author: themisvaltinos

sqlmesh/dbt/builtin.py

@@ -14,6 +14,7 @@
 from ruamel.yaml import YAMLError
 from sqlglot import Dialect
 
+from sqlmesh.core.console import get_console
 from sqlmesh.core.engine_adapter import EngineAdapter
 from sqlmesh.core.snapshot.definition import DeployabilityIndex
 from sqlmesh.dbt.adapter import BaseAdapter, ParsetimeAdapter, RuntimeAdapter
@@ -170,7 +171,13 @@ def env_var(name: str, default: t.Optional[str] = None) -> t.Optional[str]:
 
 
 def log(msg: str, info: bool = False) -> str:
-    logger.debug(msg)
+    if info:
+        # Write to both log file and stdout
+        logger.info(msg)
+        get_console().log_status_update(msg)
+    else:
+        logger.debug(msg)
+
     return ""
 
 

tests/dbt/test_transformation.py

@@ -854,13 +854,40 @@ def test_logging(sushi_test_project: Project, runtime_renderer: t.Callable):
     renderer = runtime_renderer(context, engine_adapter=engine_adapter)
 
     logger = logging.getLogger("sqlmesh.dbt.builtin")
-    with patch.object(logger, "debug") as mock_logger:
-        assert renderer('{{ log("foo") }}') == ""
-    assert "foo" in mock_logger.call_args[0][0]
 
-    with patch.object(logger, "debug") as mock_logger:
+    # Test log with info=False (default), should only log to file with debug and not to console
+    with (
+        patch.object(logger, "debug") as mock_debug,
+        patch.object(logger, "info") as mock_info,
+        patch.object(get_console(), "log_status_update") as mock_console,
+    ):
+        assert renderer('{{ log("foo") }}') == ""
+        mock_debug.assert_called_once()
+        assert "foo" in mock_debug.call_args[0][0]
+        mock_info.assert_not_called()
+        mock_console.assert_not_called()
+
+    # Test log with info=True, should log to info and also call log_status_update
+    with (
+        patch.object(logger, "debug") as mock_debug,
+        patch.object(logger, "info") as mock_info,
+        patch.object(get_console(), "log_status_update") as mock_console,
+    ):
+        assert renderer('{{ log("output to be logged with info", info=true) }}') == ""
+        mock_info.assert_called_once()
+        assert "output to be logged with info" in mock_info.call_args[0][0]
+        mock_debug.assert_not_called()
+        mock_console.assert_called_once()
+        assert "output to be logged with info" in mock_console.call_args[0][0]
+
+    # Test print function as well, should use debug
+    with (
+        patch.object(logger, "debug") as mock_logger,
+        patch.object(get_console(), "log_status_update") as mock_console,
+    ):
         assert renderer('{{ print("bar") }}') == ""
-    assert "bar" in mock_logger.call_args[0][0]
+        assert "bar" in mock_logger.call_args[0][0]
+        mock_console.assert_not_called()
 
 
 @pytest.mark.xdist_group("dbt_manifest")