sync_users.php stops with db error

Re: sync_users.php stops with db error

by Sam Stevens -
Number of replies: 38
They are two different scripts doing two different things. So entirely possible for one to work and not the other.


Most common cause for auth/ldap/cli/sync_users.php failing is extended or dodgy characters in the ldap account details.  Try setting $CFG->extendedusernamechars = true; in config.php and see what happens.


Also check out the lukas.spacy account for anything odd like white space in their name. Things like that. Check the account directly after as well as sometimes it can give an error and those details but the actual problem is with fetching the next one.

In reply to Sam Stevens

Re: sync_users.php stops with db error

by Robin Schröder -
Hi Sam,

thanks for the reply.

I tried the following steps to get more informations about the problem:

  1. i deleted the user "lukas.spacey" from the moodle-user-table. Also i deleted the users before and after "lukas.spacey" (User-ID +/- 1)
  2. i startet the sync_users.php script again and watched the table ("SELECT [name] FROM tempdb.sys.tables WHERE [name] like '#m20_tmp_extuser%'"). U can see that the tmp-table "tmp_extuser" will be created. It get dropped after the database-writing-error in the php.script
  3. the same error occurs although the user "lukas.spacey" is completly deleted (he is not flaged as deleted , he is completly deleted).

I don´t understand, why the script aborts with the same error, although the user doesnt exists anymore...


Here is the error code:

---------------------------------------------------------------

root@vmoodlet01:/home/administrator# /usr/bin/php /srv/www/auth/ldap/cli/sync_users.php >> /home/administrator/log_sync_user_15_06_2016_1.txt &
[1] 53652
root@vmoodlet01:/home/administrator# PHP Warning:  Module 'mysqli' already loaded in Unknown on line 0
PHP Notice:  Undefined property: stdClass::$dataroot in /srv/www/config.php on line 66
[AUTH LDAP] The users sync cron has been deprecated. Please use the scheduled task instead.
Default exception handler: Fehler beim Schreiben der Datenbank Debug: The statement has been terminated.
INSERT INTO #m20_tmp_extuser (username,mnethostid)  VALUES (?,?)
[array (
  0 => 'lukas.spacek',
  1 => '1',
)]
Error code: dmlwriteexception
* line 446 of /lib/dml/moodle_database.php: dml_write_exception thrown
* line 282 of /lib/dml/mssql_native_moodle_database.php: call to moodle_database->query_end()
* line 926 of /lib/dml/mssql_native_moodle_database.php: call to mssql_native_moodle_database->query_end()
* line 1060 of /auth/ldap/auth.php: call to mssql_native_moodle_database->insert_record_raw()
* line 749 of /auth/ldap/auth.php: call to auth_plugin_ldap->ldap_bulk_insert()
* line 70 of /auth/ldap/cli/sync_users.php: call to auth_plugin_ldap->sync_users()

Potential coding error - existing temptables found when disposing database. Must be dropped!
^C
[1]+  Exit 1                  /usr/bin/php /srv/www/auth/ldap/cli/sync_users.php >> /home/administrator/log_sync_user_15_06_2016_1.txt
root@vmoodlet01:/home/administrator#

root@vmoodlet01:/home/administrator# /usr/bin/php /srv/www/auth/ldap/cli/sync_users.php >> /home/administrator/log_sync_user_15_06_2016_1.txt &
[1] 53652
root@vmoodlet01:/home/administrator# PHP Warning:  Module 'mysqli' already loaded in Unknown on line 0
PHP Notice:  Undefined property: stdClass::$dataroot in /srv/www/config.php on line 66
[AUTH LDAP] The users sync cron has been deprecated. Please use the scheduled task instead.
Default exception handler: Fehler beim Schreiben der Datenbank Debug: The statement has been terminated.
INSERT INTO #m20_tmp_extuser (username,mnethostid)  VALUES (?,?)
[array (
  0 => 'lukas.spacek',
  1 => '1',
)]
Error code: dmlwriteexception
* line 446 of /lib/dml/moodle_database.php: dml_write_exception thrown
* line 282 of /lib/dml/mssql_native_moodle_database.php: call to moodle_database->query_end()
* line 926 of /lib/dml/mssql_native_moodle_database.php: call to mssql_native_moodle_database->query_end()
* line 1060 of /auth/ldap/auth.php: call to mssql_native_moodle_database->insert_record_raw()
* line 749 of /auth/ldap/auth.php: call to auth_plugin_ldap->ldap_bulk_insert()
* line 70 of /auth/ldap/cli/sync_users.php: call to auth_plugin_ldap->sync_users()

Potential coding error - existing temptables found when disposing database. Must be dropped!
^C
[1]+  Exit 1                  /usr/bin/php /srv/www/auth/ldap/cli/sync_users.php >> /home/administrator/log_sync_user_15_06_2016_1.txt
root@vmoodlet01:/home/administrator#

---------------------------------------------------------------


What else can i try? smile


Regards,

Robin

In reply to Robin Schröder

Re: sync_users.php stops with db error

by Emma Richardson -
Picture of Documentation writers Picture of Particularly helpful Moodlers Picture of Plugin developers

The error is coming from the account in AD, not the account in Moodle so deleting the Moodle account will not do anything.  You need to fix the issue in AD.  In addition to the previous suggestions, you might also check that the display name is filled in AD - I find that is often an issue.

In reply to Robin Schröder

Re: sync_users.php stops with db error

by Olumuyiwa Taiwo -
Picture of Plugin developers

Robin,

I suspect you are facing  multiple issues.

Your script is throwing a PHP notice:

PHP Notice:  Undefined property: stdClass::$dataroot in /srv/www/config.php on line 66

That makes me suspect someone has been fiddling with your config.php and somehow corrupted the $CFG variable

Also, the part of your error message that says:

INSERT INTO #m20_tmp_extuser (username,mnethostid)  VALUES (?,?)

indicates that $CFG->prefix has been set to '#m20_'. That's a very unusual value to set that variable to. In fact, my guess is that someone has tried to comment something out in config.php and has placed a "#" in front of 'm20_' which is probably what $CFG->prefix is intended to be set to.

In short, I'll suggest you carefully examine your config.php and make sure there are no spurious characters.


In reply to Olumuyiwa Taiwo

Re: sync_users.php stops with db error

by Robin Schröder -

Hi Olumuyiwa,

the config.php should be okay @line 66:

Line 65:   $CFG->lock_factory = "\\core\\lock\\file_lock_factory";
Line 66:   $CFG->lock_file_root = $CFG->dataroot . '/lock';

These parameters do not influence the sync-script i think.

The prefix ist 'm20_' without the '#'. The '#' only marks m20_tmp_extuser as teporary table.


I could identify some more AD-accounst which cause the error.

I added screenshots of their AD-atributes, perhaps u can see the problem there.


-Robin

Attachment buehler.png
Attachment hiller.png
In reply to Robin Schröder

Re: sync_users.php stops with db error

by Olumuyiwa Taiwo -
Picture of Plugin developers
Hi Robin,

You are correct in saying that the variables defined in lines 65 and 66 of config.php do not affect the sync script. However the error message regarding a variable that the script expects to have been defined earlier in config.php indicates that there is something wrong with the config.php, possibly someone modifying it and commenting out the definition of that variable.

Also, there is nowhere in the auth/ldap/auth.php where a '#' is prepended to the table name prefix for the purposes of indicating that it is a temporary table. And the script shouldn't have to since it is quite capable of knowing the name of a table it has created itself.

As I said, my suspicion is that the '#' has been put into config.php - possibly by someone trying to troubleshoot something.

In fact, I would go as far as guessing that your auth/ldap/cli/sync_users.php might have been modified and is now pointing to a config.php that has itself been modified.

Do you know whether someone has been poking around in your Moodle source files?

In reply to Olumuyiwa Taiwo

Re: sync_users.php stops with db error

by Robin Schröder -

This user-account seems to work. The sync-script doesn´t cause an error:


But i don´t see any big difference to the 2 other ones that cause the error...

In reply to Robin Schröder

Re: sync_users.php stops with db error

by Emma Richardson -
Picture of Documentation writers Picture of Particularly helpful Moodlers Picture of Plugin developers

Check that there are no random spaces in their name or email address.  I notice that these two do not have Attribute2 which appears to be a backup email - is this perhaps a mapped field in your ldap setting?

Also, check to see if they already have an account in Moodle.  If so, is it set to LDAP?  Is it suspended?

In reply to Emma Richardson

Re: sync_users.php stops with db error

by Sam Stevens -

and as i said orginally have you set $CFG->extendedusernamechars = true; ?

In reply to Sam Stevens

Re: sync_users.php stops with db error

by Robin Schröder -

Yes, i added $CFG->extendedusernamechars = true; to my config.php.

In reply to Robin Schröder

Re: sync_users.php stops with db error

by Iñaki Arenaza -
Picture of Core developers Picture of Documentation writers Picture of Particularly helpful Moodlers Picture of Peer reviewers Picture of Plugin developers
While this might be a problem later in the sync process, the problem you are having happens way before Moodle even tries to check for valid names.

This particular error triggers very early in the process, when Moodle is building the list of external users that are available in the LDAP server (I know it from the reference to
auth_plugin_ldap->ldap_bulk_insert() in your exception stack trace).

At that particular point, it doesn't impose any constraints on the usernames. The only constraint (and this is enforced by the database itself!) is that the pair (username, mnethostid) is unique, when building the external users list in a temporary table in the database.

In this particular case the value of mnethostid is always the same for all users (it's $CFG->mnet_localhost_id actually). So I would say that, somehow, you get the same external username twice. Are you using several contexts in your LDAP settings? And have you "Search subcontexts" enabled?

Also, what attribute are you using for the "User attribute" setting?

Saludos.
Iñaki.
In reply to Iñaki Arenaza

Re: sync_users.php stops with db error

by Gus Hagelberg -

Hi,

I have a similar error message when running

php sync_users.php from /home/relax/htdocs/moodle/auth/ldap/cli

similar I get the following error message:

PHP Warning:  PHP Startup: Invalid library (maybe not a PHP library) 'opcache.so' in Unknown on line 0

Verbindung zum LDAP-Server aufbauen...Temporäre Tabelle tmp_extuser erstellen

((Making connection to LDAP Server... Creating temporary table tmp_extuser))

PHP Warning:  ldap_list(): Search: Critical extension is unavailable in /home/relax/htdocs/moodle/auth/ldap/auth.php on line 729

Kein Nutzerkonto über LDAP einlesbar! Fehler?Potential coding error - existing temptables found when disposing database. Must be dropped!

((No user account readable through LDAP. Error))

Sorry for the German. Translation in in paratheses.

The following changes didn't help:

  •        Changed “Search subcontexts” to yes in ldap server settings
  •         Changed user attribute from “uid” to empty
  •         Added “$CFG->extendedusernamechars = true;” to config.php 


I am running Moodle 2.9.4 on a Debian 7 machine.

In reply to Gus Hagelberg

Re: sync_users.php stops with db error

by Dave Perry -
Picture of Testers

I don't have experience with sync_users, but can tell you for nothing that changing the user attribute field to nothing is a gamble on the surface.

Doing that makes moodle assume the username in a network profile is in attribute 'cn' - and if that is not the case in your system, that will just make things worse.
In AD for example, ObjectGUID is a weird concoction (that you wouldn't expect anyone to remember) and sAMAccountName is the proper 'username' field.

In reply to Dave Perry

Re: sync_users.php stops with db error

by Gus Hagelberg -

That was only a test. User attribute is again set to "Uid".

Thanks

In reply to Gus Hagelberg

Re: sync_users.php stops with db error

by Emma Richardson -
Picture of Documentation writers Picture of Particularly helpful Moodlers Picture of Plugin developers

What version of PHP are you using?  Is LDAP login working?  Is this a MSAD ldap server?

In reply to Emma Richardson

Re: sync_users.php stops with db error

by Gus Hagelberg -

Hi,

We have php 5.4.45.

I was wondering if php memory limit could be a cause. Its currently set to 512MB.

I have around 10,000 users. Don't know if that's a problem.

The error message mentions a tmp_extuser table. Perhaps this is part of the problem.

In reply to Gus Hagelberg

Re: sync_users.php stops with db error

by Emma Richardson -
Picture of Documentation writers Picture of Particularly helpful Moodlers Picture of Plugin developers

I have seen that error many times - normally though it stalls out after a specific user and it is due to something funky like a space in their username.

Can an LDAP user login?

In reply to Emma Richardson

Re: sync_users.php stops with db error

by Gus Hagelberg -

LDAP users can log in. User are authenticated against our LDAP server.

In reply to Gus Hagelberg

Re: sync_users.php stops with db error

by Emma Richardson -
Picture of Documentation writers Picture of Particularly helpful Moodlers Picture of Plugin developers

When I look at that area in the ldap file (line 729), part of that section actually references cookies.  I wonder if your ldap server is blocking that...hopefully Inaki can help here - I am more of a MSAD person and I have never seen this specific error before.

In reply to Emma Richardson

Re: sync_users.php stops with db error

by Gus Hagelberg -

Some more information to my problem. With -F I get more info to the error.

php -F sync_users.php

--Returns

PHP Warning:  PHP Startup: Invalid library (maybe not a PHP library) 'opcache.so' in Unknown on line 0

Verbindung zum LDAP-Server aufbauen...Temporäre Tabelle tmp_extuser erstellenPHP Warning:  ldap_list(): Search: Critical extension is unavailable in /home/relax/htdocs/moodle/auth/ldap/auth.php on line 729
Warning: ldap_list(): Search: Critical extension is unavailable in /home/relax/htdocs/moodle/auth/ldap/auth.php on line 729

Kein Nutzerkonto über LDAP einlesbar! Fehler?

PHP Notice:  Constant CLI_SCRIPT already defined in /home/relax/htdocs/moodle/auth/ldap/cli/sync_users.php on line 49

Notice: Constant CLI_SCRIPT already defined in /home/relax/htdocs/moodle/auth/ldap/cli/sync_users.php on line 49

PHP Notice:  Undefined property: stdClass::$dirroot in /home/relax/htdocs/moodle/auth/ldap/cli/sync_users.php on line 52

Notice: Undefined property: stdClass::$dirroot in /home/relax/htdocs/moodle/auth/ldap/cli/sync_users.php on line 52

PHP Warning:  require_once(/course/lib.php): failed to open stream: No such file or directory in /home/relax/htdocs/moodle/auth/ldap/cli/sync_users.php on line 52

Warning: require_once(/course/lib.php): failed to open stream: No such file or directory in /home/relax/htdocs/moodle/auth/ldap/cli/sync_users.php on line 52

PHP Fatal error:  require_once(): Failed opening required '/course/lib.php' (include_path='/home/relax/htdocs/moodle/lib/zend:/home/relax/htdocs/moodle/lib/pear:.:/usr/share/php:/usr/share/pear') in /home/relax/htdocs/moodle/auth/ldap/cli/sync_users.php on line 52

Fatal error: require_once(): Failed opening required '/course/lib.php' (include_path='/home/relax/htdocs/moodle/lib/zend:/home/relax/htdocs/moodle/lib/pear:.:/usr/share/php:/usr/share/pear') in /home/relax/htdocs/moodle/auth/ldap/cli/sync_users.php on line 52


In reply to Gus Hagelberg

Re: sync_users.php stops with db error

by Gus Hagelberg -

After that I added

$CFG->dirroot   = '/home/relax/htdocs/moodle';

to config.php

After that the error path error seems to be gone, but then I get 


[AUTH LDAP] Plugin not enabled!

In reply to Gus Hagelberg

Re: sync_users.php stops with db error

by Olumuyiwa Taiwo -
Picture of Plugin developers

You could check that:

  1. your LDAP server supports paged results
  2. you haven't set the page size setting in your LDAP settings higher than the number of entries returned by your server in response to a single query

Something else you may want to look at is the protocol version supported by your LDAP server

You may need to talk to your LDAP administrator to get answers to those questions.


In reply to Olumuyiwa Taiwo

Re: sync_users.php stops with db error

by Gus Hagelberg -

Thanks Olumuyiwa

paged results is supported as far as I know

I tried different page size settings in the LDAP Settings in Moodle. I tried 20, 250 and 10000 without any success.


The LDAP Version is

Sun-Directory-Server/11.1.1.7.2 B2014.1030.2115 64-bit

What did you mean with protocol version? Which protocol and where can we find that?


In reply to Gus Hagelberg

Re: sync_users.php stops with db error

by Gus Hagelberg -

Above you were talking about issues regarding the config.php. I wanted to show you a (cleaned up) copy of my config.php. Perhaps this helps. I am not using most of the above-mentioned variables.


<?php  // Moodle configuration file

unset($CFG);
global $CFG;
$CFG = new stdClass();

$CFG->dbtype    = 'mysqli';
$CFG->dblibrary = 'native';
$CFG->dbhost    = 'xxxxxxxx';
$CFG->dbname    = 'xxxxxxxx';
$CFG->dbuser    = 'xxxxxxx';
$CFG->dbpass    = 'xxxxxxx';
$CFG->prefix    = 'mdl_';
$CFG->dboptions = array (
  'dbpersist' => 0,
  'dbsocket' => 0,
);

$CFG->wwwroot   = 'xxxxxxx';
$CFG->dataroot  = 'xxxxx';
$CFG->admin     = 'xxxxx';

$CFG->defaultblocks_override = 'activity_modules,news_items:';

$CFG->directorypermissions = 0777;

$CFG->passwordsaltmain = 'xxxxxxxxx';

require_once(dirname(__FILE__) . '/lib/setup.php');

// There is no php closing tag in this file,
// it is intentional because it prevents trailing whitespace problems!

In reply to Gus Hagelberg

Re: sync_users.php stops with db error

by Olumuyiwa Taiwo -
Picture of Plugin developers

Your config.php looks OK.

I'm fairly sure that the issue you're having is different from the one originally reported.

In reply to Gus Hagelberg

Re: sync_users.php stops with db error

by Olumuyiwa Taiwo -
Picture of Plugin developers

By "protocol version" I mean the setting in your LDAP settings page that is labelled "Version", located just beneath the "Host URL" setting.

The reason I mention that (as well as page size) is that the LDAP sync script uses that setting to determine whether or not your LDAP server supports paging (RFC-2696 - https://www.ietf.org/rfc/rfc2696.txt), and if it does, it asks for the results of queries to be sent in page sized chunks.

If the server does not support paging, then the number of entries returned is limited to a maximum imposed by the LDAP server. This means you may get a smaller number of users than you actually have in your Moodle database.

I did a quick search on the capabilities supported by your LDAP server, and it appears that it does not in fact support RFC-2696: http://docs.oracle.com/cd/E29127_01/doc.111170/e28968/supported-standards-rfcs.htm.

To get around the problem you're having, you could set the "version" to "2". But bear in mind that your LDAP server could then send back fewer than the 10,000 users that you have in your Moodle database. You could probably fix that by convincing your LDAP administrator to increase the size limit to something over 10,000.

Note, this issue has been reported as a bug - https://tracker.moodle.org/browse/MDL-50625

Average of ratings: Useful (1)
In reply to Olumuyiwa Taiwo

Re: sync_users.php stops with db error

by Iñaki Arenaza -
Picture of Core developers Picture of Documentation writers Picture of Particularly helpful Moodlers Picture of Peer reviewers Picture of Plugin developers
Just a quick note to mention that I have proposed a patch for bug MDL-50625, to try and detect those LDAP servers that are LDAPv3 compliant but don't support paged results, so you don't need to downgrade the connection to LDAPv2 (which has other limitations/drawbacks).

Saludos.
Iñaki.
In reply to Emma Richardson

Re: sync_users.php stops with db error

by Gus Hagelberg -

Oh and its not a MSAD ldap server just an lpad server.

In reply to Gus Hagelberg

Re: sync_users.php stops with db error

by Emma Richardson -
Picture of Documentation writers Picture of Particularly helpful Moodlers Picture of Plugin developers

Could it be that you have this set up in the task server settings and then are trying to run from CLI?  Perhaps it is already running?

In reply to Emma Richardson

Re: sync_users.php stops with db error

by Gus Hagelberg -

I am running it from the command line.
On my test server I am pretty sure its not running in cron.


Right now I can't find the crontab or cron on my debian server that is responsible for this. Hope to ask my unix guy on Monday.


Would it make a difference if it is running through cron and in addition on the command line?


Just noticed I am even getting this error:

php schedule_task.php

PHP Warning:  PHP Startup: Invalid library (maybe not a PHP library) 'opcache.so' in Unknown on line 0

We checked that opchache.so is installed but seems to be a problem.


In reply to Gus Hagelberg

Re: sync_users.php stops with db error

by Emma Richardson -
Picture of Documentation writers Picture of Particularly helpful Moodlers Picture of Plugin developers

Not sure about the cache message but some weird stuff interferes with that LDAP script sometime.  I had a course format that broke it once!  You might check your opcache settings in php.ini and ensure that they match the recommended settings for moodle (found in docs).

On debian, you should be able to crontab -u www-data e to see your cron script for moodle.  However, if you are running a new version of moodle, go to SiteAdmin/Server/Scheduled Tasks and see if it is set up there.

Turn debugging on in your Moodle site and then run it again.  Perhaps that will bring something else up..

In reply to Emma Richardson

Re: sync_users.php stops with db error

by Gus Hagelberg -

We adjusted the opcache settings as suggested in the moodle docs.

The scheduled tasks are running as expected.

I have another moodle installation which is basically "clean" and the error is also showing up there. The users are authenticated against the same LDAP server.

This makes me think that the sync_script.php is having some trouble with something in LDAP.

In reply to Gus Hagelberg

Re: sync_users.php stops with db error

by Olumuyiwa Taiwo -
Picture of Plugin developers

As I explained in my earlier comment - https://moodle.org/mod/forum/discuss.php?d=333293#p1356300 - the issue seems to be due to your LDAP server not supporting paged results. I linked a few documents, in particular a bug related to the issue that has been reported in Moodle Tracker.

Try setting "Version" to "2" in your LDAP settings and see what happens. Note that it's likely that you won't be able to sync all your 10,000 users when you do that and you may have to request your LDAP administrator to increase the page size to a number that works for you.

Average of ratings: Useful (2)
In reply to Olumuyiwa Taiwo

Re: sync_users.php stops with db error

by Gus Hagelberg -

Bingo. That was it.

I changed the Version to 2 under LDAP Server Settings.

After that the sync_user.php script ran and started suspending old users.

The script stopped around a third of the way through.

I will talk to my admin about raising the page size to 10,000.

I saw the moodle tracker issue and will vote for it. Thanks.


So I guess this issue is solved if I keep the version at 2 and have the page size increased. Hopefully the bug issue will be dealt with.

Thanks a lot.

In reply to Gus Hagelberg

Re: sync_users.php stops with db error

by Olumuyiwa Taiwo -
Picture of Plugin developers

"So I guess this issue is solved if I keep the version at 2 and have the page size increased"

You could also rate my comment "Useful" smile

In reply to Olumuyiwa Taiwo

Re: sync_users.php stops with db error

by Gus Hagelberg -

Sorry, but I do have another question.

The sync_user.php script is working fine now after setting LDAP version to 2 (didn't need to change LDAP page size settings).

After the script ran the non-LDAP users were correctly "suspended" in Moodle, but

the script added LDAP users to Moodle, LDAP users wo previously didn't exist in Moodle.

Previously on my system, without the script, new users were added into Moodle only during the authenticatication during their first login in Moodle.

I am not sure if it is ok to have this script adding users to Moodle. There are a couple thousand LDAP users who don't need to be in Moodle.

Is there a way of preventing the script from adding users to Moodle?

In reply to Gus Hagelberg

Re: sync_users.php stops with db error

by Emma Richardson -
Picture of Documentation writers Picture of Particularly helpful Moodlers Picture of Plugin developers

I have a security group set up in Active Directory for my Moodle Users.  I then filter down to the group in the LDAP settings by adding the following to the Object Class field.   This way only those users assigned to the group get synced.

(|(&(objectClass=user)(!(objectClass=computer))(memberOf=cn=MoodleUser,ou=people ,dc=mydomain,dc=com)))

In reply to Emma Richardson

Re: sync_users.php stops with db error

by Gus Hagelberg -

Thanks Emma.
I don't quite understand that.
I would prefer the sync_user.php script not adding any users to Moodle, just marking the old (non-LDAP) users as "deleted".

In LDAP we have, for example, users without an Email addresses. This could cause problems in Moodle.

In reply to Gus Hagelberg

Re: sync_users.php stops with db error

by Emma Richardson -
Picture of Documentation writers Picture of Particularly helpful Moodlers Picture of Plugin developers

Creating some sort of group is the only way to do this.  You need to basically filter what users should be given access to Moodle.  Then any user that is not in the group will be removed as you specify in the LDAP settings.  Moodle needs a way to know which users are meant to be added to Moodle.

FYI - users without an email will just be prompted to add one when they first log in.  I actually do this purposely so that users enter their current email when first logging in.