Issue Details (XML | Word | Printable)

Key: MDL-18241
Type: Bug Bug
Status: Closed Closed
Resolution: Fixed
Priority: Blocker Blocker
Assignee: Dan Poltawski
Reporter: Dan Poltawski
Votes: 0
Watchers: 4
Operations

Add/Edit UI Mockup to this issue
If you were logged in you would be able to see more operations.
Moodle

My Moodle generating 12,000 database queries per pageload

Created: 14/Feb/09 07:29 AM   Updated: 17/Feb/09 12:26 PM
Component/s: Performance
Affects Version/s: 1.9.4
Fix Version/s: 1.9.5

File Attachments: 1. Text File 0001-performance-mymoodle-MDL-18241-Assigments-were-ver.patch (5 kB)
2. Text File MDL-18241-fastpatch1.patch (1 kB)

Environment: mysql

Participants: Dan Poltawski, Petr Škoda (skodak) and Tim Hunt
Security Level: None
QA Assignee: Tim Hunt
Resolved date: 16/Feb/09
Affected Branches: MOODLE_19_STABLE
Fixed Branches: MOODLE_19_STABLE


 Description  « Hide
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.



 All   Comments   Change History   Version Control      Sort Order: Ascending order - Click to sort in descending order
Dan Poltawski added a comment - 14/Feb/09 07:31 AM - edited
Adding Petr here as he did some perf work on my moodle page for 1.9

Dan Poltawski added a comment - 14/Feb/09 07:47 AM
Biggest offender appears to be assignment module (disabling drops to 810 queries)

Dan Poltawski added a comment - 14/Feb/09 08:34 AM
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).


Dan Poltawski added a comment - 14/Feb/09 10:25 AM
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


Tim Hunt added a comment - 14/Feb/09 09:20 PM
Patch looks good to me. Why hesitate to commit it (providing you have checked that it does not change the results).

Petr Škoda (skodak) added a comment - 15/Feb/09 12:53 AM
there is a bug for this somewhere already I think, +1 for commit

Dan Poltawski added a comment - 15/Feb/09 10:53 AM
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)


Dan Poltawski added a comment - 16/Feb/09 03:09 AM
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.


Dan Poltawski added a comment - 16/Feb/09 03:28 AM
Ooops, that patch introduced a regression on checking for markedness. Here is a new one

Dan Poltawski added a comment - 16/Feb/09 10:19 PM
I've done some further testing and have commited this to CVS. Please test!

Tim Hunt added a comment - 17/Feb/09 12:19 PM
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.


Tim Hunt added a comment - 17/Feb/09 12:26 PM
New bug is MDL-18280.