Django unit tests hang forever when redis is not reachable #630

Activity

1. awbacker

   added

   question

   on Nov 9, 2022
2. adamkal commented on Jan 25, 2023

   

   adamkal

   on Jan 25, 2023

   More actions

   I have the same issue. I found an infinite loop in the TestCase._clean_tracebacks

   In my case this is the way excs changes with each loop:

   [(<class 'redis.exceptions.ConnectionError'>, ConnectionError('Error 111 connecting to localhost:6379. Connection refused.'), <traceback object at 0x7f064a03f700>)]
   [(<class 'django_redis.exceptions.ConnectionInterrupted'>, ConnectionInterrupted(), <traceback object at 0x7f0649e8fa00>)]
   [(<class 'redis.exceptions.ConnectionError'>, ConnectionError('Error 111 connecting to localhost:6379. Connection refused.'), <traceback object at 0x7f064a03f700>)]
   [(<class 'django_redis.exceptions.ConnectionInterrupted'>, ConnectionInterrupted(), <traceback object at 0x7f0649e8fa00>)]
   

   Seems to me that the problem is in this line in omit_exception.

   I noticed that the algorithm for cleaning is fairly fresh which might be the trigger of the issue
3. awbacker commented on Jan 25, 2023

   

   awbacker

   on Jan 25, 2023

   Author

   More actions

   Not sure how you tracked yours down, but so far mine doesn't seem the same. I stuck a couple print()s around there and saw nothing.

   Maybe I've posted this in the wrong place. At the time I thought it was right, though, but now it seems like I have even less clue. RQ? core redis?

   In my case it doesn't even seem to start the testing, and the stack trace when I kill the process is always stuck here:

   python3.11/site-packages/rq/job.py", line 696, in save
       if self.get_redis_server_version() >= (4, 0, 0):
          ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
   ...
   python3.11/site-packages/rq/utils.py", line 281, in get_version
       return tuple(int(i) for i in connection.info("server")["redis_version"].split('.')[:3])
   ...
   python3.11/site-packages//rq_scheduler/scheduler.py", line 246, in schedule
       job.save()
   ...
   python3.11/site-packages/redis/connection.py", line 734, in on_connect
       if str_if_bytes(self.read_response()) != "OK":
                       ^^^^^^^^^^^^^^^^^^^^
   ...
   python3.11/site-packages/redis/connection.py", line 318, in read_response
       raw = self._buffer.readline()
             ^^^^^^^^^^^^^^^^^^^^^^^
   python3.11/site-packages/redis/connection.py", line 249, in readline
       self._read_from_socket()
   python3.11/site-packages/redis/connection.py", line 192, in _read_from_socket
       data = self._sock.recv(socket_read_size)
              ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
   
4. adamkal commented on Jan 26, 2023

   

   adamkal

   on Jan 26, 2023

   Last edited by adamkal

   More actions

   Indeed. I definitely get an connection exception that goes further into tests and get's stuck later, when collecting traceback.

   Might be worth mentioning I'm working on Python 3.9
5. awbacker commented on Jan 26, 2023

   

   awbacker

   on Jan 26, 2023

   Last edited by awbacker

   Author

   More actions

   My tone comes off way wrong on that one, what I meant was: "I don't know how you tracked that down, amazing work. I read the code and didn't see anything wrong, hats off to you!"

   This is definitely posted in the wrong place, it should be in redis or in rq/rq_scheduler if not. Hang is also on runserver and not just test

   Not sure what else to do to track this down, other than move the issue over there. I'll close this one. For posterity:

   Retested on 3.10 with fully upgraded redis/rq/etc and the same issue at the same point (with different surrounding code). The hang is in redis.py itself, but probably originates somewhere else like with a misconfigured client.

   connection.connect() hangs for at least >5 minutes

   https://github.com/rq/rq/blob/master/rq/utils.py#L325

   def get_version(connection: 'Redis'):
       try:
           # ... cache it on the connection object
           if not getattr(connection, "__rq_redis_server_version", None):
               setattr(
                   connection,
                   "__rq_redis_server_version",
                   # <<<
                   # <<< ------------ hang in connection.info() --------------
                   # <<<
                   tuple(int(i) for i in connection.info("server")["redis_version"].split('.')[:3])
               )
           return getattr(connection, "__rq_redis_server_version")
       except ResponseError:  # fakeredis doesn't implement Redis' INFO command
           return (5, 0, 9)
   

   rq_scheduler/scheduler.py@246,  schedule():    job.save()
   rq/job.py@759,              save():            if self.get_redis_server_version()...
   rq/job.py@722,              get_redis_server_version():  ... = get_version(self.connection)
   rq/utils.py@311,            get_version():     ... connection.info("server")...
   redis/commands/core.py@982, info():            self.execute_command("INFO", ...
   redis/client.py@1255,       execute_command(): conn = self.connection or pool.get_...
   redis/connection.py@1427,   get_connection():  connection.connect()
   redis/connection.py@636,    connect():         self.on_connect()
   redis/connection.py@759,    on_connect():      if str_if_bytes(self.read_response()) != "OK":
   redis/connection.py@848,    read_response():   response = self._parser.read_response(...
   redis/connection.py@335,    read_response():   self._read_response(...)
   redis/connection.py@344,    _read_response():  raw = self._buffer.readline()
   redis/connection.py@243,    readline():        self._read_from_socket()
   redis/connection.py", line 192, in _read_from_socket
       data = self._sock.recv(socket_read_size)
   # infinite hang here
   
6. awbacker commented on Jan 26, 2023

   

   awbacker

   on Jan 26, 2023

   Author

   More actions

   This issue is not the result of django-redis, as far as I can tell. Reopen if you find a link.
7. awbacker

   closed this as completedon Jan 26, 2023
8. awbacker commented on Jan 26, 2023

   

   awbacker

   on Jan 26, 2023

   Last edited by awbacker

   Author

   More actions

   I have the same issue. I found an infinite loop in the TestCase._clean_tracebacks

   In my case this is the way excs changes with each loop:

   [(<class 'redis.exceptions.ConnectionError'>, ConnectionError('Error 111 connecting to localhost:6379. Connection refused.'), <traceback object at 0x7f064a03f700>)]
   [(<class 'django_redis.exceptions.ConnectionInterrupted'>, ConnectionInterrupted(), <traceback object at 0x7f0649e8fa00>)]
   [(<class 'redis.exceptions.ConnectionError'>, ConnectionError('Error 111 connecting to localhost:6379. Connection refused.'), <traceback object at 0x7f064a03f700>)]
   [(<class 'django_redis.exceptions.ConnectionInterrupted'>, ConnectionInterrupted(), <traceback object at 0x7f0649e8fa00>)]
   

   I see this now, too, it was covered up before by the other library failing first!

   • Visible when using standard redis cache
   • Hidden by rq_scheduler and job.save() infinite hang on recv first
   • This leads me to believe the scheduler is not setting Redis options correctly

   Thanks!