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

      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.

        Gliffy Diagrams

          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 Skoda added a comment -

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

          Show
          Petr Skoda 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: