Moodle
  1. Moodle
  2. MDL-40584

get_record called in a loop in restore_dbops::prechek_precheck_qbanks_by_level

    Details

    • Rank:
      51414

      Description

      Inside restore_dbops::prechek_precheck_qbanks_by_level, get_record is called in a loop for all questions in a particular category. This can result in thousands of DB calls for a single category when it should be completed as a single call.

      In a large database, the largest set of questions seen is 9k for any particular category. The memory use of the cache is for the single function and an inline memory hash with a single SQL will resolve the database overhead here.

        Activity

        Hide
        Russell Smith added a comment -

        When testing MDL-40581, I the call graphs shows 8862 get_record_calls from the precheck function. As suggested in the description.

        MDL-40581_MUC_restore_precheck_63902e2b918735b170b7b87252f7db25.png shows that case.

        The result is to remove the loop and do a single call.

        Show
        Russell Smith added a comment - When testing MDL-40581 , I the call graphs shows 8862 get_record_calls from the precheck function. As suggested in the description. MDL-40581 _MUC_restore_precheck_63902e2b918735b170b7b87252f7db25.png shows that case. The result is to remove the loop and do a single call.
        Hide
        Russell Smith added a comment -
                                                            	Diff    	Diff%
        Number of Function Calls   43,762,907 	42,697,004 	-1,065,903 	-2.4%
        Incl. Wall Time (microsec) 820,491,422 	703,751,677 	-116,739,745 	-14.2%
        Incl. CPU (microsecs)      384,832,051 	346,005,623 	-38,826,428 	-10.1%
        Incl. MemUse (bytes)       89,776,112 	90,035,496 	259,384 	0.3%
        Incl. PeakMemUse (bytes)   119,346,240 	131,472,080 	12,125,840 	10.2%
        

        Performance run show a small memory increase and a 15% time increase.

        Show
        Russell Smith added a comment - Diff Diff% Number of Function Calls 43,762,907 42,697,004 -1,065,903 -2.4% Incl. Wall Time (microsec) 820,491,422 703,751,677 -116,739,745 -14.2% Incl. CPU (microsecs) 384,832,051 346,005,623 -38,826,428 -10.1% Incl. MemUse (bytes) 89,776,112 90,035,496 259,384 0.3% Incl. PeakMemUse (bytes) 119,346,240 131,472,080 12,125,840 10.2% Performance run show a small memory increase and a 15% time increase.
        Hide
        Tim Hunt added a comment -

        This looks like an obvious performance win. Just one significant, and one minor, further improvement required:

        1. You could do more work in the SQL:

        // Collect all the questions for this category into memory so we only talk to the DB once.
        $questioncache = $DB->get_records_sql_menu("
            SELECT " . $DB->sql_concat('stamp', "' '", 'version') . ", id
            FROM {question}
            WHERE category = ?", array($matchcat->id));
        

        (That replaces 7 lines of your code.)

        2. You don't need to unset($questioncache) at the end of the function. PHP uses reference-counting, and so will do that for you.

        Show
        Tim Hunt added a comment - This looks like an obvious performance win. Just one significant, and one minor, further improvement required: 1. You could do more work in the SQL: // Collect all the questions for this category into memory so we only talk to the DB once. $questioncache = $DB->get_records_sql_menu(" SELECT " . $DB->sql_concat('stamp', " ' ' ", 'version') . " , id FROM {question} WHERE category = ?", array($matchcat->id)); (That replaces 7 lines of your code.) 2. You don't need to unset($questioncache) at the end of the function. PHP uses reference-counting, and so will do that for you.
        Hide
        Russell Smith added a comment -

        Thanks Tim for the education there, too much coding on 5.1.6 where that actually helped with garage collection. I've adjusted the patch accordingly. As expected, we don't have as much of a memory rise from this new patch. I'm not so convinced by the difference in runtime. It's faster overall due to less DB calls. However it seems runtime noise related to disk performance of the database.

          Run #89104786ee7a93d605b1b82c84424893 Run #7f18b6d80460500b324c082809bf8472 Diff Diff%
        Number of Function Calls 43,762,907 42,730,892 -1,032,015 -2.4%
        Incl. Wall Time (microsec) 820,491,422 642,123,828 -178,367,594 -21.7%
        Incl. CPU (microsecs) 384,832,051 303,134,944 -81,697,107 -21.2%
        Incl. MemUse (bytes) 89,776,112 90,089,040 312,928 0.3%
        Incl. PeakMemUse (bytes) 119,346,240 127,614,584 8,268,344 6.9%

        I've not uploaded the final mpr file due to the tracker not allowing me. I'm resubmitting for peer review.

        I am not sure if I should be back-patching these, any comment there would be appreciated.

        Show
        Russell Smith added a comment - Thanks Tim for the education there, too much coding on 5.1.6 where that actually helped with garage collection. I've adjusted the patch accordingly. As expected, we don't have as much of a memory rise from this new patch. I'm not so convinced by the difference in runtime. It's faster overall due to less DB calls. However it seems runtime noise related to disk performance of the database.   Run #89104786ee7a93d605b1b82c84424893 Run #7f18b6d80460500b324c082809bf8472 Diff Diff% Number of Function Calls 43,762,907 42,730,892 -1,032,015 -2.4% Incl. Wall Time (microsec) 820,491,422 642,123,828 -178,367,594 -21.7% Incl. CPU (microsecs) 384,832,051 303,134,944 -81,697,107 -21.2% Incl. MemUse (bytes) 89,776,112 90,089,040 312,928 0.3% Incl. PeakMemUse (bytes) 119,346,240 127,614,584 8,268,344 6.9% I've not uploaded the final mpr file due to the tracker not allowing me. I'm resubmitting for peer review. I am not sure if I should be back-patching these, any comment there would be appreciated.
        Hide
        Tim Hunt added a comment -

        +1 from me for that latest patch.

        I will let you submit for integration. I don't know if you intend to back-port or not.

        Show
        Tim Hunt added a comment - +1 from me for that latest patch. I will let you submit for integration. I don't know if you intend to back-port or not.
        Hide
        Russell Smith added a comment -

        I have back-ported to 2.5 and 2.4. I'm ready for this to be submitted for integration. I can't do that.

        Show
        Russell Smith added a comment - I have back-ported to 2.5 and 2.4. I'm ready for this to be submitted for integration. I can't do that.
        Hide
        Tim Hunt added a comment -

        OK. Submitting for integration.

        Show
        Tim Hunt added a comment - OK. Submitting for integration.
        Hide
        Dan Poltawski added a comment -

        Nice improvement, i've integrated that to master, 25 and 24 - thanks Russell.

        Show
        Dan Poltawski added a comment - Nice improvement, i've integrated that to master, 25 and 24 - thanks Russell.
        Hide
        Marina Glancy added a comment -

        Test passed. Restore works fine on 2.4, 2.5 and master.

        Completely non related but I had some funny warnings about badges when trying to restore backup from 2.6 into moodle 2.4

        Show
        Marina Glancy added a comment - Test passed. Restore works fine on 2.4, 2.5 and master. Completely non related but I had some funny warnings about badges when trying to restore backup from 2.6 into moodle 2.4
        Hide
        Damyon Wiese added a comment -

        Thanks again for another week of fixes, improvements and testing. These changes have been released to the world.

        Cheers, Damyon

        Show
        Damyon Wiese added a comment - Thanks again for another week of fixes, improvements and testing. These changes have been released to the world. Cheers, Damyon

          People

          • Votes:
            0 Vote for this issue
            Watchers:
            5 Start watching this issue

            Dates

            • Created:
              Updated:
              Resolved: