[OpenSAML] Digest/Signature value logging at Receiver's side - OpenSAML 2.0

[lakshmi narasimhan]

Hello all,

 

We are using OpenSAML 2.0 for creating and validating SAML assertion. When we(receiver/validator) generate the assertion on our side itself, we are able to validate the signature successfully using our OpenSAML validation code. However, when the sender sends a similar assertion to us, we are getting the following exception:

 

05-Jan-2009 20:53:11 org.apache.xml.security.signature.Reference verify
WARNING: Verification failed for URI "#afdg3vce"
org.opensaml.xml.validation.ValidationException: Signature did not validate against the credential's key
        at org.opensaml.xml.signature.SignatureValidator.validate(SignatureValidator.j­ava:78)
        at com.aviva.tam.pmi.ValidateSAML2Signature.signatureValidator(ValidateSAML2Si­gnature.java:168)
        at org.apache.jsp.service_005fprovider_jsp._jspService(service_005fprovider_js­p.java:241)
        at org.apache.jasper.runtime.HttpJspBase.service(HttpJspBase.java:70)
        at javax.servlet.http.HttpServlet.service(HttpServlet.java:803)
        at org.apache.jasper.servlet.JspServletWrapper.service(JspServletWrapper.java:­384)
        at org.apache.jasper.servlet.JspServlet.serviceJspFile(JspServlet.java:320)
        at org.apache.jasper.servlet.JspServlet.service(JspServlet.java:266)
        at javax.servlet.http.HttpServlet.service(HttpServlet.java:803)
        at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(Applicatio­nFilterChain.java:290)
        at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterC­hain.java:206)
        at org.netbeans.modules.web.monitor.server.MonitorFilter.doFilter(MonitorFilte­r.java:196)
        at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(Applicatio­nFilterChain.java:235)
        at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterC­hain.java:206)
        at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.j­ava:228)
        at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.j­ava:175)
        at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:12­8)
        at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:10­4)
        at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.jav­a:109)
        at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:216)
        at org.apache.coyote.http11.Http11Processor.process(Http11Processor.java:844)
        at org.apache.coyote.http11.Http11Protocol$Http11ConnectionHandler.process(Htt­p11Protocol.java:634)
        at org.apache.tomcat.util.net.JIoEndpoint$Worker.run(JIoEndpoint.java:445)
        at java.lang.Thread.run(Unknown Source)

 

We are sure we are using the correct public key for validating the signature (we verified the public key successfully using the signature value and the original assertion content using OpenSSL utility). It could be that we are getting a different Digest value than what's being computed at the sender's side. However, we are not able to find out how we can turn-on logging to capture the digest value that gets computed at our end(receiving side). We would like to see the actual Digest value that gets computed as a result of Canonicalizing the message digest we receive. 

 

Can someone please guide us on how best we can achieve this and also what loggers need to be enabled? Any help would be gratefully received.

 

Thanks in advance,

Laks.     

[Scott Cantor]

> Can someone please guide us on how best we can achieve this and also what
> loggers need to be enabled? Any help would be gratefully received.

The category is org.apache.xml.security.utils.DigesterOutputStream

-- Scott

[lakshmi narasimhan]

Thanks for the quick response! I enabled logging for the given category. However, I am still not able to see the Digest value in the logs. Here is the log I'm seeing:

 

06 Jan 2010 15:37:40,035 DEBUG SignatureValidator : Attempting to validate signature using key from supplied credential

06 Jan 2010 15:37:40,035 DEBUG SignatureValidator : Creating XMLSignature object

06 Jan 2010 15:37:40,035 DEBUG SignatureValidator : Validating signature with signature algorithm URI: http://www.w3.org/2000/09/xmldsig#rsa-sha1

06 Jan 2010 15:37:40,035 DEBUG SignatureValidator : Validation credential key algorithm 'RSA', key instance class 'sun.security.rsa.RSAPublicKeyImpl'

06 Jan 2010 15:37:40,035 DEBUG XMLSignature : SignatureMethodURI = http://www.w3.org/2000/09/xmldsig#rsa-sha1

06 Jan 2010 15:37:40,035 DEBUG SignatureAlgorithm : Create URI "http://www.w3.org/2000/09/xmldsig#rsa-sha1" class "class org.apache.xml.security.algorithms.implementations.SignatureBaseRSA$SignatureRSASHA1"

06 Jan 2010 15:37:40,035 DEBUG JCEMapper : Request for URI http://www.w3.org/2000/09/xmldsig#rsa-sha1

06 Jan 2010 15:37:40,035 DEBUG SignatureBaseRSA : Created SignatureRSA using SHA1withRSA

06 Jan 2010 15:37:40,035 DEBUG XMLSignature : jceSigAlgorithm = SHA1withRSA

06 Jan 2010 15:37:40,035 DEBUG XMLSignature : jceSigProvider = SunRsaSign

06 Jan 2010 15:37:40,035 DEBUG XMLSignature : PublicKey = Sun RSA public key, 1024 bits

modulus: 144527689969456648621031867081668625591934928913828776896482250482665569845107097888771593165607135877494179594818957097695833486342364754373076091211224445098327383462514506470108892952821441828571770307210099337971034587639379246347385114506687414215313915604460209540424928001739558247290051916579336875697

public exponent: 65537

06 Jan 2010 15:37:40,067 DEBUG SignerOutputStream : Canonicalized SignedInfo:

06 Jan 2010 15:37:40,067 DEBUG SignerOutputStream : <ds:SignedInfo xmlns:ds="http://www.w3.org/2000/09/xmldsig#"><ds:CanonicalizationMethod Algorithm="http://www.w3.org/2001/10/xml-exc-c14n#"></ds:CanonicalizationMethod><ds:SignatureMethod Algorithm="http://www.w3.org/2000/09/xmldsig#rsa-sha1"></ds:SignatureMethod><ds:Reference URI="#2bab6345-e45f-436b-af65-ea0b1ea6faaa"><ds:Transforms><ds:Transform Algorithm="http://www.w3.org/2001/10/xml-exc-c14n#"></ds:Transform><ds:Transform Algorithm="http://www.w3.org/2000/09/xmldsig#enveloped-signature"></ds:Transform></ds:Transforms><ds:DigestMethod Algorithm="http://www.w3.org/2000/09/xmldsig#sha1"></ds:DigestMethod><ds:DigestValue>muqAFKmI4AzwVIu3caS1SJ6zg8w=</ds:DigestValue></ds:Reference></ds:SignedInfo>

06 Jan 2010 15:37:40,067 WARN XMLSignature : Signature verification failed.

06 Jan 2010 15:37:40,067 DEBUG SignatureValidator : Signature did not validate against the credential's key

06 Jan 2010 15:37:40,067 INFO ValidateSAML2Signature : Exception occurred during signature validationSignature did not validate against the credential's key

06 Jan 2010 15:37:40,067 DEBUG ValidateSAML2Signature : Exception occurred during signature validationSignature did not validate against the credential's key

Please advise.

 

Thanks in advance,

Laks.

On Wed, Jan 6, 2010 at 1:47 AM, Scott Cantor <cant...@osu.edu> wrote:

> Can someone please guide us on how best we can achieve this and also what
> loggers need to be enabled? Any help would be gratefully received.

[Scott Cantor]

> Thanks for the quick response! I enabled logging for the given category.
> However, I am still not able to see the Digest value in the logs. Here is
> the log I'm seeing:

It probably fails when it's digesting SignedInfo, it's not bothering with
the Reference.

-- Scott

[lakshmi narasimhan]

Hello!

 

I dug deep and found out that the API is throwing the error message at this point:

 

if (!sa.verify(sigBytes)) {
log.warn("Signature verification failed.");
return false;
}

in the source code below:

 

 

public boolean checkSignatureValue(Key pk) throws XMLSignatureException {
//COMMENT: pk suggests it can only be a public key?
//check to see if the key is not null
if (pk == null) {
Object exArgs[] = { "Didn't get a key" };
throw new XMLSignatureException("empty", exArgs);
}

try {
SignedInfo si = this.getSignedInfo();
//create a SignatureAlgorithms from the SignatureMethod inside
//SignedInfo. This is used to validate the signature.
SignatureAlgorithm sa = si.getSignatureAlgorithm();
if (log.isDebugEnabled()) {
log.debug("SignatureMethodURI = " + sa.getAlgorithmURI());
log.debug("jceSigAlgorithm = " + sa.getJCEAlgorithmString());
log.debug("jceSigProvider = " + sa.getJCEProviderName());
log.debug("PublicKey = " + pk);
}
byte sigBytes[] = null;
try {
sa.initVerify(pk);
// Get the canonicalized (normalized) SignedInfo
SignerOutputStream so = new SignerOutputStream(sa);
OutputStream bos = new UnsyncBufferedOutputStream(so);
si.signInOctectStream(bos);
bos.close();
// retrieve the byte[] from the stored signature
sigBytes = this.getSignatureValue();
} catch (IOException ex) {
// Impossible...but clear the verification cache anyway
sa.clearVerificationCache();
} catch (XMLSecurityException ex) {
sa.clearVerificationCache();
throw ex;
}
*************************  //Execution is failing at this point // ***************************

// have SignatureAlgorithm sign the input bytes and compare them to
// the bytes that were stored in the signature.
if (!sa.verify(sigBytes)) {
log.warn("Signature verification failed.");
return false;
}
return si.verify(this._followManifestsDuringValidation);
} catch (XMLSignatureException ex) {
throw ex;
} catch (XMLSecurityException ex) {
throw new XMLSignatureException("empty", ex);
}
}

 

I've been trying to figure out why this(Signature bytes comparison failure) is happening, but couldn't make it out yet. Could someone please help me out?

 

Thanks,

Laks.

 

On Wed, Jan 6, 2010 at 3:54 PM, Scott Cantor <cant...@osu.edu> wrote:

> Thanks for the quick response! I enabled logging for the given category.
> However, I am still not able to see the Digest value in the logs. Here is
> the log I'm seeing:

[Scott Cantor]

lakshmi narasimhan wrote on 2010-01-06:
> I've been trying to figure out why this(Signature bytes comparison
> failure) is happening, but couldn't make it out yet. Could someone
> please help me out?

All that's known is what I already told you. You need to determine what's
changing between signing and verification and why.

There are numerous tools like Oxygen and online verifiers like Aleksey
Sanin's that will prove to you whether the message is actually bad and that
this isn't about the code.

Welcome to signatures.

-- Scott

[lakshmi narasimhan]

Hello,

 

Thanks for this suggestion. I'll try using these tools to figure out what is changing between signing and verification. In my case, we, as the service provider, have developed a java code using OpenSAML 2.0. The identity Provider on the other end, has converted the OpenSAML API into Python and is using this code to generate the assertion.

 

We have also developed a java code to generate assertion from our side too, so we can generate and test our own assertions before receiving the one sent by the identity provider.

 

As of now, we are able to validate our own assertion successfully. However, when the identity provider sends a very similar assertion which uses the same Private key as we use, the assertion fails during the signature validation step(please refer to the code snippet below). The logs for both the cases, are almost the same until the point where Signature validation happens. At this point, the logging just stops and throws a warning saying 'Signature verification failed'. 

 

 

I was wondering if there is a way to find out what is failing at this point:

 

if (!sa.verify(sigBytes)) {
log.warn("Signature verification failed.");
return false;
}

I'm not sure how to turn on additional logging for the checkSignatureValue method in XMLSignature class. Could someone please help with a suggestion? This is a bit urgent, so any quick response would be very much appreciated.

 

Thanks in Advance,

Laks.

 

On Wed, Jan 6, 2010 at 8:07 PM, Scott Cantor <cant...@osu.edu> wrote:

lakshmi narasimhan wrote on 2010-01-06:

> I've been trying to figure out why this(Signature bytes comparison
> failure) is happening, but couldn't make it out yet. Could someone
> please help me out?

[Brent Putman]

On 1/21/10 6:56 PM, lakshmi narasimhan wrote:

As of now, we are able to validate our own assertion successfully. However, when the identity provider sends a very similar assertion which uses the same Private key as we use, the assertion fails during the signature validation step(please refer to the code snippet below). The logs for both the cases, are almost the same until the point where Signature validation happens.

In that case, one might obviously suspect that there is a bug in their Python XML signature impl (especially if they've coded it themselves), or at least in how they are wielding it.

 

I was wondering if there is a way to find out what is failing at this point:

 

if (!sa.verify(sigBytes)) {
log.warn("Signature verification failed.");
return false;
}

I can't remember if Scott already noted these or not in this thread, but important log info can be gotten by setting these log categories to DEBUG:

org.apache.xml.security.signature - the main XMLSignature related classes

org.apache.xml.security.utils.DigesterOutputStream - represents the Reference data to be digested

org.apache.xml.security.utils.SignerOutputStream    - represents the SignedInfo data to be signed


Or you could just go crazy and set all of org.apache.xml.security to DEBUG, that way you'll get pretty much everything.

Most likely, all of that is going to tell you that the verification of the Reference is failing.  And that's most likely either because: 1) the data really is being modified somewhere after they sign it and before you validate it, for example in the transmission process or serialization/de-serialization step (pretty printing, etc), or 2) their software has a bug, very possibly around how they calculate the canonicalized data over which they are computing the signature.  For the latter, you want to look at the DEBUG log output of that org.apache.xml.security.utils.DigesterOutputStream category, and compare with similar data they generate on their side.

[lakshmi narasimhan]

Thanks a ton Brent for such a quick response. This is very handy! Will check out both the possibilities.

-Laks.