Fix(cicd): Better handle model failures in GitHub check output

Author: erindru

sqlmesh/__init__.py

@@ -197,6 +197,10 @@ def configure_logging(
     level = logging.DEBUG if debug else logging.INFO
     logger.setLevel(level)
 
+    if debug:
+        # Remove noisy snowflake connector logs that are not useful for users
+        logging.getLogger("snowflake.connector").setLevel(logging.INFO)
+
     if write_to_stdout:
         stdout_handler = logging.StreamHandler(sys.stdout)
         stdout_handler.setFormatter(CustomFormatter())

sqlmesh/core/console.py

@@ -3184,6 +3184,12 @@ def log_error(self, message: str) -> None:
 
     def log_warning(self, short_message: str, long_message: t.Optional[str] = None) -> None:
         logger.warning(long_message or short_message)
+
+        if not short_message.endswith("\n"):
+            short_message += (
+                "\n"  # so that the closing ``` ends up on a newline which is important for GitHub
+            )
+
         self._print(f"```\n\\[WARNING] {short_message}```\n\n")
 
     def _print(self, value: t.Any, **kwargs: t.Any) -> None:

sqlmesh/integrations/github/cicd/command.py

@@ -22,6 +22,7 @@
 @click.option(
     "--token",
     type=str,
+    envvar="GITHUB_TOKEN",
     help="The Github Token to be used. Pass in `${{ secrets.GITHUB_TOKEN }}` if you want to use the one created by Github actions",
 )
 @click.pass_context

sqlmesh/integrations/github/cicd/controller.py

@@ -11,6 +11,7 @@
 import unittest
 from enum import Enum
 from typing import List
+from pathlib import Path
 
 import requests
 from hyperscript import Element, h
@@ -28,18 +29,19 @@
     SnapshotTableInfo,
     format_intervals,
 )
+from sqlglot.errors import SqlglotError
 from sqlmesh.core.user import User
 from sqlmesh.core.config import Config
 from sqlmesh.integrations.github.cicd.config import GithubCICDBotConfig
 from sqlmesh.utils import word_characters_only, Verbosity
-from sqlmesh.utils.concurrency import NodeExecutionFailedError
 from sqlmesh.utils.date import now
 from sqlmesh.utils.errors import (
     CICDBotError,
     NoChangesPlanError,
     PlanError,
     UncategorizedPlanError,
     LinterError,
+    SQLMeshError,
 )
 from sqlmesh.utils.pydantic import PydanticModel
 
@@ -283,7 +285,7 @@ class GithubController:
 
     def __init__(
         self,
-        paths: t.Union[str, t.Iterable[str]],
+        paths: t.Union[Path, t.Iterable[Path]],
         token: str,
         config: t.Optional[t.Union[Config, str]] = None,
         event: t.Optional[GithubEvent] = None,
@@ -307,10 +309,13 @@ def __init__(
             raise CICDBotError("Console must be a markdown console.")
         self._console = t.cast(MarkdownConsole, get_console())
 
+        from github.Consts import DEFAULT_BASE_URL
+        from github.Auth import Token
+
         self._client: Github = client or Github(
-            base_url=os.environ["GITHUB_API_URL"],
-            login_or_token=self._token,
+            base_url=os.environ.get("GITHUB_API_URL", DEFAULT_BASE_URL), auth=Token(self._token)
         )
+
         self._repo: Repository = self._client.get_repo(
             self._event.pull_request_info.full_repo_path, lazy=True
         )
@@ -328,6 +333,9 @@ def __init__(
         logger.debug(f"Approvers: {', '.join(self._approvers)}")
         self._context: Context = Context(paths=self._paths, config=self.config)
 
+        # Bot config needs the context to be initialized
+        logger.debug(f"Bot config: {self.bot_config.json(indent=2)}")
+
     @property
     def deploy_command_enabled(self) -> bool:
         return self.bot_config.enable_deploy_command
@@ -433,7 +441,6 @@ def bot_config(self) -> GithubCICDBotConfig:
         bot_config = self._context.config.cicd_bot or GithubCICDBotConfig(
             auto_categorize_changes=self._context.auto_categorize_changes
         )
-        logger.debug(f"Bot config: {bot_config.json(indent=2)}")
         return bot_config
 
     @property
@@ -454,8 +461,11 @@ def _append_output(cls, key: str, value: str) -> None:
         Appends the given key/value to output so they can be read by following steps
         """
         logger.debug(f"Setting output. Key: {key}, Value: {value}")
-        with open(os.environ["GITHUB_OUTPUT"], "a", encoding="utf-8") as fh:
-            print(f"{key}={value}", file=fh)
+
+        # GitHub Actions sets this environment variable
+        if output_file := os.environ.get("GITHUB_OUTPUT"):
+            with open(output_file, "a", encoding="utf-8") as fh:
+                print(f"{key}={value}", file=fh)
 
     def get_plan_summary(self, plan: Plan) -> str:
         try:
@@ -637,15 +647,31 @@ def _update_check(
         if text:
             kwargs["output"]["text"] = text
         logger.debug(f"Updating check with kwargs: {kwargs}")
-        if name in self._check_run_mapping:
-            logger.debug(f"Found check run in mapping so updating it. Name: {name}")
-            check_run = self._check_run_mapping[name]
-            check_run.edit(
-                **{k: v for k, v in kwargs.items() if k not in ("name", "head_sha", "started_at")}
-            )
+
+        if self.running_in_github_actions:
+            # Only make the API call to update the checks if we are running within GitHub Actions
+            # One very annoying limitation of the Pull Request Checks API is that its only available to GitHub Apps
+            # and not personal access tokens, which makes it unable to be utilized during local development
+            if name in self._check_run_mapping:
+                logger.debug(f"Found check run in mapping so updating it. Name: {name}")
+                check_run = self._check_run_mapping[name]
+                check_run.edit(
+                    **{
+                        k: v
+                        for k, v in kwargs.items()
+                        if k not in ("name", "head_sha", "started_at")
+                    }
+                )
+            else:
+                logger.debug(f"Did not find check run in mapping so creating it. Name: {name}")
+                self._check_run_mapping[name] = self._repo.create_check_run(**kwargs)
         else:
-            logger.debug(f"Did not find check run in mapping so creating it. Name: {name}")
-            self._check_run_mapping[name] = self._repo.create_check_run(**kwargs)
+            # Output the summary using print() so the newlines are resolved and the result can easily
+            # be disambiguated from the rest of the console output and copy+pasted into a Markdown renderer
+            print(
+                f"---CHECK OUTPUT START: {kwargs['output']['title']} ---\n{kwargs['output']['summary']}\n---CHECK OUTPUT END---\n"
+            )
+
         if conclusion:
             self._append_output(
                 word_characters_only(name.replace("SQLMesh - ", "").lower()), conclusion.value
@@ -890,15 +916,21 @@ def conclusion_handler(
                 else:
                     skip_reason = "A prior stage failed resulting in skipping PR creation."
 
+                if not skip_reason and exception:
+                    logger.debug(
+                        f"Got {type(exception).__name__}. Stack trace: " + traceback.format_exc()
+                    )
+
                 captured_errors = self._console.consume_captured_errors()
                 if captured_errors:
                     logger.debug(f"Captured errors: {captured_errors}")
                     failure_msg = f"**Errors:**\n{captured_errors}\n"
-                elif isinstance(exception, NodeExecutionFailedError):
-                    logger.debug(
-                        "Got Node Execution Failed Error. Stack trace: " + traceback.format_exc()
-                    )
-                    failure_msg = f"Node `{exception.node.name}` failed to apply.\n\n**Stack Trace:**\n```\n{traceback.format_exc()}\n```"
+                elif isinstance(exception, PlanError):
+                    failure_msg = f"Plan application failed.\n\n{self._console.captured_output}"
+                elif isinstance(exception, (SQLMeshError, SqlglotError, ValueError)):
+                    # this logic is taken from the global error handler attached to the CLI, which uses `click.echo()` to output the message
+                    # so cant be re-used here because it bypasses the Console
+                    failure_msg = f"**Error:** {str(exception)}"
                 else:
                     logger.debug(
                         "Got unexpected error. Error Type: "
@@ -909,7 +941,7 @@ def conclusion_handler(
                     failure_msg = f"This is an unexpected error.\n\n**Exception:**\n```\n{traceback.format_exc()}\n```"
                 conclusion_to_summary = {
                     GithubCheckConclusion.SKIPPED: f":next_track_button: Skipped creating or updating PR Environment `{self.pr_environment_name}`. {skip_reason}",
-                    GithubCheckConclusion.FAILURE: f":x: Failed to create or update PR Environment `{self.pr_environment_name}`.\n{failure_msg}",
+                    GithubCheckConclusion.FAILURE: f":x: Failed to create or update PR Environment `{self.pr_environment_name}`.\n\n{failure_msg}",
                     GithubCheckConclusion.CANCELLED: f":stop_sign: Cancelled creating or updating PR Environment `{self.pr_environment_name}`",
                     GithubCheckConclusion.ACTION_REQUIRED: f":warning: Action Required to create or update PR Environment `{self.pr_environment_name}`. There are likely uncateogrized changes. Run `plan` locally to apply these changes. If you want the bot to automatically categorize changes, then check documentation (https://sqlmesh.readthedocs.io/en/stable/integrations/github/) for more information.",
                 }
@@ -1054,3 +1086,7 @@ def _chunk_up_api_message(self, message: str) -> t.List[str]:
             message_encoded[i : i + self.MAX_BYTE_LENGTH].decode("utf-8", "ignore")
             for i in range(0, len(message_encoded), self.MAX_BYTE_LENGTH)
         ]
+
+    @property
+    def running_in_github_actions(self) -> bool:
+        return os.environ.get("GITHUB_ACTIONS", None) == "true"

…sts/integrations/github/cicd/fixtures.py …sts/integrations/github/cicd/conftest.pytests/integrations/github/cicd/fixtures.py renamed to tests/integrations/github/cicd/conftest.py tests/integrations/github/cicd/fixtures.py renamed to tests/integrations/github/cicd/conftest.py

@@ -2,6 +2,7 @@
 
 import pytest
 from pytest_mock.plugin import MockerFixture
+from pathlib import Path
 
 from sqlmesh.core.config import Config
 from sqlmesh.core.console import set_console, get_console, MarkdownConsole
@@ -13,6 +14,7 @@
     PullRequestInfo,
 )
 from sqlmesh.utils import AttributeDict
+from sqlglot.helper import ensure_list
 
 
 @pytest.fixture
@@ -59,17 +61,28 @@ def _make_function(username: str, state: str, **kwargs) -> PullRequestReview:
 
 
 @pytest.fixture
-def make_controller(mocker: MockerFixture, copy_to_temp_path: t.Callable) -> t.Callable:
+def sqlmesh_repo_root_path() -> Path:
+    return next(p for p in Path(__file__).parents if str(p).endswith("/tests")).parent
+
+
+@pytest.fixture
+def make_controller(
+    mocker: MockerFixture,
+    copy_to_temp_path: t.Callable,
+    monkeypatch: pytest.MonkeyPatch,
+    sqlmesh_repo_root_path: Path,
+) -> t.Callable:
     from github import Github
 
     def _make_function(
-        event_path: t.Union[str, t.Dict],
+        event_path: t.Union[str, Path, t.Dict],
         client: Github,
         *,
         merge_state_status: MergeStateStatus = MergeStateStatus.CLEAN,
         bot_config: t.Optional[GithubCICDBotConfig] = None,
         mock_out_context: bool = True,
         config: t.Optional[t.Union[Config, str]] = None,
+        paths: t.Optional[t.Union[Path, t.List[Path]]] = None,
     ) -> GithubController:
         if mock_out_context:
             mocker.patch("sqlmesh.core.context.Context.apply", mocker.MagicMock())
@@ -85,7 +98,23 @@ def _make_function(
                 bot_config,
             )
 
-        paths = copy_to_temp_path("examples/sushi")
+        if paths is None:
+            paths = copy_to_temp_path(sqlmesh_repo_root_path / "examples" / "sushi")
+
+        paths = ensure_list(paths)
+
+        if isinstance(event_path, str):
+            # resolve relative event_path references to absolute so they dont get affected by chdir() below
+            as_path = Path(event_path)
+            if not as_path.is_absolute():
+                event_path = sqlmesh_repo_root_path / as_path
+
+        # set the current working directory to the temp path so that config references to eg duckdb "db.db"
+        # get created in the temp path and not in the SQLMesh repo root path that the tests are triggered from
+        monkeypatch.chdir(paths[0])
+
+        # make the tests think they are running in GitHub Actions
+        monkeypatch.setenv("GITHUB_ACTIONS", "true")
 
         orig_console = get_console()
         try:
@@ -96,12 +125,13 @@ def _make_function(
                 token="abc",
                 event=(
                     GithubEvent.from_path(event_path)
-                    if isinstance(event_path, str)
+                    if isinstance(event_path, (str, Path))
                     else GithubEvent.from_obj(event_path)
                 ),
                 client=client,
                 config=config,
             )
+
         finally:
             set_console(orig_console)
 

tests/integrations/github/cicd/test_github_commands.py

@@ -18,7 +18,6 @@
 )
 from sqlmesh.utils.errors import ConflictingPlanError, PlanError, TestError, CICDBotError
 
-pytest_plugins = ["tests.integrations.github.cicd.fixtures"]
 pytestmark = [
     pytest.mark.github,
     pytest.mark.slow,

tests/integrations/github/cicd/test_github_controller.py

@@ -19,9 +19,8 @@
     GithubCheckStatus,
     MergeStateStatus,
 )
-from tests.integrations.github.cicd.fixtures import MockIssueComment
+from tests.integrations.github.cicd.conftest import MockIssueComment
 
-pytest_plugins = ["tests.integrations.github.cicd.fixtures"]
 pytestmark = pytest.mark.github
 
 github_controller_approvers_params = [

tests/integrations/github/cicd/test_github_event.py

@@ -1,6 +1,5 @@
 import pytest
 
-pytest_plugins = ["tests.integrations.github.cicd.fixtures"]
 pytestmark = pytest.mark.github
 
 

tests/integrations/github/cicd/test_integration.py

@@ -23,10 +23,9 @@
     GithubCheckStatus,
     GithubController,
 )
-from sqlmesh.utils.errors import CICDBotError
-from tests.integrations.github.cicd.fixtures import MockIssueComment
+from sqlmesh.utils.errors import CICDBotError, SQLMeshError
+from tests.integrations.github.cicd.conftest import MockIssueComment
 
-pytest_plugins = ["tests.integrations.github.cicd.fixtures"]
 pytestmark = [
     pytest.mark.slow,
     pytest.mark.github,
@@ -1502,10 +1501,9 @@ def test_error_msg_when_applying_plan_with_bug(
     assert GithubCheckStatus(pr_checks_runs[2]["status"]).is_completed
     assert GithubCheckConclusion(pr_checks_runs[2]["conclusion"]).is_failure
     assert pr_checks_runs[2]["output"]["title"] == "PR Virtual Data Environment: hello_world_2"
-    assert (
-        'Binder Error: Referenced column "non_existing_col" not found in FROM clause!'
-        in pr_checks_runs[2]["output"]["summary"]
-    )
+    summary = pr_checks_runs[2]["output"]["summary"].replace("\n", "")
+    assert 'Failed models  **"memory"."sushi"."waiter_revenue_by_day"**' in summary
+    assert 'Binder Error: Referenced column "non_existing_col" not found in FROM clause!' in summary
 
     assert "SQLMesh - Prod Plan Preview" in controller._check_run_mapping
     prod_plan_preview_checks_runs = controller._check_run_mapping[
@@ -2129,3 +2127,56 @@ def test_has_required_approval_but_not_base_branch(
             output
             == "run_unit_tests=success\nhas_required_approval=success\ncreated_pr_environment=true\npr_environment_name=hello_world_2\npr_environment_synced=success\nprod_plan_preview=success\n"
         )
+
+
+def test_unexpected_error_is_handled(
+    github_client,
+    make_controller,
+    make_mock_check_run,
+    make_mock_issue_comment,
+    mocker: MockerFixture,
+):
+    """
+    Scenario:
+    - Plan throws a SQLMeshError due to a migration version mismatch
+    - Outcome should be a nice error like the CLI gives and not a stack trace
+    """
+
+    mock_repo = github_client.get_repo()
+    mock_repo.create_check_run = mocker.MagicMock(
+        side_effect=lambda **kwargs: make_mock_check_run(**kwargs)
+    )
+
+    created_comments: t.List[MockIssueComment] = []
+    mock_issue = mock_repo.get_issue()
+    mock_issue.create_comment = mocker.MagicMock(
+        side_effect=lambda comment: make_mock_issue_comment(
+            comment=comment, created_comments=created_comments
+        )
+    )
+
+    controller = make_controller(
+        "tests/fixtures/github/pull_request_synchronized.json",
+        github_client,
+        bot_config=GithubCICDBotConfig(),
+        mock_out_context=True,
+    )
+    assert isinstance(controller, GithubController)
+
+    assert isinstance(controller._context.apply, mocker.MagicMock)
+    controller._context.apply.side_effect = SQLMeshError(
+        "SQLGlot (local) is using version 'X' which is ahead of 'Y' (remote). Please run a migration"
+    )
+
+    command._update_pr_environment(controller)
+
+    assert "SQLMesh - PR Environment Synced" in controller._check_run_mapping
+    pr_checks_runs = controller._check_run_mapping["SQLMesh - PR Environment Synced"].all_kwargs  # type: ignore
+    assert pr_checks_runs[1]["output"]["title"] == "PR Virtual Data Environment: hello_world_2"
+    summary = pr_checks_runs[1]["output"]["summary"]
+    assert (
+        "**Error:** SQLGlot (local) is using version 'X' which is ahead of 'Y' (remote). Please run a migration"
+        in pr_checks_runs[1]["output"]["summary"]
+    )
+    assert "SQLMeshError" not in summary
+    assert "Traceback (most recent call last)" not in summary