Moodle
  1. Moodle
  2. MDL-36668

Performance Issue with mod/data/view.php

    Details

    • Database:
      MySQL
    • Testing Instructions:
      Hide

      (Regression testing)

      Warning! This needs to be tested on all databases.

      1. Create a database activity.
      2. Add fields and save the template, or alternatively use the preset and import some entries.
        • (Please note with the csv file that it contains 500 entries. This may take some time to import. Feel free to remove records to make this process faster)
      3. Do a few simple searches and a few advanced searches on the database.
        • Check out the paging of the results.
        • Use different sorting criteria.
        • Check to make sure that there are no errors displayed.
          Ideally you would check to make sure that the right number of entries are returned.
      Show
      (Regression testing) Warning! This needs to be tested on all databases. Create a database activity. Add fields and save the template, or alternatively use the preset and import some entries. (Please note with the csv file that it contains 500 entries. This may take some time to import. Feel free to remove records to make this process faster) Do a few simple searches and a few advanced searches on the database. Check out the paging of the results. Use different sorting criteria. Check to make sure that there are no errors displayed. Ideally you would check to make sure that the right number of entries are returned.
    • Affected Branches:
      MOODLE_23_STABLE
    • Fixed Branches:
      MOODLE_21_STABLE, MOODLE_22_STABLE, MOODLE_23_STABLE
    • Pull from Repository:
    • Rank:
      46167

      Description

      We applied a patch of MDL-35558 to our production servers, and are noticing an extremely high amount of DB activity as a result. The offending query is:

      SELECT DISTINCT r.id, r.approved, r.timecreated, r.timemodified, r.userid, u.firstname, u.lastname
      FROM mdl_data_content c, mdl_data_records r, mdl_data_content cs, mdl_user u
      WHERE c.recordid = r.id
      AND r.dataid = '52'
      AND r.userid = u.id
      ORDER BY r.timecreated ASC , r.id ASC
      

      Output of Explain:

      ------------------------------------------------------------------------------------------------------------------------------------------------+

      id select_type table type possible_keys key key_len ref rows Extra

      ------------------------------------------------------------------------------------------------------------------------------------------------+

      1 SIMPLE r ref PRIMARY,mdl_datareco_dat_ix mdl_datareco_dat_ix 8 const 1031 Using temporary; Using filesort
      1 SIMPLE u eq_ref PRIMARY PRIMARY 8 credability.r.userid 1  
      1 SIMPLE c ref mdl_datacont_rec_ix mdl_datacont_rec_ix 8 credability.r.id 15 Using index; Distinct
      1 SIMPLE cs index NULL mdl_datacont_rec_ix 8 NULL 35526 Using index; Distinct; Using join buffer

      ------------------------------------------------------------------------------------------------------------------------------------------------+

      The biggest difference is that "AND cs.recordid = r.id" clause was moved out of the main query into the basic search query in 2 places:

      The root cause appears to stem from a partially backported fix from MDL-35961. In that fix, the second reference to "

      {data_content} cs" and corresponding filter on "AND cs.recordid = r.id" is removed. In MDL-35558, only the WHERE clause was modified, which means that the result set is multiplied by the total records in {data_content}

      . Because the query is only selecting DISTINCT values, this bug will appear undetected to functional tests although it is a major drain on database performance.

      The suggested fix is to either remove the join on

      {data_content}

      , or to add the filter back to the where clause.

        Issue Links

          Activity

          Hide
          Kris Stokking added a comment -

          Upgrading to blocker - We are able to reproduce this issue even when the Database module is disabled.

          Show
          Kris Stokking added a comment - Upgrading to blocker - We are able to reproduce this issue even when the Database module is disabled.
          Hide
          Adrian Greeve added a comment -

          Hello Kris,

          We are looking at back porting MDL-35961 to stable branches. Preliminary tests have shown that applying this patch greatly reduces the time of searches. We will do a few more tests here. Is it possible for you to apply that solution to your system to verify a performance increase?

          Show
          Adrian Greeve added a comment - Hello Kris, We are looking at back porting MDL-35961 to stable branches. Preliminary tests have shown that applying this patch greatly reduces the time of searches. We will do a few more tests here. Is it possible for you to apply that solution to your system to verify a performance increase?
          Hide
          Eloy Lafuente (stronk7) added a comment -

          I can confirm the cross-join above is killing some sites here too. The details are:

          1) One database activity with only 720 records.
          2) Total number of mdl_data_content records in the database = 239791 (belonging to other databases).

          Right now, trying to access to any database (data/view.php?id=xxx), kills the site completely.

          I've quick & dirty backported MDL-35961 and that fixed the listing (back to 0.5 seconds). As said, it was a dirty backport so I broke search completely. But surely it can be achieved with a bit of care.

          Please, don't forget to test both listing, paging and searching in this issue, to be sure that everything continues working.

          Ciao

          Show
          Eloy Lafuente (stronk7) added a comment - I can confirm the cross-join above is killing some sites here too. The details are: 1) One database activity with only 720 records. 2) Total number of mdl_data_content records in the database = 239791 (belonging to other databases). Right now, trying to access to any database (data/view.php?id=xxx), kills the site completely. I've quick & dirty backported MDL-35961 and that fixed the listing (back to 0.5 seconds). As said, it was a dirty backport so I broke search completely. But surely it can be achieved with a bit of care. Please, don't forget to test both listing, paging and searching in this issue, to be sure that everything continues working. Ciao
          Hide
          Adrian Greeve added a comment -

          I just created and tested a database module with 10,000 records.
          Before this patch mod/data/view.php would not load.
          After the patch mod/data/view.php loads in 4.3 secs.
          I tried out basic and advanced searches with different sort criteria etc. and didn't come across any problems.

          Show
          Adrian Greeve added a comment - I just created and tested a database module with 10,000 records. Before this patch mod/data/view.php would not load. After the patch mod/data/view.php loads in 4.3 secs. I tried out basic and advanced searches with different sort criteria etc. and didn't come across any problems.
          Hide
          Kris Stokking added a comment -

          We are looking at back porting MDL-35961 to stable branches. Preliminary tests have shown that applying this patch greatly reduces the time of searches. We will do a few more tests here. Is it possible for you to apply that solution to your system to verify a performance increase?

          We don't apply patches to production systems prior to a Closed status, but I should be able to test the effectiveness of the patch on a non-production system.

          Show
          Kris Stokking added a comment - We are looking at back porting MDL-35961 to stable branches. Preliminary tests have shown that applying this patch greatly reduces the time of searches. We will do a few more tests here. Is it possible for you to apply that solution to your system to verify a performance increase? We don't apply patches to production systems prior to a Closed status, but I should be able to test the effectiveness of the patch on a non-production system.
          Hide
          Kris Stokking added a comment -

          We applied the patch on a cloned site and it appears to be working fine. Performance is significantly improved. I did a smoke test of:

          • Advanced Searching using 1 field
          • Advanced Searching using multiple fields
          • Basic searching sorting on "Fields"
          • Basic searching sorting on "Other"
          • Navigating through pages

          The only test that failed was basic searching sorting on "Fields" - it returned no results even when searching on the same value sorting on a "Field". No errors were reported with errorlevel set to debugging. I'm not 100% sure that it's related to this fix - it seems odd that it would be, and I have no way to test the baseline.

          Show
          Kris Stokking added a comment - We applied the patch on a cloned site and it appears to be working fine. Performance is significantly improved. I did a smoke test of: Advanced Searching using 1 field Advanced Searching using multiple fields Basic searching sorting on "Fields" Basic searching sorting on "Other" Navigating through pages The only test that failed was basic searching sorting on "Fields" - it returned no results even when searching on the same value sorting on a "Field". No errors were reported with errorlevel set to debugging. I'm not 100% sure that it's related to this fix - it seems odd that it would be, and I have no way to test the baseline.
          Hide
          Adrian Greeve added a comment -

          I'm haven't been able to replicate the problem with sorting by 'Fields' returning no records. I am very curious as to how that error is happening.

          Show
          Adrian Greeve added a comment - I'm haven't been able to replicate the problem with sorting by 'Fields' returning no records. I am very curious as to how that error is happening.
          Hide
          Kris Stokking added a comment -

          I'm haven't been able to replicate the problem with sorting by 'Fields' returning no records. I am very curious as to how that error is happening.

          Let's treat that as a red herring for now - if sorting on 'Fields' is working in your testing, I'll research into why it's broken in our test site in a separate effort.

          Show
          Kris Stokking added a comment - I'm haven't been able to replicate the problem with sorting by 'Fields' returning no records. I am very curious as to how that error is happening. Let's treat that as a red herring for now - if sorting on 'Fields' is working in your testing, I'll research into why it's broken in our test site in a separate effort.
          Hide
          Eloy Lafuente (stronk7) added a comment -

          Side note: I've had this patch applied in one server since 2-3 days ago (using the database module intensively) and my friends are really happy and I have not received information about any regression from them since then.

          Show
          Eloy Lafuente (stronk7) added a comment - Side note: I've had this patch applied in one server since 2-3 days ago (using the database module intensively) and my friends are really happy and I have not received information about any regression from them since then.
          Hide
          Dan Poltawski added a comment -

          This is causing a major problem for recently upgraded sites. Integrating the fix.

          Show
          Dan Poltawski added a comment - This is causing a major problem for recently upgraded sites. Integrating the fix.
          Hide
          Dan Poltawski added a comment -

          Integrated to 22, 23 and also 2.1. (Because of the nature of this performance regression from the security fix)

          Show
          Dan Poltawski added a comment - Integrated to 22, 23 and also 2.1. (Because of the nature of this performance regression from the security fix)
          Hide
          Michael de Raadt added a comment -

          I've tested this in MS SQL, Postgres and Oracle with master.

          I saw no errors. Paging and sorting worked as expected.

          Show
          Michael de Raadt added a comment - I've tested this in MS SQL, Postgres and Oracle with master. I saw no errors. Paging and sorting worked as expected.
          Hide
          Andrew Davis added a comment -

          Looks good in mysql in master.

          Show
          Andrew Davis added a comment - Looks good in mysql in master.
          Hide
          Andrew Davis added a comment - - edited

          In 2.3 Im getting JS errors while importing the preset when i click "choose a file...". Probably not actually due to this bug but makes testing harder.

          Timestamp: 23/11/12 12:02:06
          Error: undefined entity
          Source File:
          Line: 4, Column: 96
          Source Code:
          <li class="fp-repo"><a href="#"><img class="fp-repo-icon" width="16" height="16" /> <span class="fp-repo-name"></span></a></li>

          Timestamp: 23/11/12 12:02:06
          Error: SyntaxError: An invalid or illegal string was specified
          Source File: http://localhost/moodle/int/moodle23stable/theme/yui_combo.php?3.5.1/build/oop/oop.js&3.5.1/build/event-custom-base/event-custom-base.js&3.5.1/build/dom-core/dom-core.js&3.5.1/build/dom-base/dom-base.js&3.5.1/build/selector-native/selector-native.js&3.5.1/build/selector/selector.js&3.5.1/build/node-core/node-core.js&3.5.1/build/node-base/node-base.js&3.5.1/build/event-base/event-base.js&3.5.1/build/event-delegate/event-delegate.js&3.5.1/build/node-event-delegate/node-event-delegate.js&3.5.1/build/pluginhost-base/pluginhost-base.js&3.5.1/build/pluginhost-config/pluginhost-config.js&3.5.1/build/node-pluginhost/node-pluginhost.js&3.5.1/build/dom-style/dom-style.js&3.5.1/build/dom-screen/dom-screen.js&3.5.1/build/node-screen/node-screen.js&3.5.1/build/node-style/node-style.js
          Line: 3318

          Ive raised MDL-36796 for this JS issue.

          Show
          Andrew Davis added a comment - - edited In 2.3 Im getting JS errors while importing the preset when i click "choose a file...". Probably not actually due to this bug but makes testing harder. Timestamp: 23/11/12 12:02:06 Error: undefined entity Source File: Line: 4, Column: 96 Source Code: <li class="fp-repo"><a href="#"><img class="fp-repo-icon" width="16" height="16" /> <span class="fp-repo-name"></span></a></li> Timestamp: 23/11/12 12:02:06 Error: SyntaxError: An invalid or illegal string was specified Source File: http://localhost/moodle/int/moodle23stable/theme/yui_combo.php?3.5.1/build/oop/oop.js&3.5.1/build/event-custom-base/event-custom-base.js&3.5.1/build/dom-core/dom-core.js&3.5.1/build/dom-base/dom-base.js&3.5.1/build/selector-native/selector-native.js&3.5.1/build/selector/selector.js&3.5.1/build/node-core/node-core.js&3.5.1/build/node-base/node-base.js&3.5.1/build/event-base/event-base.js&3.5.1/build/event-delegate/event-delegate.js&3.5.1/build/node-event-delegate/node-event-delegate.js&3.5.1/build/pluginhost-base/pluginhost-base.js&3.5.1/build/pluginhost-config/pluginhost-config.js&3.5.1/build/node-pluginhost/node-pluginhost.js&3.5.1/build/dom-style/dom-style.js&3.5.1/build/dom-screen/dom-screen.js&3.5.1/build/node-screen/node-screen.js&3.5.1/build/node-style/node-style.js Line: 3318 Ive raised MDL-36796 for this JS issue.
          Hide
          Andrew Davis added a comment -

          2.2 using MySql seems to work fine. Passing.

          Show
          Andrew Davis added a comment - 2.2 using MySql seems to work fine. Passing.
          Hide
          Dan Poltawski added a comment -

          Congratulations! Another bug solved.. only another 7330 to go, thanks for contributing to contributing to 0.8% of all bugs being fixed this week!

          ciao
          Dan

          Show
          Dan Poltawski added a comment - Congratulations! Another bug solved.. only another 7330 to go, thanks for contributing to contributing to 0.8% of all bugs being fixed this week! ciao Dan

            People

            • Votes:
              2 Vote for this issue
              Watchers:
              8 Start watching this issue

              Dates

              • Created:
                Updated:
                Resolved: