redis.exceptions.ConnectionError: Error 111 connecting to localhost:6379. Connection refused

Site Operators Site Operations Help
1

This error began appearing on a single-server installation of koa.master, in /edx/var/log/supervisor/lms_default_1-stderr.log a few months after it went live. Of the five Celery workers that i know of (three in LMS + 2 in CMS), this is the only worker that generates any errors; and at that, the only errors appear during platform restarts and server reboots. The stack trace is pasted below.

Importantly, no one has connected to the server since it went live in december-2020. More generally, i haven’t been able to locate any worker-specific connection parameters anywhere in the platform.

Has anyone else ever seen this?

worker: Warm shutdown (MainProcess) 
2021-03-01 15:32:10,129 WARNING 1460 [celery.redirected] [user None] [ip None] log.py:235 - Restoring 1 unacknowledged message(s)
2021-03-01 15:32:10,137 WARNING 1460 [celery.redirected] [user None] [ip None] log.py:235 - Traceback (most recent call last):
2021-03-01 15:32:10,139 WARNING 1460 [celery.redirected] [user None] [ip None] log.py:235 - File "/edx/app/edxapp/venvs/edxapp/lib/python3.8/site-packages/redis/connection.py", line 1198, in get_connection
    if connection.can_read():
2021-03-01 15:32:10,140 WARNING 1460 [celery.redirected] [user None] [ip None] log.py:235 - File "/edx/app/edxapp/venvs/edxapp/lib/python3.8/site-packages/redis/connection.py", line 734, in can_read
    return self._parser.can_read(timeout)
2021-03-01 15:32:10,140 WARNING 1460 [celery.redirected] [user None] [ip None] log.py:235 - File "/edx/app/edxapp/venvs/edxapp/lib/python3.8/site-packages/redis/connection.py", line 321, in can_read
    return self._buffer and self._buffer.can_read(timeout)
2021-03-01 15:32:10,141 WARNING 1460 [celery.redirected] [user None] [ip None] log.py:235 - File "/edx/app/edxapp/venvs/edxapp/lib/python3.8/site-packages/redis/connection.py", line 230, in can_read
    self._read_from_socket(timeout=timeout,
2021-03-01 15:32:10,141 WARNING 1460 [celery.redirected] [user None] [ip None] log.py:235 - File "/edx/app/edxapp/venvs/edxapp/lib/python3.8/site-packages/redis/connection.py", line 201, in _read_from_socket
    raise ConnectionError(SERVER_CLOSED_CONNECTION_ERROR)
2021-03-01 15:32:10,142 WARNING 1460 [celery.redirected] [user None] [ip None] log.py:235 - redis.exceptions.ConnectionError: Connection closed by server.
2021-03-01 15:32:10,142 WARNING 1460 [celery.redirected] [user None] [ip None] log.py:235 - During handling of the above exception, another exception occurred:
2021-03-01 15:32:10,143 WARNING 1460 [celery.redirected] [user None] [ip None] log.py:235 - Traceback (most recent call last):
2021-03-01 15:32:10,143 WARNING 1460 [celery.redirected] [user None] [ip None] log.py:235 - File "/edx/app/edxapp/venvs/edxapp/lib/python3.8/site-packages/redis/connection.py", line 559, in connect
    sock = self._connect()
2021-03-01 15:32:10,143 WARNING 1460 [celery.redirected] [user None] [ip None] log.py:235 - File "/edx/app/edxapp/venvs/edxapp/lib/python3.8/site-packages/redis/connection.py", line 615, in _connect
    raise err
2021-03-01 15:32:10,144 WARNING 1460 [celery.redirected] [user None] [ip None] log.py:235 - File "/edx/app/edxapp/venvs/edxapp/lib/python3.8/site-packages/redis/connection.py", line 603, in _connect
    sock.connect(socket_address)
2021-03-01 15:32:10,144 WARNING 1460 [celery.redirected] [user None] [ip None] log.py:235 - ConnectionRefusedError: [Errno 111] Connection refused
2021-03-01 15:32:10,145 WARNING 1460 [celery.redirected] [user None] [ip None] log.py:235 - During handling of the above exception, another exception occurred:
2021-03-01 15:32:10,145 WARNING 1460 [celery.redirected] [user None] [ip None] log.py:235 - Traceback (most recent call last):
2021-03-01 15:32:10,146 WARNING 1460 [celery.redirected] [user None] [ip None] log.py:235 - File "/usr/lib/python3.8/multiprocessing/util.py", line 300, in _run_finalizers
    finalizer()
2021-03-01 15:32:10,146 WARNING 1460 [celery.redirected] [user None] [ip None] log.py:235 - File "/usr/lib/python3.8/multiprocessing/util.py", line 224, in __call__
    res = self._callback(*self._args, **self._kwargs)
2021-03-01 15:32:10,147 WARNING 1460 [celery.redirected] [user None] [ip None] log.py:235 - File "/edx/app/edxapp/venvs/edxapp/lib/python3.8/site-packages/kombu/transport/virtual/base.py", line 287, in restore_unacked_once
    unrestored = self.restore_unacked()
2021-03-01 15:32:10,147 WARNING 1460 [celery.redirected] [user None] [ip None] log.py:235 - File "/edx/app/edxapp/venvs/edxapp/lib/python3.8/site-packages/kombu/transport/redis.py", line 164, in restore_unacked
    self.restore_by_tag(tag, client=client)
2021-03-01 15:32:10,148 WARNING 1460 [celery.redirected] [user None] [ip None] log.py:235 - File "/edx/app/edxapp/venvs/edxapp/lib/python3.8/site-packages/kombu/transport/redis.py", line 212, in restore_by_tag
    p, _, _ = self._remove_from_indices(
2021-03-01 15:32:10,148 WARNING 1460 [celery.redirected] [user None] [ip None] log.py:235 - File "/edx/app/edxapp/venvs/edxapp/lib/python3.8/site-packages/redis/client.py", line 4012, in execute
    conn = self.connection_pool.get_connection('MULTI',
2021-03-01 15:32:10,149 WARNING 1460 [celery.redirected] [user None] [ip None] log.py:235 - File "/edx/app/edxapp/venvs/edxapp/lib/python3.8/site-packages/redis/connection.py", line 1202, in get_connection
    connection.connect()
2021-03-01 15:32:10,149 WARNING 1460 [celery.redirected] [user None] [ip None] log.py:235 - File "/edx/app/edxapp/venvs/edxapp/lib/python3.8/site-packages/redis/connection.py", line 563, in connect
    raise ConnectionError(self._error_message(e))
2021-03-01 15:32:10,150 WARNING 1460 [celery.redirected] [user None] [ip None] log.py:235 - redis.exceptions.ConnectionError: Error 111 connecting to localhost:6379. Connection refused.
2021-03-01 15:33:42,641 INFO 1453 [celery.worker.consumer.connection] [user None] [ip None] connection.py:24 - Connected to redis://:**@localhost:6379//
2021-03-01 15:33:42,650 INFO 1453 [celery.worker.consumer.mingle] [user None] [ip None] mingle.py:43 - mingle: searching for neighbors
2021-03-01 15:33:43,676 INFO 1453 [celery.worker.consumer.mingle] [user None] [ip None] mingle.py:46 - mingle: sync with 1 nodes
2021-03-01 15:33:43,677 INFO 1453 [celery.worker.consumer.mingle] [user None] [ip None] mingle.py:50 - mingle: sync complete
2021-03-01 15:33:43,696 INFO 1453 [celery.apps.worker] [user None] [ip None] worker.py:161 - celery@edx.lms.core.default.ip-172-31-65-223 ready.
2021-03-01 15:33:44,542 INFO 1453 [celery.worker.strategy] [user None] [ip None] strategy.py:157 - Received task: student.send_activation_email[fd091742-e14a-4d17-92bc-9673b2406cb4]
2021-03-01 15:33:45,167 INFO 1453 [celery.worker.strategy] [user None] [ip None] strategy.py:157 - Received task: openedx.core.djangoapps.content.block_structure.tasks.update_course_in_cache_v2[33b8cb5e-0e48-4625-8ec8-5ed5c42ef674]  ETA:[2021-01-28 15:27:53.581180+00:00]
2

I am not really sure if it is related or not, but have you included this patch?

I came out a few days after koa.master (koa.1 at the time) was released.

There was a discussion I started on Slack about it that was answered by Jeremy Bowman on December 11th
https://openedx.slack.com/team/U0FBUJYCT

3

Thanks @sambapete, this might well be the culprit. the koa.master installation in question was done on or around 10-december, and i might have just missed this commit.

1 Like