Moodle
  1. Moodle
  2. MDL-28021

Duplicatated activity completion entries in database not handled correctly

    Details

    • Type: Bug Bug
    • Status: Closed
    • Priority: Critical Critical
    • Resolution: Fixed
    • Affects Version/s: 2.0.3, 2.1
    • Fix Version/s: 2.0.4
    • Component/s: Activity completion
    • Labels:
      None
    • Testing Instructions:
      Hide

      Full test involves steps that must be complete BEFORE and AFTER the upgrade. It also requires database access.

      You can also just test the AFTER steps.

      BEFORE UPGRADE

      0. Ensure completion system is enabled at system level and on a test course.
      1. Add a new Page on the test course. Use default settings including manual completion tickbox.
      2. Turn editing off. Look at the Page on the course page. Note that there is a tickbox but it is not ticked yet.
      3. Using a totally different browser (eg Internet Explorer), visit the same course page and log in using the same user account.
      4. Still using the different browser, tick the tickbox. (You can now close the different browser)
      5. Back in the first browser, tick the tickbox.
      6. Note the course-module ID of the Page. For example if the URL is /mod/page/view.php?id=319 then the course-module ID is 319.
      7. Access the database directly and run this query (where 'mdl_' is your database prefix and 319 is the course-module ID):

      SELECT * FROM mdl_course_modules_completion WHERE coursemoduleid=319;

      The result will include 2 rows. This is a demonstration of the bug; the database is now in incorrect state. Note the IDs of the two rows (for example 13 and 14).

      AFTER UPGRADE

      1. Rerun the query above. You should find that of those two duplicates, the row with the lower ID (13 in my example) has been deleted and there is only one row now.
      2. Repeat steps 1-7 of the test above (note - this means you will create a second Page activity, not reuse the last one). This time, the query from step 7 should only return one row.

      Show
      Full test involves steps that must be complete BEFORE and AFTER the upgrade. It also requires database access. You can also just test the AFTER steps. BEFORE UPGRADE 0. Ensure completion system is enabled at system level and on a test course. 1. Add a new Page on the test course. Use default settings including manual completion tickbox. 2. Turn editing off. Look at the Page on the course page. Note that there is a tickbox but it is not ticked yet. 3. Using a totally different browser (eg Internet Explorer), visit the same course page and log in using the same user account. 4. Still using the different browser, tick the tickbox. (You can now close the different browser) 5. Back in the first browser, tick the tickbox. 6. Note the course-module ID of the Page. For example if the URL is /mod/page/view.php?id=319 then the course-module ID is 319. 7. Access the database directly and run this query (where 'mdl_' is your database prefix and 319 is the course-module ID): SELECT * FROM mdl_course_modules_completion WHERE coursemoduleid=319; The result will include 2 rows. This is a demonstration of the bug; the database is now in incorrect state. Note the IDs of the two rows (for example 13 and 14). AFTER UPGRADE 1. Rerun the query above. You should find that of those two duplicates, the row with the lower ID (13 in my example) has been deleted and there is only one row now. 2. Repeat steps 1-7 of the test above (note - this means you will create a second Page activity, not reuse the last one). This time, the query from step 7 should only return one row.
    • Affected Branches:
      MOODLE_20_STABLE, MOODLE_21_STABLE
    • Fixed Branches:
      MOODLE_20_STABLE
    • Pull Master Branch:
      MDL-28021-master
    • Rank:
      17708

      Description

      We have a client heavily using activity completion within their course, and users sometimes get stuck with activities showing as not completed, despite the activity completion report showing them completion. Sometimes the completion state can even spontaneously reverse.

      I tracked this down to having duplicate completion records for each activity, i.e the records in prefix_course_modules_completion are not unique by (userid, cmid) which some of the code seems to assume e.g use of get_record. Our DB is postgres but any DB can return the records in any order it likes, so results are inconsistent.

      I have resolved this in my patch (will github soon) by only using the latest record in the php code, as the database is not indexed on time so an ORDER BY is not a trivial option.

      If it is intended for course_modules_completion to be unique by (userid, cmid) then this must be enforced by code & UNIQUE INDEX, and corrected by an upgrade script. If an audit trail of completion states should exist, then either my fix can be used or the table should be indexed by time and only the most recent records used.

      For now, my patch will resolve the immediate issue and allow students to progress in their courses.

        Activity

        Tony Levi created issue -
        Hide
        Ashley Holman added a comment -

        Raising this to critical as the bug is currently breaking activity completion.

        Show
        Ashley Holman added a comment - Raising this to critical as the bug is currently breaking activity completion.
        Ashley Holman made changes -
        Field Original Value New Value
        Priority Minor [ 4 ] Critical [ 2 ]
        Hide
        Tony Levi added a comment -

        patch applied on current 20 stable branch

        https://github.com/tlevi/moodle/tree/mdl28021

        Show
        Tony Levi added a comment - patch applied on current 20 stable branch https://github.com/tlevi/moodle/tree/mdl28021
        Hide
        Tony Levi added a comment -

        Ah, added commit to the branch now, hope nobody tried to look in those few minutes

        Show
        Tony Levi added a comment - Ah, added commit to the branch now, hope nobody tried to look in those few minutes
        Hide
        Sam Marshall added a comment -

        Hi Tony,

        I am fairly sure the intention is that this table should be unique by userid, coursemoduleid; there is not supposed to be an audit trail. Thanks to your prompting, I checked this on our live 1.9-based system that includes completion - it's had completion a few years now - and found quite a few cases with 2+ rows (15,024 out of 7,034,718). Oops. Nobody has noticed this until now...

        I will do the fix you suggest (make one of the indexes cover both fields and be unique, after throwing away the older rows in each duplicate case). If you need a workaround, you should continue to use your patch until this update is ready.

        Do you happen to know how the duplicates get created in the first place? I tried a trivial approach (set up manual completion, turn it on and off again) and this does not create 2 rows. I can look into the code but if you already know how to reproduce it that would save me having to investigate... (Obviously, if I just add the constraint in the database without fixing the underlying cause, this will cause an error at the point where it tries to add the extra row.)

        Show
        Sam Marshall added a comment - Hi Tony, I am fairly sure the intention is that this table should be unique by userid, coursemoduleid; there is not supposed to be an audit trail. Thanks to your prompting, I checked this on our live 1.9-based system that includes completion - it's had completion a few years now - and found quite a few cases with 2+ rows (15,024 out of 7,034,718). Oops. Nobody has noticed this until now... I will do the fix you suggest (make one of the indexes cover both fields and be unique, after throwing away the older rows in each duplicate case). If you need a workaround, you should continue to use your patch until this update is ready. Do you happen to know how the duplicates get created in the first place? I tried a trivial approach (set up manual completion, turn it on and off again) and this does not create 2 rows. I can look into the code but if you already know how to reproduce it that would save me having to investigate... (Obviously, if I just add the constraint in the database without fixing the underlying cause, this will cause an error at the point where it tries to add the extra row.)
        Hide
        Sam Marshall added a comment -

        Never mind, I figured it out - it's to do with the cache. When it decides whether to insert or update, it does so based on the cached data. If you have two simultaneous browser sessions, or a change is made to your completion state in another user's browser session and then you make a similar change yourself, it can screw up like this.

        To reproduce, add a new activity on a course set to manual completion. Initially it will be unticked. Open a second browser so that you have two separate logins in the course. The second one will create a second row (or if you have the fix which I've coded to require unique, it will give an error the second time).

        I think I'll change it so that when it does the insert and update it checks the real status in the database immediately before (same transaction). This should minimise errors without significantly reducing performance as it only does it when it's going to change the database anyway.

        Show
        Sam Marshall added a comment - Never mind, I figured it out - it's to do with the cache. When it decides whether to insert or update, it does so based on the cached data. If you have two simultaneous browser sessions, or a change is made to your completion state in another user's browser session and then you make a similar change yourself, it can screw up like this. To reproduce, add a new activity on a course set to manual completion. Initially it will be unticked. Open a second browser so that you have two separate logins in the course. The second one will create a second row (or if you have the fix which I've coded to require unique, it will give an error the second time). I think I'll change it so that when it does the insert and update it checks the real status in the database immediately before (same transaction). This should minimise errors without significantly reducing performance as it only does it when it's going to change the database anyway.
        Sam Marshall made changes -
        Status Open [ 1 ] Waiting for integration review [ 10010 ]
        Pull Master Diff URL https://github.com/sammarshallou/moodle/compare/master...MDL-28021-master
        Pull Master Branch MDL-28021-master
        Pull 2.0 Diff URL https://github.com/sammarshallou/moodle/compare/MOODLE_20_STABLE...MDL-28021-m20
        Pull 2.0 Branch MDL-28021-m20
        Pull from Repository git://github.com/sammarshallou/moodle.git
        Fix Version/s 2.0.4 [ 10652 ]
        Testing Instructions Full test involves steps that must be complete BEFORE and AFTER the upgrade. It also requires database access.

        You can also just test the AFTER steps.

        BEFORE UPGRADE

        0. Ensure completion system is enabled at system level and on a test course.
        1. Add a new Page on the test course. Use default settings including manual completion tickbox.
        2. Turn editing off. Look at the Page on the course page. Note that there is a tickbox but it is not ticked yet.
        3. Using a totally different browser (eg Internet Explorer), visit the same course page and log in using the same user account.
        4. Still using the different browser, tick the tickbox. (You can now close the different browser)
        5. Back in the first browser, tick the tickbox.
        6. Note the course-module ID of the Page. For example if the URL is /mod/page/view.php?id=319 then the course-module ID is 319.
        7. Access the database directly and run this query (where 'mdl_' is your database prefix and 319 is the course-module ID):

        SELECT * FROM mdl_course_modules_completion WHERE coursemoduleid=319;

        The result will include 2 rows. This is a demonstration of the bug; the database is now in incorrect state. Note the IDs of the two rows (for example 13 and 14).

        AFTER UPGRADE

        1. Rerun the query above. You should find that of those two duplicates, the row with the lower ID (13 in my example) has been deleted and there is only one row now.
        2. Repeat steps 1-7 of the test above (note - this means you will create a second Page activity, not reuse the last one). This time, the query from step 7 should only return one row.
        Hide
        Eloy Lafuente (stronk7) added a comment - - edited

        Ho Sam,

        silly question. Why outer matching when the records you want are exactly those inner matching? I mean, I can see the point if you are looking for "cmc2.id IS NULL" but for NOT NULL ones?

        Also, note for integrators in case it is not provided, this must be integrated AFTER MDL-28032 and version must be > 2011062400.01 (master) and > 2011033003.08 (20_STABLE)

        Ciao

        Show
        Eloy Lafuente (stronk7) added a comment - - edited Ho Sam, silly question. Why outer matching when the records you want are exactly those inner matching? I mean, I can see the point if you are looking for "cmc2.id IS NULL" but for NOT NULL ones? Also, note for integrators in case it is not provided, this must be integrated AFTER MDL-28032 and version must be > 2011062400.01 (master) and > 2011033003.08 (20_STABLE) Ciao
        Hide
        Sam Marshall added a comment -

        Not silly question but silly developer! I have corrected the code to just use 'JOIN' and remove the condition. Re-pushed both branches.

        Note: after the change I tested that the upgrade doesn't give a db error, although I didn't actually have any rows for it to update so it wasn't a proper test, but I can't see how that change can have broken anything (famous last words). By the way, it is safe to run the upgrade multiple times.

        Show
        Sam Marshall added a comment - Not silly question but silly developer! I have corrected the code to just use 'JOIN' and remove the condition. Re-pushed both branches. Note: after the change I tested that the upgrade doesn't give a db error, although I didn't actually have any rows for it to update so it wasn't a proper test, but I can't see how that change can have broken anything (famous last words). By the way, it is safe to run the upgrade multiple times.
        Eloy Lafuente (stronk7) made changes -
        Status Waiting for integration review [ 10010 ] Integration review in progress [ 10004 ]
        Integrator stronk7
        Currently in integration Yes
        Hide
        Eloy Lafuente (stronk7) added a comment -

        Integrated thanks!

        Sam, I've cherry-picked those in order to fix conflicts with versions in your own commit, so surely your local history there (in the MDL-28021-master branch) won't match moodle.git anymore. Just experimenting differences with the 3-ways merging conflict way.

        Ciao

        Show
        Eloy Lafuente (stronk7) added a comment - Integrated thanks! Sam, I've cherry-picked those in order to fix conflicts with versions in your own commit, so surely your local history there (in the MDL-28021 -master branch) won't match moodle.git anymore. Just experimenting differences with the 3-ways merging conflict way. Ciao
        Eloy Lafuente (stronk7) made changes -
        Status Integration review in progress [ 10004 ] Waiting for testing [ 10005 ]
        Eloy Lafuente (stronk7) made changes -
        Status Waiting for testing [ 10005 ] Testing in progress [ 10011 ]
        Tester stronk7
        Hide
        Eloy Lafuente (stronk7) added a comment -

        Tested by introducing some dupe records before upgrade. They became properly deleted.

        Tested with 2 browsers after upgrade I cannot reproduce the dupes anymore. The unique gets updated properly.

        And unit tests passing too (106).

        So, passed! Thanks!

        Show
        Eloy Lafuente (stronk7) added a comment - Tested by introducing some dupe records before upgrade. They became properly deleted. Tested with 2 browsers after upgrade I cannot reproduce the dupes anymore. The unique gets updated properly. And unit tests passing too (106). So, passed! Thanks!
        Eloy Lafuente (stronk7) made changes -
        Status Testing in progress [ 10011 ] Tested [ 10006 ]
        Eloy Lafuente (stronk7) made changes -
        Affects Version/s 2.1 [ 10370 ]
        Affects Version/s 2.0 [ 10122 ]
        Affects Version/s 2.0.2 [ 10421 ]
        Hide
        Eloy Lafuente (stronk7) added a comment -

        Moode is now, for sure, a bit better thanks to you! This fix is now upstream.

        Show
        Eloy Lafuente (stronk7) added a comment - Moode is now, for sure, a bit better thanks to you! This fix is now upstream.
        Eloy Lafuente (stronk7) made changes -
        Status Tested [ 10006 ] Closed [ 6 ]
        Resolution Fixed [ 1 ]
        Currently in integration Yes
        Integration date 27/Jun/11
        Hide
        Sam Marshall added a comment -

        Unfortunately the unique index broke backup and restore of completion data I had forgotten it worked that way. Adding comment here just so there is a link back. MDL-28116.

        Show
        Sam Marshall added a comment - Unfortunately the unique index broke backup and restore of completion data I had forgotten it worked that way. Adding comment here just so there is a link back. MDL-28116 .
        Hide
        jai gupta added a comment -

        We have a database having 100 million entries in completion table. Query in this fix takes lot of time. For resolution we added a temporary index on userid, coursemoduleid and after all duplicate entries were deleted we dropped this index and then added an unique index on userid, coursemoduleid.

        Commenting here just for reference and notes.

        Show
        jai gupta added a comment - We have a database having 100 million entries in completion table. Query in this fix takes lot of time. For resolution we added a temporary index on userid, coursemoduleid and after all duplicate entries were deleted we dropped this index and then added an unique index on userid, coursemoduleid. Commenting here just for reference and notes.
        Hide
        Sam Marshall added a comment -

        Thanks Jai. Also congrats, you may possibly be the biggest user of the completion system

        As a second comparison point, we have 'only' 7.7 million entries in mdl_course_modules_completion here and I didn't have a performance problem with the update query, using PostgreSQL. On our live database, it takes just over 30 seconds. (I did test this back when I wrote this code...) So users with smaller systems are hopefully OK.

        Show
        Sam Marshall added a comment - Thanks Jai. Also congrats, you may possibly be the biggest user of the completion system As a second comparison point, we have 'only' 7.7 million entries in mdl_course_modules_completion here and I didn't have a performance problem with the update query, using PostgreSQL. On our live database, it takes just over 30 seconds. (I did test this back when I wrote this code...) So users with smaller systems are hopefully OK.

          People

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

            Dates

            • Created:
              Updated:
              Resolved: