Uploaded image for project: 'Moodle'
  1. Moodle
  2. MDL-72796

retry interval in milliseconds for redis session cache is far too high

    XMLWordPrintable

Details

    • Bug
    • Status: Closed
    • Minor
    • Resolution: Fixed
    • 3.9.10, 3.10.7, 3.11.3
    • 3.11.5
    • Caching
    • MOODLE_310_STABLE, MOODLE_311_STABLE, MOODLE_39_STABLE
    • MOODLE_311_STABLE
    • MDL-72796_M39_fix-retry-delay-for-redis-session-cache
    • MDL-72796_M311_fix-retry-delay-for-redis-session-cache
    • MDL-72796_fix-retry-delay-for-redis-session-cache
    • Hide
      Setup
      1. The prerequisite is a working Redis installation available on localhost.
        1. Install the PHP Redis extension appropriate for your PHP version. e.g. for PHP 7.4 on Ubuntu

          sudo apt install php7.4-redis
          

        2. Run a Redis server via Docker

          docker run --name my-redis --network host -d redis 
          

      2. Add the following to config.php

        define('TEST_SESSION_REDIS_HOST', '127.0.0.1');
        $CFG->session_handler_class = '\core\session\redis';
        $CFG->session_redis_host = '127.0.0.1';
        $CFG->session_redis_acquire_lock_timeout = 120;
        $CFG->session_redis_lock_expire = 7200;
        

      Test
      1. Set up PHPUnit and run:
        vendor/bin/phpunit lib/tests/session_redis_test.php
        to verify that there are no regressions.
      2. Using the redis-cli set the connection timeout to 5 seconds.
        CONFIG SET timeout 5
      3. Then download the redis_sessions_timeout.php script from this issue and put it in the webroot and run it as the apache user:
        sudo -u www-data php path/to/moodle/redis_sessions_timeout.php

      Before the patch, this should wait a very long time, after applying the patch it should be rather quick to reconnect to the Redis server.

      Show
      Setup The prerequisite is a working Redis installation available on localhost. Install the PHP Redis extension appropriate for your PHP version. e.g. for PHP 7.4 on Ubuntu sudo apt install php7.4-redis Run a Redis server via Docker docker run --name my-redis --network host -d redis Add the following to config.php define( 'TEST_SESSION_REDIS_HOST' , '127.0.0.1' ); $CFG->session_handler_class = '\core\session\redis' ; $CFG->session_redis_host = '127.0.0.1' ; $CFG->session_redis_acquire_lock_timeout = 120 ; $CFG->session_redis_lock_expire = 7200 ; Test Set up PHPUnit and run: vendor/bin/phpunit lib/tests/session_redis_test.php to verify that there are no regressions. Using the redis-cli set the connection timeout to 5 seconds. CONFIG SET timeout 5 Then download the redis_sessions_timeout.php script from this issue and put it in the webroot and run it as the apache user: sudo -u www-data php path/to/moodle/redis_sessions_timeout.php Before the patch, this should wait a very long time, after applying the patch it should be rather quick to reconnect to the Redis server.

    Description

      In lib/classes/session/redis.php on Line 196, a random delay between 100000 and 500000 is selected. It is further used as the 5th parameter for the Redis->connect() call. That's the $retryInterval, a retry interval in milliseconds.

      This means we are effectively waiting with a retry delay of 100 seconds to 500 seconds. The indented wait should be 100 ms to 500 ms, see here for reference.
      That's off by a factor of a thousand! Using Redis as a session cache and when the connection hangs, you can get random cannot obtain session lock errors because it's waiting up to 500 seconds (or about 8.33 minutes) for a Redis connection.

      Attachments

        Issue Links

          Activity

            People

              Daniel Ziegenberg Daniel Ziegenberg
              Daniel Ziegenberg Daniel Ziegenberg
              Brendan Heywood Brendan Heywood
              Andrew Lyons Andrew Lyons
              Angelia Dela Cruz Angelia Dela Cruz
              Matteo Scaramuccia, Amaia Anabitarte, Carlos Escobedo, Ferran Recio, Ilya Tregubov, Laurent David, Raquel Ortega, Sara Arjona (@sarjona)
              Votes:
              3 Vote for this issue
              Watchers:
              15 Start watching this issue

              Dates

                Created:
                Updated:
                Resolved:
                17/Jan/22

                Time Tracking

                  Estimated:
                  Original Estimate - 0 minutes
                  0m
                  Remaining:
                  Remaining Estimate - 0 minutes
                  0m
                  Logged:
                  Time Spent - 1 hour
                  1h