Topic on Extension talk:PluggableAuth

Good evening,

First off, I'd like to thank you for your work on this plugin. It's a lot easier to work with this than try to understand MediaWiki's documentation for their AuthManager. That being said, however, I am still having issues getting this plugin to work properly. I've got my AuthProvider subclass pulling the necessary information from Symfony's security token and passing it to the authorize function (and PluggableAuth confirming that the user is authorized in debug), but I still receive the error: "Login failed in primary authentication by PluggableAuthPrimaryAuthenticationProvider". There also seems to be numerous messages about the session data being dirty, but I'm not sure if that's relevant or normal operation.

I've gone ahead and just set the authorize function to pass static information to PluggableAuth (id null, and username, email, and real name all set to strings) to simply test, and receive the same issue as before. Would you be able to provide any insight to what may be going on? I can send you a complete log if necessary.

Thank you for your kind words.

Yes, seeing the log would be helpful, especially the part before the error. The message about the session data being dirty is normal. It is interesting that even your static test is failing. Could you please also provide the code you are using for the authenticate function?

I appreciate the help on this matter.

IP: (Redacted)

Start request GET /university/wiki/index.php?title=Special:UserLogin

HTTP HEADERS:

ACCEPT: text/html,application/xhtml+xml,application/xml;q=0.9,image/webp,image/apng,*/*;q=0.8

ACCEPT-ENCODING: gzip, deflate, br

ACCEPT-LANGUAGE: en-US,en;q=0.9

CONNECTION: keep-alive

DNT: 1

HOST: new.certainty3d.com

REFERER: https://new.certainty3d.com/university/wiki/

UPGRADE-INSECURE-REQUESTS: 1

USER-AGENT: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/72.0.3626.121 Safari/537.36

[caches] cluster: SqlBagOStuff, WAN: mediawiki-main-default, stash: db-replicated, message: SqlBagOStuff, session: SqlBagOStuff

[caches] LocalisationCache: using store LCStoreDB

[DBConnection] Wikimedia\Rdbms\LoadBalancer::openConnection: calling initLB() before first connection.

[DBReplication] Cannot use ChronologyProtector with EmptyBagOStuff.

[DBReplication] Wikimedia\Rdbms\LBFactory::getChronologyProtector: using request info {

"IPAddress": "(Redacted)",

"UserAgent": "Mozilla\/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit\/537.36 (KHTML, like Gecko) Chrome\/72.0.3626.121 Safari\/537.36",

"ChronologyProtection": false,

"ChronologyPositionIndex": 0,

"ChronologyClientId": null

}

[DBConnection] Wikimedia\Rdbms\LoadBalancer::openLocalConnection: connected to database 0 at 'localhost'.

[SQLBagOStuff] Connection 5927707 will be used for SqlBagOStuff

[session] SessionBackend "e60eer465i25v3(Redacted)" is unsaved, marking dirty in constructor

[session] SessionBackend "e60eer465i25v3(Redacted)" save: dataDirty=1 metaDirty=1 forcePersist=0

[cookie] already deleted setcookie: "certain1_wiki_session", "", "1520520908", "/", "", "1", "1"

[cookie] already deleted setcookie: "certain1_wikiUserID", "", "1520520908", "/", "", "1", "1"

[cookie] already deleted setcookie: "certain1_wikiToken", "", "1520520908", "/", "", "1", "1"

[cookie] already deleted setcookie: "forceHTTPS", "", "1520520908", "/", "", "", "1"

[DBConnection] Wikimedia\Rdbms\LoadBalancer::openLocalConnection: connected to database 0 at 'localhost'.

[session] SessionBackend "e60eer465i25v3(Redacted)" force-persist due to persist()

[session] SessionBackend "e60eer465i25v3(Redacted)" save: dataDirty=0 metaDirty=1 forcePersist=1

[cookie] setcookie: "certain1_wiki_session", "e60eer465i25v3(Redacted)", "0", "/", "", "1", "1"

[cookie] already deleted setcookie: "certain1_wikiUserID", "", "1520520908", "/", "", "1", "1"

[cookie] already deleted setcookie: "certain1_wikiToken", "", "1520520908", "/", "", "1", "1"

[cookie] already deleted setcookie: "forceHTTPS", "", "1520520908", "/", "", "", "1"

[session] SessionBackend "e60eer465i25v3(Redacted)" Taking over PHP session

[session] SessionBackend "e60eer465i25v3(Redacted)" save: dataDirty=0 metaDirty=1 forcePersist=1

[cookie] already set setcookie: "certain1_wiki_session", "e60eer465i25v3(Redacted)", "0", "/", "", "1", "1"

[cookie] already deleted setcookie: "certain1_wikiUserID", "", "1520520908", "/", "", "1", "1"

[cookie] already deleted setcookie: "certain1_wikiToken", "", "1520520908", "/", "", "1", "1"

[cookie] already deleted setcookie: "forceHTTPS", "", "1520520908", "/", "", "", "1"

[SQLBagOStuff] Connection 5927707 will be used for SqlBagOStuff

[MessageCache] MessageCache::load: Loading en... local cache is empty, got from global cache

Unstubbing $wgParser on call of $wgParser::firstCallInit from MessageCache->transform

Parser: using preprocessor: Preprocessor_DOM

Unstubbing $wgLang on call of $wgLang::_unstub from ParserOptions->__construct

[session] SessionBackend "e60eer465i25v3(Redacted)" data dirty due to dirty(): LoginSignupSpecialPage->execute/SpecialUserLogin->getToken/MediaWiki\Session\Session->getToken/MediaWiki\Session\Session->set/MediaWiki\Session\SessionBackend->dirty

QuickTemplate::__construct was called with no Config instance passed to it

[session] SessionBackend "e60eer465i25v3(Redacted)" save: dataDirty=1 metaDirty=0 forcePersist=0

[authentication] MediaWiki\Auth\LegacyHookPreAuthenticationProvider::testForAuthentication: No username in $reqs, skipping hooks

[session] SessionBackend "e60eer465i25v3(Redacted)" data dirty due to dirty(): MediaWiki\Auth\AuthManager->setAuthenticationSessionData/MediaWiki\Session\Session->setSecret/MediaWiki\Session\Session->getSecretKeys/MediaWiki\Session\Session->set/MediaWiki\Session\SessionBackend->dirty

[session] SessionBackend "e60eer465i25v3(Redacted)" data dirty due to dirty(): MediaWiki\Auth\AuthManager->setAuthenticationSessionData/MediaWiki\Session\Session->setSecret/MediaWiki\Session\Session->getSecretKeys/MediaWiki\Session\Session->set/MediaWiki\Session\SessionBackend->dirty

[session] SessionBackend "e60eer465i25v3(Redacted)" data dirty due to dirty(): MediaWiki\Auth\ThrottlePreAuthenticationProvider->testForAuthentication/MediaWiki\Auth\AuthManager->setAuthenticationSessionData/MediaWiki\Session\Session->setSecret/MediaWiki\Session\Session->set/MediaWiki\Session\SessionBackend->dirty

[session] SessionBackend "e60eer465i25v3(Redacted)" save: dataDirty=1 metaDirty=0 forcePersist=0

[session] SessionBackend "e60eer465i25v3(Redacted)" data dirty due to dirty(): AuthManagerSpecialPage->performAuthenticationStep/MediaWiki\Auth\AuthManager->beginAuthentication/MediaWiki\Session\Session->setSecret/MediaWiki\Session\Session->set/MediaWiki\Session\SessionBackend->dirty

[session] SessionBackend "e60eer465i25v3(Redacted)" save: dataDirty=1 metaDirty=0 forcePersist=0

[session] SessionBackend "e60eer465i25v3(Redacted)" data dirty due to dirty(): PluggableAuthPrimaryAuthenticationProvider->beginPrimaryAuthentication/MediaWiki\Auth\AuthManager->setAuthenticationSessionData/MediaWiki\Session\Session->setSecret/MediaWiki\Session\Session->set/MediaWiki\Session\SessionBackend->dirty

[session] SessionBackend "e60eer465i25v3(Redacted)" save: dataDirty=1 metaDirty=0 forcePersist=0

[session] SessionBackend "e60eer465i25v3(Redacted)" data dirty due to dirty(): PluggableAuthPrimaryAuthenticationProvider->beginPrimaryAuthentication/MediaWiki\Auth\AuthManager->setAuthenticationSessionData/MediaWiki\Session\Session->setSecret/MediaWiki\Session\Session->set/MediaWiki\Session\SessionBackend->dirty

[session] SessionBackend "e60eer465i25v3(Redacted)" save: dataDirty=1 metaDirty=0 forcePersist=0

[session] SessionBackend "e60eer465i25v3(Redacted)" data dirty due to dirty(): PluggableAuthPrimaryAuthenticationProvider->beginPrimaryAuthentication/MediaWiki\Auth\AuthManager->setAuthenticationSessionData/MediaWiki\Session\Session->setSecret/MediaWiki\Session\Session->set/MediaWiki\Session\SessionBackend->dirty

[session] SessionBackend "e60eer465i25v3(Redacted)" save: dataDirty=1 metaDirty=0 forcePersist=0

[session] SessionBackend "e60eer465i25v3(Redacted)" data dirty due to dirty(): PluggableAuthPrimaryAuthenticationProvider->beginPrimaryAuthentication/MediaWiki\Auth\AuthManager->setAuthenticationSessionData/MediaWiki\Session\Session->setSecret/MediaWiki\Session\Session->set/MediaWiki\Session\SessionBackend->dirty

[authentication] Primary login with PluggableAuthPrimaryAuthenticationProvider returned REDIRECT

[session] SessionBackend "e60eer465i25v3(Redacted)" data dirty due to dirty(): MediaWiki\Auth\AuthManager->beginAuthentication/MediaWiki\Auth\AuthManager->continueAuthentication/MediaWiki\Session\Session->setSecret/MediaWiki\Session\Session->set/MediaWiki\Session\SessionBackend->dirty

[session] SessionBackend "e60eer465i25v3(Redacted)" save: dataDirty=1 metaDirty=0 forcePersist=0

MediaWiki::preOutputCommit: primary transaction round committed

MediaWiki::preOutputCommit: pre-send deferred updates completed

MediaWiki::preOutputCommit: LBFactory shutdown completed

OutputPage::sendCacheControl: private caching; **

Request ended normally

[session] Saving all sessions on shutdown

[DBConnection] Wikimedia\Rdbms\LoadBalancer::closeAll: closing connection to database 'localhost'.

[DBConnection] Wikimedia\Rdbms\LoadBalancer::closeAll: closing connection to database 'localhost'.

wfClientAcceptsGzip: client accepts gzip.

MediaWiki\OutputHandler::handleGzip() is compressing output

IP: (Redacted)

Start request GET /university/wiki/index.php?title=Special:PluggableAuthLogin

HTTP HEADERS:

ACCEPT: text/html,application/xhtml+xml,application/xml;q=0.9,image/webp,image/apng,*/*;q=0.8

ACCEPT-ENCODING: gzip, deflate, br

ACCEPT-LANGUAGE: en-US,en;q=0.9

CONNECTION: keep-alive

COOKIE: certain1_wiki_session=e60eer465i25v3(Redacted)

DNT: 1

HOST: new.certainty3d.com

REFERER: https://new.certainty3d.com/university/wiki/

UPGRADE-INSECURE-REQUESTS: 1

USER-AGENT: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/72.0.3626.121 Safari/537.36

[caches] cluster: SqlBagOStuff, WAN: mediawiki-main-default, stash: db-replicated, message: SqlBagOStuff, session: SqlBagOStuff

[caches] LocalisationCache: using store LCStoreDB

[session] Session "e60eer465i25v3(Redacted)" requested without UserID cookie

[DBConnection] Wikimedia\Rdbms\LoadBalancer::openConnection: calling initLB() before first connection.

[DBReplication] Cannot use ChronologyProtector with EmptyBagOStuff.

[DBReplication] Wikimedia\Rdbms\LBFactory::getChronologyProtector: using request info {

"IPAddress": "(Redacted)",

"UserAgent": "Mozilla\/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit\/537.36 (KHTML, like Gecko) Chrome\/72.0.3626.121 Safari\/537.36",

"ChronologyProtection": false,

"ChronologyPositionIndex": 0,

"ChronologyClientId": null

}

[DBConnection] Wikimedia\Rdbms\LoadBalancer::openLocalConnection: connected to database 0 at 'localhost'.

[SQLBagOStuff] Connection 5927710 will be used for SqlBagOStuff

[DBConnection] Wikimedia\Rdbms\LoadBalancer::openLocalConnection: connected to database 0 at 'localhost'.

[PluggableAuth] In execute()

[PluggableAuth] Getting PluggableAuth singleton

[PluggableAuth] Class name: SymfonyAuthProvider

[AuthBridge] [Auth] Begin Symfony Authentication

[SQLBagOStuff] Connection 5927710 will be used for SqlBagOStuff

[PluggableAuth] Authenticated existing user: David

[session] SessionBackend "e60eer465i25v3(Redacted)" data dirty due to dirty(): PluggableAuthLogin->execute/MediaWiki\Auth\AuthManager->setAuthenticationSessionData/MediaWiki\Session\Session->setSecret/MediaWiki\Session\Session->set/MediaWiki\Session\SessionBackend->dirty

[session] SessionBackend "e60eer465i25v3(Redacted)" save: dataDirty=1 metaDirty=0 forcePersist=0

[session] SessionBackend "e60eer465i25v3(Redacted)" data dirty due to dirty(): PluggableAuthLogin->execute/MediaWiki\Auth\AuthManager->setAuthenticationSessionData/MediaWiki\Session\Session->setSecret/MediaWiki\Session\Session->set/MediaWiki\Session\SessionBackend->dirty

[session] SessionBackend "e60eer465i25v3(Redacted)" save: dataDirty=1 metaDirty=0 forcePersist=0

[session] SessionBackend "e60eer465i25v3(Redacted)" data dirty due to dirty(): PluggableAuthLogin->execute/MediaWiki\Auth\AuthManager->setAuthenticationSessionData/MediaWiki\Session\Session->setSecret/MediaWiki\Session\Session->set/MediaWiki\Session\SessionBackend->dirty

[PluggableAuth] User is authorized.

[session] SessionBackend "e60eer465i25v3(Redacted)" save: dataDirty=1 metaDirty=0 forcePersist=0

[session] SessionBackend "e60eer465i25v3(Redacted)" data dirty due to dirty(): PluggableAuthLogin->execute/MediaWiki\Auth\AuthManager->setAuthenticationSessionData/MediaWiki\Session\Session->setSecret/MediaWiki\Session\Session->set/MediaWiki\Session\SessionBackend->dirty

[session] SessionBackend "e60eer465i25v3(Redacted)" save: dataDirty=1 metaDirty=0 forcePersist=0

MediaWiki::preOutputCommit: primary transaction round committed

MediaWiki::preOutputCommit: pre-send deferred updates completed

MediaWiki::preOutputCommit: LBFactory shutdown completed

Unstubbing $wgLang on call of $wgLang::hasVariants from OutputPage->sendCacheControl

User: loading options for user 1 from override cache.

OutputPage::sendCacheControl: private caching; **

Request ended normally

[session] Saving all sessions on shutdown

[DBConnection] Wikimedia\Rdbms\LoadBalancer::closeAll: closing connection to database 'localhost'.

[DBConnection] Wikimedia\Rdbms\LoadBalancer::closeAll: closing connection to database 'localhost'.

wfClientAcceptsGzip: client accepts gzip.

MediaWiki\OutputHandler::handleGzip() is compressing output

IP: (Redacted)

Start request GET /university/wiki/index.php?title=Special:UserLogin/return&wpLoginToken=12d309e7fd6254f15e36088b(Redacted)

HTTP HEADERS:

ACCEPT: text/html,application/xhtml+xml,application/xml;q=0.9,image/webp,image/apng,*/*;q=0.8

ACCEPT-ENCODING: gzip, deflate, br

ACCEPT-LANGUAGE: en-US,en;q=0.9

CONNECTION: keep-alive

COOKIE: certain1_wiki_session=e60eer465i25v3(Redacted)

DNT: 1

HOST: new.certainty3d.com

REFERER: https://new.certainty3d.com/university/wiki/

UPGRADE-INSECURE-REQUESTS: 1

USER-AGENT: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/72.0.3626.121 Safari/537.36

[caches] cluster: SqlBagOStuff, WAN: mediawiki-main-default, stash: db-replicated, message: SqlBagOStuff, session: SqlBagOStuff

[caches] LocalisationCache: using store LCStoreDB

[session] Session "e60eer465i25v3(Redacted)" requested without UserID cookie

[DBConnection] Wikimedia\Rdbms\LoadBalancer::openConnection: calling initLB() before first connection.

[DBReplication] Cannot use ChronologyProtector with EmptyBagOStuff.

[DBReplication] Wikimedia\Rdbms\LBFactory::getChronologyProtector: using request info {

"IPAddress": "(Redacted)",

"UserAgent": "Mozilla\/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit\/537.36 (KHTML, like Gecko) Chrome\/72.0.3626.121 Safari\/537.36",

"ChronologyProtection": false,

"ChronologyPositionIndex": 0,

"ChronologyClientId": null

}

[DBConnection] Wikimedia\Rdbms\LoadBalancer::openLocalConnection: connected to database 0 at 'localhost'.

[SQLBagOStuff] Connection 5927712 will be used for SqlBagOStuff

[DBConnection] Wikimedia\Rdbms\LoadBalancer::openLocalConnection: connected to database 0 at 'localhost'.

[session] SessionBackend "e60eer465i25v3(Redacted)" data dirty due to dirty(): AuthManagerSpecialPage->handleReturnBeforeExecute/MediaWiki\Auth\AuthManager->setAuthenticationSessionData/MediaWiki\Session\Session->setSecret/MediaWiki\Session\Session->set/MediaWiki\Session\SessionBackend->dirty

MediaWiki::preOutputCommit: primary transaction round committed

MediaWiki::preOutputCommit: pre-send deferred updates completed

MediaWiki::preOutputCommit: LBFactory shutdown completed

Unstubbing $wgLang on call of $wgLang::hasVariants from OutputPage->sendCacheControl

OutputPage::sendCacheControl: private caching; **

Request ended normally

[session] Saving all sessions on shutdown

[session] SessionBackend "e60eer465i25v3(Redacted)" save: dataDirty=1 metaDirty=0 forcePersist=0

[DBConnection] Wikimedia\Rdbms\LoadBalancer::closeAll: closing connection to database 'localhost'.

[DBConnection] Wikimedia\Rdbms\LoadBalancer::closeAll: closing connection to database 'localhost'.

wfClientAcceptsGzip: client accepts gzip.

MediaWiki\OutputHandler::handleGzip() is compressing output

IP: (Redacted)

Start request GET /university/wiki/index.php?title=Special:UserLogin

HTTP HEADERS:

ACCEPT: text/html,application/xhtml+xml,application/xml;q=0.9,image/webp,image/apng,*/*;q=0.8

ACCEPT-ENCODING: gzip, deflate, br

ACCEPT-LANGUAGE: en-US,en;q=0.9

CONNECTION: keep-alive

COOKIE: certain1_wiki_session=e60eer465i25v3(Redacted)

DNT: 1

HOST: new.certainty3d.com

REFERER: https://new.certainty3d.com/university/wiki/

UPGRADE-INSECURE-REQUESTS: 1

USER-AGENT: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/72.0.3626.121 Safari/537.36

[caches] cluster: SqlBagOStuff, WAN: mediawiki-main-default, stash: db-replicated, message: SqlBagOStuff, session: SqlBagOStuff

[caches] LocalisationCache: using store LCStoreDB

[session] Session "e60eer465i25v3(Redacted)" requested without UserID cookie

[DBConnection] Wikimedia\Rdbms\LoadBalancer::openConnection: calling initLB() before first connection.

[DBReplication] Cannot use ChronologyProtector with EmptyBagOStuff.

[DBReplication] Wikimedia\Rdbms\LBFactory::getChronologyProtector: using request info {

"IPAddress": "(Redacted)",

"UserAgent": "Mozilla\/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit\/537.36 (KHTML, like Gecko) Chrome\/72.0.3626.121 Safari\/537.36",

"ChronologyProtection": false,

"ChronologyPositionIndex": 0,

"ChronologyClientId": null

}

[DBConnection] Wikimedia\Rdbms\LoadBalancer::openLocalConnection: connected to database 0 at 'localhost'.

[SQLBagOStuff] Connection 5927714 will be used for SqlBagOStuff

[DBConnection] Wikimedia\Rdbms\LoadBalancer::openLocalConnection: connected to database 0 at 'localhost'.

[session] SessionBackend "e60eer465i25v3(Redacted)" data dirty due to dirty(): AuthManagerSpecialPage->handleReturnBeforeExecute/MediaWiki\Auth\AuthManager->removeAuthenticationSessionData/MediaWiki\Session\Session->setSecret/MediaWiki\Session\Session->set/MediaWiki\Session\SessionBackend->dirty

[session] SessionBackend "e60eer465i25v3(Redacted)" save: dataDirty=1 metaDirty=0 forcePersist=0

[SQLBagOStuff] Connection 5927714 will be used for SqlBagOStuff

[MessageCache] MessageCache::load: Loading en... local cache is empty, got from global cache

Unstubbing $wgParser on call of $wgParser::firstCallInit from MessageCache->transform

Parser: using preprocessor: Preprocessor_DOM

Unstubbing $wgLang on call of $wgLang::_unstub from ParserOptions->__construct

QuickTemplate::__construct was called with no Config instance passed to it

[session] SessionBackend "e60eer465i25v3(Redacted)" data dirty due to dirty(): PluggableAuthPrimaryAuthenticationProvider->continuePrimaryAuthentication/MediaWiki\Auth\AuthManager->removeAuthenticationSessionData/MediaWiki\Session\Session->setSecret/MediaWiki\Session\Session->set/MediaWiki\Session\SessionBackend->dirty

[authentication] Login failed in primary authentication by PluggableAuthPrimaryAuthenticationProvider

[session] SessionBackend "e60eer465i25v3(Redacted)" data dirty due to dirty(): AuthManagerSpecialPage->handleFormSubmit/AuthManagerSpecialPage->performAuthenticationStep/MediaWiki\Auth\AuthManager->continueAuthentication/MediaWiki\Session\Session->remove/MediaWiki\Session\SessionBackend->dirty

[session] SessionBackend "e60eer465i25v3(Redacted)" save: dataDirty=1 metaDirty=0 forcePersist=0

[authevents] Login attempt

QuickTemplate::__construct was called with no Config instance passed to it

MediaWiki::preOutputCommit: primary transaction round committed

MediaWiki::preOutputCommit: pre-send deferred updates completed

MediaWiki::preOutputCommit: LBFactory shutdown completed

OutputPage::sendCacheControl: private caching; **

Request ended normally

[session] Saving all sessions on shutdown

[DBConnection] Wikimedia\Rdbms\LoadBalancer::closeAll: closing connection to database 'localhost'.

[DBConnection] Wikimedia\Rdbms\LoadBalancer::closeAll: closing connection to database 'localhost'.

wfClientAcceptsGzip: client accepts gzip.

MediaWiki\OutputHandler::handleGzip() is compressing output

[caches] cluster: SqlBagOStuff, WAN: mediawiki-main-default, stash: db-replicated, message: SqlBagOStuff, session: SqlBagOStuff

[caches] LocalisationCache: using store LCStoreDB

[caches] cluster: SqlBagOStuff, WAN: mediawiki-main-default, stash: db-replicated, message: SqlBagOStuff, session: SqlBagOStuff

[DBReplication] Cannot use ChronologyProtector with EmptyBagOStuff.

[DBReplication] Wikimedia\Rdbms\LBFactory::getChronologyProtector: using request info {

"IPAddress": "(Redacted)",

"UserAgent": "Mozilla\/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit\/537.36 (KHTML, like Gecko) Chrome\/72.0.3626.121 Safari\/537.36",

"ChronologyProtection": false,

"ChronologyPositionIndex": 0,

"ChronologyClientId": null

}

[caches] LocalisationCache: using store LCStoreDB

[DBReplication] Cannot use ChronologyProtector with EmptyBagOStuff.

[DBReplication] Wikimedia\Rdbms\LBFactory::getChronologyProtector: using request info {

"IPAddress": "(Redacted)",

"UserAgent": "Mozilla\/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit\/537.36 (KHTML, like Gecko) Chrome\/72.0.3626.121 Safari\/537.36",

"ChronologyProtection": false,

"ChronologyPositionIndex": 0,

"ChronologyClientId": null

}

[DBConnection] Wikimedia\Rdbms\LoadBalancer::openConnection: calling initLB() before first connection.

[DBConnection] Wikimedia\Rdbms\LoadBalancer::openLocalConnection: connected to database 0 at 'localhost'.

[DBConnection] Wikimedia\Rdbms\LoadBalancer::openLocalConnection: connected to database 0 at 'localhost'.

[SQLBagOStuff] Connection 5927717 will be used for SqlBagOStuff

[DBConnection] Wikimedia\Rdbms\LoadBalancer::openConnection: calling initLB() before first connection.

[SQLBagOStuff] Connection 5927717 will be used for SqlBagOStuff

[MessageCache] MessageCache::load: Loading en... local cache is empty, got from global cache

[DBConnection] Wikimedia\Rdbms\LoadBalancer::openLocalConnection: connected to database 0 at 'localhost'.

[DBConnection] Wikimedia\Rdbms\LoadBalancer::openLocalConnection: connected to database 0 at 'localhost'.

[SQLBagOStuff] Connection 5927719 will be used for SqlBagOStuff

[SQLBagOStuff] Connection 5927719 will be used for SqlBagOStuff

[DBConnection] Wikimedia\Rdbms\LoadBalancer::closeAll: closing connection to database 'localhost'.

[DBConnection] Wikimedia\Rdbms\LoadBalancer::closeAll: closing connection to database 'localhost'.

[DBConnection] Wikimedia\Rdbms\LoadBalancer::closeAll: closing connection to database 'localhost'.

[DBConnection] Wikimedia\Rdbms\LoadBalancer::closeAll: closing connection to database 'localhost'.

[caches] cluster: SqlBagOStuff, WAN: mediawiki-main-default, stash: db-replicated, message: SqlBagOStuff, session: SqlBagOStuff

[caches] LocalisationCache: using store LCStoreDB

[DBReplication] Cannot use ChronologyProtector with EmptyBagOStuff.

[DBReplication] Wikimedia\Rdbms\LBFactory::getChronologyProtector: using request info {

"IPAddress": "(Redacted)",

"UserAgent": "Mozilla\/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit\/537.36 (KHTML, like Gecko) Chrome\/72.0.3626.121 Safari\/537.36",

"ChronologyProtection": false,

"ChronologyPositionIndex": 0,

"ChronologyClientId": null

}

[DBConnection] Wikimedia\Rdbms\LoadBalancer::openConnection: calling initLB() before first connection.

[DBConnection] Wikimedia\Rdbms\LoadBalancer::openLocalConnection: connected to database 0 at 'localhost'.

[DBConnection] Wikimedia\Rdbms\LoadBalancer::openLocalConnection: connected to database 0 at 'localhost'.

[SQLBagOStuff] Connection 5927721 will be used for SqlBagOStuff

[SQLBagOStuff] Connection 5927721 will be used for SqlBagOStuff

[DBConnection] Wikimedia\Rdbms\LoadBalancer::closeAll: closing connection to database 'localhost'.

[DBConnection] Wikimedia\Rdbms\LoadBalancer::closeAll: closing connection to database 'localhost'.

My authenticate function after testing with passing static data: public function authenticate(&$id, &$username, &$realname, &$email, &$errorMessage){

     wfDebugLog( 'AuthBridge', '[Auth] Begin Symfony Authentication');
     // Let's set up an error message. Upon error, this should be
     // overwritten, so if we hard-fail we can provide an accurate
     // reason as to why.
     $errorMessage = 'error-unknown';
     $params = [];
     $id = null;
     $username = $email = 'email@email.com';
     $realname = 'David';
     return true;

}

I don't see anything obviously and definitively wrong, but I do have several questions.

Which version of PluggableAuth are you using?

In your static test, I believe you should use a username that does not have a '@' in it. Also, if the user already exists, you should set $id to the user ID of that user.

It is odd that you get:

[PluggableAuth] User is authorized.

with no indication of an error after it, but you then get:

[authentication] Login failed in primary authentication by PluggableAuthPrimaryAuthenticationProvider

later. The fact that you are setting $errorMessage to something other than null should cause an error, actually, but you should also see an error message. That's why I'm wondering if you're using an older version of PluggableAuth.

I set up a brand new wiki to test some things. I had the errormessage being overwritten in my authentication class, so I've gone and removed that so Pluggable would give me errors. The login form is now giving me the error: "Auto-creation of a local account failed: You have not specified a valid username". I plugged in testing1 for the username (which should be valid by any means) in the static authentication function, but that didn't seem to do much. I've also gone and manually traced through some of PluggableAuthPrimaryAuthenticationProvider and it seems to be running User::newFromName just fine (and returning a valid user object) so I don't know where the issue lies.

I think I'd grabbed the latest version of PluggableAuth. The extension.json says 5.6.

I was trying to test the autocreation of the user in the static function I had set up, but did attempt to manually set the ID to an existing user to see if logging in to an existing user would work. Didn't seem to in my initial test.

So I think what may have been causing all of these problems was having that error message set.

I didn't immediately see changes because of caching, but it seems to be working now in the new test wiki I had set up. I'll let you know if it gets resolved.