After messing with keys and optimizing tables and such, most things seem to be much faster. However, there is one class of query which still takes a long time and if it is run by a few users at once can make the whole system very slow. I've started logging slow queries and these queries take anywhere up to 40 or 50 seconds.
An example of a query:
SELECT rc.capability, c1.id as id1, c2.id as id2, (c1.contextlevel * 100 + c2.contextlevel) AS aggrlevel, rc.permission AS sum FROM mdl_role_assignments ra, mdl_role_capabilities rc, mdl_context c1, mdl_context c2 WHERE ra.contextid=c1.id AND ra.roleid=rc.roleid AND ra.userid=516579 AND rc.contextid=c2.id AND c1.id IN (2919,921,1110,1115,1682,1986,2053,1767,2132,2537,2253,2695,2569,1416,1389,2539,2945,3827,3613,3130,3939,3615,3132 ,3140) AND rc.contextid != 1 AND ((ra.timestart = 0 OR ra.timestart < 1168013945) AND (ra.timeend = 0 OR ra.timeend > 1168013945)) GROUP BY rc.capability, (c1.contextlevel * 100 + c2.contextlevel), c1.id, c2.id, rc.permission ORDER BY aggrlevel ASC;
Which returns 170000 rows or so.
Explain select shows that there is no key for rc, which makes sense since as far as I can tell there is nothing in the where statement which would restrict it.
What can I do to speed up this query, and/or make it occur less frequently, and/or decrease the number of rows it returns?
moodle 1.7 -- one very slow query in particular
Number of replies: 6
Re: moodle 1.7 -- one very slow query in particular
We upgraded from Moodle 1.5.3 to 1.7+ on 1/8/07 and are also running into this issue. We have a dedicated MySQL server that is making some heroic efforts to keep up on queries similar to this one:
<<example excerpt from the MySQL slow query log>>
# Query_time: 31 Lock_time: 0 Rows_sent: 334368 Rows_examined: 1340316
SELECT rc.capability, c1.id as id1, c2.id as id2, (c1.contextlevel * 100 + c2.contextlevel) AS aggrlevel,
rc.permission AS sum
FROM
mdl_role_assignments ra,
mdl_role_capabilities rc,
mdl_context c1,
mdl_context c2
WHERE
ra.contextid=c1.id AND
ra.roleid=rc.roleid AND
ra.userid=22 AND
rc.contextid=c2.id AND
c1.id IN (54,35,83,102,107,75,172,203,69,389,223,219,257,383,291,298,512,302,366,363,378,217,316,457,456,431,362,319,361,345,58,354,385) AND
rc.contextid != 1
AND ((ra.timestart = 0 OR ra.timestart < 1168276177) AND (ra.timeend = 0 OR ra.timeend > 1168276177))
GROUP BY
rc.capability, (c1.contextlevel * 100 + c2.contextlevel), c1.id, c2.id, rc.permission
ORDER BY
aggrlevel ASC;
This particular query returned 334,368 rows and took 31 seconds to complete (our PHP execution timeout is set to 30 seconds). I noticed that an index on role_capabilities.capability was present in our fresh 1.7 test install but not present in our upgraded 1.7 version. I went ahead and added an index, but the issue of 300k+ rows returned is still biting us.
If anyone knows of a solution, we would be most interested!
<<example excerpt from the MySQL slow query log>>
# Query_time: 31 Lock_time: 0 Rows_sent: 334368 Rows_examined: 1340316
SELECT rc.capability, c1.id as id1, c2.id as id2, (c1.contextlevel * 100 + c2.contextlevel) AS aggrlevel,
rc.permission AS sum
FROM
mdl_role_assignments ra,
mdl_role_capabilities rc,
mdl_context c1,
mdl_context c2
WHERE
ra.contextid=c1.id AND
ra.roleid=rc.roleid AND
ra.userid=22 AND
rc.contextid=c2.id AND
c1.id IN (54,35,83,102,107,75,172,203,69,389,223,219,257,383,291,298,512,302,366,363,378,217,316,457,456,431,362,319,361,345,58,354,385) AND
rc.contextid != 1
AND ((ra.timestart = 0 OR ra.timestart < 1168276177) AND (ra.timeend = 0 OR ra.timeend > 1168276177))
GROUP BY
rc.capability, (c1.contextlevel * 100 + c2.contextlevel), c1.id, c2.id, rc.permission
ORDER BY
aggrlevel ASC;
This particular query returned 334,368 rows and took 31 seconds to complete (our PHP execution timeout is set to 30 seconds). I noticed that an index on role_capabilities.capability was present in our fresh 1.7 test install but not present in our upgraded 1.7 version. I went ahead and added an index, but the issue of 300k+ rows returned is still biting us.
If anyone knows of a solution, we would be most interested!
Re: moodle 1.7 -- one very slow query in particular
How are you viewing the slow query log? Is this built in to MySQL?
Re: moodle 1.7 -- one very slow query in particular
Just run mysqld_safe with the "--log-slow-queries" option. It will create a log file in /var/lib/mysql.
Re: moodle 1.7 -- one very slow query in particular
Whew!! Glad it is not just me. I posted a bug to bug tracker today. It looks like it takes about 9 seconds typically on my server and up to 22 at times. I am getting a log file full of them - those are the only queries I am getting as slow.
If you have any information to add, here is the link to my report:
http://tracker.moodle.org/browse/MDL-8138
Jenny
Re: moodle 1.7 -- one very slow query in particular
Hello,
I've submitted a ticket to the Moodle Tracker system. It does not appear that the issue (very large MySQL result set) has been reported yet.
http://tracker.moodle.org/browse/MDL-8120
-Max
I've submitted a ticket to the Moodle Tracker system. It does not appear that the issue (very large MySQL result set) has been reported yet.
http://tracker.moodle.org/browse/MDL-8120
-Max
Re: moodle 1.7 -- one very slow query in particular
Hi, Max!
It looks like you reported yours ahead of mine. I did a quick search but did not find any others. Hopefully they will take a look and resolve it.
Jenny