javawebspherespnegoltpa

Websphere7 - Spnego logon fails (LtpaToken2 parsing exception)


I'm using WebSphere 7.0.0.29 and I've problem with SPNEGO authorization - WAS returns HTTP Code 401 in second response and logon fails.

This is because (as I suppose) it can't parse LTPA Token (LtpaToken2) from client. It throws ArrayIndexOutOfBoundsException while Base64 decoding cookie with LtpaToken2. This LtpaToken2 in cookie in second client request is the same (as I can see) as token in first server response (Set-Cookie). So everything should be OK, but unfortunately it isn't :/

On my second, similar, environment (with the same version of WAS and the same its configuration) everything is OK - but it is in different domains, hence different domain controller.

While tedious comparing differences between client-server communication on these enviroments I noticed that on my non-working env, the LtpaToken2 is shorter(!) than on working one (as you can see in http_access.log). LtpaToken is shorter too. But I have no idea, why.

Maybe it is encoding cause? Or different KDC configuration...?

My client is Java Web Start 1.7.0_60-b19.

I'm pasting fragments of WebSphere logs. If something else would be helpful please let me know.


AppSrv01/logs/ffdc/server1_6150615_15.08.06_16.17.48.8658543509569228235853.txt:

[8/6/15 16:17:48:865 CEST]     FFDC Exception:java.lang.ArrayIndexOutOfBoundsException SourceId:com.ibm.ws.security.web.WebAuthenticator.handleSSO ProbeId:1257 Reporter:com.ibm.ws.security.web.WebAuthenticator@64bd64bd
    java.lang.ArrayIndexOutOfBoundsException
        at com.ibm.ws.security.util.Base64Coder.base64Decode(Base64Coder.java:51)
        at com.ibm.ws.security.util.Base64Coder.base64Decode(Base64Coder.java:109)
        at com.ibm.ws.security.web.WebAuthenticator.validateCookie(WebAuthenticator.java:1225)
        at com.ibm.ws.security.web.WebAuthenticator.handleSSO(WebAuthenticator.java:1139)
        at com.ibm.ws.security.web.WebAuthenticator.authenticate(WebAuthenticator.java:3291)
        at com.ibm.ws.security.web.WebAuthenticator.authenticate(WebAuthenticator.java:3143)
        at com.ibm.ws.security.web.WebCollaborator.authorize(WebCollaborator.java:1235)
        (...)

http_access.log (I've changed addresses):

ADDRESS_IP - - [06/Aug/2015:16:17:47 +0200] "POST ADDRESS HTTP/1.1" 200 - "-" "Java/1.7.0_60" "-"
ADDRESS_IP - - [06/Aug/2015:16:17:48 +0200] "POST ADDRESS HTTP/1.1" 401 148 "-" "Java/1.7.0_60" "null: LtpaToken:Tug3uTyc366i+dGtAAr/Hk1jm2zyUwO764AxDcjR//qzuxz+aTbQ2DwkygRbW9qJ5dKRIHhO+CmejTLNZTHzhSThiMDg59JF3JAASjCAQ0wVK29e/Ty4jlqx7CDPkONSf36iEfrxcjBtsrc+Sa1Y668XMWTW4Ri4G6HzJiOkvZYXrKgWjewP3qJRcEtn3GgSo/8V3qD20SAD3G94u4arGa5yL6l3838/Yw8gXwXiwEdB6hghlzHBsGLyyIloSFXIbljxB0b9GrI2kaU41D2+z+tWEk6x489SrhGNQrH7Gso LtpaToken2:jiF2h0WgMW2KlBS0Wf5wJvVziyZ8CR7HXvPedw/vVqLAbY6DLINVaCNS4UiEwDtJxVIVGIGP3XfqIY5DKOkTVxmeRRJBbEZCfqt0VYWLPWuh00glGNsDZDP5FH2+1HTBek/VhqQRl8K1vF3l5ZWUkamFQDVNlazMEG6GaamugenHDyyDwM7WPRTEzy1cFwRZvN7OAJqJy71DodO7ZSEqT4ad5SUdoc6AoOrEEXR2iEsiSj29+5SFOYe5OmeYZJeqsj2ac6bmL278pZsX1rx38LI9ncQUHg/rhCVHxuRrCrxy95Dtg+r7Z2S8zWfwMqSapqsApqlhKp+FJyVWqb3jnLjWUj+TeO3SOU0TYXiAoCznmyu6oRlq1FA4WVtaw34Pro52sv6FoX7ewPvFo6MpXwK9hiHuDMBJA+jJFSMr6gHa4d6/miQFtynLiLT+QyYl1+d9EJwZ16abq2TJCYR96g2Wl5PAUoR6iu4kMDghTQy3bKd1nfSF+Aink5c9WxDwZW3HUzXqtttcimGyrmi/+BE6oLj/oze3nsro/oFNVzL4/R6P10qEvD8bIYiOMQHgla1STjqJPXyZA+OrPYNGjDOVeOonBggmlbjmm7Nm9dk"

Example of http_access.log from working WAS:

ADDRESS_IP - - [06/Aug/2015:12:05:41 +0200] "POST ADDRESS HTTP/1.1" 200 - "-" "Java/1.7.0_60" "-"
ADDRESS_IP - - [06/Aug/2015:12:05:42 +0200] "POST ADDRESS HTTP/1.1" 200 - "-" "Java/1.7.0_60" "null: LtpaToken:nu4weYnVv5SyLBt94EdI/8hDq2Rcb/Qw9VRiMOmmtcVmsnLq6zId1iIgLHt0gciG2LlztUo9jgdG7sM3v2NwZ2IPiXamBJ3mNat1D9ZEcoTIqXfENnEN4k+Zr6SpN+PUxiMGQrSHZXWSJfkZ5fyUpxhvCyLBxdOJ8qIV1HRiFjzK/07J/0At4uI8Xj9okOnAjqB3snsRd2NYKArSZsiFbqC6mN7F9AR9dlzP10BrO1TOmIorfp8DSiJnr1sUZHlJjepE/vxlKdyaHWFsVQRrlkp3uL+oedT+ LtpaToken2:XVFROEeE5PBV5zLAwKVb2YFzZzKN2JJG7sJ2yFBMENl6hVewbiBjaAhdRI0vtsB18UHG24IQbKWUc6khnN6YqbHOCXocKQkgpSCMrvmi15TD7CT0a1k7dir4Y9/x9syOGLyeZ0/a134oB0Zc9neSntO8E1tb3SzvDnbsYRRaswGva+c2Ph5sbaXVMWUjou6IFHNcPguV2KmyrcWwH0b0xGuBfAbuN0L6ec1DNfprFLoQYZ3GaBDi7o+fRuhQBF1p1oU4o/PrtltbYd8GMTTp7SAdLCzaAULiiXRknz8i8qqVZhZvYwy5B0sRNCGpkYV4m/C8s8W54suvebuqJkKpupTJj4YurucKbQ36kxDT4sSe0TlZTBX5JjgFVYS6DCEZNthz3Kq3M+grgR5mYlol9IYdwkx6pYRd7k6RbaaDNzFTaoKwWdYFBV0hQLmoRxr/tzvdU/ob7gS0NzuM7pQDVV4ou9jYRRBVEp+NoIN9eqrXiSNhTHL1A/TFv8ZJq3iwph/kMltxWf4JOKxYEYZPLr5szwL56K81CwacW3lD+gidIBl7RBSwXzEslB8LpDbGIv1EVZWBTc3bRh4aVXuYQY5fV4TDazOdfxKusJBHCN7wNzBKK3c06mYXpCvZILgs"

trace.log (I've cut private data and some non significant lines):

[8/6/15 16:17:48:475 CEST] 00000036 TrustAssociat 2 com.ibm.ws.security.spnego.TrustAssociationInterceptorImpl negotiateValidateandEstablishTrust Authenticated user: ___USER___ Subject: Subject:
    Principal: USER@DOMAIN
    Private Credential: 
    (...)
[8/6/15 16:17:48:475 CEST] 00000036 TrustAssociat < com.ibm.ws.security.spnego.TrustAssociationInterceptorImpl negotiateValidateandEstablishTrust RETURN com.ibm.wsspi.security.tai.TAIResult@21c721c7
(...)
[8/6/15 16:17:48:878 CEST] 00000037 FfdcProvider  W com.ibm.ws.ffdc.impl.FfdcProvider logIncident FFDC1003I: FFDC Incident emitted on /home/wasadm/IBM/WebSphere/AppServer/profiles/AppSrv01/logs/ffdc/server1_6150615_15.08.06_16.17.48.8658543509569228235853.txt com.ibm.ws.security.web.WebAuthenticator.handleSSO 1257
[8/6/15 16:17:48:878 CEST] 00000037 TrustAssociat > com.ibm.ws.security.spnego.TrustAssociationInterceptorImpl getInstance ENTRY domainID: global
(...)
[8/6/15 16:17:48:887 CEST] 00000037 SpnegoHandler 2 com.ibm.ws.security.spnego.SpnegoHandler handleRequest No Authorization header found, sending **401** challenge to the client

Solution

  • After spending some time at analyzing issue I have finally found source of the problem! :)

    The problem was in my client code. I was parsing response from server (which contained LTPA tokens) in wrong way by splitting the cookies by "cookie.split("=").

    BUT the server response was already containing equals sign at the end of the cookie value: "LtpaToken2=abc123...def=". So my code was removing the last equals sing (that was very significant :) and sending the wrong cookie value to server.

    After fixing my code everything works OK :)