General help

 
 
Picture of Justin Doyle
Flat File Enrolment broken since upgrade: Unknown role in field2
 
Hi,
I am having some trouble with the enrolement plugin since recently upgrading from 1.8 to 1.9 and wondering if anyone can help ? Flat file enrolement is no logner working.

I am on now on moodle 1.9.2+ with PHP 5.1.6, MySQL 5.0.45, and redhat 5.2

The enrolement plugin was working fine on 1.8
I have a new fresh 1.9 instance in the same environment and the enrolement plugin is working fine there also. I am using the same scripts to generate the flat file on both the working 1.9 and broken 1.9.

Flat file enrolement was working intermittantly on the upgraded moodle instance but now it is failing every time. To try and rule out database problems I have run mysqldiff and there is no difference now between my upgraded 1.9 and a clean 1.9 install. I have also run the database optimisation script which analyses and optimises the tables.

I am running the moodle cron job from the command line through the OS cron and keeping the log files. The process fails for all users and roles.

Here is a sample of the error in the log file.

127193: add editingteacher 95023976 2009_BE306 :Unknown role in field2 - ignoring line
...
133190: add student 99318911 2009_CA511 :Unknown role in field2 - ignoring line

The mdl_roles table seems ok in the database

Full Texts id name shortname description sortorder

Edit Delete 1 Administrator admin Administrators can usually do anything on the site... 0

Edit Delete 2 Course creator coursecreator Course creators can create new courses and teach i... 1

Edit Delete 3 Teacher editingteacher Teachers can do anything within a course, includi... 2

Edit Delete 4 Non-editing teacher teacher Non-editing teachers can teach in courses and grad... 3

Edit Delete 5 Student student Students generally have less privileges within a ... 4

Edit Delete 6 Guest guest Guests have minimal privileges and usually can not... 5

Edit Delete 7 Authenticated user user All logged in users. 6

Can anyone suggest where I should be looking to try and resolve this ?
Or has anyone seen this problem before ?

Thanks for you help,
Justin
 
Average of ratings: -
Picture of John White
Re: Flat File Enrolment broken since upgrade: Unknown role in field2
 
Justin,

This might be a difference between the Flat-file settings inherited from your 1.8 installation and those expected by 1.9.

Have a look in Site Administration->Courses->Enrolments and click Edit against Flat-file.

Check that the pseudonyms for roles exactly match the db shortnames.

Does this help?

John
 
Average of ratings: -
Picture of Justin Doyle
Re: Flat File Enrolment broken since upgrade: Unknown role in field2
 
Hi John,
Thank you for getting back to me ..

I have checked the pseudonyms as you suggest and they seem to match ok.
editingteacher and student are the 2 of main interest to me at the moment
and they are spelled correctly and have the same case as those in the mdl_roles table.

Strange also how works occassionaly ...
I am running the enrolments every 30 mins ...
According to the logs it worked ok once in last 24 hours ...

Any other suggestions ?

Thanks,
Justin
 
Average of ratings: -
Picture of John White
Re: Flat File Enrolment broken since upgrade: Unknown role in field2
 
Justin,

I'm very perplexed by the notion that it works once in 24 hours, because the error in the log is being generated by the following lines in /enrol/flatfile/enrol.php ...

/// check correct formatting of role field
if (!isset($rolemap[$fields[1]]) && !isset($roles[$fields[1]])) {
$this->log .= "Unknown role in field2 - ignoring line\n";
continue;
}

...in short this will printed 'Unknown role...' only if the the role name in the file does not match a role shortname in the database ($roles) or in the pseudonym list ($rolemap)!

So, have you checked to make sure there are absolutely no spaces (or other hidden characters) in either the database or the rolemap records?

To me, the only other possibility is that there is a bug preventing proper completion, such as if the upgrade was not completed properly.
And I only mention that because of a case that George Spencer raised at:
http://moodle.org/mod/forum/discuss.php?d=103876
...which he eventually fixed with a further upgrade!
Do you get anything strange if you click on 'Notifications' ???

Regards,
John
 
Average of ratings: -
Picture of Justin Doyle
Re: Flat File Enrolment broken since upgrade: Unknown role in field2
 
Hi John,
Thanks for taking the time to help me solve this issue ...

This is turning out to be a right head scratcher !

I do not see anything strange when I click on 'Notifications'.

I have looked through some of the other logs and I found one where it worked it's way through the flat file reporting 'OK' for each line ... and then will suddenly start reporting 'Unknown user idnumber in field 3' and will report this for all remaining users.

Again, I have checked the database for some of the users concerned and they have the relevant id number set in their profile.

Is it possible somehow that the problem is somehow related to the connection to the database but the enrolment plugin is giving an incorrect error ?
My enrolement file is quite large ~100,000 lines - can there be a limit here ?

I have another problem with this installation which I was going to post a message about once I had this resolved .. but perhaps they are related .. I will explain the problem to see if you think they are related ?

The cron process can take a long time to complete ... sometimes an hour .. sometimes longer. Other times it can run in seconds. I have turned off statistics and forum_trackreadposts in an effort to reduce load on the cron job. As I mentioned in my original post ... I have used mysqldiff to sync my database with a clean 1.9 install and have run the mdl-db-opt script to analyse and optimise tables.

mysqld will appear like this in top

PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND
17033 mysql 15 0 571m 133m 4372 S 101 0.8 57:51.31 mysqld

a tail -f of the cron log file will be stalled at this point

hotpot: ...NOT SUPPORTED (file)
questionnaire: ...NOT SUPPORTED (file)
lams: ...NOT SUPPORTED (file)
Ending rssfeeds......OK
Rssfeeds finished


I have placed a snippet from an strace of mysqld at this time at the end of this post .. perhaps this would mean something to you ?

Thanks again John for helping with this ... I am of course in the middle of student registrations !

Kind Regards,
Justin

[pid 17052] lseek(362, 2331712, SEEK_SET) = 2331712
[pid 17052] read(362, "\1\0-\0\376\246\302\0\0\0\0\0\0F\0\0\0\0\0\0", 20) = 20
[pid 17052] read(362, "\00008\2\0\0\0\0\0\21/1/33/42424/49830\4", 28) = 28
[pid 17052] lseek(420, 2127320, SEEK_SET) = 2127320
[pid 17052] read(420, "\3\0C\1 Qq\0\0\0\0\0\0\246\302\0\0\0\0\0", 20) = 20
[pid 17052] read(420, "\0\5\0\0\0\0\0\0\0\31mod/forum:startdiscuss"..., 51) = 51
[pid 17052] lseek(420, 2127392, SEEK_SET) = 2127392
[pid 17052] read(420, "\1\0A Rq\0\0\0\0\0\0\246\302\0\0\0\0\0\0", 20) = 20
[pid 17052] read(420, "\5\0\0\0\0\0\0\0\27mod/forum:viewanyrating"..., 48) = 48
[pid 17052] lseek(420, 2127460, SEEK_SET) = 2127460
[pid 17052] read(420, "\1\0= Sq\0\0\0\0\0\0\247\302\0\0\0\0\0\0", 20) = 20
[pid 17052] read(420, "\5\0\0\0\0\0\0\0\23mod/forum:replypost\1\0\0\0"..., 44) = 44
[pid 17052] lseek(362, 2331760, SEEK_SET) = 2331760
[pid 17052] read(362, "\1\0-\0\376\247\302\0\0\0\0\0\0F\0\0\0\0\0\0", 20) = 20
[pid 17052] read(362, "\00018\2\0\0\0\0\0\21/1/33/42424/49831\4", 28) = 28
[pid 17052] lseek(420, 2127524, SEEK_SET) = 2127524
[pid 17052] read(420, "\3\0C\1 Tq\0\0\0\0\0\0\247\302\0\0\0\0\0", 20) = 20
[pid 17052] read(420, "\0\5\0\0\0\0\0\0\0\31mod/forum:startdiscuss"..., 51) = 51
[pid 17052] lseek(420, 2127596, SEEK_SET) = 2127596
[pid 17052] read(420, "\1\0A Uq\0\0\0\0\0\0\247\302\0\0\0\0\0\0", 20) = 20
[pid 17052] read(420, "\5\0\0\0\0\0\0\0\27mod/forum:viewanyrating"..., 48) = 48
[pid 17052] lseek(420, 2127664, SEEK_SET) = 2127664
[pid 17052] read(420, "\3\0008\0 Vq\0\0\0\0\0\0\250\302\0\0\0\0\0", 20) = 20
[pid 17052] read(420, "\0\5\0\0\0\0\0\0\0\16mod/forum:rate\1\0\0\0\0\0\0\0"..., 40) = 40
[pid 17052] lseek(362, 2331808, SEEK_SET) = 2331808
[pid 17052] read(362, "\1\0-\0\376\250\302\0\0\0\0\0\0F\0\0\0\0\0\0", 20) = 20
[pid 17052] read(362, "\00028\2\0\0\0\0\0\21/1/33/42424/49832\4", 28) = 28
[pid 17052] lseek(420, 2127724, SEEK_SET) = 2127724
[pid 17052] read(420, "\1\0= Wq\0\0\0\0\0\0\250\302\0\0\0\0\0\0", 20) = 20
[pid 17052] read(420, "\5\0\0\0\0\0\0\0\23mod/forum:replypost\1\0\0\0"..., 44) = 44
[pid 17052] lseek(420, 2127788, SEEK_SET) = 2127788
[pid 17052] read(420, "\3\0C\1 Xq\0\0\0\0\0\0\250\302\0\0\0\0\0", 20) = 20
[pid 17052] read(420, "\0\5\0\0\0\0\0\0\0\31mod/forum:startdiscuss"..., 51) = 51
[pid 17052] lseek(420, 2127860, SEEK_SET) = 2127860
[pid 17052] read(420, "\1\0A Yq\0\0\0\0\0\0\250\302\0\0\0\0\0\0", 20) = 20
[pid 17052] read(420, "\5\0\0\0\0\0\0\0\27mod/forum:viewanyrating"..., 48) = 48
[pid 17052] lseek(420, 2127928, SEEK_SET) = 2127928
[pid 17052] read(420, "\3\0008\0 Zq\0\0\0\0\0\0\251\302\0\0\0\0\0", 20) = 20
[pid 17052] read(420, "\0\5\0\0\0\0\0\0\0\16mod/forum:rate\1\0\0\0\0\0\0\0"..., 40) = 40
[pid 17052] lseek(362, 2331856, SEEK_SET) = 2331856
[pid 17052] read(362, "\1\0-\0\376\251\302\0\0\0\0\0\0F\0\0\0\0\0\0", 20) = 20
[pid 17052] read(362, "\00038\2\0\0\0\0\0\21/1/33/42424/49833\4", 28) = 28
[pid 17052] lseek(420, 2127988, SEEK_SET) = 2127988
[pid 17052] read(420, "\1\0= [q\0\0\0\0\0\0\251\302\0\0\0\0\0\0", 20) = 20
[pid 17052] read(420, "\5\0\0\0\0\0\0\0\23mod/forum:replypost\1\0\0\0"..., 44) = 44
[pid 17052] lseek(420, 2128052, SEEK_SET) = 2128052
[pid 17052] read(420, "\3\0C\1 \\q\0\0\0\0\0\0\251\302\0\0\0\0\0", 20) = 20
[pid 17052] read(420, "\0\5\0\0\0\0\0\0\0\31mod/forum:startdiscuss"..., 51) = 51
[pid 17052] lseek(420, 2128124, SEEK_SET) = 2128124
[pid 17052] read(420, "\1\0A ]q\0\0\0\0\0\0\251\302\0\0\0\0\0\0", 20) = 20
[pid 17052] read(420, "\5\0\0\0\0\0\0\0\27mod/forum:viewanyrating"..., 48) = 48
[pid 17052] lseek(420, 2128192, SEEK_SET) = 2128192
[pid 17052] read(420, "\1\0= ^q\0\0\0\0\0\0\252\302\0\0\0\0\0\0", 20) = 20
[pid 17052] read(420, "\5\0\0\0\0\0\0\0\23mod/forum:replypost\1\0\0\0"..., 44) = 44
[pid 17052] lseek(362, 2331904, SEEK_SET) = 2331904
[pid 17052] read(362, "\1\0-\0\376\252\302\0\0\0\0\0\0F\0\0\0\0\0\0", 20) = 20
[pid 17052] read(362, "\00088\2\0\0\0\0\0\21/1/33/42424/49834\4", 28) = 28
[pid 17052] lseek(420, 2128256, SEEK_SET) = 2128256
[pid 17052] read(420, "\3\0C\1 _q\0\0\0\0\0\0\252\302\0\0\0\0\0", 20) = 20
[pid 17052] read(420, "\0\5\0\0\0\0\0\0\0\31mod/forum:startdiscuss"..., 51) = 51
[pid 17052] lseek(420, 2128328, SEEK_SET) = 2128328
[pid 17052] read(420, "\1\0A `q\0\0\0\0\0\0\252\302\0\0\0\0\0\0", 20) = 20
[pid 17052] read(420, "\5\0\0\0\0\0\0\0\27mod/forum:viewanyrating"..., 48) = 48
[pid 17052] lseek(420, 2128396, SEEK_SET) = 2128396
[pid 17052] read(420, "\1\0= aq\0\0\0\0\0\0\253\302\0\0\0\0\0\0", 20) = 20
[pid 17052] read(420, "\5\0\0\0\0\0\0\0\23mod/forum:replypost\1\0\0\0"..., 44) = 44
[pid 17052] lseek(362, 2331952, SEEK_SET) = 2331952
[pid 17052] read(362, "\1\0-\0\376\253\302\0\0\0\0\0\0F\0\0\0\0\0\0", 20) = 20
[pid 17052] read(362, "\0?8\2\0\0\0\0\0\21/1/33/42424/49835\4", 28) = 28
[pid 17052] lseek(420, 2128460, SEEK_SET) = 2128460
[pid 17052] read(420, "\3\0C\1 bq\0\0\0\0\0\0\253\302\0\0\0\0\0", 20) = 20
[pid 17052] read(420, "\0\5\0\0\0\0\0\0\0\31mod/forum:startdiscuss"..., 51) = 51
[pid 17052] lseek(420, 2128532, SEEK_SET) = 2128532
[pid 17052] read(420, "\1\0A cq\0\0\0\0\0\0\253\302\0\0\0\0\0\0", 20) = 20
[pid 17052] read(420, "\5\0\0\0\0\0\0\0\27mod/forum:viewanyrating"..., 48) = 48
[pid 17052] lseek(420, 2128600, SEEK_SET) = 2128600
[pid 17052] read(420, "\1\0= dq\0\0\0\0\0\0\254\302\0\0\0\0\0\0", 20) = 20
[pid 17052] read(420, "\5\0\0\0\0\0\0\0\23mod/forum:replypost\1\0\0\0"..., 44) = 44
[pid 17052] lseek(362, 2332000, SEEK_SET) = 2332000
[pid 17052] read(362, "\1\0-\0\376\254\302\0\0\0\0\0\0F\0\0\0\0\0\0", 20) = 20
[pid 17052] read(362, "\0G8\2\0\0\0\0\0\21/1/33/42424/49836\4", 28) = 28
[pid 17052] lseek(420, 2128664, SEEK_SET) = 2128664
[pid 17052] read(420, "\3\0C\1 eq\0\0\0\0\0\0\254\302\0\0\0\0\0", 20) = 20
[pid 17052] read(420, "\0\5\0\0\0\0\0\0\0\31mod/forum:startdiscuss"..., 51) = 51
[pid 17052] lseek(420, 2128736, SEEK_SET) = 2128736
[pid 17052] read(420, "\1\0A fq\0\0\0\0\0\0\254\302\0\0\0\0\0\0", 20) = 20
[pid 17052] read(420, "\5\0\0\0\0\0\0\0\27mod/forum:viewanyrating"..., 48) = 48
[pid 17052] lseek(420, 2128804, SEEK_SET) = 2128804
[pid 17052] read(420, "\1\0= gq\0\0\0\0\0\0\255\302\0\0\0\0\0\0", 20) = 20
[pid 17052] read(420, "\5\0\0\0\0\0\0\0\23mod/forum:replypost\1\0\0\0"..., 44) = 44
[pid 17052] lseek(362, 2332048, SEEK_SET) = 2332048
[pid 17052] read(362, "\1\0-\0\376\255\302\0\0\0\0\0\0F\0\0\0\0\0\0", 20) = 20
[pid 17052] read(362, "\0J8\2\0\0\0\0\0\21/1/33/42424/49837\4", 28) = 28
[pid 17052] lseek(420, 2128868, SEEK_SET) = 2128868
[pid 17052] read(420, "\3\0C\1 hq\0\0\0\0\0\0\255\302\0\0\0\0\0", 20) = 20
[pid 17052] read(420, "\0\5\0\0\0\0\0\0\0\31mod/forum:startdiscuss"..., 51) = 51
[pid 17052] lseek(420, 2128940, SEEK_SET) = 2128940
[pid 17052] read(420, "\1\0A iq\0\0\0\0\0\0\255\302\0\0\0\0\0\0", 20) = 20
[pid 17052] read(420, "\5\0\0\0\0\0\0\0\27mod/forum:viewanyrating"..., 48) = 48
[pid 17052] lseek(420, 2129008, SEEK_SET) = 2129008
[pid 17052] read(420, "\1\0= jq\0\0\0\0\0\0\256\302\0\0\0\0\0\0", 20) = 20
[pid 17052] read(420, "\5\0\0\0\0\0\0\0\23mod/forum:replypost\1\0\0\0"..., 44) = 44
[pid 17052] lseek(362, 2332096, SEEK_SET) = 2332096
[pid 17052] read(362, "\1\0-\0\376\256\302\0\0\0\0\0\0F\0\0\0\0\0\0", 20) = 20
[pid 17052] read(362, "\0O8\2\0\0\0\0\0\21/1/33/42424/49838\4", 28) = 28
[pid 17052] lseek(420, 2129072, SEEK_SET) = 2129072
[pid 17052] read(420, "\3\0C\1 kq\0\0\0\0\0\0\256\302\0\0\0\0\0", 20) = 20
[pid 17052] read(420, "\0\5\0\0\0\0\0\0\0\31mod/forum:startdiscuss"..., 51) = 51
 
Average of ratings: -
Picture of John White
Re: Flat File Enrolment broken since upgrade: Unknown role in field2
 
Justin,

This now WAY past my comfort zone!
You may need an expert here!

I notice that the id error you report now is not the same as the role error reported before, though I'm sure the cause is related.

Try cutting the enrolment file down to less than 32000 lines and run it again.
Even try splitting the file into such chunks and run each.
Does this work?

Is there a point - a record - at which it fails?

Any help?

John
 
Average of ratings: -
Picture of Justin Doyle
Re: Flat File Enrolment broken since upgrade: Unknown role in field2
 
Hi John,
I split the flat file as you suggested .. into 5 chunks of approx 19,000 lines

I ran the cron again using chunk #1..
and for all users it gave the unknown role id error

I ran it again using chunk #1 ..
and it processed all users on the file correctly.

I have run it again now on chunk #2 ..
and it is stalled again at this stage

lams: ...NOT SUPPORTED (file)
Ending rssfeeds......OK
Rssfeeds finished

with mysqld at the top of process table

It seems this will be one of the occasions when cron will take an hour or more to complete. And I would bet that the enrolment part will fail ...

Thank you very much for your help John.
I will keep digging and let you know how I get on ..

Kind Regards,
Justin
 
Average of ratings: -
Picture of Justin Doyle
Re: Flat File Enrolment broken since upgrade: Unknown role in field2
 
Just to add another layer to this problem ....

If the cron jobs are allowed to run in succession and they are taking a long
time ... mysqld gets very busy ... and then emails start arriving to the admin
account saying there is a problem writing to mdl_log

Insert into log table failed at Friday 19th of September 2008 10:40:29 AM.
 It is possible that your disk is full.

The failed SQL is:

INSERT INTO mdl_log (time, userid, course, ip, module, cmid, action, url, info)
 VALUES ('1221817229', '28925', '1', '86.45.97.225', 'course', '0', 'view', 'view.php?id=1', '1')


The disk is not full ... and this only happens when mysqld seems to get swamped by multiple cron jobs ..

Kind Regards,
Justin



 
Average of ratings: -
C'est moi :-)
Re: Flat File Enrolment broken since upgrade: Unknown role in field2
Group Documentation writersGroup Particularly helpful MoodlersGroup TestersGroup Translators

Hi

If someone reads that, about problem "Insert into log table failed at ... It is possible that your disk is full.", see MDL-14100.

Séverin

 
Average of ratings: -
Picture of Justin Doyle
Re: Flat File Enrolment broken since upgrade: Unknown role in field2
 
As a workaround I tried to change my enrolment method to external db.
For one course I changed the enrol column in mdl_role_assignments to 'database' for all registered students. I set theses students up in the external db and ran the enrol_database_sync.php script .. all seemed to work fine. Students were now being enroled using 'database' rather than 'flat'

But ... when I put all registrations for all students on all courses into the external db approx 80,000 entries - I hit problems. The sync script was not able to complete. It would fail with an error saying that mysql had gone away.
There were also regular enrol_db errors in the php error file regarding mysql gone away .. I assume as it was checking the external db for each user login.

Load on the box also increased significantly ... at some stages making the box very unresponsive for users. Tried upgrading to latest version of mysql incase there was a mysql bug. Tried tuning mysql and adjusting settings in conf file.

I read through the upgrade notes for each version of moodle to see if there were any steps which may have been missed or may help. We had progressed through all versions including 1.7. The upgrade to 1.8 suggested resetting all roles to defaults. I am not sure if this step was missed at that time or if the problem was introduced later somehow .... but this fixed the problem !

After resetting all roles to defaults the sync script completed for the first time and all enrolments were corrected. Load on the box reduced significantly and it became more responsive.

Flat file enrolment is still broken and giving the same errors sad but at least students are now enroled correctly smile
 
Average of ratings: -
C'est moi :-)
Re: Flat File Enrolment broken since upgrade: Unknown role in field2
Group Documentation writersGroup Particularly helpful MoodlersGroup TestersGroup Translators
Hello,

one year later, with Moodle 1.9.5+, the problem is still here...

I had declared the bug MDL-17031 (still open), and talked about it in this thread...

Hope this helps...
 
Average of ratings: -