catalyst / moodle-auth_saml2

SAML done 100% in Moodle, fast, simple, secure
https://moodle.org/plugins/auth_saml2
72 stars 134 forks source link

Authentication not working #825

Closed fkohrt closed 4 months ago

fkohrt commented 4 months ago

What happened?

After upgrading Moodle from 4.3 to 4.4, SAML authentication stopped working.

Upon login, after entering credentials at the IdP, I am redirected to a blank /auth/saml2/login.php?wants&idp=[IDP]&passive=off, but I'm still not logged in.

However, the info page /auth/saml2/test.php says I'm authed and everything looks good there.

/var/log/nginx/error.log (With personal information redacted.) After navigating to `/login/index.php`: 2024/07/10 12:59:07 [error] 557206#557206: *16993 FastCGI sent in stderr: "PHP message: auth_saml2: loginpage_hook enter; PHP message: auth_saml2: should_login_redirect enter; PHP message: auth_saml2: should_login_redirect skipping due to dual auth; PHP message: auth_saml2: loginpage_hook exit" while reading response header from upstream, client: [IP], server: [MOODLE_HOST], request: "GET /login/index.php HTTP/1.1", upstream: "fastcgi://unix:/var/run/php/php8.2-fpm.sock:", host: "[MOODLE_HOST]", referrer: "https://[MOODLE_HOST]/" After clicking on "Login via SAML2": 2024/07/10 13:00:01 [error] 557206#557206: *16993 FastCGI sent in stderr: "PHP message: %date{%b %d %H:%M:%S} [IP] SimpleSAMLphp DEBUG [0d4f2ef43a] Session: '[MOODLE_HOST]' not valid because we are not authenticated.; PHP message: %date{%b %d %H:%M:%S} [IP] SimpleSAMLphp DEBUG [0d4f2ef43a] Saved state: '[SAVED_STATE]'; PHP message: %date{%b %d %H:%M:%S} [IP] SimpleSAMLphp DEBUG [0d4f2ef43a] Sending SAML 2 AuthnRequest to 'https://[IDP_HOST]/auth/realms/cloud'; PHP message: %date{%b %d %H:%M:%S} [IP] SimpleSAMLphp DEBUG [0d4f2ef43a] Sending message:; PHP message: %date{%b %d %H:%M:%S} [IP] SimpleSAMLphp DEBUG [0d4f2ef43a] ; PHP message: %date{%b %d %H:%M:%S} [IP] SimpleSAMLphp DEBUG [0d4f2ef43a] https://[MOODLE_HOST]/auth/saml2/sp/metadata.php; PHP message: %date{%b %d %H:%M:%S} [IP] SimpleSAMLphp DEBUG [0d4f2ef43a] ; PHP message: %date{%b %d %H:%M:%S} [IP] SimpleSAMLphp DEBUG [0d4f2ef43a] ; PHP message: %date{%b %d %H:%M:%S} [IP] SimpleSAMLphp DEBUG [0d4f2ef43a] Redirect to 1177 byte URL: https://[IDP_HOST]/auth/realms/cloud/protocol/saml?SAMLRequest=[SAML_REQUEST] After logging in at the IdP: 2024/07/10 13:01:09 [error] 557206#557206: *16993 FastCGI sent in stderr: "PHP message: %date{%b %d %H:%M:%S} [IP] SimpleSAMLphp DEBUG [0d4f2ef43a] Received message:; PHP message: %date{%b %d %H:%M:%S} [IP] SimpleSAMLphp DEBUG [0d4f2ef43a] ; PHP message: %date{%b %d %H:%M:%S} [IP] SimpleSAMLphp DEBUG [0d4f2ef43a] https://[IDP_HOST]/auth/realms/cloud; PHP message: %date{%b %d %H:%M:%S} [IP] SimpleSAMLphp DEBUG [0d4f2ef43a] ; PHP message: %date{%b %d %H:%M:%S} [IP] SimpleSAMLphp DEBUG [0d4f2ef43a] ; PHP message: %date{%b %d %H:%M:%S} [IP] SimpleSAMLphp DEBUG [0d4f2ef43a] ; PHP message: %date{%b %d %H:%M:%S} [IP] SimpleSAMLphp DEBUG [0d4f2ef43a] ; PHP message: %date{%b %d %H:%M:%S} [IP] SimpleSAMLphp DEBUG [0d4f2ef43a] ; PHP message: %date{%b %d %H:%M:%S} [IP] SimpleSAMLphp DEBUG [0d4f2ef43a] ; PHP message: %date{%b %d %H:%M:%S} [IP] SimpleSAMLphp DEBUG [0d4f2ef43a] ; PHP message: %date{%b %d %H:%M:%S} [IP] SimpleSAMLphp DEBUG [0d4f2ef43a] ; PHP message: %date{%b %d %H:%M:%S} 93 2024/07/10 13:01:09 [error] 557206#557206: *16993 FastCGI sent in stderr: "[DSIG]; PHP message: %date{%b %d %H:%M:%S} [IP] SimpleSAMLphp DEBUG [0d4f2ef43a] ; PHP message: %date{%b %d %H:%M:%S} [IP] SimpleSAMLphp DEBUG [0d4f2ef43a] ; PHP message: %date{%b %d %H:%M:%S} [IP] SimpleSAMLphp DEBUG [0d4f2ef43a] [DSIG_MODULUS]; PHP message: %date{%b %d %H:%M:%S} [IP] SimpleSAMLphp DEBUG [0d4f2ef43a] AQAB; PHP message: %date{%b %d %H:%M:%S} [IP] SimpleSAMLphp DEBUG [0d4f2ef43a] ; PHP message: %date{%b %d %H:%M:%S} [IP] SimpleSAMLphp DEBUG [0d4f2ef43a] ; PHP message: %date{%b %d %H:%M:%S} [IP] SimpleSAMLphp DEBUG [0d4f2ef43a] ; PHP message: %date{%b %d %H:%M:%S} [IP] SimpleSAMLphp DEBUG [0d4f2ef43a] ; PHP message: %date{%b %d %H:%M:%S} [IP] SimpleSAMLphp DEBUG [0d4f2ef43a] ; PHP message: %date{%b %d %H:%M:%S} [IP] SimpleSAMLphp DEBUG [0d4f2ef43a] ; PHP message: %date{%b %d %H:%M:%S} [IP] SimpleSAMLphp DEBUG [0d4f2ef43a] ; PHP message: %date{%b %d %H:%M:%S} [IP] SimpleSAMLphp DEBUG [0d4f2ef43a] ; PHP message: %date{%b %d %H:%M:%S} [IP] SimpleSAMLphp DEBUG [0d4f2ef43a] ; PHP message: %date{%b %d %H:%M:%S} [IP] SimpleSAMLphp DEBUG [0d4f2ef43a] urn:oasis:names:tc:SAML:2.0:ac:classes:unspecified; PHP message: %date{%b %d %H:%M:%S} [IP] SimpleSAMLphp DEBUG [0d4f2ef43a] ; PHP message: %date{%b %d %H:%M:%S} [IP] SimpleSAMLphp DEBUG [0d4f2ef43a] ; PHP message: %date{%b %d %H:%M:%S} [IP] SimpleSAMLphp DEBUG [0d4f2ef43a] ; PHP message: %date{%b %d %H:%M:%S} [IP] SimpleSAMLphp DEBUG [0d4f2ef43a] ; PHP message: %date{%b %d %H:%M:%S} [IP] SimpleSAMLphp DEBUG [0d4f2ef43a] [USER_EMAIL]; PHP message: %date{%b %d %H:%M:%S} [IP] SimpleSAMLphp DEBUG [0d4f2ef43a] ; PHP message: %date{%b %d %H:%M:%S} [IP] SimpleSAMLphp DEBUG [0d4f2ef43a] ; PHP message: %date{%b %d %H:%M:%S} [IP] SimpleSAMLphp DEBUG [0d4f2ef43a] query-clients; PHP message: %date{%b %d %H:%M:%S} [IP] SimpleSAMLphp DEBUG [0d4f2ef43a] view-users; PHP message: %date{%b %d %H:%M:%S} [IP] SimpleSAMLphp DEBUG [0d4f2ef43a] view-identity-providers; PHP message: %date{%b %d %H:%M:%S} [IP] SimpleSAMLphp DEBUG [0d4f2ef43a] manage-account-links; PHP message: %date{%b %d %H:%M:%S} [IP] SimpleSAMLphp DEBUG [0d4f2ef43a] view-events; PHP message: %date{%b %d %H:%M:%S} [IP] SimpleSAMLphp DEBUG [0d4f2ef43a] manage-clients; PHP message: %date{%b %d %H:%M:%S} [IP] SimpleSAMLphp DEBUG [0d4f2ef43a] query-groups; PHP message: %date{%b %d %H:%M:%S} [IP] SimpleSAMLphp DEBUG [0d4f2ef43a] 2024/07/10 13:01:09 [error] 557206#557206: *16993 FastCGI sent in stderr: "/2001/XMLSchema" xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance" xsi:type="xs:string">impersonation; PHP message: %date{%b %d %H:%M:%S} [IP] SimpleSAMLphp DEBUG [0d4f2ef43a] view-realm; PHP message: %date{%b %d %H:%M:%S} [IP] SimpleSAMLphp DEBUG [0d4f2ef43a] manage-realm; PHP message: %date{%b %d %H:%M:%S} [IP] SimpleSAMLphp DEBUG [0d4f2ef43a] manage-identity-providers; PHP message: %date{%b %d %H:%M:%S} [IP] SimpleSAMLphp DEBUG [0d4f2ef43a] manage-authorization; PHP message: %date{%b %d %H:%M:%S} [IP] SimpleSAMLphp DEBUG [0d4f2ef43a] query-realms; PHP message: %date{%b %d %H:%M:%S} [IP] SimpleSAMLphp DEBUG [0d4f2ef43a] default-roles-cloud; PHP message: %date{%b %d %H:%M:%S} [IP] SimpleSAMLphp DEBUG [0d4f2ef43a] 2024/07/10 13:01:09 [error] 557206#557206: *16993 FastCGI sent in stderr: "dORAddress', 'urn:oid:0.9.2342.19200300.100.1.20' => 'homePhone', 'urn:oid:0.9.2342.19200300.100.1.21' => 'secretary', 'urn:oid:0.9.2342.19200300.100.1.22' => 'otherMail...; PHP message: %date{%b %d %H:%M:%S} [IP] SimpleSAMLphp DEBUG [0d4f2ef43a] Deleting state: '[SAVED_STATE]'; PHP message: %date{%b %d %H:%M:%S} [IP] SimpleSAMLphp DEBUG [0d4f2ef43a] Session: doLogin("[MOODLE_HOST]")" while reading response header from upstream, client: [IP], server: [MOODLE_HOST], request: "POST /auth/saml2/sp/saml2-acs.php/[MOODLE_HOST] HTTP/1.1", upstream: "fastcgi://unix:/var/run/php/php8.2-fpm.sock:", host: "[MOODLE_HOST]" 2024/07/10 13:01:09 [error] 557206#557206: *16993 FastCGI sent in stderr: "PHP message: %date{%b %d %H:%M:%S} [IP] SimpleSAMLphp DEBUG [0d4f2ef43a] Session: Valid session found with '[MOODLE_HOST]'.; PHP message: %date{%b %d %H:%M:%S} [IP] SimpleSAMLphp DEBUG [0d4f2ef43a] Session: Valid session found with '[MOODLE_HOST]'.; PHP message: auth_saml2: saml_login_complete found user [USER]" while reading response header from upstream, client: [IP], server: [MOODLE_HOST], request: "GET /auth/saml2/login.php?wants&idp=657109c5839f52704d2f5a2400ccec43&passive=off HTTP/1.1", upstream: "fastcgi://unix:/var/run/php/php8.2-fpm.sock:", host: "[MOODLE_HOST]"

Local login, of course, still works, but upon logout I am redirected to a blank /login/logout.php?sesskey=[SESSKEY] (though being logged out at the end).

On the IdP side nothing seems at odd.

Versions

  • Moodle: 4.4.1+ (Build: 20240705) (2024042201.04)
  • PHP: 8.2.20
  • postgres: 13.14
  • auth_saml2: 2022111701
fkohrt commented 4 months ago

Nevermind, upgrading to the version form GitHub rather than Moodle's plugin directory resolved the issue.

Duplicate of #86