Sensei: Learner is added twice to a Course or Lesson

[beags121]

Steps to Reproduce

Unknown - customer contacts support stating cannot reset lesson or quiz - questions completed 100% correct but system says user still needs 100%. Reset button appears but doesn't reset.

What I Expected

I expected to be able to do this manually for them

What Happened Instead

I discovered the user had been added to the lesson twice (only this lesson, 12 of 15), some minutes apart. I deleted the later addition and this cured the problem, all quiz buttons reappeared and user able to reset quiz and complete it.

PHP / WordPress / Sensei version

PHP 7.0.33-0+deb9u2.
Wordpress 5.2.2
Sensei LMS 2.1.2

Browser / OS version

[donnapep]

Hi there. It sounds like this may require some back and forth to learn more details about the issue and your site. It would be best to open a Support ticket and our Happiness Engineers will take good care of you. Thanks!

[lkraav]

I'm surprised to see this, as I thought https://github.com/Automattic/sensei/issues/1496 would've taken care of it.

OTOH, I've now still seen a rare occurrence of this double-add even after #1496 landed.

It might be related to site load spikes, and external object caches are probably involved. Something goes awry somewhere, but really difficult to put the finger on what, where and when.

[jennafarr]

Was this ever resolved? We are seeing this issue happen daily now. It started a few days ago. Maybe only to users with relatively slow internet connections. We didn't make any plugin or site changes but it could be that the site is a little busier.

[danjjohnson]

Issue occurring again in 2935642-zen

[lkraav]

I've had zero incidents with this for a long time.

Perhaps for these folks there are other over-eager wp_cache_flush() calling plugins in play?

[jom]

\Sensei_Utils::sensei_log_activity does a direct database check right before inserting a new comment. This could be a strange race condition, possibly related to MySQL replication to nodes or possibly query caching in MySQL.

From the sites I've seen, they often have very large {prefix}comments tables.

New theory, MyISAM sometimes has issues with selects immediately following inserts (without a table lock). From the ticket directly above, their {prefix}comments table was MyISAM and database is 5.5.5-10.1.35-MariaDB-cll-lve.

For other users with this issue, please post the following:

• MySQL version.
• Storage engine (MyISAM or InnoDB) of your {prefix}comments table.
• Estimated number of entries in your comments table.

One hack might be to try locking the {prefix}comments in sensei_log_activity_before and unlocking in sensei_log_activity_after.

[jennafarr]

Thank you for checking into this!

• MariaDB 10.1
• MyISAM
• Nearly 10 million rows in _commentmeta and 3 million rows in _comments.

This installation has been in place for about 5 years. Total students is 42,000. Sensei LMS version is 2.2.1

[jom]

For those who feel comfortable with the process, are able to take the site into maintenance mode temporarily, and do backups, switching to InnoDB might be worth considering for the {prefix}comments table. As always, I recommend testing this first on a staging site.

Some considerations: https://mariadb.com/kb/en/converting-tables-from-myisam-to-innodb/

[jennafarr]

After switching our database tables to InnoDB, the problem persists for us. Four users have been stuck in a lesson in the past 24 hours.

[jennafarr]

Do you have any other suggestions. So far we have removed data to get those tables down about 10% of their original size. Learners are still getting stuck. A few each day and it doesn't seem to correlate either with busier site activity.

[lkraav]

@jennafarr need more details on your setup. Any object cache?

[donnapep]

Received the following from a user:

We occasionally get duplicate comment entries for the same lesson and have to manually fix it.

There will usually either be one "in-progress" and one "complete" for the same user for the same lesson or two "in-progress" entries, which both block progress.

It's pretty rare, considering the number of lessons per day our users are completing, but it happens enough to wonder if there is an issue.

It happened more on AWS with WP on Lightsail and the db on RDS.

We wondered if db latency was causing it because the only similar issue we saw on GitHub was from years ago before the code to check for duplicate entries was added so we moved to Kinsta and, although the occurrences were significantly reduced, we still see them occasionally.

He then sent the following from his server log and wondered if it might be related:

2020/05/25 20:40:33 [error] 61606#61606: *137731 FastCGI sent in stderr: "PHP message: WordPress database error Deadlock found when trying to get lock; try restarting transaction for query UPDATE wpp6w5hh8g_actionscheduler_actions SET attempts = attempts+1, status='in-progress', last_attempt_gmt = '2020-05-25 20:40:28', last_attempt_local = '2020-05-25 13:40:28' WHERE action_id = 23198 made by do_action('wp_ajax_as_async_request_queue_runner'), WP_Hook->do_action, WP_Hook->apply_filters, WP_Async_Request->maybe_handle, ActionScheduler_AsyncRequest_QueueRunner->handle, do_action('action_scheduler_run_queue'), WP_Hook->do_action, WP_Hook->apply_filters, ActionScheduler_QueueRunner->run, ActionScheduler_QueueRunner->do_batch, ActionScheduler_Abstract_QueueRunner->process_action, ActionScheduler_DBStore->log_execution" while reading response header from upstream, client: 35.235.105.138, server: abc.com, request: "POST /wp/wp-admin/admin-ajax.php?action=as_async_request_queue_runner&nonce=f9f8c0cdf3 HTTP/1.0", upstream: "fastcgi://unix:/var/run/php7.3-fpm-abc.sock:", host: "abc.com", referrer: "https://abc.com/wp/wp-admin/admin-ajax.php?action=as_async_request_queue_runner&nonce=f9f8c0cdf3"

Note that I've changed the server name to be safe.

[jennafarr]

No, we don't have any object caching and no, we don't see anything that indicates that deadlocks are happening as Donna's user saw. We have been reading the Sensei release notes and we are just trying to get the site upgraded before troubleshooting more and seeing what happens but this continues on a daily basis. For reference we are running Sensei LMS 2.2.1 | WooCommerce Paid Courses 1.2.4. We have also "archived" millions of records thinking and still nothing improved.

[ludyamano]

Same problem here. This usually happens from 5-10X a day. This issue brings a lot of effort from support team to help "stuck" learners. We have to manually delete the duplicated record on DB (the one with "in-progress" status).

I can see Deadlock errors on log files as well:

[21-Aug-2020 12:57:15 UTC] Erro de banco de dados do WordPress Deadlock found when trying to get lock; try restarting transaction para a consulta UPDATE wp_actionscheduler_actions SET attempts = attempts+1, status='in-progress', last_attempt_gmt = '2020-08-21 12:57:14', last_attempt_local = '2020-08-21 09:57:14' WHERE action_id = 325080 feita por do_action_ref_array('action_scheduler_run_queue'), WP_Hook->do_action, WP_Hook->apply_filters, ActionScheduler_QueueRunner->run, ActionScheduler_QueueRunner->do_batch, ActionScheduler_Abstract_QueueRunner->process_action, ActionScheduler_DBStore->log_execution

Hosted on Pressable (uses Memcached object caching)
PHP 7.4
MariaDB
wp_comments table has 400k rows (innoDB)
wp_commentmeta table has 1.2M rows (innoDB)
WP 5.5
Sensei LMS 3.4.1
WooCommerce Paid Courses 2.1.0

[yscik]

SQL query to find duplications (shows just one of the rows, change the last > to != to show both):

SELECT c1.*, c2.comment_ID as c2_comment_ID 
FROM wp_comments c1, wp_comments c2 
WHERE c1.comment_type = "sensei_lesson_status" 
  AND c2.comment_type = "sensei_lesson_status" 
  AND c1.user_id = c2.user_id 
  AND c1.comment_post_ID = c2.comment_post_ID 
  AND c1.comment_ID > c2.comment_ID

And this should delete one of them:

DELETE FROM wp_comments c1 
INNER JOIN wp_comments c2 
  ON c1.comment_type = c2.comment_type 
  AND c1.user_id = c2.user_id  
  AND c1.comment_post_ID = c2.comment_post_ID 
  AND c1.comment_ID > c2.comment_ID 
WHERE c1.comment_type = "sensei_lesson_status"

[cena]

reported in 3223683-zen

Adding the info from the ticket:

10.3.24-MariaDB-cll-lve with Innodb
Number of table entries: 6187
Host: wiroos

[alastair-janestaffordtextiles]

Here's an example of a learner's duplicate lessons, if it's of any help:

[cena]

@yscik 2 users have commented that the second code block from your August 28th comment doesen't work for them, most recently in 3342464-zen. Can you confirm it works?

[alastair-janestaffordtextiles]

The SQL @yscik posted does work but can be slow on large tables.

To show duplicate courses and lessons, I've used:

SELECT DISTINCT c.user_id, u.user_email, c.comment_post_ID, c.comment_type, p.post_title, COUNT(*) AS RecordCount
FROM wp_comments AS c
LEFT JOIN wp_users AS u ON c.user_id = u.ID
LEFT JOIN wp_posts AS p ON c.comment_post_ID = p.ID
WHERE c.comment_type IN ("sensei_course_status", "sensei_lesson_status")
GROUP BY c.user_id, u.user_email, c.comment_post_ID, c.comment_type, p.post_title
HAVING COUNT(*) > 1;

[gkaragia]

Hey @cena I prepared a revised version of the queries. To delete the rows we need to create a temporary table. So the following creates the table with ids of all comments which have a duplicate:

CREATE TEMPORARY TABLE comments_to_delete
SELECT 
    DISTINCT c2.comment_ID
FROM 
    wp_comments c1
    INNER JOIN wp_comments c2 
        ON c1.comment_type = c2.comment_type
        AND c1.user_id = c2.user_id 
        AND c1.comment_post_ID = c2.comment_post_ID 
WHERE 
      c1.comment_type IN ( 'sensei_lesson_status', 'sensei_course_status' )
  AND c1.comment_ID > c2.comment_ID;

and then actually delete the comments:

DELETE FROM wp_comments WHERE comment_id IN ( SELECT comment_ID FROM comments_to_delete );

DROP TEMPORARY TABLE comments_to_delete;

We should be cautious when suggesting this to the users though and notify them to definitely try it to a testing site first.

[jondcampbell]

Would it be a bad/crazy idea for Sensei to fix the status comments if it finds more than one row for a user & lesson/course/quiz combo? Instead of it getting confused by the multiple rows it could delete down to only one row and try again?

BTW, had this happen 3 times in the last week with quizzes hadn't had it in a while before then.

[jennafarr]

Here is what we did to address this for now. Not ideal but it's helped cut down on support calls. We have this wrapped in a cli-command that we run on a schedule of every 15 minutes so that's the longest a learner stays "stuck". Change "[email protected]" to your support email or whoever might want to get a notice when a learner has been stuck and the duplicate entry deleted:

function remove_duplicate_lesson_entries() {
    global $wpdb;
    $sql = $wpdb->prepare("delete from $wpdb->comments where comment_ID in (select comment_ID from (select comment_post_ID, max(comment_ID) as comment_ID 
        from (SELECT c.comment_post_ID, c.comment_ID from $wpdb->comments c join (select comment_post_ID, comment_type, user_id, count(comment_post_ID) 
        from $wpdb->comments where comment_type in ('sensei_lesson_status') group by comment_post_ID, comment_type, user_id having count(comment_post_ID) > 1) as t 
        where c.comment_post_ID = t.comment_post_ID and c.comment_type = t.comment_type and c.user_id = t.user_id) as p group by comment_post_ID) as d)");
    $result = $wpdb->query($sql);
    if ($result) {
        $entry_text = ($result == 1) ? 'entry has' : 'entries have';
        wp_mail('[email protected]', sprintf('Duplicate lesson entry removal at %s', date('Y-m-d H:i:s')), 
        sprintf("The process for finding duplicate lesson entries has completed; %d duplicate lesson %s been removed.\n\nRegards,\nYour friendly neighborhood wp-cli", $result, $entry_text));
    }
}

[yscik]

I created a snippet that should prevent duplicated entries causing any harm. It doesn't delete them, and there will be still some inaccuracies in the admin side, like In Progress count for a lesson, but it should handle users getting stuck:

add_filter( 'sensei_check_for_activity', 'sensei_filter_duplicate_user_status' );

function sensei_filter_duplicate_user_status( $comments ) {
    if(! is_array($comments)) {
        return $comments;
    }

    $found    = [];
    $filtered = [];
    foreach ( $comments as $comment ) {
        $key = $comment->comment_post_ID . '-' . $comment->comment_type . '-' . $comment->user_id;
        if ( empty( $found[ $key ] ) ) {
            $filtered[] = $comment;
        }
        $found[ $key ] = true;
    }
    return $filtered;
}

[visionistics]

This lesson duplication problem has plagued us for months. We have over 7,000 learners so it is a big problem. It prevents a learner from marking lesson complete or completing a course.

We USED to be able to fix it though LEARNER MANAGEMENT by LESSON. We would search for the learner in a specific lesson and click REMOVE FROM LESSON on the "IN PROGRESS" dupe. We've just discovered that feature no longer exists. Now the only option available is RESET PROGRESS, which does NOT fix the problem.

I'm not a database expert so the SQL queries worry me. Any ideas very welcome!

[donnapep]

We'll need to spend some more time investigating this one and either figure out what the problem is and fix it, or at least try to mitigate it as per https://github.com/Automattic/sensei/issues/2748#issuecomment-706750791.

[jennafarr]

@donnapep - Thanks for putting this as priority! Just to provide a little more information. We have never been able to replicate the issue in our development environment and we have had it happen to users in lessons with quizzes and lessons without. We also capture their browser/OS and we find that it happens across a variety. Hope that helps and thanks again for looking into this.

[visionistics]

Thank you @donnapep. Just to clarify, the duplicated learner in a lesson is annoying, but the more urgent issue is that there is no longer way to delete the duplicated record. The duplicated record prevents a learner from being able to mark a lesson or course complete. (This is a big deal in corporate training)

In the past, we could delete the dupe record in LEARNER MANAGEMENT. Then instantly, the lesson/course would be complete.

For some reason, the option to REMOVE A LEARNER from a LESSON no longer exists. Now the only option is RESET PROGRESS which does not solve the problem.

So... what we really need is to get back the ability to remove a duplicated learner from a lesson. Or, if there is some workaround, I'd love to know.

In the meantime, we have THOUSANDS of learners who cannot complete a course or lesson, and we no longer have a way to fix it. And learners have no way to get their certificates as a result. Huge thanks in advance for any ideas!

[donnapep]

@visionistics As a workaround, you may want to try installing the Code Snippets plugin and then adding this snippet of code.

[visionistics]

Wow! Thank you so much! You are a sanity-saver.

[cena]

3499919-zen

[cena]

https://wordpress.org/support/topic/multiple-in-progress-statuses-for-same-lession

[cena]

3538100-zen

[renatho]

Since we created 3 PRs (https://github.com/Automattic/sensei/pull/3838, https://github.com/Automattic/sensei/pull/3855, https://github.com/Automattic/sensei/pull/3857) trying to mitigate this issue, I'm closing it. If it happens again, we can re-open it.