Moodle
  1. Moodle
  2. MDL-25674

E-mail sent from course during cron.php results in the unenroll action for the enrol/database plugin being triggered for that course.

    Details

    • Type: Bug Bug
    • Status: Closed
    • Priority: Major Major
    • Resolution: Fixed
    • Affects Version/s: 2.0
    • Fix Version/s: 2.0.1
    • Component/s: Enrolments
    • Labels:
      None
    • Environment:
      WAMP, MySQL 5.051b, PHP 5.2.11
    • Database:
      MySQL
    • Affected Branches:
      MOODLE_20_STABLE
    • Fixed Branches:
      MOODLE_20_STABLE
    • Rank:
      15800

      Description

      Enrollments based on enrol/database are being dropped from courses during the cron.php run. This seems to occur only on courses which have an e-mail waiting to be sent, such as a subscribed forum post or news posting.

      Expected behavior: Enrol/database enrolls according to the external database, with no other effects.

      Actual behavior: Unenrollment (or other action set in enrol/database) occurs in courses with pending e-mails when cron.php is run.

      Steps to reproduce:
      1. Take a test course with database enrollments. Verify the user status as fully enrolled via external database.
      2. Post to news forum with "mail now" checked.
      3. Run admin/cron.php
      4. Refresh user page for course to see unenrollment has taken place.
      5. Run CLI script for enrol/database to restore prior enrollments.

      1. lib.php
        26 kB
        Bill Johnson

        Activity

        Hide
        Petr Škoda added a comment -

        It might be a problem hidden somewhere in public function sync_user_enrolments($user), because it gets executed when loading user information necessary for the mailing.

        Unfortunately I can not reproduce it on my test server, could you please try it on a fresh install of Moodle 2.0?

        Show
        Petr Škoda added a comment - It might be a problem hidden somewhere in public function sync_user_enrolments($user), because it gets executed when loading user information necessary for the mailing. Unfortunately I can not reproduce it on my test server, could you please try it on a fresh install of Moodle 2.0?
        Hide
        Bill Johnson added a comment -

        Replicated on fresh moodle 2 install. Using current weekly build with the changes to enrol/database/lib.php which we made yesterday, as well as removing line 294, "JOIN

        {enrol}

        e ON (e.courseid = c.id AND e.enrol = 'database')". (I don't fully understand the code here, but it appears to be requiring an enrolment plugin instance for database in the query, but the function is to add where it's not present. In practice it simply doesn't seem to reliably add the enrollment method with that line in place.)

        Show
        Bill Johnson added a comment - Replicated on fresh moodle 2 install. Using current weekly build with the changes to enrol/database/lib.php which we made yesterday, as well as removing line 294, "JOIN {enrol} e ON (e.courseid = c.id AND e.enrol = 'database')". (I don't fully understand the code here, but it appears to be requiring an enrolment plugin instance for database in the query, but the function is to add where it's not present. In practice it simply doesn't seem to reliably add the enrollment method with that line in place.)
        Hide
        Bill Johnson added a comment -

        Updated original report to include the lib.php I'm using for diff purposes.

        Show
        Bill Johnson added a comment - Updated original report to include the lib.php I'm using for diff purposes.
        Hide
        Petr Škoda added a comment -

        Please test it with the latest cvs or git checkout, do NOT remove any lines at all.

        Show
        Petr Škoda added a comment - Please test it with the latest cvs or git checkout, do NOT remove any lines at all.
        Hide
        Bill Johnson added a comment -

        Verified with GIT copy of lib.php.

        Show
        Bill Johnson added a comment - Verified with GIT copy of lib.php.
        Hide
        Petr Škoda added a comment -

        I have tried it once more, still works fine for me. Could you please try to add following new method to your enrol/database/lib.php

            public function unenrol_user(stdClass $instance, $userid) {
                debugging("unenrolling user $userid from course $instance->courseid");
                parent::unenrol_user($instance, $userid);
            }
        

        and enable debug mode in the site configuration. Hopefully it should print the exact code location where the users get unernolled when processing the cron forum mailing.

        Show
        Petr Škoda added a comment - I have tried it once more, still works fine for me. Could you please try to add following new method to your enrol/database/lib.php public function unenrol_user(stdClass $instance, $userid) { debugging( "unenrolling user $userid from course $instance->courseid" ); parent::unenrol_user($instance, $userid); } and enable debug mode in the site configuration. Hopefully it should print the exact code location where the users get unernolled when processing the cron forum mailing.
        Hide
        Bill Johnson added a comment -

        Lines inserted at line 44.

        Cron output:

        Server Time: Tue, 14 Dec 2010 12:17:27 -0500

        Cleaning up stale sessions
        Starting activity modules
        Processing module function assignment_cron ...... used 3 dbqueries
        ... used 0.061705112457275 seconds
        done.
        Processing module function forum_cron ...<br />
        <b>Notice</b>: Undefined property: stdClass::$idnumber in <b>C:\wamp\www\moodletest\enrol\database\lib.php</b> on line <b>100</b><br />
        Processing user 3
        0 users were sent post 5, 'test5'
        Starting digest processing...
        Cleaned old digest records
        ... used 59 dbqueries
        ... used 0.46035599708557 seconds
        done.
        Finished activity modules
        Starting blocks
        Finished blocks
        Starting quiz reports
        Finished quiz reports
        Starting admin reports
        Finished admin reports
        Starting main gradebook job ...
        done.
        Starting processing the event queue...
        done.
        Running clean-up tasks...
        Deleted old cache_text records
        checking for create_password
        Executed tag cron
        Cleaned up contexts
        Cleaned cache flags
        Built context paths
        Cleaned up read notifications
        Finished clean-up tasks...
        Checking automated backup status...INACTIVE
        Running auth crons if required...
        Running enrol crons if required...
        Running cron for enrol_cohort...
        Fetching external blog entries...Deleting blog associations linked to non-existent contexts...Starting registration update on hubs...
        Finished registration update on hubs.
        Deleting old draft files... Deleting session linked tokens more than one day old...done.
        Cron script completed correctly
        Execution took 1.133131 seconds

        Lines 95-105 of lib.php:
        $roles = array();
        foreach ($allroles as $role)

        { $roles[$role->$localrolefield] = $role->id; }

        $enrols = array(); //<---line 100
        $instances = array();

        $extdb = $this->db_init();

        // read remote enrols and create instances

        Show
        Bill Johnson added a comment - Lines inserted at line 44. Cron output: Server Time: Tue, 14 Dec 2010 12:17:27 -0500 Cleaning up stale sessions Starting activity modules Processing module function assignment_cron ...... used 3 dbqueries ... used 0.061705112457275 seconds done. Processing module function forum_cron ...<br /> <b>Notice</b>: Undefined property: stdClass::$idnumber in <b>C:\wamp\www\moodletest\enrol\database\lib.php</b> on line <b>100</b><br /> Processing user 3 0 users were sent post 5, 'test5' Starting digest processing... Cleaned old digest records ... used 59 dbqueries ... used 0.46035599708557 seconds done. Finished activity modules Starting blocks Finished blocks Starting quiz reports Finished quiz reports Starting admin reports Finished admin reports Starting main gradebook job ... done. Starting processing the event queue... done. Running clean-up tasks... Deleted old cache_text records checking for create_password Executed tag cron Cleaned up contexts Cleaned cache flags Built context paths Cleaned up read notifications Finished clean-up tasks... Checking automated backup status...INACTIVE Running auth crons if required... Running enrol crons if required... Running cron for enrol_cohort... Fetching external blog entries...Deleting blog associations linked to non-existent contexts...Starting registration update on hubs... Finished registration update on hubs. Deleting old draft files... Deleting session linked tokens more than one day old...done. Cron script completed correctly Execution took 1.133131 seconds Lines 95-105 of lib.php: $roles = array(); foreach ($allroles as $role) { $roles[$role->$localrolefield] = $role->id; } $enrols = array(); //<---line 100 $instances = array(); $extdb = $this->db_init(); // read remote enrols and create instances
        Hide
        Bill Johnson added a comment -

        My apologies...I screwed up on that one. Correct info below. (Too many Textmate windows open at once.)

        Lines pasted at line 44, before instance_deleteable.

        Cron Output:

        Server Time: Tue, 14 Dec 2010 12:37:50 -0500

        Cleaning up stale sessions
        Starting activity modules
        Processing module function assignment_cron ...... used 3 dbqueries
        ... used 0.072622060775757 seconds
        done.
        Processing module function chat_cron ...... used 5 dbqueries
        ... used 0.05665397644043 seconds
        done.
        Processing module function forum_cron ...<br />
        <b>Notice</b>: Undefined property: stdClass::$idnumber in <b>C:\wamp\www\moodletest\enrol\database\lib.php</b> on line <b>106</b><br />
        <div class="notifytiny">unenrolling user 3 from course 2* line 45 of \enrol\database\lib.php: call to debugging()

        • line 220 of \enrol\database\lib.php: call to enrol_database_plugin->unenrol_user()
        • line 217 of \lib\enrollib.php: call to enrol_database_plugin->sync_user_enrolments()
        • line 882 of \lib\sessionlib.php: call to enrol_check_plugins()
        • line 964 of \lib\sessionlib.php: call to session_set_user()
        • line 490 of \mod\forum\lib.php: call to cron_setup_user()
        • line 87 of \lib\cronlib.php: call to forum_cron()
        • line 79 of \admin\cron.php: call to cron_run()
          </div>Processing user 3
          0 users were sent post 6, 'test6'
          Starting digest processing...
          Cleaned old digest records
          ... used 59 dbqueries
          ... used 0.40010285377502 seconds
          done.
          Processing module function scorm_cron ...... used 1 dbqueries
          ... used 0.0070700645446777 seconds
          done.
          Finished activity modules
          Starting blocks
          Processing cron function for rss_client....
          0 feeds refreshed (took 0.022963 seconds)
          done.
          Finished blocks
          Starting quiz reports
          Finished quiz reports
          Starting admin reports
          Finished admin reports
          Starting main gradebook job ...
          done.
          Starting processing the event queue...
          done.
          Checking automated backup status...INACTIVE
          Running auth crons if required...
          Running enrol crons if required...
          Running cron for enrol_self...
          Running cron for enrol_cohort...
          Fetching external blog entries...Deleting blog associations linked to non-existent contexts...Starting registration update on hubs...
          Finished registration update on hubs.
          Deleting old draft files... Deleting session linked tokens more than one day old...done.
          Cron script completed correctly
          Execution took 1.128519 seconds

        Lines 101-111 of lib.php:
        $instances = array();

        $extdb = $this->db_init();

        // read remote enrols and create instances
        $sql = $this->db_get_sql($table, array($userfield=>$user->$localuserfield), array(), false); //line 106

        if ($rs = $extdb->Execute($sql)) {
        if (!$rs->EOF) {
        while ($fields = $rs->FetchRow()) {
        $fields = $this->db_decode($fields);

        Show
        Bill Johnson added a comment - My apologies...I screwed up on that one. Correct info below. (Too many Textmate windows open at once.) Lines pasted at line 44, before instance_deleteable. Cron Output: Server Time: Tue, 14 Dec 2010 12:37:50 -0500 Cleaning up stale sessions Starting activity modules Processing module function assignment_cron ...... used 3 dbqueries ... used 0.072622060775757 seconds done. Processing module function chat_cron ...... used 5 dbqueries ... used 0.05665397644043 seconds done. Processing module function forum_cron ...<br /> <b>Notice</b>: Undefined property: stdClass::$idnumber in <b>C:\wamp\www\moodletest\enrol\database\lib.php</b> on line <b>106</b><br /> <div class="notifytiny">unenrolling user 3 from course 2* line 45 of \enrol\database\lib.php: call to debugging() line 220 of \enrol\database\lib.php: call to enrol_database_plugin->unenrol_user() line 217 of \lib\enrollib.php: call to enrol_database_plugin->sync_user_enrolments() line 882 of \lib\sessionlib.php: call to enrol_check_plugins() line 964 of \lib\sessionlib.php: call to session_set_user() line 490 of \mod\forum\lib.php: call to cron_setup_user() line 87 of \lib\cronlib.php: call to forum_cron() line 79 of \admin\cron.php: call to cron_run() </div>Processing user 3 0 users were sent post 6, 'test6' Starting digest processing... Cleaned old digest records ... used 59 dbqueries ... used 0.40010285377502 seconds done. Processing module function scorm_cron ...... used 1 dbqueries ... used 0.0070700645446777 seconds done. Finished activity modules Starting blocks Processing cron function for rss_client.... 0 feeds refreshed (took 0.022963 seconds) done. Finished blocks Starting quiz reports Finished quiz reports Starting admin reports Finished admin reports Starting main gradebook job ... done. Starting processing the event queue... done. Checking automated backup status...INACTIVE Running auth crons if required... Running enrol crons if required... Running cron for enrol_self... Running cron for enrol_cohort... Fetching external blog entries...Deleting blog associations linked to non-existent contexts...Starting registration update on hubs... Finished registration update on hubs. Deleting old draft files... Deleting session linked tokens more than one day old...done. Cron script completed correctly Execution took 1.128519 seconds Lines 101-111 of lib.php: $instances = array(); $extdb = $this->db_init(); // read remote enrols and create instances $sql = $this->db_get_sql($table, array($userfield=>$user->$localuserfield), array(), false); //line 106 if ($rs = $extdb->Execute($sql)) { if (!$rs->EOF) { while ($fields = $rs->FetchRow()) { $fields = $this->db_decode($fields);
        Hide
        Bill Johnson added a comment -

        Problem is in /mod/forum/lib.php. Function is forum_subscribed_users (line 2801).

        Adding u.idnumber to the $fields (line 2814) variable ensures that the enrol/database/lib.php search doesn't come up empty.

        Tested and working here. Any unforeseen ramifications of that particular change?

        Show
        Bill Johnson added a comment - Problem is in /mod/forum/lib.php. Function is forum_subscribed_users (line 2801). Adding u.idnumber to the $fields (line 2814) variable ensures that the enrol/database/lib.php search doesn't come up empty. Tested and working here. Any unforeseen ramifications of that particular change?
        Hide
        Petr Škoda added a comment -

        arrrrggh, forum strikes back again! I have used user->id for the sync. I am going to add some detection there because the user object needs to be complete there.

        Thanks a lot!!

        Show
        Petr Škoda added a comment - arrrrggh, forum strikes back again! I have used user->id for the sync. I am going to add some detection there because the user object needs to be complete there. Thanks a lot!!
        Hide
        Bill Johnson added a comment -

        No problem! Thanks for all your help on this one. It's been a bit to pin down a test case, but I'm really glad we were able to find the source. Can you let me know when you've checked in the fix, or will the tracker do that automagically? Thanks again!

        -Bill

        Show
        Bill Johnson added a comment - No problem! Thanks for all your help on this one. It's been a bit to pin down a test case, but I'm really glad we were able to find the source. Can you let me know when you've checked in the fix, or will the tracker do that automagically? Thanks again! -Bill
        Hide
        Petr Škoda added a comment -

        The tracker will notify you, it will be most probably committed into new official git repository new Wednesday. patch will be available sometime later this week. Thanks again

        Show
        Petr Škoda added a comment - The tracker will notify you, it will be most probably committed into new official git repository new Wednesday. patch will be available sometime later this week. Thanks again
        Hide
        Petr Škoda added a comment -
        Show
        Petr Škoda added a comment - My progress can be tracked at https://github.com/skodak/moodle/compare/master...MDL-25674
        Hide
        Petr Škoda added a comment -

        committed, thanks for the report

        Show
        Petr Škoda added a comment - committed, thanks for the report

          People

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

            Dates

            • Created:
              Updated:
              Resolved: