Invalid token error for valid session when validating through Crowd REST API

[Heidi]

I am trying to keep a Crowd SSO session alive through posts to the token resource, as indicated in the docs. The session validity is checked by a GET using the cookie token immediately before, so I know the token itself is valid. However, I get back a 400 error from Crowd saying it is invalid.

This is the sequence of requests and the error message:

GET http://user:pass@myhost:8095/crowd/rest/usermanagement/1/session/abc123.json?expand=user

POST http://user:pass@myhost:8095/crowd/rest/usermanagement/1/session/abc123

post data = {"validationFactors":[{"name":"remote_addr","value":"123.123.123.123"}]} (where the value is my client's public IP)

response = 400 Bad Request: {"reason":"INVALID_SSO_TOKEN","message":"Token doesn't match the existing token."}

I know the session is valid since the first GET comes back as expected, so why would the POST return an error? Currently my only hypothesis is that the client IP does not match the IP that authentication was done with, or that Crowd is not expecting the client IP but something else. Could it be either of these?

[joe · Accepted solution]

Yes, it's very likely to be a difference in the validation factors. Increasing Crowd's logging and comparing the factors used in the initial creation (TokenKeyGenerator) and the retrieval (TokenAuthenticationManagerImpl) should show the difference.

[Heidi]

Session check and validation:

2012-08-08 10:27:27,953 http-8095-2 DEBUG [crowd.manager.authentication.TokenAuthenticationManagerImpl] validateUserToken: abc123
2012-08-08 10:27:27,953 http-8095-2 DEBUG [crowd.manager.authentication.TokenAuthenticationManagerImpl] genericValidateToken
2012-08-08 10:27:27,954 http-8095-2 DEBUG [crowd.manager.authentication.TokenAuthenticationManagerImpl] checking if the token is expired:
2012-08-08 10:27:27,954 http-8095-2 DEBUG [crowd.manager.authentication.TokenAuthenticationManagerImpl]         now:                    1344436047954
2012-08-08 10:27:27,954 http-8095-2 DEBUG [crowd.manager.authentication.TokenAuthenticationManagerImpl]         last accessed:  2012-08-08 10:27:23.811
2012-08-08 10:27:27,954 http-8095-2 DEBUG [crowd.manager.authentication.TokenAuthenticationManagerImpl]         difference:     4143
2012-08-08 10:27:27,954 http-8095-2 DEBUG [crowd.manager.authentication.TokenAuthenticationManagerImpl]         allowed elapse: 3600000
2012-08-08 10:27:27,954 http-8095-2 DEBUG [manager.token.factory.TokenKeyGeneratorImpl] Generating Token for principal: myusername
2012-08-08 10:27:27,955 http-8095-2 DEBUG [manager.token.factory.TokenKeyGeneratorImpl] Generating Token for principal: myusername
2012-08-08 10:27:27,955 http-8095-2 DEBUG [manager.token.factory.TokenKeyGeneratorImpl] Adding Random-Number of com.atlassian.crowd.model.authentication.ValidationFactor@16804aa9[name=Random-Number,value=...]
2012-08-08 10:27:27,955 http-8095-2 DEBUG [crowd.manager.authentication.TokenAuthenticationManagerImpl] Current Validation Factors:
com.atlassian.crowd.model.authentication.ValidationFactor@40a5a8c9[name=remote_addr,value=127.0.0.1]
2012-08-08 10:27:27,955 http-8095-2 DEBUG [crowd.manager.authentication.TokenAuthenticationManagerImpl] comparing existing token ... with a validation token ...
2012-08-08 10:27:27,955 http-8095-2 DEBUG [crowd.manager.authentication.TokenAuthenticationManagerImpl] The token keys don't match
 

[Heidi]

Thanks for the tip. I increased logging, but don't see a clear discrepancy in the validation factors. In fact, I get a notice saying 'The token keys don't match'. I've confirmed that the client app is using identical token values in the GET and POST urls -- it's pulled from the cookie, and not changed between requests.

I'm including the relevant sections of the logs here. Maybe there's something else I'm missing?

Token creation:

2012-08-08 10:27:23,737 http-8095-17 DEBUG [crowd.manager.authentication.TokenAuthenticationManagerImpl] Authenticating user: myusername
2012-08-08 10:27:23,810 http-8095-17 DEBUG [crowd.manager.authentication.TokenAuthenticationManagerImpl] generateUserToken: user myusername
2012-08-08 10:27:23,811 http-8095-17 DEBUG [manager.token.factory.TokenKeyGeneratorImpl] Generating Token for principal: myusername
2012-08-08 10:27:23,811 http-8095-17 DEBUG [manager.token.factory.TokenKeyGeneratorImpl] Adding remote address of 127.0.0.1
2012-08-08 10:27:23,811 http-8095-17 DEBUG [manager.token.factory.TokenKeyGeneratorImpl] Generating Token for principal: myusername
2012-08-08 10:27:23,811 http-8095-17 DEBUG [manager.token.factory.TokenKeyGeneratorImpl] Adding remote address of 127.0.0.1
2012-08-08 10:27:23,811 http-8095-17 DEBUG [manager.token.factory.TokenKeyGeneratorImpl] Adding Random-Number of com.atlassian.crowd.model.authentication.ValidationFactor@1dae3d5b[name=Random-Number,value=7978257918329571996]
2012-08-08 10:27:23,812 http-8095-17 DEBUG [crowd.dao.token.TokenDAOHibernate] Saving object: com.atlassian.crowd.model.token.Token@c01043ef
2012-08-08 10:27:23,812 http-8095-17 DEBUG [crowd.manager.authentication.TokenAuthenticationManagerImpl] Returning newly created token

[joe]

Thanks for those logs. Your second log, where the token is being validated, doesn't show a line for "Adding remote address" in its log. Looking later, the IP is shown as a factor with a name of "remote_addr", so it's being taken into account. However, the special name for the remote address factor is "remote_address". Change your code to pass that and you should see this working.

Please let me know if there's any documentation we need to fix here; I can see that we could make this situation easier to debug!

[Heidi]

Thank you, that was exactly it. I copied the JSON from somewhere, but checking your examples here, the factor name is correct in all examples.

Outside my clear typo here, the documentation is very good with providing examples, perhaps just lacking a bit in highlighting/explaining differences between the XML and JSON formats. Concretely, it wasn't clear to me initially whether the session validation call does or doesn't contain a wrapping "validation-factors" node, whereas the XML does, and the hyphenation vs. camel-casing is a bit confusing.

Thanks again for your assistance!

[JustinK]

myusername and abc123 are two different usernames .... can you make sure that you have the same user authing and validating.

[Heidi]

Um... I'm fairly certain I obfuscated those accurately - replacing my actual user name and token where they appeared in the logs.

[JustinK]

I am not sure how anyone can help you effectively if you change the values of the things we are actually trying to check, especially if you didn't change them consistently