search

otatarintseva / moodle-auth_samlidp

0 stars 5 forks source link

Error: 'moodle-userpass' not valid because we are not authenticated. (Moodle 3.9, PHP 7.4) #3

Open jstilwell opened 3 years ago

jstilwell commented 3 years ago

Hello, thank you for this plugin. I use it quite often, so I am pretty familiar with how to set it up and have it function correctly -- from both the IdP and SP side of the equation.

I built a new VM today on a new platform where the only real difference would be an upgrade from PHP 7.2 to PHP 7.4 and MariaDB 10.2 to MariaDB 10.5. However, no matter what I seem to try, I keep getting the error below:

Error: 'moodle-userpass' not valid because we are not authenticated.

I spent a few hours troubleshooting it but I can never get beyond this point. I captured debugging from the SimpleSAMLphp log and was hoping that you might be able to assist. 

Jan 27 11:37:52 simplesamlphp_moodle_prod INFO [dc5419b2ab] SAML2.0 - IdP.SSOService: Accessing SAML 2.0 IdP endpoint SSOService
Jan 27 11:37:52 simplesamlphp_moodle_prod DEBUG [dc5419b2ab] Received message:
Jan 27 11:37:52 simplesamlphp_moodle_prod DEBUG [dc5419b2ab] <samlp:AuthnRequest xmlns:samlp="urn:oasis:names:tc:SAML:2.0:protocol" xmlns:saml="urn:oasis:names:tc:SAML:2.0:assertion" ID="_73431af89b1873eef9e19cddc42414fb5003a57dff" Version="2.0" IssueInstant="2021-01-27T16:37:52Z" Destination="https://bespoke.remote-learner.net/simplesamlphp_moodle_prod/saml2/idp/SSOService.php" AssertionConsumerServiceURL="https://xxxxxxx.xxxxxxx.com/auth/saml2/sp/saml2-acs.php/xxxxxxx.xxxxxxx.com" ProtocolBinding="urn:oasis:names:tc:SAML:2.0:bindings:HTTP-POST">
Jan 27 11:37:52 simplesamlphp_moodle_prod DEBUG [dc5419b2ab]   <saml:Issuer>https://xxxxxxx.xxxxxxx.com/auth/saml2/sp/metadata.php</saml:Issuer>
Jan 27 11:37:52 simplesamlphp_moodle_prod DEBUG [dc5419b2ab]   <samlp:NameIDPolicy Format="urn:oasis:names:tc:SAML:1.1:nameid-format:unspecified"/>
Jan 27 11:37:52 simplesamlphp_moodle_prod DEBUG [dc5419b2ab] </samlp:AuthnRequest>
Jan 27 11:37:52 simplesamlphp_moodle_prod DEBUG [dc5419b2ab] Has 1 candidate keys for validation.
Jan 27 11:37:52 simplesamlphp_moodle_prod DEBUG [dc5419b2ab] Validation with key #0 succeeded.

Jan 27 11:37:52 simplesamlphp_moodle_prod INFO [dc5419b2ab] SAML2.0 - IdP.SSOService: incoming authentication request: 'https://xxxxxxx.xxxxxxx.com/auth/saml2/sp/metadata.php'

Jan 27 11:37:52 simplesamlphp_moodle_prod DEBUG [dc5419b2ab] Session: 'moodle-userpass' not valid because we are not authenticated.

Jan 27 11:37:52 simplesamlphp_moodle_prod WARNING [dc5419b2ab] The class or interface 'SimpleSAML_Auth_State' is now using namespaces, please use 'SimpleSAML\Auth\State'.
Jan 27 11:37:52 simplesamlphp_moodle_prod DEBUG [dc5419b2ab] Saved state: '_593b7e234a98612af579032b6f2e5aca9fbe11d8e7:https://yyyyyyy.yyyyyyy.net/simplesamlphp_moodle_prod/saml2/idp/SSOService.php?spentityid=https%3A%2F%2Fxxxxxxx.xxxxxxx.com%2Fauth%2Fsaml2%2Fsp%2Fmetadata.php&RelayState=https%3A%2F%2Fxxxxxxx.xxxxxxx.com%2Fauth%2Fsaml2%2Flogin.php%3Fwants%26idp%3Ddfade658c8c33651772c7c0780feb34a%26passive%3Doff&cookieTime=1611765472'
Jan 27 11:37:52 simplesamlphp_moodle_prod WARNING [dc5419b2ab] The class or interface 'SimpleSAML_Module' is now using namespaces, please use 'SimpleSAML\Module'.
Jan 27 11:37:52 simplesamlphp_moodle_prod WARNING [dc5419b2ab] The class or interface 'SimpleSAML_Utilities' is now using namespaces, please use 'SimpleSAML\Utilities'.
Jan 27 11:38:00 simplesamlphp_moodle_prod WARNING [dc5419b2ab] The class or interface 'SimpleSAML_Logger' is now using namespaces, please use 'SimpleSAML\Logger'.
Jan 27 11:38:00 simplesamlphp_moodle_prod WARNING [dc5419b2ab] The class or interface 'SimpleSAML_Auth_Source' is now using namespaces, please use 'SimpleSAML\Auth\Source'.
Jan 27 11:38:00 simplesamlphp_moodle_prod WARNING [dc5419b2ab] The class or interface 'SimpleSAML_Auth_State' is now using namespaces, please use 'SimpleSAML\Auth\State'.
Jan 27 11:38:00 simplesamlphp_moodle_prod DEBUG [dc5419b2ab] Loading state: '_593b7e234a98612af579032b6f2e5aca9fbe11d8e7:https://yyyyyyy.yyyyyyy.net/simplesamlphp_moodle_prod/saml2/idp/SSOService.php?spentityid=https%3A%2F%2Fxxxxxxx.xxxxxxx.com%2Fauth%2Fsaml2%2Fsp%2Fmetadata.php&RelayState=https%3A%2F%2Fxxxxxxx.xxxxxxx.com%2Fauth%2Fsaml2%2Flogin.php%3Fwants%26idp%3Ddfade658c8c33651772c7c0780feb34a%26passive%3Doff&cookieTime=1611765472'
Jan 27 11:38:00 simplesamlphp_moodle_prod WARNING [dc5419b2ab] The class or interface 'SimpleSAML_Configuration' is now using namespaces, please use 'SimpleSAML\Configuration'.
Jan 27 11:38:00 simplesamlphp_moodle_prod WARNING [dc5419b2ab] The class or interface 'SimpleSAML_Error_Exception' is now using namespaces, please use 'SimpleSAML\Error\Exception'.
Jan 27 11:38:00 simplesamlphp_moodle_prod ERROR [dc5419b2ab] SimpleSAML\Error\Error: UNHANDLEDEXCEPTION
Jan 27 11:38:00 simplesamlphp_moodle_prod ERROR [dc5419b2ab] Backtrace:
Jan 27 11:38:00 simplesamlphp_moodle_prod ERROR [dc5419b2ab] 1 /usr/share/simplesamlphp/www/_include.php:17 (SimpleSAML_exception_handler)
Jan 27 11:38:00 simplesamlphp_moodle_prod ERROR [dc5419b2ab] 0 [builtin] (N/A)
Jan 27 11:38:00 simplesamlphp_moodle_prod ERROR [dc5419b2ab] Caused by: SimpleSAML\Error\Exception: User not authenticated after login page.
Jan 27 11:38:00 simplesamlphp_moodle_prod ERROR [dc5419b2ab] Backtrace:
Jan 27 11:38:00 simplesamlphp_moodle_prod ERROR [dc5419b2ab] 3 /mnt/code/www/moodle_prod/auth/samlidp/moodle/lib/Auth/Source/External.php:91 (sspmod_moodle_Auth_Source_External::resume)
Jan 27 11:38:00 simplesamlphp_moodle_prod ERROR [dc5419b2ab] 2 /mnt/code/www/moodle_prod/auth/samlidp/moodle/www/resume.php:27 (require)
Jan 27 11:38:00 simplesamlphp_moodle_prod ERROR [dc5419b2ab] 1 /usr/share/simplesamlphp/lib/SimpleSAML/Module.php:266 (SimpleSAML\Module::process)
Jan 27 11:38:00 simplesamlphp_moodle_prod ERROR [dc5419b2ab] 0 /usr/share/simplesamlphp/www/module.php:10 (N/A)
Jan 27 11:38:00 simplesamlphp_moodle_prod ERROR [dc5419b2ab] Error report with id b10dd204 generated.
Jan 27 11:38:00 simplesamlphp_moodle_prod DEBUG [dc5419b2ab] Session: Valid session found with 'admin'.
Jan 27 11:38:00 simplesamlphp_moodle_prod DEBUG [dc5419b2ab] Localization: using old system
Jan 27 11:38:00 simplesamlphp_moodle_prod DEBUG [dc5419b2ab] Translate: Reading dictionary [/usr/share/simplesamlphp/dictionaries/errors]
iv-enovation commented 3 years ago

Hi

This "Error: 'moodle-userpass' not valid because we are not authenticated" is probably the most difficult thing to troubleshoot in the whole SimpleSAML story. Usually it means the SimpleSAMLphp's session cannot be saved, so here i'd first check 2 things: 1) if the session store in SimpleSAMLphp configuration is indeed SQL and it is configured correctly (DB credentials, tables' prefix) and 2) the SimpleSAMLphp's cookie name, if it does not collide with another set by some other instance of SimpleSAMLphp btw i just created a pull request, hopefully all those warnings about using namespaces will go