Statistics stupidly inefficient

Statistics stupidly inefficient

by Bruce Webster -
Number of replies: 17
On 1.9.3+ (Build: 20090109) stats are completely unusable for us.

Working on one single day of stats on our site (a pilot of only 30-odd courses but with 30000 mostly-unused rows in the user table), MySQL struggled for 6 HOURS on a single stats query!!

2 Hours after this particular query, stats was still processing with MySQL locked up at 100% usage and not allowing moodle to connect.

Here is the monstrous query. We showed it to our Computer Science SQL lecturer for a laugh who said 'it is definitely a very bad query. Using cross join on large tables is a definite NO'. Creating 1.2 billion rows to look at from our little DB is insane.

# Time: 090306  6:30:42
# User@Host: moodle[moodle] @ localhost []
# Query_time: 21631  Lock_time: 0  Rows_sent: 0  Rows_examined: 1199857693
UPDATE mdl_stats_daily
                   SET stat2 = (SELECT COUNT(DISTINCT ra.userid)
                                  FROM mdl_role_assignments ra JOIN mdl_context ctx
                  ON ctx.id = ra.contextid
             CROSS JOIN mdl_course c
             JOIN mdl_role_capabilities rc
                  ON rc.roleid = ra.roleid LEFT OUTER JOIN mdl_course_categories cc1
                            ON cc1.id = c.category
                                 WHERE ra.roleid = mdl_stats_daily.roleid AND
                                       c.id = mdl_stats_daily.courseid AND
                                       ((rc.capability = 'moodle/course:view' )
               AND rc.permission = 1 AND rc.contextid = 1
               AND (ctx.contextlevel = 10
                    OR (c.id = ctx.instanceid AND ctx.contextlevel = 50) OR (cc1.id = ctx.instanceid AND ctx.contextlevel = 40))) AND
                                       EXISTS (SELECT 'x'
                                                 FROM mdl_log l
                                                WHERE l.course = mdl_stats_daily.courseid AND
                                                      l.userid = ra.userid AND l.time >= 1236164400  AND l.time  < 1236250800))
                 WHERE mdl_stats_daily.stattype = 'enrolments' AND
                       mdl_stats_daily.timeend = 1236250800 AND
                       mdl_stats_daily.courseid IN
                          (SELECT DISTINCT l.course
                             FROM mdl_log l
                            WHERE l.time >= 1236164400  AND l.time  < 1236250800);
Average of ratings: Useful (1)
In reply to Bruce Webster

Re: Statistics stupidly inefficient

by Dan Marsden -
Picture of Core developers Picture of Particularly helpful Moodlers Picture of Peer reviewers Picture of Plugin developers Picture of Plugins guardians Picture of Testers Picture of Translators
Hi Bruce,

Matt Clarkson (from Catalyst) is just having a quick look at this too - I see you've created MDL-18484 for this as well - great! - Matt has an improved query that could do with some testing that he will add to the tracker issue.
Average of ratings: Useful (1)
In reply to Bruce Webster

Re: Statistics stupidly inefficient

by Matt Clarkson -
Picture of Core developers Picture of Peer reviewers Picture of Plugin developers
Hi Bruce,

I have re-written the section of this query that works out course enrolments. One side effect of this optimisation is that enrolments against nested course categories can now be considered with minimal performance impact. (Normally any enrolments in nested course categories are ignored.)

Can you run this query and let me know how long it takes:
UPDATE mdl_stats_daily
 SET stat2 = (SELECT COUNT(DISTINCT ra.userid)
 FROM mdl_role_assignments ra
 INNER JOIN mdl_context cx ON ra.contextid = cx.id AND cx.contextlevel <= 50
 LEFT JOIN mdl_context scx ON scx.path LIKE CONCAT(cx.path, '/%') AND scx.contextlevel = 50 AND cx.contextlevel < 50
 INNER JOIN mdl_course c ON scx.instanceid = c.id OR (cx.contextlevel = 50 AND cx.instanceid = c.id)
 INNER JOIN mdl_role_capabilities rc ON rc.roleid = ra.roleid
 WHERE ra.roleid = mdl_stats_daily.roleid AND
 c.id = mdl_stats_daily.courseid AND
 rc.capability = 'moodle/course:view'AND
 rc.permission = 1 AND rc.contextid = 1
 AND EXISTS (SELECT 'x'
 FROM mdl_log l
 WHERE l.course = mdl_stats_daily.courseid AND
 l.userid = ra.userid AND l.time >= 1236164400 AND l.time < 1236250800))
 WHERE mdl_stats_daily.stattype = 'enrolments' AND
 mdl_stats_daily.timeend = 1236250800 AND
 mdl_stats_daily.courseid IN
 (SELECT DISTINCT l.course
 FROM mdl_log l
 WHERE l.time >= 1236164400 AND l.time < 1236250800);



Cheers,
Matt.
Average of ratings: Useful (1)
In reply to Matt Clarkson

Re: Statistics unusable

by Bruce Webster -
Thanks Matt, but that made little difference, 5% (55 million) MORE rows examined than before. A few hours in, MySQL locked up (moodle unable to connect).

Maybe this is faster in Postgres, but "In MySQL, CROSS JOIN is a syntactic equivalent to INNER JOIN (they can replace each other)"
http://dev.mysql.com/doc/refman/5.0/en/join.html

# Time: 090310 22:37:40
# User@Host: moodle-remote
# Query_time: 21060 Lock_time: 0 Rows_sent: 0 Rows_examined: 1254137425
Average of ratings: Useful (1)
In reply to Bruce Webster

Re: Statistics unusable

by Matt Clarkson -
Picture of Core developers Picture of Peer reviewers Picture of Plugin developers
Hi Bruce,

I had a similar experience running the query on a different data set.

Although a CROSS JOIN and INNER JOIN are the same thing in mysql, the important distinction is the use of an ON clause which limits the scope of the join. Generally if the scope of the ON clause is narrow enough there shouldn't be performance issues using an INNER/CROSS JOIN.

It seems quite likely that you are suffering from table locking which is contributing to poor performace. MySQL using the innodb storage engine is much better in this respect, as is postgres.

I have been playing around with the building a temp table of course enrolments which can be used throughout the stats processing.


Trying running this SQL script and let me know how long it takes:


CREATE TEMPORARY TABLE stats_enrolments
 SELECT DISTINCT ra.roleid, ra.userid, c.id AS courseid
 FROM mdl_role_assignments ra
 INNER JOIN mdl_role_capabilities rc ON ra.roleid = rc.roleid AND rc.capability = 'moodle/course:view' AND rc.permission = 1 AND rc.contextid = 1
 INNER JOIN mdl_context cx ON ra.contextid = cx.id AND cx.contextlevel = 10
 CROSS JOIN mdl_course c
 UNION
 SELECT DISTINCT ra.roleid, ra.userid, c.id AS courseid
 FROM mdl_role_assignments ra
 INNER JOIN mdl_role_capabilities rc ON ra.roleid = rc.roleid AND rc.capability = 'moodle/course:view' AND rc.permission = 1 AND rc.contextid = 1
 INNER JOIN mdl_context cx ON ra.contextid = cx.id AND cx.contextlevel = 40
 INNER JOIN mdl_course_categories cc ON cx.instanceid = cc.id
 LEFT JOIN mdl_course_categories scc ON scc.path LIKE CONCAT(cc.path,"'/%'")
 INNER JOIN mdl_course c ON c.category = scc.id OR c.category = cc.id
 UNION
 SELECT DISTINCT ra.roleid, ra.userid, c.id AS courseid
 FROM mdl_role_assignments ra
 INNER JOIN mdl_role_capabilities rc ON ra.roleid = rc.roleid AND rc.capability = 'moodle/course:view' AND rc.permission = 1 AND rc.contextid = 1
 INNER JOIN mdl_context cx ON ra.contextid = cx.id AND cx.contextlevel = 50
 INNER JOIN mdl_course c ON cx.instanceid = c.id

;
CREATE INDEX stats_enrol_idx ON stats_enrolments (userid, courseid);


UPDATE mdl_stats_daily
 SET stat2 = (
 SELECT COUNT(DISTINCT e.userid)
 FROM stats_enrolments e
 INNER JOIN mdl_log l ON l.userid = e.userid AND l.course = e.courseid
 WHERE e.courseid = mdl_stats_daily.courseid
 AND l.time >= 1236164400
 AND l.time < 1236250800)
 WHERE mdl_stats_daily.stattype = 'enrolments' AND
 mdl_stats_daily.timeend = 1236250800 AND
 mdl_stats_daily.roleid = 0 AND
 mdl_stats_daily.courseid IN
 (SELECT DISTINCT l.course
 FROM mdl_log l
 WHERE l.time >= 1236164400 AND l.time < 1236250800 );

DROP TABLE stats_enrolments; 
In reply to Matt Clarkson

Re: Statistics unusable

by Juan Segarra Montesinos -
Picture of Core developers Picture of Plugin developers
Hi Matt smile

Category level enrollments can be calculated in a UNION just like it's done now [1]. I think they will perform better.

On the other hand. Query still is really slow. More can be done: create a temporary table with the day logs and index it correctly. For instance:

CREATE TABLE mdl_tmp_stats_logs
SELECT *
FROM mdl_log l
WHERE l.time >= 1236164400 AND l.time < 1236250800;

CREATE INDEX mdl_tmp_stats_logs_time_idx ON mdl_tmp_stats_logs ( time );
CREATE INDEX mdl_tmp_stats_logs_course_idx ON mdl_tmp_stats_logs ( course );

(
and all the indexes necessary... to simplify the creation you can use this trick:

CREATE TABLE mdl_tmp_stats_logs LIKE mdl_log;
INSERT INTO mdl_tmp_stats_logs select * from mdl_log l WHERE l.time >= 1236164400 AND l.time < 1236250800;
)


Now rewrite the query as:

UPDATE mdl_stats_daily
 SET stat2 = (
 SELECT COUNT(DISTINCT e.userid)
 FROM stats_enrolments e
 INNER JOIN mdl_tmp_stats_logs l ON l.userid = e.userid AND l.course = e.courseid
 WHERE e.courseid = mdl_stats_daily.courseid)
 WHERE mdl_stats_daily.stattype = 'enrolments' AND
 mdl_stats_daily.timeend = 1236250800 AND
 mdl_stats_daily.roleid = 0 AND
 mdl_stats_daily.courseid IN
 (SELECT DISTINCT course
 FROM mdl_tmp_stats_logs);

This performs much, much better (less than a second... if i'm not wrong... let's see the others ;) )

Now you'll have to calculate a mdl_log "view" for each day... but it can be reused (as stats_enrolments) in the other queries.

On the other hand, using TEMPORARY table can produce problems in a replication configuration. Maybe removing the word TEMPORARY and CREATING and DROPING the table in code should be much better.

Hope this helps ;)

---------
[1] The new stats_enrolments calculus for the example ( just one category level):

CREATE TEMPORARY TABLE stats_enrolments
SELECT DISTINCT ra.roleid, ra.userid, c.id AS courseid
FROM mdl_role_assignments ra
INNER JOIN mdl_role_capabilities rc ON ra.roleid = rc.roleid AND rc.capability = 'moodle/course:view' AND rc.permission = 1 AND rc.contextid = 1
INNER JOIN mdl_context cx ON ra.contextid = cx.id AND cx.contextlevel = 10
CROSS JOIN mdl_course c
UNION
SELECT DISTINCT ra.roleid, ra.userid, c.id as courseid
FROM mdl_role_assignments ra
JOIN
mdl_context ctx ON ctx.id = ra.contextid
CROSS JOIN
mdl_course c
JOIN mdl_role_capabilities rc ON rc.roleid = ra.roleid
LEFT OUTER JOIN mdl_course_categories cc1 ON cc1.id = c.category
WHERE (
(rc.capability = 'moodle/course:view' ) AND
rc.permission = 1 AND
rc.contextid = 1 AND
((cc1.id = ctx.instanceid AND ctx.contextlevel = 40)))
UNION
SELECT DISTINCT ra.roleid, ra.userid, c.id AS courseid
FROM mdl_role_assignments ra
INNER JOIN mdl_role_capabilities rc ON ra.roleid = rc.roleid AND rc.capability = 'moodle/course:view' AND rc.permission = 1 AND rc.contextid = 1
INNER JOIN mdl_context cx ON ra.contextid = cx.id AND cx.contextlevel = 50
INNER JOIN mdl_course c ON cx.instanceid = c.id

;
CREATE INDEX stats_enrol_idx ON stats_enrolments (userid, courseid);
In reply to Juan Segarra Montesinos

Re: Statistics unusable

by Matteo Scaramuccia -
Picture of Core developers Picture of Peer reviewers Picture of Plugin developers

Hi Juan,

did you make any progress on evaluating this issue? Please, take a look at MDL-18484: I've tried Matt's proposal, reviewing his patch (=> statslib.php-rev02.diff) but I'm in need to review the population of the mdl_tmp_stats_enrolments table since it sometime takes MDL-18484#comment_98383_header_matteo" target="_blank" rel="noreferrer noopener">too much time.

TIA,

Matteo

In reply to Matt Clarkson

Re: Statistics unusable

by Bruce Webster -
I took a sql dump over to another server since I didn't want to test on the live server. The weird thing is that the *original* query then only took 6 seconds! Something funny going on there.

Juan's method is a bit quicker than Matts (.09 secs vs .76 secs), better than 6 secs but I haven't tested them on the problem server (which is working fine in all other respects).

INNODB might work better with regard to locking but the 1.2 billion rows was the primary cause.

-Bruce.
In reply to Bruce Webster

Re: Statistics unusable

by HJWUCGA INC. -
mine is exactly the same ...innodb .. ... on the test box, it ran fine but on production, it locked up and had to restart the service ...

the test is a mirror of production in every way - hardware, patch levels, plugins, design, os/moodle/php and mysql release ...

innodb made no difference ... when we had it as myISAM, it seemed fine.
In reply to Bruce Webster

Re: Statistics stupidly inefficient

by Jose' Coelho -

Hi Bruce,

The block Usage (http://moodle.org/mod/data/view.php?d=13&rid=1851) gives statistics on the fly that are updated only in the cron, and only the information that change.

It is working in a server with a load of 2 to 5 million page views per month, and it is in the front page (check it www.moodle.univ-ab.pt). Clicking over the image, shows the data in a table bellow.

Regards,
José Coelho

In reply to Bruce Webster

Re: Statistics stupidly inefficient

by HJWUCGA INC. -
Where did you get this query from? which file is it? I'm experiencing the same problem as it crashes moodle every time when we run our cron tasks and I've always suspected it might have something to do with the mdl_log and stats processing.

Doing a top command, i notice the mysql is taken up 99% of the CPU time most of the time when executing the cron.
In reply to HJWUCGA INC.

Re: Statistics stupidly inefficient

by Dan Marsden -
Picture of Core developers Picture of Particularly helpful Moodlers Picture of Peer reviewers Picture of Plugin developers Picture of Plugins guardians Picture of Testers Picture of Translators
Bruce pulled it out of the mysql slow query log - which you can enable by adding something like:
log_slow_queries=/var/log/mysql/mysql-slow.log

to your my.cnf file

moodle.org has recently seen some good improvements when running innodb instead of the MyISAM tables created by default. Martin Dougiamas has posted recently about this here: http://moodle.org/mod/forum/discuss.php?d=117913
In reply to Dan Marsden

Re: Statistics stupidly inefficient

by Juan Segarra Montesinos -
Picture of Core developers Picture of Plugin developers
Hi Dan smile

Running innodb improves overall performance but, even with that, statistics become a problem in sites with a respectable load (we have more than a million actions per month). We are running Innodb for two years and we're very happy smile

I've observed contention in rows of tables like mdl_user, mdl_course and mdl_log while statistics are running, causing response time to be poor, CPU nealy 100%, slaves delay, etc.

I think work needs to be done in order to improve statistics performance. And think it can be relatively easy.

Administration tricks can be done instead... but it'll be nice to have a more efficient implementation.

Regards smile

In reply to Juan Segarra Montesinos

Re: Statistics stupidly inefficient

by Dan Marsden -
Picture of Core developers Picture of Particularly helpful Moodlers Picture of Peer reviewers Picture of Plugin developers Picture of Plugins guardians Picture of Testers Picture of Translators
Hi Juan,

I don't disagree! - It would be good to get some feedback regarding the query Matt posted above, but that will take time/whereas Innodb might be a partial quick win for performance.
In reply to Bruce Webster

Re: Statistics stupidly inefficient

by Petr Skoda -
Picture of Core developers Picture of Documentation writers Picture of Peer reviewers Picture of Plugin developers
Hmm, yes that code is probably very silly and yes that was probably me who wrote it, but you should have seen it when it was looping all courses and users in PHP big grin

There is another problem we have to keep in mind, the stats code needs to execute for all 4 supported databases, this was in fact the worst problem me and Eloy faced when trying to find some suitable solution.

I suppose this code could be greatly simplified if we implement major enrolment changes in 2.0, until that gets decided I do not think we should touch this code in HEAD.

In any case thanks a lot for having a look at this ugly query, please file a report and push any working patches there, maybe somebody will step up and test/optimise it for all 4 databases wink

thanks again!
In reply to Petr Skoda

Re: Statistics stupidly inefficient

by Juan Segarra Montesinos -
Picture of Core developers Picture of Plugin developers
Definitely, the way this problem has been reported, has not been adequate.

You (developers) are doing great work with moodle ;)

Regards smile

In reply to Juan Segarra Montesinos

Re: Statistics unusable

by Bruce Webster -
Juan, what extra information is needed? I think it is clear that this is a bad query and the CROSS or INNER joins are the problem. Your post in the tracker is a good start to improving it - it appears that trying to do everything in one query is not the best approach here.

I'm sorry if you took offence to my title of "stupidly inefficient", but taking over 8 hours (I killed the process) to process 24 hours of stats with a small number of courses is not clever! I certainly don't think moodle or moodle developers are stupid. I referred to it as "impossibly slow" in the tracker.