Moodle
  1. Moodle
  2. MDL-13478

Choice responses use inefficient SQL causing memory to run out

    Details

    • Type: Bug Bug
    • Status: Closed
    • Priority: Major Major
    • Resolution: Fixed
    • Affects Version/s: 1.9
    • Fix Version/s: 1.9
    • Component/s: Choice
    • Labels:
      None
    • Rank:
      30558
    1. choice.patch
      34 kB
      Dan Marsden
    2. choice.patch
      32 kB
      Dan Marsden
    3. choice.patch
      34 kB
      Dan Marsden
    4. choice.patch
      14 kB
      Dan Marsden
    5. lib.php.patch
      4 kB
      Dan Marsden
    6. lib.php.patch
      2 kB
      Dan Marsden
    7. report.php.patch
      4 kB
      Dan Marsden

      Issue Links

        Activity

        Helen Foster created issue -
        Hide
        Martin Dougiamas added a comment -

        It's related to using too much memory (usually these are a get_records type call)

        [Fri Feb 15 17:34:26 2008] [error] [client 220.227.31.67] PHP Fatal error: Allowed memory size of 100663296 bytes exhausted (tried to allocate 71 bytes) in /var/www/html/moodle/lib/adodb/adodb.inc.php on line 3004, referer: http://moodle.org/mod/choice/view.php?id=6689

        Show
        Martin Dougiamas added a comment - It's related to using too much memory (usually these are a get_records type call) [Fri Feb 15 17:34:26 2008] [error] [client 220.227.31.67] PHP Fatal error: Allowed memory size of 100663296 bytes exhausted (tried to allocate 71 bytes) in /var/www/html/moodle/lib/adodb/adodb.inc.php on line 3004, referer: http://moodle.org/mod/choice/view.php?id=6689
        Hide
        Dan Marsden added a comment -

        attaching 1st version of a patch which should improve things!

        Show
        Dan Marsden added a comment - attaching 1st version of a patch which should improve things!
        Dan Marsden made changes -
        Field Original Value New Value
        Attachment lib.php.patch [ 13149 ]
        Hide
        Dan Marsden added a comment -

        there are a few other areas of the choice code that need a good tidy up, - I'm going to try and spend some time on cleaning it up a bit for 2.0

        Dan

        Show
        Dan Marsden added a comment - there are a few other areas of the choice code that need a good tidy up, - I'm going to try and spend some time on cleaning it up a bit for 2.0 Dan
        Hide
        Dan Marsden added a comment -

        I'm thinking that call to get_record('user', 'id', $usr->userid);
        could be replaced with something like:

        get_record_sql('SELECT id, picture, firstname, lastname, idnumber FROM '. $CFG->prefix .'user WHERE id= '.$usr->userid);

        as I don't need all the fields back from the user table

        Show
        Dan Marsden added a comment - I'm thinking that call to get_record('user', 'id', $usr->userid); could be replaced with something like: get_record_sql('SELECT id, picture, firstname, lastname, idnumber FROM '. $CFG->prefix .'user WHERE id= '.$usr->userid); as I don't need all the fields back from the user table
        Hide
        Dan Marsden added a comment -

        ..forgot to mention - that patch breaks display of users in the unanswered column.

        Show
        Dan Marsden added a comment - ..forgot to mention - that patch breaks display of users in the unanswered column.
        Hide
        Dan Marsden added a comment -

        tidier patch that shouldn't break unanswered column - also cleans up a couple of unneeded calls to has_capability

        Show
        Dan Marsden added a comment - tidier patch that shouldn't break unanswered column - also cleans up a couple of unneeded calls to has_capability
        Dan Marsden made changes -
        Attachment lib.php.patch [ 13150 ]
        Hide
        Dan Marsden added a comment -

        cleaned up patch and now in HEAD and 1.9STABLE which should improve when not using the unanswered column.

        thanks,

        Dan

        Show
        Dan Marsden added a comment - cleaned up patch and now in HEAD and 1.9STABLE which should improve when not using the unanswered column. thanks, Dan
        Hide
        Martin Dougiamas added a comment -

        Not working for moodle.org ... I need to look into this ...

        Show
        Martin Dougiamas added a comment - Not working for moodle.org ... I need to look into this ...
        Martin Dougiamas made changes -
        Fix Version/s 1.9 [ 10190 ]
        Hide
        Dan Marsden added a comment -

        I see the responses are loading now. - did you find where it was causing issues?

        Dan

        Show
        Dan Marsden added a comment - I see the responses are loading now. - did you find where it was causing issues? Dan
        Hide
        Martin Dougiamas added a comment -

        No, I didn't. it's working for ordinary users but not for admins...

        Show
        Martin Dougiamas added a comment - No, I didn't. it's working for ordinary users but not for admins...
        Hide
        Dan Marsden added a comment -

        hmmm.... It will probably be due to the 2 get_users_by_capability calls.. - I'm thinking about restructuring that page, and only using get_users_by_capability for the unanswered column - means it should only need to be called once...

        Dan

        Show
        Dan Marsden added a comment - hmmm.... It will probably be due to the 2 get_users_by_capability calls.. - I'm thinking about restructuring that page, and only using get_users_by_capability for the unanswered column - means it should only need to be called once... Dan
        Hide
        Martin Dougiamas added a comment -

        Any chance of that in the next few hours? :-P

        Show
        Martin Dougiamas added a comment - Any chance of that in the next few hours? :-P
        Hide
        Dan Marsden added a comment -

        just saw the message....ummmm - how much time do I have now?

        Dan

        Show
        Dan Marsden added a comment - just saw the message....ummmm - how much time do I have now? Dan
        Hide
        Dan Marsden added a comment -

        first fix - new version of choice_show_report_link (not tested completely yet, but should be fine!)

        function choice_show_reportlink($choice, $courseid, $cm, $groupmode) {

        if ($groupmode > 0)

        { $currentgroup = groups_get_activity_group($cm); }

        else

        { $currentgroup = 0; }

        $context = get_context_instance(CONTEXT_MODULE, $cm->id);

        $allresponses = get_records("choice_answers", "choiceid", $choice->id); //get all responses for this choice.
        $responsecount = 0;
        foreach ($allresponses as $usr) {
        if (has_capability('mod/choice:choose', $context, $usr->userid, false))

        { //if this user is allowed to select a choice. $responsecount++; }

        }

        echo '<div class="reportlink">';
        echo "<a href=\"report.php?id=$cm->id\">".get_string("viewallresponses", "choice", $responsecount)."</a>";
        echo '</div>';
        }

        Show
        Dan Marsden added a comment - first fix - new version of choice_show_report_link (not tested completely yet, but should be fine!) function choice_show_reportlink($choice, $courseid, $cm, $groupmode) { if ($groupmode > 0) { $currentgroup = groups_get_activity_group($cm); } else { $currentgroup = 0; } $context = get_context_instance(CONTEXT_MODULE, $cm->id); $allresponses = get_records("choice_answers", "choiceid", $choice->id); //get all responses for this choice. $responsecount = 0; foreach ($allresponses as $usr) { if (has_capability('mod/choice:choose', $context, $usr->userid, false)) { //if this user is allowed to select a choice. $responsecount++; } } echo '<div class="reportlink">'; echo "<a href=\"report.php?id=$cm->id\">".get_string("viewallresponses", "choice", $responsecount)."</a>"; echo '</div>'; }
        Hide
        Dan Marsden added a comment -

        ...in fact - I think that will actually "fix" it for admin's - still a few performance tweaks to make though, but they might be able to wait for 1.9.1

        Dan

        Show
        Dan Marsden added a comment - ...in fact - I think that will actually "fix" it for admin's - still a few performance tweaks to make though, but they might be able to wait for 1.9.1 Dan
        Hide
        Dan Marsden added a comment -

        should be sorted now - feel free to reopen if still not working!

        thanks!

        Dan

        Show
        Dan Marsden added a comment - should be sorted now - feel free to reopen if still not working! thanks! Dan
        Dan Marsden made changes -
        Status Open [ 1 ] Resolved [ 5 ]
        Resolution Fixed [ 1 ]
        Hide
        Martin Dougiamas added a comment -

        By jove it's working, thanks!!!!! :-D

        Show
        Martin Dougiamas added a comment - By jove it's working, thanks!!!!! :-D
        Hide
        Helen Foster added a comment -

        Hi Dan,

        Thanks a lot for your work on this issue. However when I test it on moodle.org as an admin, the bar chart of responses is displayed but the view 3000 responses results in a blank page

        Show
        Helen Foster added a comment - Hi Dan, Thanks a lot for your work on this issue. However when I test it on moodle.org as an admin, the bar chart of responses is displayed but the view 3000 responses results in a blank page
        Helen Foster made changes -
        Resolution Fixed [ 1 ]
        Status Resolved [ 5 ] Reopened [ 4 ]
        QA Assignee tsala
        Hide
        Dan Marsden added a comment -

        doh! - thanks Helen, I'll look into it further! -

        Dan

        Show
        Dan Marsden added a comment - doh! - thanks Helen, I'll look into it further! - Dan
        Hide
        Dan Marsden added a comment -

        yeah - that report.php file is pretty bad - Dan P has written an intial patch that tidies it up a bit - will review and try to fix properly tonight!

        thanks,

        Dan

        Show
        Dan Marsden added a comment - yeah - that report.php file is pretty bad - Dan P has written an intial patch that tidies it up a bit - will review and try to fix properly tonight! thanks, Dan
        Hide
        Dan Marsden added a comment -

        I'd really like to fix this properly and am half way through a proper patch but I'm not going to get a chance to check it properly until Monday - in the interim I've quickly written this patch, which should work to improve performance, but I won't have a chance to commit anything till monday - if someone else wants to test this initial basic patch before then, feel free to commit it to CVS before we release 1.9!

        Show
        Dan Marsden added a comment - I'd really like to fix this properly and am half way through a proper patch but I'm not going to get a chance to check it properly until Monday - in the interim I've quickly written this patch, which should work to improve performance, but I won't have a chance to commit anything till monday - if someone else wants to test this initial basic patch before then, feel free to commit it to CVS before we release 1.9!
        Hide
        Dan Marsden added a comment -

        helps If I attach the file - here it is....

        Show
        Dan Marsden added a comment - helps If I attach the file - here it is....
        Dan Marsden made changes -
        Attachment report.php.patch [ 13255 ]
        Hide
        Martin Dougiamas added a comment -

        Here are some numbers from http://moodle.org/mod/choice/view.php?id=158

        Displaying view.php as admin:

        45.419154 secs
        RAM: 30.1MB
        RAM peak: 51.8MB
        Included 55 files
        DB queries 51810 (!!!!!)
        Log writes 1
        ticks: 4542 user: 1969 sys: 86 cuser: 0 csys: 0
        Load average: 1.60
        Record cache hit/miss ratio : 0/8

        Displaying view.php as ordinary user:

        26.286735 secs
        RAM: 28MB
        RAM peak: 49.6MB
        Included 41 files
        DB queries 51805
        Log writes 1
        ticks: 2629 user: 1792 sys: 69 cuser: 0 csys: 0
        Load average: 1.98
        Record cache hit/miss ratio : 0/8

        Displaying report.php as admin (with patch, thanks, because it runs out of memory without patch):

        69.938082 secs
        RAM: 28.1MB
        RAM peak: 49.6MB
        Included 42 files
        DB queries 59945
        Log writes 1
        ticks: 6994 user: 2128 sys: 463 cuser: 0 csys: 0
        Load average: 1.43
        Record cache hit/miss ratio : 1/9

        There is still a long way to go here (look at all those db accesses for has_capability inside loops). Really we should be able to get all the data with one SQL statement and some joins.

        Oddly, there are 4367 active participants in Using Moodle currently, but Choice says there's 8407 responses, so something is wrong.

        Originally, the choice module only showed and counted answers from currently enrolled people. I'm guessing the code is still trying to do that (but it seems to be failing to do so accurately).

        On the other hand perhaps we COULD let it show just all the choices that have been recorded (back until the course start date perhaps or even a choice start date). This would be bog-simple SQL and fast.

        Show
        Martin Dougiamas added a comment - Here are some numbers from http://moodle.org/mod/choice/view.php?id=158 Displaying view.php as admin: 45.419154 secs RAM: 30.1MB RAM peak: 51.8MB Included 55 files DB queries 51810 (!!!!!) Log writes 1 ticks: 4542 user: 1969 sys: 86 cuser: 0 csys: 0 Load average: 1.60 Record cache hit/miss ratio : 0/8 Displaying view.php as ordinary user: 26.286735 secs RAM: 28MB RAM peak: 49.6MB Included 41 files DB queries 51805 Log writes 1 ticks: 2629 user: 1792 sys: 69 cuser: 0 csys: 0 Load average: 1.98 Record cache hit/miss ratio : 0/8 Displaying report.php as admin (with patch, thanks, because it runs out of memory without patch): 69.938082 secs RAM: 28.1MB RAM peak: 49.6MB Included 42 files DB queries 59945 Log writes 1 ticks: 6994 user: 2128 sys: 463 cuser: 0 csys: 0 Load average: 1.43 Record cache hit/miss ratio : 1/9 There is still a long way to go here (look at all those db accesses for has_capability inside loops). Really we should be able to get all the data with one SQL statement and some joins. Oddly, there are 4367 active participants in Using Moodle currently, but Choice says there's 8407 responses, so something is wrong. Originally, the choice module only showed and counted answers from currently enrolled people. I'm guessing the code is still trying to do that (but it seems to be failing to do so accurately). On the other hand perhaps we COULD let it show just all the choices that have been recorded (back until the course start date perhaps or even a choice start date). This would be bog-simple SQL and fast.
        Martin Dougiamas made changes -
        Summary Choice responses no longer displayed Choice responses use inefficient SQL causing memory to run out
        Martin Dougiamas made changes -
        Priority Minor [ 4 ] Major [ 3 ]
        Hide
        Dan Marsden added a comment -

        wow! - thanks for posting details on those numbers!

        • I'm not too keen displaying "all" choices that have been recorded, it should just show those that have "has_capability" for that course (although that must be failing somewhere.) - I'm trying to seperate out all the calls to get repsonses to one single function that creates an array with all the right stuff. and only call that function once per page (when admin logged in it does it twice on view.php, and report.php is really stupid!

        should have something better somtime this morning!

        Dan

        Show
        Dan Marsden added a comment - wow! - thanks for posting details on those numbers! I'm not too keen displaying "all" choices that have been recorded, it should just show those that have "has_capability" for that course (although that must be failing somewhere.) - I'm trying to seperate out all the calls to get repsonses to one single function that creates an array with all the right stuff. and only call that function once per page (when admin logged in it does it twice on view.php, and report.php is really stupid! should have something better somtime this morning! Dan
        Hide
        Dan Marsden added a comment -

        attaching first version of patch for report.php (only really tidies up download of results)

        Show
        Dan Marsden added a comment - attaching first version of patch for report.php (only really tidies up download of results)
        Dan Marsden made changes -
        Attachment choice.patch [ 13261 ]
        Hide
        Dan Marsden added a comment -

        here's a patch that should tidy it up a lot - still room for improvement - but keen to see if it makes much of a difference on moodle.org!

        Dan

        Show
        Dan Marsden added a comment - here's a patch that should tidy it up a lot - still room for improvement - but keen to see if it makes much of a difference on moodle.org! Dan
        Dan Marsden made changes -
        Attachment choice.patch [ 13263 ]
        Hide
        Dan Marsden added a comment -

        doh - that patch won't work.. give me a bit longer to sort it out properly!

        Show
        Dan Marsden added a comment - doh - that patch won't work.. give me a bit longer to sort it out properly!
        Hide
        Dan Marsden added a comment -

        better patch - missed correct creation of array when not using groups.

        Show
        Dan Marsden added a comment - better patch - missed correct creation of array when not using groups.
        Dan Marsden made changes -
        Attachment choice.patch [ 13264 ]
        Hide
        Dan Marsden added a comment -

        arg - still not right!

        Show
        Dan Marsden added a comment - arg - still not right!
        Hide
        Dan Marsden added a comment -

        this one's the right patch!

        Dan

        Show
        Dan Marsden added a comment - this one's the right patch! Dan
        Dan Marsden made changes -
        Attachment choice.patch [ 13265 ]
        Hide
        Martin Dougiamas added a comment -

        Thanks man! Testing it now.

        Show
        Martin Dougiamas added a comment - Thanks man! Testing it now.
        Hide
        Martin Dougiamas added a comment -

        Current stats: (not much different)

        46.523566 secs
        RAM: 38.1MB
        RAM peak: 47.4MB
        Included 41 files
        DB queries 51828
        Log writes 1
        ticks: 4652 user: 1725 sys: 77 cuser: 0 csys: 0
        Load average: 1.81
        Record cache hit/miss ratio : 0/2

        I'm looking into the code now for a bit. Perhaps we can just get ALL the responses and then cull them down.

        Show
        Martin Dougiamas added a comment - Current stats: (not much different) 46.523566 secs RAM: 38.1MB RAM peak: 47.4MB Included 41 files DB queries 51828 Log writes 1 ticks: 4652 user: 1725 sys: 77 cuser: 0 csys: 0 Load average: 1.81 Record cache hit/miss ratio : 0/2 I'm looking into the code now for a bit. Perhaps we can just get ALL the responses and then cull them down.
        Hide
        Martin Dougiamas added a comment -

        I think the main issue is a bug in get_users_by_capability() ! (ie not your fault! Working on it)

        Show
        Martin Dougiamas added a comment - I think the main issue is a bug in get_users_by_capability() ! (ie not your fault! Working on it)
        Hide
        Martín Langhoff added a comment -

        > DB queries 51828
        ...
        > think the main issue is a bug in get_users_by_capability()

        MD - is there any path in get_users_by_capability() in 1.9 that causes such insane unbound number of DBQs?

        Show
        Martín Langhoff added a comment - > DB queries 51828 ... > think the main issue is a bug in get_users_by_capability() MD - is there any path in get_users_by_capability() in 1.9 that causes such insane unbound number of DBQs?
        Hide
        Martin Dougiamas added a comment -

        Yep, though this problem is a little from column A and a little from column B.

        1) get_users_by_capability() returns ALL users on the site (causing memory limit on moodle.org) when a capability is defined positive for a default role (eg Authenticated users) regardless of the users being actually able to access the given context. So in this case, we were checking for mod/choice:choose in a Choice activity within a course, and the default user has that capability. However you also need to be a participant in that course (moodle/course:view) to actually use that capability, so really we want to check BOTH.

        In this case I could just remove that capability from Authenticated User because we don't really need it (and it's not default!). I don't know how it got there.

        However this issue could easily crop up on big sites in future.

        2) Very small bug I noticed on the way: In the same function there user_lastaccess is JOINed all the time even when we don't really need it (because we specified our own sorting). I will check in a patch for this bit shortly.

        3) I've rewritten choice_get_response_data to be much more efficient (it now always uses get_users_by_capability), but then I found that there is a totally unneeded has_capability inside a big loop in choice_show_form, which I'm fixing now.

        Should be fast shortly!

        Show
        Martin Dougiamas added a comment - Yep, though this problem is a little from column A and a little from column B. 1) get_users_by_capability() returns ALL users on the site (causing memory limit on moodle.org) when a capability is defined positive for a default role (eg Authenticated users) regardless of the users being actually able to access the given context. So in this case, we were checking for mod/choice:choose in a Choice activity within a course, and the default user has that capability. However you also need to be a participant in that course (moodle/course:view) to actually use that capability, so really we want to check BOTH. In this case I could just remove that capability from Authenticated User because we don't really need it (and it's not default!). I don't know how it got there. However this issue could easily crop up on big sites in future. 2) Very small bug I noticed on the way: In the same function there user_lastaccess is JOINed all the time even when we don't really need it (because we specified our own sorting). I will check in a patch for this bit shortly. 3) I've rewritten choice_get_response_data to be much more efficient (it now always uses get_users_by_capability), but then I found that there is a totally unneeded has_capability inside a big loop in choice_show_form, which I'm fixing now. Should be fast shortly!
        Hide
        Dan Marsden added a comment -

        makes a bit more sense now! - I was using has_capability as it seemed to be faster than using get_users_by_capability

        thanks!

        Dan

        Show
        Dan Marsden added a comment - makes a bit more sense now! - I was using has_capability as it seemed to be faster than using get_users_by_capability thanks! Dan
        Hide
        Martin Dougiamas added a comment -

        http://moodle.org/mod/choice/view.php?id=158

        1.579156 secs
        RAM: 9.3MB
        RAM peak: 24.6MB
        Included 41 files
        DB queries 43
        Log writes 1 ticks: 158 user: 45 sys: 6 cuser: 0 csys: 0
        Load average: 0.70
        Record cache hit/miss ratio : 0/2

        Just checking and tidying and it's going in.

        Show
        Martin Dougiamas added a comment - http://moodle.org/mod/choice/view.php?id=158 1.579156 secs RAM: 9.3MB RAM peak: 24.6MB Included 41 files DB queries 43 Log writes 1 ticks: 158 user: 45 sys: 6 cuser: 0 csys: 0 Load average: 0.70 Record cache hit/miss ratio : 0/2 Just checking and tidying and it's going in.
        Hide
        Dan Marsden added a comment -

        awesome! - well done!

        will test it completely first thing tomorrow morning!

        thanks!

        Dan

        Show
        Dan Marsden added a comment - awesome! - well done! will test it completely first thing tomorrow morning! thanks! Dan
        Hide
        Martín Langhoff added a comment -

        > DB queries 51828
        ...
        >DB queries 43

        Kudos. That's how Real Men Do SQL.

        Show
        Martín Langhoff added a comment - > DB queries 51828 ... >DB queries 43 Kudos. That's how Real Men Do SQL.
        Hide
        Martin Dougiamas added a comment -

        Thanks Dan (your fixes got us half way there) and Martin for support

        Show
        Martin Dougiamas added a comment - Thanks Dan (your fixes got us half way there) and Martin for support
        Martin Dougiamas made changes -
        Status Reopened [ 4 ] Resolved [ 5 ]
        Resolution Fixed [ 1 ]
        Hide
        Martin Dougiamas added a comment -

        Just adding a link to MDL-13755 which is about the issue in get_users_by_capability()

        Show
        Martin Dougiamas added a comment - Just adding a link to MDL-13755 which is about the issue in get_users_by_capability()
        Martin Dougiamas made changes -
        Link This issue has a non-specific relationship to MDL-13755 [ MDL-13755 ]
        Hide
        Helen Foster added a comment -

        Wow - it's really fast now! Fantastic work - a big THANK YOU Martin and Dan!

        Show
        Helen Foster added a comment - Wow - it's really fast now! Fantastic work - a big THANK YOU Martin and Dan!
        Helen Foster made changes -
        Status Resolved [ 5 ] Closed [ 6 ]
        Martin Dougiamas made changes -
        Workflow jira [ 24910 ] MDL Workflow [ 58839 ]
        Martin Dougiamas made changes -
        Workflow MDL Workflow [ 58839 ] MDL Full Workflow [ 87991 ]
        Stephen Bourget made changes -
        Link This issue caused a regression MDL-34375 [ MDL-34375 ]

          People

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

            Dates

            • Created:
              Updated:
              Resolved: