[Bug] Error during handoff of virtualenv lock

[jhoang-movableink]

Astronomer Cosmos Version

1.10.1

dbt-core version

1.10.5

Versions of dbt adapters

dbt-redshift 1.9.5

LoadMode

AUTOMATIC

ExecutionMode

VIRTUALENV

InvocationMode

None

airflow version

2.10.1

Operating System

Amazon Linux 2023

If a you think it's an UI issue, what browsers are you seeing the problem on?

No response

Deployment

Amazon (AWS) MWAA

Deployment details

No response

What happened?

During handoff on the hold for the virtual environment, an error occurred. I suspect it is due to an improper hand-off of the virtual environment.

This task is downstream of other dbt models. To reduce overhead of re-building the virtual environment, a shared virtual environment was referenced via ExecutionConfig. We found this to be necessary as without a shared virtual environment, tasks were failing due to a heartbeat timeout, and the time required to complete tasks was high due to the number of virtual environments spooled up.

Within this DAG, the task that failed executes in parallel with other dbt models at that step of the transformation.

Relevant log output

[2025-07-28, 21:00:19 UTC] {local_task_job_runner.py:123} ▼ Pre task execution logs
[2025-07-28, 21:00:19 UTC] {taskinstance.py:2612} INFO - Dependencies all met for dep_context=non-requeueable deps ti=<TaskInstance: masked_my_dbt_project.masked_my_dbt_model.test manual__2025-07-28T20:57:17.436682+00:00 [queued]>
[2025-07-28, 21:00:19 UTC] {taskinstance.py:2612} INFO - Dependencies all met for dep_context=requeueable deps ti=<TaskInstance: masked_my_dbt_project.masked_my_dbt_model.test manual__2025-07-28T20:57:17.436682+00:00 [queued]>
[2025-07-28, 21:00:19 UTC] {taskinstance.py:2865} INFO - Starting attempt 1 of 1
[2025-07-28, 21:00:19 UTC] {taskinstance.py:2888} INFO - Executing <Task(DbtTestVirtualenvOperator): masked_my_dbt_model.test> on 2025-07-28 20:57:17.436682+00:00
[2025-07-28, 21:00:19 UTC] {standard_task_runner.py:72} INFO - Started process 22092 to run task
[2025-07-28, 21:00:19 UTC] {standard_task_runner.py:104} INFO - Running: ['airflow', 'tasks', 'run', 'masked_my_dbt_project', 'masked_my_dbt_model.test', 'manual__2025-07-28T20:57:17.436682+00:00', '--job-id', '6952880', '--raw', '--subdir', 'DAGS_FOLDER/masked_my_dbt_project/masked_my_dbt_project.py', '--cfg-path', '/tmp/tmpx02rvwkx']
[2025-07-28, 21:00:19 UTC] {standard_task_runner.py:105} INFO - Job 6952880: Subtask masked_my_dbt_model.test
[2025-07-28, 21:00:20 UTC] {taskinstance.py:3131} INFO - Exporting env vars: AIRFLOW_CTX_DAG_OWNER='airflow' AIRFLOW_CTX_DAG_ID='masked_my_dbt_project' AIRFLOW_CTX_TASK_ID='masked_my_dbt_model.test' AIRFLOW_CTX_EXECUTION_DATE='2025-07-28T20:57:17.436682+00:00' AIRFLOW_CTX_TRY_NUMBER='1' AIRFLOW_CTX_DAG_RUN_ID='manual__2025-07-28T20:57:17.436682+00:00'
[2025-07-28, 21:00:20 UTC] {taskinstance.py:731} ▲▲▲ Log group end
[2025-07-28, 21:00:20 UTC] {baseoperator.py:405} WARNING - DbtTestVirtualenvOperator.execute cannot be called outside TaskInstance!
[2025-07-28, 21:00:20 UTC] {virtualenv.py:120} INFO - Checking if the virtualenv lock /tmp/redshift_rw-venv/cosmos_virtualenv.lock exists
[2025-07-28, 21:00:20 UTC] {virtualenv.py:178} INFO - Checking for running process with PID 22045
[2025-07-28, 21:00:20 UTC] {virtualenv.py:181} INFO - Process 22045 running: True and has the lock /tmp/redshift_rw-venv/cosmos_virtualenv.lock.
[2025-07-28, 21:00:20 UTC] {virtualenv.py:122} INFO - Waiting for virtualenv lock to be released
[2025-07-28, 21:00:21 UTC] {virtualenv.py:178} INFO - Checking for running process with PID 22045
[2025-07-28, 21:00:21 UTC] {virtualenv.py:181} INFO - Process 22045 running: True and has the lock /tmp/redshift_rw-venv/cosmos_virtualenv.lock.
[2025-07-28, 21:00:21 UTC] {virtualenv.py:122} INFO - Waiting for virtualenv lock to be released
[2025-07-28, 21:00:22 UTC] {virtualenv.py:178} INFO - Checking for running process with PID 22045
[2025-07-28, 21:00:22 UTC] {virtualenv.py:181} INFO - Process 22045 running: True and has the lock /tmp/redshift_rw-venv/cosmos_virtualenv.lock.
[2025-07-28, 21:00:22 UTC] {virtualenv.py:122} INFO - Waiting for virtualenv lock to be released
[2025-07-28, 21:00:23 UTC] {virtualenv.py:178} INFO - Checking for running process with PID 22045
[2025-07-28, 21:00:23 UTC] {virtualenv.py:181} INFO - Process 22045 running: True and has the lock /tmp/redshift_rw-venv/cosmos_virtualenv.lock.
[2025-07-28, 21:00:23 UTC] {virtualenv.py:122} INFO - Waiting for virtualenv lock to be released
[2025-07-28, 21:00:24 UTC] {virtualenv.py:178} INFO - Checking for running process with PID 22045
[2025-07-28, 21:00:24 UTC] {virtualenv.py:181} INFO - Process 22045 running: True and has the lock /tmp/redshift_rw-venv/cosmos_virtualenv.lock.
[2025-07-28, 21:00:24 UTC] {virtualenv.py:122} INFO - Waiting for virtualenv lock to be released
[2025-07-28, 21:00:25 UTC] {virtualenv.py:178} INFO - Checking for running process with PID 22045
[2025-07-28, 21:00:25 UTC] {virtualenv.py:181} INFO - Process 22045 running: True and has the lock /tmp/redshift_rw-venv/cosmos_virtualenv.lock.
[2025-07-28, 21:00:25 UTC] {virtualenv.py:122} INFO - Waiting for virtualenv lock to be released
[2025-07-28, 21:00:26 UTC] {virtualenv.py:178} INFO - Checking for running process with PID 22045
[2025-07-28, 21:00:26 UTC] {virtualenv.py:181} INFO - Process 22045 running: True and has the lock /tmp/redshift_rw-venv/cosmos_virtualenv.lock.
[2025-07-28, 21:00:26 UTC] {virtualenv.py:122} INFO - Waiting for virtualenv lock to be released
[2025-07-28, 21:00:27 UTC] {virtualenv.py:178} INFO - Checking for running process with PID 22045
[2025-07-28, 21:00:27 UTC] {virtualenv.py:181} INFO - Process 22045 running: True and has the lock /tmp/redshift_rw-venv/cosmos_virtualenv.lock.
[2025-07-28, 21:00:27 UTC] {virtualenv.py:122} INFO - Waiting for virtualenv lock to be released
[2025-07-28, 21:00:28 UTC] {virtualenv.py:178} INFO - Checking for running process with PID 22045
[2025-07-28, 21:00:28 UTC] {virtualenv.py:181} INFO - Process 22045 running: True and has the lock /tmp/redshift_rw-venv/cosmos_virtualenv.lock.
[2025-07-28, 21:00:28 UTC] {virtualenv.py:122} INFO - Waiting for virtualenv lock to be released
[2025-07-28, 21:00:29 UTC] {virtualenv.py:178} INFO - Checking for running process with PID 22045
[2025-07-28, 21:00:29 UTC] {virtualenv.py:181} INFO - Process 22045 running: True and has the lock /tmp/redshift_rw-venv/cosmos_virtualenv.lock.
[2025-07-28, 21:00:29 UTC] {virtualenv.py:122} INFO - Waiting for virtualenv lock to be released
[2025-07-28, 21:00:30 UTC] {virtualenv.py:178} INFO - Checking for running process with PID 22045
[2025-07-28, 21:00:30 UTC] {virtualenv.py:181} INFO - Process 22045 running: True and has the lock /tmp/redshift_rw-venv/cosmos_virtualenv.lock.
[2025-07-28, 21:00:30 UTC] {virtualenv.py:122} INFO - Waiting for virtualenv lock to be released
[2025-07-28, 21:00:31 UTC] {virtualenv.py:178} INFO - Checking for running process with PID 22045
[2025-07-28, 21:00:31 UTC] {virtualenv.py:181} INFO - Process 22045 running: True and has the lock /tmp/redshift_rw-venv/cosmos_virtualenv.lock.
[2025-07-28, 21:00:31 UTC] {virtualenv.py:122} INFO - Waiting for virtualenv lock to be released
[2025-07-28, 21:00:32 UTC] {virtualenv.py:126} INFO - Acquiring the virtualenv lock
[2025-07-28, 21:00:32 UTC] {virtualenv.py:195} INFO - Acquiring lock at /tmp/redshift_rw-venv/cosmos_virtualenv.lock with pid 22092
[2025-07-28, 21:00:32 UTC] {virtualenv.py:153} INFO - Creating or updating the virtualenv at `/tmp/redshift_rw-venv
[2025-07-28, 21:00:32 UTC] {process_utils.py:186} INFO - Executing cmd: /usr/local/bin/python3.11 -m virtualenv /tmp/redshift_rw-venv --python=python3
[2025-07-28, 21:00:32 UTC] {process_utils.py:190} INFO - Output:
[2025-07-28, 21:00:34 UTC] {process_utils.py:194} INFO - created virtual environment CPython3.11.9.final.0-64 in 1573ms
[2025-07-28, 21:00:34 UTC] {process_utils.py:194} INFO -   creator CPython3Posix(dest=/tmp/redshift_rw-venv, clear=False, no_vcs_ignore=False, global=False)
[2025-07-28, 21:00:34 UTC] {process_utils.py:194} INFO -   seeder FromAppData(download=False, pip=bundle, setuptools=bundle, wheel=bundle, via=copy, app_data_dir=/usr/local/airflow/.local/share/virtualenv)
[2025-07-28, 21:00:34 UTC] {process_utils.py:194} INFO -     added seed packages: MarkupSafe==3.0.2, PyYAML==6.0.2, agate==1.9.1, annotated_types==0.7.0, asn1crypto==1.5.1, attrs==25.3.0, babel==2.17.0, beautifulsoup4==4.13.4, boto3==1.39.14, botocore==1.39.14, certifi==2025.7.14, charset_normalizer==3.4.2, click==8.2.1, colorama==0.4.6, daff==1.4.2, dbt_adapters==1.16.3, dbt_common==1.27.1, dbt_core==1.10.5, dbt_extractor==0.6.0, dbt_postgres==1.9.0, dbt_protos==1.0.348, dbt_redshift==1.9.5, dbt_semantic_interfaces==0.9.0, deepdiff==7.0.1, idna==3.10, importlib_metadata==8.7.0, isodate==0.6.1, jinja2==3.1.6, jmespath==1.0.1, jsonschema==4.25.0, jsonschema_specifications==2025.4.1, leather==0.4.0, lxml==5.4.0, mashumaro==3.14, more_itertools==10.7.0, msgpack==1.1.1, networkx==3.5, ordered_set==4.1.0, packaging==25.0, parsedatetime==2.6, pathspec==0.12.1, pip==25.1.1, protobuf==5.29.5, psycopg2_binary==2.9.10, pydantic==2.11.7, pydantic_core==2.33.2, python_dateutil==2.9.0.post0, python_slugify==8.0.4, pytimeparse==1.1.8, pytz==2025.2, redshift_connector==2.1.8, referencing==0.36.2, requests==2.32.4, rpds_py==0.26.0, s3transfer==0.13.1, scramp==1.4.6, setuptools==80.9.0, six==1.17.0, snowplow_tracker==1.1.0, soupsieve==2.7, sqlparse==0.5.3, text_unidecode==1.3, typing_extensions==4.14.1, typing_inspection==0.4.1, urllib3==2.5.0, wheel==0.45.1, zipp==3.23.0
[2025-07-28, 21:00:34 UTC] {process_utils.py:194} INFO -   activators BashActivator,CShellActivator,FishActivator,NushellActivator,PowerShellActivator,PythonActivator
[2025-07-28, 21:00:34 UTC] {process_utils.py:186} INFO - Executing cmd: /tmp/redshift_rw-venv/bin/pip install dbt-redshift
[2025-07-28, 21:00:34 UTC] {process_utils.py:190} INFO - Output:
[2025-07-28, 21:00:37 UTC] {process_utils.py:194} INFO - Traceback (most recent call last):
[2025-07-28, 21:00:37 UTC] {process_utils.py:194} INFO -   File "/tmp/redshift_rw-venv/bin/pip", line 8, in <module>
[2025-07-28, 21:00:37 UTC] {process_utils.py:194} INFO -   File "/tmp/redshift_rw-venv/lib/python3.11/site-packages/pip/_internal/cli/main.py", line 77, in main
[2025-07-28, 21:00:37 UTC] {process_utils.py:194} INFO -     command = create_command(cmd_name, isolated=("--isolated" in cmd_args))
[2025-07-28, 21:00:37 UTC] {process_utils.py:194} INFO -               ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
[2025-07-28, 21:00:37 UTC] {process_utils.py:194} INFO -   File "/tmp/redshift_rw-venv/lib/python3.11/site-packages/pip/_internal/commands/__init__.py", line 119, in create_command
[2025-07-28, 21:00:37 UTC] {process_utils.py:194} INFO -     module = importlib.import_module(module_path)
[2025-07-28, 21:00:37 UTC] {process_utils.py:194} INFO -              ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
[2025-07-28, 21:00:37 UTC] {process_utils.py:194} INFO -   File "/usr/local/lib/python3.11/importlib/__init__.py", line 126, in import_module
[2025-07-28, 21:00:37 UTC] {process_utils.py:194} INFO -     return _bootstrap._gcd_import(name[level:], package, level)
[2025-07-28, 21:00:37 UTC] {process_utils.py:194} INFO -            ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
[2025-07-28, 21:00:37 UTC] {process_utils.py:194} INFO -   File "<frozen importlib._bootstrap>", line 1204, in _gcd_import
[2025-07-28, 21:00:37 UTC] {process_utils.py:194} INFO -   File "<frozen importlib._bootstrap>", line 1176, in _find_and_load
[2025-07-28, 21:00:37 UTC] {process_utils.py:194} INFO -   File "<frozen importlib._bootstrap>", line 1147, in _find_and_load_unlocked
[2025-07-28, 21:00:37 UTC] {process_utils.py:194} INFO -   File "<frozen importlib._bootstrap>", line 690, in _load_unlocked
[2025-07-28, 21:00:37 UTC] {process_utils.py:194} INFO -   File "<frozen importlib._bootstrap_external>", line 940, in exec_module
[2025-07-28, 21:00:37 UTC] {process_utils.py:194} INFO -   File "<frozen importlib._bootstrap>", line 241, in _call_with_frames_removed
[2025-07-28, 21:00:37 UTC] {process_utils.py:194} INFO -   File "/tmp/redshift_rw-venv/lib/python3.11/site-packages/pip/_internal/commands/install.py", line 11, in <module>
[2025-07-28, 21:00:37 UTC] {process_utils.py:194} INFO -     from pip._vendor.requests.exceptions import InvalidProxyURL
[2025-07-28, 21:00:37 UTC] {process_utils.py:194} INFO -   File "/tmp/redshift_rw-venv/lib/python3.11/site-packages/pip/_vendor/requests/__init__.py", line 43, in <module>
[2025-07-28, 21:00:37 UTC] {process_utils.py:194} INFO -   File "/tmp/redshift_rw-venv/lib/python3.11/site-packages/pip/_vendor/urllib3/__init__.py", line 13, in <module>
[2025-07-28, 21:00:37 UTC] {process_utils.py:194} INFO -   File "/tmp/redshift_rw-venv/lib/python3.11/site-packages/pip/_vendor/urllib3/connectionpool.py", line 12, in <module>
[2025-07-28, 21:00:37 UTC] {process_utils.py:194} INFO - ModuleNotFoundError: No module named 'pip._vendor.urllib3._collections'
[2025-07-28, 21:00:37 UTC] {virtualenv.py:131} INFO - Releasing virtualenv lock
[2025-07-28, 21:00:37 UTC] {virtualenv.py:210} WARNING - Lockfile owned by process of pid 21878, while operator has pid 22092
[2025-07-28, 21:00:37 UTC] {taskinstance.py:3310} ERROR - Task failed with exception
Traceback (most recent call last):
  File "/usr/local/airflow/.local/lib/python3.11/site-packages/airflow/models/taskinstance.py", line 767, in _execute_task
    result = _execute_callable(context=context, **execute_callable_kwargs)
             ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/airflow/.local/lib/python3.11/site-packages/airflow/models/taskinstance.py", line 733, in _execute_callable
    return ExecutionCallableRunner(
           ^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/airflow/.local/lib/python3.11/site-packages/airflow/utils/operator_helpers.py", line 252, in run
    return self.func(*args, **kwargs)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/airflow/.local/lib/python3.11/site-packages/airflow/models/baseoperator.py", line 406, in wrapper
    return func(self, *args, **kwargs)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/airflow/.local/lib/python3.11/site-packages/cosmos/operators/virtualenv.py", line 144, in execute
    output = super().execute(context)
             ^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/airflow/.local/lib/python3.11/site-packages/airflow/models/baseoperator.py", line 406, in wrapper
    return func(self, *args, **kwargs)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/airflow/.local/lib/python3.11/site-packages/cosmos/operators/local.py", line 1078, in execute
    result = self.build_and_run_cmd(context=context, cmd_flags=self.add_cmd_flags())
             ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/airflow/.local/lib/python3.11/site-packages/cosmos/operators/local.py", line 842, in build_and_run_cmd
    result = self.run_command(
             ^^^^^^^^^^^^^^^^^
  File "/usr/local/airflow/.local/lib/python3.11/site-packages/cosmos/operators/virtualenv.py", line 128, in run_command
    self._py_bin = self._prepare_virtualenv()
                   ^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/airflow/.local/lib/python3.11/site-packages/cosmos/operators/virtualenv.py", line 154, in _prepare_virtualenv
    py_bin = prepare_virtualenv(
             ^^^^^^^^^^^^^^^^^^^
  File "/usr/local/airflow/.local/lib/python3.11/site-packages/airflow/utils/python_virtualenv.py", line 119, in prepare_virtualenv
    execute_in_subprocess(pip_cmd)
  File "/usr/local/airflow/.local/lib/python3.11/site-packages/airflow/utils/process_utils.py", line 175, in execute_in_subprocess
    execute_in_subprocess_with_kwargs(cmd, cwd=cwd, env=env)
  File "/usr/local/airflow/.local/lib/python3.11/site-packages/airflow/utils/process_utils.py", line 198, in execute_in_subprocess_with_kwargs
    raise subprocess.CalledProcessError(exit_code, cmd)
subprocess.CalledProcessError: Command '['/tmp/redshift_rw-venv/bin/pip', 'install', 'dbt-redshift']' returned non-zero exit status 1.
[2025-07-28, 21:00:37 UTC] {taskinstance.py:1225} INFO - Marking task as FAILED. dag_id=masked_my_dbt_project, task_id=masked_my_dbt_model.test, run_id=manual__2025-07-28T20:57:17.436682+00:00, execution_date=20250728T205717, start_date=20250728T210019, end_date=20250728T210037
[2025-07-28, 21:00:37 UTC] {taskinstance.py:340} ▼ Post task execution logs
[2025-07-28, 21:00:37 UTC] {standard_task_runner.py:124} ERROR - Failed to execute job 6952880 for task masked_my_dbt_model.test (Command '['/tmp/redshift_rw-venv/bin/pip', 'install', 'dbt-redshift']' returned non-zero exit status 1.; 22092)
Traceback (most recent call last):
  File "/usr/local/airflow/.local/lib/python3.11/site-packages/airflow/task/task_runner/standard_task_runner.py", line 117, in _start_by_fork
    ret = args.func(args, dag=self.dag)
          ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/airflow/.local/lib/python3.11/site-packages/airflow/cli/cli_config.py", line 49, in command
    return func(*args, **kwargs)
           ^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/airflow/.local/lib/python3.11/site-packages/airflow/utils/cli.py", line 115, in wrapper
    return f(*args, **kwargs)
           ^^^^^^^^^^^^^^^^^^
  File "/usr/local/airflow/.local/lib/python3.11/site-packages/airflow/cli/commands/task_command.py", line 483, in task_run
    task_return_code = _run_task_by_selected_method(args, _dag, ti)
                       ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/airflow/.local/lib/python3.11/site-packages/airflow/cli/commands/task_command.py", line 256, in _run_task_by_selected_method
    return _run_raw_task(args, ti)
           ^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/airflow/.local/lib/python3.11/site-packages/airflow/cli/commands/task_command.py", line 341, in _run_raw_task
    return ti._run_raw_task(
           ^^^^^^^^^^^^^^^^^
  File "/usr/local/airflow/.local/lib/python3.11/site-packages/airflow/utils/session.py", line 97, in wrapper
    return func(*args, session=session, **kwargs)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/airflow/.local/lib/python3.11/site-packages/airflow/models/taskinstance.py", line 3004, in _run_raw_task
    return _run_raw_task(
           ^^^^^^^^^^^^^^
  File "/usr/local/airflow/.local/lib/python3.11/site-packages/airflow/models/taskinstance.py", line 273, in _run_raw_task
    TaskInstance._execute_task_with_callbacks(
  File "/usr/local/airflow/.local/lib/python3.11/site-packages/airflow/models/taskinstance.py", line 3158, in _execute_task_with_callbacks
    result = self._execute_task(context, task_orig)
             ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/airflow/.local/lib/python3.11/site-packages/airflow/models/taskinstance.py", line 3182, in _execute_task
    return _execute_task(self, context, task_orig)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/airflow/.local/lib/python3.11/site-packages/airflow/models/taskinstance.py", line 767, in _execute_task
    result = _execute_callable(context=context, **execute_callable_kwargs)
             ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/airflow/.local/lib/python3.11/site-packages/airflow/models/taskinstance.py", line 733, in _execute_callable
    return ExecutionCallableRunner(
           ^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/airflow/.local/lib/python3.11/site-packages/airflow/utils/operator_helpers.py", line 252, in run
    return self.func(*args, **kwargs)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/airflow/.local/lib/python3.11/site-packages/airflow/models/baseoperator.py", line 406, in wrapper
    return func(self, *args, **kwargs)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/airflow/.local/lib/python3.11/site-packages/cosmos/operators/virtualenv.py", line 144, in execute
    output = super().execute(context)
             ^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/airflow/.local/lib/python3.11/site-packages/airflow/models/baseoperator.py", line 406, in wrapper
    return func(self, *args, **kwargs)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/airflow/.local/lib/python3.11/site-packages/cosmos/operators/local.py", line 1078, in execute
    result = self.build_and_run_cmd(context=context, cmd_flags=self.add_cmd_flags())
             ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/airflow/.local/lib/python3.11/site-packages/cosmos/operators/local.py", line 842, in build_and_run_cmd
    result = self.run_command(
             ^^^^^^^^^^^^^^^^^
  File "/usr/local/airflow/.local/lib/python3.11/site-packages/cosmos/operators/virtualenv.py", line 128, in run_command
    self._py_bin = self._prepare_virtualenv()
                   ^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/airflow/.local/lib/python3.11/site-packages/cosmos/operators/virtualenv.py", line 154, in _prepare_virtualenv
    py_bin = prepare_virtualenv(
             ^^^^^^^^^^^^^^^^^^^
  File "/usr/local/airflow/.local/lib/python3.11/site-packages/airflow/utils/python_virtualenv.py", line 119, in prepare_virtualenv
    execute_in_subprocess(pip_cmd)
  File "/usr/local/airflow/.local/lib/python3.11/site-packages/airflow/utils/process_utils.py", line 175, in execute_in_subprocess
    execute_in_subprocess_with_kwargs(cmd, cwd=cwd, env=env)
  File "/usr/local/airflow/.local/lib/python3.11/site-packages/airflow/utils/process_utils.py", line 198, in execute_in_subprocess_with_kwargs
    raise subprocess.CalledProcessError(exit_code, cmd)
subprocess.CalledProcessError: Command '['/tmp/redshift_rw-venv/bin/pip', 'install', 'dbt-redshift']' returned non-zero exit status 1.
[2025-07-28, 21:00:38 UTC] {local_task_job_runner.py:266} INFO - Task exited with return code 1
[2025-07-28, 21:00:38 UTC] {local_task_job_runner.py:245} ▲▲▲ Log group end

How to reproduce

1. Dag was created using DbtDag.
2. ExecutionConfig was defined as such:

ExecutionConfig(
        execution_mode=ExecutionMode.VIRTUALENV,
        virtualenv_dir=Path("/tmp/redshift_rw-venv"),
)

3. operator_args were defined as such:

operator_args = {
    py_requirements=["dbt-redshift"],
    callback=upload_to_aws_s3,
    callback_args={
        "aws_conn_id": "airflow_s3_connection_id",
        "bucket_name": "valid_s3_bucket",
    }
}

Anything else :)?

Problem doesn't seem to be consistent. Upon re-execution of the task, the model completed successfully. Given that it's an issue during execution of pip install dbt-redshift, it seems very likely it is due to how the virtual environment hand-off is being managed.

Are you willing to submit PR?

• Yes I am willing to submit a PR!

Contact Details

No response

[tatiana]

@jhoang-movableink Thanks for reporting this!
Is there any particular reason why you're running using ExecutionMode.VIRTUALENV instead of ExecutionMode.LOCAL, as explained in the docs?

[jhoang-movableink]

Hi @tatiana - Good question - unfortunately, we have some custom packages that caused dependency issues that don't allow us to run with ExecutionMode.LOCAL.

[tatiana]

@jhoang-movableink, if you follow the instructions described in: https://astronomer.github.io/astronomer-cosmos/getting_started/mwaa.html, you'd have isolation between the dbt dependencies and the Airflow dependencies, and they would not conflict.

The example describes the steps for you to pre-create a virtualenv in your base image, install dbt dependencies in that virtualenv, and tell Cosmos the path to this dbt binary by defining the dbt_executable_path to the pre-installed dbt binary. Via This is one of the two possible behaviours of ExecutionMode.LOCAL.

If you set ExecutionMode.VIRTUALENV, Cosmos will be the one creating and managing your virtualenv, which is more costly from a task execution perspective and more error-prone.