Details

    • Type: Bug Bug
    • Status: Closed
    • Priority: Major Major
    • Resolution: Fixed
    • Affects Version/s: 1.9.3, 1.9.4, 1.9.5
    • Fix Version/s: None
    • Component/s: Administration
    • Labels:
    • Environment:
      LAMP
    • Database:
      MySQL
    • Affected Branches:
      MOODLE_19_STABLE
    • Rank:
      2335

      Description

      On 1.9.3+ (Build: 20090109) stats are completely unusable for us.

      My server tried to runs stats for ONE SINGLE DAY of logs on our site (a pilot of only 30-odd courses but with 30000 mostly-unused rows in the user table). After 8 HOURS, I had to restart MySQL in the morning as it was still locked up at 100% and moodle could not connect to the DB.

      MySQL struggled for 6 HOURS on a single query!!

      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 from our little DB is insane.

      1. Time: 090306 6:30:42
      2. User@Host: moodle[moodle] @ localhost []
      3. 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);
      1. commit-5b5a23f
        14 kB
        Matt Clarkson
      2. statslib.php-rev01.diff
        17 kB
        Matteo Scaramuccia
      3. statslib.php-rev02.diff
        18 kB
        Matteo Scaramuccia
      4. statslib.php-rev03.diff
        28 kB
        Juan Segarra Montesinos
      5. statslib.php-rev04.diff
        31 kB
        Juan Segarra Montesinos
      6. statslib.php-rev05.diff
        34 kB
        Juan Segarra Montesinos
      7. statslib.php-rev06.diff
        36 kB
        Juan Segarra Montesinos
      8. statslib.php-rev07.diff
        36 kB
        Juan Segarra Montesinos
      9. statslib.php-rev08.diff
        38 kB
        Juan Segarra Montesinos
      10. statslib.php-rev09.diff
        38 kB
        Tyler Bannister

        Issue Links

          Activity

          Hide
          Juan Segarra Montesinos added a comment -

          I've been working on this in our test servers and found serveral approaches that can be used in order to improve performance and table (or row) contention. We work with mysql 5.0.x and Innodb. Maybe this can help:

          1. Enrollments are calculated in nearly every query in daily stats. They can be precalculated (just one time) in an indexed-temporary table and then use this temporary table in queries.

          2. Logs table can be precalculated too. I'm using a temporary table of logs with this time restrictions. This reduces contention in mdl_log table and allows working with less data.

          3. The ORs in enrollments calculation can be decompossed in UNIONs. This performs better in mysql because of one-index per table restriction. Don't know postgress or oracle...

          Hope this tips help.

          Regards

          Show
          Juan Segarra Montesinos added a comment - I've been working on this in our test servers and found serveral approaches that can be used in order to improve performance and table (or row) contention. We work with mysql 5.0.x and Innodb. Maybe this can help: 1. Enrollments are calculated in nearly every query in daily stats. They can be precalculated (just one time) in an indexed-temporary table and then use this temporary table in queries. 2. Logs table can be precalculated too. I'm using a temporary table of logs with this time restrictions. This reduces contention in mdl_log table and allows working with less data. 3. The ORs in enrollments calculation can be decompossed in UNIONs. This performs better in mysql because of one-index per table restriction. Don't know postgress or oracle... Hope this tips help. Regards
          Hide
          Rosalyn Metz added a comment -

          Has there been any movement toward resolving this problem?

          Show
          Rosalyn Metz added a comment - Has there been any movement toward resolving this problem?
          Hide
          Wen Hao Chuang added a comment -

          ++1 on this too. Any forward momentum on this one? Thanks!

          Show
          Wen Hao Chuang added a comment - ++1 on this too. Any forward momentum on this one? Thanks!
          Hide
          Matt Clarkson added a comment -

          For reference, I have attached a patch to statslib that incorporates many of the ideas from this tracker item. On a large DB it dropped stats process times down to around 10 minutes from several hours.

          The patch is postgres specific, although it probably works in MySQL too.

          Show
          Matt Clarkson added a comment - For reference, I have attached a patch to statslib that incorporates many of the ideas from this tracker item. On a large DB it dropped stats process times down to around 10 minutes from several hours. The patch is postgres specific, although it probably works in MySQL too.
          Hide
          Susana Leitão added a comment -

          We are having the same issue...
          Did anyone try out Matt's patch with MySQL DB?

          Show
          Susana Leitão added a comment - We are having the same issue... Did anyone try out Matt's patch with MySQL DB?
          Hide
          Masaaki Niimura added a comment -

          We are having the same issue, too.

          We try out Matt's patch with MySQL 5.1.28.
          This patch works, but error occured.

          But, it will done in 1 minute.
          Thanks for Matt.

          — cron.php output —

          Running daily statistics gathering, starting at 1242140400:
          ......error occured, completed 0 days of statistics.

          Show
          Masaaki Niimura added a comment - We are having the same issue, too. We try out Matt's patch with MySQL 5.1.28. This patch works, but error occured. But, it will done in 1 minute. Thanks for Matt. — cron.php output — Running daily statistics gathering, starting at 1242140400: ......error occured, completed 0 days of statistics.
          Hide
          Heiko Schach added a comment -

          Just applied the patch and it works perfectly for our installation. We are currently running Moodle 1.9.7 on PostgreSQL.
          Before we had the problem of hanging database processes every once in a while. This was caused by the "UPDATE mdl_stats_daily" query hanging forever with postgres locked up at 100% CPU.
          We got rid of this problem by applying the patch. In addition the stats processing is now significantly faster.
          Thank you Matt for sharing this patch.

          Show
          Heiko Schach added a comment - Just applied the patch and it works perfectly for our installation. We are currently running Moodle 1.9.7 on PostgreSQL. Before we had the problem of hanging database processes every once in a while. This was caused by the "UPDATE mdl_stats_daily" query hanging forever with postgres locked up at 100% CPU. We got rid of this problem by applying the patch. In addition the stats processing is now significantly faster. Thank you Matt for sharing this patch.
          Hide
          Elan Hasson added a comment -

          I can confirm that this is also occurring in Moodle 1.9.6+ (Build: 20091104).
          We are on MySQL 5.0.44.

          The query causing the blocking was:

          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 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 >= 1258351200 AND l.time < 1258437600))
          WHERE mdl_stats_daily.stattype = 'enrolments' AND
          mdl_stats_daily.timeend = 1258437600 AND
          mdl_stats_daily.roleid = 0 AND
          mdl_stats_daily.courseid IN
          (SELECT l.course
          FROM mdl_log l
          WHERE l.time >= 1258351200 AND l.time < 1258437600 AND l.course <> 1)

          Output from Queries requested by others in this thread:

          select * from mdl_config where name like '%stats%';
          id, name, value
          2, 'statsrolesupgraded', '1250715358'
          146, 'enablestats', '1'
          147, 'statsfirstrun', 'none'
          148, 'statsmaxruntime', '0'
          149, 'statsruntimestarthour', '0'
          150, 'statsruntimestartminute', '0'
          151, 'statsuserthreshold', '0'
          152, 'statscatdepth', '1'
          381, 'statsruntimedays', '31'
          418, 'coursereport_stats_version', '2007101501'
          430, 'statslastdaily', '1258351200'
          431, 'statslastexecution', '1266386431'
          432, 'statsrunning', '1266472831'

          Show
          Elan Hasson added a comment - I can confirm that this is also occurring in Moodle 1.9.6+ (Build: 20091104). We are on MySQL 5.0.44. The query causing the blocking was: 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 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 >= 1258351200 AND l.time < 1258437600)) WHERE mdl_stats_daily.stattype = 'enrolments' AND mdl_stats_daily.timeend = 1258437600 AND mdl_stats_daily.roleid = 0 AND mdl_stats_daily.courseid IN (SELECT l.course FROM mdl_log l WHERE l.time >= 1258351200 AND l.time < 1258437600 AND l.course <> 1) Output from Queries requested by others in this thread: select * from mdl_config where name like '%stats%'; id, name, value 2, 'statsrolesupgraded', '1250715358' 146, 'enablestats', '1' 147, 'statsfirstrun', 'none' 148, 'statsmaxruntime', '0' 149, 'statsruntimestarthour', '0' 150, 'statsruntimestartminute', '0' 151, 'statsuserthreshold', '0' 152, 'statscatdepth', '1' 381, 'statsruntimedays', '31' 418, 'coursereport_stats_version', '2007101501' 430, 'statslastdaily', '1258351200' 431, 'statslastexecution', '1266386431' 432, 'statsrunning', '1266472831'
          Hide
          Tony Butler added a comment -

          Thanks for the patch Matt. I've tested it with MySQL in a couple of different dev/test environments, and it gives the same error each time:

          Running daily statistics gathering, starting at 1283904000:
          1:103 2:0 3:24 <div class="notifytiny" style="text-align:center">Can't reopen table: 'l'<br /><br />UPDATE mdl_stats_daily
          SET stat2 = (SELECT COUNT(DISTINCT e.userid)
          FROM mdl_tmp_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 AND e.roleid = mdl_stats_daily.roleid
          )
          WHERE mdl_stats_daily.stattype = 'enrolments' AND
          mdl_stats_daily.timeend = 1283990400 AND
          mdl_stats_daily.courseid IN
          (SELECT DISTINCT course
          FROM mdl_tmp_stats_logs)<ul style="text-align: left"><li>line 103 of lib/dmllib.php: call to debugging()</li><li>line 274 of lib/statslib.php: call to execute_sql()</li><li>line 542 of admin/cron.php: call to stats_cron_daily()</li></ul></div>
          ...error occured, completed 0 days of statistics.

          Any advice on how to make it work in MySQL?

          Cheers,
          Tony

          Show
          Tony Butler added a comment - Thanks for the patch Matt. I've tested it with MySQL in a couple of different dev/test environments, and it gives the same error each time: Running daily statistics gathering, starting at 1283904000: 1:103 2:0 3:24 <div class="notifytiny" style="text-align:center">Can't reopen table: 'l'<br /><br />UPDATE mdl_stats_daily SET stat2 = (SELECT COUNT(DISTINCT e.userid) FROM mdl_tmp_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 AND e.roleid = mdl_stats_daily.roleid ) WHERE mdl_stats_daily.stattype = 'enrolments' AND mdl_stats_daily.timeend = 1283990400 AND mdl_stats_daily.courseid IN (SELECT DISTINCT course FROM mdl_tmp_stats_logs)<ul style="text-align: left"><li>line 103 of lib/dmllib.php: call to debugging()</li><li>line 274 of lib/statslib.php: call to execute_sql()</li><li>line 542 of admin/cron.php: call to stats_cron_daily()</li></ul></div> ...error occured, completed 0 days of statistics. Any advice on how to make it work in MySQL? Cheers, Tony
          Hide
          Matteo Scaramuccia added a comment -

          Hi Tony,
          have you tried to remove the string "TEMPORARY " from Matt's patch?
          Since these 2 new temp tables, tmp_stats_*s, will be explicitly DROPped at the end of the process, TEMPORARY is not required and this could fix your Can't reopen table: 'l' error in MySQL. The same should apply to PostgreSQL too: in both systems, at the very end, a TEMPORARY table is used to strictly definy the life cycle of the table itself just within the user connection session i.e. assuming an automatic DROP statement, here explicitly coded.

          Let me know since I'm interested too (+1)
          Matteo

          Show
          Matteo Scaramuccia added a comment - Hi Tony, have you tried to remove the string "TEMPORARY " from Matt's patch? Since these 2 new temp tables, tmp_stats_*s , will be explicitly DROPped at the end of the process, TEMPORARY is not required and this could fix your Can't reopen table: 'l' error in MySQL. The same should apply to PostgreSQL too: in both systems, at the very end, a TEMPORARY table is used to strictly definy the life cycle of the table itself just within the user connection session i.e. assuming an automatic DROP statement, here explicitly coded. Let me know since I'm interested too (+1) Matteo
          Hide
          Matteo Scaramuccia added a comment -

          This is a first review of the original proposed patch, commit-5b5a23f.
          Differences are:

          • Removed TEMPORARY to avoid errors w/ MySQL
          • [Minor] Added time elapsed for weekly and monthly, to keep tracking of the time spent on these tasks
          • [Trivial] Added {dayly, weekly, monthly} stats type in "finished until" statement for the sake of easy reading
          • [Trivial] Fixed indentation
          Show
          Matteo Scaramuccia added a comment - This is a first review of the original proposed patch, commit-5b5a23f . Differences are: Removed TEMPORARY to avoid errors w/ MySQL [Minor] Added time elapsed for weekly and monthly , to keep tracking of the time spent on these tasks [Trivial] Added { dayly , weekly , monthly } stats type in "finished until" statement for the sake of easy reading [Trivial] Fixed indentation
          Hide
          Matteo Scaramuccia added a comment -

          Find below the time benefits of the first run of the reviewed patch proposal (commit-5b5a23f => statslib.php-rev01.diff) in MySQL on a medium sized Moodle site: besides locking is no more an issue.

          Before:

          cron_output-20101101T000301.log:................  finished until 1288566000: lunedì, 1 novembre 2010, 00:00 (in 4050 s)
          cron_output-20101102T000301.log:................  finished until 1288652400: martedì, 2 novembre 2010, 00:00 (in 3905 s)
          cron_output-20101103T000301.log:................  finished until 1288738800: mercoledì, 3 novembre 2010, 00:00 (in 4794 s)
          cron_output-20101104T000301.log:................  finished until 1288825200: giovedì, 4 novembre 2010, 00:00 (in 5040 s)
          cron_output-20101105T000301.log:................  finished until 1288911600: venerdì, 5 novembre 2010, 00:00 (in 8839 s)
          cron_output-20101106T000301.log:................  finished until 1288998000: sabato, 6 novembre 2010, 00:00 (in 8891 s)
          cron_output-20101107T000301.log:................  finished until 1289084400: domenica, 7 novembre 2010, 00:00 (in 9031 s)
          cron_output-20101108T000301.log:................  finished until 1289170800: lunedì, 8 novembre 2010, 00:00 (in 8582 s)
          

          After:

          cron_output-20101109T000301.log: finished until 1289257200: martedì, 9 novembre 2010, 00:00 (in 1591 s)
          

          Note: dots missing here since I'm using $CFG->showcronsql = true; to track queries.

          Show
          Matteo Scaramuccia added a comment - Find below the time benefits of the first run of the reviewed patch proposal ( commit-5b5a23f => statslib.php-rev01.diff ) in MySQL on a medium sized Moodle site: besides locking is no more an issue. Before: cron_output-20101101T000301.log:................ finished until 1288566000: lunedì, 1 novembre 2010, 00:00 (in 4050 s) cron_output-20101102T000301.log:................ finished until 1288652400: martedì, 2 novembre 2010, 00:00 (in 3905 s) cron_output-20101103T000301.log:................ finished until 1288738800: mercoledì, 3 novembre 2010, 00:00 (in 4794 s) cron_output-20101104T000301.log:................ finished until 1288825200: giovedì, 4 novembre 2010, 00:00 (in 5040 s) cron_output-20101105T000301.log:................ finished until 1288911600: venerdì, 5 novembre 2010, 00:00 (in 8839 s) cron_output-20101106T000301.log:................ finished until 1288998000: sabato, 6 novembre 2010, 00:00 (in 8891 s) cron_output-20101107T000301.log:................ finished until 1289084400: domenica, 7 novembre 2010, 00:00 (in 9031 s) cron_output-20101108T000301.log:................ finished until 1289170800: lunedì, 8 novembre 2010, 00:00 (in 8582 s) After: cron_output-20101109T000301.log: finished until 1289257200: martedì, 9 novembre 2010, 00:00 (in 1591 s) Note: dots missing here since I'm using $CFG->showcronsql = true; to track queries.
          Hide
          Matteo Scaramuccia added a comment -

          Added statslib.php-rev02.diff, small review of statslib.php-rev01.diff to cleanup not used vars & phpdoc and to better track DROP failures. I will start keep tracking of performances to see the time gain and possible other locking issues, the 1st result being already reported.
          I expect some similar issues in the weekly process, being weekly simplier but acting on the same tables causing locking issues (monthly is equal to weekly except for table names and time range).

          Show
          Matteo Scaramuccia added a comment - Added statslib.php-rev02.diff , small review of statslib.php-rev01.diff to cleanup not used vars & phpdoc and to better track DROP failures. I will start keep tracking of performances to see the time gain and possible other locking issues, the 1st result being already reported. I expect some similar issues in the weekly process, being weekly simplier but acting on the same tables causing locking issues ( monthly is equal to weekly except for table names and time range).
          Hide
          Matteo Scaramuccia added a comment -

          MySQL slow queries w/ statslib.php-rev02.diff is:

          # Time: 101110  0:14:36
          # User@Host: <moodleuser>[<moodleuser>] @ <moodlehost> [<moodleipaddress>]
          # Query_time: 692  Lock_time: 0  Rows_sent: 0  Rows_examined: 2100148
          use <moodle19db>;
          CREATE TABLE mdl_tmp_stats_enrolments AS
          ### stats_create_enrolled_table() ###
          ...
          # Time: 101110  0:15:04
          # User@Host: <moodleuser>[<moodleuser>] @ <moodlehost> [<moodleipaddress>]
          # Query_time: 25  Lock_time: 0  Rows_sent: 0  Rows_examined: 16753728
          SET insert_id=1381637;
          INSERT INTO mdl_stats_user_daily (stattype, timeend, courseid, userid, statsreads, statswrites)
          ### 10th query ###
          ...
          # Time: 101110  0:28:57
          # User@Host: <moodleuser>[<moodleuser>] @ <moodlehost> [<moodleipaddress>]
          # Query_time: 832  Lock_time: 0  Rows_sent: 0  Rows_examined: 14121095
          use <moodle19db>;
          SET insert_id=6695347;
          INSERT INTO mdl_stats_daily (stattype, timeend, courseid, roleid, stat1, stat2)
          ### 12th query ###
          ...
          # Time: 101110  0:29:16
          # User@Host: <moodleuser>[<moodleuser>] @ <moodlehost> [<moodleipaddress>]
          # Query_time: 19  Lock_time: 0  Rows_sent: 0  Rows_examined: 2063623
          SET insert_id=6696487;
          INSERT INTO mdl_stats_daily (stattype, timeend, courseid, roleid, stat1, stat2)
          ### 13th query ###
          ...
          

          Time spent here is 1568 while the overall time of the run is 1575:

          cron_output-20101110T000301.log: finished daily until 1289343600: mercoledì,  10 novembre 2010, 00:00 (in 1575 s)
          
          Show
          Matteo Scaramuccia added a comment - MySQL slow queries w/ statslib.php-rev02.diff is: # Time: 101110 0:14:36 # User@Host: <moodleuser>[<moodleuser>] @ <moodlehost> [<moodleipaddress>] # Query_time: 692 Lock_time: 0 Rows_sent: 0 Rows_examined: 2100148 use <moodle19db>; CREATE TABLE mdl_tmp_stats_enrolments AS ### stats_create_enrolled_table() ### ... # Time: 101110 0:15:04 # User@Host: <moodleuser>[<moodleuser>] @ <moodlehost> [<moodleipaddress>] # Query_time: 25 Lock_time: 0 Rows_sent: 0 Rows_examined: 16753728 SET insert_id=1381637; INSERT INTO mdl_stats_user_daily (stattype, timeend, courseid, userid, statsreads, statswrites) ### 10th query ### ... # Time: 101110 0:28:57 # User@Host: <moodleuser>[<moodleuser>] @ <moodlehost> [<moodleipaddress>] # Query_time: 832 Lock_time: 0 Rows_sent: 0 Rows_examined: 14121095 use <moodle19db>; SET insert_id=6695347; INSERT INTO mdl_stats_daily (stattype, timeend, courseid, roleid, stat1, stat2) ### 12th query ### ... # Time: 101110 0:29:16 # User@Host: <moodleuser>[<moodleuser>] @ <moodlehost> [<moodleipaddress>] # Query_time: 19 Lock_time: 0 Rows_sent: 0 Rows_examined: 2063623 SET insert_id=6696487; INSERT INTO mdl_stats_daily (stattype, timeend, courseid, roleid, stat1, stat2) ### 13th query ### ... Time spent here is 1568 while the overall time of the run is 1575 : cron_output-20101110T000301.log: finished daily until 1289343600: mercoledì, 10 novembre 2010, 00:00 (in 1575 s)
          Hide
          Matteo Scaramuccia added a comment -

          Find below the result of a 1 week screening: numbers are stable, locking has gone, optimization should be done as already described in http://tracker.moodle.org/browse/MDL-18484#comment_97426_header_matteo.

          cron_output-20101109T000301.log: finished until 1289257200: martedì, 9 novembre 2010, 00:00 (in 1591 s)
          cron_output-20101110T000301.log: finished daily until 1289343600: mercoledì,  10 novembre 2010, 00:00 (in 1575 s)
          cron_output-20101111T000301.log: finished daily until 1289430000: giovedì,  11 novembre 2010, 00:00 (in 1574 s)
          cron_output-20101112T000301.log: finished daily until 1289516400: venerdì, 12 novembre 2010, 00:00 (in 1575 s)
          cron_output-20101113T000301.log: finished daily until 1289602800: sabato, 13 novembre 2010, 00:00 (in 1570 s)
          cron_output-20101114T000302.log: finished daily until 1289689200: domenica, 14 novembre 2010, 00:00 (in 1565 s)
          cron_output-20101114T000302.log: finished weekly until 1289689200: domenica, 14 novembre 2010, 00:00 (in 1 s)
          
          Show
          Matteo Scaramuccia added a comment - Find below the result of a 1 week screening: numbers are stable, locking has gone, optimization should be done as already described in http://tracker.moodle.org/browse/MDL-18484#comment_97426_header_matteo . cron_output-20101109T000301.log: finished until 1289257200: martedì, 9 novembre 2010, 00:00 (in 1591 s) cron_output-20101110T000301.log: finished daily until 1289343600: mercoledì, 10 novembre 2010, 00:00 (in 1575 s) cron_output-20101111T000301.log: finished daily until 1289430000: giovedì, 11 novembre 2010, 00:00 (in 1574 s) cron_output-20101112T000301.log: finished daily until 1289516400: venerdì, 12 novembre 2010, 00:00 (in 1575 s) cron_output-20101113T000301.log: finished daily until 1289602800: sabato, 13 novembre 2010, 00:00 (in 1570 s) cron_output-20101114T000302.log: finished daily until 1289689200: domenica, 14 novembre 2010, 00:00 (in 1565 s) cron_output-20101114T000302.log: finished weekly until 1289689200: domenica, 14 novembre 2010, 00:00 (in 1 s)
          Hide
          Tony Butler added a comment -

          Hi Matteo,

          This is looking very good. I've run a week's worth of stats on a test server, both before and after applying the patch, on the same set of data, just to satisfy myself that the actual statistics generated will be the same (and I can confirm that they are).

          I've now applied the patched statslib.php to our live server and ran the first real set of stats last night. It took 32 minutes, as opposed to the usual hour+, so I'm very optimistic.

          I'll report back with the results when I've got about a week's worth to show you.

          Cheers,
          Tony

          Show
          Tony Butler added a comment - Hi Matteo, This is looking very good. I've run a week's worth of stats on a test server, both before and after applying the patch, on the same set of data, just to satisfy myself that the actual statistics generated will be the same (and I can confirm that they are). I've now applied the patched statslib.php to our live server and ran the first real set of stats last night. It took 32 minutes, as opposed to the usual hour+, so I'm very optimistic. I'll report back with the results when I've got about a week's worth to show you. Cheers, Tony
          Hide
          Matteo Scaramuccia added a comment -

          Hi All,
          the unresolved issues related w/ query #10 and #12 keep on giving some serious problems, see e.g. numbers ( 3631615089!!! ) at the end of a week:

          # Time: 101121  0:41:55
          # User@Host: <moodleuser>[<moodleuser>] @ <moodlehost> [<moodleipaddress>]
          # Query_time: 2332  Lock_time: 0  Rows_sent: 0  Rows_examined: 3631615089
          use <moodle19db>;
          CREATE TABLE mdl_tmp_stats_enrolments AS
          
                         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 (ctx.contextlevel = 10
                              OR (c.id = ctx.instanceid AND ctx.contextlevel = 50) OR (cc1.id = ctx.instanceid AND ctx.contextlevel = 40)));
          

          Maybe an approach like the one suggested by Juan could be winning: has someone already reviewed statslib.php-rev02.diff, adding new stuff?

          Show
          Matteo Scaramuccia added a comment - Hi All, the unresolved issues related w/ query #10 and #12 keep on giving some serious problems, see e.g. numbers ( 3631615089 !!! ) at the end of a week: # Time: 101121 0:41:55 # User@Host: <moodleuser>[<moodleuser>] @ <moodlehost> [<moodleipaddress>] # Query_time: 2332 Lock_time: 0 Rows_sent: 0 Rows_examined: 3631615089 use <moodle19db>; CREATE TABLE mdl_tmp_stats_enrolments AS 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 (ctx.contextlevel = 10 OR (c.id = ctx.instanceid AND ctx.contextlevel = 50) OR (cc1.id = ctx.instanceid AND ctx.contextlevel = 40))); Maybe an approach like the one suggested by Juan could be winning: has someone already reviewed statslib.php-rev02.diff , adding new stuff?
          Hide
          Tony Butler added a comment -

          It's now a week since I applied statslib.php-rev02.diff to our production server, so here are the results so far.

          Before applying patch:

          ................  finished until 1289260800: Tuesday, 9 November 2010, 12:00 AM (in 6305 s)
          ................  finished until 1289347200: Wednesday,  10 November 2010, 12:00 AM (in 4912 s)
          ................  finished until 1289433600: Thursday,  11 November 2010, 12:00 AM (in 5757 s)
          ................  finished until 1289520000: Friday,  12 November 2010, 12:00 AM (in 4911 s)
          ................  finished until 1289606400: Saturday,  13 November 2010, 12:00 AM (in 4427 s)
          ................  finished until 1289692800: Sunday,  14 November 2010, 12:00 AM (in 3415 s)
          ................  finished until 1289779200: Monday,  15 November 2010, 12:00 AM (in 3653 s)
          

          After applying patch:

          ................ finished daily until 1289865600: Tuesday,  16 November 2010, 12:00 AM (in 1924 s)
          ................ finished daily until 1289952000: Wednesday,  17 November 2010, 12:00 AM (in 1912 s)
          ................ finished daily until 1290038400: Thursday,  18 November 2010, 12:00 AM (in 2071 s)
          ................ finished daily until 1290124800: Friday,  19 November 2010, 12:00 AM (in 1699 s)
          ................ finished daily until 1290211200: Saturday,  20 November 2010, 12:00 AM (in 1520 s)
          ................ finished daily until 1290297600: Sunday,  21 November 2010, 12:00 AM (in 1497 s)
          ................ finished daily until 1290384000: Monday,  22 November 2010, 12:00 AM (in 1414 s)
          

          That's an average execution time of ~1720 seconds per night, as opposed to ~4769 seconds before applying the patch, which I reckon is a pretty impressive improvement.

          Locking is still an issue though. Nagios reports the site as being unresponsive for about 10 minutes now, whereas before applying the patch it was about 30 minutes per night.

          Tony

          Show
          Tony Butler added a comment - It's now a week since I applied statslib.php-rev02.diff to our production server, so here are the results so far. Before applying patch: ................ finished until 1289260800: Tuesday, 9 November 2010, 12:00 AM (in 6305 s) ................ finished until 1289347200: Wednesday, 10 November 2010, 12:00 AM (in 4912 s) ................ finished until 1289433600: Thursday, 11 November 2010, 12:00 AM (in 5757 s) ................ finished until 1289520000: Friday, 12 November 2010, 12:00 AM (in 4911 s) ................ finished until 1289606400: Saturday, 13 November 2010, 12:00 AM (in 4427 s) ................ finished until 1289692800: Sunday, 14 November 2010, 12:00 AM (in 3415 s) ................ finished until 1289779200: Monday, 15 November 2010, 12:00 AM (in 3653 s) After applying patch: ................ finished daily until 1289865600: Tuesday, 16 November 2010, 12:00 AM (in 1924 s) ................ finished daily until 1289952000: Wednesday, 17 November 2010, 12:00 AM (in 1912 s) ................ finished daily until 1290038400: Thursday, 18 November 2010, 12:00 AM (in 2071 s) ................ finished daily until 1290124800: Friday, 19 November 2010, 12:00 AM (in 1699 s) ................ finished daily until 1290211200: Saturday, 20 November 2010, 12:00 AM (in 1520 s) ................ finished daily until 1290297600: Sunday, 21 November 2010, 12:00 AM (in 1497 s) ................ finished daily until 1290384000: Monday, 22 November 2010, 12:00 AM (in 1414 s) That's an average execution time of ~1720 seconds per night, as opposed to ~4769 seconds before applying the patch, which I reckon is a pretty impressive improvement. Locking is still an issue though. Nagios reports the site as being unresponsive for about 10 minutes now, whereas before applying the patch it was about 30 minutes per night. Tony
          Hide
          Juan Segarra Montesinos added a comment -

          Hi Matteo,

          Sorry but I'm not really involved with this... if I just have time... I'll try to help.

          Please, rewrite the query as in [1] and test (run it from mysql cilent, for instance. Do a RESET QUERY CACHE before). Please note that the query may contain repeated rows. I don't know if this can cause some problems in code... please review that Maybe not or maybe we can circumvent it from PHP.

          [1]

          CREATE TABLE mdl_tmp_stats_enrolments AS
          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 ctx.contextlevel = 10)

          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 c.id = ctx.instanceid AND ctx.contextlevel = 50)

          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);

          Show
          Juan Segarra Montesinos added a comment - Hi Matteo, Sorry but I'm not really involved with this... if I just have time... I'll try to help. Please, rewrite the query as in [1] and test (run it from mysql cilent, for instance. Do a RESET QUERY CACHE before). Please note that the query may contain repeated rows. I don't know if this can cause some problems in code... please review that Maybe not or maybe we can circumvent it from PHP. [1] CREATE TABLE mdl_tmp_stats_enrolments AS 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 ctx.contextlevel = 10) 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 c.id = ctx.instanceid AND ctx.contextlevel = 50) 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);
          Hide
          Juan Segarra Montesinos added a comment -

          Mmmm... forget about the repeated rows... it won't contain any

          Show
          Juan Segarra Montesinos added a comment - Mmmm... forget about the repeated rows... it won't contain any
          Hide
          Andrea Gregory (Gordon) added a comment -

          Hi Juan,

          I've been following this as we have been having the same issue across a few sites. Is it possible to add your latest update into another attached diff file?

          Thanks,

          Andrea

          Show
          Andrea Gregory (Gordon) added a comment - Hi Juan, I've been following this as we have been having the same issue across a few sites. Is it possible to add your latest update into another attached diff file? Thanks, Andrea
          Hide
          Martin Dougiamas added a comment -

          Is anyone working on a 2.0 patch?

          Show
          Martin Dougiamas added a comment - Is anyone working on a 2.0 patch?
          Hide
          Matteo Scaramuccia added a comment -

          Matteo => no

          Show
          Matteo Scaramuccia added a comment - Matteo => no
          Hide
          Juan Segarra Montesinos added a comment -

          I'm not working on this... and I don't have a patch... but I think that following this guidelines, code can run faster and reduce contention. I'll try to work on this and help...

          Show
          Juan Segarra Montesinos added a comment - I'm not working on this... and I don't have a patch... but I think that following this guidelines, code can run faster and reduce contention. I'll try to work on this and help...
          Hide
          Andrea Gregory (Gordon) added a comment -

          That's great Juan because we still do not have this resolved. We have gone through all patches and guidelines here. The only part we were stuck on was the last comment by yourself. If that could be a patch, that would be amazing thanks - Andrea

          Show
          Andrea Gregory (Gordon) added a comment - That's great Juan because we still do not have this resolved. We have gone through all patches and guidelines here. The only part we were stuck on was the last comment by yourself. If that could be a patch, that would be amazing thanks - Andrea
          Hide
          Juan Segarra Montesinos added a comment -

          Hi all... I'm about to finish a new patch. Not heavily reviewed... so I'll need some feedback... stay tunned

          Show
          Juan Segarra Montesinos added a comment - Hi all... I'm about to finish a new patch. Not heavily reviewed... so I'll need some feedback... stay tunned
          Hide
          Juan Segarra Montesinos added a comment -

          This is a preliminary patch to test. It just adresses daily statistics gathering problem... once we get it validated I'll start with weekly and monthly.

          Please, if you fell comfortable with SQL, please help to ensure equivalence with the new and old queries and the new enrollment pre-calculated tables.

          The patch probably wont work for now in postgrees, but it can be easily adapted.

          Thanks

          Show
          Juan Segarra Montesinos added a comment - This is a preliminary patch to test. It just adresses daily statistics gathering problem... once we get it validated I'll start with weekly and monthly. Please, if you fell comfortable with SQL, please help to ensure equivalence with the new and old queries and the new enrollment pre-calculated tables. The patch probably wont work for now in postgrees, but it can be easily adapted. Thanks
          Hide
          Juan Segarra Montesinos added a comment -

          Patch statslib.php-rev03.diff runs on 1.9 branch

          Show
          Juan Segarra Montesinos added a comment - Patch statslib.php-rev03.diff runs on 1.9 branch
          Hide
          Juan Segarra Montesinos added a comment -

          Hi again. I'm trying to manage the whole thing with git:

          https://github.com/anariel/moodle/tree/MDL-18484

          bye!

          Show
          Juan Segarra Montesinos added a comment - Hi again. I'm trying to manage the whole thing with git: https://github.com/anariel/moodle/tree/MDL-18484 bye!
          Hide
          Juan Segarra Montesinos added a comment -

          Added statslib.php-rev04.diff

          This patch adds the following:

          . solves a critical problem in rev03 patch
          . creates temporary tables using XMLDB
          . runs faster than rev03

          Please... anyone interested in testing?

          bye

          Show
          Juan Segarra Montesinos added a comment - Added statslib.php-rev04.diff This patch adds the following: . solves a critical problem in rev03 patch . creates temporary tables using XMLDB . runs faster than rev03 Please... anyone interested in testing? bye
          Hide
          Juan Segarra Montesinos added a comment -

          Added statslib.php-rev05.diff

          Fixes some bugs in previous patch.

          Need a little more testing

          Show
          Juan Segarra Montesinos added a comment - Added statslib.php-rev05.diff Fixes some bugs in previous patch. Need a little more testing
          Hide
          Juan Segarra Montesinos added a comment -

          Added statslib.php-rev06.php

          This fixes some bugs.

          I have validated the results against the original statslib.php version on a server with more than 1 million actions per moth.

          It runs really quickly. More or less 50 seconds per day.

          Please give it a try.

          Not tested on servers other than mysql. Runs on moodle 1.9.x

          This just optimizes daily statistics. I'll do some code cleanup.

          Regards

          Show
          Juan Segarra Montesinos added a comment - Added statslib.php-rev06.php This fixes some bugs. I have validated the results against the original statslib.php version on a server with more than 1 million actions per moth. It runs really quickly. More or less 50 seconds per day. Please give it a try. Not tested on servers other than mysql. Runs on moodle 1.9.x This just optimizes daily statistics. I'll do some code cleanup. Regards
          Hide
          Juan Segarra Montesinos added a comment -

          Uploaded statslib.php-rev07.diff

          Fixed a typo in enrollments calculation.

          Show
          Juan Segarra Montesinos added a comment - Uploaded statslib.php-rev07.diff Fixed a typo in enrollments calculation.
          Hide
          Tony Butler added a comment -

          Thanks Juan, I'll definitely give this a try. I've got a few things on the go right now but I'll hopefully have time to test it before the end of the week.

          Tony

          Show
          Tony Butler added a comment - Thanks Juan, I'll definitely give this a try. I've got a few things on the go right now but I'll hopefully have time to test it before the end of the week. Tony
          Hide
          Juan Segarra Montesinos added a comment -

          Thanks Tony I need help with data validation... ie, if we get exactly the same results as with the original library.

          Regards

          Show
          Juan Segarra Montesinos added a comment - Thanks Tony I need help with data validation... ie, if we get exactly the same results as with the original library. Regards
          Hide
          Juan Segarra Montesinos added a comment -

          (sorry for the spam)

          Uploaded statslib.php-rev08.diff

          Just code cleanup.

          Regards

          Show
          Juan Segarra Montesinos added a comment - (sorry for the spam) Uploaded statslib.php-rev08.diff Just code cleanup. Regards
          Hide
          Tony Butler added a comment -

          Hi Juan,

          I've re-run last week's stats on a test server, with the following results (original results in brackets):

          Period ending Guest Student Support Tutor Lecturer Administrator All
          9 April 2011 139(139) 3546(3546) 87(87) 1105(1105) 653(653) 5572(5572)
          8 April 2011 133(133) 4370(4371) 114(114) 1244(1244) 113(113) 5935(5935)
          7 April 2011 147(147) 5680(5684) 326(326) 1937(1937) 124(124) 8313(8313)
          6 April 2011 161(161) 4984(4984) 255(283) 1946(1918) 102(102) 7506(7506)
          5 April 2011 130(114) 6299(6315) 163(163) 2251(2251) 228(228) 9139(9139)

          As you can hopefully see (if the table formatting worked), most of the results are identical with just a few slight differences. But couldn't these small discrepancies have been caused by the fact that the stats were re-run at a later time, when some of the enrolments are bound to have changed?

          By the way: wow, is it fast! It averaged about 35 seconds per day, even on a puny test VM. Nice work!

          Show
          Tony Butler added a comment - Hi Juan, I've re-run last week's stats on a test server, with the following results (original results in brackets): Period ending Guest Student Support Tutor Lecturer Administrator All 9 April 2011 139(139) 3546(3546) 87(87) 1105(1105) 653(653) 5572(5572) 8 April 2011 133(133) 4370(4371) 114(114) 1244(1244) 113(113) 5935(5935) 7 April 2011 147(147) 5680(5684) 326(326) 1937(1937) 124(124) 8313(8313) 6 April 2011 161(161) 4984(4984) 255(283) 1946(1918) 102(102) 7506(7506) 5 April 2011 130(114) 6299(6315) 163(163) 2251(2251) 228(228) 9139(9139) As you can hopefully see (if the table formatting worked), most of the results are identical with just a few slight differences. But couldn't these small discrepancies have been caused by the fact that the stats were re-run at a later time, when some of the enrolments are bound to have changed? By the way: wow, is it fast! It averaged about 35 seconds per day, even on a puny test VM. Nice work!
          Hide
          Juan Segarra Montesinos added a comment -

          Thanks Tony

          Changes in roles may be the cause for the different numbers. The best way to test may be the following:

          0. Use a copy of your database not in production. We are going to compare with the same resultset.
          1. Calculate the stats with the original library
          2. Copy the tables mdl_stats_daily and mdl_stats_user_daily. Just like this:

          CREATE TABLE mdl_stats_daily_original LIKE
          SELECT * FROM mdl_stats_daily;

          CREATE TABLE mdl_stats_user_daily_original LIKE
          SELECT * FROM mdl_stats_user_daily;

          3. Now delete the rows just inserted in mdl_stats_daily and mdl_stats_user_daily.
          4. Run the stats over the same period with the new statslib.php and with the same original data.

          Now we can compare rows in both tables like this (sorry but :

          SELECT COUNT
          FROM mdl_stats_daily s1
          WHERE timeend > "put here a reasonable timestamp " AND
          EXISTS (
          SELECT 1
          FROM mdl_stats_daily_original s2
          WHERE s1.timeend = s2.timeend AND
          s1.userid = s2.userid AND
          s1.courseid = s2.courseid AND
          s1.roleid = s2.roleid AND
          s1.stattype = s2.stattype AND
          ( s1.stat1 <> s2.stat1 OR
          s1.stat2 <> s2.stat2 )
          );

          This COUNT should be 0

          And this one too:

          SELECT COUNT
          FROM mdl_stats_user_daily s1
          WHERE timeend > "put here a reasonable timestamp " AND
          EXISTS (
          SELECT 1
          FROM mdl_stats_user_daily_original s2
          WHERE s1.timeend = s2.timeend AND
          s1.userid = s2.userid AND
          s1.courseid = s2.courseid AND
          s1.roleid = s2.roleid AND
          s1.stattype = s2.stattype AND
          ( s1.statsreads <> s2.statsread OR
          s1.statswrites <> s2.statswrites )
          );

          I've written this queries without testing them... so be careful. If I have time I'll do an easy script to automate this tests and others.

          Thank you again for your time

          Show
          Juan Segarra Montesinos added a comment - Thanks Tony Changes in roles may be the cause for the different numbers. The best way to test may be the following: 0. Use a copy of your database not in production. We are going to compare with the same resultset. 1. Calculate the stats with the original library 2. Copy the tables mdl_stats_daily and mdl_stats_user_daily. Just like this: CREATE TABLE mdl_stats_daily_original LIKE SELECT * FROM mdl_stats_daily; CREATE TABLE mdl_stats_user_daily_original LIKE SELECT * FROM mdl_stats_user_daily; 3. Now delete the rows just inserted in mdl_stats_daily and mdl_stats_user_daily. 4. Run the stats over the same period with the new statslib.php and with the same original data. Now we can compare rows in both tables like this (sorry but : SELECT COUNT FROM mdl_stats_daily s1 WHERE timeend > "put here a reasonable timestamp " AND EXISTS ( SELECT 1 FROM mdl_stats_daily_original s2 WHERE s1.timeend = s2.timeend AND s1.userid = s2.userid AND s1.courseid = s2.courseid AND s1.roleid = s2.roleid AND s1.stattype = s2.stattype AND ( s1.stat1 <> s2.stat1 OR s1.stat2 <> s2.stat2 ) ); This COUNT should be 0 And this one too: SELECT COUNT FROM mdl_stats_user_daily s1 WHERE timeend > "put here a reasonable timestamp " AND EXISTS ( SELECT 1 FROM mdl_stats_user_daily_original s2 WHERE s1.timeend = s2.timeend AND s1.userid = s2.userid AND s1.courseid = s2.courseid AND s1.roleid = s2.roleid AND s1.stattype = s2.stattype AND ( s1.statsreads <> s2.statsread OR s1.statswrites <> s2.statswrites ) ); I've written this queries without testing them... so be careful. If I have time I'll do an easy script to automate this tests and others. Thank you again for your time
          Hide
          Tony Butler added a comment -

          No problem. I was hoping to get away with not re-running the stats with the original library on my test VM because of the amount of time it would take, but it looks like it's going to be the only way to get accurate results.

          I left it going overnight and so far it's managed to process 1 day with the original library - in 56995 seconds! That's even worse than I expected. So I guess we can expect the final results by about the middle of next week.

          Show
          Tony Butler added a comment - No problem. I was hoping to get away with not re-running the stats with the original library on my test VM because of the amount of time it would take, but it looks like it's going to be the only way to get accurate results. I left it going overnight and so far it's managed to process 1 day with the original library - in 56995 seconds! That's even worse than I expected. So I guess we can expect the final results by about the middle of next week.
          Hide
          Juan Segarra Montesinos added a comment -

          Hi again. I've validated again in the way similar to that described before. I get exactly the same results with the original library and the new one. So the patch is ok.

          Someone is able to test with postgress and others?

          I'll port this to 2.x

          Regards

          Show
          Juan Segarra Montesinos added a comment - Hi again. I've validated again in the way similar to that described before. I get exactly the same results with the original library and the new one. So the patch is ok. Someone is able to test with postgress and others? I'll port this to 2.x Regards
          Hide
          Tony Butler added a comment -

          Hi Juan,

          Sorry about the delay with my results. By the time the re-run with the original library had completed (it took about a week!) I was out of the office on a week's leave. Since I got back I've been trying to compare the 2 sets of results using the method you described above (exact query used below):

          SELECT COUNT
          FROM mdl_stats_daily s1
          WHERE timeend > "1301616000" AND
          EXISTS (
          SELECT 1
          FROM mdl_stats_daily_original s2
          WHERE s1.timeend = s2.timeend AND
          s1.courseid = s2.courseid AND
          s1.roleid = s2.roleid AND
          s1.stattype = s2.stattype AND
          ( s1.stat1 <> s2.stat1 OR
          s1.stat2 <> s2.stat2 )
          );

          This one query has now been running for 517695 seconds (almost 6 days!) and still hasn't finished!

          However, I have also done a visual comparison of the statistics report for the week in question, and the 2 sets of results are identical.

          Tony

          Show
          Tony Butler added a comment - Hi Juan, Sorry about the delay with my results. By the time the re-run with the original library had completed (it took about a week!) I was out of the office on a week's leave. Since I got back I've been trying to compare the 2 sets of results using the method you described above (exact query used below): SELECT COUNT FROM mdl_stats_daily s1 WHERE timeend > "1301616000" AND EXISTS ( SELECT 1 FROM mdl_stats_daily_original s2 WHERE s1.timeend = s2.timeend AND s1.courseid = s2.courseid AND s1.roleid = s2.roleid AND s1.stattype = s2.stattype AND ( s1.stat1 <> s2.stat1 OR s1.stat2 <> s2.stat2 ) ); This one query has now been running for 517695 seconds (almost 6 days!) and still hasn't finished! However, I have also done a visual comparison of the statistics report for the week in question, and the 2 sets of results are identical. Tony
          Hide
          Jean-Philippe Gaudreau added a comment -

          Hi Juan,

          We have the "same" problems with stats in Moodle 2.x. Have you been able to port your fix yet?

          Thx!

          Jean-Philippe

          Show
          Jean-Philippe Gaudreau added a comment - Hi Juan, We have the "same" problems with stats in Moodle 2.x. Have you been able to port your fix yet? Thx! Jean-Philippe
          Hide
          Jean-Philippe Gaudreau added a comment -

          Here's a fix for Moodle 2.x. : http://tracker.moodle.org/browse/MDL-30643

          I only created temporary table for logs but the performances are good this way. (Less than 50 seconds -> 150 000 logs per day)

          Show
          Jean-Philippe Gaudreau added a comment - Here's a fix for Moodle 2.x. : http://tracker.moodle.org/browse/MDL-30643 I only created temporary table for logs but the performances are good this way. (Less than 50 seconds -> 150 000 logs per day)
          Hide
          Tyler Bannister added a comment - - edited

          I tried out the patch on a test server and cron.php spat out these warnings 30 times each:

          Warning: Invalid argument supplied for foreach() in /home/tyler/projects/moodle-plain/lib/statslib.php on line 258
          Warning: Invalid argument supplied for foreach() in /home/tyler/projects/moodle-plain/lib/statslib.php on line 308

          It looks like the patched code should check the return values from get_records_sql.

          Show
          Tyler Bannister added a comment - - edited I tried out the patch on a test server and cron.php spat out these warnings 30 times each: Warning: Invalid argument supplied for foreach() in /home/tyler/projects/moodle-plain/lib/statslib.php on line 258 Warning: Invalid argument supplied for foreach() in /home/tyler/projects/moodle-plain/lib/statslib.php on line 308 It looks like the patched code should check the return values from get_records_sql.
          Hide
          Juan Segarra Montesinos added a comment -

          Hi Tyler,

          This warning (in 1.9) is shown because get_records_sql returns false and we're giving foreach() a false value You can test $res before giving it to forach().

          bye!

          Show
          Juan Segarra Montesinos added a comment - Hi Tyler, This warning (in 1.9) is shown because get_records_sql returns false and we're giving foreach() a false value You can test $res before giving it to forach(). bye!
          Hide
          Tyler Bannister added a comment -

          I've added another patch file that fixes the error issue I mentioned.

          My testing is returning identical results from this version as the original (unpatched) stats generation. With my additional changes the processing time for my sample data went from 90 minutes for 31 days of logs to approximately 88 seconds for the same logs which is a little less than the rev08 version.

          The big changes are replacing the looped updates with individual queries and the removal of an unnecessary cross join during the "enrollments view" creation.

          Show
          Tyler Bannister added a comment - I've added another patch file that fixes the error issue I mentioned. My testing is returning identical results from this version as the original (unpatched) stats generation. With my additional changes the processing time for my sample data went from 90 minutes for 31 days of logs to approximately 88 seconds for the same logs which is a little less than the rev08 version. The big changes are replacing the looped updates with individual queries and the removal of an unnecessary cross join during the "enrollments view" creation.
          Hide
          Tyler Bannister added a comment -

          I've now back ported the fixes from the Moodle 2 issue (MDL-30643) to Moodle 1.9. On my test data, stat generation is around 150 times faster with my patch. This patch uses 5 temporary tables, 2 for logs (MySQL limitation), 1 each for temporary daily and user_daily stats and a temporary table to mock M2's user_enrol table.

          I've published the patch to github and here's the link to the compare page:
          https://github.com/tbannister/moodle/compare/MOODLE_19_STABLE...MDL-18484_m19-log-speed

          Show
          Tyler Bannister added a comment - I've now back ported the fixes from the Moodle 2 issue ( MDL-30643 ) to Moodle 1.9. On my test data, stat generation is around 150 times faster with my patch. This patch uses 5 temporary tables, 2 for logs (MySQL limitation), 1 each for temporary daily and user_daily stats and a temporary table to mock M2's user_enrol table. I've published the patch to github and here's the link to the compare page: https://github.com/tbannister/moodle/compare/MOODLE_19_STABLE...MDL-18484_m19-log-speed
          Hide
          Tyler Bannister added a comment -

          As an additional note, I found an error in the Moodle stats during my work, query 13 appears to be producing incorrect results (number of view from guests in each course) because it's checking for people not enrolled in the site rather than not enrolled in the course. The fix is simple and documented in the comments in the code. There's doesn't seem to be much point to opening a bug issue for it, though since it's unlikely to get fixed and my solution applies to the patched code above.

          Show
          Tyler Bannister added a comment - As an additional note, I found an error in the Moodle stats during my work, query 13 appears to be producing incorrect results (number of view from guests in each course) because it's checking for people not enrolled in the site rather than not enrolled in the course. The fix is simple and documented in the comments in the code. There's doesn't seem to be much point to opening a bug issue for it, though since it's unlikely to get fixed and my solution applies to the patched code above.
          Hide
          Eloy Lafuente (stronk7) added a comment -

          U P S T R E A M I Z E D !

          Many thanks, this is now available in all the repos (git & cvs).

          Closing, ciao

          Show
          Eloy Lafuente (stronk7) added a comment - U P S T R E A M I Z E D ! Many thanks, this is now available in all the repos (git & cvs). Closing, ciao
          Hide
          Eloy Lafuente (stronk7) added a comment -

          Doh,

          somehow this issue was closed incorrectly when processing all the integrated issues this week. (sort of most voted and current in integration filters mix). Apologies for the confusion, reseting to previous status!

          Ciao, Eloy

          Show
          Eloy Lafuente (stronk7) added a comment - Doh, somehow this issue was closed incorrectly when processing all the integrated issues this week. (sort of most voted and current in integration filters mix). Apologies for the confusion, reseting to previous status! Ciao, Eloy
          Hide
          Matteo Scaramuccia added a comment -

          Hi Tyler,
          your amazing work for MDL-30643 has finally landed into the main stream : any plan to update your 1.9 branch to backport everything and let the unsupported 1.9 benefit from all the peer review cycles against your "first" proposal?

          TIA,
          Matteo

          Show
          Matteo Scaramuccia added a comment - Hi Tyler, your amazing work for MDL-30643 has finally landed into the main stream : any plan to update your 1.9 branch to backport everything and let the unsupported 1.9 benefit from all the peer review cycles against your "first" proposal? TIA, Matteo
          Hide
          Michael de Raadt added a comment -

          This is fixed by MDL-30643.

          I don't this will (or should) be backported to 1.9.

          Show
          Michael de Raadt added a comment - This is fixed by MDL-30643 . I don't this will (or should) be backported to 1.9.

            Dates

            • Created:
              Updated:
              Resolved: