[OPENAM-10619] Post Authentication Plugin not run during session upgrade Created: 14/Feb/17  Updated: 05/Sep/19  Resolved: 19/Dec/17

Status: Closed
Project: OpenAM
Component/s: authentication
Affects Version/s: 13.0.0, 13.5.0, 13.5.1, 14.1.1, 14.5.0
Fix Version/s: 13.5.2, 6.0.0, 14.1.2, 5.5.2

Type: Bug Priority: Major
Reporter: Jonathan Thomas Assignee: Lawrence Yarham
Resolution: Fixed Votes: 0
Labels: Community, EDISON
Remaining Estimate: Not Specified
Time Spent: Not Specified
Original Estimate: Not Specified
Environment:

Linux, Tomcat8, jdk7


Issue Links:
Duplicate
duplicates OPENAM-12421 Re-authentication/Session upgrade usi... Resolved
Target Version/s:
Rank: 1|hzsxgv:
Sprint: AM Sustaining Sprint 45, AM Sustaining Sprint 46
Story Points: 5
Needs backport:
Yes
Support Ticket IDs:
Verified Version/s:
Needs QA verification:
Yes
Functional tests:
No
Are the reproduction steps defined?:
Yes and I used the same an in the description

 Description   

During the last phases of session upgrade, starting of PostAuthPlugin fails because LoginState is unable to create session token. Possibly because the LoginState.session created for session upgrade is not valid:

amAuth:02/14/2017 01:42:51:626 PM CET: Thread[http-nio-8080-exec-2,5,main]: TransactionId[3cd9630d-0cf5-4aaf-a676-86abcad044ef-1373]
postLoginProcess Class Name is : com.sun.identity.authentication.spi.ReplayPasswd
amAuth:02/14/2017 01:42:51:627 PM CET: Thread[http-nio-8080-exec-2,5,main]: TransactionId[3cd9630d-0cf5-4aaf-a676-86abcad044ef-1373]
Error retrieving SSOToken :
com.iplanet.sso.SSOException: Invalid session ID.AQIC5wM2LY4SfcxaFQkKTJFrFxAOVXJuogneOby7rr6Q1z0.AAJTSQACMDEAAlNLABM0NTU0MzA5NTkxNjU4MjYxMzE2AAJTMQAA
at com.iplanet.sso.providers.dpro.SSOProviderImpl.createSSOToken(SSOProviderImpl.java:220)
at com.iplanet.sso.providers.dpro.SSOProviderImpl.createSSOToken(SSOProviderImpl.java:184)
at com.iplanet.sso.providers.dpro.SSOProviderImpl.createSSOToken(SSOProviderImpl.java:236)
at com.iplanet.sso.SSOTokenManager.createSSOToken(SSOTokenManager.java:367)
at com.sun.identity.authentication.service.LoginState.getSSOToken(LoginState.java:1856)
at com.sun.identity.authentication.service.LoginState.executePostProcessSPI(LoginState.java:4949)
at com.sun.identity.authentication.service.LoginState.postProcess(LoginState.java:4919)
at com.sun.identity.authentication.service.AMLoginContext.postProcessOnSuccess(AMLoginContext.java:1944)
at com.sun.identity.authentication.service.AMLoginContext.getStatus(AMLoginContext.java:1058)
at com.sun.identity.authentication.server.AuthContextLocal.submitRequirements(AuthContextLocal.java:619)
at org.forgerock.openam.core.rest.authn.core.wrappers.AuthContextLocalWrapper.submitRequirements(AuthContextLocalWrapper.java:114)
at org.forgerock.openam.core.rest.authn.core.LoginProcess.next(LoginProcess.java:171)
at org.forgerock.openam.core.rest.authn.RestAuthenticationHandler.processAuthentication(RestAuthenticationHandler.java:262)
at org.forgerock.openam.core.rest.authn.RestAuthenticationHandler.authenticate(RestAuthenticationHandler.java:167)
at org.forgerock.openam.core.rest.authn.RestAuthenticationHandler.initiateAuthentication(RestAuthenticationHandler.java:98)
at org.forgerock.openam.core.rest.authn.http.AuthenticationServiceV1.authenticate(AuthenticationServiceV1.java:142)
at sun.reflect.GeneratedMethodAccessor75.invoke(Unknown Source)

To recreate I:

  1. did install tomcat8 (latest as of today, 8.5.11)
  2. did install openam13 (downloaded OpenAM-13.0.0.zip, copied war to tomcat webapps dir as openam.war; chose default install and entered the passwords)
  3. did configure openam to debuglog on message level
  4. did configure post auth plugin for the root realm (realms -> top level realm -> authentication -> settings -> post authentication processing -> entered "com.sun.identity.authentication.spi.ReplayPasswd" as Authentication Post Processing Classes, saved)
  5. checked with curl that authentication succeeds and pap will run:
    ??$ curl -X POST -H 'Content-type: application/octet-stream' -H 'X-OpenAM-username: demo' -H 'X-OpenAM-Password: changeit' 'http://localhost:8080/openam/json/authenticate?authIndexType=service&authIndexValue=ldapService'; echo {"tokenId":"AQIC5wM2LY4SfcyaAHCimazNYpigUeGBHijEBhvLsnZy1zI.*AAJTSQACMDEAAlNLABQtODEzNTE4NzAwODkzNTg0OTQ2NQACUzEAAA..*","successUrl":"/openam/console"}

    ??

amAuth:02/14/2017 02:12:18:150 PM CET: Thread[http-nio-8080-exec-6,5,main]: TransactionId[3cd9630d-0cf5-4aaf-a676-86abcad044ef-1534]
setPostLoginInstances : com.sun.identity.authentication.spi.ReplayPasswd
amAuth:02/14/2017 02:12:18:150 PM CET: Thread[http-nio-8080-exec-6,5,main]: TransactionId[3cd9630d-0cf5-4aaf-a676-86abcad044ef-1534]
setPostLoginInstances : 1
amAuth:02/14/2017 02:12:18:150 PM CET: Thread[http-nio-8080-exec-6,5,main]: TransactionId[3cd9630d-0cf5-4aaf-a676-86abcad044ef-1534]
postLoginProcess Class Name is : com.sun.identity.authentication.spi.ReplayPasswd
ReplayPasswd:02/14/2017 02:12:18:150 PM CET: Thread[http-nio-8080-exec-6,5,main]: TransactionId[3cd9630d-0cf5-4aaf-a676-86abcad044ef-1534]
ReplayPasswd.onLoginSuccess called: Req:http://localhost:8080/openam/json/authenticate
ReplayPasswd:02/14/2017 02:12:18:150 PM CET: Thread[http-nio-8080-exec-6,5,main]: TransactionId[3cd9630d-0cf5-4aaf-a676-86abcad044ef-1534]
ReplayPasswd.encodePassword: cannot encode password, Replay PaswordKey is empty
ReplayPasswd:02/14/2017 02:12:18:150 PM CET: Thread[http-nio-8080-exec-6,5,main]: TransactionId[3cd9630d-0cf5-4aaf-a676-86abcad044ef-1534]
WARNING: ReplayPasswd: unable to set encrypted Password as encrypted value is empty
ReplayPasswd:02/14/2017 02:12:18:150 PM CET: Thread[http-nio-8080-exec-6,5,main]: TransactionId[3cd9630d-0cf5-4aaf-a676-86abcad044ef-1534]
ReplayPasswd.onLoginSuccess: Replay password concluded successfully

  1. tried session upgrade (note the ForceAuth, rest layer would otherwise short-circuit the request. In real case we will use force auth as we have a rerunnable authentication chain. Nevertheless the problem seems to be present even without force auth)

curl -X POST -H 'Content-type: application/octet-stream' -H 'X-OpenAM-username: demo' -H 'X-OpenAM-Password: changeit' 'http://localhost:8080/openam/json/authenticate?authIndexType=service&authIndexValue=ldapService&sessionUpgradeSSOTokenId=AQIC5wM2LY4SfcyaAHCimazNYpigUeGBHijEBhvLsnZy1zI.AAJTSQACMDEAAlNLABQtODEzNTE4NzAwODkzNTg0OTQ2NQACUzEAAA..'&ForceAuth=true; echo

{"tokenId":"AQIC5wM2LY4SfcyaAHCimazNYpigUeGBHijEBhvLsnZy1zI.*AAJTSQACMDEAAlNLABQtODEzNTE4NzAwODkzNTg0OTQ2NQACUzEAAA..*","successUrl":"/openam/console"}

amAuth:02/14/2017 02:21:54:065 PM CET: Thread[http-nio-8080-exec-9,5,main]: TransactionId[3cd9630d-0cf5-4aaf-a676-86abcad044ef-1624]
postLoginProcess Class Name is : com.sun.identity.authentication.spi.ReplayPasswd
amAuth:02/14/2017 02:21:54:065 PM CET: Thread[http-nio-8080-exec-9,5,main]: TransactionId[3cd9630d-0cf5-4aaf-a676-86abcad044ef-1624]
Error retrieving SSOToken :
com.iplanet.sso.SSOException: Invalid session ID.AQIC5wM2LY4SfcyjtxW3mcWTEWHMYjOW84m1OQonGqk0Stg.AAJTSQACMDEAAlNLABQtMjYyODY3OTUxOTQ5MDM3NzAyMAACUzEAAA..
at com.iplanet.sso.providers.dpro.SSOProviderImpl.createSSOToken(SSOProviderImpl.java:220)
at com.iplanet.sso.providers.dpro.SSOProviderImpl.createSSOToken(SSOProviderImpl.java:184)
at com.iplanet.sso.providers.dpro.SSOProviderImpl.createSSOToken(SSOProviderImpl.java:236)
at com.iplanet.sso.SSOTokenManager.createSSOToken(SSOTokenManager.java:367)
at com.sun.identity.authentication.service.LoginState.getSSOToken(LoginState.java:1856)
at com.sun.identity.authentication.service.LoginState.executePostProcessSPI(LoginState.java:4949)
at com.sun.identity.authentication.service.LoginState.postProcess(LoginState.java:4919)
at com.sun.identity.authentication.service.AMLoginContext.postProcessOnSuccess(AMLoginContext.java:1944)
at com.sun.identity.authentication.service.AMLoginContext.getStatus(AMLoginContext.java:1058)
at com.sun.identity.authentication.server.AuthContextLocal.submitRequirements(AuthContextLocal.java:619)
at org.forgerock.openam.core.rest.authn.core.wrappers.AuthContextLocalWrapper.submitRequirements(AuthContextLocalWrapper.java:114)
at org.forgerock.openam.core.rest.authn.core.LoginProcess.next(LoginProcess.java:171)
at org.forgerock.openam.core.rest.authn.RestAuthenticationHandler.processAuthentication(RestAuthenticationHandler.java:262)

Handling of old and new sessions in LoginState and during authentication seems to be broken. It is not clear which session will be finally returned to user, from where the session ids come etc.



 Comments   
Comment by Andrew Vinall [ 15/Feb/17 ]

Bug Triage: Please raise a support ticket in Backstage.

Comment by Ľubomír Mlích [ 24/Jan/18 ]

Ok, I say it's verified and feel free to dispute it

Reproduced in OpenAM 13.5.0 Build 550cfe7d60 (2016-July-13 08:43)
Verified in OpenAM 13.5.2-RC1 Build be353da9e6 (2018-January-03 11:17) 

Comment by Ľubomír Mlích [ 24/Jan/18 ]

I thought it would be something like this, just wanted to confirm. Thanks.

Comment by Ľubomír Mlích [ 05/Sep/19 ]

In ForgeRock Access Management 5.5.1 Build 96b47ad4f1 (2017-October-26 15:41) I see one PAP plugin call after first login and session upgrade ends with HTTP 500 error.

ForgeRock Access Management 5.5.2-M7 Build 965200a558 (2019-August-20 08:11) I see two PAP plugin calls in debug, after login and after session upgrade resulting in HTTP 200 and id token.

Generated at Tue May 11 10:03:39 UTC 2021 using Jira 8.16.0#816000-sha1:a455b91378454416b49bbc88d03e653cb9815ed5.