[Bug] can not process DAG and not have error log

[xianzheTM]

Astronomer Cosmos Version

1.10.2

dbt-core version

1.8.9

Versions of dbt adapters

Athena 1.8.4

LoadMode

DBT_LS

ExecutionMode

LOCAL

InvocationMode

None

airflow version

2.11.0

Operating System

debian 12

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

No response

Deployment

Docker-Compose

Deployment details

# Licensed to the Apache Software Foundation (ASF) under one
# or more contributor license agreements.  See the NOTICE file
# distributed with this work for additional information
# regarding copyright ownership.  The ASF licenses this file
# to you under the Apache License, Version 2.0 (the
# "License"); you may not use this file except in compliance
# with the License.  You may obtain a copy of the License at
#
#   http://www.apache.org/licenses/LICENSE-2.0
#
# Unless required by applicable law or agreed to in writing,
# software distributed under the License is distributed on an
# "AS IS" BASIS, WITHOUT WARRANTIES OR CONDITIONS OF ANY
# KIND, either express or implied.  See the License for the
# specific language governing permissions and limitations
# under the License.
#

# Basic Airflow cluster configuration for CeleryExecutor with Redis and PostgreSQL.
#
# WARNING: This configuration is for local development. Do not use it in a production deployment.
#
# This configuration supports basic configuration using environment variables or an .env file
# The following variables are supported:
#
# AIRFLOW_IMAGE_NAME           - Docker image name used to run Airflow.
#                                Default: apache/airflow:2.11.0
# AIRFLOW_UID                  - User ID in Airflow containers
#                                Default: 50000
# AIRFLOW_PROJ_DIR             - Base path to which all the files will be volumed.
#                                Default: .
# Those configurations are useful mostly in case of standalone testing/running Airflow in test/try-out mode
#
# _AIRFLOW_WWW_USER_USERNAME   - Username for the administrator account (if requested).
#                                Default: airflow
# _AIRFLOW_WWW_USER_PASSWORD   - Password for the administrator account (if requested).
#                                Default: airflow
# _PIP_ADDITIONAL_REQUIREMENTS - Additional PIP requirements to add when starting all containers.
#                                Use this option ONLY for quick checks. Installing requirements at container
#                                startup is done EVERY TIME the service is started.
#                                A better way is to build a custom image or extend the official image
#                                as described in https://airflow.apache.org/docs/docker-stack/build.html.
#                                Default: ''
#
# Feel free to modify this file to suit your needs.
---
x-airflow-common:
  &airflow-common
  # Use a custom image that bakes in dbt + cosmos.
  # Build context is repo root containing the Dockerfile.
  build: .
  image: airflow-cosmos-local:2.11.0
  environment:
    &airflow-common-env
    AIRFLOW__CORE__EXECUTOR: CeleryExecutor
    AIRFLOW__DATABASE__SQL_ALCHEMY_CONN: postgresql+psycopg2://airflow:airflow@postgres/airflow
    AIRFLOW__CELERY__RESULT_BACKEND: db+postgresql://airflow:airflow@postgres/airflow
    AIRFLOW__CELERY__BROKER_URL: redis://:@redis:6379/0
    AIRFLOW__CORE__FERNET_KEY: ''
    AIRFLOW__CORE__DAGS_ARE_PAUSED_AT_CREATION: 'true'
    AIRFLOW__CORE__LOAD_EXAMPLES: 'true'
    AIRFLOW__API__AUTH_BACKENDS: 'airflow.api.auth.backend.basic_auth,airflow.api.auth.backend.session'
    DBT_PROFILES_DIR: /opt/airflow/dbt
    PIP_INDEX_URL: https://pypi.tuna.tsinghua.edu.cn/simple
    PIP_TIMEOUT: '120'
    AIRFLOW__CORE__DAGBAG_IMPORT_TIMEOUT: '300'
    # yamllint disable rule:line-length
    # Use simple http server on scheduler for health checks
    # See https://airflow.apache.org/docs/apache-airflow/stable/administration-and-deployment/logging-monitoring/check-health.html#scheduler-health-check-server
    # yamllint enable rule:line-length
    AIRFLOW__SCHEDULER__ENABLE_HEALTH_CHECK: 'true'
    # 日志配置
    AIRFLOW__LOGGING__LOGGING_LEVEL: INFO
    AIRFLOW__LOGGING__FAB_LOGGING_LEVEL: WARN
    AIRFLOW__LOGGING__BASE_LOG_FOLDER: /opt/airflow/logs
    AIRFLOW__LOGGING__REMOTE_LOGGING: 'false'
    AIRFLOW__LOGGING__REMOTE_BASE_LOG_FOLDER: ''
    AIRFLOW__LOGGING__REMOTE_LOG_CONN_ID: ''
    AIRFLOW__LOGGING__ENCRYPT_S3_LOGS: 'false'
    # WARNING: Use _PIP_ADDITIONAL_REQUIREMENTS option ONLY for a quick checks
    # for other purpose (development, test and especially production usage) build/extend Airflow image.
    _PIP_ADDITIONAL_REQUIREMENTS: ${_PIP_ADDITIONAL_REQUIREMENTS:-}
    # The following line can be used to set a custom config file, stored in the local config folder
    # If you want to use it, outcomment it and replace airflow.cfg with the name of your config file
    AIRFLOW_CONFIG: '/opt/airflow/config/airflow.cfg'
  volumes:
    - ${AIRFLOW_PROJ_DIR:-.}/dags:/opt/airflow/dags
    - ${AIRFLOW_PROJ_DIR:-.}/logs:/opt/airflow/logs
    - ${AIRFLOW_PROJ_DIR:-.}/config:/opt/airflow/config
    - ${AIRFLOW_PROJ_DIR:-.}/plugins:/opt/airflow/plugins
    - /home/leiyang/work/unified-data-all/unified-data-dbt:/opt/airflow/dbt
    - /home/leiyang/.aws:/home/airflow/.aws:ro
  user: "${AIRFLOW_UID:-50000}:0"
  depends_on:
    &airflow-common-depends-on
    redis:
      condition: service_healthy
    postgres:
      condition: service_healthy

services:
  postgres:
    image: postgres:13
    environment:
      POSTGRES_USER: airflow
      POSTGRES_PASSWORD: airflow
      POSTGRES_DB: airflow
    volumes:
      - postgres-db-volume:/var/lib/postgresql/data
    healthcheck:
      test: ["CMD", "pg_isready", "-U", "airflow"]
      interval: 10s
      retries: 5
      start_period: 5s
    restart: always

  redis:
    # Redis is limited to 7.2-bookworm due to licencing change
    # https://redis.io/blog/redis-adopts-dual-source-available-licensing/
    image: redis:7.2-bookworm
    expose:
      - 6379
    healthcheck:
      test: ["CMD", "redis-cli", "ping"]
      interval: 10s
      timeout: 30s
      retries: 50
      start_period: 30s
    restart: always

  airflow-webserver:
    <<: *airflow-common
    command: webserver
    ports:
      - "8080:8080"
    healthcheck:
      test: ["CMD", "curl", "--fail", "http://localhost:8080/health"]
      interval: 30s
      timeout: 10s
      retries: 5
      start_period: 30s
    restart: always
    depends_on:
      <<: *airflow-common-depends-on
      airflow-init:
        condition: service_completed_successfully

  airflow-scheduler:
    <<: *airflow-common
    command: scheduler
    healthcheck:
      test: ["CMD", "curl", "--fail", "http://localhost:8974/health"]
      interval: 30s
      timeout: 10s
      retries: 5
      start_period: 30s
    restart: always
    depends_on:
      <<: *airflow-common-depends-on
      airflow-init:
        condition: service_completed_successfully

  airflow-worker:
    <<: *airflow-common
    command: celery worker
    healthcheck:
      # yamllint disable rule:line-length
      test:
        - "CMD-SHELL"
        - 'celery --app airflow.providers.celery.executors.celery_executor.app inspect ping -d "celery@$${HOSTNAME}" || celery --app airflow.executors.celery_executor.app inspect ping -d "celery@$${HOSTNAME}"'
      interval: 30s
      timeout: 10s
      retries: 5
      start_period: 30s
    environment:
      <<: *airflow-common-env
      # Required to handle warm shutdown of the celery workers properly
      # See https://airflow.apache.org/docs/docker-stack/entrypoint.html#signal-propagation
      DUMB_INIT_SETSID: "0"
    restart: always
    depends_on:
      <<: *airflow-common-depends-on
      airflow-init:
        condition: service_completed_successfully

  airflow-triggerer:
    <<: *airflow-common
    command: triggerer
    healthcheck:
      test: ["CMD-SHELL", 'airflow jobs check --job-type TriggererJob --hostname "$${HOSTNAME}"']
      interval: 30s
      timeout: 10s
      retries: 5
      start_period: 30s
    restart: always
    depends_on:
      <<: *airflow-common-depends-on
      airflow-init:
        condition: service_completed_successfully

  airflow-init:
    <<: *airflow-common
    entrypoint: /bin/bash
    # yamllint disable rule:line-length
    command:
      - -c
      - |
        if [[ -z "${AIRFLOW_UID}" ]]; then
          echo
          echo -e "\033[1;33mWARNING!!!: AIRFLOW_UID not set!\e[0m"
          echo "If you are on Linux, you SHOULD follow the instructions below to set "
          echo "AIRFLOW_UID environment variable, otherwise files will be owned by root."
          echo "For other operating systems you can get rid of the warning with manually created .env file:"
          echo "    See: https://airflow.apache.org/docs/apache-airflow/stable/howto/docker-compose/index.html#setting-the-right-airflow-user"
          echo
        fi
        one_meg=1048576
        mem_available=$$(($$(getconf _PHYS_PAGES) * $$(getconf PAGE_SIZE) / one_meg))
        cpus_available=$$(grep -cE 'cpu[0-9]+' /proc/stat)
        disk_available=$$(df / | tail -1 | awk '{print $$4}')
        warning_resources="false"
        if (( mem_available < 4000 )) ; then
          echo
          echo -e "\033[1;33mWARNING!!!: Not enough memory available for Docker.\e[0m"
          echo "At least 4GB of memory required. You have $$(numfmt --to iec $$((mem_available * one_meg)))"
          echo
          warning_resources="true"
        fi
        if (( cpus_available < 2 )); then
          echo
          echo -e "\033[1;33mWARNING!!!: Not enough CPUS available for Docker.\e[0m"
          echo "At least 2 CPUs recommended. You have $${cpus_available}"
          echo
          warning_resources="true"
        fi
        if (( disk_available < one_meg * 10 )); then
          echo
          echo -e "\033[1;33mWARNING!!!: Not enough Disk space available for Docker.\e[0m"
          echo "At least 10 GBs recommended. You have $$(numfmt --to iec $$((disk_available * 1024 )))"
          echo
          warning_resources="true"
        fi
        if [[ $${warning_resources} == "true" ]]; then
          echo
          echo -e "\033[1;33mWARNING!!!: You have not enough resources to run Airflow (see above)!\e[0m"
          echo "Please follow the instructions to increase amount of resources available:"
          echo "   https://airflow.apache.org/docs/apache-airflow/stable/howto/docker-compose/index.html#before-you-begin"
          echo
        fi
        mkdir -p /sources/logs /sources/dags /sources/plugins
        chown -R "${AIRFLOW_UID}:0" /sources/{logs,dags,plugins}
        exec /entrypoint airflow version
    # yamllint enable rule:line-length
    environment:
      <<: *airflow-common-env
      _AIRFLOW_DB_MIGRATE: 'true'
      _AIRFLOW_WWW_USER_CREATE: 'true'
      _AIRFLOW_WWW_USER_USERNAME: ${_AIRFLOW_WWW_USER_USERNAME:-airflow}
      _AIRFLOW_WWW_USER_PASSWORD: ${_AIRFLOW_WWW_USER_PASSWORD:-airflow}
      _PIP_ADDITIONAL_REQUIREMENTS: ''
    user: "0:0"
    volumes:
      - ${AIRFLOW_PROJ_DIR:-.}:/sources

  airflow-cli:
    <<: *airflow-common
    profiles:
      - debug
    environment:
      <<: *airflow-common-env
      CONNECTION_CHECK_MAX_COUNT: "0"
    # Workaround for entrypoint issue. See: https://github.com/apache/airflow/issues/16252
    command:
      - bash
      - -c
      - airflow

  # You can enable flower by adding "--profile flower" option e.g. docker-compose --profile flower up
  # or by explicitly targeted on the command line e.g. docker-compose up flower.
  # See: https://docs.docker.com/compose/profiles/
  flower:
    <<: *airflow-common
    command: celery flower
    profiles:
      - flower
    ports:
      - "5555:5555"
    healthcheck:
      test: ["CMD", "curl", "--fail", "http://localhost:5555/"]
      interval: 30s
      timeout: 10s
      retries: 5
      start_period: 30s
    restart: always
    depends_on:
      <<: *airflow-common-depends-on
      airflow-init:
        condition: service_completed_successfully

volumes:
  postgres-db-volume:

and DCOKFILE:

FROM apache/airflow:2.11.0

# Switch to root to adjust apt sources and install minimal tools
USER root
RUN set -ex \
    # Remove any extra sources to avoid slow/failing repos
    && rm -f /etc/apt/sources.list.d/* || true \
    # Write a fresh sources.list using Aliyun mirrors (Debian 12/bookworm)
    && echo 'deb https://mirrors.aliyun.com/debian bookworm main contrib non-free non-free-firmware' > /etc/apt/sources.list \
    && echo 'deb https://mirrors.aliyun.com/debian bookworm-updates main contrib non-free non-free-firmware' >> /etc/apt/sources.list \
    && echo 'deb https://mirrors.aliyun.com/debian-security bookworm-security main contrib non-free non-free-firmware' >> /etc/apt/sources.list \
    && apt-get update \
    && apt-get install -y --no-install-recommends \
       python3-venv \
       build-essential \
    && rm -rf /var/lib/apt/lists/* \
    && mkdir -p /opt/airflow/.venvs \
    && chown -R airflow:0 /opt/airflow/.venvs

# Switch to airflow user for Python package installation
USER airflow

# Install Cosmos for Local execution into the image's Python env (venv)
RUN pip install --no-cache-dir -i https://pypi.tuna.tsinghua.edu.cn/simple "astronomer-cosmos[local]"

# Create a dedicated venv for dbt + athena and install packages there
ENV DBT_VENV=/opt/airflow/.venvs/dbt-athena
RUN python3 -m venv "$DBT_VENV" \
    && "$DBT_VENV/bin/pip" install --no-cache-dir -i https://pypi.tuna.tsinghua.edu.cn/simple --upgrade pip setuptools wheel \
    && "$DBT_VENV/bin/pip" install --no-cache-dir -i https://pypi.tuna.tsinghua.edu.cn/simple \
         "dbt-core>=1.8,<1.9" \
         "dbt-athena-community>=1.8,<1.9"

What happened?

should success process DAG file and find it in web ui,but process DAG faild. And it appears to have entered a loop, continuously retrying.

This is airflow config:

[core]
executor = CeleryExecutor
fernet_key =
dags_are_paused_at_creation = True
load_examples = True
dagbag_import_timeout = 300

[database]
sql_alchemy_conn = postgresql+psycopg2://airflow:airflow@postgres/airflow

[celery]
result_backend = db+postgresql://airflow:airflow@postgres/airflow
broker_url = redis://:@redis:6379/0

[api]
auth_backends = airflow.api.auth.backend.basic_auth,airflow.api.auth.backend.session

[scheduler]
enable_health_check = True

[logging]
logging_level = DEBUG
fab_logging_level = DEBUG
base_log_folder = /opt/airflow/logs
remote_logging = False
remote_base_log_folder =
remote_log_conn_id =
encrypt_s3_logs = False

Relevant log output

How to reproduce

DAG file:

from __future__ import annotations

from datetime import datetime

from cosmos import DbtDag
from cosmos.config import (
    ProjectConfig,
    ProfileConfig,
    ExecutionConfig,
    RenderConfig,
    LoadMode,
    ExecutionMode,
)


# Cosmos Local mode: call a fixed dbt binary inside a dedicated venv
# baked into the Airflow image, to keep global env clean while avoiding
# per-task venv overhead.

DBT_PROJECT_DIR = "/opt/airflow/dbt"
DBT_PROFILES_DIR = DBT_PROJECT_DIR


dag = DbtDag(
    dag_id="ext_walmart_adgroup_aditem_report",
    schedule_interval=None,
    start_date=datetime(2024, 1, 1),
    catchup=False,
    default_args={"owner": "airflow"},
    project_config=ProjectConfig(
        dbt_project_path=DBT_PROJECT_DIR,
    ),
    profile_config=ProfileConfig(
        profile_name="athena",
        target_name="dev",
        profiles_yml_filepath=f"{DBT_PROFILES_DIR}/profiles.yml",
    ),
    render_config=RenderConfig(
        load_method=LoadMode.DBT_LS,
        select=["ext_walmart_aditem_report"],
    ),
    execution_config=ExecutionConfig(
        execution_mode=ExecutionMode.LOCAL,
        dbt_executable_path="/opt/airflow/.venvs/dbt-athena/bin/dbt",
    ),
)

It's a very simple model. Running these two commands directly inside the container is very fast:

/opt/airflow/.venvs/dbt-athena/bin/dbt deps --project-dir /tmp/tmpd96z2aj5 --profiles-dir /opt/airflow/dbt --profile athena --target dev
/opt/airflow/.venvs/dbt-athena/bin/dbt ls --output json --project-dir /tmp/tmpd96z2aj5 --profiles-dir /opt/airflow/dbt --profile athena --target dev --select ext_walmart_aditem_report

ext_walmart_aditem_report.sql:

  {{ config(materialized='table') }}

  select 1 as test_column

Anything else :)?

No response

Are you willing to submit PR?

• Yes I am willing to submit a PR!

Contact Details

No response

[xianzheTM]

[2025-09-23T09:41:26.121+0000] {logging_mixin.py:190} INFO - [2025-09-23T09:41:26.121+0000] {settings.py:475} DEBUG - Setting up DB connection pool (PID 352)
[2025-09-23T09:41:26.121+0000] {logging_mixin.py:190} INFO - [2025-09-23T09:41:26.121+0000] {settings.py:579} DEBUG - settings.prepare_engine_args(): Using pool settings. pool_size=5, max_overflow=10, pool_recycle=1800, pid=352
[2025-09-23T09:41:26.125+0000] {processor.py:186} INFO - Started process (PID=352) to work on /opt/airflow/dags/ext_walmart_adgroup_aditem_report.py
[2025-09-23T09:41:26.125+0000] {processor.py:914} INFO - Processing file /opt/airflow/dags/ext_walmart_adgroup_aditem_report.py for tasks to queue
[2025-09-23T09:41:26.126+0000] {logging_mixin.py:190} INFO - [2025-09-23T09:41:26.126+0000] {dagbag.py:588} INFO - Filling up the DagBag from /opt/airflow/dags/ext_walmart_adgroup_aditem_report.py
[2025-09-23T09:41:26.127+0000] {logging_mixin.py:190} INFO - [2025-09-23T09:41:26.127+0000] {dagbag.py:369} DEBUG - Importing /opt/airflow/dags/ext_walmart_adgroup_aditem_report.py
[2025-09-23T09:41:26.131+0000] {logging_mixin.py:190} INFO - [2025-09-23T09:41:26.131+0000] {graph.py:615} INFO - Trying to parse the dbt project using dbt ls cache cosmos_cache__ext_walmart_adgroup_aditem_report...
[2025-09-23T09:41:26.141+0000] {logging_mixin.py:190} INFO - [2025-09-23T09:41:26.141+0000] {graph.py:621} INFO - Cosmos performance: Cache miss for cosmos_cache__ext_walmart_adgroup_aditem_report
[2025-09-23T09:41:26.142+0000] {logging_mixin.py:190} INFO - [2025-09-23T09:41:26.142+0000] {graph.py:725} INFO - Trying to parse the dbt project in `/opt/airflow/dbt` using dbt ls...
[2025-09-23T09:41:26.142+0000] {logging_mixin.py:190} INFO - [2025-09-23T09:41:26.142+0000] {graph.py:731} DEBUG - Content of the dbt project dir /opt/airflow/dbt: `['.sqlfluff', 'requirements_parquet_fixer.txt', '.github', 'env.example', 'diagram.mmd', 'README.md', 'athena_monitor.py', 'comparison_result.txt', 'profiles.yml', 'package-lock.yml', 'dbt_packages', 'docs', '.gitignore', 'packages.yml', 'compare_columns.py', 'processing_checkpoint.json', 'macros', '.env', 'logs', '1.csv', 'utils', 'dbt_project.yml', 'scripts', '2.csv', 'target', 'snapshots', 'tests', 'models', 'requirements.txt', 'CICD_README.md', 'fix_parquet_boolean_column.py', 'manifest_partition.py', '.claude', '.venv', '.user.yml', '.git', 'templates', 'selectors.yml', 'profiles.yml.example', '.idea', 'analyses', 'seeds', 'csv_diff_tool.py', 'check_csv.py']`
[2025-09-23T09:41:26.148+0000] {logging_mixin.py:190} INFO - [2025-09-23T09:41:26.148+0000] {graph.py:744} INFO - Partial parse is enabled and the latest partial parse file is /opt/airflow/dbt/target/partial_parse.msgpack
[2025-09-23T09:41:26.178+0000] {logging_mixin.py:190} INFO - [2025-09-23T09:41:26.177+0000] {config.py:362} INFO - Using user-supplied profiles.yml at /opt/airflow/dbt/profiles.yml
[2025-09-23T09:41:26.179+0000] {logging_mixin.py:190} INFO - [2025-09-23T09:41:26.179+0000] {graph.py:271} INFO - Running command with Python subprocess: `/opt/airflow/.venvs/dbt-athena/bin/dbt deps --project-dir /tmp/tmpxee8b1tv --profiles-dir /opt/airflow/dbt --profile athena --target dev`
[2025-09-23T09:41:26.180+0000] {logging_mixin.py:190} INFO - [2025-09-23T09:41:26.179+0000] {graph.py:272} DEBUG - Environment variable keys: dict_keys(['UV_CACHE_DIR', 'PYTHON_SHA256', 'DUMB_INIT_SETSID', 'HOSTNAME', 'PYTHON_VERSION', 'DBT_PROFILES_DIR', 'LANGUAGE', 'AIRFLOW_USER_HOME_DIR', 'ADDITIONAL_RUNTIME_APT_DEPS', 'PIP_TIMEOUT', 'PWD', 'AIRFLOW_VERSION', 'AIRFLOW__CORE__LOAD_EXAMPLES', 'INSTALL_MSSQL_CLIENT', 'INSTALL_MYSQL_CLIENT_TYPE', 'GUNICORN_CMD_ARGS', 'LD_PRELOAD', 'HOME', 'LANG', 'VIRTUAL_ENV', 'AIRFLOW_HOME', 'DBT_VENV', 'GPG_KEY', 'AIRFLOW_USE_UV', 'COMMIT_SHA', 'PIP_CACHE_DIR', 'AIRFLOW_PIP_VERSION', 'ADDITIONAL_RUNTIME_APT_COMMAND', 'AIRFLOW_UV_VERSION', '_PIP_ADDITIONAL_REQUIREMENTS', 'INSTALL_POSTGRES_CLIENT', 'PIP_INDEX_URL', 'SHLVL', 'LC_MESSAGES', 'RUNTIME_APT_DEPS', 'RUNTIME_APT_COMMAND', 'LD_LIBRARY_PATH', 'LC_CTYPE', 'AIRFLOW_INSTALLATION_METHOD', 'AIRFLOW_CONFIG', 'LC_ALL', 'INSTALL_MYSQL_CLIENT', 'PATH', 'PYTHON_BASE_IMAGE', 'AIRFLOW_UID', 'BUILD_ID', 'DEBIAN_FRONTEND', 'AIRFLOW__LOGGING__COLORED_CONSOLE_LOG', 'DBT_TARGET_PATH', 'DBT_LOG_PATH'])
[2025-09-23T09:42:08.089+0000] {logging_mixin.py:190} INFO - [2025-09-23T09:42:08.088+0000] {graph.py:279} DEBUG - dbt ls output: 09:41:27  Running with dbt=1.8.9
09:41:27  [WARNING]: Deprecated functionality
The `tests` config has been renamed to `data_tests`. Please see
https://docs.getdbt.com/docs/build/data-tests#new-data_tests-syntax for more
information.
09:41:47  Installing dbt-labs/dbt_utils
09:41:51  Installed from version 1.3.0
09:41:51  Updated version available: 1.3.1
09:41:51  Installing dbt-labs/codegen
09:41:56  Installed from version 0.13.1
09:41:56  Up to date!
09:41:56  Installing dbt-labs/dbt_external_tables
09:42:02  Installed from version 0.11.1
09:42:02  Up to date!
09:42:02  
09:42:02  Updates available for packages: ['dbt-labs/dbt_utils']                 
Update your versions in packages.yml, then run dbt deps
[2025-09-23T09:42:08.089+0000] {logging_mixin.py:190} INFO - [2025-09-23T09:42:08.089+0000] {graph.py:283} DEBUG - dbt logs available in: /tmp/tmpxee8b1tv/logs/dbt.log
[2025-09-23T09:42:08.090+0000] {logging_mixin.py:190} INFO - [2025-09-23T09:42:08.090+0000] {graph.py:287} DEBUG - 09:41:27.401707 [debug] [MainThread]: Sending event: {'category': 'dbt', 'action': 'invocation', 'label': 'start', 'context': [<snowplow_tracker.self_describing_json.SelfDescribingJson object at 0x739ce1b9b7a0>, <snowplow_tracker.self_describing_json.SelfDescribingJson object at 0x739ce1001e80>, <snowplow_tracker.self_describing_json.SelfDescribingJson object at 0x739ce1003da0>]}
[2025-09-23T09:42:08.090+0000] {logging_mixin.py:190} INFO - [2025-09-23T09:42:08.090+0000] {graph.py:287} DEBUG -
[2025-09-23T09:42:08.090+0000] {logging_mixin.py:190} INFO - [2025-09-23T09:42:08.090+0000] {graph.py:287} DEBUG -
[2025-09-23T09:42:08.091+0000] {logging_mixin.py:190} INFO - [2025-09-23T09:42:08.090+0000] {graph.py:287} DEBUG - ============================== 09:41:27.407558 | a1496b6c-f335-4ac5-9b44-09d2b854d420 ==============================
[2025-09-23T09:42:08.091+0000] {logging_mixin.py:190} INFO - [2025-09-23T09:42:08.091+0000] {graph.py:287} DEBUG - 09:41:27.407558 [info ] [MainThread]: Running with dbt=1.8.9
[2025-09-23T09:42:08.091+0000] {logging_mixin.py:190} INFO - [2025-09-23T09:42:08.091+0000] {graph.py:287} DEBUG - 09:41:27.407906 [debug] [MainThread]: running dbt with arguments {'printer_width': '80', 'indirect_selection': 'eager', 'write_json': 'True', 'log_cache_events': 'False', 'partial_parse': 'True', 'cache_selected_only': 'False', 'warn_error': 'None', 'debug': 'False', 'version_check': 'True', 'log_path': '/tmp/tmpxee8b1tv/logs', 'fail_fast': 'False', 'profiles_dir': '/opt/airflow/dbt', 'use_colors': 'True', 'use_experimental_parser': 'False', 'no_print': 'None', 'quiet': 'False', 'empty': 'None', 'warn_error_options': 'WarnErrorOptions(include=[], exclude=[])', 'static_parser': 'True', 'invocation_command': 'dbt deps --project-dir /tmp/tmpxee8b1tv --profiles-dir /opt/airflow/dbt --profile athena --target dev', 'introspect': 'True', 'target_path': 'None', 'log_format': 'default', 'send_anonymous_usage_stats': 'True'}
[2025-09-23T09:42:08.091+0000] {logging_mixin.py:190} INFO - [2025-09-23T09:42:08.091+0000] {graph.py:287} DEBUG - 09:41:27.459770 [warn ] [MainThread]: [WARNING]: Deprecated functionality
[2025-09-23T09:42:08.092+0000] {logging_mixin.py:190} INFO - [2025-09-23T09:42:08.091+0000] {graph.py:287} DEBUG - The `tests` config has been renamed to `data_tests`. Please see
[2025-09-23T09:42:08.092+0000] {logging_mixin.py:190} INFO - [2025-09-23T09:42:08.092+0000] {graph.py:287} DEBUG - https://docs.getdbt.com/docs/build/data-tests#new-data_tests-syntax for more
[2025-09-23T09:42:08.092+0000] {logging_mixin.py:190} INFO - [2025-09-23T09:42:08.092+0000] {graph.py:287} DEBUG - information.
[2025-09-23T09:42:08.092+0000] {logging_mixin.py:190} INFO - [2025-09-23T09:42:08.092+0000] {graph.py:287} DEBUG - 09:41:27.460356 [debug] [MainThread]: Sending event: {'category': 'dbt', 'action': 'deprecation', 'label': 'a1496b6c-f335-4ac5-9b44-09d2b854d420', 'property_': 'warn', 'context': [<snowplow_tracker.self_describing_json.SelfDescribingJson object at 0x739ce1001eb0>]}
[2025-09-23T09:42:08.092+0000] {logging_mixin.py:190} INFO - [2025-09-23T09:42:08.092+0000] {graph.py:287} DEBUG - 09:41:27.495514 [debug] [MainThread]: Sending event: {'category': 'dbt', 'action': 'project_id', 'label': 'a1496b6c-f335-4ac5-9b44-09d2b854d420', 'context': [<snowplow_tracker.self_describing_json.SelfDescribingJson object at 0x739ce0d6f9b0>]}
[2025-09-23T09:42:08.092+0000] {logging_mixin.py:190} INFO - [2025-09-23T09:42:08.092+0000] {graph.py:287} DEBUG - 09:41:27.506049 [debug] [MainThread]: Set downloads directory='/tmp/dbt-downloads-bqmv1kdq'
[2025-09-23T09:42:08.092+0000] {logging_mixin.py:190} INFO - [2025-09-23T09:42:08.092+0000] {graph.py:287} DEBUG - 09:41:27.506355 [debug] [MainThread]: Making package index registry request: GET https://hub.getdbt.com/api/v1/index.json
[2025-09-23T09:42:08.092+0000] {logging_mixin.py:190} INFO - [2025-09-23T09:42:08.092+0000] {graph.py:287} DEBUG - 09:41:32.333982 [debug] [MainThread]: Response from registry index: GET https://hub.getdbt.com/api/v1/index.json 200
[2025-09-23T09:42:08.092+0000] {logging_mixin.py:190} INFO - [2025-09-23T09:42:08.092+0000] {graph.py:287} DEBUG - 09:41:32.336494 [debug] [MainThread]: Making package registry request: GET https://hub.getdbt.com/api/v1/dbt-labs/dbt_utils.json
[2025-09-23T09:42:08.093+0000] {logging_mixin.py:190} INFO - [2025-09-23T09:42:08.093+0000] {graph.py:287} DEBUG - 09:41:37.206250 [debug] [MainThread]: Response from registry: GET https://hub.getdbt.com/api/v1/dbt-labs/dbt_utils.json 200
[2025-09-23T09:42:08.093+0000] {logging_mixin.py:190} INFO - [2025-09-23T09:42:08.093+0000] {graph.py:287} DEBUG - 09:41:37.209460 [debug] [MainThread]: Making package registry request: GET https://hub.getdbt.com/api/v1/dbt-labs/codegen.json
[2025-09-23T09:42:08.093+0000] {logging_mixin.py:190} INFO - [2025-09-23T09:42:08.093+0000] {graph.py:287} DEBUG - 09:41:41.994858 [debug] [MainThread]: Response from registry: GET https://hub.getdbt.com/api/v1/dbt-labs/codegen.json 200
[2025-09-23T09:42:08.093+0000] {logging_mixin.py:190} INFO - [2025-09-23T09:42:08.093+0000] {graph.py:287} DEBUG - 09:41:41.998103 [debug] [MainThread]: Making package registry request: GET https://hub.getdbt.com/api/v1/dbt-labs/dbt_external_tables.json
[2025-09-23T09:42:08.093+0000] {logging_mixin.py:190} INFO - [2025-09-23T09:42:08.093+0000] {graph.py:287} DEBUG - 09:41:47.010049 [debug] [MainThread]: Response from registry: GET https://hub.getdbt.com/api/v1/dbt-labs/dbt_external_tables.json 200
[2025-09-23T09:42:08.093+0000] {logging_mixin.py:190} INFO - [2025-09-23T09:42:08.093+0000] {graph.py:287} DEBUG - 09:41:47.014795 [info ] [MainThread]: Installing dbt-labs/dbt_utils
[2025-09-23T09:42:08.093+0000] {logging_mixin.py:190} INFO - [2025-09-23T09:42:08.093+0000] {graph.py:287} DEBUG - 09:41:51.896280 [info ] [MainThread]: Installed from version 1.3.0
[2025-09-23T09:42:08.093+0000] {logging_mixin.py:190} INFO - [2025-09-23T09:42:08.093+0000] {graph.py:287} DEBUG - 09:41:51.896626 [info ] [MainThread]: Updated version available: 1.3.1
[2025-09-23T09:42:08.093+0000] {logging_mixin.py:190} INFO - [2025-09-23T09:42:08.093+0000] {graph.py:287} DEBUG - 09:41:51.896871 [debug] [MainThread]: Sending event: {'category': 'dbt', 'action': 'package', 'label': 'a1496b6c-f335-4ac5-9b44-09d2b854d420', 'property_': 'install', 'context': [<snowplow_tracker.self_describing_json.SelfDescribingJson object at 0x739ce11c5ca0>, <snowplow_tracker.self_describing_json.SelfDescribingJson object at 0x739ce097eb40>]}
[2025-09-23T09:42:08.094+0000] {logging_mixin.py:190} INFO - [2025-09-23T09:42:08.093+0000] {graph.py:287} DEBUG - 09:41:51.897143 [info ] [MainThread]: Installing dbt-labs/codegen
[2025-09-23T09:42:08.094+0000] {logging_mixin.py:190} INFO - [2025-09-23T09:42:08.094+0000] {graph.py:287} DEBUG - 09:41:56.723297 [info ] [MainThread]: Installed from version 0.13.1
[2025-09-23T09:42:08.094+0000] {logging_mixin.py:190} INFO - [2025-09-23T09:42:08.094+0000] {graph.py:287} DEBUG - 09:41:56.723623 [info ] [MainThread]: Up to date!
[2025-09-23T09:42:08.094+0000] {logging_mixin.py:190} INFO - [2025-09-23T09:42:08.094+0000] {graph.py:287} DEBUG - 09:41:56.723891 [debug] [MainThread]: Sending event: {'category': 'dbt', 'action': 'package', 'label': 'a1496b6c-f335-4ac5-9b44-09d2b854d420', 'property_': 'install', 'context': [<snowplow_tracker.self_describing_json.SelfDescribingJson object at 0x739ce1e3ddf0>, <snowplow_tracker.self_describing_json.SelfDescribingJson object at 0x739ce1e3ce00>]}
[2025-09-23T09:42:08.094+0000] {logging_mixin.py:190} INFO - [2025-09-23T09:42:08.094+0000] {graph.py:287} DEBUG - 09:41:56.724162 [info ] [MainThread]: Installing dbt-labs/dbt_external_tables
[2025-09-23T09:42:08.094+0000] {logging_mixin.py:190} INFO - [2025-09-23T09:42:08.094+0000] {graph.py:287} DEBUG - 09:42:02.581095 [info ] [MainThread]: Installed from version 0.11.1
[2025-09-23T09:42:08.094+0000] {logging_mixin.py:190} INFO - [2025-09-23T09:42:08.094+0000] {graph.py:287} DEBUG - 09:42:02.581413 [info ] [MainThread]: Up to date!
[2025-09-23T09:42:08.094+0000] {logging_mixin.py:190} INFO - [2025-09-23T09:42:08.094+0000] {graph.py:287} DEBUG - 09:42:02.581660 [debug] [MainThread]: Sending event: {'category': 'dbt', 'action': 'package', 'label': 'a1496b6c-f335-4ac5-9b44-09d2b854d420', 'property_': 'install', 'context': [<snowplow_tracker.self_describing_json.SelfDescribingJson object at 0x739ce1e3ce00>, <snowplow_tracker.self_describing_json.SelfDescribingJson object at 0x739ce1e3df10>]}
[2025-09-23T09:42:08.094+0000] {logging_mixin.py:190} INFO - [2025-09-23T09:42:08.094+0000] {graph.py:287} DEBUG - 09:42:02.581896 [info ] [MainThread]:
[2025-09-23T09:42:08.094+0000] {logging_mixin.py:190} INFO - [2025-09-23T09:42:08.094+0000] {graph.py:287} DEBUG - 09:42:02.582093 [info ] [MainThread]: Updates available for packages: ['dbt-labs/dbt_utils']
[2025-09-23T09:42:08.095+0000] {logging_mixin.py:190} INFO - [2025-09-23T09:42:08.095+0000] {graph.py:287} DEBUG - Update your versions in packages.yml, then run dbt deps
[2025-09-23T09:42:08.095+0000] {logging_mixin.py:190} INFO - [2025-09-23T09:42:08.095+0000] {graph.py:287} DEBUG - 09:42:02.582920 [debug] [MainThread]: Resource report: {"command_name": "deps", "command_success": true, "command_wall_clock_time": 35.241127, "process_in_blocks": "42749", "process_kernel_time": 0.091104, "process_mem_max_rss": "251500", "process_out_blocks": "3041", "process_user_time": 1.47369}
[2025-09-23T09:42:08.095+0000] {logging_mixin.py:190} INFO - [2025-09-23T09:42:08.095+0000] {graph.py:287} DEBUG - 09:42:02.583239 [debug] [MainThread]: Command `dbt deps` succeeded at 09:42:02.583176 after 35.24 seconds
[2025-09-23T09:42:08.095+0000] {logging_mixin.py:190} INFO - [2025-09-23T09:42:08.095+0000] {graph.py:287} DEBUG - 09:42:02.583472 [debug] [MainThread]: Sending event: {'category': 'dbt', 'action': 'invocation', 'label': 'end', 'context': [<snowplow_tracker.self_describing_json.SelfDescribingJson object at 0x739ce1003da0>, <snowplow_tracker.self_describing_json.SelfDescribingJson object at 0x739ce125eb40>, <snowplow_tracker.self_describing_json.SelfDescribingJson object at 0x739ce1602ae0>]}
[2025-09-23T09:42:08.095+0000] {logging_mixin.py:190} INFO - [2025-09-23T09:42:08.095+0000] {graph.py:287} DEBUG - 09:42:02.583697 [debug] [MainThread]: Flushing usage events
[2025-09-23T09:42:08.095+0000] {logging_mixin.py:190} INFO - [2025-09-23T09:42:08.095+0000] {graph.py:271} INFO - Running command with Python subprocess: `/opt/airflow/.venvs/dbt-athena/bin/dbt ls --output json --project-dir /tmp/tmpxee8b1tv --profiles-dir /opt/airflow/dbt --profile athena --target dev --select ext_walmart_aditem_report`
[2025-09-23T09:42:08.095+0000] {logging_mixin.py:190} INFO - [2025-09-23T09:42:08.095+0000] {graph.py:272} DEBUG - Environment variable keys: dict_keys(['UV_CACHE_DIR', 'PYTHON_SHA256', 'DUMB_INIT_SETSID', 'HOSTNAME', 'PYTHON_VERSION', 'DBT_PROFILES_DIR', 'LANGUAGE', 'AIRFLOW_USER_HOME_DIR', 'ADDITIONAL_RUNTIME_APT_DEPS', 'PIP_TIMEOUT', 'PWD', 'AIRFLOW_VERSION', 'AIRFLOW__CORE__LOAD_EXAMPLES', 'INSTALL_MSSQL_CLIENT', 'INSTALL_MYSQL_CLIENT_TYPE', 'GUNICORN_CMD_ARGS', 'LD_PRELOAD', 'HOME', 'LANG', 'VIRTUAL_ENV', 'AIRFLOW_HOME', 'DBT_VENV', 'GPG_KEY', 'AIRFLOW_USE_UV', 'COMMIT_SHA', 'PIP_CACHE_DIR', 'AIRFLOW_PIP_VERSION', 'ADDITIONAL_RUNTIME_APT_COMMAND', 'AIRFLOW_UV_VERSION', '_PIP_ADDITIONAL_REQUIREMENTS', 'INSTALL_POSTGRES_CLIENT', 'PIP_INDEX_URL', 'SHLVL', 'LC_MESSAGES', 'RUNTIME_APT_DEPS', 'RUNTIME_APT_COMMAND', 'LD_LIBRARY_PATH', 'LC_CTYPE', 'AIRFLOW_INSTALLATION_METHOD', 'AIRFLOW_CONFIG', 'LC_ALL', 'INSTALL_MYSQL_CLIENT', 'PATH', 'PYTHON_BASE_IMAGE', 'AIRFLOW_UID', 'BUILD_ID', 'DEBIAN_FRONTEND', 'AIRFLOW__LOGGING__COLORED_CONSOLE_LOG', 'DBT_TARGET_PATH', 'DBT_LOG_PATH'])
[2025-09-23T09:42:46.606+0000] {logging_mixin.py:190} INFO - [2025-09-23T09:42:46.605+0000] {settings.py:475} DEBUG - Setting up DB connection pool (PID 420)
[2025-09-23T09:42:46.606+0000] {logging_mixin.py:190} INFO - [2025-09-23T09:42:46.606+0000] {settings.py:579} DEBUG - settings.prepare_engine_args(): Using pool settings. pool_size=5, max_overflow=10, pool_recycle=1800, pid=420
[2025-09-23T09:42:46.610+0000] {processor.py:186} INFO - Started process (PID=420) to work on /opt/airflow/dags/ext_walmart_adgroup_aditem_report.py
[2025-09-23T09:42:46.610+0000] {processor.py:914} INFO - Processing file /opt/airflow/dags/ext_walmart_adgroup_aditem_report.py for tasks to queue
[2025-09-23T09:42:46.611+0000] {logging_mixin.py:190} INFO - [2025-09-23T09:42:46.611+0000] {dagbag.py:588} INFO - Filling up the DagBag from /opt/airflow/dags/ext_walmart_adgroup_aditem_report.py
[2025-09-23T09:42:46.612+0000] {logging_mixin.py:190} INFO - [2025-09-23T09:42:46.611+0000] {dagbag.py:369} DEBUG - Importing /opt/airflow/dags/ext_walmart_adgroup_aditem_report.py
[2025-09-23T09:42:46.613+0000] {logging_mixin.py:190} INFO - [2025-09-23T09:42:46.613+0000] {graph.py:615} INFO - Trying to parse the dbt project using dbt ls cache cosmos_cache__ext_walmart_adgroup_aditem_report...
[2025-09-23T09:42:46.624+0000] {logging_mixin.py:190} INFO - [2025-09-23T09:42:46.624+0000] {graph.py:621} INFO - Cosmos performance: Cache miss for cosmos_cache__ext_walmart_adgroup_aditem_report
[2025-09-23T09:42:46.624+0000] {logging_mixin.py:190} INFO - [2025-09-23T09:42:46.624+0000] {graph.py:725} INFO - Trying to parse the dbt project in `/opt/airflow/dbt` using dbt ls...
[2025-09-23T09:42:46.625+0000] {logging_mixin.py:190} INFO - [2025-09-23T09:42:46.624+0000] {graph.py:731} DEBUG - Content of the dbt project dir /opt/airflow/dbt: `['.sqlfluff', 'requirements_parquet_fixer.txt', '.github', 'env.example', 'diagram.mmd', 'README.md', 'athena_monitor.py', 'comparison_result.txt', 'profiles.yml', 'package-lock.yml', 'dbt_packages', 'docs', '.gitignore', 'packages.yml', 'compare_columns.py', 'processing_checkpoint.json', 'macros', '.env', 'logs', '1.csv', 'utils', 'dbt_project.yml', 'scripts', '2.csv', 'target', 'snapshots', 'tests', 'models', 'requirements.txt', 'CICD_README.md', 'fix_parquet_boolean_column.py', 'manifest_partition.py', '.claude', '.venv', '.user.yml', '.git', 'templates', 'selectors.yml', 'profiles.yml.example', '.idea', 'analyses', 'seeds', 'csv_diff_tool.py', 'check_csv.py']`
[2025-09-23T09:42:46.629+0000] {logging_mixin.py:190} INFO - [2025-09-23T09:42:46.629+0000] {graph.py:744} INFO - Partial parse is enabled and the latest partial parse file is /opt/airflow/dbt/target/partial_parse.msgpack
[2025-09-23T09:42:46.656+0000] {logging_mixin.py:190} INFO - [2025-09-23T09:42:46.656+0000] {config.py:362} INFO - Using user-supplied profiles.yml at /opt/airflow/dbt/profiles.yml
[2025-09-23T09:42:46.658+0000] {logging_mixin.py:190} INFO - [2025-09-23T09:42:46.658+0000] {graph.py:271} INFO - Running command with Python subprocess: `/opt/airflow/.venvs/dbt-athena/bin/dbt deps --project-dir /tmp/tmp_ed9z1hb --profiles-dir /opt/airflow/dbt --profile athena --target dev`
[2025-09-23T09:42:46.659+0000] {logging_mixin.py:190} INFO - [2025-09-23T09:42:46.658+0000] {graph.py:272} DEBUG - Environment variable keys: dict_keys(['UV_CACHE_DIR', 'PYTHON_SHA256', 'DUMB_INIT_SETSID', 'HOSTNAME', 'PYTHON_VERSION', 'DBT_PROFILES_DIR', 'LANGUAGE', 'AIRFLOW_USER_HOME_DIR', 'ADDITIONAL_RUNTIME_APT_DEPS', 'PIP_TIMEOUT', 'PWD', 'AIRFLOW_VERSION', 'AIRFLOW__CORE__LOAD_EXAMPLES', 'INSTALL_MSSQL_CLIENT', 'INSTALL_MYSQL_CLIENT_TYPE', 'GUNICORN_CMD_ARGS', 'LD_PRELOAD', 'HOME', 'LANG', 'VIRTUAL_ENV', 'AIRFLOW_HOME', 'DBT_VENV', 'GPG_KEY', 'AIRFLOW_USE_UV', 'COMMIT_SHA', 'PIP_CACHE_DIR', 'AIRFLOW_PIP_VERSION', 'ADDITIONAL_RUNTIME_APT_COMMAND', 'AIRFLOW_UV_VERSION', '_PIP_ADDITIONAL_REQUIREMENTS', 'INSTALL_POSTGRES_CLIENT', 'PIP_INDEX_URL', 'SHLVL', 'LC_MESSAGES', 'RUNTIME_APT_DEPS', 'RUNTIME_APT_COMMAND', 'LD_LIBRARY_PATH', 'LC_CTYPE', 'AIRFLOW_INSTALLATION_METHOD', 'AIRFLOW_CONFIG', 'LC_ALL', 'INSTALL_MYSQL_CLIENT', 'PATH', 'PYTHON_BASE_IMAGE', 'AIRFLOW_UID', 'BUILD_ID', 'DEBIAN_FRONTEND', 'AIRFLOW__LOGGING__COLORED_CONSOLE_LOG', 'DBT_TARGET_PATH', 'DBT_LOG_PATH'])
[2025-09-23T09:43:27.523+0000] {logging_mixin.py:190} INFO - [2025-09-23T09:43:27.523+0000] {graph.py:279} DEBUG - dbt ls output: 09:42:47  Running with dbt=1.8.9
09:42:48  [WARNING]: Deprecated functionality
The `tests` config has been renamed to `data_tests`. Please see
https://docs.getdbt.com/docs/build/data-tests#new-data_tests-syntax for more
information.
09:43:06  Installing dbt-labs/dbt_utils
09:43:11  Installed from version 1.3.0
09:43:11  Updated version available: 1.3.1
09:43:11  Installing dbt-labs/codegen
09:43:16  Installed from version 0.13.1
09:43:16  Up to date!
09:43:16  Installing dbt-labs/dbt_external_tables
09:43:22  Installed from version 0.11.1
09:43:22  Up to date!
09:43:22  
09:43:22  Updates available for packages: ['dbt-labs/dbt_utils']                 
Update your versions in packages.yml, then run dbt deps
[2025-09-23T09:43:27.524+0000] {logging_mixin.py:190} INFO - [2025-09-23T09:43:27.524+0000] {graph.py:283} DEBUG - dbt logs available in: /tmp/tmp_ed9z1hb/logs/dbt.log
[2025-09-23T09:43:27.524+0000] {logging_mixin.py:190} INFO - [2025-09-23T09:43:27.524+0000] {graph.py:287} DEBUG - 09:42:47.941824 [debug] [MainThread]: Sending event: {'category': 'dbt', 'action': 'invocation', 'label': 'start', 'context': [<snowplow_tracker.self_describing_json.SelfDescribingJson object at 0x7328e807c740>, <snowplow_tracker.self_describing_json.SelfDescribingJson object at 0x7328e648f230>, <snowplow_tracker.self_describing_json.SelfDescribingJson object at 0x7328e8438800>]}
[2025-09-23T09:43:27.525+0000] {logging_mixin.py:190} INFO - [2025-09-23T09:43:27.525+0000] {graph.py:287} DEBUG -
[2025-09-23T09:43:27.525+0000] {logging_mixin.py:190} INFO - [2025-09-23T09:43:27.525+0000] {graph.py:287} DEBUG -
[2025-09-23T09:43:27.525+0000] {logging_mixin.py:190} INFO - [2025-09-23T09:43:27.525+0000] {graph.py:287} DEBUG - ============================== 09:42:47.951884 | 721f4257-1747-47d8-a59d-1705921728de ==============================
[2025-09-23T09:43:27.526+0000] {logging_mixin.py:190} INFO - [2025-09-23T09:43:27.525+0000] {graph.py:287} DEBUG - 09:42:47.951884 [info ] [MainThread]: Running with dbt=1.8.9
[2025-09-23T09:43:27.526+0000] {logging_mixin.py:190} INFO - [2025-09-23T09:43:27.526+0000] {graph.py:287} DEBUG - 09:42:47.952520 [debug] [MainThread]: running dbt with arguments {'printer_width': '80', 'indirect_selection': 'eager', 'log_cache_events': 'False', 'write_json': 'True', 'partial_parse': 'True', 'cache_selected_only': 'False', 'warn_error': 'None', 'version_check': 'True', 'fail_fast': 'False', 'log_path': '/tmp/tmp_ed9z1hb/logs', 'debug': 'False', 'profiles_dir': '/opt/airflow/dbt', 'use_colors': 'True', 'use_experimental_parser': 'False', 'empty': 'None', 'quiet': 'False', 'no_print': 'None', 'log_format': 'default', 'invocation_command': 'dbt deps --project-dir /tmp/tmp_ed9z1hb --profiles-dir /opt/airflow/dbt --profile athena --target dev', 'static_parser': 'True', 'introspect': 'True', 'target_path': 'None', 'warn_error_options': 'WarnErrorOptions(include=[], exclude=[])', 'send_anonymous_usage_stats': 'True'}
[2025-09-23T09:43:27.526+0000] {logging_mixin.py:190} INFO - [2025-09-23T09:43:27.526+0000] {graph.py:287} DEBUG - 09:42:48.010409 [warn ] [MainThread]: [WARNING]: Deprecated functionality
[2025-09-23T09:43:27.526+0000] {logging_mixin.py:190} INFO - [2025-09-23T09:43:27.526+0000] {graph.py:287} DEBUG - The `tests` config has been renamed to `data_tests`. Please see
[2025-09-23T09:43:27.526+0000] {logging_mixin.py:190} INFO - [2025-09-23T09:43:27.526+0000] {graph.py:287} DEBUG - https://docs.getdbt.com/docs/build/data-tests#new-data_tests-syntax for more
[2025-09-23T09:43:27.527+0000] {logging_mixin.py:190} INFO - [2025-09-23T09:43:27.526+0000] {graph.py:287} DEBUG - information.
[2025-09-23T09:43:27.527+0000] {logging_mixin.py:190} INFO - [2025-09-23T09:43:27.527+0000] {graph.py:287} DEBUG - 09:42:48.010862 [debug] [MainThread]: Sending event: {'category': 'dbt', 'action': 'deprecation', 'label': '721f4257-1747-47d8-a59d-1705921728de', 'property_': 'warn', 'context': [<snowplow_tracker.self_describing_json.SelfDescribingJson object at 0x7328e5a653a0>]}
[2025-09-23T09:43:27.527+0000] {logging_mixin.py:190} INFO - [2025-09-23T09:43:27.527+0000] {graph.py:287} DEBUG - 09:42:48.045553 [debug] [MainThread]: Sending event: {'category': 'dbt', 'action': 'project_id', 'label': '721f4257-1747-47d8-a59d-1705921728de', 'context': [<snowplow_tracker.self_describing_json.SelfDescribingJson object at 0x7328e5887140>]}
[2025-09-23T09:43:27.527+0000] {logging_mixin.py:190} INFO - [2025-09-23T09:43:27.527+0000] {graph.py:287} DEBUG - 09:42:48.058372 [debug] [MainThread]: Set downloads directory='/tmp/dbt-downloads-essjc_7h'
[2025-09-23T09:43:27.527+0000] {logging_mixin.py:190} INFO - [2025-09-23T09:43:27.527+0000] {graph.py:287} DEBUG - 09:42:48.058857 [debug] [MainThread]: Making package index registry request: GET https://hub.getdbt.com/api/v1/index.json
[2025-09-23T09:43:27.527+0000] {logging_mixin.py:190} INFO - [2025-09-23T09:43:27.527+0000] {graph.py:287} DEBUG - 09:42:52.835629 [debug] [MainThread]: Response from registry index: GET https://hub.getdbt.com/api/v1/index.json 200
[2025-09-23T09:43:27.527+0000] {logging_mixin.py:190} INFO - [2025-09-23T09:43:27.527+0000] {graph.py:287} DEBUG - 09:42:52.837336 [debug] [MainThread]: Making package registry request: GET https://hub.getdbt.com/api/v1/dbt-labs/dbt_utils.json
[2025-09-23T09:43:27.527+0000] {logging_mixin.py:190} INFO - [2025-09-23T09:43:27.527+0000] {graph.py:287} DEBUG - 09:42:57.573429 [debug] [MainThread]: Response from registry: GET https://hub.getdbt.com/api/v1/dbt-labs/dbt_utils.json 200
[2025-09-23T09:43:27.528+0000] {logging_mixin.py:190} INFO - [2025-09-23T09:43:27.527+0000] {graph.py:287} DEBUG - 09:42:57.578207 [debug] [MainThread]: Making package registry request: GET https://hub.getdbt.com/api/v1/dbt-labs/codegen.json
[2025-09-23T09:43:27.528+0000] {logging_mixin.py:190} INFO - [2025-09-23T09:43:27.528+0000] {graph.py:287} DEBUG - 09:43:02.096267 [debug] [MainThread]: Response from registry: GET https://hub.getdbt.com/api/v1/dbt-labs/codegen.json 200
[2025-09-23T09:43:27.528+0000] {logging_mixin.py:190} INFO - [2025-09-23T09:43:27.528+0000] {graph.py:287} DEBUG - 09:43:02.099494 [debug] [MainThread]: Making package registry request: GET https://hub.getdbt.com/api/v1/dbt-labs/dbt_external_tables.json
[2025-09-23T09:43:27.528+0000] {logging_mixin.py:190} INFO - [2025-09-23T09:43:27.528+0000] {graph.py:287} DEBUG - 09:43:06.784753 [debug] [MainThread]: Response from registry: GET https://hub.getdbt.com/api/v1/dbt-labs/dbt_external_tables.json 200
[2025-09-23T09:43:27.528+0000] {logging_mixin.py:190} INFO - [2025-09-23T09:43:27.528+0000] {graph.py:287} DEBUG - 09:43:06.788829 [info ] [MainThread]: Installing dbt-labs/dbt_utils
[2025-09-23T09:43:27.528+0000] {logging_mixin.py:190} INFO - [2025-09-23T09:43:27.528+0000] {graph.py:287} DEBUG - 09:43:11.961891 [info ] [MainThread]: Installed from version 1.3.0
[2025-09-23T09:43:27.528+0000] {logging_mixin.py:190} INFO - [2025-09-23T09:43:27.528+0000] {graph.py:287} DEBUG - 09:43:11.962553 [info ] [MainThread]: Updated version available: 1.3.1
[2025-09-23T09:43:27.528+0000] {logging_mixin.py:190} INFO - [2025-09-23T09:43:27.528+0000] {graph.py:287} DEBUG - 09:43:11.963066 [debug] [MainThread]: Sending event: {'category': 'dbt', 'action': 'package', 'label': '721f4257-1747-47d8-a59d-1705921728de', 'property_': 'install', 'context': [<snowplow_tracker.self_describing_json.SelfDescribingJson object at 0x7328e541ea80>, <snowplow_tracker.self_describing_json.SelfDescribingJson object at 0x7328e5550c50>]}
[2025-09-23T09:43:27.528+0000] {logging_mixin.py:190} INFO - [2025-09-23T09:43:27.528+0000] {graph.py:287} DEBUG - 09:43:11.963538 [info ] [MainThread]: Installing dbt-labs/codegen
[2025-09-23T09:43:27.528+0000] {logging_mixin.py:190} INFO - [2025-09-23T09:43:27.528+0000] {graph.py:287} DEBUG - 09:43:16.698904 [info ] [MainThread]: Installed from version 0.13.1
[2025-09-23T09:43:27.529+0000] {logging_mixin.py:190} INFO - [2025-09-23T09:43:27.529+0000] {graph.py:287} DEBUG - 09:43:16.699211 [info ] [MainThread]: Up to date!
[2025-09-23T09:43:27.529+0000] {logging_mixin.py:190} INFO - [2025-09-23T09:43:27.529+0000] {graph.py:287} DEBUG - 09:43:16.699456 [debug] [MainThread]: Sending event: {'category': 'dbt', 'action': 'package', 'label': '721f4257-1747-47d8-a59d-1705921728de', 'property_': 'install', 'context': [<snowplow_tracker.self_describing_json.SelfDescribingJson object at 0x7328e5885ac0>, <snowplow_tracker.self_describing_json.SelfDescribingJson object at 0x7328e5884230>]}
[2025-09-23T09:43:27.529+0000] {logging_mixin.py:190} INFO - [2025-09-23T09:43:27.529+0000] {graph.py:287} DEBUG - 09:43:16.699698 [info ] [MainThread]: Installing dbt-labs/dbt_external_tables
[2025-09-23T09:43:27.529+0000] {logging_mixin.py:190} INFO - [2025-09-23T09:43:27.529+0000] {graph.py:287} DEBUG - 09:43:22.242232 [info ] [MainThread]: Installed from version 0.11.1
[2025-09-23T09:43:27.529+0000] {logging_mixin.py:190} INFO - [2025-09-23T09:43:27.529+0000] {graph.py:287} DEBUG - 09:43:22.242562 [info ] [MainThread]: Up to date!
[2025-09-23T09:43:27.529+0000] {logging_mixin.py:190} INFO - [2025-09-23T09:43:27.529+0000] {graph.py:287} DEBUG - 09:43:22.242797 [debug] [MainThread]: Sending event: {'category': 'dbt', 'action': 'package', 'label': '721f4257-1747-47d8-a59d-1705921728de', 'property_': 'install', 'context': [<snowplow_tracker.self_describing_json.SelfDescribingJson object at 0x7328e5550c50>, <snowplow_tracker.self_describing_json.SelfDescribingJson object at 0x7328e5552030>]}
[2025-09-23T09:43:27.529+0000] {logging_mixin.py:190} INFO - [2025-09-23T09:43:27.529+0000] {graph.py:287} DEBUG - 09:43:22.243022 [info ] [MainThread]:
[2025-09-23T09:43:27.529+0000] {logging_mixin.py:190} INFO - [2025-09-23T09:43:27.529+0000] {graph.py:287} DEBUG - 09:43:22.243215 [info ] [MainThread]: Updates available for packages: ['dbt-labs/dbt_utils']
[2025-09-23T09:43:27.529+0000] {logging_mixin.py:190} INFO - [2025-09-23T09:43:27.529+0000] {graph.py:287} DEBUG - Update your versions in packages.yml, then run dbt deps
[2025-09-23T09:43:27.529+0000] {logging_mixin.py:190} INFO - [2025-09-23T09:43:27.529+0000] {graph.py:287} DEBUG - 09:43:22.244034 [debug] [MainThread]: Resource report: {"command_name": "deps", "command_success": true, "command_wall_clock_time": 34.36494, "process_in_blocks": "42749", "process_kernel_time": 0.124974, "process_mem_max_rss": "251692", "process_out_blocks": "3041", "process_user_time": 1.515689}
[2025-09-23T09:43:27.530+0000] {logging_mixin.py:190} INFO - [2025-09-23T09:43:27.529+0000] {graph.py:287} DEBUG - 09:43:22.244358 [debug] [MainThread]: Command `dbt deps` succeeded at 09:43:22.244294 after 34.37 seconds
[2025-09-23T09:43:27.530+0000] {logging_mixin.py:190} INFO - [2025-09-23T09:43:27.530+0000] {graph.py:287} DEBUG - 09:43:22.244578 [debug] [MainThread]: Sending event: {'category': 'dbt', 'action': 'invocation', 'label': 'end', 'context': [<snowplow_tracker.self_describing_json.SelfDescribingJson object at 0x7328e807c740>, <snowplow_tracker.self_describing_json.SelfDescribingJson object at 0x7328e5813170>, <snowplow_tracker.self_describing_json.SelfDescribingJson object at 0x7328e58b6870>]}
[2025-09-23T09:43:27.530+0000] {logging_mixin.py:190} INFO - [2025-09-23T09:43:27.530+0000] {graph.py:287} DEBUG - 09:43:22.244809 [debug] [MainThread]: Flushing usage events
[2025-09-23T09:43:27.530+0000] {logging_mixin.py:190} INFO - [2025-09-23T09:43:27.530+0000] {graph.py:271} INFO - Running command with Python subprocess: `/opt/airflow/.venvs/dbt-athena/bin/dbt ls --output json --project-dir /tmp/tmp_ed9z1hb --profiles-dir /opt/airflow/dbt --profile athena --target dev --select ext_walmart_aditem_report`
[2025-09-23T09:43:27.530+0000] {logging_mixin.py:190} INFO - [2025-09-23T09:43:27.530+0000] {graph.py:272} DEBUG - Environment variable keys: dict_keys(['UV_CACHE_DIR', 'PYTHON_SHA256', 'DUMB_INIT_SETSID', 'HOSTNAME', 'PYTHON_VERSION', 'DBT_PROFILES_DIR', 'LANGUAGE', 'AIRFLOW_USER_HOME_DIR', 'ADDITIONAL_RUNTIME_APT_DEPS', 'PIP_TIMEOUT', 'PWD', 'AIRFLOW_VERSION', 'AIRFLOW__CORE__LOAD_EXAMPLES', 'INSTALL_MSSQL_CLIENT', 'INSTALL_MYSQL_CLIENT_TYPE', 'GUNICORN_CMD_ARGS', 'LD_PRELOAD', 'HOME', 'LANG', 'VIRTUAL_ENV', 'AIRFLOW_HOME', 'DBT_VENV', 'GPG_KEY', 'AIRFLOW_USE_UV', 'COMMIT_SHA', 'PIP_CACHE_DIR', 'AIRFLOW_PIP_VERSION', 'ADDITIONAL_RUNTIME_APT_COMMAND', 'AIRFLOW_UV_VERSION', '_PIP_ADDITIONAL_REQUIREMENTS', 'INSTALL_POSTGRES_CLIENT', 'PIP_INDEX_URL', 'SHLVL', 'LC_MESSAGES', 'RUNTIME_APT_DEPS', 'RUNTIME_APT_COMMAND', 'LD_LIBRARY_PATH', 'LC_CTYPE', 'AIRFLOW_INSTALLATION_METHOD', 'AIRFLOW_CONFIG', 'LC_ALL', 'INSTALL_MYSQL_CLIENT', 'PATH', 'PYTHON_BASE_IMAGE', 'AIRFLOW_UID', 'BUILD_ID', 'DEBIAN_FRONTEND', 'AIRFLOW__LOGGING__COLORED_CONSOLE_LOG', 'DBT_TARGET_PATH', 'DBT_LOG_PATH'])
[2025-09-23T09:44:07.068+0000] {logging_mixin.py:190} INFO - [2025-09-23T09:44:07.068+0000] {settings.py:475} DEBUG - Setting up DB connection pool (PID 494)
[2025-09-23T09:44:07.069+0000] {logging_mixin.py:190} INFO - [2025-09-23T09:44:07.069+0000] {settings.py:579} DEBUG - settings.prepare_engine_args(): Using pool settings. pool_size=5, max_overflow=10, pool_recycle=1800, pid=494
[2025-09-23T09:44:07.072+0000] {processor.py:186} INFO - Started process (PID=494) to work on /opt/airflow/dags/ext_walmart_adgroup_aditem_report.py
[2025-09-23T09:44:07.072+0000] {processor.py:914} INFO - Processing file /opt/airflow/dags/ext_walmart_adgroup_aditem_report.py for tasks to queue
[2025-09-23T09:44:07.073+0000] {logging_mixin.py:190} INFO - [2025-09-23T09:44:07.073+0000] {dagbag.py:588} INFO - Filling up the DagBag from /opt/airflow/dags/ext_walmart_adgroup_aditem_report.py
[2025-09-23T09:44:07.074+0000] {logging_mixin.py:190} INFO - [2025-09-23T09:44:07.074+0000] {dagbag.py:369} DEBUG - Importing /opt/airflow/dags/ext_walmart_adgroup_aditem_report.py
[2025-09-23T09:44:07.076+0000] {logging_mixin.py:190} INFO - [2025-09-23T09:44:07.076+0000] {graph.py:615} INFO - Trying to parse the dbt project using dbt ls cache cosmos_cache__ext_walmart_adgroup_aditem_report...
[2025-09-23T09:44:07.085+0000] {logging_mixin.py:190} INFO - [2025-09-23T09:44:07.085+0000] {graph.py:621} INFO - Cosmos performance: Cache miss for cosmos_cache__ext_walmart_adgroup_aditem_report
[2025-09-23T09:44:07.085+0000] {logging_mixin.py:190} INFO - [2025-09-23T09:44:07.085+0000] {graph.py:725} INFO - Trying to parse the dbt project in `/opt/airflow/dbt` using dbt ls...
[2025-09-23T09:44:07.086+0000] {logging_mixin.py:190} INFO - [2025-09-23T09:44:07.086+0000] {graph.py:731} DEBUG - Content of the dbt project dir /opt/airflow/dbt: `['.sqlfluff', 'requirements_parquet_fixer.txt', '.github', 'env.example', 'diagram.mmd', 'README.md', 'athena_monitor.py', 'comparison_result.txt', 'profiles.yml', 'package-lock.yml', 'dbt_packages', 'docs', '.gitignore', 'packages.yml', 'compare_columns.py', 'processing_checkpoint.json', 'macros', '.env', 'logs', '1.csv', 'utils', 'dbt_project.yml', 'scripts', '2.csv', 'target', 'snapshots', 'tests', 'models', 'requirements.txt', 'CICD_README.md', 'fix_parquet_boolean_column.py', 'manifest_partition.py', '.claude', '.venv', '.user.yml', '.git', 'templates', 'selectors.yml', 'profiles.yml.example', '.idea', 'analyses', 'seeds', 'csv_diff_tool.py', 'check_csv.py']`
[2025-09-23T09:44:07.091+0000] {logging_mixin.py:190} INFO - [2025-09-23T09:44:07.091+0000] {graph.py:744} INFO - Partial parse is enabled and the latest partial parse file is /opt/airflow/dbt/target/partial_parse.msgpack
[2025-09-23T09:44:07.119+0000] {logging_mixin.py:190} INFO - [2025-09-23T09:44:07.119+0000] {config.py:362} INFO - Using user-supplied profiles.yml at /opt/airflow/dbt/profiles.yml
[2025-09-23T09:44:07.121+0000] {logging_mixin.py:190} INFO - [2025-09-23T09:44:07.121+0000] {graph.py:271} INFO - Running command with Python subprocess: `/opt/airflow/.venvs/dbt-athena/bin/dbt deps --project-dir /tmp/tmpoz5d4vrq --profiles-dir /opt/airflow/dbt --profile athena --target dev`
[2025-09-23T09:44:07.122+0000] {logging_mixin.py:190} INFO - [2025-09-23T09:44:07.121+0000] {graph.py:272} DEBUG - Environment variable keys: dict_keys(['UV_CACHE_DIR', 'PYTHON_SHA256', 'DUMB_INIT_SETSID', 'HOSTNAME', 'PYTHON_VERSION', 'DBT_PROFILES_DIR', 'LANGUAGE', 'AIRFLOW_USER_HOME_DIR', 'ADDITIONAL_RUNTIME_APT_DEPS', 'PIP_TIMEOUT', 'PWD', 'AIRFLOW_VERSION', 'AIRFLOW__CORE__LOAD_EXAMPLES', 'INSTALL_MSSQL_CLIENT', 'INSTALL_MYSQL_CLIENT_TYPE', 'GUNICORN_CMD_ARGS', 'LD_PRELOAD', 'HOME', 'LANG', 'VIRTUAL_ENV', 'AIRFLOW_HOME', 'DBT_VENV', 'GPG_KEY', 'AIRFLOW_USE_UV', 'COMMIT_SHA', 'PIP_CACHE_DIR', 'AIRFLOW_PIP_VERSION', 'ADDITIONAL_RUNTIME_APT_COMMAND', 'AIRFLOW_UV_VERSION', '_PIP_ADDITIONAL_REQUIREMENTS', 'INSTALL_POSTGRES_CLIENT', 'PIP_INDEX_URL', 'SHLVL', 'LC_MESSAGES', 'RUNTIME_APT_DEPS', 'RUNTIME_APT_COMMAND', 'LD_LIBRARY_PATH', 'LC_CTYPE', 'AIRFLOW_INSTALLATION_METHOD', 'AIRFLOW_CONFIG', 'LC_ALL', 'INSTALL_MYSQL_CLIENT', 'PATH', 'PYTHON_BASE_IMAGE', 'AIRFLOW_UID', 'BUILD_ID', 'DEBIAN_FRONTEND', 'AIRFLOW__LOGGING__COLORED_CONSOLE_LOG', 'DBT_TARGET_PATH', 'DBT_LOG_PATH'])
[2025-09-23T09:44:48.498+0000] {logging_mixin.py:190} INFO - [2025-09-23T09:44:48.498+0000] {graph.py:279} DEBUG - dbt ls output: 09:44:08  Running with dbt=1.8.9
09:44:08  [WARNING]: Deprecated functionality
The `tests` config has been renamed to `data_tests`. Please see
https://docs.getdbt.com/docs/build/data-tests#new-data_tests-syntax for more
information.
09:44:27  Installing dbt-labs/dbt_utils
09:44:32  Installed from version 1.3.0
09:44:32  Updated version available: 1.3.1
09:44:32  Installing dbt-labs/codegen
09:44:37  Installed from version 0.13.1
09:44:37  Up to date!
09:44:37  Installing dbt-labs/dbt_external_tables
09:44:43  Installed from version 0.11.1
09:44:43  Up to date!
09:44:43  
09:44:43  Updates available for packages: ['dbt-labs/dbt_utils']                 
Update your versions in packages.yml, then run dbt deps
[2025-09-23T09:44:48.499+0000] {logging_mixin.py:190} INFO - [2025-09-23T09:44:48.499+0000] {graph.py:283} DEBUG - dbt logs available in: /tmp/tmpoz5d4vrq/logs/dbt.log
[2025-09-23T09:44:48.499+0000] {logging_mixin.py:190} INFO - [2025-09-23T09:44:48.499+0000] {graph.py:287} DEBUG - 09:44:08.407795 [debug] [MainThread]: Sending event: {'category': 'dbt', 'action': 'invocation', 'label': 'start', 'context': [<snowplow_tracker.self_describing_json.SelfDescribingJson object at 0x77430fb5be00>, <snowplow_tracker.self_describing_json.SelfDescribingJson object at 0x7743108a4590>, <snowplow_tracker.self_describing_json.SelfDescribingJson object at 0x77430f6f84d0>]}
[2025-09-23T09:44:48.499+0000] {logging_mixin.py:190} INFO - [2025-09-23T09:44:48.499+0000] {graph.py:287} DEBUG -
[2025-09-23T09:44:48.499+0000] {logging_mixin.py:190} INFO - [2025-09-23T09:44:48.499+0000] {graph.py:287} DEBUG -
[2025-09-23T09:44:48.499+0000] {logging_mixin.py:190} INFO - [2025-09-23T09:44:48.499+0000] {graph.py:287} DEBUG - ============================== 09:44:08.415640 | 4a38a74c-9b94-4971-be23-3f46986aaaeb ==============================
[2025-09-23T09:44:48.499+0000] {logging_mixin.py:190} INFO - [2025-09-23T09:44:48.499+0000] {graph.py:287} DEBUG - 09:44:08.415640 [info ] [MainThread]: Running with dbt=1.8.9
[2025-09-23T09:44:48.499+0000] {logging_mixin.py:190} INFO - [2025-09-23T09:44:48.499+0000] {graph.py:287} DEBUG - 09:44:08.416014 [debug] [MainThread]: running dbt with arguments {'printer_width': '80', 'indirect_selection': 'eager', 'log_cache_events': 'False', 'write_json': 'True', 'partial_parse': 'True', 'cache_selected_only': 'False', 'profiles_dir': '/opt/airflow/dbt', 'debug': 'False', 'warn_error': 'None', 'log_path': '/tmp/tmpoz5d4vrq/logs', 'version_check': 'True', 'fail_fast': 'False', 'use_colors': 'True', 'use_experimental_parser': 'False', 'empty': 'None', 'quiet': 'False', 'no_print': 'None', 'log_format': 'default', 'introspect': 'True', 'static_parser': 'True', 'invocation_command': 'dbt deps --project-dir /tmp/tmpoz5d4vrq --profiles-dir /opt/airflow/dbt --profile athena --target dev', 'target_path': 'None', 'warn_error_options': 'WarnErrorOptions(include=[], exclude=[])', 'send_anonymous_usage_stats': 'True'}
[2025-09-23T09:44:48.500+0000] {logging_mixin.py:190} INFO - [2025-09-23T09:44:48.500+0000] {graph.py:287} DEBUG - 09:44:08.467549 [warn ] [MainThread]: [WARNING]: Deprecated functionality
[2025-09-23T09:44:48.500+0000] {logging_mixin.py:190} INFO - [2025-09-23T09:44:48.500+0000] {graph.py:287} DEBUG - The `tests` config has been renamed to `data_tests`. Please see
[2025-09-23T09:44:48.500+0000] {logging_mixin.py:190} INFO - [2025-09-23T09:44:48.500+0000] {graph.py:287} DEBUG - https://docs.getdbt.com/docs/build/data-tests#new-data_tests-syntax for more
[2025-09-23T09:44:48.500+0000] {logging_mixin.py:190} INFO - [2025-09-23T09:44:48.500+0000] {graph.py:287} DEBUG - information.
[2025-09-23T09:44:48.500+0000] {logging_mixin.py:190} INFO - [2025-09-23T09:44:48.500+0000] {graph.py:287} DEBUG - 09:44:08.467912 [debug] [MainThread]: Sending event: {'category': 'dbt', 'action': 'deprecation', 'label': '4a38a74c-9b94-4971-be23-3f46986aaaeb', 'property_': 'warn', 'context': [<snowplow_tracker.self_describing_json.SelfDescribingJson object at 0x77430f146ff0>]}
[2025-09-23T09:44:48.500+0000] {logging_mixin.py:190} INFO - [2025-09-23T09:44:48.500+0000] {graph.py:287} DEBUG - 09:44:08.501932 [debug] [MainThread]: Sending event: {'category': 'dbt', 'action': 'project_id', 'label': '4a38a74c-9b94-4971-be23-3f46986aaaeb', 'context': [<snowplow_tracker.self_describing_json.SelfDescribingJson object at 0x77430e5f02c0>]}
[2025-09-23T09:44:48.500+0000] {logging_mixin.py:190} INFO - [2025-09-23T09:44:48.500+0000] {graph.py:287} DEBUG - 09:44:08.512006 [debug] [MainThread]: Set downloads directory='/tmp/dbt-downloads-brhnq3c3'
[2025-09-23T09:44:48.500+0000] {logging_mixin.py:190} INFO - [2025-09-23T09:44:48.500+0000] {graph.py:287} DEBUG - 09:44:08.512310 [debug] [MainThread]: Making package index registry request: GET https://hub.getdbt.com/api/v1/index.json
[2025-09-23T09:44:48.500+0000] {logging_mixin.py:190} INFO - [2025-09-23T09:44:48.500+0000] {graph.py:287} DEBUG - 09:44:13.139171 [debug] [MainThread]: Response from registry index: GET https://hub.getdbt.com/api/v1/index.json 200
[2025-09-23T09:44:48.500+0000] {logging_mixin.py:190} INFO - [2025-09-23T09:44:48.500+0000] {graph.py:287} DEBUG - 09:44:13.140942 [debug] [MainThread]: Making package registry request: GET https://hub.getdbt.com/api/v1/dbt-labs/dbt_utils.json
[2025-09-23T09:44:48.501+0000] {logging_mixin.py:190} INFO - [2025-09-23T09:44:48.501+0000] {graph.py:287} DEBUG - 09:44:18.166525 [debug] [MainThread]: Response from registry: GET https://hub.getdbt.com/api/v1/dbt-labs/dbt_utils.json 200
[2025-09-23T09:44:48.501+0000] {logging_mixin.py:190} INFO - [2025-09-23T09:44:48.501+0000] {graph.py:287} DEBUG - 09:44:18.170434 [debug] [MainThread]: Making package registry request: GET https://hub.getdbt.com/api/v1/dbt-labs/codegen.json
[2025-09-23T09:44:48.501+0000] {logging_mixin.py:190} INFO - [2025-09-23T09:44:48.501+0000] {graph.py:287} DEBUG - 09:44:22.953187 [debug] [MainThread]: Response from registry: GET https://hub.getdbt.com/api/v1/dbt-labs/codegen.json 200
[2025-09-23T09:44:48.501+0000] {logging_mixin.py:190} INFO - [2025-09-23T09:44:48.501+0000] {graph.py:287} DEBUG - 09:44:22.955339 [debug] [MainThread]: Making package registry request: GET https://hub.getdbt.com/api/v1/dbt-labs/dbt_external_tables.json
[2025-09-23T09:44:48.501+0000] {logging_mixin.py:190} INFO - [2025-09-23T09:44:48.501+0000] {graph.py:287} DEBUG - 09:44:27.698297 [debug] [MainThread]: Response from registry: GET https://hub.getdbt.com/api/v1/dbt-labs/dbt_external_tables.json 200
[2025-09-23T09:44:48.501+0000] {logging_mixin.py:190} INFO - [2025-09-23T09:44:48.501+0000] {graph.py:287} DEBUG - 09:44:27.702032 [info ] [MainThread]: Installing dbt-labs/dbt_utils
[2025-09-23T09:44:48.501+0000] {logging_mixin.py:190} INFO - [2025-09-23T09:44:48.501+0000] {graph.py:287} DEBUG - 09:44:32.732179 [info ] [MainThread]: Installed from version 1.3.0
[2025-09-23T09:44:48.501+0000] {logging_mixin.py:190} INFO - [2025-09-23T09:44:48.501+0000] {graph.py:287} DEBUG - 09:44:32.732496 [info ] [MainThread]: Updated version available: 1.3.1
[2025-09-23T09:44:48.501+0000] {logging_mixin.py:190} INFO - [2025-09-23T09:44:48.501+0000] {graph.py:287} DEBUG - 09:44:32.732723 [debug] [MainThread]: Sending event: {'category': 'dbt', 'action': 'package', 'label': '4a38a74c-9b94-4971-be23-3f46986aaaeb', 'property_': 'install', 'context': [<snowplow_tracker.self_describing_json.SelfDescribingJson object at 0x77430e5afaa0>, <snowplow_tracker.self_describing_json.SelfDescribingJson object at 0x77430e5ae540>]}
[2025-09-23T09:44:48.501+0000] {logging_mixin.py:190} INFO - [2025-09-23T09:44:48.501+0000] {graph.py:287} DEBUG - 09:44:32.732959 [info ] [MainThread]: Installing dbt-labs/codegen
[2025-09-23T09:44:48.502+0000] {logging_mixin.py:190} INFO - [2025-09-23T09:44:48.502+0000] {graph.py:287} DEBUG - 09:44:37.862789 [info ] [MainThread]: Installed from version 0.13.1
[2025-09-23T09:44:48.502+0000] {logging_mixin.py:190} INFO - [2025-09-23T09:44:48.502+0000] {graph.py:287} DEBUG - 09:44:37.863380 [info ] [MainThread]: Up to date!
[2025-09-23T09:44:48.502+0000] {logging_mixin.py:190} INFO - [2025-09-23T09:44:48.502+0000] {graph.py:287} DEBUG - 09:44:37.863900 [debug] [MainThread]: Sending event: {'category': 'dbt', 'action': 'package', 'label': '4a38a74c-9b94-4971-be23-3f46986aaaeb', 'property_': 'install', 'context': [<snowplow_tracker.self_describing_json.SelfDescribingJson object at 0x77430e4df860>, <snowplow_tracker.self_describing_json.SelfDescribingJson object at 0x77430e4df740>]}
[2025-09-23T09:44:48.502+0000] {logging_mixin.py:190} INFO - [2025-09-23T09:44:48.502+0000] {graph.py:287} DEBUG - 09:44:37.864517 [info ] [MainThread]: Installing dbt-labs/dbt_external_tables
[2025-09-23T09:44:48.502+0000] {logging_mixin.py:190} INFO - [2025-09-23T09:44:48.502+0000] {graph.py:287} DEBUG - 09:44:43.017906 [info ] [MainThread]: Installed from version 0.11.1
[2025-09-23T09:44:48.502+0000] {logging_mixin.py:190} INFO - [2025-09-23T09:44:48.502+0000] {graph.py:287} DEBUG - 09:44:43.018217 [info ] [MainThread]: Up to date!
[2025-09-23T09:44:48.502+0000] {logging_mixin.py:190} INFO - [2025-09-23T09:44:48.502+0000] {graph.py:287} DEBUG - 09:44:43.018469 [debug] [MainThread]: Sending event: {'category': 'dbt', 'action': 'package', 'label': '4a38a74c-9b94-4971-be23-3f46986aaaeb', 'property_': 'install', 'context': [<snowplow_tracker.self_describing_json.SelfDescribingJson object at 0x77430e5af6b0>, <snowplow_tracker.self_describing_json.SelfDescribingJson object at 0x77430e5ae5d0>]}
[2025-09-23T09:44:48.502+0000] {logging_mixin.py:190} INFO - [2025-09-23T09:44:48.502+0000] {graph.py:287} DEBUG - 09:44:43.018708 [info ] [MainThread]:
[2025-09-23T09:44:48.502+0000] {logging_mixin.py:190} INFO - [2025-09-23T09:44:48.502+0000] {graph.py:287} DEBUG - 09:44:43.018914 [info ] [MainThread]: Updates available for packages: ['dbt-labs/dbt_utils']
[2025-09-23T09:44:48.502+0000] {logging_mixin.py:190} INFO - [2025-09-23T09:44:48.502+0000] {graph.py:287} DEBUG - Update your versions in packages.yml, then run dbt deps
[2025-09-23T09:44:48.503+0000] {logging_mixin.py:190} INFO - [2025-09-23T09:44:48.502+0000] {graph.py:287} DEBUG - 09:44:43.019718 [debug] [MainThread]: Resource report: {"command_name": "deps", "command_success": true, "command_wall_clock_time": 34.670265, "process_in_blocks": "42749", "process_kernel_time": 0.116376, "process_mem_max_rss": "251692", "process_out_blocks": "3041", "process_user_time": 1.50386}
[2025-09-23T09:44:48.503+0000] {logging_mixin.py:190} INFO - [2025-09-23T09:44:48.503+0000] {graph.py:287} DEBUG - 09:44:43.020036 [debug] [MainThread]: Command `dbt deps` succeeded at 09:44:43.019971 after 34.67 seconds
[2025-09-23T09:44:48.503+0000] {logging_mixin.py:190} INFO - [2025-09-23T09:44:48.503+0000] {graph.py:287} DEBUG - 09:44:43.020268 [debug] [MainThread]: Sending event: {'category': 'dbt', 'action': 'invocation', 'label': 'end', 'context': [<snowplow_tracker.self_describing_json.SelfDescribingJson object at 0x77430ee995b0>, <snowplow_tracker.self_describing_json.SelfDescribingJson object at 0x77430f3dbef0>, <snowplow_tracker.self_describing_json.SelfDescribingJson object at 0x77430e8fae70>]}
[2025-09-23T09:44:48.503+0000] {logging_mixin.py:190} INFO - [2025-09-23T09:44:48.503+0000] {graph.py:287} DEBUG - 09:44:43.020487 [debug] [MainThread]: Flushing usage events
[2025-09-23T09:44:48.503+0000] {logging_mixin.py:190} INFO - [2025-09-23T09:44:48.503+0000] {graph.py:271} INFO - Running command with Python subprocess: `/opt/airflow/.venvs/dbt-athena/bin/dbt ls --output json --project-dir /tmp/tmpoz5d4vrq --profiles-dir /opt/airflow/dbt --profile athena --target dev --select ext_walmart_aditem_report`
[2025-09-23T09:44:48.503+0000] {logging_mixin.py:190} INFO - [2025-09-23T09:44:48.503+0000] {graph.py:272} DEBUG - Environment variable keys: dict_keys(['UV_CACHE_DIR', 'PYTHON_SHA256', 'DUMB_INIT_SETSID', 'HOSTNAME', 'PYTHON_VERSION', 'DBT_PROFILES_DIR', 'LANGUAGE', 'AIRFLOW_USER_HOME_DIR', 'ADDITIONAL_RUNTIME_APT_DEPS', 'PIP_TIMEOUT', 'PWD', 'AIRFLOW_VERSION', 'AIRFLOW__CORE__LOAD_EXAMPLES', 'INSTALL_MSSQL_CLIENT', 'INSTALL_MYSQL_CLIENT_TYPE', 'GUNICORN_CMD_ARGS', 'LD_PRELOAD', 'HOME', 'LANG', 'VIRTUAL_ENV', 'AIRFLOW_HOME', 'DBT_VENV', 'GPG_KEY', 'AIRFLOW_USE_UV', 'COMMIT_SHA', 'PIP_CACHE_DIR', 'AIRFLOW_PIP_VERSION', 'ADDITIONAL_RUNTIME_APT_COMMAND', 'AIRFLOW_UV_VERSION', '_PIP_ADDITIONAL_REQUIREMENTS', 'INSTALL_POSTGRES_CLIENT', 'PIP_INDEX_URL', 'SHLVL', 'LC_MESSAGES', 'RUNTIME_APT_DEPS', 'RUNTIME_APT_COMMAND', 'LD_LIBRARY_PATH', 'LC_CTYPE', 'AIRFLOW_INSTALLATION_METHOD', 'AIRFLOW_CONFIG', 'LC_ALL', 'INSTALL_MYSQL_CLIENT', 'PATH', 'PYTHON_BASE_IMAGE', 'AIRFLOW_UID', 'BUILD_ID', 'DEBIAN_FRONTEND', 'AIRFLOW__LOGGING__COLORED_CONSOLE_LOG', 'DBT_TARGET_PATH', 'DBT_LOG_PATH'])
[2025-09-23T09:45:27.551+0000] {logging_mixin.py:190} INFO - [2025-09-23T09:45:27.551+0000] {settings.py:475} DEBUG - Setting up DB connection pool (PID 567)
[2025-09-23T09:45:27.552+0000] {logging_mixin.py:190} INFO - [2025-09-23T09:45:27.552+0000] {settings.py:579} DEBUG - settings.prepare_engine_args(): Using pool settings. pool_size=5, max_overflow=10, pool_recycle=1800, pid=567
[2025-09-23T09:45:27.556+0000] {processor.py:186} INFO - Started process (PID=567) to work on /opt/airflow/dags/ext_walmart_adgroup_aditem_report.py
[2025-09-23T09:45:27.556+0000] {processor.py:914} INFO - Processing file /opt/airflow/dags/ext_walmart_adgroup_aditem_report.py for tasks to queue
[2025-09-23T09:45:27.557+0000] {logging_mixin.py:190} INFO - [2025-09-23T09:45:27.557+0000] {dagbag.py:588} INFO - Filling up the DagBag from /opt/airflow/dags/ext_walmart_adgroup_aditem_report.py
[2025-09-23T09:45:27.558+0000] {logging_mixin.py:190} INFO - [2025-09-23T09:45:27.558+0000] {dagbag.py:369} DEBUG - Importing /opt/airflow/dags/ext_walmart_adgroup_aditem_report.py
[2025-09-23T09:45:27.561+0000] {logging_mixin.py:190} INFO - [2025-09-23T09:45:27.560+0000] {graph.py:615} INFO - Trying to parse the dbt project using dbt ls cache cosmos_cache__ext_walmart_adgroup_aditem_report...
[2025-09-23T09:45:27.573+0000] {logging_mixin.py:190} INFO - [2025-09-23T09:45:27.572+0000] {graph.py:621} INFO - Cosmos performance: Cache miss for cosmos_cache__ext_walmart_adgroup_aditem_report
[2025-09-23T09:45:27.573+0000] {logging_mixin.py:190} INFO - [2025-09-23T09:45:27.573+0000] {graph.py:725} INFO - Trying to parse the dbt project in `/opt/airflow/dbt` using dbt ls...
[2025-09-23T09:45:27.574+0000] {logging_mixin.py:190} INFO - [2025-09-23T09:45:27.573+0000] {graph.py:731} DEBUG - Content of the dbt project dir /opt/airflow/dbt: `['.sqlfluff', 'requirements_parquet_fixer.txt', '.github', 'env.example', 'diagram.mmd', 'README.md', 'athena_monitor.py', 'comparison_result.txt', 'profiles.yml', 'package-lock.yml', 'dbt_packages', 'docs', '.gitignore', 'packages.yml', 'compare_columns.py', 'processing_checkpoint.json', 'macros', '.env', 'logs', '1.csv', 'utils', 'dbt_project.yml', 'scripts', '2.csv', 'target', 'snapshots', 'tests', 'models', 'requirements.txt', 'CICD_README.md', 'fix_parquet_boolean_column.py', 'manifest_partition.py', '.claude', '.venv', '.user.yml', '.git', 'templates', 'selectors.yml', 'profiles.yml.example', '.idea', 'analyses', 'seeds', 'csv_diff_tool.py', 'check_csv.py']`
[2025-09-23T09:45:27.579+0000] {logging_mixin.py:190} INFO - [2025-09-23T09:45:27.579+0000] {graph.py:744} INFO - Partial parse is enabled and the latest partial parse file is /opt/airflow/dbt/target/partial_parse.msgpack
[2025-09-23T09:45:27.606+0000] {logging_mixin.py:190} INFO - [2025-09-23T09:45:27.606+0000] {config.py:362} INFO - Using user-supplied profiles.yml at /opt/airflow/dbt/profiles.yml
[2025-09-23T09:45:27.609+0000] {logging_mixin.py:190} INFO - [2025-09-23T09:45:27.608+0000] {graph.py:271} INFO - Running command with Python subprocess: `/opt/airflow/.venvs/dbt-athena/bin/dbt deps --project-dir /tmp/tmpn5kugh2m --profiles-dir /opt/airflow/dbt --profile athena --target dev`
[2025-09-23T09:45:27.611+0000] {logging_mixin.py:190} INFO - [2025-09-23T09:45:27.609+0000] {graph.py:272} DEBUG - Environment variable keys: dict_keys(['UV_CACHE_DIR', 'PYTHON_SHA256', 'DUMB_INIT_SETSID', 'HOSTNAME', 'PYTHON_VERSION', 'DBT_PROFILES_DIR', 'LANGUAGE', 'AIRFLOW_USER_HOME_DIR', 'ADDITIONAL_RUNTIME_APT_DEPS', 'PIP_TIMEOUT', 'PWD', 'AIRFLOW_VERSION', 'AIRFLOW__CORE__LOAD_EXAMPLES', 'INSTALL_MSSQL_CLIENT', 'INSTALL_MYSQL_CLIENT_TYPE', 'GUNICORN_CMD_ARGS', 'LD_PRELOAD', 'HOME', 'LANG', 'VIRTUAL_ENV', 'AIRFLOW_HOME', 'DBT_VENV', 'GPG_KEY', 'AIRFLOW_USE_UV', 'COMMIT_SHA', 'PIP_CACHE_DIR', 'AIRFLOW_PIP_VERSION', 'ADDITIONAL_RUNTIME_APT_COMMAND', 'AIRFLOW_UV_VERSION', '_PIP_ADDITIONAL_REQUIREMENTS', 'INSTALL_POSTGRES_CLIENT', 'PIP_INDEX_URL', 'SHLVL', 'LC_MESSAGES', 'RUNTIME_APT_DEPS', 'RUNTIME_APT_COMMAND', 'LD_LIBRARY_PATH', 'LC_CTYPE', 'AIRFLOW_INSTALLATION_METHOD', 'AIRFLOW_CONFIG', 'LC_ALL', 'INSTALL_MYSQL_CLIENT', 'PATH', 'PYTHON_BASE_IMAGE', 'AIRFLOW_UID', 'BUILD_ID', 'DEBIAN_FRONTEND', 'AIRFLOW__LOGGING__COLORED_CONSOLE_LOG', 'DBT_TARGET_PATH', 'DBT_LOG_PATH'])
[2025-09-23T09:46:13.403+0000] {logging_mixin.py:190} INFO - [2025-09-23T09:46:13.403+0000] {graph.py:279} DEBUG - dbt ls output: 09:45:28  Running with dbt=1.8.9
09:45:28  [WARNING]: Deprecated functionality
The `tests` config has been renamed to `data_tests`. Please see
https://docs.getdbt.com/docs/build/data-tests#new-data_tests-syntax for more
information.
09:45:48  Installing dbt-labs/dbt_utils
09:45:52  Installed from version 1.3.0
09:45:52  Updated version available: 1.3.1
09:45:52  Installing dbt-labs/codegen
09:45:57  Installed from version 0.13.1
09:45:57  Up to date!
09:45:57  Installing dbt-labs/dbt_external_tables
09:46:07  Installed from version 0.11.1
09:46:07  Up to date!
09:46:07  
09:46:07  Updates available for packages: ['dbt-labs/dbt_utils']                 
Update your versions in packages.yml, then run dbt deps
[2025-09-23T09:46:13.404+0000] {logging_mixin.py:190} INFO - [2025-09-23T09:46:13.403+0000] {graph.py:283} DEBUG - dbt logs available in: /tmp/tmpn5kugh2m/logs/dbt.log
[2025-09-23T09:46:13.404+0000] {logging_mixin.py:190} INFO - [2025-09-23T09:46:13.404+0000] {graph.py:287} DEBUG - 09:45:28.917943 [debug] [MainThread]: Sending event: {'category': 'dbt', 'action': 'invocation', 'label': 'start', 'context': [<snowplow_tracker.self_describing_json.SelfDescribingJson object at 0x77511087dd00>, <snowplow_tracker.self_describing_json.SelfDescribingJson object at 0x775110ea33e0>, <snowplow_tracker.self_describing_json.SelfDescribingJson object at 0x77511087de50>]}
[2025-09-23T09:46:13.404+0000] {logging_mixin.py:190} INFO - [2025-09-23T09:46:13.404+0000] {graph.py:287} DEBUG -
[2025-09-23T09:46:13.404+0000] {logging_mixin.py:190} INFO - [2025-09-23T09:46:13.404+0000] {graph.py:287} DEBUG -
[2025-09-23T09:46:13.404+0000] {logging_mixin.py:190} INFO - [2025-09-23T09:46:13.404+0000] {graph.py:287} DEBUG - ============================== 09:45:28.924726 | d848ad21-421f-47d7-9a36-d3b8228ddb6b ==============================
[2025-09-23T09:46:13.404+0000] {logging_mixin.py:190} INFO - [2025-09-23T09:46:13.404+0000] {graph.py:287} DEBUG - 09:45:28.924726 [info ] [MainThread]: Running with dbt=1.8.9
[2025-09-23T09:46:13.404+0000] {logging_mixin.py:190} INFO - [2025-09-23T09:46:13.404+0000] {graph.py:287} DEBUG - 09:45:28.925121 [debug] [MainThread]: running dbt with arguments {'printer_width': '80', 'indirect_selection': 'eager', 'write_json': 'True', 'log_cache_events': 'False', 'partial_parse': 'True', 'cache_selected_only': 'False', 'warn_error': 'None', 'fail_fast': 'False', 'debug': 'False', 'log_path': '/tmp/tmpn5kugh2m/logs', 'version_check': 'True', 'profiles_dir': '/opt/airflow/dbt', 'use_colors': 'True', 'use_experimental_parser': 'False', 'empty': 'None', 'quiet': 'False', 'no_print': 'None', 'log_format': 'default', 'static_parser': 'True', 'introspect': 'True', 'invocation_command': 'dbt deps --project-dir /tmp/tmpn5kugh2m --profiles-dir /opt/airflow/dbt --profile athena --target dev', 'target_path': 'None', 'warn_error_options': 'WarnErrorOptions(include=[], exclude=[])', 'send_anonymous_usage_stats': 'True'}
[2025-09-23T09:46:13.404+0000] {logging_mixin.py:190} INFO - [2025-09-23T09:46:13.404+0000] {graph.py:287} DEBUG - 09:45:28.992657 [warn ] [MainThread]: [WARNING]: Deprecated functionality
[2025-09-23T09:46:13.404+0000] {logging_mixin.py:190} INFO - [2025-09-23T09:46:13.404+0000] {graph.py:287} DEBUG - The `tests` config has been renamed to `data_tests`. Please see
[2025-09-23T09:46:13.405+0000] {logging_mixin.py:190} INFO - [2025-09-23T09:46:13.405+0000] {graph.py:287} DEBUG - https://docs.getdbt.com/docs/build/data-tests#new-data_tests-syntax for more
[2025-09-23T09:46:13.405+0000] {logging_mixin.py:190} INFO - [2025-09-23T09:46:13.405+0000] {graph.py:287} DEBUG - information.
[2025-09-23T09:46:13.405+0000] {logging_mixin.py:190} INFO - [2025-09-23T09:46:13.405+0000] {graph.py:287} DEBUG - 09:45:28.993087 [debug] [MainThread]: Sending event: {'category': 'dbt', 'action': 'deprecation', 'label': 'd848ad21-421f-47d7-9a36-d3b8228ddb6b', 'property_': 'warn', 'context': [<snowplow_tracker.self_describing_json.SelfDescribingJson object at 0x77511068f4a0>]}
[2025-09-23T09:46:13.405+0000] {logging_mixin.py:190} INFO - [2025-09-23T09:46:13.405+0000] {graph.py:287} DEBUG - 09:45:29.037032 [debug] [MainThread]: Sending event: {'category': 'dbt', 'action': 'project_id', 'label': 'd848ad21-421f-47d7-9a36-d3b8228ddb6b', 'context': [<snowplow_tracker.self_describing_json.SelfDescribingJson object at 0x7751124fa690>]}
[2025-09-23T09:46:13.405+0000] {logging_mixin.py:190} INFO - [2025-09-23T09:46:13.405+0000] {graph.py:287} DEBUG - 09:45:29.048529 [debug] [MainThread]: Set downloads directory='/tmp/dbt-downloads-kpkq9f_x'
[2025-09-23T09:46:13.405+0000] {logging_mixin.py:190} INFO - [2025-09-23T09:46:13.405+0000] {graph.py:287} DEBUG - 09:45:29.048879 [debug] [MainThread]: Making package index registry request: GET https://hub.getdbt.com/api/v1/index.json
[2025-09-23T09:46:13.405+0000] {logging_mixin.py:190} INFO - [2025-09-23T09:46:13.405+0000] {graph.py:287} DEBUG - 09:45:33.944131 [debug] [MainThread]: Response from registry index: GET https://hub.getdbt.com/api/v1/index.json 200
[2025-09-23T09:46:13.405+0000] {logging_mixin.py:190} INFO - [2025-09-23T09:46:13.405+0000] {graph.py:287} DEBUG - 09:45:33.945601 [debug] [MainThread]: Making package registry request: GET https://hub.getdbt.com/api/v1/dbt-labs/dbt_utils.json
[2025-09-23T09:46:13.405+0000] {logging_mixin.py:190} INFO - [2025-09-23T09:46:13.405+0000] {graph.py:287} DEBUG - 09:45:38.706159 [debug] [MainThread]: Response from registry: GET https://hub.getdbt.com/api/v1/dbt-labs/dbt_utils.json 200
[2025-09-23T09:46:13.405+0000] {logging_mixin.py:190} INFO - [2025-09-23T09:46:13.405+0000] {graph.py:287} DEBUG - 09:45:38.711143 [debug] [MainThread]: Making package registry request: GET https://hub.getdbt.com/api/v1/dbt-labs/codegen.json
[2025-09-23T09:46:13.406+0000] {logging_mixin.py:190} INFO - [2025-09-23T09:46:13.406+0000] {graph.py:287} DEBUG - 09:45:43.319156 [debug] [MainThread]: Response from registry: GET https://hub.getdbt.com/api/v1/dbt-labs/codegen.json 200
[2025-09-23T09:46:13.406+0000] {logging_mixin.py:190} INFO - [2025-09-23T09:46:13.406+0000] {graph.py:287} DEBUG - 09:45:43.321384 [debug] [MainThread]: Making package registry request: GET https://hub.getdbt.com/api/v1/dbt-labs/dbt_external_tables.json
[2025-09-23T09:46:13.407+0000] {logging_mixin.py:190} INFO - [2025-09-23T09:46:13.406+0000] {graph.py:287} DEBUG - 09:45:48.023923 [debug] [MainThread]: Response from registry: GET https://hub.getdbt.com/api/v1/dbt-labs/dbt_external_tables.json 200
[2025-09-23T09:46:13.407+0000] {logging_mixin.py:190} INFO - [2025-09-23T09:46:13.407+0000] {graph.py:287} DEBUG - 09:45:48.027880 [info ] [MainThread]: Installing dbt-labs/dbt_utils
[2025-09-23T09:46:13.407+0000] {logging_mixin.py:190} INFO - [2025-09-23T09:46:13.407+0000] {graph.py:287} DEBUG - 09:45:52.857791 [info ] [MainThread]: Installed from version 1.3.0
[2025-09-23T09:46:13.408+0000] {logging_mixin.py:190} INFO - [2025-09-23T09:46:13.408+0000] {graph.py:287} DEBUG - 09:45:52.858109 [info ] [MainThread]: Updated version available: 1.3.1
[2025-09-23T09:46:13.408+0000] {logging_mixin.py:190} INFO - [2025-09-23T09:46:13.408+0000] {graph.py:287} DEBUG - 09:45:52.858382 [debug] [MainThread]: Sending event: {'category': 'dbt', 'action': 'package', 'label': 'd848ad21-421f-47d7-9a36-d3b8228ddb6b', 'property_': 'install', 'context': [<snowplow_tracker.self_describing_json.SelfDescribingJson object at 0x7751102c40e0>, <snowplow_tracker.self_describing_json.SelfDescribingJson object at 0x7751102c5340>]}
[2025-09-23T09:46:13.408+0000] {logging_mixin.py:190} INFO - [2025-09-23T09:46:13.408+0000] {graph.py:287} DEBUG - 09:45:52.858650 [info ] [MainThread]: Installing dbt-labs/codegen
[2025-09-23T09:46:13.409+0000] {logging_mixin.py:190} INFO - [2025-09-23T09:46:13.408+0000] {graph.py:287} DEBUG - 09:45:57.591083 [info ] [MainThread]: Installed from version 0.13.1
[2025-09-23T09:46:13.409+0000] {logging_mixin.py:190} INFO - [2025-09-23T09:46:13.409+0000] {graph.py:287} DEBUG - 09:45:57.591416 [info ] [MainThread]: Up to date!
[2025-09-23T09:46:13.409+0000] {logging_mixin.py:190} INFO - [2025-09-23T09:46:13.409+0000] {graph.py:287} DEBUG - 09:45:57.591665 [debug] [MainThread]: Sending event: {'category': 'dbt', 'action': 'package', 'label': 'd848ad21-421f-47d7-9a36-d3b8228ddb6b', 'property_': 'install', 'context': [<snowplow_tracker.self_describing_json.SelfDescribingJson object at 0x775110211220>, <snowplow_tracker.self_describing_json.SelfDescribingJson object at 0x7751102111f0>]}
[2025-09-23T09:46:13.409+0000] {logging_mixin.py:190} INFO - [2025-09-23T09:46:13.409+0000] {graph.py:287} DEBUG - 09:45:57.591918 [info ] [MainThread]: Installing dbt-labs/dbt_external_tables
[2025-09-23T09:46:13.409+0000] {logging_mixin.py:190} INFO - [2025-09-23T09:46:13.409+0000] {graph.py:287} DEBUG - 09:46:07.827625 [info ] [MainThread]: Installed from version 0.11.1
[2025-09-23T09:46:13.410+0000] {logging_mixin.py:190} INFO - [2025-09-23T09:46:13.410+0000] {graph.py:287} DEBUG - 09:46:07.828123 [info ] [MainThread]: Up to date!
[2025-09-23T09:46:13.410+0000] {logging_mixin.py:190} INFO - [2025-09-23T09:46:13.410+0000] {graph.py:287} DEBUG - 09:46:07.828577 [debug] [MainThread]: Sending event: {'category': 'dbt', 'action': 'package', 'label': 'd848ad21-421f-47d7-9a36-d3b8228ddb6b', 'property_': 'install', 'context': [<snowplow_tracker.self_describing_json.SelfDescribingJson object at 0x775110213d10>, <snowplow_tracker.self_describing_json.SelfDescribingJson object at 0x775110213bf0>]}
[2025-09-23T09:46:13.410+0000] {logging_mixin.py:190} INFO - [2025-09-23T09:46:13.410+0000] {graph.py:287} DEBUG - 09:46:07.829214 [info ] [MainThread]:
[2025-09-23T09:46:13.410+0000] {logging_mixin.py:190} INFO - [2025-09-23T09:46:13.410+0000] {graph.py:287} DEBUG - 09:46:07.829691 [info ] [MainThread]: Updates available for packages: ['dbt-labs/dbt_utils']
[2025-09-23T09:46:13.410+0000] {logging_mixin.py:190} INFO - [2025-09-23T09:46:13.410+0000] {graph.py:287} DEBUG - Update your versions in packages.yml, then run dbt deps
[2025-09-23T09:46:13.410+0000] {logging_mixin.py:190} INFO - [2025-09-23T09:46:13.410+0000] {graph.py:287} DEBUG - 09:46:07.831025 [debug] [MainThread]: Resource report: {"command_name": "deps", "command_success": true, "command_wall_clock_time": 38.986084, "process_in_blocks": "42749", "process_kernel_time": 0.116265, "process_mem_max_rss": "251388", "process_out_blocks": "3041", "process_user_time": 1.56157}
[2025-09-23T09:46:13.411+0000] {logging_mixin.py:190} INFO - [2025-09-23T09:46:13.410+0000] {graph.py:287} DEBUG - 09:46:07.831407 [debug] [MainThread]: Command `dbt deps` succeeded at 09:46:07.831334 after 38.99 seconds
[2025-09-23T09:46:13.411+0000] {logging_mixin.py:190} INFO - [2025-09-23T09:46:13.411+0000] {graph.py:287} DEBUG - 09:46:07.831666 [debug] [MainThread]: Sending event: {'category': 'dbt', 'action': 'invocation', 'label': 'end', 'context': [<snowplow_tracker.self_describing_json.SelfDescribingJson object at 0x775110ea33e0>, <snowplow_tracker.self_describing_json.SelfDescribingJson object at 0x775111030230>, <snowplow_tracker.self_describing_json.SelfDescribingJson object at 0x775110846a20>]}
[2025-09-23T09:46:13.411+0000] {logging_mixin.py:190} INFO - [2025-09-23T09:46:13.411+0000] {graph.py:287} DEBUG - 09:46:07.831901 [debug] [MainThread]: Flushing usage events
[2025-09-23T09:46:13.411+0000] {logging_mixin.py:190} INFO - [2025-09-23T09:46:13.411+0000] {graph.py:271} INFO - Running command with Python subprocess: `/opt/airflow/.venvs/dbt-athena/bin/dbt ls --output json --project-dir /tmp/tmpn5kugh2m --profiles-dir /opt/airflow/dbt --profile athena --target dev --select ext_walmart_aditem_report`
[2025-09-23T09:46:13.411+0000] {logging_mixin.py:190} INFO - [2025-09-23T09:46:13.411+0000] {graph.py:272} DEBUG - Environment variable keys: dict_keys(['UV_CACHE_DIR', 'PYTHON_SHA256', 'DUMB_INIT_SETSID', 'HOSTNAME', 'PYTHON_VERSION', 'DBT_PROFILES_DIR', 'LANGUAGE', 'AIRFLOW_USER_HOME_DIR', 'ADDITIONAL_RUNTIME_APT_DEPS', 'PIP_TIMEOUT', 'PWD', 'AIRFLOW_VERSION', 'AIRFLOW__CORE__LOAD_EXAMPLES', 'INSTALL_MSSQL_CLIENT', 'INSTALL_MYSQL_CLIENT_TYPE', 'GUNICORN_CMD_ARGS', 'LD_PRELOAD', 'HOME', 'LANG', 'VIRTUAL_ENV', 'AIRFLOW_HOME', 'DBT_VENV', 'GPG_KEY', 'AIRFLOW_USE_UV', 'COMMIT_SHA', 'PIP_CACHE_DIR', 'AIRFLOW_PIP_VERSION', 'ADDITIONAL_RUNTIME_APT_COMMAND', 'AIRFLOW_UV_VERSION', '_PIP_ADDITIONAL_REQUIREMENTS', 'INSTALL_POSTGRES_CLIENT', 'PIP_INDEX_URL', 'SHLVL', 'LC_MESSAGES', 'RUNTIME_APT_DEPS', 'RUNTIME_APT_COMMAND', 'LD_LIBRARY_PATH', 'LC_CTYPE', 'AIRFLOW_INSTALLATION_METHOD', 'AIRFLOW_CONFIG', 'LC_ALL', 'INSTALL_MYSQL_CLIENT', 'PATH', 'PYTHON_BASE_IMAGE', 'AIRFLOW_UID', 'BUILD_ID', 'DEBIAN_FRONTEND', 'AIRFLOW__LOGGING__COLORED_CONSOLE_LOG', 'DBT_TARGET_PATH', 'DBT_LOG_PATH'])