Logging system exception when celery beat can not connect to redis

[undo-nothing]

same issue report in Celery

I am setting Redis as broker, and setting broker_connection_max_retries = 1.

I start celery beat with python -m celery -A proj beat -l debug --logfile="logging/beat.log", and not running Redis service. Celery beat will check redis connection, when over max_retries, will raise Exception, I think the log output seems duplicate and format error.

some log in output:

[2024-06-05 11:07:08,121: CRITICAL beat.py beat.115] beat raised exception <class 'kombu.exceptions.OperationalError'>: OperationalError('Error 10061 connecting to 127.0.0.1:6379. 由于目标计算机积极拒绝，无法连接。.')
Traceback (most recent call last):
File "C:\Miniforge3\envs\python311_django42\Lib\site-packages\kombu\transport\virtual\base.py", line 951, in create_channel
return self._avail_channels.pop()
^^^^^^^^^^^^^^^^^^^^^^^^^^
IndexError: pop from empty list

During handling of the above exception, another exception occurred:
...

[2024-06-05 11:07:08,186: WARNING log.py log.232] Traceback (most recent call last):
[2024-06-05 11:07:08,186: WARNING log.py log.232] File "C:\Miniforge3\envs\python311_django42\Lib\site-packages\kombu\transport\virtual\base.py", line 951, in create_channel
[2024-06-05 11:07:08,187: WARNING log.py log.232]
[2024-06-05 11:07:08,188: WARNING log.py log.232] return self._avail_channels.pop()
[2024-06-05 11:07:08,188: WARNING log.py log.232]
[2024-06-05 11:07:08,188: WARNING log.py log.232]
[2024-06-05 11:07:08,188: WARNING log.py log.232]
[2024-06-05 11:07:08,188: WARNING log.py log.232]
[2024-06-05 11:07:08,188: WARNING log.py log.232]
[2024-06-05 11:07:08,188: WARNING log.py log.232]
[2024-06-05 11:07:08,189: WARNING log.py log.232]
[2024-06-05 11:07:08,189: WARNING log.py log.232]
[2024-06-05 11:07:08,189: WARNING log.py log.232]
[2024-06-05 11:07:08,189: WARNING log.py log.232]
[2024-06-05 11:07:08,189: WARNING log.py log.232]
[2024-06-05 11:07:08,189: WARNING log.py log.232] ^
[2024-06-05 11:07:08,189: WARNING log.py log.232] ^
[2024-06-05 11:07:08,189: WARNING log.py log.232] ^
[2024-06-05 11:07:08,189: WARNING log.py log.232] ^
[2024-06-05 11:07:08,190: WARNING log.py log.232] ^
[2024-06-05 11:07:08,190: WARNING log.py log.232] ^
[2024-06-05 11:07:08,190: WARNING log.py log.232] ^
[2024-06-05 11:07:08,190: WARNING log.py log.232] ^
[2024-06-05 11:07:08,190: WARNING log.py log.232] ^
[2024-06-05 11:07:08,190: WARNING log.py log.232] ^
[2024-06-05 11:07:08,190: WARNING log.py log.232] ^
[2024-06-05 11:07:08,190: WARNING log.py log.232] ^
[2024-06-05 11:07:08,190: WARNING log.py log.232] ^
[2024-06-05 11:07:08,191: WARNING log.py log.232] ^
[2024-06-05 11:07:08,191: WARNING log.py log.232] ^
[2024-06-05 11:07:08,191: WARNING log.py log.232] ^
[2024-06-05 11:07:08,191: WARNING log.py log.232] ^
[2024-06-05 11:07:08,191: WARNING log.py log.232] ^
[2024-06-05 11:07:08,191: WARNING log.py log.232] ^
[2024-06-05 11:07:08,191: WARNING log.py log.232] ^
[2024-06-05 11:07:08,191: WARNING log.py log.232] ^
[2024-06-05 11:07:08,192: WARNING log.py log.232] ^
[2024-06-05 11:07:08,192: WARNING log.py log.232] ^
[2024-06-05 11:07:08,192: WARNING log.py log.232] ^
[2024-06-05 11:07:08,192: WARNING log.py log.232] ^
[2024-06-05 11:07:08,192: WARNING log.py log.232] ^
[2024-06-05 11:07:08,192: WARNING log.py log.232] IndexError
[2024-06-05 11:07:08,192: WARNING log.py log.232] :
[2024-06-05 11:07:08,192: WARNING log.py log.232] pop from empty list
[2024-06-05 11:07:08,193: WARNING log.py log.232] During handling of the above exception, another exception occurred:
[2024-06-05 11:07:08,193: WARNING log.py log.232] Traceback (most recent call last):
[2024-06-05 11:07:08,193: WARNING log.py log.232] File "C:\Miniforge3\envs\python311_django42\Lib\site-packages\redis\connection.py", line 259, in connect
[2024-06-05 11:07:08,194: WARNING log.py log.232]
[2024-06-05 11:07:08,194: WARNING log.py log.232] sock = self.retry.call_with_retry(
[2024-06-05 11:07:08,194: WARNING log.py log.232]
[2024-06-05 11:07:08,194: WARNING log.py log.232]
[2024-06-05 11:07:08,194: WARNING log.py log.232]
[2024-06-05 11:07:08,194: WARNING log.py log.232]
[2024-06-05 11:07:08,194: WARNING log.py log.232]
[2024-06-05 11:07:08,195: WARNING log.py log.232]
[2024-06-05 11:07:08,195: WARNING log.py log.232]
[2024-06-05 11:07:08,195: WARNING log.py log.232]
[2024-06-05 11:07:08,195: WARNING log.py log.232]
[2024-06-05 11:07:08,195: WARNING log.py log.232]
[2024-06-05 11:07:08,195: WARNING log.py log.232]
[2024-06-05 11:07:08,195: WARNING log.py log.232] ^
[2024-06-05 11:07:08,195: WARNING log.py log.232] ^
[2024-06-05 11:07:08,195: WARNING log.py log.232] ^
[2024-06-05 11:07:08,196: WARNING log.py log.232] ^
[2024-06-05 11:07:08,196: WARNING log.py log.232] ^
[2024-06-05 11:07:08,196: WARNING log.py log.232] ^
[2024-06-05 11:07:08,196: WARNING log.py log.232] ^
[2024-06-05 11:07:08,196: WARNING log.py log.232] ^
[2024-06-05 11:07:08,196: WARNING log.py log.232] ^
[2024-06-05 11:07:08,196: WARNING log.py log.232] ^
[2024-06-05 11:07:08,196: WARNING log.py log.232] ^
[2024-06-05 11:07:08,196: WARNING log.py log.232] ^
...

I don't know why log.py log.232 will logging this error, and the format of log will split with line? can log.py log.232 log the whole error message with one message instead of split it with so many lines?

celery report

software -> celery:5.4.0 (opalescent) kombu:5.3.7 py:3.11.4
billiard:4.2.0 redis:5.0.0
platform -> system:Windows arch:64bit, WindowsPE
kernel version:10 imp:CPython
loader -> celery.loaders.app.AppLoader
settings -> transport:redis results:redis://127.0.0.1:6379/2

Config: <class 'decouple.Config'>
Queue: <class 'kombu.entity.Queue'>
RepositoryEnv: <class 'decouple.RepositoryEnv'>
accept_content: ['pickle', 'json', 'msgpack', 'yaml']
broker_connection_max_retries: 1
broker_connection_retry_on_startup: True
broker_url: 'redis://127.0.0.1:6379/1'
crontab: <class 'celery.schedules.crontab'>
enable_utc: True
env_config: <decouple.Config object at 0x00000202A6E75B90>
redis_backend_health_check_interval: 10
result_backend: 'redis://127.0.0.1:6379/2'
result_backend_transport_options:
'retry_policy': {'max_retries': 1}}
result_expires: 3600
settings: <LazySettings "BioTime.settings">
task_always_eager: False
task_ignore_result: False
task_serializer: 'pickle'
timezone: 'UTC'
worker_cancel_long_running_tasks_on_connection_loss: True
worker_concurrency: 3
worker_log_format: ('[%(asctime)s: %(levelname)s %(filename)s '
'%(module)s.%(lineno)d] %(message)s')
worker_max_tasks_per_child: 100
deprecated_settings: None

repro steps：

app = Celery('tasks', broker='redis://:@127.0.0.1:6379/1')

app.conf.update(
    broker_connection_max_retries=1,
    beat_schedule = {
    'add': {
        'task': 'add',
        'schedule': 3,
    },
}
)

@app.task
def add(x, y):
    return x + y

1. redis is not running
2. run celery -A tasks beat --loglevel=INFO