Kombu: "Error 110 while writing to socket. Connection timed out." With kombu 4.4.0/4.5.0 and redis 3.2.0/3.2.1

[alexandre-paroissien]

I was previously on kombu 4.3.0 and redis 2.10.6, and after upgrading to kombu 4.4.0/4.5.0 and redis 3.2.0/3.2.1 I noticed a new issue on my Django REST endpoints:

Error 110 while writing to socket. Connection timed out.

These endpoints never had any issues before and this issue popped up only once since I upgraded, but happened on both endpoints simultaneously

Edit: Bug still there in most recent versions of the libraries (celery 4.3.0, kombu 4.5.0, redis 3.2.1)
(I also had the bug when just upgrading kombu/redis and keeping celery at 4.2.2)
Bug is not there in celery 4.2.2, kombu 4.3.0, redis 2.10.6

2019-05-21T07:51:02.022118+00:00 app[worker.1]: [2019-05-21 07:51:02,021: ERROR/ForkPoolWorker-5] Connection to Redis lost: Retry (0/20) now.
2019-05-21T07:51:02.024750+00:00 app[worker.1]: [2019-05-21 07:51:02,024: ERROR/ForkPoolWorker-5] Connection to Redis lost: Retry (1/20) in 1.00 second.
2019-05-21T07:51:03.028332+00:00 app[worker.1]: [2019-05-21 07:51:03,028: ERROR/ForkPoolWorker-5] Connection to Redis lost: Retry (2/20) in 1.00 second.
2019-05-21T07:51:04.032513+00:00 app[worker.1]: [2019-05-21 07:51:04,032: ERROR/ForkPoolWorker-5] Connection to Redis lost: Retry (3/20) in 1.00 second.
2019-05-21T07:51:05.037741+00:00 app[worker.1]: [2019-05-21 07:51:05,037: ERROR/ForkPoolWorker-5] Connection to Redis lost: Retry (4/20) in 1.00 second.
2019-05-21T07:51:06.041513+00:00 app[worker.1]: [2019-05-21 07:51:06,041: ERROR/ForkPoolWorker-5] Connection to Redis lost: Retry (5/20) in 1.00 second.
2019-05-21T07:51:07.045367+00:00 app[worker.1]: [2019-05-21 07:51:07,045: ERROR/ForkPoolWorker-5] Connection to Redis lost: Retry (6/20) in 1.00 second.
2019-05-21T07:51:08.048339+00:00 app[worker.1]: [2019-05-21 07:51:08,048: ERROR/ForkPoolWorker-5] Connection to Redis lost: Retry (7/20) in 1.00 second.
2019-05-21T07:51:09.052390+00:00 app[worker.1]: [2019-05-21 07:51:09,052: ERROR/ForkPoolWorker-5] Connection to Redis lost: Retry (8/20) in 1.00 second.

[nyhobbit]

I confirm that I encountered the same issue and also Error 32 (broken pipe) AS PER #1018 after upgrading to the combination of:

• celery 4.3.0 RC2
• kombu 4.4.0
• redis 3.2.0

The errors are intermittent: certain transactions work out and write into redis just fine, others break down. The stack traces when errors occur are identical to the ones from the OP.
I have not been able to uncover any specifics about which transactions are likely to fail and which are likely to work. The entries I write in redis are all very similar, and it looks like sometimes the same entry that had broken down earlier get written just fine later.

The most up-to-date combination of libraries that seems to guarantee the disappearance of these issues is to my knowledge as follows:

• celery 4.2.1
• kombu 4.3.0
• redis 2.10.6

However, I would really like to be able to upgrade to redis >= 3.0 without losing this guarantee. If you could publish a 4.2.x celery version that supports redis 3.x and is stable with respect to #1018 and #1019 it would be greatly appreciated.

[alexandre-paroissien]

Here is my environment, exceptions only happen when I switch from kombu 4.3.0 and redis 2.10.6 to kombu 4.4.0 and redis 3.2.0 (The environment and the other libraries remaining unchanged)

Stack:
Ubuntu 18 (Heroku-18)
Python 3.6.8
Redis 3.2.12 (Redis To Go)

Libraries:
Django==2.1.7
djangorestframework==3.9.1
celery==4.2.1
kombu==4.3.0 ok / 4.4.0 not ok
billiard==3.5.0.5
amqp==2.4.2
vine==1.2.0
django-celery-beat==1.4.0
redis==2.10.6 ok / redis 3.2.0 not ok

I hope this can help understanding the exceptions. Is there any other information I could collect or tests I could do?

[thedrow]

How about the Redis logs?
Maybe you could also ask upstream?

[thedrow]

@nyhobbit I don't think that's possible but we can look into it if you'll open a new issue about it.

[alexandre-paroissien]

@thedrow Ok I will check the logs

By upstream you mean python-redis library?

I just checked and it seems you're right! Found the following issues in python-redis:

Sporadic "Connection not ready" exceptions with BlockingConnectionPool since 3.2.0 (22 days ago)
https://github.com/andymccurdy/redis-py/issues/1136

3.2.0 Error while reading from socket: ('Connection closed by server.',) (15 days ago)
https://github.com/andymccurdy/redis-py/issues/1140

[alexandre-paroissien]

These 2 previous issues are there in python-redis 3.2.0

Reverting to 3.1.0 would reintroduce this issue that was fixed in 3.2.0:
https://github.com/andymccurdy/redis-py/issues/1127

So maybe the previous python-redis 3.0.1 would be fine?

But it seems that currently kombu is requiring redis >= 3.2.0

[thedrow]

Are you using eventlet?

3.0.1 doesn't work since it crashes Celery when forking.

[alexandre-paroissien]

I am not using eventlet

I just posted this comment on redis-py https://github.com/andymccurdy/redis-py/issues/1140#issuecomment-472712115

[dejlek]

I've noticed similar behaviour as well. I had to fix this by catching the error and reconnecting... It is really annoying. It reminds me of another problem that started few months ago - with connection timeouts. I've reported this to Celery but who knows what is really causing it...

[alexandre-paroissien]

Hi @nyhobbit and @dejlek I still have the issue, how about you? Any update?
Maybe you can report your situation there too https://github.com/andymccurdy/redis-py/issues/1140

[auvipy]

celery 4.3 and latest kombu?

[harrybiddle]

Hey @alexandre-paroissien, I'm sorry, I gave up and downgraded to Redis 2.10.6 / Kombu 4.3.0 / a forked Celery 4.2 with Python 3.7 support...!

I also considered doing what @dejlek did; I think if we have to upgrade and the problem is still there that's what I'll have to do too :(.

[auvipy]

did you try kombu 4.5 and celery 4.3?

[harrybiddle]

I saw this on two stacks: one with

• celery 4.3.0rc1
• kombu 4.3.0
• redis 3.2.0

and another with

• celery 4.3.0rc1
• kombu 4.4.0
• redis 3.2.1

In both cases the downgrade to Celery 4.2 / kombu 4.3.0 / redis 2.10.6 fixed it. I don't know which library was causing the issue!

Unfortunately we don't have a great testing environment for me to try other combinations. It only appeared intermittently on production, and not at all on staging, I guess because the staging traffic was too low. We have a plan to run some load testing on staging. I very much doubt we'll do it any time soon, but if we do get to that and this issue is still open I'll try newer versions of the libraries!

[alexandre-paroissien]

I confirm I still encounter this issue in the most recent versions of the libraries
celery 4.3.0, kombu 4.5.0, redis 3.2.1

(I also had the bug when just upgrading kombu/redis and keeping celery at 4.2.1)

I tested in a test app with no traffic apart from me, I launched a simple task manually, first time worked, second time gave the following output (and ending up working)

2019-05-21T07:51:02.022118+00:00 app[worker.1]: [2019-05-21 07:51:02,021: ERROR/ForkPoolWorker-5] Connection to Redis lost: Retry (0/20) now.
2019-05-21T07:51:02.024750+00:00 app[worker.1]: [2019-05-21 07:51:02,024: ERROR/ForkPoolWorker-5] Connection to Redis lost: Retry (1/20) in 1.00 second.
2019-05-21T07:51:03.028332+00:00 app[worker.1]: [2019-05-21 07:51:03,028: ERROR/ForkPoolWorker-5] Connection to Redis lost: Retry (2/20) in 1.00 second.
2019-05-21T07:51:04.032513+00:00 app[worker.1]: [2019-05-21 07:51:04,032: ERROR/ForkPoolWorker-5] Connection to Redis lost: Retry (3/20) in 1.00 second.
2019-05-21T07:51:05.037741+00:00 app[worker.1]: [2019-05-21 07:51:05,037: ERROR/ForkPoolWorker-5] Connection to Redis lost: Retry (4/20) in 1.00 second.
2019-05-21T07:51:06.041513+00:00 app[worker.1]: [2019-05-21 07:51:06,041: ERROR/ForkPoolWorker-5] Connection to Redis lost: Retry (5/20) in 1.00 second.
2019-05-21T07:51:07.045367+00:00 app[worker.1]: [2019-05-21 07:51:07,045: ERROR/ForkPoolWorker-5] Connection to Redis lost: Retry (6/20) in 1.00 second.
2019-05-21T07:51:08.048339+00:00 app[worker.1]: [2019-05-21 07:51:08,048: ERROR/ForkPoolWorker-5] Connection to Redis lost: Retry (7/20) in 1.00 second.
2019-05-21T07:51:09.052390+00:00 app[worker.1]: [2019-05-21 07:51:09,052: ERROR/ForkPoolWorker-5] Connection to Redis lost: Retry (8/20) in 1.00 second.

[alexandre-paroissien]

Could it be related to this issue? https://github.com/celery/celery/issues/3932

[thedrow]

Your problem appeared while upgrading py-redis so I don't know really.

[alexandre-paroissien]

Right, for anyone reading this, it seems the issue appeared from the 3.x branch of redispy indeed (which is required by celery 4.3+ / kombu 4.4+), and the status of the issue is evolving there:

https://github.com/andymccurdy/redis-py/issues/1140

[thedrow]

Why is this closed? The upstream issue is not resolved.

[mlissner]

I'm unfortunately in no position to fix this, but I thought I'd at least make sure that the dots were connected between redis-py and here. Over on their upstream issue, they just did a release (3.3.0) with a new feature, and they say:

For Celery users, this change won't automatically fix ConnectionErrors encountered by Celery. Celery uses PubSub in a non-standard way which can not take advantage of the automatic health checks at this time. Once this code is released, we should be able to create a PR for Celery to regularly call pubsub.check_health().

(https://github.com/andymccurdy/redis-py/issues/1140#issuecomment-515634842)

It'd be great to have Celery start using this functionality.

[bwilliams18]

Is there currently a bodge to prevent this from happening while a more permanent fix is in the works?

[thedrow]

Nope.
Someone needs to contribute a PR.

[wowkin2]

What needs to be done here?

• Should adding health_check_interval=30 by default to a kombu client for Redis and setting redis-py version >= 3.3.0 be enough?
• Anybody tested that on any environment?

[thedrow]

It is more complicated than that.
You'll have to integrate with our event loop and ensure that the check is run periodically.

[jschwartzentruber]

Like this, or is there more to it?

diff --git a/kombu/transport/redis.py b/kombu/transport/redis.py
index b4a3d362..60a444bb 100644
--- a/kombu/transport/redis.py
+++ b/kombu/transport/redis.py
@@ -339,6 +339,12 @@ class MultiChannelPoller(object):
                     num=channel.unacked_restore_limit,
                 )

+    def maybe_check_subclient_health(self):
+        for channel in self._channels:
+            client = channel.__dict__.get('subclient')  # only if property cached
+            if client is not None:
+                client.check_health()
+
     def on_readable(self, fileno):
         chan, type = self._fd_to_chan[fileno]
         if chan.qos.can_consume():
@@ -1095,6 +1101,7 @@ class Transport(virtual.Transport):
             [add_reader(fd, on_readable, fd) for fd in cycle.fds]
         loop.on_tick.add(on_poll_start)
         loop.call_repeatedly(10, cycle.maybe_restore_messages)
+        loop.call_repeatedly(30, cycle.maybe_check_subclient_health)

     def on_readable(self, fileno):
         """Handle AIO event for one of our file descriptors."""

[thedrow]

I think that might do the trick (although the interval should be configurable using broker_transport_options in my opinion).
Can anyone apply this patch and ensure that it works?

[rotten]

I can confirm that with:

celery==4.3.0
kombu==4.6.5
amqp==2.5.1
redis==3.3.8

we are still getting a very high frequency of timeouts, even after a bunch of broker_transport_options tuning attempts. I was so hopeful the new Redis version would make a difference. :-(

We will try backing out of some of these upgrades this week to see if we can get back to where we were before upgrading those libraries. We'll probably have to drop back from python 3.7 to 3.6.8 too, so this is a real pain to back down on.

[thedrow]

@rotten Can you try to apply @jschwartzentruber's patch?
I want to see if that works.

[rotten]

@rotten Can you try to apply @jschwartzentruber's patch?
I want to see if that works.

I gave up before I saw your message and switch to a RabbitMQ backend. Sorry! I think that swap solved our timeout issues. I'm still testing to be sure.

[Ashish-Bansal]

This would fix the issue in places where celery event loop is running.

What about cases when celery event loop isn't running ?

Example: Let's say we have two services, frontend server and backend server. Frontend just accepts HTTP requests from the client-side and then uses celery.send_task to enqueue a task. In that case, celery event loop won't be running and these health checks won't be triggered.

Though, I would like to know if above setup is correct logically ? If yes, then I'm not sure if we can really handle it gracefully. Seems like user will have to wrap send_task manually to catch exception and try again. Or more graceful way would be celery kombu issuing health checks manually once every x seconds before any interaction with transport and recreate connection if connection is already dead. This way it would be independent of celery's event loop.

[Fiftyseventheory]

I'm experiencing this issue as well.
celery==4.3.0
kombu==4.6.4
redis==3.3.8

[rotten]

On Nov 27, 2019 12:43 PM, Fiftyseventheory [e-mail] wrote:I'm experiencing this issue as well.
celery==4.3.0
kombu==4.6.4
redis==3.3.8

—You are receiving this because you were mentioned.Reply to this email directly, view it on GitHub, or unsubscribe.
It is definitely better with Celery 4.4.0rc3/4, and slightly better with pyamqp instead of redis.  I can't say it is totally solved though.  We still see these pop up, just not as often.

[auvipy]

thanks for the report. there is an open PR relating to this check https://github.com/celery/kombu/pull/1122 plz

[wisefool769]

I am still seeing this with:
celery==4.4.0
django-redis==4.10.0
kombu==4.6.7
redis==3.3.11

Is there any setting i have to change to pick up the fixes in #1122 ?

[jingtt0704]

I am still seeing this with:
celery==4.4.0
django-redis==4.10.0
kombu==4.6.7
redis==3.3.11

Is there any setting i have to change to pick up the fixes in #1122 ?

I am also still having the issue with the same lib versions

[Ashish-Bansal]

@wisefool769 @jingtt0704 This issue will still persist in case celery's event loop is not running.

Ref - https://github.com/celery/kombu/issues/1019#issuecomment-552538834

[sklarsa]

@auvipy can this issue be reopened? I don't think this is fully resolved yet, as I'm experiencing errors similar to many of the recent commenters on this thread

[sklarsa]

@Ashish-Bansal Is there any way that I can help fix this in the case you described where celery's event loop is not running?

For clarification, I'm running

celery = "=4.3.0"
kombu = "=4.4.0"
redis = "=2.10.5"

[auvipy]

try latest celery with latest kombu

[gtalarico]

Sorry to pile up on this, just wanted to report I am having the same error, and I am on the latest releases of celery, kombu and redis.

Traceback

[2020-03-24 16:28:44,787: INFO/MainProcess] mingle: all alone
[2020-03-24 16:30:23,873: WARNING/MainProcess] consumer: Connection to broker lost. Trying to re-establish the connection...
Traceback (most recent call last):
  File "/usr/local/lib/python3.7/site-packages/celery/worker/consumer/consumer.py", line 318, in start
    blueprint.start(self)
  File "/usr/local/lib/python3.7/site-packages/celery/bootsteps.py", line 119, in start
    step.start(parent)
  File "/usr/local/lib/python3.7/site-packages/celery/worker/consumer/consumer.py", line 599, in start
    c.loop(*c.loop_args())
  File "/usr/local/lib/python3.7/site-packages/celery/worker/loops.py", line 83, in asynloop
    next(loop)
  File "/usr/local/lib/python3.7/site-packages/kombu/asynchronous/hub.py", line 364, in create_loop
    cb(*cbargs)
  File "/usr/local/lib/python3.7/site-packages/kombu/transport/redis.py", line 1088, in on_readable
    self.cycle.on_readable(fileno)
  File "/usr/local/lib/python3.7/site-packages/kombu/transport/redis.py", line 359, in on_readable
    chan.handlers[type]()
  File "/usr/local/lib/python3.7/site-packages/kombu/transport/redis.py", line 693, in _receive
    ret.append(self._receive_one(c))
  File "/usr/local/lib/python3.7/site-packages/kombu/transport/redis.py", line 703, in _receive_one
    response = c.parse_response()
  File "/usr/local/lib/python3.7/site-packages/redis/client.py", line 3453, in parse_response
    response = self._execute(conn, conn.read_response)
  File "/usr/local/lib/python3.7/site-packages/redis/client.py", line 3427, in _execute
    return command(*args, **kwargs)
  File "/usr/local/lib/python3.7/site-packages/redis/connection.py", line 734, in read_response
    response = self._parser.read_response()
  File "/usr/local/lib/python3.7/site-packages/redis/connection.py", line 316, in read_response
    response = self._buffer.readline()
  File "/usr/local/lib/python3.7/site-packages/redis/connection.py", line 248, in readline
    self._read_from_socket()
  File "/usr/local/lib/python3.7/site-packages/redis/connection.py", line 193, in _read_from_socket
    raise ConnectionError(SERVER_CLOSED_CONNECTION_ERROR)
redis.exceptions.ConnectionError: Connection closed by server.
[2020-03-24 16:30:23,911: INFO/MainProcess] Connected to redis://redis:11535//

celery==4.4.1
kombu==4.6.8
redis==3.4.1

[adi-]

Same here. Any fixes on that?

[yashu-seth]

Same here.