Moodle

My Moodle generating 12,000 database queries per pageload

Details

  • Type: Bug Bug
  • Status: Closed 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.

Activity

Ascending order - Click to sort in descending order
Hide
Permalink
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
Permalink
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
Permalink
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
Permalink
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
Permalink
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
Permalink
Petr Škoda (skodak) added a comment -

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

Show
Petr Škoda (skodak) added a comment - there is a bug for this somewhere already I think, +1 for commit
Hide
Permalink
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
Permalink
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
Permalink
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
Permalink
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
Permalink
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
Permalink
Tim Hunt added a comment -

New bug is MDL-18280.

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

People

Vote (0)
Watch (4)

Dates

  • Created:
    Updated:
    Resolved:
Atlassian JIRA (v4.4.3#663-r165197) | Report a problem
Powered by a free Atlassian JIRA open source license for Moodle. Try JIRA - bug tracking software for your team.