[OPENAM-10311] Insufficient error logging for "The SAML Request is invalid" Created: 03/Jan/17  Updated: 09/Jan/17  Resolved: 09/Jan/17

Status: Closed
Project: OpenAM
Component/s: SAML
Affects Version/s: 10.0.0, 10.0.1, 10.1.0-Xpress, 10.0.2, 11.0.0, 11.0.1, 11.0.2, 11.0.3, 11.0.4, 12.0.0, 12.0.1, 12.0.2, 12.0.3, 12.0.4, 13.0.0
Fix Version/s: None

Type: Bug Priority: Major
Reporter: Bernhard Thalmayr Assignee: Unassigned
Resolution: Won't Fix Votes: 0
Labels: None
Remaining Estimate: Not Specified
Time Spent: Not Specified
Original Estimate: Not Specified
Environment:

Mac OS X - 10.11.6

java version "1.8.0_111"
Java(TM) SE Runtime Environment (build 1.8.0_111-b14)
Java HotSpot(TM) 64-Bit Server VM (build 25.111-b14, mixed mode)

Apache Tomcat/8.0.24

OpenAM 13.0.0 configured as IdP proxy


Rank: 1|hzspjj:

 Description   

SP-initiated SSO, started by sample app of Spring Security SAML extension fails with HTTP Status 500

excerpt of Tomcat access log
127.0.0.1 - - [03/Jan/2017:12:45:30 +0100] "GET /openam/SSORedirect/metaAlias/proxyidp?SAMLRequest=.....&SigAlg=http%3A%2F%2Fwww.w3.org%2F2000%2F09%2Fxmldsig%23rsa-sha1&Signature=A%2B%2FNq2qjF2AHY%2FmPTbRasavMps%2BqKf73gbtvyykU0Zj4To1%2FfDoA95OOd8jhvSL7bWZeJpWruLoNVilfyn6p4ivtEmI2Z%2FA%2Bh3g0w4vrVjG%2F6J09wu3SqW8ZxvZW%2BeFNewzIOffd5qvlqZEbz6OCozblHHhYyY5idxL1fGBnNZNlmZg7iu8sExr9Fd6HfP7WDYGL%2B8J7IPckojAM1I%2FTGNsYVvHrL%2FX7RnXE%2BNbkU0ZRa9WdXhtV%2F%2BctDKcenM1AMIIFMgybLT%2B7dQRrbFni2%2BOq0ztFrVEqM%2F1vqkGAkWSRnNcso%2Fcaxi6bA6ALSX64o6Y41xxdxCBlwtvA59iiRg%3D%3D HTTP/1.1" 500 1096

saml2error.jsp tells 'The SAML Request is invalid', however there is not a single error message or even stacktrace in OpenAM debug logs when debug level is set to error.

--> there is no chance to troubleshoot this issue in productive environment where typically only error level is configured.

ls -lrt
total 0
-rw-r--r--  1 openam  staff  0 Jan  3 12:50 Session
-rw-r--r--  1 openam  staff  0 Jan  3 12:50 IdRepo
-rw-r--r--  1 openam  staff  0 Jan  3 12:50 Federation
-rw-r--r--  1 openam  staff  0 Jan  3 12:50 CoreSystem
decoded SAML AuthnRequest
<saml2p:AuthnRequest xmlns:saml2p="urn:oasis:names:tc:SAML:2.0:protocol"
                     AssertionConsumerServiceURL="http://app.partner.xyz:8282/app/saml/SSO"
                     Destination="http://sso.test.xyz:8080/openam/SSORedirect/metaAlias/proxyidp"
                     ForceAuthn="false"
                     ID="a3303hbi8j1h27393b58d88e66f5255"
                     IsPassive="false"
                     IssueInstant="2017-01-03T11:45:29.889Z"
                     ProtocolBinding="urn:oasis:names:tc:SAML:2.0:bindings:HTTP-POST"
                     Version="2.0"
                     >
    <saml2:Issuer xmlns:saml2="urn:oasis:names:tc:SAML:2.0:assertion">http://app.partner.xyz:8282/app/saml/metadata</saml2:Issuer>
    <saml2p:Scoping ProxyCount="1" />
</saml2p:AuthnRequest>


 Comments   
Comment by Bernhard Thalmayr [ 03/Jan/17 ]

In this specific case the error was an incorrect issuer, but this is only logged at WARNING level, although it later on results in an error.

excerpt of OpenAM debug level, level set to message
WARNING: UtilProxySAMLAuthenticator.authenticate:  Issuer in Request is not valid.
Comment by Phill Cunnington [ 04/Jan/17 ]

Bernhard Thalmayr Did you test against 13.5 or 14 and find the issue is not present?

Comment by Andrew Vinall [ 09/Jan/17 ]

Bug Triage: Please re-open if this problem exists in AM14.

Generated at Wed Mar 03 21:25:29 UTC 2021 using Jira 7.13.12#713012-sha1:6e07c38070d5191bbf7353952ed38f111754533a.