From 6ceb7f2410bb848d9bb8f1a4d3ba3eadea82c895 Mon Sep 17 00:00:00 2001 From: davidsteinar Date: Fri, 31 May 2024 14:22:40 +0200 Subject: [PATCH] Improve error logging in DbtLocalBaseOperator (#1004) Improve error logging when the `dbt` command returns a non-zero exit code. Instead of raising an `AirflowException` with the full output, log the output using the logger and then raise the exception with a concise error message. This makes the dbt output more readable and not in a single line as AirflowException logs message in a single line, and it can get very long. closes #1003 --------- Co-authored-by: David Steinar Asgrimsson Co-authored-by: pre-commit-ci[bot] <66853113+pre-commit-ci[bot]@users.noreply.github.com> --- cosmos/operators/local.py | 6 ++---- tests/operators/test_local.py | 20 ++++++++++++++++++++ 2 files changed, 22 insertions(+), 4 deletions(-) diff --git a/cosmos/operators/local.py b/cosmos/operators/local.py index 1104b43fb..c62f708e8 100644 --- a/cosmos/operators/local.py +++ b/cosmos/operators/local.py @@ -179,10 +179,8 @@ def handle_exception_subprocess(self, result: FullOutputSubprocessResult) -> Non if self.skip_exit_code is not None and result.exit_code == self.skip_exit_code: raise AirflowSkipException(f"dbt command returned exit code {self.skip_exit_code}. Skipping.") elif result.exit_code != 0: - raise AirflowException( - f"dbt command failed. The command returned a non-zero exit code {result.exit_code}. Details: ", - *result.full_output, - ) + logger.error("\n".join(result.full_output)) + raise AirflowException(f"dbt command failed. The command returned a non-zero exit code {result.exit_code}.") def handle_exception_dbt_runner(self, result: dbtRunnerResult) -> None: """dbtRunnerResult has an attribute `success` that is False if the command failed.""" diff --git a/tests/operators/test_local.py b/tests/operators/test_local.py index 14ed66027..5513b1c4b 100644 --- a/tests/operators/test_local.py +++ b/tests/operators/test_local.py @@ -23,6 +23,7 @@ parse_number_of_warnings_dbt_runner, parse_number_of_warnings_subprocess, ) +from cosmos.hooks.subprocess import FullOutputSubprocessResult from cosmos.operators.local import ( DbtBuildLocalOperator, DbtDocsAzureStorageLocalOperator, @@ -914,3 +915,22 @@ def test_dbt_local_operator_on_kill_sigterm(mock_send_sigterm) -> None: dbt_base_operator.on_kill() mock_send_sigterm.assert_called_once() + + +def test_handle_exception_subprocess(caplog): + """ + Test the handle_exception_subprocess method of the DbtLocalBaseOperator class for non-zero dbt exit code. + """ + operator = ConcreteDbtLocalBaseOperator( + profile_config=None, + task_id="my-task", + project_dir="my/dir", + ) + result = FullOutputSubprocessResult(exit_code=1, output="test", full_output=["n" * n for n in range(1, 1000)]) + + caplog.set_level(logging.ERROR) + # Test when exit_code is non-zero + with pytest.raises(AirflowException) as err_context: + operator.handle_exception_subprocess(result) + assert len(str(err_context.value)) < 100 # Ensure the error message is not too long + assert len(caplog.text) > 1000 # Ensure the log message is not truncated