Issue with invalidateSessionCookiesAfterAuthorizationFlow

By: Bruce Gordon Account Admin 29 May 2019 at 2:18 a.m. CDT

12 Responses
Bruce Gordon gravatar
This is related to the JSONConfiguration->oxAuthConfiguration->invalidateSessionCookiesAfterAuthorizationFlow. When running with Cache Redis as Cache provider after this is set to "true" it is no longer possible to log on. However "in memory" or "mem cached" work as expected.
CentOS 7.0
closed

Answers

By Yuriy Zabrovarnyy staff 29 May 2019 at 4 a.m. CDT

Copy
Yuriy Zabrovarnyy gravatar
1. Would you please attach oxauth.log file with log level TRACE ? 2. What type of redis connection do you use? (standalone, cluster, sharded) 3. If you set invalidateSessionCookiesAfterAuthorizationFlow=false, does it work good with redis? Thanks, Yuriy Z

By Bruce Gordon Account Admin 29 May 2019 at 4:31 a.m. CDT

Copy
Bruce Gordon gravatar
``` 2019-05-29 09:25:41,489 DEBUG [qtp804611486-17] [org.xdi.oxauth.service.UserService] (UserService.java:88) - Getting user information from LDAP: userId = admin 2019-05-29 09:25:41,533 DEBUG [qtp804611486-17] [org.xdi.oxauth.service.UserService] (UserService.java:97) - Found 1 entries for user id = admin 2019-05-29 09:25:41,710 TRACE [qtp804611486-17] [org.xdi.service.cache.RedisStandaloneProvider] (RedisStandaloneProvider.java:109) - put - key: client_id_@!69a6.3fd5.755b.ee1a!0001!7539.fc10!0008!c009.f7b8, status: OK 2019-05-29 09:25:41,713 TRACE [qtp804611486-17] [org.xdi.service.cache.RedisStandaloneProvider] (RedisStandaloneProvider.java:109) - put - key: client_dn_inum=@!69a6.3fd5.755b.ee1a!0001!7539.fc10!0008!c009.f7b8,ou=clients,o=@!69a6.3fd5.755b.ee1a!0001!7539.fc10,o=gluu, status: OK 2019-05-29 09:25:41,716 DEBUG [qtp804611486-17] [org.xdi.oxauth.service.ClientService] (ClientService.java:141) - Found 1 entries for client id = @!69A6.3FD5.755B.EE1A!0001!7539.FC10!0008!C009.F7B8 2019-05-29 09:25:41,753 DEBUG [qtp804611486-17] [org.xdi.oxauth.service.UserService] (UserService.java:88) - Getting user information from LDAP: userId = admin 2019-05-29 09:25:41,768 DEBUG [qtp804611486-17] [org.xdi.oxauth.service.UserService] (UserService.java:97) - Found 1 entries for user id = admin 2019-05-29 09:25:41,783 TRACE [qtp804611486-17] [org.xdi.oxauth.service.ClientService] (ClientService.java:199) - Get client from cache by Dn 'inum=@!69A6.3FD5.755B.EE1A!0001!7539.FC10!0008!C009.F7B8,ou=clients,o=@!69A6.3FD5.755B.EE1A!0001!7539.FC10,o=gluu' 2019-05-29 09:25:41,784 DEBUG [qtp804611486-17] [org.xdi.oxauth.service.ClientService] (ClientService.java:141) - Found 1 entries for client id = @!69A6.3FD5.755B.EE1A!0001!7539.FC10!0008!C009.F7B8 2019-05-29 09:25:41,859 TRACE [qtp804611486-17] [org.xdi.oxauth.service.SessionIdService] (SessionIdService.java:290) - Found session_id cookie: '8c444b54-5c44-40ef-a130-42929231c34d' 2019-05-29 09:25:41,865 TRACE [qtp804611486-17] [org.xdi.oxauth.service.SessionIdService] (SessionIdService.java:761) - Try to get session by id: 8c444b54-5c44-40ef-a130-42929231c34d ... 2019-05-29 09:25:41,865 TRACE [qtp804611486-17] [org.xdi.oxauth.service.SessionIdService] (SessionIdService.java:763) - Session dn: oxAuthSessionId=8c444b54-5c44-40ef-a130-42929231c34d,ou=session,o=@!69A6.3FD5.755B.EE1A!0001!7539.FC10,o=gluu 2019-05-29 09:25:41,868 TRACE [qtp804611486-17] [org.xdi.service.cache.RedisStandaloneProvider] (RedisStandaloneProvider.java:133) - remove - key: 8c444b54-5c44-40ef-a130-42929231c34d, entriesRemoved: 1 2019-05-29 09:25:41,998 TRACE [qtp804611486-17] [org.xdi.oxauth.service.GrantService] (GrantService.java:193) - Removed token from LDAP, code: {sha256Hex}74605aacb41cd25c461a628e230301a2845894049dc25da9ffa682920fa18226 2019-05-29 09:25:41,999 TRACE [qtp804611486-17] [org.xdi.service.cache.RedisStandaloneProvider] (RedisStandaloneProvider.java:133) - remove - key: @!69A6.3FD5.755B.EE1A!0001!7539.FC10!0008!C009.F7B8_{sha256Hex}81832503fe9082ab9b61bafce27a5742be1f1de8168c8298e22c70fa9efd0173, entriesRemoved: 0 2019-05-29 09:25:42,001 TRACE [qtp804611486-17] [org.xdi.oxauth.service.GrantService] (GrantService.java:193) - Removed token from LDAP, code: {sha256Hex}42ed79097d3a82ed7f91b9eff41b2b416a69e0b45aebad040e74e47ab2a1a998 2019-05-29 09:25:42,001 TRACE [qtp804611486-17] [org.xdi.service.cache.RedisStandaloneProvider] (RedisStandaloneProvider.java:133) - remove - key: @!69A6.3FD5.755B.EE1A!0001!7539.FC10!0008!C009.F7B8_{sha256Hex}81832503fe9082ab9b61bafce27a5742be1f1de8168c8298e22c70fa9efd0173, entriesRemoved: 0 2019-05-29 09:25:42,002 TRACE [qtp804611486-17] [org.xdi.service.cache.RedisStandaloneProvider] (RedisStandaloneProvider.java:133) - remove - key: {sha256Hex}169b32ae4369c1a43b1dde10311a80ee30e438efed747dedab124a2fd4f051e4, entriesRemoved: 1 2019-05-29 09:25:42,002 TRACE [qtp804611486-17] [org.xdi.oxauth.service.GrantService] (GrantService.java:190) - Removed token from cache, code: {sha256Hex}169b32ae4369c1a43b1dde10311a80ee30e438efed747dedab124a2fd4f051e4 2019-05-29 09:25:42,003 TRACE [qtp804611486-17] [org.xdi.service.cache.RedisStandaloneProvider] (RedisStandaloneProvider.java:133) - remove - key: @!69A6.3FD5.755B.EE1A!0001!7539.FC10!0008!C009.F7B8_{sha256Hex}81832503fe9082ab9b61bafce27a5742be1f1de8168c8298e22c70fa9efd0173, entriesRemoved: 0 2019-05-29 09:25:42,079 TRACE [qtp804611486-17] [org.xdi.oxauth.service.ClientService] (ClientService.java:199) - Get client from cache by Dn 'inum=@!69A6.3FD5.755B.EE1A!0001!7539.FC10!0008!C009.F7B8,ou=clients,o=@!69A6.3FD5.755B.EE1A!0001!7539.FC10,o=gluu' 2019-05-29 09:25:42,080 DEBUG [qtp804611486-17] [org.xdi.oxauth.service.ClientService] (ClientService.java:141) - Found 1 entries for client id = @!69A6.3FD5.755B.EE1A!0001!7539.FC10!0008!C009.F7B8 2019-05-29 09:25:42,094 DEBUG [qtp804611486-17] [org.xdi.oxauth.service.RedirectionUriService] (RedirectionUriService.java:119) - Validating post logout redirect URI: clientId = @!69A6.3FD5.755B.EE1A!0001!7539.FC10!0008!C009.F7B8, postLogoutRedirectUri = https://UC1SSODLOAD01/identity/authentication/finishlogout 2019-05-29 09:25:42,094 DEBUG [qtp804611486-17] [org.xdi.oxauth.service.RedirectionUriService] (RedirectionUriService.java:123) - Comparing https://UC1SSODLOAD01/identity/authentication/finishlogout == https://UC1SSODLOAD01/identity/authentication/finishlogout 2019-05-29 09:25:42,116 TRACE [qtp804611486-17] [org.xdi.oxauth.service.ClientService] (ClientService.java:199) - Get client from cache by Dn 'inum=@!69A6.3FD5.755B.EE1A!0001!7539.FC10!0008!C009.F7B8,ou=clients,o=@!69A6.3FD5.755B.EE1A!0001!7539.FC10,o=gluu' 2019-05-29 09:25:42,116 DEBUG [qtp804611486-17] [org.xdi.oxauth.service.ClientService] (ClientService.java:141) - Found 1 entries for client id = @!69A6.3FD5.755B.EE1A!0001!7539.FC10!0008!C009.F7B8 2019-05-29 09:25:42,477 TRACE [qtp804611486-16] [org.xdi.oxauth.service.ClientService] (ClientService.java:199) - Get client from cache by Dn 'inum=@!69A6.3FD5.755B.EE1A!0001!7539.FC10!0008!C009.F7B8,ou=clients,o=@!69A6.3FD5.755B.EE1A!0001!7539.FC10,o=gluu' 2019-05-29 09:25:42,478 DEBUG [qtp804611486-16] [org.xdi.oxauth.service.ClientService] (ClientService.java:141) - Found 1 entries for client id = @!69A6.3FD5.755B.EE1A!0001!7539.FC10!0008!C009.F7B8 2019-05-29 09:25:42,478 TRACE [qtp804611486-16] [org.xdi.oxauth.auth.AuthenticationFilter] (AuthenticationFilter.java:91) - Get request to: 'https://uc1ssodload01/oxauth/restv1/authorize' 2019-05-29 09:25:42,501 DEBUG [qtp804611486-16] [xdi.oxauth.authorize.ws.rs.AuthorizeRestWebServiceImpl] (AuthorizeRestWebServiceImpl.java:166) - Attempting to request authorization: responseType = code, clientId = @!69A6.3FD5.755B.EE1A!0001!7539.FC10!0008!C009.F7B8, scope = openid profile email user_name, redirectUri = https://UC1SSODLOAD01/identity/authentication/getauthcode, nonce = a5f9a153-2cab-4c3f-b82f-40b186679a21, state = 161b0ce5-a99c-4f25-90e1-a60eac12303c, request = null, isSecure = true, requestSessionId = null, sessionId = null 2019-05-29 09:25:42,503 DEBUG [qtp804611486-16] [xdi.oxauth.authorize.ws.rs.AuthorizeRestWebServiceImpl] (AuthorizeRestWebServiceImpl.java:172) - Attempting to request authorization: acrValues = auth_ldap_server, amrValues = null, originHeaders = null, codeChallenge = null, codeChallengeMethod = null, customRespHeaders = null, claims = null, tokenBindingHeader = null 2019-05-29 09:25:42,505 TRACE [qtp804611486-16] [org.xdi.oxauth.service.ClientService] (ClientService.java:199) - Get client from cache by Dn 'inum=@!69A6.3FD5.755B.EE1A!0001!7539.FC10!0008!C009.F7B8,ou=clients,o=@!69A6.3FD5.755B.EE1A!0001!7539.FC10,o=gluu' 2019-05-29 09:25:42,505 DEBUG [qtp804611486-16] [org.xdi.oxauth.service.ClientService] (ClientService.java:141) - Found 1 entries for client id = @!69A6.3FD5.755B.EE1A!0001!7539.FC10!0008!C009.F7B8 2019-05-29 09:25:42,506 DEBUG [qtp804611486-16] [org.xdi.oxauth.model.authorize.ScopeChecker] (ScopeChecker.java:39) - Checking scopes policy for: openid profile email user_name 2019-05-29 09:25:42,513 TRACE [qtp804611486-16] [org.xdi.service.cache.RedisStandaloneProvider] (RedisStandaloneProvider.java:109) - put - key: scope_name_openid, status: OK 2019-05-29 09:25:42,514 TRACE [qtp804611486-16] [org.xdi.service.cache.RedisStandaloneProvider] (RedisStandaloneProvider.java:109) - put - key: scope_dn_inum=@!69a6.3fd5.755b.ee1a!0001!7539.fc10!0009!f0c4,ou=scopes,o=@!69a6.3fd5.755b.ee1a!0001!7539.fc10,o=gluu, status: OK 2019-05-29 09:25:42,524 TRACE [qtp804611486-16] [org.xdi.service.cache.RedisStandaloneProvider] (RedisStandaloneProvider.java:109) - put - key: scope_name_user_name, status: OK 2019-05-29 09:25:42,525 TRACE [qtp804611486-16] [org.xdi.service.cache.RedisStandaloneProvider] (RedisStandaloneProvider.java:109) - put - key: scope_dn_inum=@!69a6.3fd5.755b.ee1a!0001!7539.fc10!0009!10b2,ou=scopes,o=@!69a6.3fd5.755b.ee1a!0001!7539.fc10,o=gluu, status: OK 2019-05-29 09:25:42,527 TRACE [qtp804611486-16] [org.xdi.service.cache.RedisStandaloneProvider] (RedisStandaloneProvider.java:109) - put - key: scope_name_email, status: OK 2019-05-29 09:25:42,528 TRACE [qtp804611486-16] [org.xdi.service.cache.RedisStandaloneProvider] (RedisStandaloneProvider.java:109) - put - key: scope_dn_inum=@!69a6.3fd5.755b.ee1a!0001!7539.fc10!0009!764c,ou=scopes,o=@!69a6.3fd5.755b.ee1a!0001!7539.fc10,o=gluu, status: OK 2019-05-29 09:25:42,536 DEBUG [qtp804611486-16] [org.xdi.oxauth.model.authorize.ScopeChecker] (ScopeChecker.java:68) - Granted scopes: [openid, user_name, email] 2019-05-29 09:25:42,537 TRACE [qtp804611486-16] [org.xdi.oxauth.service.ClientService] (ClientService.java:199) - Get client from cache by Dn 'inum=@!69A6.3FD5.755B.EE1A!0001!7539.FC10!0008!C009.F7B8,ou=clients,o=@!69A6.3FD5.755B.EE1A!0001!7539.FC10,o=gluu' 2019-05-29 09:25:42,537 DEBUG [qtp804611486-16] [org.xdi.oxauth.service.ClientService] (ClientService.java:141) - Found 1 entries for client id = @!69A6.3FD5.755B.EE1A!0001!7539.FC10!0008!C009.F7B8 2019-05-29 09:25:42,537 DEBUG [qtp804611486-16] [org.xdi.oxauth.service.RedirectionUriService] (RedirectionUriService.java:76) - Validating redirection URI: clientIdentifier = @!69A6.3FD5.755B.EE1A!0001!7539.FC10!0008!C009.F7B8, redirectionUri = https://UC1SSODLOAD01/identity/authentication/getauthcode, found = 5 2019-05-29 09:25:42,537 DEBUG [qtp804611486-16] [org.xdi.oxauth.service.RedirectionUriService] (RedirectionUriService.java:82) - Comparing https://UC1SSODLOAD01/identity/scim/auth == https://UC1SSODLOAD01/identity/authentication/getauthcode 2019-05-29 09:25:42,538 DEBUG [qtp804611486-16] [org.xdi.oxauth.service.RedirectionUriService] (RedirectionUriService.java:82) - Comparing https://UC1SSODLOAD01/identity/authentication/authcode == https://UC1SSODLOAD01/identity/authentication/getauthcode 2019-05-29 09:25:42,538 DEBUG [qtp804611486-16] [org.xdi.oxauth.service.RedirectionUriService] (RedirectionUriService.java:82) - Comparing https://UC1SSODLOAD01/identity/authentication/getauthcode == https://UC1SSODLOAD01/identity/authentication/getauthcode 2019-05-29 09:25:42,747 TRACE [qtp804611486-15] [org.xdi.oxauth.service.ClientService] (ClientService.java:199) - Get client from cache by Dn 'inum=@!69A6.3FD5.755B.EE1A!0001!7539.FC10!0008!C009.F7B8,ou=clients,o=@!69A6.3FD5.755B.EE1A!0001!7539.FC10,o=gluu' 2019-05-29 09:25:42,747 DEBUG [qtp804611486-15] [org.xdi.oxauth.service.ClientService] (ClientService.java:141) - Found 1 entries for client id = @!69A6.3FD5.755B.EE1A!0001!7539.FC10!0008!C009.F7B8 2019-05-29 09:25:42,747 DEBUG [qtp804611486-15] [org.xdi.oxauth.model.authorize.ScopeChecker] (ScopeChecker.java:39) - Checking scopes policy for: openid profile email user_name 2019-05-29 09:25:42,758 DEBUG [qtp804611486-15] [org.xdi.oxauth.model.authorize.ScopeChecker] (ScopeChecker.java:68) - Granted scopes: [openid, user_name, email] 2019-05-29 09:25:42,764 TRACE [qtp804611486-15] [org.xdi.oxauth.service.SessionIdService] (SessionIdService.java:544) - Generated new session, id = '45514b31-12f3-4d0e-a62c-15237ef27252', state = 'unauthenticated', asJwt = 'false', persisted = 'false' 2019-05-29 09:25:42,765 TRACE [qtp804611486-15] [org.xdi.oxauth.service.SessionIdService] (SessionIdService.java:617) - sessionIdAttributes: org.xdi.oxauth.model.common.SessionIdAccessMap@993e82f 2019-05-29 09:25:42,766 TRACE [qtp804611486-15] [org.xdi.service.cache.RedisStandaloneProvider] (RedisStandaloneProvider.java:109) - put - key: 45514b31-12f3-4d0e-a62c-15237ef27252, status: OK 2019-05-29 09:25:42,766 TRACE [qtp804611486-15] [xdi.oxauth.authorize.ws.rs.AuthorizeAction] (AuthorizeAction.java:289) - Session '45514b31-12f3-4d0e-a62c-15237ef27252' persisted to LDAP 2019-05-29 09:25:42,974 TRACE [qtp804611486-11] [org.xdi.oxauth.service.SessionIdService] (SessionIdService.java:290) - Found session_id cookie: '45514b31-12f3-4d0e-a62c-15237ef27252' 2019-05-29 09:25:42,976 TRACE [qtp804611486-11] [org.xdi.oxauth.service.SessionIdService] (SessionIdService.java:761) - Try to get session by id: 45514b31-12f3-4d0e-a62c-15237ef27252 ... 2019-05-29 09:25:42,976 TRACE [qtp804611486-11] [org.xdi.oxauth.service.SessionIdService] (SessionIdService.java:763) - Session dn: oxAuthSessionId=45514b31-12f3-4d0e-a62c-15237ef27252,ou=session,o=@!69A6.3FD5.755B.EE1A!0001!7539.FC10,o=gluu 2019-05-29 09:25:42,986 TRACE [qtp804611486-11] [org.xdi.service.cache.RedisStandaloneProvider] (RedisStandaloneProvider.java:109) - put - key: 45514b31-12f3-4d0e-a62c-15237ef27252, status: OK 2019-05-29 09:25:43,249 TRACE [qtp804611486-11] [org.xdi.oxauth.service.ClientService] (ClientService.java:199) - Get client from cache by Dn 'inum=@!69A6.3FD5.755B.EE1A!0001!7539.FC10!0008!C009.F7B8,ou=clients,o=@!69A6.3FD5.755B.EE1A!0001!7539.FC10,o=gluu' 2019-05-29 09:25:43,252 DEBUG [qtp804611486-11] [org.xdi.oxauth.service.ClientService] (ClientService.java:141) - Found 1 entries for client id = @!69A6.3FD5.755B.EE1A!0001!7539.FC10!0008!C009.F7B8 2019-05-29 09:25:43,257 TRACE [qtp804611486-11] [org.xdi.oxauth.service.ClientService] (ClientService.java:199) - Get client from cache by Dn 'inum=@!69A6.3FD5.755B.EE1A!0001!7539.FC10!0008!C009.F7B8,ou=clients,o=@!69A6.3FD5.755B.EE1A!0001!7539.FC10,o=gluu' 2019-05-29 09:25:43,257 DEBUG [qtp804611486-11] [org.xdi.oxauth.service.ClientService] (ClientService.java:141) - Found 1 entries for client id = @!69A6.3FD5.755B.EE1A!0001!7539.FC10!0008!C009.F7B8 2019-05-29 09:25:43,260 TRACE [qtp804611486-11] [org.xdi.oxauth.service.ClientService] (ClientService.java:199) - Get client from cache by Dn 'inum=@!69A6.3FD5.755B.EE1A!0001!7539.FC10!0008!C009.F7B8,ou=clients,o=@!69A6.3FD5.755B.EE1A!0001!7539.FC10,o=gluu' 2019-05-29 09:25:43,261 DEBUG [qtp804611486-11] [org.xdi.oxauth.service.ClientService] (ClientService.java:141) - Found 1 entries for client id = @!69A6.3FD5.755B.EE1A!0001!7539.FC10!0008!C009.F7B8 2019-05-29 09:25:43,264 TRACE [qtp804611486-11] [org.xdi.oxauth.service.ClientService] (ClientService.java:199) - Get client from cache by Dn 'inum=@!69A6.3FD5.755B.EE1A!0001!7539.FC10!0008!C009.F7B8,ou=clients,o=@!69A6.3FD5.755B.EE1A!0001!7539.FC10,o=gluu' 2019-05-29 09:25:43,265 DEBUG [qtp804611486-11] [org.xdi.oxauth.service.ClientService] (ClientService.java:141) - Found 1 entries for client id = @!69A6.3FD5.755B.EE1A!0001!7539.FC10!0008!C009.F7B8 2019-05-29 09:25:43,268 TRACE [qtp804611486-11] [org.xdi.oxauth.service.ClientService] (ClientService.java:199) - Get client from cache by Dn 'inum=@!69A6.3FD5.755B.EE1A!0001!7539.FC10!0008!C009.F7B8,ou=clients,o=@!69A6.3FD5.755B.EE1A!0001!7539.FC10,o=gluu' 2019-05-29 09:25:43,268 DEBUG [qtp804611486-11] [org.xdi.oxauth.service.ClientService] (ClientService.java:141) - Found 1 entries for client id = @!69A6.3FD5.755B.EE1A!0001!7539.FC10!0008!C009.F7B8 2019-05-29 09:25:43,269 TRACE [qtp804611486-11] [org.xdi.oxauth.service.ClientService] (ClientService.java:199) - Get client from cache by Dn 'inum=@!69A6.3FD5.755B.EE1A!0001!7539.FC10!0008!C009.F7B8,ou=clients,o=@!69A6.3FD5.755B.EE1A!0001!7539.FC10,o=gluu' 2019-05-29 09:25:43,269 DEBUG [qtp804611486-11] [org.xdi.oxauth.service.ClientService] (ClientService.java:141) - Found 1 entries for client id = @!69A6.3FD5.755B.EE1A!0001!7539.FC10!0008!C009.F7B8 2019-05-29 09:25:43,270 TRACE [qtp804611486-11] [org.xdi.oxauth.service.ClientService] (ClientService.java:199) - Get client from cache by Dn 'inum=@!69A6.3FD5.755B.EE1A!0001!7539.FC10!0008!C009.F7B8,ou=clients,o=@!69A6.3FD5.755B.EE1A!0001!7539.FC10,o=gluu' 2019-05-29 09:25:43,270 DEBUG [qtp804611486-11] [org.xdi.oxauth.service.ClientService] (ClientService.java:141) - Found 1 entries for client id = @!69A6.3FD5.755B.EE1A!0001!7539.FC10!0008!C009.F7B8 2019-05-29 09:25:43,270 TRACE [qtp804611486-11] [org.xdi.oxauth.service.ClientService] (ClientService.java:199) - Get client from cache by Dn 'inum=@!69A6.3FD5.755B.EE1A!0001!7539.FC10!0008!C009.F7B8,ou=clients,o=@!69A6.3FD5.755B.EE1A!0001!7539.FC10,o=gluu' 2019-05-29 09:25:43,271 DEBUG [qtp804611486-11] [org.xdi.oxauth.service.ClientService] (ClientService.java:141) - Found 1 entries for client id = @!69A6.3FD5.755B.EE1A!0001!7539.FC10!0008!C009.F7B8 2019-05-29 09:25:43,328 TRACE [qtp804611486-11] [org.xdi.oxauth.service.ClientService] (ClientService.java:199) - Get client from cache by Dn 'inum=@!69A6.3FD5.755B.EE1A!0001!7539.FC10!0008!C009.F7B8,ou=clients,o=@!69A6.3FD5.755B.EE1A!0001!7539.FC10,o=gluu' 2019-05-29 09:25:43,329 DEBUG [qtp804611486-11] [org.xdi.oxauth.service.ClientService] (ClientService.java:141) - Found 1 entries for client id = @!69A6.3FD5.755B.EE1A!0001!7539.FC10!0008!C009.F7B8 2019-05-29 09:25:43,330 TRACE [qtp804611486-11] [org.xdi.oxauth.service.ClientService] (ClientService.java:199) - Get client from cache by Dn 'inum=@!69A6.3FD5.755B.EE1A!0001!7539.FC10!0008!C009.F7B8,ou=clients,o=@!69A6.3FD5.755B.EE1A!0001!7539.FC10,o=gluu' 2019-05-29 09:25:43,330 DEBUG [qtp804611486-11] [org.xdi.oxauth.service.ClientService] (ClientService.java:141) - Found 1 entries for client id = @!69A6.3FD5.755B.EE1A!0001!7539.FC10!0008!C009.F7B8 2019-05-29 09:25:47,364 TRACE [qtp804611486-11] [org.xdi.oxauth.service.ClientService] (ClientService.java:199) - Get client from cache by Dn 'inum=@!69A6.3FD5.755B.EE1A!0001!7539.FC10!0008!C009.F7B8,ou=clients,o=@!69A6.3FD5.755B.EE1A!0001!7539.FC10,o=gluu' 2019-05-29 09:25:47,364 DEBUG [qtp804611486-11] [org.xdi.oxauth.service.ClientService] (ClientService.java:141) - Found 1 entries for client id = @!69A6.3FD5.755B.EE1A!0001!7539.FC10!0008!C009.F7B8 2019-05-29 09:25:47,365 TRACE [qtp804611486-11] [org.xdi.oxauth.auth.AuthenticationFilter] (AuthenticationFilter.java:91) - Get request to: 'https://uc1ssodload01/oxauth/restv1/authorize' 2019-05-29 09:25:47,365 TRACE [qtp804611486-11] [org.xdi.oxauth.service.SessionIdService] (SessionIdService.java:290) - Found session_id cookie: '45514b31-12f3-4d0e-a62c-15237ef27252' 2019-05-29 09:25:47,366 TRACE [qtp804611486-11] [org.xdi.oxauth.service.SessionIdService] (SessionIdService.java:761) - Try to get session by id: 45514b31-12f3-4d0e-a62c-15237ef27252 ... 2019-05-29 09:25:47,366 TRACE [qtp804611486-11] [org.xdi.oxauth.service.SessionIdService] (SessionIdService.java:763) - Session dn: oxAuthSessionId=45514b31-12f3-4d0e-a62c-15237ef27252,ou=session,o=@!69A6.3FD5.755B.EE1A!0001!7539.FC10,o=gluu 2019-05-29 09:25:47,368 DEBUG [qtp804611486-11] [xdi.oxauth.authorize.ws.rs.AuthorizeRestWebServiceImpl] (AuthorizeRestWebServiceImpl.java:166) - Attempting to request authorization: responseType = code, clientId = @!69A6.3FD5.755B.EE1A!0001!7539.FC10!0008!C009.F7B8, scope = openid profile email user_name, redirectUri = https://UC1SSODLOAD01/identity/authentication/getauthcode, nonce = 6325fbb7-2a2b-48ed-9135-b551c89ab1e5, state = 7750f983-867f-4e48-8aff-4aed45c0aeff, request = null, isSecure = true, requestSessionId = null, sessionId = null 2019-05-29 09:25:47,368 DEBUG [qtp804611486-11] [xdi.oxauth.authorize.ws.rs.AuthorizeRestWebServiceImpl] (AuthorizeRestWebServiceImpl.java:172) - Attempting to request authorization: acrValues = auth_ldap_server, amrValues = null, originHeaders = null, codeChallenge = null, codeChallengeMethod = null, customRespHeaders = null, claims = null, tokenBindingHeader = null 2019-05-29 09:25:47,369 TRACE [qtp804611486-11] [org.xdi.oxauth.service.ClientService] (ClientService.java:199) - Get client from cache by Dn 'inum=@!69A6.3FD5.755B.EE1A!0001!7539.FC10!0008!C009.F7B8,ou=clients,o=@!69A6.3FD5.755B.EE1A!0001!7539.FC10,o=gluu' 2019-05-29 09:25:47,369 DEBUG [qtp804611486-11] [org.xdi.oxauth.service.ClientService] (ClientService.java:141) - Found 1 entries for client id = @!69A6.3FD5.755B.EE1A!0001!7539.FC10!0008!C009.F7B8 2019-05-29 09:25:47,369 DEBUG [qtp804611486-11] [org.xdi.oxauth.model.authorize.ScopeChecker] (ScopeChecker.java:39) - Checking scopes policy for: openid profile email user_name 2019-05-29 09:25:47,374 DEBUG [qtp804611486-11] [org.xdi.oxauth.model.authorize.ScopeChecker] (ScopeChecker.java:68) - Granted scopes: [openid, user_name, email] 2019-05-29 09:25:47,375 TRACE [qtp804611486-11] [org.xdi.oxauth.service.ClientService] (ClientService.java:199) - Get client from cache by Dn 'inum=@!69A6.3FD5.755B.EE1A!0001!7539.FC10!0008!C009.F7B8,ou=clients,o=@!69A6.3FD5.755B.EE1A!0001!7539.FC10,o=gluu' 2019-05-29 09:25:47,375 DEBUG [qtp804611486-11] [org.xdi.oxauth.service.ClientService] (ClientService.java:141) - Found 1 entries for client id = @!69A6.3FD5.755B.EE1A!0001!7539.FC10!0008!C009.F7B8 2019-05-29 09:25:47,375 DEBUG [qtp804611486-11] [org.xdi.oxauth.service.RedirectionUriService] (RedirectionUriService.java:76) - Validating redirection URI: clientIdentifier = @!69A6.3FD5.755B.EE1A!0001!7539.FC10!0008!C009.F7B8, redirectionUri = https://UC1SSODLOAD01/identity/authentication/getauthcode, found = 5 2019-05-29 09:25:47,376 DEBUG [qtp804611486-11] [org.xdi.oxauth.service.RedirectionUriService] (RedirectionUriService.java:82) - Comparing https://UC1SSODLOAD01/identity/scim/auth == https://UC1SSODLOAD01/identity/authentication/getauthcode 2019-05-29 09:25:47,376 DEBUG [qtp804611486-11] [org.xdi.oxauth.service.RedirectionUriService] (RedirectionUriService.java:82) - Comparing https://UC1SSODLOAD01/identity/authentication/authcode == https://UC1SSODLOAD01/identity/authentication/getauthcode 2019-05-29 09:25:47,376 DEBUG [qtp804611486-11] [org.xdi.oxauth.service.RedirectionUriService] (RedirectionUriService.java:82) - Comparing https://UC1SSODLOAD01/identity/authentication/getauthcode == https://UC1SSODLOAD01/identity/authentication/getauthcode 2019-05-29 09:25:47,577 TRACE [qtp804611486-15] [org.xdi.oxauth.service.ClientService] (ClientService.java:199) - Get client from cache by Dn 'inum=@!69A6.3FD5.755B.EE1A!0001!7539.FC10!0008!C009.F7B8,ou=clients,o=@!69A6.3FD5.755B.EE1A!0001!7539.FC10,o=gluu' 2019-05-29 09:25:47,577 DEBUG [qtp804611486-15] [org.xdi.oxauth.service.ClientService] (ClientService.java:141) - Found 1 entries for client id = @!69A6.3FD5.755B.EE1A!0001!7539.FC10!0008!C009.F7B8 2019-05-29 09:25:47,577 DEBUG [qtp804611486-15] [org.xdi.oxauth.model.authorize.ScopeChecker] (ScopeChecker.java:39) - Checking scopes policy for: openid profile email user_name 2019-05-29 09:25:47,580 DEBUG [qtp804611486-15] [org.xdi.oxauth.model.authorize.ScopeChecker] (ScopeChecker.java:68) - Granted scopes: [openid, user_name, email] 2019-05-29 09:25:47,581 TRACE [qtp804611486-15] [org.xdi.oxauth.service.SessionIdService] (SessionIdService.java:290) - Found session_id cookie: '45514b31-12f3-4d0e-a62c-15237ef27252' 2019-05-29 09:25:47,583 TRACE [qtp804611486-15] [org.xdi.oxauth.service.SessionIdService] (SessionIdService.java:761) - Try to get session by id: 45514b31-12f3-4d0e-a62c-15237ef27252 ... 2019-05-29 09:25:47,583 TRACE [qtp804611486-15] [org.xdi.oxauth.service.SessionIdService] (SessionIdService.java:763) - Session dn: oxAuthSessionId=45514b31-12f3-4d0e-a62c-15237ef27252,ou=session,o=@!69A6.3FD5.755B.EE1A!0001!7539.FC10,o=gluu 2019-05-29 09:25:47,583 TRACE [qtp804611486-15] [org.xdi.oxauth.auth.Authenticator] (Authenticator.java:736) - authenticateBySessionId, sessionId = '45514b31-12f3-4d0e-a62c-15237ef27252', session = 'SessionState {dn='oxAuthSessionId=45514b31-12f3-4d0e-a62c-15237ef27252,ou=session,o=@!69A6.3FD5.755B.EE1A!0001!7539.FC10,o=gluu', id='45514b31-12f3-4d0e-a62c-15237ef27252', lastUsedAt=Wed May 29 09:25:42 UTC 2019, userDn='', authenticationTime=Wed May 29 09:25:42 UTC 2019, state=unauthenticated, sessionState='3f4710c44c1cbaf6d8db03d1c4afd56ba42bed5ed3dea9d02d0ffb413ec99d54.a7d85895-63d8-4e8a-b9fa-748692b066b3', permissionGranted=null, isJwt=false, jwt=null, permissionGrantedMap=org.xdi.oxauth.model.common.SessionIdAccessMap@2b769b52, involvedClients=null, sessionAttributes={auth_external_attributes=null, opbs=f4886836-179a-4dd4-8dfc-c679a97c3885, response_type=code, nonce=a5f9a153-2cab-4c3f-b82f-40b186679a21, client_id=@!69A6.3FD5.755B.EE1A!0001!7539.FC10!0008!C009.F7B8, auth_step=1, acr=auth_ldap_server, remote_ip=10.80.157.230, 10.121.18.38, scope=openid profile email user_name, acr_values=auth_ldap_server, redirect_uri=https://UC1SSODLOAD01/identity/authentication/getauthcode, state=161b0ce5-a99c-4f25-90e1-a60eac12303c}, persisted=false}', state= 'unauthenticated' 2019-05-29 09:25:47,584 TRACE [qtp804611486-15] [org.xdi.oxauth.service.SessionIdService] (SessionIdService.java:761) - Try to get session by id: 45514b31-12f3-4d0e-a62c-15237ef27252 ... 2019-05-29 09:25:47,584 TRACE [qtp804611486-15] [org.xdi.oxauth.service.SessionIdService] (SessionIdService.java:763) - Session dn: oxAuthSessionId=45514b31-12f3-4d0e-a62c-15237ef27252,ou=session,o=@!69A6.3FD5.755B.EE1A!0001!7539.FC10,o=gluu 2019-05-29 09:25:47,585 TRACE [qtp804611486-15] [org.xdi.oxauth.service.SessionIdService] (SessionIdService.java:544) - Generated new session, id = 'c4d163d8-2460-4a03-afeb-d38e1622db4e', state = 'unauthenticated', asJwt = 'false', persisted = 'false' 2019-05-29 09:25:47,599 TRACE [qtp804611486-15] [org.xdi.service.cache.RedisStandaloneProvider] (RedisStandaloneProvider.java:133) - remove - key: 45514b31-12f3-4d0e-a62c-15237ef27252, entriesRemoved: 1 2019-05-29 09:25:47,599 TRACE [qtp804611486-15] [org.xdi.oxauth.service.SessionIdService] (SessionIdService.java:617) - sessionIdAttributes: org.xdi.oxauth.model.common.SessionIdAccessMap@7a58426a 2019-05-29 09:25:47,601 TRACE [qtp804611486-15] [org.xdi.service.cache.RedisStandaloneProvider] (RedisStandaloneProvider.java:109) - put - key: c4d163d8-2460-4a03-afeb-d38e1622db4e, status: OK 2019-05-29 09:25:47,601 TRACE [qtp804611486-15] [xdi.oxauth.authorize.ws.rs.AuthorizeAction] (AuthorizeAction.java:289) - Session 'c4d163d8-2460-4a03-afeb-d38e1622db4e' persisted to LDAP 2019-05-29 09:25:47,788 TRACE [qtp804611486-18] [org.xdi.oxauth.service.SessionIdService] (SessionIdService.java:290) - Found session_id cookie: 'c4d163d8-2460-4a03-afeb-d38e1622db4e' 2019-05-29 09:25:47,789 TRACE [qtp804611486-18] [org.xdi.oxauth.service.SessionIdService] (SessionIdService.java:761) - Try to get session by id: c4d163d8-2460-4a03-afeb-d38e1622db4e ... 2019-05-29 09:25:47,789 TRACE [qtp804611486-18] [org.xdi.oxauth.service.SessionIdService] (SessionIdService.java:763) - Session dn: oxAuthSessionId=c4d163d8-2460-4a03-afeb-d38e1622db4e,ou=session,o=@!69A6.3FD5.755B.EE1A!0001!7539.FC10,o=gluu 2019-05-29 09:25:47,791 TRACE [qtp804611486-18] [org.xdi.service.cache.RedisStandaloneProvider] (RedisStandaloneProvider.java:109) - put - key: c4d163d8-2460-4a03-afeb-d38e1622db4e, status: OK 2019-05-29 09:25:47,818 TRACE [qtp804611486-18] [org.xdi.oxauth.service.ClientService] (ClientService.java:199) - Get client from cache by Dn 'inum=@!69A6.3FD5.755B.EE1A!0001!7539.FC10!0008!C009.F7B8,ou=clients,o=@!69A6.3FD5.755B.EE1A!0001!7539.FC10,o=gluu' 2019-05-29 09:25:47,818 DEBUG [qtp804611486-18] [org.xdi.oxauth.service.ClientService] (ClientService.java:141) - Found 1 entries for client id = @!69A6.3FD5.755B.EE1A!0001!7539.FC10!0008!C009.F7B8 2019-05-29 09:25:47,819 TRACE [qtp804611486-18] [org.xdi.oxauth.service.ClientService] (ClientService.java:199) - Get client from cache by Dn 'inum=@!69A6.3FD5.755B.EE1A!0001!7539.FC10!0008!C009.F7B8,ou=clients,o=@!69A6.3FD5.755B.EE1A!0001!7539.FC10,o=gluu' 2019-05-29 09:25:47,819 DEBUG [qtp804611486-18] [org.xdi.oxauth.service.ClientService] (ClientService.java:141) - Found 1 entries for client id = @!69A6.3FD5.755B.EE1A!0001!7539.FC10!0008!C009.F7B8 2019-05-29 09:25:47,820 TRACE [qtp804611486-18] [org.xdi.oxauth.service.ClientService] (ClientService.java:199) - Get client from cache by Dn 'inum=@!69A6.3FD5.755B.EE1A!0001!7539.FC10!0008!C009.F7B8,ou=clients,o=@!69A6.3FD5.755B.EE1A!0001!7539.FC10,o=gluu' 2019-05-29 09:25:47,821 DEBUG [qtp804611486-18] [org.xdi.oxauth.service.ClientService] (ClientService.java:141) - Found 1 entries for client id = @!69A6.3FD5.755B.EE1A!0001!7539.FC10!0008!C009.F7B8 2019-05-29 09:25:47,821 TRACE [qtp804611486-18] [org.xdi.oxauth.service.ClientService] (ClientService.java:199) - Get client from cache by Dn 'inum=@!69A6.3FD5.755B.EE1A!0001!7539.FC10!0008!C009.F7B8,ou=clients,o=@!69A6.3FD5.755B.EE1A!0001!7539.FC10,o=gluu' 2019-05-29 09:25:47,822 DEBUG [qtp804611486-18] [org.xdi.oxauth.service.ClientService] (ClientService.java:141) - Found 1 entries for client id = @!69A6.3FD5.755B.EE1A!0001!7539.FC10!0008!C009.F7B8 2019-05-29 09:25:47,822 TRACE [qtp804611486-18] [org.xdi.oxauth.service.ClientService] (ClientService.java:199) - Get client from cache by Dn 'inum=@!69A6.3FD5.755B.EE1A!0001!7539.FC10!0008!C009.F7B8,ou=clients,o=@!69A6.3FD5.755B.EE1A!0001!7539.FC10,o=gluu' 2019-05-29 09:25:47,822 DEBUG [qtp804611486-18] [org.xdi.oxauth.service.ClientService] (ClientService.java:141) - Found 1 entries for client id = @!69A6.3FD5.755B.EE1A!0001!7539.FC10!0008!C009.F7B8 2019-05-29 09:25:47,823 TRACE [qtp804611486-18] [org.xdi.oxauth.service.ClientService] (ClientService.java:199) - Get client from cache by Dn 'inum=@!69A6.3FD5.755B.EE1A!0001!7539.FC10!0008!C009.F7B8,ou=clients,o=@!69A6.3FD5.755B.EE1A!0001!7539.FC10,o=gluu' 2019-05-29 09:25:47,823 DEBUG [qtp804611486-18] [org.xdi.oxauth.service.ClientService] (ClientService.java:141) - Found 1 entries for client id = @!69A6.3FD5.755B.EE1A!0001!7539.FC10!0008!C009.F7B8 2019-05-29 09:25:47,824 TRACE [qtp804611486-18] [org.xdi.oxauth.service.ClientService] (ClientService.java:199) - Get client from cache by Dn 'inum=@!69A6.3FD5.755B.EE1A!0001!7539.FC10!0008!C009.F7B8,ou=clients,o=@!69A6.3FD5.755B.EE1A!0001!7539.FC10,o=gluu' 2019-05-29 09:25:47,825 DEBUG [qtp804611486-18] [org.xdi.oxauth.service.ClientService] (ClientService.java:141) - Found 1 entries for client id = @!69A6.3FD5.755B.EE1A!0001!7539.FC10!0008!C009.F7B8 2019-05-29 09:25:47,825 TRACE [qtp804611486-18] [org.xdi.oxauth.service.ClientService] (ClientService.java:199) - Get client from cache by Dn 'inum=@!69A6.3FD5.755B.EE1A!0001!7539.FC10!0008!C009.F7B8,ou=clients,o=@!69A6.3FD5.755B.EE1A!0001!7539.FC10,o=gluu' 2019-05-29 09:25:47,826 DEBUG [qtp804611486-18] [org.xdi.oxauth.service.ClientService] (ClientService.java:141) - Found 1 entries for client id = @!69A6.3FD5.755B.EE1A!0001!7539.FC10!0008!C009.F7B8 2019-05-29 09:25:47,828 TRACE [qtp804611486-18] [org.xdi.oxauth.service.ClientService] (ClientService.java:199) - Get client from cache by Dn 'inum=@!69A6.3FD5.755B.EE1A!0001!7539.FC10!0008!C009.F7B8,ou=clients,o=@!69A6.3FD5.755B.EE1A!0001!7539.FC10,o=gluu' 2019-05-29 09:25:47,829 DEBUG [qtp804611486-18] [org.xdi.oxauth.service.ClientService] (ClientService.java:141) - Found 1 entries for client id = @!69A6.3FD5.755B.EE1A!0001!7539.FC10!0008!C009.F7B8 2019-05-29 09:25:47,829 TRACE [qtp804611486-18] [org.xdi.oxauth.service.ClientService] (ClientService.java:199) - Get client from cache by Dn 'inum=@!69A6.3FD5.755B.EE1A!0001!7539.FC10!0008!C009.F7B8,ou=clients,o=@!69A6.3FD5.755B.EE1A!0001!7539.FC10,o=gluu' 2019-05-29 09:25:47,830 DEBUG [qtp804611486-18] [org.xdi.oxauth.service.ClientService] (ClientService.java:141) - Found 1 entries for client id = @!69A6.3FD5.755B.EE1A!0001!7539.FC10!0008!C009.F7B8 2019-05-29 09:25:53,501 DEBUG [oxAuthScheduler_Worker-2] [org.xdi.service.timer.RequestJobListener] (RequestJobListener.java:52) - Bound request started 2019-05-29 09:25:53,501 DEBUG [oxAuthScheduler_Worker-2] [org.xdi.service.timer.TimerJob] (TimerJob.java:34) - Fire timer event [org.xdi.service.cdi.event.ConfigurationEvent] with qualifiers [@org.xdi.service.cdi.event.Scheduled()] 2019-05-29 09:25:53,502 DEBUG [oxAuthScheduler_Worker-2] [org.xdi.service.timer.RequestJobListener] (RequestJobListener.java:62) - Bound request ended 2019-05-29 09:25:53,504 INFO [Thread-84845] [org.xdi.oxauth.model.config.ConfigurationFactory] (ConfigurationFactory.java:337) - Loading configuration from LDAP... 2019-05-29 09:25:53,516 DEBUG [oxAuthScheduler_Worker-3] [org.xdi.service.timer.RequestJobListener] (RequestJobListener.java:52) - Bound request started 2019-05-29 09:25:53,516 DEBUG [oxAuthScheduler_Worker-3] [org.xdi.service.timer.TimerJob] (TimerJob.java:34) - Fire timer event [org.xdi.service.cdi.event.LoggerUpdateEvent] with qualifiers [@org.xdi.service.cdi.event.Scheduled()] 2019-05-29 09:25:53,516 DEBUG [oxAuthScheduler_Worker-3] [org.xdi.service.timer.RequestJobListener] (RequestJobListener.java:62) - Bound request ended 2019-05-29 09:25:53,517 INFO [Thread-84846] [org.xdi.service.logger.LoggerService] (LoggerService.java:145) - Uppdated log level of '1' loggers to TRACE 2019-05-29 09:25:53,555 DEBUG [oxAuthScheduler_Worker-4] [org.xdi.service.timer.RequestJobListener] (RequestJobListener.java:52) - Bound request started 2019-05-29 09:25:53,555 DEBUG [oxAuthScheduler_Worker-4] [org.xdi.service.timer.TimerJob] (TimerJob.java:34) - Fire timer event [org.xdi.service.cdi.event.LdapStatusEvent] with qualifiers [@org.xdi.service.cdi.event.Scheduled()] 2019-05-29 09:25:53,555 DEBUG [oxAuthScheduler_Worker-4] [org.xdi.service.timer.RequestJobListener] (RequestJobListener.java:62) - Bound request ended 2019-05-29 09:25:53,702 INFO [Thread-84845] [org.xdi.service.logger.LoggerService] (LoggerService.java:175) - External log configuration: 2019-05-29 09:25:53,703 INFO [Thread-84845] [org.xdi.service.logger.LoggerService] (LoggerService.java:118) - Setting loggers level to: 'TRACE' 2019-05-29 09:25:53,729 DEBUG [oxAuthScheduler_Worker-1] [org.xdi.service.timer.RequestJobListener] (RequestJobListener.java:52) - Bound request started 2019-05-29 09:25:53,729 DEBUG [oxAuthScheduler_Worker-1] [org.xdi.service.timer.TimerJob] (TimerJob.java:34) - Fire timer event [org.xdi.oxauth.service.cdi.event.AuthConfigurationEvent] with qualifiers [@org.xdi.service.cdi.event.Scheduled()] 2019-05-29 09:25:53,738 DEBUG [oxAuthScheduler_Worker-1] [org.xdi.service.timer.RequestJobListener] (RequestJobListener.java:62) - Bound request ended 2019-05-29 09:25:53,738 TRACE [Thread-84848] [org.xdi.oxauth.service.AppInitializer] (AppInitializer.java:282) - Attempting to use ldapEntryManager: org.gluu.site.ldap.OperationsFacade@545e0df5 2019-05-29 09:25:57,895 DEBUG [oxAuthScheduler_Worker-5] [org.xdi.service.timer.RequestJobListener] (RequestJobListener.java:52) - Bound request started 2019-05-29 09:25:57,896 DEBUG [oxAuthScheduler_Worker-5] [org.xdi.service.timer.TimerJob] (TimerJob.java:34) - Fire timer event [org.xdi.service.cdi.event.UpdateScriptEvent] with qualifiers [@org.xdi.service.cdi.event.Scheduled()] 2019-05-29 09:25:57,919 DEBUG [oxAuthScheduler_Worker-5] [org.xdi.service.timer.RequestJobListener] (RequestJobListener.java:62) - Bound request ended 2019-05-29 09:25:59,494 TRACE [qtp804611486-15] [org.xdi.oxauth.auth.Authenticator] (Authenticator.java:181) - Authenticating ... (interactive: true, skipPassword: false, credentials.username: admin) 2019-05-29 09:25:59,495 TRACE [qtp804611486-15] [org.xdi.oxauth.service.SessionIdService] (SessionIdService.java:290) - Found session_id cookie: 'c4d163d8-2460-4a03-afeb-d38e1622db4e' 2019-05-29 09:25:59,496 TRACE [qtp804611486-15] [org.xdi.oxauth.service.SessionIdService] (SessionIdService.java:761) - Try to get session by id: c4d163d8-2460-4a03-afeb-d38e1622db4e ... 2019-05-29 09:25:59,496 TRACE [qtp804611486-15] [org.xdi.oxauth.service.SessionIdService] (SessionIdService.java:763) - Session dn: oxAuthSessionId=c4d163d8-2460-4a03-afeb-d38e1622db4e,ou=session,o=@!69A6.3FD5.755B.EE1A!0001!7539.FC10,o=gluu 2019-05-29 09:25:59,499 DEBUG [qtp804611486-15] [org.xdi.oxauth.service.AuthenticationService] (AuthenticationService.java:121) - Authenticating user with LDAP: username: 'admin', credentials: '1410883874' 2019-05-29 09:25:59,513 DEBUG [qtp804611486-15] [org.xdi.oxauth.service.AuthenticationService] (AuthenticationService.java:267) - Attempting to find userDN by primary key: 'uid' and key value: 'admin', credentials: '1410883874' 2019-05-29 09:25:59,514 DEBUG [qtp804611486-15] [org.xdi.oxauth.service.AuthenticationService] (AuthenticationService.java:362) - Getting user information from LDAP: attributeName = 'uid', attributeValue = 'admin' 2019-05-29 09:25:59,514 DEBUG [qtp804611486-15] [org.xdi.oxauth.service.AuthenticationService] (AuthenticationService.java:376) - Searching user by attributes: '[Attribute [name=uid, values=[admin]]]', baseDn: 'o=gluu' 2019-05-29 09:25:59,556 DEBUG [qtp804611486-15] [org.xdi.oxauth.service.AuthenticationService] (AuthenticationService.java:378) - Found '1' entries 2019-05-29 09:25:59,562 DEBUG [qtp804611486-15] [org.xdi.oxauth.service.AuthenticationService] (AuthenticationService.java:289) - Attempting to authenticate userDN: inum=@!69A6.3FD5.755B.EE1A!0001!7539.FC10!0000!A8F2.DE1E.D7FB,ou=people,o=@!69A6.3FD5.755B.EE1A!0001!7539.FC10,o=gluu 2019-05-29 09:25:59,579 DEBUG [qtp804611486-15] [org.xdi.oxauth.service.AuthenticationService] (AuthenticationService.java:291) - User authenticated: inum=@!69A6.3FD5.755B.EE1A!0001!7539.FC10!0000!A8F2.DE1E.D7FB,ou=people,o=@!69A6.3FD5.755B.EE1A!0001!7539.FC10,o=gluu 2019-05-29 09:25:59,580 DEBUG [qtp804611486-15] [org.xdi.oxauth.service.AuthenticationService] (AuthenticationService.java:293) - Attempting to find userDN by local primary key: uid 2019-05-29 09:25:59,580 DEBUG [qtp804611486-15] [org.xdi.oxauth.service.UserService] (UserService.java:193) - Getting user information from LDAP: attributeName = 'uid', attributeValue = 'admin' 2019-05-29 09:25:59,586 DEBUG [qtp804611486-15] [org.xdi.oxauth.service.UserService] (UserService.java:204) - Found '1' entries 2019-05-29 09:25:59,619 TRACE [qtp804611486-15] [org.xdi.oxauth.service.AuthenticationService] (AuthenticationService.java:303) - authenticate_external: credentials: '1410883874', credentials.userName: 'admin', authenticatedUser.userId: 'admin' 2019-05-29 09:25:59,627 TRACE [qtp804611486-15] [org.xdi.oxauth.service.SessionIdService] (SessionIdService.java:290) - Found session_id cookie: 'c4d163d8-2460-4a03-afeb-d38e1622db4e' 2019-05-29 09:25:59,628 TRACE [qtp804611486-15] [org.xdi.oxauth.service.SessionIdService] (SessionIdService.java:761) - Try to get session by id: c4d163d8-2460-4a03-afeb-d38e1622db4e ... 2019-05-29 09:25:59,628 TRACE [qtp804611486-15] [org.xdi.oxauth.service.SessionIdService] (SessionIdService.java:763) - Session dn: oxAuthSessionId=c4d163d8-2460-4a03-afeb-d38e1622db4e,ou=session,o=@!69A6.3FD5.755B.EE1A!0001!7539.FC10,o=gluu 2019-05-29 09:25:59,629 TRACE [qtp804611486-15] [org.xdi.service.cache.RedisStandaloneProvider] (RedisStandaloneProvider.java:109) - put - key: c4d163d8-2460-4a03-afeb-d38e1622db4e, status: OK 2019-05-29 09:25:59,632 TRACE [qtp804611486-15] [org.xdi.oxauth.service.SessionIdService] (SessionIdService.java:290) - Found session_id cookie: 'c4d163d8-2460-4a03-afeb-d38e1622db4e' 2019-05-29 09:25:59,632 TRACE [qtp804611486-15] [org.xdi.oxauth.service.SessionIdService] (SessionIdService.java:761) - Try to get session by id: c4d163d8-2460-4a03-afeb-d38e1622db4e ... 2019-05-29 09:25:59,632 TRACE [qtp804611486-15] [org.xdi.oxauth.service.SessionIdService] (SessionIdService.java:763) - Session dn: oxAuthSessionId=c4d163d8-2460-4a03-afeb-d38e1622db4e,ou=session,o=@!69A6.3FD5.755B.EE1A!0001!7539.FC10,o=gluu 2019-05-29 09:25:59,632 TRACE [qtp804611486-15] [org.xdi.oxauth.service.AuthenticationService] (AuthenticationService.java:426) - configureSessionUser: credentials: '1410883874', sessionId: 'SessionState {dn='oxAuthSessionId=c4d163d8-2460-4a03-afeb-d38e1622db4e,ou=session,o=@!69A6.3FD5.755B.EE1A!0001!7539.FC10,o=gluu', id='c4d163d8-2460-4a03-afeb-d38e1622db4e', lastUsedAt=Wed May 29 09:25:59 UTC 2019, userDn='', authenticationTime=Wed May 29 09:25:47 UTC 2019, state=unauthenticated, sessionState='48809ba0538f908d4d4491831d9dd54c4a85c241371e50801946286f4a455f44.6c0db896-2535-4bd1-949b-b652c12d9696', permissionGranted=null, isJwt=false, jwt=null, permissionGrantedMap=org.xdi.oxauth.model.common.SessionIdAccessMap@6a2f4df1, involvedClients=null, sessionAttributes={auth_external_attributes=null, opbs=0bfad5f4-da2a-4941-b11d-7d8d4f3be72d, response_type=code, nonce=6325fbb7-2a2b-48ed-9135-b551c89ab1e5, client_id=@!69A6.3FD5.755B.EE1A!0001!7539.FC10!0008!C009.F7B8, auth_step=1, acr=auth_ldap_server, remote_ip=10.80.157.230, 10.121.18.38, auth_user=admin, scope=openid profile email user_name, acr_values=auth_ldap_server, redirect_uri=https://UC1SSODLOAD01/identity/authentication/getauthcode, state=7750f983-867f-4e48-8aff-4aed45c0aeff}, persisted=false}', credentials.userName: 'admin', authenticatedUser.userId: 'admin' 2019-05-29 09:25:59,633 TRACE [qtp804611486-15] [org.xdi.oxauth.service.AuthenticationService] (AuthenticationService.java:436) - configureSessionUser sessionId: 'SessionState {dn='oxAuthSessionId=c4d163d8-2460-4a03-afeb-d38e1622db4e,ou=session,o=@!69A6.3FD5.755B.EE1A!0001!7539.FC10,o=gluu', id='c4d163d8-2460-4a03-afeb-d38e1622db4e', lastUsedAt=Wed May 29 09:25:59 UTC 2019, userDn='', authenticationTime=Wed May 29 09:25:47 UTC 2019, state=unauthenticated, sessionState='48809ba0538f908d4d4491831d9dd54c4a85c241371e50801946286f4a455f44.6c0db896-2535-4bd1-949b-b652c12d9696', permissionGranted=null, isJwt=false, jwt=null, permissionGrantedMap=org.xdi.oxauth.model.common.SessionIdAccessMap@6a2f4df1, involvedClients=null, sessionAttributes={auth_external_attributes=null, opbs=0bfad5f4-da2a-4941-b11d-7d8d4f3be72d, response_type=code, nonce=6325fbb7-2a2b-48ed-9135-b551c89ab1e5, client_id=@!69A6.3FD5.755B.EE1A!0001!7539.FC10!0008!C009.F7B8, auth_step=1, acr=auth_ldap_server, remote_ip=10.80.157.230, 10.121.18.38, auth_user=admin, scope=openid profile email user_name, acr_values=auth_ldap_server, redirect_uri=https://UC1SSODLOAD01/identity/authentication/getauthcode, state=7750f983-867f-4e48-8aff-4aed45c0aeff}, persisted=false}', sessionId.auth_user: 'admin' 2019-05-29 09:25:59,634 TRACE [qtp804611486-15] [org.xdi.service.cache.RedisStandaloneProvider] (RedisStandaloneProvider.java:109) - put - key: c4d163d8-2460-4a03-afeb-d38e1622db4e, status: OK 2019-05-29 09:25:59,635 TRACE [qtp804611486-15] [org.xdi.oxauth.service.SessionIdService] (SessionIdService.java:593) - Authenticated session, id = 'c4d163d8-2460-4a03-afeb-d38e1622db4e', state = 'authenticated', persisted = 'true' 2019-05-29 09:25:59,637 DEBUG [qtp804611486-15] [org.xdi.oxauth.auth.Authenticator] (Authenticator.java:406) - Sending event to trigger user redirection: 'admin' 2019-05-29 09:25:59,637 INFO [qtp804611486-15] [org.xdi.oxauth.service.AuthenticationService] (AuthenticationService.java:533) - Attempting to redirect user: SessionUser: SessionState {dn='oxAuthSessionId=c4d163d8-2460-4a03-afeb-d38e1622db4e,ou=session,o=@!69A6.3FD5.755B.EE1A!0001!7539.FC10,o=gluu', id='c4d163d8-2460-4a03-afeb-d38e1622db4e', lastUsedAt=Wed May 29 09:25:59 UTC 2019, userDn='inum=@!69A6.3FD5.755B.EE1A!0001!7539.FC10!0000!A8F2.DE1E.D7FB,ou=people,o=@!69A6.3FD5.755B.EE1A!0001!7539.FC10,o=gluu', authenticationTime=Wed May 29 09:25:59 UTC 2019, state=authenticated, sessionState='48809ba0538f908d4d4491831d9dd54c4a85c241371e50801946286f4a455f44.6c0db896-2535-4bd1-949b-b652c12d9696', permissionGranted=null, isJwt=false, jwt=null, permissionGrantedMap=org.xdi.oxauth.model.common.SessionIdAccessMap@6a2f4df1, involvedClients=null, sessionAttributes={auth_external_attributes=null, opbs=0bfad5f4-da2a-4941-b11d-7d8d4f3be72d, response_type=code, nonce=6325fbb7-2a2b-48ed-9135-b551c89ab1e5, client_id=@!69A6.3FD5.755B.EE1A!0001!7539.FC10!0008!C009.F7B8, auth_step=1, acr=auth_ldap_server, remote_ip=10.80.157.230, 10.121.18.38, auth_user=admin, scope=openid profile email user_name, acr_values=auth_ldap_server, redirect_uri=https://UC1SSODLOAD01/identity/authentication/getauthcode, state=7750f983-867f-4e48-8aff-4aed45c0aeff}, persisted=true} 2019-05-29 09:25:59,643 INFO [qtp804611486-15] [org.xdi.oxauth.service.AuthenticationService] (AuthenticationService.java:541) - Attempting to redirect user: User: org.xdi.oxauth.model.common.User@5034b3d4 2019-05-29 09:25:59,644 TRACE [qtp804611486-15] [org.xdi.oxauth.service.AuthenticationService] (AuthenticationService.java:549) - Logged in successfully! User: org.xdi.oxauth.model.common.User@5034b3d4, page: /authorize.xhtml, map: {scope=openid profile email user_name, acr_values=auth_ldap_server, response_type=code, redirect_uri=https://UC1SSODLOAD01/identity/authentication/getauthcode, state=7750f983-867f-4e48-8aff-4aed45c0aeff, nonce=6325fbb7-2a2b-48ed-9135-b551c89ab1e5, client_id=@!69A6.3FD5.755B.EE1A!0001!7539.FC10!0008!C009.F7B8} 2019-05-29 09:25:59,645 INFO [qtp804611486-15] [org.xdi.oxauth.auth.Authenticator] (Authenticator.java:409) - Authentication success for User: 'admin' 2019-05-29 09:25:59,645 TRACE [qtp804611486-15] [org.xdi.oxauth.auth.Authenticator] (Authenticator.java:205) - Authentication successfully for 'admin' 2019-05-29 09:25:59,838 TRACE [qtp804611486-17] [org.xdi.oxauth.service.ClientService] (ClientService.java:199) - Get client from cache by Dn 'inum=@!69A6.3FD5.755B.EE1A!0001!7539.FC10!0008!C009.F7B8,ou=clients,o=@!69A6.3FD5.755B.EE1A!0001!7539.FC10,o=gluu' 2019-05-29 09:25:59,839 DEBUG [qtp804611486-17] [org.xdi.oxauth.service.ClientService] (ClientService.java:141) - Found 1 entries for client id = @!69A6.3FD5.755B.EE1A!0001!7539.FC10!0008!C009.F7B8 2019-05-29 09:25:59,839 DEBUG [qtp804611486-17] [org.xdi.oxauth.model.authorize.ScopeChecker] (ScopeChecker.java:39) - Checking scopes policy for: openid profile email user_name 2019-05-29 09:25:59,842 DEBUG [qtp804611486-17] [org.xdi.oxauth.model.authorize.ScopeChecker] (ScopeChecker.java:68) - Granted scopes: [openid, user_name, email] 2019-05-29 09:25:59,843 TRACE [qtp804611486-17] [org.xdi.oxauth.service.SessionIdService] (SessionIdService.java:290) - Found session_id cookie: 'c4d163d8-2460-4a03-afeb-d38e1622db4e' 2019-05-29 09:25:59,844 TRACE [qtp804611486-17] [org.xdi.oxauth.service.SessionIdService] (SessionIdService.java:761) - Try to get session by id: c4d163d8-2460-4a03-afeb-d38e1622db4e ... 2019-05-29 09:25:59,844 TRACE [qtp804611486-17] [org.xdi.oxauth.service.SessionIdService] (SessionIdService.java:763) - Session dn: oxAuthSessionId=c4d163d8-2460-4a03-afeb-d38e1622db4e,ou=session,o=@!69A6.3FD5.755B.EE1A!0001!7539.FC10,o=gluu 2019-05-29 09:25:59,844 TRACE [qtp804611486-17] [org.xdi.oxauth.auth.Authenticator] (Authenticator.java:736) - authenticateBySessionId, sessionId = 'c4d163d8-2460-4a03-afeb-d38e1622db4e', session = 'SessionState {dn='oxAuthSessionId=c4d163d8-2460-4a03-afeb-d38e1622db4e,ou=session,o=@!69A6.3FD5.755B.EE1A!0001!7539.FC10,o=gluu', id='c4d163d8-2460-4a03-afeb-d38e1622db4e', lastUsedAt=Wed May 29 09:25:59 UTC 2019, userDn='inum=@!69A6.3FD5.755B.EE1A!0001!7539.FC10!0000!A8F2.DE1E.D7FB,ou=people,o=@!69A6.3FD5.755B.EE1A!0001!7539.FC10,o=gluu', authenticationTime=Wed May 29 09:25:59 UTC 2019, state=authenticated, sessionState='48809ba0538f908d4d4491831d9dd54c4a85c241371e50801946286f4a455f44.6c0db896-2535-4bd1-949b-b652c12d9696', permissionGranted=null, isJwt=false, jwt=null, permissionGrantedMap=org.xdi.oxauth.model.common.SessionIdAccessMap@7002183f, involvedClients=null, sessionAttributes={auth_external_attributes=null, opbs=0bfad5f4-da2a-4941-b11d-7d8d4f3be72d, response_type=code, nonce=6325fbb7-2a2b-48ed-9135-b551c89ab1e5, client_id=@!69A6.3FD5.755B.EE1A!0001!7539.FC10!0008!C009.F7B8, auth_step=1, acr=auth_ldap_server, remote_ip=10.80.157.230, 10.121.18.38, auth_user=admin, scope=openid profile email user_name, acr_values=auth_ldap_server, redirect_uri=https://UC1SSODLOAD01/identity/authentication/getauthcode, state=7750f983-867f-4e48-8aff-4aed45c0aeff}, persisted=false}', state= 'authenticated' 2019-05-29 09:25:59,852 TRACE [qtp804611486-17] [org.xdi.service.cache.RedisStandaloneProvider] (RedisStandaloneProvider.java:109) - put - key: c4d163d8-2460-4a03-afeb-d38e1622db4e, status: OK 2019-05-29 09:25:59,852 TRACE [qtp804611486-17] [org.xdi.oxauth.service.SessionIdService] (SessionIdService.java:761) - Try to get session by id: c4d163d8-2460-4a03-afeb-d38e1622db4e ... 2019-05-29 09:25:59,853 TRACE [qtp804611486-17] [org.xdi.oxauth.service.SessionIdService] (SessionIdService.java:763) - Session dn: oxAuthSessionId=c4d163d8-2460-4a03-afeb-d38e1622db4e,ou=session,o=@!69A6.3FD5.755B.EE1A!0001!7539.FC10,o=gluu 2019-05-29 09:25:59,853 TRACE [qtp804611486-17] [org.xdi.oxauth.service.ClientService] (ClientService.java:199) - Get client from cache by Dn 'inum=@!69A6.3FD5.755B.EE1A!0001!7539.FC10!0008!C009.F7B8,ou=clients,o=@!69A6.3FD5.755B.EE1A!0001!7539.FC10,o=gluu' 2019-05-29 09:25:59,854 DEBUG [qtp804611486-17] [org.xdi.oxauth.service.ClientService] (ClientService.java:141) - Found 1 entries for client id = @!69A6.3FD5.755B.EE1A!0001!7539.FC10!0008!C009.F7B8 2019-05-29 09:25:59,854 DEBUG [qtp804611486-17] [org.xdi.oxauth.service.RedirectionUriService] (RedirectionUriService.java:76) - Validating redirection URI: clientIdentifier = @!69A6.3FD5.755B.EE1A!0001!7539.FC10!0008!C009.F7B8, redirectionUri = https://UC1SSODLOAD01/identity/authentication/getauthcode, found = 5 2019-05-29 09:25:59,854 DEBUG [qtp804611486-17] [org.xdi.oxauth.service.RedirectionUriService] (RedirectionUriService.java:82) - Comparing https://UC1SSODLOAD01/identity/scim/auth == https://UC1SSODLOAD01/identity/authentication/getauthcode 2019-05-29 09:25:59,854 DEBUG [qtp804611486-17] [org.xdi.oxauth.service.RedirectionUriService] (RedirectionUriService.java:82) - Comparing https://UC1SSODLOAD01/identity/authentication/authcode == https://UC1SSODLOAD01/identity/authentication/getauthcode 2019-05-29 09:25:59,854 DEBUG [qtp804611486-17] [org.xdi.oxauth.service.RedirectionUriService] (RedirectionUriService.java:82) - Comparing https://UC1SSODLOAD01/identity/authentication/getauthcode == https://UC1SSODLOAD01/identity/authentication/getauthcode 2019-05-29 09:25:59,861 TRACE [qtp804611486-17] [xdi.oxauth.authorize.ws.rs.AuthorizeAction] (AuthorizeAction.java:316) - checkPermissionGranted, user = org.xdi.oxauth.model.common.User@5f4fc426 2019-05-29 09:25:59,861 TRACE [qtp804611486-17] [org.xdi.oxauth.service.AuthorizeService] (AuthorizeService.java:135) - permissionGranted 2019-05-29 09:25:59,868 TRACE [qtp804611486-17] [org.xdi.oxauth.service.ClientService] (ClientService.java:199) - Get client from cache by Dn 'inum=@!69A6.3FD5.755B.EE1A!0001!7539.FC10!0008!C009.F7B8,ou=clients,o=@!69A6.3FD5.755B.EE1A!0001!7539.FC10,o=gluu' 2019-05-29 09:25:59,868 DEBUG [qtp804611486-17] [org.xdi.oxauth.service.ClientService] (ClientService.java:141) - Found 1 entries for client id = @!69A6.3FD5.755B.EE1A!0001!7539.FC10!0008!C009.F7B8 2019-05-29 09:25:59,869 TRACE [qtp804611486-17] [org.xdi.service.cache.RedisStandaloneProvider] (RedisStandaloneProvider.java:109) - put - key: c4d163d8-2460-4a03-afeb-d38e1622db4e, status: OK 2019-05-29 09:25:59,870 TRACE [qtp804611486-17] [org.xdi.oxauth.service.AuthorizeService] (AuthorizeService.java:172) - permissionGranted, redirectTo: /oxauth/restv1/authorize?scope=openid+profile+email+user_name&acr_values=auth_ldap_server&response_type=code&redirect_uri=https%3A%2F%2FUC1SSODLOAD01%2Fidentity%2Fauthentication%2Fgetauthcode&state=7750f983-867f-4e48-8aff-4aed45c0aeff&nonce=6325fbb7-2a2b-48ed-9135-b551c89ab1e5&client_id=%40%2169A6.3FD5.755B.EE1A%210001%217539.FC10%210008%21C009.F7B8 2019-05-29 09:25:59,870 TRACE [qtp804611486-17] [org.xdi.oxauth.service.AuthorizeService] (AuthorizeService.java:245) - Invalidated session_id cookie. 2019-05-29 09:25:59,870 TRACE [qtp804611486-17] [org.xdi.oxauth.service.AuthorizeService] (AuthorizeService.java:248) - Invalidated consent_session_id cookie. 2019-05-29 09:26:00,197 TRACE [qtp804611486-16] [org.xdi.oxauth.service.ClientService] (ClientService.java:199) - Get client from cache by Dn 'inum=@!69A6.3FD5.755B.EE1A!0001!7539.FC10!0008!C009.F7B8,ou=clients,o=@!69A6.3FD5.755B.EE1A!0001!7539.FC10,o=gluu' 2019-05-29 09:26:00,197 DEBUG [qtp804611486-16] [org.xdi.oxauth.service.ClientService] (ClientService.java:141) - Found 1 entries for client id = @!69A6.3FD5.755B.EE1A!0001!7539.FC10!0008!C009.F7B8 2019-05-29 09:26:00,197 TRACE [qtp804611486-16] [org.xdi.oxauth.auth.AuthenticationFilter] (AuthenticationFilter.java:91) - Get request to: 'https://uc1ssodload01/oxauth/restv1/authorize' 2019-05-29 09:26:00,199 DEBUG [qtp804611486-16] [xdi.oxauth.authorize.ws.rs.AuthorizeRestWebServiceImpl] (AuthorizeRestWebServiceImpl.java:166) - Attempting to request authorization: responseType = code, clientId = @!69A6.3FD5.755B.EE1A!0001!7539.FC10!0008!C009.F7B8, scope = openid profile email user_name, redirectUri = https://UC1SSODLOAD01/identity/authentication/getauthcode, nonce = 6325fbb7-2a2b-48ed-9135-b551c89ab1e5, state = 7750f983-867f-4e48-8aff-4aed45c0aeff, request = null, isSecure = true, requestSessionId = null, sessionId = null 2019-05-29 09:26:00,199 DEBUG [qtp804611486-16] [xdi.oxauth.authorize.ws.rs.AuthorizeRestWebServiceImpl] (AuthorizeRestWebServiceImpl.java:172) - Attempting to request authorization: acrValues = auth_ldap_server, amrValues = null, originHeaders = null, codeChallenge = null, codeChallengeMethod = null, customRespHeaders = null, claims = null, tokenBindingHeader = null 2019-05-29 09:26:00,200 TRACE [qtp804611486-16] [org.xdi.oxauth.service.ClientService] (ClientService.java:199) - Get client from cache by Dn 'inum=@!69A6.3FD5.755B.EE1A!0001!7539.FC10!0008!C009.F7B8,ou=clients,o=@!69A6.3FD5.755B.EE1A!0001!7539.FC10,o=gluu' 2019-05-29 09:26:00,200 DEBUG [qtp804611486-16] [org.xdi.oxauth.service.ClientService] (ClientService.java:141) - Found 1 entries for client id = @!69A6.3FD5.755B.EE1A!0001!7539.FC10!0008!C009.F7B8 2019-05-29 09:26:00,200 DEBUG [qtp804611486-16] [org.xdi.oxauth.model.authorize.ScopeChecker] (ScopeChecker.java:39) - Checking scopes policy for: openid profile email user_name 2019-05-29 09:26:00,203 DEBUG [qtp804611486-16] [org.xdi.oxauth.model.authorize.ScopeChecker] (ScopeChecker.java:68) - Granted scopes: [openid, user_name, email] 2019-05-29 09:26:00,204 TRACE [qtp804611486-16] [org.xdi.oxauth.service.ClientService] (ClientService.java:199) - Get client from cache by Dn 'inum=@!69A6.3FD5.755B.EE1A!0001!7539.FC10!0008!C009.F7B8,ou=clients,o=@!69A6.3FD5.755B.EE1A!0001!7539.FC10,o=gluu' 2019-05-29 09:26:00,204 DEBUG [qtp804611486-16] [org.xdi.oxauth.service.ClientService] (ClientService.java:141) - Found 1 entries for client id = @!69A6.3FD5.755B.EE1A!0001!7539.FC10!0008!C009.F7B8 2019-05-29 09:26:00,204 DEBUG [qtp804611486-16] [org.xdi.oxauth.service.RedirectionUriService] (RedirectionUriService.java:76) - Validating redirection URI: clientIdentifier = @!69A6.3FD5.755B.EE1A!0001!7539.FC10!0008!C009.F7B8, redirectionUri = https://UC1SSODLOAD01/identity/authentication/getauthcode, found = 5 2019-05-29 09:26:00,204 DEBUG [qtp804611486-16] [org.xdi.oxauth.service.RedirectionUriService] (RedirectionUriService.java:82) - Comparing https://UC1SSODLOAD01/identity/scim/auth == https://UC1SSODLOAD01/identity/authentication/getauthcode 2019-05-29 09:26:00,205 DEBUG [qtp804611486-16] [org.xdi.oxauth.service.RedirectionUriService] (RedirectionUriService.java:82) - Comparing https://UC1SSODLOAD01/identity/authentication/authcode == https://UC1SSODLOAD01/identity/authentication/getauthcode 2019-05-29 09:26:00,205 DEBUG [qtp804611486-16] [org.xdi.oxauth.service.RedirectionUriService] (RedirectionUriService.java:82) - Comparing https://UC1SSODLOAD01/identity/authentication/getauthcode == https://UC1SSODLOAD01/identity/authentication/getauthcode 2019-05-29 09:26:00,395 TRACE [qtp804611486-11] [org.xdi.oxauth.service.ClientService] (ClientService.java:199) - Get client from cache by Dn 'inum=@!69A6.3FD5.755B.EE1A!0001!7539.FC10!0008!C009.F7B8,ou=clients,o=@!69A6.3FD5.755B.EE1A!0001!7539.FC10,o=gluu' 2019-05-29 09:26:00,395 DEBUG [qtp804611486-11] [org.xdi.oxauth.service.ClientService] (ClientService.java:141) - Found 1 entries for client id = @!69A6.3FD5.755B.EE1A!0001!7539.FC10!0008!C009.F7B8 2019-05-29 09:26:00,395 DEBUG [qtp804611486-11] [org.xdi.oxauth.model.authorize.ScopeChecker] (ScopeChecker.java:39) - Checking scopes policy for: openid profile email user_name 2019-05-29 09:26:00,400 DEBUG [qtp804611486-11] [org.xdi.oxauth.model.authorize.ScopeChecker] (ScopeChecker.java:68) - Granted scopes: [openid, user_name, email] 2019-05-29 09:26:00,400 TRACE [qtp804611486-11] [org.xdi.oxauth.service.SessionIdService] (SessionIdService.java:544) - Generated new session, id = 'df3e3fdd-055a-446f-9ab1-0f7f21067fa2', state = 'unauthenticated', asJwt = 'false', persisted = 'false' 2019-05-29 09:26:00,401 TRACE [qtp804611486-11] [org.xdi.oxauth.service.SessionIdService] (SessionIdService.java:617) - sessionIdAttributes: org.xdi.oxauth.model.common.SessionIdAccessMap@4112f8c 2019-05-29 09:26:00,402 TRACE [qtp804611486-11] [org.xdi.service.cache.RedisStandaloneProvider] (RedisStandaloneProvider.java:109) - put - key: df3e3fdd-055a-446f-9ab1-0f7f21067fa2, status: OK 2019-05-29 09:26:00,402 TRACE [qtp804611486-11] [xdi.oxauth.authorize.ws.rs.AuthorizeAction] (AuthorizeAction.java:289) - Session 'df3e3fdd-055a-446f-9ab1-0f7f21067fa2' persisted to LDAP 2019-05-29 09:26:00,591 TRACE [qtp804611486-12] [org.xdi.oxauth.service.SessionIdService] (SessionIdService.java:290) - Found session_id cookie: 'df3e3fdd-055a-446f-9ab1-0f7f21067fa2' 2019-05-29 09:26:00,591 TRACE [qtp804611486-12] [org.xdi.oxauth.service.SessionIdService] (SessionIdService.java:761) - Try to get session by id: df3e3fdd-055a-446f-9ab1-0f7f21067fa2 ... 2019-05-29 09:26:00,592 TRACE [qtp804611486-12] [org.xdi.oxauth.service.SessionIdService] (SessionIdService.java:763) - Session dn: oxAuthSessionId=df3e3fdd-055a-446f-9ab1-0f7f21067fa2,ou=session,o=@!69A6.3FD5.755B.EE1A!0001!7539.FC10,o=gluu 2019-05-29 09:26:00,593 TRACE [qtp804611486-12] [org.xdi.service.cache.RedisStandaloneProvider] (RedisStandaloneProvider.java:109) - put - key: df3e3fdd-055a-446f-9ab1-0f7f21067fa2, status: OK 2019-05-29 09:26:00,603 TRACE [qtp804611486-12] [org.xdi.oxauth.service.ClientService] (ClientService.java:199) - Get client from cache by Dn 'inum=@!69A6.3FD5.755B.EE1A!0001!7539.FC10!0008!C009.F7B8,ou=clients,o=@!69A6.3FD5.755B.EE1A!0001!7539.FC10,o=gluu' 2019-05-29 09:26:00,603 DEBUG [qtp804611486-12] [org.xdi.oxauth.service.ClientService] (ClientService.java:141) - Found 1 entries for client id = @!69A6.3FD5.755B.EE1A!0001!7539.FC10!0008!C009.F7B8 2019-05-29 09:26:00,604 TRACE [qtp804611486-12] [org.xdi.oxauth.service.ClientService] (ClientService.java:199) - Get client from cache by Dn 'inum=@!69A6.3FD5.755B.EE1A!0001!7539.FC10!0008!C009.F7B8,ou=clients,o=@!69A6.3FD5.755B.EE1A!0001!7539.FC10,o=gluu' 2019-05-29 09:26:00,604 DEBUG [qtp804611486-12] [org.xdi.oxauth.service.ClientService] (ClientService.java:141) - Found 1 entries for client id = @!69A6.3FD5.755B.EE1A!0001!7539.FC10!0008!C009.F7B8 2019-05-29 09:26:00,605 TRACE [qtp804611486-12] [org.xdi.oxauth.service.ClientService] (ClientService.java:199) - Get client from cache by Dn 'inum=@!69A6.3FD5.755B.EE1A!0001!7539.FC10!0008!C009.F7B8,ou=clients,o=@!69A6.3FD5.755B.EE1A!0001!7539.FC10,o=gluu' 2019-05-29 09:26:00,605 DEBUG [qtp804611486-12] [org.xdi.oxauth.service.ClientService] (ClientService.java:141) - Found 1 entries for client id = @!69A6.3FD5.755B.EE1A!0001!7539.FC10!0008!C009.F7B8 2019-05-29 09:26:00,606 TRACE [qtp804611486-12] [org.xdi.oxauth.service.ClientService] (ClientService.java:199) - Get client from cache by Dn 'inum=@!69A6.3FD5.755B.EE1A!0001!7539.FC10!0008!C009.F7B8,ou=clients,o=@!69A6.3FD5.755B.EE1A!0001!7539.FC10,o=gluu' 2019-05-29 09:26:00,606 DEBUG [qtp804611486-12] [org.xdi.oxauth.service.ClientService] (ClientService.java:141) - Found 1 entries for client id = @!69A6.3FD5.755B.EE1A!0001!7539.FC10!0008!C009.F7B8 2019-05-29 09:26:00,607 TRACE [qtp804611486-12] [org.xdi.oxauth.service.ClientService] (ClientService.java:199) - Get client from cache by Dn 'inum=@!69A6.3FD5.755B.EE1A!0001!7539.FC10!0008!C009.F7B8,ou=clients,o=@!69A6.3FD5.755B.EE1A!0001!7539.FC10,o=gluu' 2019-05-29 09:26:00,607 DEBUG [qtp804611486-12] [org.xdi.oxauth.service.ClientService] (ClientService.java:141) - Found 1 entries for client id = @!69A6.3FD5.755B.EE1A!0001!7539.FC10!0008!C009.F7B8 2019-05-29 09:26:00,608 TRACE [qtp804611486-12] [org.xdi.oxauth.service.ClientService] (ClientService.java:199) - Get client from cache by Dn 'inum=@!69A6.3FD5.755B.EE1A!0001!7539.FC10!0008!C009.F7B8,ou=clients,o=@!69A6.3FD5.755B.EE1A!0001!7539.FC10,o=gluu' 2019-05-29 09:26:00,609 DEBUG [qtp804611486-12] [org.xdi.oxauth.service.ClientService] (ClientService.java:141) - Found 1 entries for client id = @!69A6.3FD5.755B.EE1A!0001!7539.FC10!0008!C009.F7B8 2019-05-29 09:26:00,610 TRACE [qtp804611486-12] [org.xdi.oxauth.service.ClientService] (ClientService.java:199) - Get client from cache by Dn 'inum=@!69A6.3FD5.755B.EE1A!0001!7539.FC10!0008!C009.F7B8,ou=clients,o=@!69A6.3FD5.755B.EE1A!0001!7539.FC10,o=gluu' 2019-05-29 09:26:00,610 DEBUG [qtp804611486-12] [org.xdi.oxauth.service.ClientService] (ClientService.java:141) - Found 1 entries for client id = @!69A6.3FD5.755B.EE1A!0001!7539.FC10!0008!C009.F7B8 2019-05-29 09:26:00,611 TRACE [qtp804611486-12] [org.xdi.oxauth.service.ClientService] (ClientService.java:199) - Get client from cache by Dn 'inum=@!69A6.3FD5.755B.EE1A!0001!7539.FC10!0008!C009.F7B8,ou=clients,o=@!69A6.3FD5.755B.EE1A!0001!7539.FC10,o=gluu' 2019-05-29 09:26:00,612 DEBUG [qtp804611486-12] [org.xdi.oxauth.service.ClientService] (ClientService.java:141) - Found 1 entries for client id = @!69A6.3FD5.755B.EE1A!0001!7539.FC10!0008!C009.F7B8 2019-05-29 09:26:00,617 TRACE [qtp804611486-12] [org.xdi.oxauth.service.ClientService] (ClientService.java:199) - Get client from cache by Dn 'inum=@!69A6.3FD5.755B.EE1A!0001!7539.FC10!0008!C009.F7B8,ou=clients,o=@!69A6.3FD5.755B.EE1A!0001!7539.FC10,o=gluu' 2019-05-29 09:26:00,618 DEBUG [qtp804611486-12] [org.xdi.oxauth.service.ClientService] (ClientService.java:141) - Found 1 entries for client id = @!69A6.3FD5.755B.EE1A!0001!7539.FC10!0008!C009.F7B8 2019-05-29 09:26:00,618 TRACE [qtp804611486-12] [org.xdi.oxauth.service.ClientService] (ClientService.java:199) - Get client from cache by Dn 'inum=@!69A6.3FD5.755B.EE1A!0001!7539.FC10!0008!C009.F7B8,ou=clients,o=@!69A6.3FD5.755B.EE1A!0001!7539.FC10,o=gluu' 2019-05-29 09:26:00,619 DEBUG [qtp804611486-12] [org.xdi.oxauth.service.ClientService] (ClientService.java:141) - Found 1 entries for client id = @!69A6.3FD5.755B.EE1A!0001!7539.FC10!0008!C009.F7B8 2019-05-29 09:26:08,517 DEBUG [oxAuthScheduler_Worker-2] [org.xdi.service.timer.RequestJobListener] (RequestJobListener.java:52) - Bound request started 2019-05-29 09:26:08,517 DEBUG [oxAuthScheduler_Worker-2] [org.xdi.service.timer.TimerJob] (TimerJob.java:34) - Fire timer event [org.xdi.service.cdi.event.LoggerUpdateEvent] with qualifiers [@org.xdi.service.cdi.event.Scheduled()] 2019-05-29 09:26:08,517 DEBUG [oxAuthScheduler_Worker-2] [org.xdi.service.timer.RequestJobListener] (RequestJobListener.java:62) - Bound request ended ```

By Bruce Gordon Account Admin 29 May 2019 at 4:32 a.m. CDT

Copy
Bruce Gordon gravatar
Redis is being used in a cluster and yes when the value is set back to false it works good again. Thanks !

By Aliaksandr Samuseu staff 29 May 2019 at 6:31 a.m. CDT

Copy
Aliaksandr Samuseu gravatar
Hi, Bruce. Could you provide a link to the doc you used to build the cluster?

By Yuriy Zabrovarnyy staff 29 May 2019 at 6:35 a.m. CDT

Copy
Yuriy Zabrovarnyy gravatar
According to logs you have single standalone redis connection, not cluster. ``` 2019-05-29 09:25:59,629 TRACE [qtp804611486-15] [org.xdi.service.cache.RedisStandaloneProvider] ``` Otherwise logs looks ok. Re-assigning to Alex for reproducing.

By Bruce Gordon Account Admin 29 May 2019 at 6:36 a.m. CDT

Copy
Bruce Gordon gravatar
Hi Yuriy, This is with latest Gluu Cluster Manager out of the box in my test environment. This was only setup a couple of weeks ago so up to date probably. Will confirmed previously that someone in GLUU had been able to reproduce the issue. Thanks!

By Mohib Zico staff 29 May 2019 at 7:56 a.m. CDT

Copy
Mohib Zico gravatar
@Yuriy.Zabrovarnyy: I was able to reproduce this issue. Had a little chat on this last Friday...

By Aliaksandr Samuseu staff 29 May 2019 at 9:37 a.m. CDT

Copy
Aliaksandr Samuseu gravatar
Reassigning to Zico as he already was working on this issue before.

By Yuriy Zabrovarnyy staff 31 May 2019 at 3:18 p.m. CDT

Copy
Yuriy Zabrovarnyy gravatar
We have reproducible case and are working on figuring out the root cause.

By Yuriy Zabrovarnyy staff 03 Jun 2019 at 3:17 a.m. CDT

Copy
Yuriy Zabrovarnyy gravatar
Ticket https://github.com/GluuFederation/oxAuth/issues/1083

By William Lowe user 03 Jun 2019 at 4:44 a.m. CDT

Copy
William Lowe gravatar
Looks like Yuriy pushed a patch to 3.1.6, which we will be pushing sometime this week. Thanks, Will

By Yuriy Zabrovarnyy staff 03 Jun 2019 at 9:57 a.m. CDT

Copy
Yuriy Zabrovarnyy gravatar
Issue is fixed in 3.1.6.sp2 and master. You can try by replacing oxauth war file: https://ox.gluu.org/maven/org/xdi/oxauth-server/3.1.6.sp2/oxauth-server-3.1.6.sp2.war Thanks, Yuriy Z

Post an answer