Celery task disconnects from redis broker and takes a long time to reconnect

Viewed 420

I have a pretty stable setup with celery 4.4.7 and a redis node on AWS.

However, once every few weeks, I notice that the celery workers suddenly stop processing the queue.

If I inspect the logs, I see the following:

[2021-10-14 06:36:52,250: DEBUG/ForkPoolWorker-1] Executing task PutObjectTask(transfer_id=0, {'bucket': 'cdn.my-app.com', 'key': 'thumbs/-0DqXnEL1k3J_1824x0_n1wMX-gx.jpg', 'extra_args': {'ContentType': 'image/jpeg', 'Expires': 'Wed, 31 Dec 2036 23:59:59 GMT', 'StorageClass': 'INTELLIGENT_TIERING', 'ACL': 'private'}}) with kwargs {'client': <botocore.client.S3 object at 0xffff90746040>, 'fileobj': <s3transfer.utils.ReadFileChunk object at 0xffff9884d670>, 'bucket': 'cdn.my-app.com', 'key': 'thumbs/-0DqXnEL1k3J_1824x0_n1wMX-gx.jpg', 'extra_args': {'ContentType': 'image/jpeg', 'Expires': 'Wed, 31 Dec 2036 23:59:59 GMT', 'StorageClass': 'INTELLIGENT_TIERING', 'ACL': 'private'}}
[2021-10-14 06:36:52,253: DEBUG/ForkPoolWorker-1] Releasing acquire 0/None
[2021-10-14 06:36:52,429: DEBUG/ForkPoolWorker-1] Releasing acquire 0/None
[2021-10-14 06:37:50,202: INFO/MainProcess] missed heartbeat from celery@3a05aa0db663
[2021-10-14 06:37:50,202: INFO/MainProcess] missed heartbeat from celery@7c9532243cd0
[2021-10-14 06:37:50,202: INFO/MainProcess] missed heartbeat from celery@686f7e96d04f
[2021-10-14 06:54:06,510: WARNING/MainProcess] consumer: Connection to broker lost. Trying to re-establish the connection...
Traceback (most recent call last):
  File "/usr/local/lib/python3.8/dist-packages/redis/connection.py", line 706, in send_packed_command
    sendall(self._sock, item)
  File "/usr/local/lib/python3.8/dist-packages/redis/_compat.py", line 9, in sendall
    return sock.sendall(*args, **kwargs)
TimeoutError: [Errno 110] Connection timed out

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/usr/local/lib/python3.8/dist-packages/celery/worker/consumer/consumer.py", line 318, in start
    blueprint.start(self)
  File "/usr/local/lib/python3.8/dist-packages/celery/bootsteps.py", line 119, in start
    step.start(parent)
  File "/usr/local/lib/python3.8/dist-packages/celery/worker/consumer/consumer.py", line 599, in start
    c.loop(*c.loop_args())
  File "/usr/local/lib/python3.8/dist-packages/celery/worker/loops.py", line 83, in asynloop
    next(loop)
  File "/usr/local/lib/python3.8/dist-packages/kombu/asynchronous/hub.py", line 364, in create_loop
    cb(*cbargs)
  File "/usr/local/lib/python3.8/dist-packages/kombu/transport/redis.py", line 1083, in on_readable
    self.cycle.on_readable(fileno)
  File "/usr/local/lib/python3.8/dist-packages/kombu/transport/redis.py", line 354, in on_readable
    chan.handlers[type]()
  File "/usr/local/lib/python3.8/dist-packages/kombu/transport/redis.py", line 688, in _receive
    ret.append(self._receive_one(c))
  File "/usr/local/lib/python3.8/dist-packages/kombu/transport/redis.py", line 698, in _receive_one
    response = c.parse_response()
  File "/usr/local/lib/python3.8/dist-packages/redis/client.py", line 3501, in parse_response
    self.check_health()
  File "/usr/local/lib/python3.8/dist-packages/redis/client.py", line 3521, in check_health
    conn.send_command('PING', self.HEALTH_CHECK_MESSAGE,
  File "/usr/local/lib/python3.8/dist-packages/redis/connection.py", line 725, in send_command
    self.send_packed_command(self.pack_command(*args),
  File "/usr/local/lib/python3.8/dist-packages/redis/connection.py", line 717, in send_packed_command
    raise ConnectionError("Error %s while writing to socket. %s." %
redis.exceptions.ConnectionError: Error 110 while writing to socket. Connection timed out.
[2021-10-14 06:54:06,520: DEBUG/MainProcess] Canceling task consumer...
[2021-10-14 06:54:06,538: INFO/MainProcess] Connected to redis://my-redis-endpoint.cache.amazonaws.com:6379/0
[2021-10-14 06:54:06,548: INFO/MainProcess] mingle: searching for neighbors
[2021-10-14 07:09:45,507: INFO/MainProcess] mingle: sync with 1 nodes
[2021-10-14 07:09:45,507: DEBUG/MainProcess] mingle: processing reply from celery@3a05aa0db663
[2021-10-14 07:09:45,508: INFO/MainProcess] mingle: sync complete
[2021-10-14 07:09:45,536: INFO/MainProcess] Received task: my-app.tasks.retrieve_thumbnail[f50d66fd-28f5-4f1d-9b69-bf79daab43c0]  

Please note the amount of time passed with seemingly no activity between 06:37:50,202 (detected loss of connection from other workers) and 06:54:06,510 (detected loss of connection to broker), and also between 06:54:06,548 (reconnected to broker) and 07:09:45,536 started receiving tasks.

All in all, my celery setup was not processing tasks between 06:37:50 and 07:09:45, which impact the functioning of my app.

Any suggestions on how to tackle this issue?

Thanks!c

0 Answers
Related