Moodle
  1. Moodle
  2. MDL-18241

My Moodle generating 12,000 database queries per pageload

    Details

    • Type: Bug Bug
    • Status: Closed
    • Priority: Blocker Blocker
    • Resolution: Fixed
    • Affects Version/s: 1.9.4
    • Fix Version/s: 1.9.5
    • Component/s: Performance
    • Labels:
      None
    • Environment:
      mysql
    • Affected Branches:
      MOODLE_19_STABLE
    • Fixed Branches:
      MOODLE_19_STABLE
    • Rank:
      31530

      Description

      We had some reports of slowness on one of our moodle sites. It turned out the school had my moodle redirect switched on.

      Upon investigating the performance log I discovered for a single user /my/ page was causing 12401 database queries.

      Here is a perf log line from my dev machine (artificially fast due to front/backend being the same).

      [Tue Feb 10 19:38:55 2009] [error] [client 10.0.0.5] PERF: /my/ time: 5.407977s memory_total: 21916276B (20.9MB) memory_growth: 21626784B (20.6MB) memory_peak: 22259484B (21.2MB) includecount: 80 dbqueries: 12401 ticks: 541 user: 211 sys: 144 cuser: 0 csys: 0 serverload: 0.11 rcache: 0/0

      I want to investigate this and search and destroy whatever is causing it. This obviously cripples a moodle site with my moodle redirection.

        Activity

        Hide
        Dan Poltawski added a comment - - edited

        Adding Petr here as he did some perf work on my moodle page for 1.9

        Show
        Dan Poltawski added a comment - - edited Adding Petr here as he did some perf work on my moodle page for 1.9
        Hide
        Dan Poltawski added a comment -

        Biggest offender appears to be assignment module (disabling drops to 810 queries)

        Show
        Dan Poltawski added a comment - Biggest offender appears to be assignment module (disabling drops to 810 queries)
        Hide
        Dan Poltawski added a comment -

        Spent about 2mins hacking up this patch.

        Before: time: 5.975912s - dbqueries: 12400
        After: time: 0.809208s - dbqueries: 431

        Will look a bit deeper tomorrow (for instance in this case it might useful to find out if php test vs large db packet is more efficient).

        Show
        Dan Poltawski added a comment - Spent about 2mins hacking up this patch. Before: time: 5.975912s - dbqueries: 12400 After: time: 0.809208s - dbqueries: 431 Will look a bit deeper tomorrow (for instance in this case it might useful to find out if php test vs large db packet is more efficient).
        Hide
        Dan Poltawski added a comment -

        Real life perfmance log entry:

        [Fri Feb 13 09:57:52 2009] [error] PERF: /my/ time: 708.269655s memory_total: 16262224B (15.5MB) memory_growth: 16210736B (15.5MB) memory_peak: 17764064B (16.9MB) includecount: 105 dbqueries: 12874 ticks: 70844 user: 2382 sys: 259 cuser: 0 csys: 0 serverload: 1.90 rcache: 0/19

        Show
        Dan Poltawski added a comment - Real life perfmance log entry: [Fri Feb 13 09:57:52 2009] [error] PERF: /my/ time: 708.269655s memory_total: 16262224B (15.5MB) memory_growth: 16210736B (15.5MB) memory_peak: 17764064B (16.9MB) includecount: 105 dbqueries: 12874 ticks: 70844 user: 2382 sys: 259 cuser: 0 csys: 0 serverload: 1.90 rcache: 0/19
        Hide
        Tim Hunt added a comment -

        Patch looks good to me. Why hesitate to commit it (providing you have checked that it does not change the results).

        Show
        Tim Hunt added a comment - Patch looks good to me. Why hesitate to commit it (providing you have checked that it does not change the results).
        Hide
        Petr Škoda added a comment -

        there is a bug for this somewhere already I think, +1 for commit

        Show
        Petr Škoda added a comment - there is a bug for this somewhere already I think, +1 for commit
        Hide
        Dan Poltawski added a comment -

        Hesitate because I did no testing! Will need to do that. thanks for encouragement.

        I think we can remove another set in-loop dbq too.

        Ps: this raises an interesting question related to a 'joinable' database table for enrolments - in this case would it help us at all, cos we'd have to check each individual capabiltity? (devils advocate here)

        Show
        Dan Poltawski added a comment - Hesitate because I did no testing! Will need to do that. thanks for encouragement. I think we can remove another set in-loop dbq too. Ps: this raises an interesting question related to a 'joinable' database table for enrolments - in this case would it help us at all, cos we'd have to check each individual capabiltity? (devils advocate here)
        Hide
        Dan Poltawski added a comment -

        New patch which takes all the sql I think we can out of the loops. Its a shame I don't we can't get rid of the get_users_by_capability() call, but still a big improvement.

        Real query numbers before/after:
        Teacher: 12,509 / 314
        Student: 127 / 72
        Admin: 718 / 133

        Need to do a bit more testing and then will commit.

        Show
        Dan Poltawski added a comment - New patch which takes all the sql I think we can out of the loops. Its a shame I don't we can't get rid of the get_users_by_capability() call, but still a big improvement. Real query numbers before/after: Teacher: 12,509 / 314 Student: 127 / 72 Admin: 718 / 133 Need to do a bit more testing and then will commit.
        Hide
        Dan Poltawski added a comment -

        Ooops, that patch introduced a regression on checking for markedness. Here is a new one

        Show
        Dan Poltawski added a comment - Ooops, that patch introduced a regression on checking for markedness. Here is a new one
        Hide
        Dan Poltawski added a comment -

        I've done some further testing and have commited this to CVS. Please test!

        Show
        Dan Poltawski added a comment - I've done some further testing and have commited this to CVS. Please test!
        Hide
        Tim Hunt added a comment -

        Reviewed code, and it looks good. (You even avoided the mistakes I usually make when merging DB code from 1.9 -> 2.0 ) Also tested a bit and the code still seems to work properly.

        Hmm. Unfortunately, I have just found another bug. If the assignment is set to separate groups, and (non-editing) teachers don't have 'accessallgroups', then the display on the My Moodle page is wrong. However, that was wrong before, and your reworking does not change that, so I will file a separate bug.

        Show
        Tim Hunt added a comment - Reviewed code, and it looks good. (You even avoided the mistakes I usually make when merging DB code from 1.9 -> 2.0 ) Also tested a bit and the code still seems to work properly. Hmm. Unfortunately, I have just found another bug. If the assignment is set to separate groups, and (non-editing) teachers don't have 'accessallgroups', then the display on the My Moodle page is wrong. However, that was wrong before, and your reworking does not change that, so I will file a separate bug.
        Hide
        Tim Hunt added a comment -

        New bug is MDL-18280.

        Show
        Tim Hunt added a comment - New bug is MDL-18280 .

          People

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

            Dates

            • Created:
              Updated:
              Resolved: