CeleryExecutor tasks flooded by repeated ‘Secrets backends loaded for worker’ INFO logs

[lesliejjytbw]

Apache Airflow version

3.0.1

If "Other Airflow 2 version" selected, which one?

No response

What happened?

It seems like #49205 change made all the task logs get dominated by the exact logs for our celery executors.

It emits the logs every time the dag calls Variable.get.

[2025-05-09, 15:03:48] INFO - Secrets backends loaded for worker: count=1: backend_classes=["EnvironmentVariablesBackend"]: source="supervisor"
[2025-05-09, 15:03:48] INFO - Secrets backends loaded for worker: count=1: backend_classes=["EnvironmentVariablesBackend"]: source="supervisor"
[2025-05-09, 15:05:00] INFO - Secrets backends loaded for worker: count=1: backend_classes=["EnvironmentVariablesBackend"]: source="supervisor"
[2025-05-09, 15:05:00] INFO - Secrets backends loaded for worker: count=1: backend_classes=["EnvironmentVariablesBackend"]: source="supervisor"
[2025-05-09, 15:05:41] INFO - Secrets backends loaded for worker: count=1: backend_classes=["EnvironmentVariablesBackend"]: source="supervisor"
[2025-05-09, 15:05:41] INFO - Secrets backends loaded for worker: count=1: backend_classes=["EnvironmentVariablesBackend"]: source="supervisor"
[2025-05-09, 15:06:21] INFO - Secrets backends loaded for worker: count=1: backend_classes=["EnvironmentVariablesBackend"]: source="supervisor"
[2025-05-09, 15:06:21] INFO - Secrets backends loaded for worker: count=1: backend_classes=["EnvironmentVariablesBackend"]: source="supervisor"
[2025-05-09, 15:07:03] INFO - Secrets backends loaded for worker: count=1: backend_classes=["EnvironmentVariablesBackend"]: source="supervisor"
[2025-05-09, 15:07:03] INFO - Secrets backends loaded for worker: count=1: backend_classes=["EnvironmentVariablesBackend"]: source="supervisor"
[2025-05-09, 15:07:55] INFO - Secrets backends loaded for worker: count=1: backend_classes=["EnvironmentVariablesBackend"]: source="supervisor"
[2025-05-09, 15:07:55] INFO - Secrets backends loaded for worker: count=1: backend_classes=["EnvironmentVariablesBackend"]: source="supervisor"
[2025-05-09, 15:07:55] INFO - Secrets backends loaded for worker: count=1: backend_classes=["EnvironmentVariablesBackend"]: source="supervisor"
[2025-05-09, 15:07:55] INFO - Secrets backends loaded for worker: count=1: backend_classes=["EnvironmentVariablesBackend"]: source="supervisor"
[2025-05-09, 15:07:55] INFO - Secrets backends loaded for worker: count=1: backend_classes=["EnvironmentVariablesBackend"]: source="supervisor"
[2025-05-09, 15:07:55] INFO - Secrets backends loaded for worker: count=1: backend_classes=["EnvironmentVariablesBackend"]: source="supervisor"
[2025-05-09, 15:08:06] INFO - Secrets backends loaded for worker: count=1: backend_classes=["EnvironmentVariablesBackend"]: source="supervisor"
[2025-05-09, 15:08:06] INFO - Secrets backends loaded for worker: count=1: backend_classes=["EnvironmentVariablesBackend"]: source="supervisor"
[2025-05-09, 15:09:15] INFO - Secrets backends loaded for worker: count=1: backend_classes=["EnvironmentVariablesBackend"]: source="supervisor"
[2025-05-09, 15:09:15] INFO - Secrets backends loaded for worker: count=1: backend_classes=["EnvironmentVariablesBackend"]: source="supervisor"
[2025-05-09, 15:10:11] INFO - Secrets backends loaded for worker: count=1: backend_classes=["EnvironmentVariablesBackend"]: source="supervisor"
[2025-05-09, 15:10:11] INFO - Secrets backends loaded for worker: count=1: backend_classes=["EnvironmentVariablesBackend"]: source="supervisor"
[2025-05-09, 15:10:20] INFO - Secrets backends loaded for worker: count=1: backend_classes=["EnvironmentVariablesBackend"]: source="supervisor"
[2025-05-09, 15:10:20] INFO - Secrets backends loaded for worker: count=1: backend_classes=["EnvironmentVariablesBackend"]: source="supervisor"
[2025-05-09, 15:10:33] INFO - Secrets backends loaded for worker: count=1: backend_classes=["EnvironmentVariablesBackend"]: source="supervisor"
[2025-05-09, 15:10:33] INFO - Secrets backends loaded for worker: count=1: backend_classes=["EnvironmentVariablesBackend"]: source="supervisor"

They are calling the same variables in a loop

What you think should happen instead?

It shouldn't get logged everytime it reads Variable. Expected at most 1 log per task.

How to reproduce

I get 101 lines of the log for

from airflow.sdk import DAG, task, Variable

import datetime as dt
from zoneinfo import ZoneInfo

TIME_ZONE = Variable.get("TIME_ZONE", "UTC")

with DAG(
    dag_id="test",
    start_date=dt.datetime(2025, 5, 1, tzinfo=ZoneInfo(TIME_ZONE)),
    schedule=None,
    catchup=False,
) as dag:
    @task()
    def test_task():
        for i in range(100):
            print(f"Variable {i}: {Variable.get(f'var_{i}', f'default_{i}')}")

    test_task()

I still get the duplicated logs for extracting same variable in my actual tasks

Operating System

Rocky Linux 8.10

Versions of Apache Airflow Providers

apache-airflow-providers-apache-spark==3.0.0
apache-airflow-providers-celery==3.10.6
apache-airflow-providers-common-compat==1.6.0
apache-airflow-providers-common-io==1.5.4
apache-airflow-providers-common-sql==1.26.0
apache-airflow-providers-docker==4.3.1
apache-airflow-providers-fab==2.0.1
apache-airflow-providers-ftp==3.12.0
apache-airflow-providers-http==5.0.0
apache-airflow-providers-imap==3.8.0
apache-airflow-providers-jdbc==5.1.0
apache-airflow-providers-oracle==4.0.3
apache-airflow-providers-postgres==6.1.3
apache-airflow-providers-redis==4.0.2
apache-airflow-providers-smtp==2.0.3
apache-airflow-providers-sqlite==4.0.0
apache-airflow-providers-standard==1.0.0

Deployment

Official Apache Airflow Helm Chart

Deployment details

HOME={homedir}/airflow
PYTHONPATH=$AIRFLOW_HOME/config:$AIRFLOW_HOME:$PYTHONPATH
AIRFLOW__CORE__EXECUTOR=CeleryExecutor
AIRFLOW__CORE__LOAD_EXAMPLES=False
AIRFLOW__CELERY__BROKER_URL=xx
AIRFLOW__DATABASE__SQL_ALCHEMY_CONN=xx
AIRFLOW__WEBSERVER__EXPOSE_CONFIG=True
AIRFLOW__CORE__DAGBAG_IMPORT_TIMEOUT=300.0
AIRFLOW__DAG_PROCESSOR__DAG_FILE_PROCESSOR_TIMEOUT=500
AIRFLOW__API__BASE_URL=xxx
AIRFLOW__CORE__EXECUTION_API_SERVER_URL=xx
AIRFLOW__WEBSERVER__SECRET_KEY=xx
AIRFLOW__LOGGING__LOGGING_CONFIG_CLASS=log_config.LOGGING_CONFIG

Anything else?

I've tried to disable the log using custom logging, but didn't work out

from copy import deepcopy
from pydantic.v1.utils import deep_update
from airflow.config_templates.airflow_local_settings import DEFAULT_LOGGING_CONFIG

LOGGING_CONFIG = deep_update(
    deepcopy(DEFAULT_LOGGING_CONFIG),
    {
        "loggers": {
            "airflow.sdk.execution_time.supervisor": {
                "handlers": ["task"],
                "level": "WARNING",
                "propagate": False,
            }
        }
    },
)

So i just monkey patched as below.

from airflow.sdk.execution_time import supervisor as sup_mod
from airflow.configuration import ensure_secrets_loaded as _cfg_load
from airflow.secrets import DEFAULT_SECRETS_SEARCH_PATH_WORKERS

def ensure_secrets_backend_loaded():
    return _cfg_load(default_backends=DEFAULT_SECRETS_SEARCH_PATH_WORKERS)

sup_mod.ensure_secrets_backend_loaded = ensure_secrets_backend_loaded

Are you willing to submit PR?

• Yes I am willing to submit a PR!

Code of Conduct

• I agree to follow this project's Code of Conduct

[boring-cyborg]

Thanks for opening your first issue here! Be sure to follow the issue template! If you are willing to raise PR to address this issue please do so, no need to wait for approval.

[tirkarthi]

cc: @amoghrajesh

[amoghrajesh]

Well this is not nice and is a lot of noise. Let me self assign this. Will look at it soon.

[amoghrajesh]

Shouldn't be specific to celery however. It is a task sdk problem