06 May 2023, 0:44

Hello,

We've been using Mahara for years and it's been good. One hitch we had was our local team maintaining the server, so we hosted elsewhere. We used the downtime to also switch from LDAP auth to SAML. Ever since, some users have been having a really hard time staying in the system. They log in and are okay, until it comes time to edit a page or upload a file, then a slew of errors show (I have debugging on).

The first error that is odd is

[DBG] 00 (auth/saml/lib.php:562) remote user '[email protected]' is now reanimated as '[email protected]'

Now "everything" works until, as I said, an edit or upload happens. Then it triggers all of these errors:

[WAR] b0 (auth/lib.php:1315) Invalid account selected
Cal stack (most recent first):
auth_check_required_fields() at /var/www/mrhosts/CURRENT_MP2/mahara/auth/lib.php:547
auth_setup() at /var/www/mrhosts/CURRENT_MP2/mahara/init.php:424
require("/var/www/mrhosts/CURRENT_MP2/mahara/init.php") at /var/www/mrhosts/CURRENT_MP2/mahara/artefact/file/download.php:14
[WAR] ce (auth/lib.php:1315) Invalid account selected
Cal stack (most recent first):
auth_check_required_fields() at /var/www/mrhosts/CURRENT_MP2/mahara/auth/lib.php:547
 auth_setup() at /var/www/mrhosts/CURRENT_MP2/mahara/init.php:424
 require("/var/www/mrhosts/CURRENT_MP2/mahara/init.php") at /var/www/mrhosts/CURRENT_MP2/mahara/view/blocks.php:17
[WAR] d0 (auth/lib.php:1315) Invalid account selected
Call stack (most recent first):
auth_check_required_fields() at /var/www/mrhosts/CURRENT_MP2/mahara/auth/lib.php:547
auth_setup() at /var/www/mrhosts/CURRENT_MP2/mahara/init.php:424
require("/var/www/mrhosts/CURRENT_MP2/mahara/init.php") at /var/www/mrhosts/CURRENT_MP2/mahara/view/blocks.php:17
[WAR] 83 (auth/lib.php:1315) Invalid account selected
Call stack (most recent first):
auth_check_required_fields() at /var/www/mrhosts/CURRENT_MP2/mahara/auth/lib.php:547
auth_setup() at /var/www/mrhosts/CURRENT_MP2/mahara/init.php:424
require("/var/www/mrhosts/CURRENT_MP2/mahara/init.php") at /var/www/mrhosts/CURRENT_MP2/mahara/view/blocks.php:17
[WAR] b5 (auth/lib.php:1315) Invalid account selected
Call stack (most recent first):
auth_check_required_fields() at /var/www/mrhosts/CURRENT_MP2/mahara/auth/lib.php:547
auth_setup() at /var/www/mrhosts/CURRENT_MP2/mahara/init.php:424
require("/var/www/mrhosts/CURRENT_MP2/mahara/init.php") at /var/www/mrhosts/CURRENT_MP2/mahara/view/blocks.php:17
[WAR] 76 (auth/lib.php:1315) Invalid account selected
Cal stack (most recent first):
auth_check_required_fields() at /var/www/mrhosts/CURRENT_MP2/mahara/auth/lib.php:547
auth_setup() at /var/www/mrhosts/CURRENT_MP2/mahara/init.php:424
 require("/ar/www/mrhosts/CURRENT_MP2/mahara/init.php") at /var/www/mrhosts/CURRENT_MP2/mahara/view/blocks.php:17
[WAR] ee (auth/lib.php:1315) Invalid account selected
Call stack (most recent first):
auth_check_required_fields() at /var/www/mrhosts/CURRENT_MP2/mahara/auth/lib.php:547
auth_setup() at /var/www/mrhosts/CURRENT_MP2/mahara/init.php:424
require("/var/www/mrhosts/CURRENT_MP2/mahara/init.php") at /var/www/mrhosts/CURRENT_MP2/mahara/view/blocks.php:17
[WAR] 96 (auth/lib.php:1315) Invalid account selected
Call stack (most recent first):
auth_check_required_fields() at /var/www/mrhosts/CURRENT_MP2/mahara/auth/lib.php:547
auth setup0) at /var/www/mrhosts/CURRENT MP2/mahara/init.php:424


Call stack (most recent first):
auth_check_required_fields() at /var/www/mrhosts/CURRENT_MP2/mahara/auth/lib.php:547
auth_setup() at /var/www/mrhosts/CURRENT_MP2/mahara/init.php:424
 require("/ar/www/mrhosts/CURRENT_MP2/mahara/init.php") at /var/www/mrhosts/CURRENT_MP2/mahara/view/blocks.php:17
[WAR] ef (auth/lib.php:1315) Invalid account selected
Call stack (most recent first):
auth_check_required_fields() at /var/www/mrhosts/CURRENT_MP2/mahara/auth/lib.php:547
auth_setup() at /var/www/mrhosts/CURRENT_MP2/mahara/init.php:424
 require("/var/www/mrhosts/CURRENT_MP2/mahara/init.php") at /var/www/mrhosts/CURRENT_MP2/mahara/index.php:16
 [WAR] a9 (auth/lib.php:1315) Invalid account selected
Call stack (most recent first):
auth_check_required_fields() at /var/www/mrhosts/CURRENT_MP2/mahara/auth/lib.php:547
auth_setup() at /var/www/mrhosts/CURRENT_MP2/mahara/init.php:424
require("/var/www/mrhosts/CURRENT_MP2/mahara/init.php") at /var/www/mrhosts/CURRENT_MP2/mahara/index.php:16


[WAR] fe (lib/errors.php:853) Failed to get a recordset: postgres9 error: [-5: ERROR: duplicate key value violates unique constraint "usr_use_uix"
DETAIL: Key (lower(username:text)=() already exists.] in EXECUTE("INSERT INTO "usr" ("id", "salt", "passwordchange", "active", "deleted", "expirymailsent", "inactivemailsent",
"staff", "admin", "firstname", "lastname", "studentid", "preferredname", "email", "quotaused", "authinstance", "lastaccess", "showhomeinfo", "username", "password", "unread",
"probation") VALUES (?, ?, ?, ?,?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?)")Command was: INSERT INTO "usr"("id", "salt", "passwordchange", "active", "deleted", "expirymailsent",
"inactivemailsent", "staf", "admin", "firstname", "lastname", "studentid", "preferredname", "email", "quotaused", "authinstance", "lastaccess", "showhomeinfo", "username",
"password", "unread", "probation") VALUES (?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?) and values was
(id:2374,salt:, passwordchange:0,active:1,deleted:0,expirymailsent:0,inactivemailsent:0,staff:0,admin:0, firstname:,lastname:,studentid:, preferredname:, email:, quotaused:0,authinstance
04-2023:51:22,showhomeinfo:1,username:, password:,unread:0,probation:0)
Cal stack (most recent first):
log_message(string(size 1230), integer, true, true) at /var/www/mrhosts/CURRENT_MP2/mahara/lib/errors.php:89
log_warn(string(size 1230) at /var/www/mrhosts/CURRENT_MP2/mahara/lib/errors.php:853
SQLException->_construct(string(size 1230) at /var/www/mrhosts/CURRENT_MP2/mahara/lib/dml.php:1235
insert_record(string(size 3), object(stdClass), string(size 2), true) at /var/www/mrhosts/CURRENT_MP2/mahara/auth/user.php:434
User->commit() at /var/www/mrhosts/CURRENT_MP2/mahara/auth/user.php:2116
LiveUser->commit() at /var/www/mrhosts/CURRENT_MP2/mahara/auth/user.php:2137
 LiveUser->renew() at /var/www/mrhosts/CURRENT_MP2/mahara/auth/lib.php:546
auth_setup() at /var/www/mrhosts/CURRENT_MP2/mahara/init.php:424
require("/var/www/mrhosts/CURRENT_MP2/mahara/init.php") at /var/www/mrhosts/CURRENT_MP2/mahara/index.php:16
X[WAR] fe (lib/dml.php:1235) Failed to get a recordset: postgres9 error: [-5: ERROR: duplicate key value violates unique constraint "usr_use_uix"
DETAIL: Key (lower(username:text)=() already exists.] in EXECUTE("INSERT INTO "usr" ("id", "salt", "passwordchange", "active", "deleted", "expirymailsent", "inactivemailsent",
"staff", "admin", "firstname", "lastname", "studentid", "preferredname", "email", "quotaused", "authinstance", "lastaccess", "showhomeinfo", "username", "password", "unread",
"probation") VALUES (?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?)")Command was: INSERT INTO "usr" ("id", "salt", "passwordchange", "active", "deleted", "expirymailsent",
"inactivemailsent", "staff", "admin", "firstname", "lastname", "studentid", "preferredname", "email", "quotaused", "authinstance", "lastaccess", "showhomeinfo", "username",
"password", "unread", "probation") VALUES (?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?) and values was
(id:2374,salt:, passwordchange:0,active:1,deleted:0,expirymailsent:0,inactivemailsent:0,staff:0,admin:0,firstname:, lastname:, studentid:, preferredname:, email:, quotaused:0,authinstance
04-2023:51:22,showhomeinfo:1,username:,password:,unread:0,probation:0)
Cal stack (most recent first):
insert_record(string(size 3), object(stdClass), string(size 2), true) at /var/www/mrhosts/CURRENT_MP2/mahara/auth/user.php:434
User->commit() at /var/www/mrhosts/CURRENT_MP2/mahara/auth/user.php:2116
LiveUser->commit() at /var/www/mrhosts/CURRENT_MP2/mahara/auth/user.php:2137
LiveUser->renew() at /var/www/mrhosts/CURRENT_MP2/mahara/auth/lib.php:546
auth_setup() at /var/www/mrhosts/CURRENT_MP2/mahara/init.php:424
require("/var/www/mrhosts/CURRENT_MP2/mahara/init.php") at /var/www/mrhosts/CURRENT_MP2/mahara/index.php:16

Mahara at King's College: Site unavailable
A nonrecoverable error occurred. This probably means you have encountered a bug in the system

Then the user is locked out until a full site cache/cookie clearing. Try again and it happens again.

My host won't update the site, so I can't test if this addresses the issue (bugs.launchpad.net/mahara/22.04/+bug/1975428)

The host says there are no duplicate users with the email/username of my affected students, either.

Do you have any ideas where I can look next? 🙏 Thank you for considering.

10 May 2023, 14:25

Hi Pete,

These errors look like something is going wrong with sessions - as the errors you pasted look to occur when the system tries to check if the user is still logged in but thinks the user is ID = 0 (actually the logged out guest session) and tries to save the user with no username.

Can I get you to check something?

Go to the directory mentioned in your config.php file $cfg->dataroot value and then check that the 'sessions' directory and all of it's sub directories are owned by the webserver, for example on my Ubuntu that is www-data

In 'sessions' directory there should be subdirectories from 0 to 9 and a to v

If any are missing then delete the '0' directory and all it's subdirectories and reload mahara and it should build the missing 'session' directories.

Also check what $cfg->session_timeout is set to (note this value is in seconds) it might be a bit too low causing people to be logged out while editing portfolios if they don't save / reload page in a timely fashion.

Cheers

Robert

19 May 2023, 0:27

Thanks for the reply, Robert! I got the host to check this out and they reported:

Sessions are handed by a memcache server rather than with files.  All of our Mahara-using customers are set up the same way. So I don't think the session directories are relevant.  But I am going to clear them anyway.
 
The session timeout config item is not set in the config.php, so it is currently whatever the default Mahara setting is - looking in the site options, Session timeout is set to 120 minutes.

What's got me so stumped is that I gave one user a whole new, solely internal account and she still had issues getting booted. But in the previous (SAML) situation she'd get booted and couldn't login again until she cleared the browser cache. Now she can get in and work for a longer than the SAML account, but gets booted eventually, anyway.

One other big shift that happened: when we moved to the host, they were most familiar with MySQL, but our database was PostgreSQL. Would anything in the database cause trouble like this?

02 February 2024, 6:59

Hi Pete,

We started to get the same issue after migrating our mahara environment to AWS.

We had to fall back to use file session because using memcached with elasticache got us into the same headache as you.

We are trying to get a workaround to be back using memcached but with no luck so far.

Did you find a work around it?

Have a nice day

Nelson

02 February 2024, 8:30

Unfortunately, no. Our instance is hosted by OpenLMS, so I don't know what most of the terms you mentioned mean. I'm a front-end trainer, type. The problem persisted, but it was so erratic that they didn't really seem to believe it was a problem. They've stopped supporting it, so I'm pulling our data now. Funny timing!

02 February 2024, 9:14

Thanks for taking the time to answer Pete.

I understand your situation, I deal with the whole mahara stack so I did not have the choice that to get a workaround because that problem happened most of the time a the users where frustrated (understably). Well, most of what I mentioned was backend stuff, so it is natural that it does not sound to you.

Sorry to hear that you did not get a solution... maybe Robert Lyon can have some new hints for us :)

Good luck!

02 February 2024, 14:29

Hi,

I chatted with some folks that use AWS and they said they also had trouble with memcached so switched to using redis as the session handler and that sorted their problems.

For them it was an issue where there was a load-balanced front end the memcached session wasn't being shared correctly.

The redis session handler was able to handle that fine.

Hope that helps

Cheers

Robert

03 February 2024, 1:50

Thanks Robert,

We used to handle the memcached session without problems when we were on premises. The problem started when we switched to elasticache. The memcached server is completely independent of our web server instances, so, it does not seem to be an issue of sharing the session data.
It seems something that corrupts the session after some usage and we lost the user information and that makes the system unusable... So far, falling back to the filesystem, we are ok and as we dont have that many users, the system works.

Thank you again for your answer.

Have a nice day

Nelson