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

Extra session lock debugging for redis session handler

    XMLWordPrintable

    Details

    • Testing Instructions:
      Hide
      1. Ensure debugging is turned on on your site.
      2. Setup redis
      3. Setup redis as the session handler (notice the session_redis_acquire_lock_timeout value):

        $CFG->session_redis_host = '127.0.0.1';
        $CFG->session_redis_port = 6379; // Optional.
        $CFG->session_redis_acquire_lock_timeout = 5;
        $CFG->session_handler_class = '\core\session\redis';
        

      4. Write a dud script that hangs onto the session for ages called long-session.php

        <?php
        require('config.php');
        require_login();
        sleep(10);
        

      5. Go to <yoursite>/long-session.php and log in
      6. Tail the logs with debugging on (eg. tail -f /usr/local/var/log/httpd/error_log in your terminal)
      7. Open in two tabs at the same time in fast succession within 5 seconds
        1. <yoursite>/long-session.php
        2. <yoursite>/long-session.php
      8. You should see an error log like:

        Cannot obtain session lock for sid: a5u30psl4he2t3sqpkroghucbj within 5 seconds. It is likely another page (zebrafish:25101 /long-session.php?id=1) has a long session lock, or the session lock was never released.
        

      Show
      Ensure debugging is turned on on your site. Setup redis Setup redis as the session handler (notice the session_redis_acquire_lock_timeout value): $CFG->session_redis_host = '127.0.0.1' ; $CFG->session_redis_port = 6379 ; // Optional. $CFG->session_redis_acquire_lock_timeout = 5 ; $CFG->session_handler_class = '\core\session\redis' ; Write a dud script that hangs onto the session for ages called long-session.php <?php require( 'config.php' ); require_login(); sleep( 10 ); Go to <yoursite>/long-session.php and log in Tail the logs with debugging on (eg. tail -f /usr/local/var/log/httpd/error_log in your terminal) Open in two tabs at the same time in fast succession within 5 seconds <yoursite>/long-session.php <yoursite>/long-session.php You should see an error log like: Cannot obtain session lock for sid: a5u30psl4he2t3sqpkroghucbj within 5 seconds. It is likely another page (zebrafish:25101 /long-session.php?id=1) has a long session lock, or the session lock was never released.
    • Affected Branches:
      MOODLE_39_STABLE
    • Fixed Branches:
      MOODLE_39_STABLE
    • Pull Master Branch:
      MDL-67075-redis-session-locks

      Description

      This adds more debugging to make it easier to track down open session locks.

      Note this is superficially similar to MDL-64449 but with a couple key differences. Firstly that one mutates the session which means more churning. Secondly it only works after the fact, if you have a blocked session you can't see what's blocking you right now. More importantly it also doesn't work if the session lock times out, for it to work you must eventually gain the session lock to get access to what's inside the session data.

        Attachments

          Issue Links

            Activity

              People

              Assignee:
              brendanheywood Brendan Heywood
              Reporter:
              brendanheywood Brendan Heywood
              Peer reviewer:
              Mark Nelson
              Integrator:
              Andrew Nicols
              Tester:
              Janelle Barcega
              Participants:
              Component watchers:
              Matteo Scaramuccia, Andrew Nicols, Jun Pataleta, Michael Hawkins, Shamim Rezaie, Simey Lameze
              Votes:
              1 Vote for this issue
              Watchers:
              8 Start watching this issue

                Dates

                Created:
                Updated:
                Resolved:
                Fix Release Date:
                15/Jun/20

                  Time Tracking

                  Estimated:
                  Original Estimate - Not Specified
                  Not Specified
                  Remaining:
                  Remaining Estimate - 0 minutes
                  0m
                  Logged:
                  Time Spent - 1 hour, 49 minutes
                  1h 49m