Removing Unconfirmed Users - Cron job issues

Removing Unconfirmed Users - Cron job issues

by Todd Kurth -
Number of replies: 5

I have users creating accounts on our site but not confirming their accounts (they used the wrong email address, etc). I have it currently set to remove unconfirmed accounts after one hour. There are accounts which have been there for days. I looked at the Scheduled Tasks and it says it is being run every hour without problems. If I run this command on the server (php schedule_task.php --execute=\\core\\task\\delete_unconfirmed_users_task)


Scheduled task: Delete unconfirmed users
... used 1 dbqueries
... used 0.0084500312805176 seconds
Task completed.

I get the above yet nothing is removed. I'm not sure what is wrong. Running the cron.php from the server produces the following:

Server Time: Mon, 31 Aug 2015 19:03:48 -0400


Execute scheduled task: Cleanup old sessions
... started 19:03:48. Current memory use 18.3MB.
... used 8 dbqueries
... used 0.011120080947876 seconds
Scheduled task complete: Cleanup old sessions
Execute scheduled task: Send new user passwords
... started 19:03:48. Current memory use 19.6MB.
... used 1 dbqueries
... used 0.00074601173400879 seconds
Scheduled task complete: Send new user passwords
Execute scheduled task: Send failed login notifications
... started 19:03:48. Current memory use 19.7MB.
... used 2 dbqueries
... used 0.0010101795196533 seconds
Scheduled task complete: Send failed login notifications
Execute scheduled task: Legacy cron processing for plugins
... started 19:03:48. Current memory use 19.8MB.
Running auth crons if required...
Running enrol crons if required...
Running cron for enrol_manual...
Verifying manual enrolment expiration...
...manual enrolment updates finished.
manual enrolment expiry notifications were already sent today at Monday, August 31, 2015, 6:00 AM.
Running cron for enrol_self...
Verifying self-enrolments...
...user self-enrolment updates finished.
No expired enrol_self enrolments detected
self enrolment expiry notifications were already sent today at Monday, August 31, 2015, 6:00 AM.
Starting activity modules
Processing module function assign_cron ...
... used 4 dbqueries
... used 0.08845591545105 seconds
done.
Processing module function quiz_cron ...

  Looking for quiz overdue quiz attempts...
  Considered 0 attempts in 0 quizzes.
Starting quiz reports
Finished quiz reports
... used 2 dbqueries
... used 0.032218933105469 seconds
done.
Processing module function workshop_cron ...
 processing workshop subplugins ...
Starting workshop allocation methods
Processing cron function for workshopallocation_scheduled...
... started 19:03:48. Current memory use 36.1MB.
... no workshops awaiting scheduled allocation. done. (1 dbqueries, 0 seconds)
Finished workshop allocation methods
... used 6 dbqueries
... used 0.014323949813843 seconds
done.
Finished activity modules
Starting blocks
Processing cron function for recent_activity....done.
Finished blocks
Starting admin reports
Finished admin reports
Starting course reports
Finished course reports
Starting gradebook plugins
Finished gradebook plugins
Starting repository plugins
Processing cron function for repository_dropbox...
... started 19:03:48. Current memory use 43.8MB.
done. (1 dbqueries, 0 seconds)
Processing cron function for repository_filesystem...
... started 19:03:48. Current memory use 43.8MB.
done. (3 dbqueries, 0 seconds)
Finished repository plugins
... used 31 dbqueries
... used 0.24193596839905 seconds
Scheduled task complete: Legacy cron processing for plugins
Execute scheduled task: Background processing for gradebook
... started 19:03:49. Current memory use 43.9MB.
... used 2 dbqueries
... used 0.001823902130127 seconds
Scheduled task complete: Background processing for gradebook
Execute scheduled task: Background processing for events
... started 19:03:49. Current memory use 43.9MB.
... used 2 dbqueries
... used 0.00078296661376953 seconds
Scheduled task complete: Background processing for events
Execute scheduled task: Calculate completion data
... started 19:03:49. Current memory use 43.9MB.
... used 7 dbqueries
... used 0.010979890823364 seconds
Scheduled task complete: Calculate completion data
Execute scheduled task: Background processing for portfolio plugins
... started 19:03:49. Current memory use 44.3MB.
... used 0 dbqueries
... used 4.7206878662109E-5 seconds
Scheduled task complete: Background processing for portfolio plugins
Execute scheduled task: Background processing for plagiarism plugins
... started 19:03:49. Current memory use 44.3MB.
... used 0 dbqueries
... used 0.00056600570678711 seconds
Scheduled task complete: Background processing for plagiarism plugins
Execute scheduled task: Send calendar notifications
... started 19:03:49. Current memory use 44.4MB.
Updating calendar subscriptions:
... started 19:03:49. Current memory use 45.3MB.
Finished updating calendar subscriptions.
... used 1 dbqueries
... used 0.0056741237640381 seconds
Scheduled task complete: Send calendar notifications
Execute scheduled task: Sync external blogs
... started 19:03:49. Current memory use 45.3MB.
... used 1 dbqueries
... used 0.0060508251190186 seconds
Scheduled task complete: Sync external blogs
Execute scheduled task: Background processing for question engine
... started 19:03:49. Current memory use 45.8MB.

  Cleaning up old question previews...done.

  Cleaning up old question statistics cache records...done.
... used 6 dbqueries
... used 0.0041120052337646 seconds
Scheduled task complete: Background processing for question engine
Execute scheduled task: Forum mailings and maintenance jobs
... started 19:03:49. Current memory use 47MB.
Starting digest processing...
Cleaned old digest records
... used 4 dbqueries
... used 0.018473863601685 seconds
Scheduled task complete: Forum mailings and maintenance jobs
Execute scheduled task: Incoming email pickup
... started 19:03:49. Current memory use 47.3MB.
Inbound Message not fully configured - exiting early.
... used 0 dbqueries
... used 0.001723051071167 seconds
Scheduled task complete: Incoming email pickup
Execute scheduled task: Removes any unnecessary event monitor events
... started 19:03:49. Current memory use 47.6MB.
... used 0 dbqueries
... used 0.00013399124145508 seconds
Scheduled task complete: Removes any unnecessary event monitor events
Cron script completed correctly
Cron completed at 19:03:49. Memory used 47.6MB.
Execution took 0.403075 seconds

I'm lost to what I'm missing and would appreicate any help. The log above doesn't even mention unconfirmed accounts. Currently at 300 users with two teachers, expected to grow by another 18+ teachers very soon and need this under control. Thank you!



Average of ratings: -
In reply to Todd Kurth

Re: Removing Unconfirmed Users - Cron job issues

by Robert Brenstein -
Do you expect to have those record actually removed? Moodle does not do that. It marks them as deleted but the records stay for the sake of database consistency.
In reply to Robert Brenstein

Re: Removing Unconfirmed Users - Cron job issues

by Todd Kurth -

They don't have to be actually deleted, but on the list of users in the admin tab the account stays, never removes itself and has the "Confirm" link next to their name.

In reply to Todd Kurth

Re: Removing Unconfirmed Users - Cron job issues

by Robert Brenstein -
Have you looked those records up in the database? Column deleted.
Have you checked the server logs for errors? Moodle debugging must be on.
Have you tried setting the deletion threshold to 1 or 2 days? Maybe 1 hr is too short.
In reply to Robert Brenstein

Re: Removing Unconfirmed Users - Cron job issues

by Todd Kurth -

So I've made changes and still the account exists. I've set it for 1 day or 2 days, nothing is removed. The column in the database does not show as being marked deleted either. The cron job lists it is running a query to remove unconfirmed accounts. I'm baffled. I didn't see anything inside of any logs, though I'll be honest not sure if I was looking in the correct places.

In reply to Todd Kurth

Re: Removing Unconfirmed Users - Cron job issues

by Carles Bellver -

We have recently noticed this same problem: unconfirmed users are not being deleted by the cron task when it is executed. Our database shows more than one hundred users with confirmed = 0, deleted = 0 since our last upgrade from Moodle 2.7.

We have checked the code in lib/classes/task/delete_unconfirmed_users_task.php and this is the SQL query that retrieves the users to be deleted:

$rs = $DB->get_recordset_sql ("SELECT * FROM {user} WHERE confirmed = 0 AND firstaccess > 0 AND firstaccess < ? AND deleted = 0", array($cuttime));

($cuttime is current time - deleteunconfirmed threshold, 7 days by default.)

But the problem is that these users have firstaccess = 0 in DB, because login/signup.php sets $user->firstaccess = 0 when the account is created, so that the AND condition is never matched. And this didn't happen before upgrading because we have found that in Moodle 2.7 login/signup.php set $user->firstaccess = time(), i. e. account creation time, not zero.

So we think we have a bug and I have filed one in the Tracker. Could you please have a look there and vote?

[MDL-54106] Delete unconfirmed users not working because firstaccess == 0