Uploaded image for project: 'Moodle'
  1. Moodle
  2. MDL-53869

SQL query in participation report is not optimised to use the index on logstore_standard_log table

    XMLWordPrintable

    Details

    • Type: Bug
    • Status: Closed
    • Priority: Major
    • Resolution: Duplicate
    • Affects Version/s: 2.7.11
    • Fix Version/s: None
    • Labels:
    • Environment:
      Linux, PHP 5.4, MySQL 5.6
    • Database:
      MySQL
    • Testing Instructions:
      Hide

      Upgrade

      1. Before upgrading to this version of the standard logstore plugin check the logstore_standard_log table does not have an index on the contextinstanceid field.
      2. Upgrade Moodle to use the new version of this plugin (2016081500). There should be no errors.
      3. Check the logstore_standard_log table, there should now be an index on the contextinstanceid field.
      Show
      Upgrade Before upgrading to this version of the standard logstore plugin check the logstore_standard_log table does not have an index on the contextinstanceid field. Upgrade Moodle to use the new version of this plugin (2016081500). There should be no errors. Check the logstore_standard_log table, there should now be an index on the contextinstanceid field.
    • Affected Branches:
      MOODLE_27_STABLE
    • Pull from Repository:
    • Pull Master Branch:

      Description

      On Friday evening our Moodle site was heading towards a crash.

      The issue seems to have been caused by a single user trying to generate a participation report for a single course. They appear to have been trying to generate the report periodically because to them it was not finishing.

      The offending query is:

      SELECT ra.userid, u.firstnamephonetic, u.lastnamephonetic, u.middlename, u.alternatename, u.firstname, u.lastname, u.idnumber, COUNT(l.actioncount) AS count 
      FROM (SELECT DISTINCT userid 
      FROM mdl_role_assignments 
      WHERE contextid IN (?, ?, ?, ?) AND roleid = ? ) ra 
      JOIN mdl_user u ON u.id = ra.userid LEFT JOIN
       ( SELECT userid, COUNT(crud) AS actioncount 
      FROM mdl_logstore_standard_log 
      WHERE contextinstanceid = ? AND timecreated > ? AND crud = ? AND edulevel = ? AND anonymous = ? AND contextlevel = ? AND (origin = ? OR origin = ?) 
      GROUP BY userid, timecreated) l ON (l.userid = ra.userid) 
      GROUP BY ra.userid, u.firstnamephonetic, u.lastnamephonetic, u.middlename, u.alternatename, u.firstname, u.lastname, u.idnumber 
      ORDER BY lastname DESC LIMIT ?, ?

      At its worst it took 12,800,000 ms to complete.

      The fastest time I can see for it is: 108,000 ms

      The query analysis on our monitoring gave the following report:

      Table Hint
      <derived2> This table was retrieved with a full table scan, which is often quite bad for performance, unless you only retrieve a few rows.
      The table was retrieved with this index:
      No index was used in this part of the query.
      A temporary table was created to access this part of the query, which can cause poor performance. This typically happens if the query contains GROUP BY and ORDER BY clauses that list columns differently.
      MySQL had to do an extra pass to retrieve the rows in sorted order, which is a cause of poor performance but sometimes unavoidable.
      You can speed up this query by querying only fields that are within the index. Or you can create an index that includes every field in your query, including the primary key.
      Approximately 1167 rows of this table were scanned.
      u The table was retrieved with this index: PRIMARY
      You can speed up this query by querying only fields that are within the index. Or you can create an index that includes every field in your query, including the primary key.
      Approximately 1 row of this table was scanned.
      <derived3> The table was retrieved with this index: <auto_key0>
      You can speed up this query by querying only fields that are within the index. Or you can create an index that includes every field in your query, including the primary key.
      Approximately 18342 rows of this table were scanned.
      mdl_logstore_standard_log This table was retrieved with an index scan, which is like a full table scan, except it only hits the index (not the actual table). This is usually not great for performance.
      The table was retrieved with this index: mdl_logsstanlog_useconconcr_ix
      You can speed up this query by querying only fields that are within the index. Or you can create an index that includes every field in your query, including the primary key.
      Approximately 42810897 rows of this table were scanned.
      mdl_role_assignments The table was retrieved with this index: mdl_roleassi_rolcon_ix
      A temporary table was created to access this part of the query, which can cause poor performance. This typically happens if the query contains GROUP BY and ORDER BY clauses that list columns differently.
      You can speed up this query by querying only fields that are within the index. Or you can create an index that includes every field in your query, including the primary key.
      Approximately 1167 rows of this table were scanned.

      After looking at it more I have found that the sub-query on the logstore_standard_log table is not using a useful index. I think adding an index to logstore_standard_log.contextinstanceid will greatly improve performance on this report.

        Attachments

          Issue Links

            Activity

              People

              Assignee:
              nmagill Neill Magill
              Reporter:
              nmagill Neill Magill
              Participants:
              Component watchers:
              Andrew Nicols, Jun Pataleta, Michael Hawkins, Shamim Rezaie, Simey Lameze, Matteo Scaramuccia, Andrew Nicols, Jun Pataleta, Michael Hawkins, Shamim Rezaie, Simey Lameze, Adrian Greeve, Jake Dallimore, Mathew May, Mihail Geshoski, Peter Dias
              Votes:
              0 Vote for this issue
              Watchers:
              3 Start watching this issue

                Dates

                Created:
                Updated:
                Resolved: