Moodle
  1. Moodle
  2. MDL-9215

admin/cron.php infinite loop in backup_log_info caused when old logs are deleted

    Details

    • Type: Bug Bug
    • Status: Closed
    • Priority: Major Major
    • Resolution: Won't Fix
    • Affects Version/s: 1.6
    • Fix Version/s: None
    • Component/s: Backup, Libraries, Other
    • Labels:
      None
    • Database:
      Any
    • Affected Branches:
      MOODLE_16_STABLE
    • Rank:
      1761

      Description

      It is possible for backup_log_info() (called from cron.php) to get into a (potentially) infinite loop when iterating over the logs. This can happen when one or more old log entries are deleted by another invocation of cron.php between the time when the current number of logs is determined by this line:

      $count_logs = count_records("log","course",$preferences->backup_course);

      and when the test to terminate the loop ("while ($counter < $count_logs)") is made and which should cause termination. If some logs have been deleted, the final call to get_records() may not return enough logs for the counter to equal $count_logs.

      I first identified and described this problem (without knowing the cause) here: http://moodle.org/mod/forum/discuss.php?d=50467#238903

      The following patch should fix the problem, but recognising that if get_records() doesn't return anything, then it's time to stop.

          • backuplib.php.orig Mon Jan 15 13:13:38 2007
          • backuplib.php Thu Apr 5 16:40:03 2007
            ***************
          • 1308,1313 ****
          • 1308,1317 ----
            backup_flush(300);
            }
            }
            + } else { + //No logs -- old ones were deleted by a different cron.php + //execution; break to avoid potentially infinite loop + break; }

            }
            //End logs tag

      I haven't yet had a chance to verify that this fix works. As this problem does not occur every single time backup_log_info(), a test case would need to be created.

        Activity

        Hide
        Bruce Webster added a comment -

        Looks like this is what happened to us. Backups started at midnight and I caught this query still running over and over this morning (at 10am). It was seriously affecting performance of the server. I killed the cron job.

        SELECT * FROM mdl_log WHERE course = '331' ORDER BY time LIMIT 108276,1000;

        We're on Moodle 1.9.5.

        We need a database-based check that there is no cron job running before a new cron starts.

        Show
        Bruce Webster added a comment - Looks like this is what happened to us. Backups started at midnight and I caught this query still running over and over this morning (at 10am). It was seriously affecting performance of the server. I killed the cron job. SELECT * FROM mdl_log WHERE course = '331' ORDER BY time LIMIT 108276,1000; We're on Moodle 1.9.5. We need a database-based check that there is no cron job running before a new cron starts.
        Hide
        Bruce Webster added a comment -

        To prevent backup errors caused by extra crons running during backup, I bunged this at the top of cron.php (after require config.php)

        // HACK – avoid running cron while backups are running.
        $brunning = get_field_sql("SELECT value FROM {$CFG->prefix}backup_config WHERE name='backup_sche_running'");
        if(!empty($brunning))

        {echo "Skipping cron as backups are running.\n";exit;}

        // END HACK

        Show
        Bruce Webster added a comment - To prevent backup errors caused by extra crons running during backup, I bunged this at the top of cron.php (after require config.php) // HACK – avoid running cron while backups are running. $brunning = get_field_sql("SELECT value FROM {$CFG->prefix}backup_config WHERE name='backup_sche_running'"); if(!empty($brunning)) {echo "Skipping cron as backups are running.\n";exit;} // END HACK
        Hide
        Martin Dougiamas added a comment -

        Passing to Eloy for looking at.

        The last patch though, is not the answer. Cron does other things too, we don't want to stop it all just because backup is running. And I'm pretty sure Backup already detects itself running and will wait. But perhaps there's another issue.

        Thanks Eloy!

        Show
        Martin Dougiamas added a comment - Passing to Eloy for looking at. The last patch though, is not the answer. Cron does other things too, we don't want to stop it all just because backup is running. And I'm pretty sure Backup already detects itself running and will wait. But perhaps there's another issue. Thanks Eloy!
        Hide
        Geoff Crompton added a comment -

        This issue is still present in 1.9.11. Which was released over 4 years after this bug was reported, and the simple patch provided by the original requestor (which is well explained in the bug report) has not yet been applied.

        Whats going on here? Is there something wrong with the patch? The problem has been also identified by Bruce, so it is a problem (though rarely triggered, as is often the case with race conditions).

        Show
        Geoff Crompton added a comment - This issue is still present in 1.9.11. Which was released over 4 years after this bug was reported, and the simple patch provided by the original requestor (which is well explained in the bug report) has not yet been applied. Whats going on here? Is there something wrong with the patch? The problem has been also identified by Bruce, so it is a problem (though rarely triggered, as is often the case with race conditions).
        Hide
        Michael de Raadt added a comment -

        Thanks for reporting this issue.

        We have detected that this issue has been inactive for over a year has been recorded as affecting versions that are no longer supported.

        If you believe that this issue is still relevant to current versions (2.3 and beyond), please comment on the issue. Issues left inactive for a further month will be closed.

        Michael d;

        4d6f6f646c6521

        Show
        Michael de Raadt added a comment - Thanks for reporting this issue. We have detected that this issue has been inactive for over a year has been recorded as affecting versions that are no longer supported. If you believe that this issue is still relevant to current versions (2.3 and beyond), please comment on the issue. Issues left inactive for a further month will be closed. Michael d; 4d6f6f646c6521
        Hide
        Michael de Raadt added a comment -

        I'm closing this issue as it has been inactive for over a year has been recorded as affecting versions that are no longer supported.

        If you still believe this is an issue in supported versions, please report a new issue.

        Show
        Michael de Raadt added a comment - I'm closing this issue as it has been inactive for over a year has been recorded as affecting versions that are no longer supported. If you still believe this is an issue in supported versions, please report a new issue.

          People

          • Votes:
            1 Vote for this issue
            Watchers:
            2 Start watching this issue

            Dates

            • Created:
              Updated:
              Resolved: