Moodle
  1. Moodle
  2. MDL-34251

Cron task never finishes. Gets to line 'Looking for quiz overdue quiz attempts between Wednesday, 31 December 1969, 6:00 PM...' then never advances

    Details

    • Type: Bug Bug
    • Status: Closed
    • Priority: Minor Minor
    • Resolution: Fixed
    • Affects Version/s: 2.3.1
    • Fix Version/s: 2.2.5, 2.3.2
    • Component/s: Quiz
    • Labels:
    • Testing Instructions:
      Hide

      1. Running the unit tests should be sufficient.

      2. You could also do a basic test of attempting a quiz, and regrading, say, just to make sure there are no regressions caused by these changes.

      Show
      1. Running the unit tests should be sufficient. 2. You could also do a basic test of attempting a quiz, and regrading, say, just to make sure there are no regressions caused by these changes.
    • Affected Branches:
      MOODLE_23_STABLE
    • Fixed Branches:
      MOODLE_22_STABLE, MOODLE_23_STABLE
    • Pull from Repository:
    • Pull Master Branch:
    • Rank:
      42600

      Description

      Related to http://tracker.moodle.org/browse/MDL-34109

      Cron script runs, but gets stuck at 'Looking for quiz overdue quiz attempts'. Checking SQL server, the cron is executing the following statements in an endless loop:

      SELECT q.*, qc.contextid
      FROM moodle.mdl_question q
      JOIN moodle.mdl_question_categories qc ON q.category = qc.id
      WHERE q.id = '4549'
      (1 row returned)

      SELECT * FROM moodle.mdl_question_hints WHERE questionid = '4549' ORDER BY id ASC
      (0 rows returned)

      SELECT * FROM moodle.mdl_question_multichoice WHERE question = '4549'.
      (1 row returned)

      SELECT * FROM moodle.mdl_question_answers WHERE question = '4549' ORDER BY id ASC
      (4 rows returned)

      Running https://github.com/moodle/moodle/blob/master/mod/quiz/cronlib.php#L91 by hand yields 140 records, so this isn't a huge database

      1. mdl19-attempts.csv
        343 kB
        Brian King
      2. mdl19-quiz-detail.csv
        1 kB
        Brian King
      3. quba-59800.csv
        1 kB
        Brian King
      1. question_attempt-load_from_records-object_values.jpg
        235 kB

        Issue Links

          Activity

          Hide
          Tim Hunt added a comment -

          Are you using a version of Moodle that includes the fix for MDL-34109?

          When you say the results repeat those 4 queries in an infinite loop, are you sure the loop is infinite, or is it just going through that loop 140 times?

          And, when you say it is the same query in the infinite loop, is it the same questionid every time?

          I would actually expect it to do those queries once for each question in each attempt - so more than 140 times.

          Show
          Tim Hunt added a comment - Are you using a version of Moodle that includes the fix for MDL-34109 ? When you say the results repeat those 4 queries in an infinite loop, are you sure the loop is infinite, or is it just going through that loop 140 times? And, when you say it is the same query in the infinite loop, is it the same questionid every time? I would actually expect it to do those queries once for each question in each attempt - so more than 140 times.
          Hide
          Ben Steeples added a comment -

          Running Moodle 2.3.1 (Build: 20120706)

          I ran the cron for nearly 4 hours this morning, and it's looping through the same 4 queries and question id (4549).

          I also did a bit of debugging, it seems to reach https://github.com/moodle/moodle/blob/master/mod/quiz/cronlib.php#L78 in cronlib, then start the infinite loop. I didn't investigate what "new quiz_attempt($attempt, $quizforuser, $cm, $course);" actually does.

          Show
          Ben Steeples added a comment - Running Moodle 2.3.1 (Build: 20120706) I ran the cron for nearly 4 hours this morning, and it's looping through the same 4 queries and question id (4549). I also did a bit of debugging, it seems to reach https://github.com/moodle/moodle/blob/master/mod/quiz/cronlib.php#L78 in cronlib, then start the infinite loop. I didn't investigate what "new quiz_attempt($attempt, $quizforuser, $cm, $course);" actually does.
          Hide
          Tim Hunt added a comment -

          new quiz_attempt($attempt, $quizforuser, $cm, $course); is loading the all the quiz attempt data, so that it can be processed. This is exactly what the quiz does when you go to mod/quiz/review.php.

          Are you able to find the attemptid for the attempt where cron gets stuck? For example you could add

          mtrace('    Processing attempt ' . $attempt->id);
          

          just after the line

          foreach ($attemptstoprocess as $attempt) {
          

          which will give you more information about what is going on.

          If you can do that, then go to

          http://.../mod/quiz/review.php?attemptid=...

          and see if that page loads.

          Show
          Tim Hunt added a comment - new quiz_attempt($attempt, $quizforuser, $cm, $course); is loading the all the quiz attempt data, so that it can be processed. This is exactly what the quiz does when you go to mod/quiz/review.php. Are you able to find the attemptid for the attempt where cron gets stuck? For example you could add mtrace(' Processing attempt ' . $attempt->id); just after the line foreach ($attemptstoprocess as $attempt) { which will give you more information about what is going on. If you can do that, then go to http://.../mod/quiz/review.php?attemptid= ... and see if that page loads.
          Hide
          Ben Steeples added a comment -

          Ok, cron gets to:

          Processing attempt 13949
          

          The, loading http://.../mod/quiz/review.php?attemptid=13949 shows:

          Debug info:
          Error code: missingparam
          Stack trace:
          
              line 467 of /lib/setuplib.php: moodle_exception thrown
              line 508 of /lib/moodlelib.php: call to print_error()
              line 33 of /mod/quiz/review.php: call to required_param()
          

          I checked another attempt and review.php loaded correctly.

          Show
          Ben Steeples added a comment - Ok, cron gets to: Processing attempt 13949 The, loading http://.../mod/quiz/review.php?attemptid=13949 shows: Debug info: Error code: missingparam Stack trace: line 467 of /lib/setuplib.php: moodle_exception thrown line 508 of /lib/moodlelib.php: call to print_error() line 33 of /mod/quiz/review.php: call to required_param() I checked another attempt and review.php loaded correctly.
          Hide
          Tim Hunt added a comment -

          Sorry, I got that wrong, the review URL needs to be

          http://.../mod/quiz/review.php?attempt=13949

          (no id).

          Please can you try again.

          Show
          Tim Hunt added a comment - Sorry, I got that wrong, the review URL needs to be http://.../mod/quiz/review.php?attempt=13949 (no id). Please can you try again.
          Hide
          Ben Steeples added a comment -

          No problem.

          Loading that page causes the browser to go into an indefinite 'connecting/loading page' state. ie. nothing is returned to the browser, but the server isn't terminating the connection either.

          Show
          Ben Steeples added a comment - No problem. Loading that page causes the browser to go into an indefinite 'connecting/loading page' state. ie. nothing is returned to the browser, but the server isn't terminating the connection either.
          Hide
          Tõnis Tartes added a comment -

          Tim, could you please help?
          After upgrade to 2.3.1+ i have got the same problem that my cron never finishes.

          Log:
          Processing module function quiz_cron ...
          Looking for quiz overdue quiz attempts between neljapäev, 1. jaanuar 1970, 02:00 and esmaspäev, 16. juuli 2012, 11:20...
          !!! Vigane valemi süntaks algusega '0.1*(((8.0)(2*(0.09)))*2) ((2.6)(0.09)) !!!
          !!
          Error code: illegalformulasyntax !!
          !! Stack trace: * line 356 of /question/type/calculated/question.php: moodle_exception thrown

          • line 344 of /question/type/calculated/question.php: call to qtype_calculated_variable_substituter->calculate_raw()
          • line 70 of /question/type/calculated/question.php: call to qtype_calculated_variable_substituter->calculate()
          • line 150 of /question/type/calculated/question.php: call to qtype_calculated_question->calculate_all_expressions()
          • line 59 of /question/type/calculated/question.php: call to qtype_calculated_question_helper::apply_attempt_state()
          • line 1220 of /question/engine/questionattempt.php: call to qtype_calculated_question->apply_attempt_state()
          • line 721 of /question/engine/questionusage.php: call to question_attempt::load_from_records()
          • line 344 of /question/engine/datalib.php: call to question_usage_by_activity::load_from_records()
          • line 78 of /question/engine/lib.php: call to question_engine_data_mapper->load_questions_usage_by_activity()
          • line 468 of /mod/quiz/attemptlib.php: call to question_engine::load_questions_usage_by_activity()
          • line 78 of /mod/quiz/cronlib.php: call to quiz_attempt->__construct()
          • line 469 of /mod/quiz/lib.php: call to mod_quiz_overdue_attempt_updater->update_overdue_attempts()
          • line 259 of /lib/cronlib.php: call to quiz_cron()
          • line 88 of /admin/cron.php: call to cron_run()
            !!

          For what i understand, it has wrong formula syntax, but could you give me any suggestions, what is wrong with the syntax and how to fix it?

          Show
          Tõnis Tartes added a comment - Tim, could you please help? After upgrade to 2.3.1+ i have got the same problem that my cron never finishes. Log: Processing module function quiz_cron ... Looking for quiz overdue quiz attempts between neljapäev, 1. jaanuar 1970, 02:00 and esmaspäev, 16. juuli 2012, 11:20... !!! Vigane valemi süntaks algusega '0.1*(((8.0) (2*(0.09)))* 2) ((2.6) (0.09)) !!! !! Error code: illegalformulasyntax !! !! Stack trace: * line 356 of /question/type/calculated/question.php: moodle_exception thrown line 344 of /question/type/calculated/question.php: call to qtype_calculated_variable_substituter->calculate_raw() line 70 of /question/type/calculated/question.php: call to qtype_calculated_variable_substituter->calculate() line 150 of /question/type/calculated/question.php: call to qtype_calculated_question->calculate_all_expressions() line 59 of /question/type/calculated/question.php: call to qtype_calculated_question_helper::apply_attempt_state() line 1220 of /question/engine/questionattempt.php: call to qtype_calculated_question->apply_attempt_state() line 721 of /question/engine/questionusage.php: call to question_attempt::load_from_records() line 344 of /question/engine/datalib.php: call to question_usage_by_activity::load_from_records() line 78 of /question/engine/lib.php: call to question_engine_data_mapper->load_questions_usage_by_activity() line 468 of /mod/quiz/attemptlib.php: call to question_engine::load_questions_usage_by_activity() line 78 of /mod/quiz/cronlib.php: call to quiz_attempt->__construct() line 469 of /mod/quiz/lib.php: call to mod_quiz_overdue_attempt_updater->update_overdue_attempts() line 259 of /lib/cronlib.php: call to quiz_cron() line 88 of /admin/cron.php: call to cron_run() !! For what i understand, it has wrong formula syntax, but could you give me any suggestions, what is wrong with the syntax and how to fix it?
          Hide
          Tim Hunt added a comment -

          Ben, that is progress of a sort. It is much easier to debug a problem that occurs when you visit on URL in your web browser, compared to a problem that can only be triggered in the middle of cron.

          It looks like we are getting the same infinite loop in both cases, but I cannot understand how that might be happening. Do you feel like tracing what happens when you go to the review.php URL. Basically go through review.php and add

          echo 'Got to line X';
          

          statements throughout the code, to try to work out exactly where the problem is.

          Tonis, your problem has a different cause, so I have created a separate issue, MDL-34351, to track it.

          Show
          Tim Hunt added a comment - Ben, that is progress of a sort. It is much easier to debug a problem that occurs when you visit on URL in your web browser, compared to a problem that can only be triggered in the middle of cron. It looks like we are getting the same infinite loop in both cases, but I cannot understand how that might be happening. Do you feel like tracing what happens when you go to the review.php URL. Basically go through review.php and add echo 'Got to line X'; statements throughout the code, to try to work out exactly where the problem is. Tonis, your problem has a different cause, so I have created a separate issue, MDL-34351 , to track it.
          Hide
          Brian King added a comment - - edited

          I'm seeing this too on a Moodle upgraded to 2.3.1. Cron keeps running forever, the last sign of action is "Looking for quiz overdue quiz attempts between Thursday, 1. January 1970, 01:00 and Monday, 16. July 2012, 16:55...". Well, it's keeping apache and postgresql busy.

          I'll try to pinpoint where it's getting lost. For the momement, in my case, it's not coming back after it calls

          $attemptobj = quiz_attempt::create($attemptid);
          

          when i try to review one of these quiz attempts.

          Will follow up later ... but it might be a day or two before I can get back to it.

          Show
          Brian King added a comment - - edited I'm seeing this too on a Moodle upgraded to 2.3.1. Cron keeps running forever, the last sign of action is "Looking for quiz overdue quiz attempts between Thursday, 1. January 1970, 01:00 and Monday, 16. July 2012, 16:55...". Well, it's keeping apache and postgresql busy. I'll try to pinpoint where it's getting lost. For the momement, in my case, it's not coming back after it calls $attemptobj = quiz_attempt::create($attemptid); when i try to review one of these quiz attempts. Will follow up later ... but it might be a day or two before I can get back to it.
          Hide
          Darko Grabar added a comment - - edited

          Same problem here, Moodle 2.3.1., postgresql database. Moodle was upgraded from 1.9.18 -> 2.2 ->2.3.

          Looking for quiz overdue quiz attempts between Thursday, 1 January 1970, 2:00 AM and Monday, 16 July 2012, 5:25 PM...

          Show
          Darko Grabar added a comment - - edited Same problem here, Moodle 2.3.1., postgresql database. Moodle was upgraded from 1.9.18 -> 2.2 ->2.3. Looking for quiz overdue quiz attempts between Thursday, 1 January 1970, 2:00 AM and Monday, 16 July 2012, 5:25 PM...
          Hide
          Brian King added a comment -

          Tim, this bit of code never advances, does it? Shouldn't it be calling $records->next() instead or $records->current()?

          lines 717 - 727 of question/engine/questionusage.php

                  while ($record && $record->qubaid == $qubaid && !is_null($record->slot)) {
                      $quba->questionattempts[$record->slot] =
                              question_attempt::load_from_records($records,
                              $record->questionattemptid, $quba->observer,
                              $quba->get_preferred_behaviour());
                      if ($records->valid()) {
                          $record = $records->current();
                      } else {
                          $record = false;
                      }
                  }
          

          This is where it seems to be getting stuck by me.

          Show
          Brian King added a comment - Tim, this bit of code never advances, does it? Shouldn't it be calling $records->next() instead or $records->current()? lines 717 - 727 of question/engine/questionusage.php while ($record && $record->qubaid == $qubaid && !is_null($record->slot)) { $quba->questionattempts[$record->slot] = question_attempt::load_from_records($records, $record->questionattemptid, $quba->observer, $quba->get_preferred_behaviour()); if ($records->valid()) { $record = $records->current(); } else { $record = false; } } This is where it seems to be getting stuck by me.
          Hide
          Tim Hunt added a comment -

          I am pretty sure question_attempt::load_from_records should always advance at least one record (because question_attempt_step::load_from_records always advances at least one record).

          Show
          Tim Hunt added a comment - I am pretty sure question_attempt::load_from_records should always advance at least one record (because question_attempt_step::load_from_records always advances at least one record).
          Hide
          Brian King added a comment - - edited

          Tim, in this case $records is not getting advanced in question_attempt::load_from_records. The attached screenshot question_attempt-load_from_records-object_values shows a set of object values in question_attempt::load_from_records that result in $records not getting advanced.

          question_engine_data_mapper->load_questions_usage_by_activity(), which is called earlier, returns 6 records, all of which have questionid = 0.

          Looking in the database, I see that 3412 out of 1270247 records in mdl_question_attempts that have questionid = 0.

          Another piece of information, in case it's helpful: all of the questions in this quiz are of type 'random'.

          Show
          Brian King added a comment - - edited Tim, in this case $records is not getting advanced in question_attempt::load_from_records. The attached screenshot question_attempt-load_from_records-object_values shows a set of object values in question_attempt::load_from_records that result in $records not getting advanced. question_engine_data_mapper->load_questions_usage_by_activity(), which is called earlier, returns 6 records, all of which have questionid = 0. Looking in the database, I see that 3412 out of 1270247 records in mdl_question_attempts that have questionid = 0. Another piece of information, in case it's helpful: all of the questions in this quiz are of type 'random'.
          Hide
          Tim Hunt added a comment -

          Obviously, questionid = 0 should never happen. The fact it relates to random questions suggests to me that these are old attempts upgraded from Moodle <= 2.0, and the data was bad before the upgrade.

          The screen-grab is not really the information I need. What would be most useful is:

          Take the SQL query from question_engine_data_mapper->load_questions_usage_by_activity (with one of the usage ids that causes the problem) and save the data that it outputs as a .csv file, then attach that here.

          Show
          Tim Hunt added a comment - Obviously, questionid = 0 should never happen. The fact it relates to random questions suggests to me that these are old attempts upgraded from Moodle <= 2.0, and the data was bad before the upgrade. The screen-grab is not really the information I need. What would be most useful is: Take the SQL query from question_engine_data_mapper->load_questions_usage_by_activity (with one of the usage ids that causes the problem) and save the data that it outputs as a .csv file, then attach that here.
          Hide
          Brian King added a comment -

          OK, quba-59800.csv is attached.

          Show
          Brian King added a comment - OK, quba-59800.csv is attached.
          Hide
          Ben Steeples added a comment -

          Tim,

          re: http://.../mod/quiz/review.php?attempt=13949

          Tried to add some debug comments, but the page isn't sending any output to the browser, so it's tricky to debug where it's reaching. Any ideas?

          Thanks,
          Ben

          Show
          Ben Steeples added a comment - Tim, re: http://.../mod/quiz/review.php?attempt=13949 Tried to add some debug comments, but the page isn't sending any output to the browser, so it's tricky to debug where it's reaching. Any ideas? Thanks, Ben
          Hide
          Tim Hunt added a comment -

          That is seriously screwed up data! It seems that you have question_attempts with no question_attempt_steps, and that really should never happen.

          OK, so since we have found that this happens in practice, I need to make the code robust so that this does not cause an infinite loop.

          Meanwhile, you probably need to clean up the mess in your database manually. One thing you could do is to go to Home ► Site administration ► Development ► XMLDB editor and use the [Check foreign keys] option. It seems you know a bit about databases, and will understand what you are doing.

          That is a general check. To investigate your specific problem, try a query like:

          SELECT
              qa.questionusageid,
              qa.id AS question_attemtp_id,
              quiza.id AS quiz_attempt_id
          
          FROM q_question_attempts qa
          LEFT JOIN q_question_attempt_steps qas ON qas.questionattemptid = qa.id
          LEFT JOIN q_quiz_attempts quiza ON quiza.uniqueid = qa.questionusageid
          
          WHERE qas.id IS NULL
          
          ORDER BY quiza.quiz
          

          That will find all the question_usages, and associated quiz_attempts, where there are question_attempts that don't have any steps. So, on a healthy Moodle site, that query should return 0 rows.

          You need to have a look at the rows that it does return on your site and decide if there is any useful data there. Hopefully all the data that is there is real garbage, and you can just delete it. If so, that is simple. Have a look at delete_questions_usage_by_activities in question/engine/datalib.php to see what needs to be deleted, and then delete the corresponding quiz_attempts rows.

          If the data that remains in those garbled attempts is important, then you have a bigger problem.

          Show
          Tim Hunt added a comment - That is seriously screwed up data! It seems that you have question_attempts with no question_attempt_steps, and that really should never happen. OK, so since we have found that this happens in practice, I need to make the code robust so that this does not cause an infinite loop. Meanwhile, you probably need to clean up the mess in your database manually. One thing you could do is to go to Home ► Site administration ► Development ► XMLDB editor and use the [Check foreign keys] option. It seems you know a bit about databases, and will understand what you are doing. That is a general check. To investigate your specific problem, try a query like: SELECT qa.questionusageid, qa.id AS question_attemtp_id, quiza.id AS quiz_attempt_id FROM q_question_attempts qa LEFT JOIN q_question_attempt_steps qas ON qas.questionattemptid = qa.id LEFT JOIN q_quiz_attempts quiza ON quiza.uniqueid = qa.questionusageid WHERE qas.id IS NULL ORDER BY quiza.quiz That will find all the question_usages, and associated quiz_attempts, where there are question_attempts that don't have any steps. So, on a healthy Moodle site, that query should return 0 rows. You need to have a look at the rows that it does return on your site and decide if there is any useful data there. Hopefully all the data that is there is real garbage, and you can just delete it. If so, that is simple. Have a look at delete_questions_usage_by_activities in question/engine/datalib.php to see what needs to be deleted, and then delete the corresponding quiz_attempts rows. If the data that remains in those garbled attempts is important, then you have a bigger problem.
          Hide
          Tim Hunt added a comment -

          Debug messages not showing up probably means that your site is configured to use gzip compression or output buffering, or something like that.

          Show
          Tim Hunt added a comment - Debug messages not showing up probably means that your site is configured to use gzip compression or output buffering, or something like that.
          Hide
          Tim Hunt added a comment -

          Right, I think this should fix it. With luck it will be integrated into next week's weekly build.

          Ben, Brian, or anyone else who has this problem: if you can try applying the patch this week, and confirm that it solves the problem, then that would be really helpful.

          Show
          Tim Hunt added a comment - Right, I think this should fix it. With luck it will be integrated into next week's weekly build. Ben, Brian, or anyone else who has this problem: if you can try applying the patch this week, and confirm that it solves the problem, then that would be really helpful.
          Hide
          Brian King added a comment - - edited

          I can confirm that it lets cron complete for my case.

          In my case, the problem is restricted to just two courses and six quizzes, so probably not the end of the world. The problem seems to exist for all attempts of these six quizzes. This is a Moodle that started life at 1.6, and was most recently upgraded from 1.9.12 to 1.9.latest -> 2.2.latest -> 2.3.1.

          Interestingly, reviewing these troublesome attempts in the still-running Moodle 1.9.12 works fine. It seems something went wrong during the upgrade. The data got borked somehow, and now reviewing one of these attempts with the borked data and Tim's patch shows an error "Coding error detected, it must be fixed by a programmer: Unexpected question state."

          Reviewing attempts in 1.9.12 for one of the six problem quizzes shows "The number of random questions required is more than are still available in the category!" for one of the questions. Reviewing attempts for the other five quizzes doesn't reveal anything weird. All of these six quizzes are composed exclusively of questions of type "random". The most recent problematic attempts happened when the Moodle was already running 1.9.12.

          Show
          Brian King added a comment - - edited I can confirm that it lets cron complete for my case. In my case, the problem is restricted to just two courses and six quizzes, so probably not the end of the world. The problem seems to exist for all attempts of these six quizzes. This is a Moodle that started life at 1.6, and was most recently upgraded from 1.9.12 to 1.9.latest -> 2.2.latest -> 2.3.1. Interestingly, reviewing these troublesome attempts in the still-running Moodle 1.9.12 works fine. It seems something went wrong during the upgrade. The data got borked somehow, and now reviewing one of these attempts with the borked data and Tim's patch shows an error "Coding error detected, it must be fixed by a programmer: Unexpected question state." Reviewing attempts in 1.9.12 for one of the six problem quizzes shows "The number of random questions required is more than are still available in the category!" for one of the questions. Reviewing attempts for the other five quizzes doesn't reveal anything weird. All of these six quizzes are composed exclusively of questions of type "random". The most recent problematic attempts happened when the Moodle was already running 1.9.12.
          Hide
          Tim Hunt added a comment -

          Odd. I suppose this means you have found an upgrade bug. Could you run this query: http://docs.moodle.org/dev/Question_database_structure#Following_what_happens_when_questions_are_attempted on the Moodle 1.9 database, for these attemts, and attach the CVS file. I guess it would also be good to have the corresponding quiz settings and question definitions, if possible, but with random questions, working out what are the corresponding question definitions can be tricky.

          Show
          Tim Hunt added a comment - Odd. I suppose this means you have found an upgrade bug. Could you run this query: http://docs.moodle.org/dev/Question_database_structure#Following_what_happens_when_questions_are_attempted on the Moodle 1.9 database, for these attemts, and attach the CVS file. I guess it would also be good to have the corresponding quiz settings and question definitions, if possible, but with random questions, working out what are the corresponding question definitions can be tricky.
          Hide
          Brian King added a comment -

          Attached mdl19-attempts.csv with the attempt data, and mdl19-quiz-detail.csv with the quiz details (with courseid, name, intro anonymized).

          What sort of question detail would you want for the used questions? I see things like 'random94527-...' in mdl19-attempts.csv, which I take to mean that it used the "real" question 94527. Do you want details just from the mdl_question table, or also from the specific question type tables?

          Show
          Brian King added a comment - Attached mdl19-attempts.csv with the attempt data, and mdl19-quiz-detail.csv with the quiz details (with courseid, name, intro anonymized). What sort of question detail would you want for the used questions? I see things like 'random94527-...' in mdl19-attempts.csv, which I take to mean that it used the "real" question 94527. Do you want details just from the mdl_question table, or also from the specific question type tables?
          Hide
          Tim Hunt added a comment -

          Hmm, that all looks quite like how one would expect.

          I don't really need to see the details of the questions. I think we just need to know that the questions exist, and I think we should check that both questions exist, the random question that will be pointed to by question_states.question, and the real question used, which is the id from 'random94527-...' as you correctly guessed.

          Show
          Tim Hunt added a comment - Hmm, that all looks quite like how one would expect. I don't really need to see the details of the questions. I think we just need to know that the questions exist, and I think we should check that both questions exist, the random question that will be pointed to by question_states.question, and the real question used, which is the id from 'random94527-...' as you correctly guessed.
          Hide
          Darko Grabar added a comment -

          Hi, I can also confirm that your patch resolves the problem.
          Thanks

          Show
          Darko Grabar added a comment - Hi, I can also confirm that your patch resolves the problem. Thanks
          Hide
          Dan Poltawski added a comment -

          The main moodle.git repository has just been updated with latest weekly modifications. You may wish to rebase your PULL branches to simplify history and avoid any possible merge conflicts. This would also make integrator's life easier next week.

          TIA and ciao

          Show
          Dan Poltawski added a comment - The main moodle.git repository has just been updated with latest weekly modifications. You may wish to rebase your PULL branches to simplify history and avoid any possible merge conflicts. This would also make integrator's life easier next week. TIA and ciao
          Hide
          Brian King added a comment -

          Tim, for the data related to mdl19-attempts.csv, I found that all of the used random questions exist. There was one real question missing. This is the case for the quiz with id 3039 (this is the quiz that shows "The number of random questions required is more than are still available in the category!" when reviewing attempts in Moodle 1.9). The data in mdl19-attempts.csv is actually only for this one quiz.

          I noticed for 6 of the 7 problem quizzes, http://docs.moodle.org/dev/Question_database_structure#Following_what_happens_when_questions_are_attempted returns no rows when run against the Moodle 1.9 database (my where clause is "WHERE quiza.quiz in (1465,1466,1467,1468,1469,1470,3039)") It is however possible to review these attempts in the browser. These 6 quizzes and their attempts all date from 2009.

          Here's some data from one of the attempts that shows why no data is returned; the questionids do not match:

          > select * from mdl_question_states where attempt=59823;
          +---------+---------+----------+------------------+------------+-------------------------------------------------------+------------+-------+-------+-----------+---------+
          | id      | attempt | question | originalquestion | seq_number | answer                                                | timestamp  | event | grade | raw_grade | penalty |
          +---------+---------+----------+------------------+------------+-------------------------------------------------------+------------+-------+-------+-----------+---------+
          | 1958150 |   59823 |    36273 |                0 |          1 | random36273-143163                                    | 1254516546 |     6 |     1 |         1 |       1 | 
          | 1958149 |   59823 |    36274 |                0 |          1 | random36274-143165                                    | 1254516546 |     6 |     1 |         1 |       1 | 
          | 1958148 |   59823 |    36246 |                0 |          1 | random36246-143093                                    | 1254516546 |     6 |     1 |         1 |       1 | 
          | 1958147 |   59823 |    36253 |                0 |          1 | random36253-143106                                    | 1254516546 |     6 |     1 |         1 |       1 | 
          | 1958146 |   59823 |    36235 |                0 |          1 | random36235-143060,143061,143059,143058:143060        | 1254516546 |     6 |     1 |         1 |     0.1 | 
          | 1958145 |   59823 |    36240 |                0 |          1 | random36240-143082,143080,143083,143079,143081:143083 | 1254516546 |     6 |     1 |         1 |     0.1 | 
          | 1958144 |   59823 |    36235 |                0 |          0 | random36235-143060,143061,143059,143058:              | 1254515660 |     0 |     0 |         0 |       0 | 
          | 1958143 |   59823 |    36253 |                0 |          0 | random36253-                                          | 1254515660 |     0 |     0 |         0 |       0 | 
          | 1958142 |   59823 |    36240 |                0 |          0 | random36240-143082,143080,143083,143079,143081:       | 1254515660 |     0 |     0 |         0 |       0 | 
          | 1958141 |   59823 |    36274 |                0 |          0 | random36274-                                          | 1254515660 |     0 |     0 |         0 |       0 | 
          | 1958140 |   59823 |    36246 |                0 |          0 | random36246-                                          | 1254515660 |     0 |     0 |         0 |       0 | 
          | 1958139 |   59823 |    36273 |                0 |          0 | random36273-                                          | 1254515660 |     0 |     0 |         0 |       0 | 
          +---------+---------+----------+------------------+------------+-------------------------------------------------------+------------+-------+-------+-----------+---------+
          
          > select * from mdl_question_sessions where attemptid=59823;
          +--------+-----------+------------+---------+-----------+------------+---------------+
          | id     | attemptid | questionid | newest  | newgraded | sumpenalty | manualcomment |
          +--------+-----------+------------+---------+-----------+------------+---------------+
          | 742034 |     59823 |      36255 | 1958150 |   1958150 |          1 |               | 
          | 742035 |     59823 |      36256 | 1958148 |   1958148 |          1 |               | 
          | 742036 |     59823 |      36257 | 1958149 |   1958149 |          1 |               | 
          | 742037 |     59823 |      36258 | 1958145 |   1958145 |        0.1 |               | 
          | 742038 |     59823 |      36259 | 1958147 |   1958147 |          1 |               | 
          | 742039 |     59823 |      36260 | 1958146 |   1958146 |        0.1 |               | 
          +--------+-----------+------------+---------+-----------+------------+---------------+
          
          Show
          Brian King added a comment - Tim, for the data related to mdl19-attempts.csv, I found that all of the used random questions exist. There was one real question missing. This is the case for the quiz with id 3039 (this is the quiz that shows "The number of random questions required is more than are still available in the category!" when reviewing attempts in Moodle 1.9). The data in mdl19-attempts.csv is actually only for this one quiz. I noticed for 6 of the 7 problem quizzes, http://docs.moodle.org/dev/Question_database_structure#Following_what_happens_when_questions_are_attempted returns no rows when run against the Moodle 1.9 database (my where clause is "WHERE quiza.quiz in (1465,1466,1467,1468,1469,1470,3039)") It is however possible to review these attempts in the browser. These 6 quizzes and their attempts all date from 2009. Here's some data from one of the attempts that shows why no data is returned; the questionids do not match: > select * from mdl_question_states where attempt=59823; +---------+---------+----------+------------------+------------+-------------------------------------------------------+------------+-------+-------+-----------+---------+ | id | attempt | question | originalquestion | seq_number | answer | timestamp | event | grade | raw_grade | penalty | +---------+---------+----------+------------------+------------+-------------------------------------------------------+------------+-------+-------+-----------+---------+ | 1958150 | 59823 | 36273 | 0 | 1 | random36273-143163 | 1254516546 | 6 | 1 | 1 | 1 | | 1958149 | 59823 | 36274 | 0 | 1 | random36274-143165 | 1254516546 | 6 | 1 | 1 | 1 | | 1958148 | 59823 | 36246 | 0 | 1 | random36246-143093 | 1254516546 | 6 | 1 | 1 | 1 | | 1958147 | 59823 | 36253 | 0 | 1 | random36253-143106 | 1254516546 | 6 | 1 | 1 | 1 | | 1958146 | 59823 | 36235 | 0 | 1 | random36235-143060,143061,143059,143058:143060 | 1254516546 | 6 | 1 | 1 | 0.1 | | 1958145 | 59823 | 36240 | 0 | 1 | random36240-143082,143080,143083,143079,143081:143083 | 1254516546 | 6 | 1 | 1 | 0.1 | | 1958144 | 59823 | 36235 | 0 | 0 | random36235-143060,143061,143059,143058: | 1254515660 | 0 | 0 | 0 | 0 | | 1958143 | 59823 | 36253 | 0 | 0 | random36253- | 1254515660 | 0 | 0 | 0 | 0 | | 1958142 | 59823 | 36240 | 0 | 0 | random36240-143082,143080,143083,143079,143081: | 1254515660 | 0 | 0 | 0 | 0 | | 1958141 | 59823 | 36274 | 0 | 0 | random36274- | 1254515660 | 0 | 0 | 0 | 0 | | 1958140 | 59823 | 36246 | 0 | 0 | random36246- | 1254515660 | 0 | 0 | 0 | 0 | | 1958139 | 59823 | 36273 | 0 | 0 | random36273- | 1254515660 | 0 | 0 | 0 | 0 | +---------+---------+----------+------------------+------------+-------------------------------------------------------+------------+-------+-------+-----------+---------+ > select * from mdl_question_sessions where attemptid=59823; +--------+-----------+------------+---------+-----------+------------+---------------+ | id | attemptid | questionid | newest | newgraded | sumpenalty | manualcomment | +--------+-----------+------------+---------+-----------+------------+---------------+ | 742034 | 59823 | 36255 | 1958150 | 1958150 | 1 | | | 742035 | 59823 | 36256 | 1958148 | 1958148 | 1 | | | 742036 | 59823 | 36257 | 1958149 | 1958149 | 1 | | | 742037 | 59823 | 36258 | 1958145 | 1958145 | 0.1 | | | 742038 | 59823 | 36259 | 1958147 | 1958147 | 1 | | | 742039 | 59823 | 36260 | 1958146 | 1958146 | 0.1 | | +--------+-----------+------------+---------+-----------+------------+---------------+
          Hide
          Tim Hunt added a comment -

          Oh yes, if you look, question_states.question is the same as the random123 bit, not the random question. How odd. That seems sufficiently weird, and I have no idea what would have caused it, so I am not inclined to try to fix upgrade to cope with it.

          But thanks for finding out what was going on.

          Show
          Tim Hunt added a comment - Oh yes, if you look, question_states.question is the same as the random123 bit, not the random question. How odd. That seems sufficiently weird, and I have no idea what would have caused it, so I am not inclined to try to fix upgrade to cope with it. But thanks for finding out what was going on.
          Hide
          Brian King added a comment -

          Yea, OK, I agree, it's probably not worth trying to fix. Thanks for your help!

          Show
          Brian King added a comment - Yea, OK, I agree, it's probably not worth trying to fix. Thanks for your help!
          Hide
          Dan Poltawski added a comment -

          Thanks Tim, i've integrated this now.

          Thanks also to everyone on this bug who has confirmed the issue has been fixed with this patch, it really helps us integrate things more confidently

          Show
          Dan Poltawski added a comment - Thanks Tim, i've integrated this now. Thanks also to everyone on this bug who has confirmed the issue has been fixed with this patch, it really helps us integrate things more confidently
          Hide
          Dan Poltawski added a comment -

          Passing. I could regrade successfully without error.

          Note there is another issue discovered this week MDL-34251, which I have no reason to believe is related to this, but thought would mention anyway.

          Show
          Dan Poltawski added a comment - Passing. I could regrade successfully without error. Note there is another issue discovered this week MDL-34251 , which I have no reason to believe is related to this, but thought would mention anyway.
          Hide
          Dan Poltawski added a comment -

          Grr, I meant MDL-34532

          Show
          Dan Poltawski added a comment - Grr, I meant MDL-34532
          Hide
          Aparup Banerjee added a comment -

          yay, it works!

          This issue has been put through rigorous processes and finally swam upstream along with some 65 others this week.

          Thank you all for taking the time to get us here.

          cheers!

          Show
          Aparup Banerjee added a comment - yay, it works! This issue has been put through rigorous processes and finally swam upstream along with some 65 others this week. Thank you all for taking the time to get us here. cheers!

            People

            • Votes:
              0 Vote for this issue
              Watchers:
              7 Start watching this issue

              Dates

              • Created:
                Updated:
                Resolved: