By: Vreixo Luis Gonzalez Caneda user 20 Jun 2021 at 1:09 p.m. CDT

6 Responses
Vreixo Luis Gonzalez Caneda gravatar
I have configured Passport with Azure AD but is not working and the error is generic one in interface. The problem is that any error log is produced, in passport neither in oxauth_script. These are lines from oxauth as it's generating entries but I don't see any errors. ``` 2021-06-20 17:57:09,183 TRACE [qtp222511810-4501] [org.gluu.oxauth.service.external.ExternalAuthenticationService] (ExternalAuthenticationService.java:291) - Executing python 'getPageForStep' authenticator method 2021-06-20 17:57:09,184 INFO [qtp222511810-4501] [org.gluu.service.PythonService$PythonLoggerOutputStream] (PythonService.java:243) - Passport. getPageForStep called 2021-06-20 17:57:09,195 TRACE [qtp222511810-4501] [org.gluu.oxauth.service.external.ExternalAuthenticationService] (ExternalAuthenticationService.java:398) - Validating acr_values: 'passport_social' 2021-06-20 17:57:09,195 DEBUG [qtp222511810-4501] [org.gluu.oxauth.service.external.ExternalAuthenticationService] (ExternalAuthenticationService.java:165) - Executing python 'isValidAuthenticationMethod' authenticator method 2021-06-20 17:57:09,195 TRACE [qtp222511810-4501] [org.gluu.oxauth.service.external.ExternalAuthenticationService] (ExternalAuthenticationService.java:263) - Executing python 'prepareForStep' authenticator method 2021-06-20 17:57:09,196 INFO [qtp222511810-4501] [org.gluu.service.PythonService$PythonLoggerOutputStream] (PythonService.java:243) - Passport. prepareForStep called 1 2021-06-20 17:57:09,197 INFO [qtp222511810-4501] [org.gluu.service.PythonService$PythonLoggerOutputStream] (PythonService.java:243) - Passport. parseAllProviders. Adding providers 2021-06-20 17:57:09,200 INFO [qtp222511810-4501] [org.gluu.service.PythonService$PythonLoggerOutputStream] (PythonService.java:243) - Passport. parseProviderConfigs. Configured providers: 2021-06-20 17:57:09,200 INFO [qtp222511810-4501] [org.gluu.service.PythonService$PythonLoggerOutputStream] (PythonService.java:243) - {u'Microsoft365': {'requestForEmail': False, 'displayName': u'Login with Microsoft', 'emailLinkingSafe': False, 'type': u'openidconnect', 'logo_img': None, 'saml': False}} 2021-06-20 17:57:09,202 INFO [qtp222511810-4501] [org.gluu.service.PythonService$PythonLoggerOutputStream] (PythonService.java:243) - Passport. prepareForStep. A page to manually select an identity provider will be shown 2021-06-20 17:57:09,202 TRACE [qtp222511810-4501] [org.gluu.oxauth.service.external.ExternalAuthenticationService] (ExternalAuthenticationService.java:277) - Executing python 'getExtraParametersForStep' authenticator method 2021-06-20 17:57:09,202 INFO [qtp222511810-4501] [org.gluu.service.PythonService$PythonLoggerOutputStream] (PythonService.java:243) - Passport. getExtraParametersForStep called 2021-06-20 17:57:10,665 TRACE [qtp222511810-22] [org.gluu.oxauth.service.external.ExternalAuthenticationService] (ExternalAuthenticationService.java:207) - Executing python 'authenticate' authenticator method 2021-06-20 17:57:10,671 INFO [qtp222511810-22] [org.gluu.service.PythonService$PythonLoggerOutputStream] (PythonService.java:243) - Passport. authenticate for step 1 called 2021-06-20 17:57:10,672 INFO [qtp222511810-22] [org.gluu.service.PythonService$PythonLoggerOutputStream] (PythonService.java:243) - Passport. authenticate for step 1. Retrying step 1 2021-06-20 17:57:10,673 TRACE [qtp222511810-22] [org.gluu.oxauth.service.external.ExternalAuthenticationService] (ExternalAuthenticationService.java:305) - Executing python 'getApiVersion' authenticator method 2021-06-20 17:57:10,674 TRACE [qtp222511810-22] [org.gluu.oxauth.service.external.ExternalAuthenticationService] (ExternalAuthenticationService.java:221) - Executing python 'getNextStep' authenticator method 2021-06-20 17:57:10,685 TRACE [qtp222511810-22] [org.gluu.oxauth.service.external.ExternalAuthenticationService] (ExternalAuthenticationService.java:277) - Executing python 'getExtraParametersForStep' authenticator method 2021-06-20 17:57:10,685 INFO [qtp222511810-22] [org.gluu.service.PythonService$PythonLoggerOutputStream] (PythonService.java:243) - Passport. getExtraParametersForStep called 2021-06-20 17:57:10,686 TRACE [qtp222511810-22] [org.gluu.oxauth.service.external.ExternalAuthenticationService] (ExternalAuthenticationService.java:193) - Executing python 'getCountAuthenticationSteps' authenticator method 2021-06-20 17:57:10,686 INFO [qtp222511810-22] [org.gluu.service.PythonService$PythonLoggerOutputStream] (PythonService.java:243) - Passport. getCountAuthenticationSteps called 2021-06-20 17:57:10,686 TRACE [qtp222511810-22] [org.gluu.oxauth.service.external.ExternalAuthenticationService] (ExternalAuthenticationService.java:291) - Executing python 'getPageForStep' authenticator method 2021-06-20 17:57:10,687 INFO [qtp222511810-22] [org.gluu.service.PythonService$PythonLoggerOutputStream] (PythonService.java:243) - Passport. getPageForStep called 2021-06-20 17:57:10,687 TRACE [qtp222511810-22] [org.gluu.oxauth.service.external.ExternalAuthenticationService] (ExternalAuthenticationService.java:277) - Executing python 'getExtraParametersForStep' authenticator method 2021-06-20 17:57:10,687 INFO [qtp222511810-22] [org.gluu.service.PythonService$PythonLoggerOutputStream] (PythonService.java:243) - Passport. getExtraParametersForStep called 2021-06-20 17:57:10,717 TRACE [qtp222511810-16] [org.gluu.oxauth.service.external.ExternalAuthenticationService] (ExternalAuthenticationService.java:398) - Validating acr_values: 'passport_social' 2021-06-20 17:57:10,717 DEBUG [qtp222511810-16] [org.gluu.oxauth.service.external.ExternalAuthenticationService] (ExternalAuthenticationService.java:165) - Executing python 'isValidAuthenticationMethod' authenticator method 2021-06-20 17:57:10,717 TRACE [qtp222511810-16] [org.gluu.oxauth.service.external.ExternalAuthenticationService] (ExternalAuthenticationService.java:263) - Executing python 'prepareForStep' authenticator method 2021-06-20 17:57:10,717 INFO [qtp222511810-16] [org.gluu.service.PythonService$PythonLoggerOutputStream] (PythonService.java:243) - Passport. prepareForStep called 1 2021-06-20 17:57:10,718 INFO [qtp222511810-16] [org.gluu.service.PythonService$PythonLoggerOutputStream] (PythonService.java:243) - Passport. parseAllProviders. Adding providers 2021-06-20 17:57:10,721 INFO [qtp222511810-16] [org.gluu.service.PythonService$PythonLoggerOutputStream] (PythonService.java:243) - Passport. parseProviderConfigs. Configured providers: 2021-06-20 17:57:10,721 INFO [qtp222511810-16] [org.gluu.service.PythonService$PythonLoggerOutputStream] (PythonService.java:243) - {u'Microsoft365': {'requestForEmail': False, 'displayName': u'Login with Microsoft', 'emailLinkingSafe': False, 'type': u'openidconnect', 'logo_img': None, 'saml': False}} 2021-06-20 17:57:10,723 INFO [qtp222511810-16] [org.gluu.service.PythonService$PythonLoggerOutputStream] (PythonService.java:243) - Passport. getPassportRedirectUrl. Obtaining token from passport at https://gluu-vm.pre.whispeak.io/passport/token 2021-06-20 17:57:10,744 INFO [qtp222511810-16] [org.gluu.service.PythonService$PythonLoggerOutputStream] (PythonService.java:243) - Passport. getPassportRedirectUrl. Response was 200 2021-06-20 17:57:10,746 TRACE [qtp222511810-16] [org.gluu.oxauth.service.external.ExternalAuthenticationService] (ExternalAuthenticationService.java:277) - Executing python 'getExtraParametersForStep' authenticator method 2021-06-20 17:57:10,747 INFO [qtp222511810-16] [org.gluu.service.PythonService$PythonLoggerOutputStream] (PythonService.java:243) - Passport. getExtraParametersForStep called 2021-06-20 17:57:15,456 TRACE [qtp222511810-22] [org.gluu.oxauth.service.external.ExternalAuthenticationService] (ExternalAuthenticationService.java:398) - Validating acr_values: 'passport_social' 2021-06-20 17:57:15,456 DEBUG [qtp222511810-22] [org.gluu.oxauth.service.external.ExternalAuthenticationService] (ExternalAuthenticationService.java:165) - Executing python 'isValidAuthenticationMethod' authenticator method 2021-06-20 17:57:15,457 TRACE [qtp222511810-22] [org.gluu.oxauth.service.external.ExternalAuthenticationService] (ExternalAuthenticationService.java:263) - Executing python 'prepareForStep' authenticator method 2021-06-20 17:57:15,457 INFO [qtp222511810-22] [org.gluu.service.PythonService$PythonLoggerOutputStream] (PythonService.java:243) - Passport. prepareForStep called 1 2021-06-20 17:57:15,458 INFO [qtp222511810-22] [org.gluu.service.PythonService$PythonLoggerOutputStream] (PythonService.java:243) - Passport. parseAllProviders. Adding providers 2021-06-20 17:57:15,461 INFO [qtp222511810-22] [org.gluu.service.PythonService$PythonLoggerOutputStream] (PythonService.java:243) - Passport. parseProviderConfigs. Configured providers: 2021-06-20 17:57:15,461 INFO [qtp222511810-22] [org.gluu.service.PythonService$PythonLoggerOutputStream] (PythonService.java:243) - {u'Microsoft365': {'requestForEmail': False, 'displayName': u'Login with Microsoft', 'emailLinkingSafe': False, 'type': u'openidconnect', 'logo_img': None, 'saml': False}} 2021-06-20 17:57:15,463 INFO [qtp222511810-22] [org.gluu.service.PythonService$PythonLoggerOutputStream] (PythonService.java:243) - Passport. prepareForStep. A page to manually select an identity provider will be shown 2021-06-20 17:57:15,463 TRACE [qtp222511810-22] [org.gluu.oxauth.service.external.ExternalAuthenticationService] (ExternalAuthenticationService.java:277) - Executing python 'getExtraParametersForStep' authenticator method 2021-06-20 17:57:15,463 INFO [qtp222511810-22] [org.gluu.service.PythonService$PythonLoggerOutputStream] (PythonService.java:243) - Passport. getExtraParametersForStep called ``` https://www.dropbox.com/s/29mqhj1s4n5g32p/Capture%20d%E2%80%99%C3%A9cran%20de%202021-06-20%2020-06-22.png?dl=0 https://www.dropbox.com/s/thr65s8dks1klm6/Capture%20d%E2%80%99%C3%A9cran%20de%202021-06-20%2020-07-35.png?dl=0 https://www.dropbox.com/s/n2e94r1rrbutjhi/Capture%20d%E2%80%99%C3%A9cran%20de%202021-06-20%2020-07-19.png?dl=0 https://www.dropbox.com/s/jhac7mslveyfxov/Capture%20d%E2%80%99%C3%A9cran%20de%202021-06-20%2020-06-58.png?dl=0

By Mobarak Hosen Shakil staff 21 Jun 2021 at 9:34 a.m. CDT

Mobarak Hosen Shakil gravatar
We need more information. images link are not working. Thanks & Regards ~ Shakil

By Vreixo Luis Gonzalez Caneda user 21 Jun 2021 at 11:06 a.m. CDT

Vreixo Luis Gonzalez Caneda gravatar
Sorry, there were issues with the URLs indeed, now these are the good addresses and images are ok. I'm looking for more logs but I'm not finding any more files with relevant information.

By Vreixo Luis Gonzalez Caneda user 21 Jun 2021 at 11:24 a.m. CDT

Vreixo Luis Gonzalez Caneda gravatar
Logs from oxauth ``` 2021-06-21 16:16:36,139 TRACE [qtp222511810-21] [org.gluu.service.BaseCacheService] (BaseCacheService.java:37) - Request data, key 'inum=764C,ou=scopes,o=gluu' 2021-06-21 16:16:36,139 TRACE [qtp222511810-21] [org.gluu.service.BaseCacheService] (BaseCacheService.java:39) - Loaded data, key 'inum=764C,ou=scopes,o=gluu': 'Scope{dn='inum=764C,ou=scopes,o=gluu', inum='764C', displayName='null', id='email', iconUrl='null', description='View your email address.', scopeType=openid, oxAuthClaims=[inum=8F88,ou=attributes,o=gluu, inum=CAE3,ou=attributes,o=gluu], defaultScope=false, oxAuthGroupClaims=null, dynamicScopeScripts=null, umaAuthorizationPolicies=null, deletable=null, expirationDate=null, attributes=ScopeAttributes{spontaneousClientId=''spontaneousClientScopes='[]'showInConfigurationEndpoint='true'}}' 2021-06-21 16:16:36,139 TRACE [qtp222511810-21] [org.gluu.service.BaseCacheService] (BaseCacheService.java:58) - Loaded from cache, key: 'inum=764C,ou=scopes,o=gluu' 2021-06-21 16:16:36,139 TRACE [qtp222511810-21] [org.gluu.service.BaseCacheService] (BaseCacheService.java:84) - Put data, key 'email': 'Scope{dn='inum=764C,ou=scopes,o=gluu', inum='764C', displayName='null', id='email', iconUrl='null', description='View your email address.', scopeType=openid, oxAuthClaims=[inum=8F88,ou=attributes,o=gluu, inum=CAE3,ou=attributes,o=gluu], defaultScope=false, oxAuthGroupClaims=null, dynamicScopeScripts=null, umaAuthorizationPolicies=null, deletable=null, expirationDate=null, attributes=ScopeAttributes{spontaneousClientId=''spontaneousClientScopes='[]'showInConfigurationEndpoint='true'}}' 2021-06-21 16:16:36,140 TRACE [qtp222511810-21] [org.gluu.service.BaseCacheService] (BaseCacheService.java:37) - Request data, key 'inum=F0C4,ou=scopes,o=gluu' 2021-06-21 16:16:36,140 TRACE [qtp222511810-21] [org.gluu.service.BaseCacheService] (BaseCacheService.java:39) - Loaded data, key 'inum=F0C4,ou=scopes,o=gluu': 'Scope{dn='inum=F0C4,ou=scopes,o=gluu', inum='F0C4', displayName='null', id='openid', iconUrl='null', description='Authenticate using OpenID Connect.', scopeType=openid, oxAuthClaims=null, defaultScope=true, oxAuthGroupClaims=null, dynamicScopeScripts=null, umaAuthorizationPolicies=null, deletable=null, expirationDate=null, attributes=ScopeAttributes{spontaneousClientId=''spontaneousClientScopes='[]'showInConfigurationEndpoint='true'}}' 2021-06-21 16:16:36,141 TRACE [qtp222511810-21] [org.gluu.service.BaseCacheService] (BaseCacheService.java:58) - Loaded from cache, key: 'inum=F0C4,ou=scopes,o=gluu' 2021-06-21 16:16:36,141 TRACE [qtp222511810-21] [org.gluu.service.BaseCacheService] (BaseCacheService.java:84) - Put data, key 'openid': 'Scope{dn='inum=F0C4,ou=scopes,o=gluu', inum='F0C4', displayName='null', id='openid', iconUrl='null', description='Authenticate using OpenID Connect.', scopeType=openid, oxAuthClaims=null, defaultScope=true, oxAuthGroupClaims=null, dynamicScopeScripts=null, umaAuthorizationPolicies=null, deletable=null, expirationDate=null, attributes=ScopeAttributes{spontaneousClientId=''spontaneousClientScopes='[]'showInConfigurationEndpoint='true'}}' 2021-06-21 16:16:36,141 TRACE [qtp222511810-21] [org.gluu.service.BaseCacheService] (BaseCacheService.java:37) - Request data, key 'inum=10B2,ou=scopes,o=gluu' 2021-06-21 16:16:36,141 TRACE [qtp222511810-21] [org.gluu.service.BaseCacheService] (BaseCacheService.java:39) - Loaded data, key 'inum=10B2,ou=scopes,o=gluu': 'Scope{dn='inum=10B2,ou=scopes,o=gluu', inum='10B2', displayName='null', id='user_name', iconUrl='null', description='View your local username in the Gluu Server.', scopeType=openid, oxAuthClaims=[inum=42E0,ou=attributes,o=gluu], defaultScope=false, oxAuthGroupClaims=null, dynamicScopeScripts=null, umaAuthorizationPolicies=null, deletable=null, expirationDate=null, attributes=ScopeAttributes{spontaneousClientId=''spontaneousClientScopes='[]'showInConfigurationEndpoint='true'}}' 2021-06-21 16:16:36,142 TRACE [qtp222511810-21] [org.gluu.service.BaseCacheService] (BaseCacheService.java:58) - Loaded from cache, key: 'inum=10B2,ou=scopes,o=gluu' 2021-06-21 16:16:36,142 TRACE [qtp222511810-21] [org.gluu.service.BaseCacheService] (BaseCacheService.java:84) - Put data, key 'user_name': 'Scope{dn='inum=10B2,ou=scopes,o=gluu', inum='10B2', displayName='null', id='user_name', iconUrl='null', description='View your local username in the Gluu Server.', scopeType=openid, oxAuthClaims=[inum=42E0,ou=attributes,o=gluu], defaultScope=false, oxAuthGroupClaims=null, dynamicScopeScripts=null, umaAuthorizationPolicies=null, deletable=null, expirationDate=null, attributes=ScopeAttributes{spontaneousClientId=''spontaneousClientScopes='[]'showInConfigurationEndpoint='true'}}' 2021-06-21 16:16:36,142 TRACE [qtp222511810-21] [org.gluu.service.BaseCacheService] (BaseCacheService.java:37) - Request data, key 'inum=764C,ou=scopes,o=gluu' 2021-06-21 16:16:36,143 TRACE [qtp222511810-21] [org.gluu.service.BaseCacheService] (BaseCacheService.java:39) - Loaded data, key 'inum=764C,ou=scopes,o=gluu': 'Scope{dn='inum=764C,ou=scopes,o=gluu', inum='764C', displayName='null', id='email', iconUrl='null', description='View your email address.', scopeType=openid, oxAuthClaims=[inum=8F88,ou=attributes,o=gluu, inum=CAE3,ou=attributes,o=gluu], defaultScope=false, oxAuthGroupClaims=null, dynamicScopeScripts=null, umaAuthorizationPolicies=null, deletable=null, expirationDate=null, attributes=ScopeAttributes{spontaneousClientId=''spontaneousClientScopes='[]'showInConfigurationEndpoint='true'}}' 2021-06-21 16:16:36,143 TRACE [qtp222511810-21] [org.gluu.service.BaseCacheService] (BaseCacheService.java:58) - Loaded from cache, key: 'inum=764C,ou=scopes,o=gluu' 2021-06-21 16:16:36,143 TRACE [qtp222511810-21] [org.gluu.service.BaseCacheService] (BaseCacheService.java:84) - Put data, key 'email': 'Scope{dn='inum=764C,ou=scopes,o=gluu', inum='764C', displayName='null', id='email', iconUrl='null', description='View your email address.', scopeType=openid, oxAuthClaims=[inum=8F88,ou=attributes,o=gluu, inum=CAE3,ou=attributes,o=gluu], defaultScope=false, oxAuthGroupClaims=null, dynamicScopeScripts=null, umaAuthorizationPolicies=null, deletable=null, expirationDate=null, attributes=ScopeAttributes{spontaneousClientId=''spontaneousClientScopes='[]'showInConfigurationEndpoint='true'}}' 2021-06-21 16:16:36,143 TRACE [qtp222511810-21] [org.gluu.service.BaseCacheService] (BaseCacheService.java:37) - Request data, key 'inum=F0C4,ou=scopes,o=gluu' 2021-06-21 16:16:36,144 TRACE [qtp222511810-21] [org.gluu.service.BaseCacheService] (BaseCacheService.java:39) - Loaded data, key 'inum=F0C4,ou=scopes,o=gluu': 'Scope{dn='inum=F0C4,ou=scopes,o=gluu', inum='F0C4', displayName='null', id='openid', iconUrl='null', description='Authenticate using OpenID Connect.', scopeType=openid, oxAuthClaims=null, defaultScope=true, oxAuthGroupClaims=null, dynamicScopeScripts=null, umaAuthorizationPolicies=null, deletable=null, expirationDate=null, attributes=ScopeAttributes{spontaneousClientId=''spontaneousClientScopes='[]'showInConfigurationEndpoint='true'}}' 2021-06-21 16:16:36,144 TRACE [qtp222511810-21] [org.gluu.service.BaseCacheService] (BaseCacheService.java:58) - Loaded from cache, key: 'inum=F0C4,ou=scopes,o=gluu' 2021-06-21 16:16:36,145 TRACE [qtp222511810-21] [org.gluu.service.BaseCacheService] (BaseCacheService.java:84) - Put data, key 'openid': 'Scope{dn='inum=F0C4,ou=scopes,o=gluu', inum='F0C4', displayName='null', id='openid', iconUrl='null', description='Authenticate using OpenID Connect.', scopeType=openid, oxAuthClaims=null, defaultScope=true, oxAuthGroupClaims=null, dynamicScopeScripts=null, umaAuthorizationPolicies=null, deletable=null, expirationDate=null, attributes=ScopeAttributes{spontaneousClientId=''spontaneousClientScopes='[]'showInConfigurationEndpoint='true'}}' 2021-06-21 16:16:36,145 TRACE [qtp222511810-21] [org.gluu.service.BaseCacheService] (BaseCacheService.java:37) - Request data, key 'inum=10B2,ou=scopes,o=gluu' 2021-06-21 16:16:36,145 TRACE [qtp222511810-21] [org.gluu.service.BaseCacheService] (BaseCacheService.java:39) - Loaded data, key 'inum=10B2,ou=scopes,o=gluu': 'Scope{dn='inum=10B2,ou=scopes,o=gluu', inum='10B2', displayName='null', id='user_name', iconUrl='null', description='View your local username in the Gluu Server.', scopeType=openid, oxAuthClaims=[inum=42E0,ou=attributes,o=gluu], defaultScope=false, oxAuthGroupClaims=null, dynamicScopeScripts=null, umaAuthorizationPolicies=null, deletable=null, expirationDate=null, attributes=ScopeAttributes{spontaneousClientId=''spontaneousClientScopes='[]'showInConfigurationEndpoint='true'}}' 2021-06-21 16:16:36,145 TRACE [qtp222511810-21] [org.gluu.service.BaseCacheService] (BaseCacheService.java:58) - Loaded from cache, key: 'inum=10B2,ou=scopes,o=gluu' 2021-06-21 16:16:36,146 TRACE [qtp222511810-21] [org.gluu.service.BaseCacheService] (BaseCacheService.java:84) - Put data, key 'user_name': 'Scope{dn='inum=10B2,ou=scopes,o=gluu', inum='10B2', displayName='null', id='user_name', iconUrl='null', description='View your local username in the Gluu Server.', scopeType=openid, oxAuthClaims=[inum=42E0,ou=attributes,o=gluu], defaultScope=false, oxAuthGroupClaims=null, dynamicScopeScripts=null, umaAuthorizationPolicies=null, deletable=null, expirationDate=null, attributes=ScopeAttributes{spontaneousClientId=''spontaneousClientScopes='[]'showInConfigurationEndpoint='true'}}' 2021-06-21 16:16:36,146 TRACE [qtp222511810-21] [org.gluu.service.BaseCacheService] (BaseCacheService.java:37) - Request data, key 'inum=764C,ou=scopes,o=gluu' 2021-06-21 16:16:36,146 TRACE [qtp222511810-21] [org.gluu.service.BaseCacheService] (BaseCacheService.java:39) - Loaded data, key 'inum=764C,ou=scopes,o=gluu': 'Scope{dn='inum=764C,ou=scopes,o=gluu', inum='764C', displayName='null', id='email', iconUrl='null', description='View your email address.', scopeType=openid, oxAuthClaims=[inum=8F88,ou=attributes,o=gluu, inum=CAE3,ou=attributes,o=gluu], defaultScope=false, oxAuthGroupClaims=null, dynamicScopeScripts=null, umaAuthorizationPolicies=null, deletable=null, expirationDate=null, attributes=ScopeAttributes{spontaneousClientId=''spontaneousClientScopes='[]'showInConfigurationEndpoint='true'}}' 2021-06-21 16:16:36,146 TRACE [qtp222511810-21] [org.gluu.service.BaseCacheService] (BaseCacheService.java:58) - Loaded from cache, key: 'inum=764C,ou=scopes,o=gluu' 2021-06-21 16:16:36,147 TRACE [qtp222511810-21] [org.gluu.service.BaseCacheService] (BaseCacheService.java:84) - Put data, key 'email': 'Scope{dn='inum=764C,ou=scopes,o=gluu', inum='764C', displayName='null', id='email', iconUrl='null', description='View your email address.', scopeType=openid, oxAuthClaims=[inum=8F88,ou=attributes,o=gluu, inum=CAE3,ou=attributes,o=gluu], defaultScope=false, oxAuthGroupClaims=null, dynamicScopeScripts=null, umaAuthorizationPolicies=null, deletable=null, expirationDate=null, attributes=ScopeAttributes{spontaneousClientId=''spontaneousClientScopes='[]'showInConfigurationEndpoint='true'}}' 2021-06-21 16:16:36,147 DEBUG [qtp222511810-21] [org.gluu.oxauth.model.authorize.ScopeChecker] (ScopeChecker.java:90) - Granted scopes: [openid, user_name, email] 2021-06-21 16:16:36,220 TRACE [qtp222511810-19] [org.gluu.service.BaseCacheService] (BaseCacheService.java:37) - Request data, key 'inum=1001.fcfdac3c-87a3-4422-8159-b0610e207cdb,ou=clients,o=gluu' 2021-06-21 16:16:36,222 TRACE [qtp222511810-19] [org.gluu.service.BaseCacheService] (BaseCacheService.java:39) - Loaded data, key 'inum=1001.fcfdac3c-87a3-4422-8159-b0610e207cdb,ou=clients,o=gluu': 'DeletableEntity{expirationDate=null, deletable=null} BaseEntry [dn=null]' 2021-06-21 16:16:36,222 TRACE [qtp222511810-19] [org.gluu.service.BaseCacheService] (BaseCacheService.java:58) - Loaded from cache, key: 'inum=1001.fcfdac3c-87a3-4422-8159-b0610e207cdb,ou=clients,o=gluu' 2021-06-21 16:16:36,222 DEBUG [qtp222511810-19] [org.gluu.oxauth.service.ClientService] (ClientService.java:135) - Found 1 entries for client id = 1001.fcfdac3c-87a3-4422-8159-b0610e207cdb 2021-06-21 16:16:36,223 DEBUG [qtp222511810-19] [org.gluu.oxauth.model.authorize.ScopeChecker] (ScopeChecker.java:58) - Checking scopes policy for: [openid, profile, email, user_name] 2021-06-21 16:16:36,223 TRACE [qtp222511810-19] [org.gluu.service.BaseCacheService] (BaseCacheService.java:37) - Request data, key 'inum=F0C4,ou=scopes,o=gluu' 2021-06-21 16:16:36,225 TRACE [qtp222511810-19] [org.gluu.service.BaseCacheService] (BaseCacheService.java:39) - Loaded data, key 'inum=F0C4,ou=scopes,o=gluu': 'Scope{dn='inum=F0C4,ou=scopes,o=gluu', inum='F0C4', displayName='null', id='openid', iconUrl='null', description='Authenticate using OpenID Connect.', scopeType=openid, oxAuthClaims=null, defaultScope=true, oxAuthGroupClaims=null, dynamicScopeScripts=null, umaAuthorizationPolicies=null, deletable=null, expirationDate=null, attributes=ScopeAttributes{spontaneousClientId=''spontaneousClientScopes='[]'showInConfigurationEndpoint='true'}}' 2021-06-21 16:16:36,225 TRACE [qtp222511810-19] [org.gluu.service.BaseCacheService] (BaseCacheService.java:58) - Loaded from cache, key: 'inum=F0C4,ou=scopes,o=gluu' 2021-06-21 16:16:36,226 TRACE [qtp222511810-19] [org.gluu.service.BaseCacheService] (BaseCacheService.java:84) - Put data, key 'openid': 'Scope{dn='inum=F0C4,ou=scopes,o=gluu', inum='F0C4', displayName='null', id='openid', iconUrl='null', description='Authenticate using OpenID Connect.', scopeType=openid, oxAuthClaims=null, defaultScope=true, oxAuthGroupClaims=null, dynamicScopeScripts=null, umaAuthorizationPolicies=null, deletable=null, expirationDate=null, attributes=ScopeAttributes{spontaneousClientId=''spontaneousClientScopes='[]'showInConfigurationEndpoint='true'}}' 2021-06-21 16:16:36,226 TRACE [qtp222511810-19] [org.gluu.service.BaseCacheService] (BaseCacheService.java:37) - Request data, key 'inum=10B2,ou=scopes,o=gluu' 2021-06-21 16:16:36,227 TRACE [qtp222511810-19] [org.gluu.service.BaseCacheService] (BaseCacheService.java:39) - Loaded data, key 'inum=10B2,ou=scopes,o=gluu': 'Scope{dn='inum=10B2,ou=scopes,o=gluu', inum='10B2', displayName='null', id='user_name', iconUrl='null', description='View your local username in the Gluu Server.', scopeType=openid, oxAuthClaims=[inum=42E0,ou=attributes,o=gluu], defaultScope=false, oxAuthGroupClaims=null, dynamicScopeScripts=null, umaAuthorizationPolicies=null, deletable=null, expirationDate=null, attributes=ScopeAttributes{spontaneousClientId=''spontaneousClientScopes='[]'showInConfigurationEndpoint='true'}}' 2021-06-21 16:16:36,228 TRACE [qtp222511810-19] [org.gluu.service.BaseCacheService] (BaseCacheService.java:58) - Loaded from cache, key: 'inum=10B2,ou=scopes,o=gluu' 2021-06-21 16:16:36,228 TRACE [qtp222511810-19] [org.gluu.service.BaseCacheService] (BaseCacheService.java:84) - Put data, key 'user_name': 'Scope{dn='inum=10B2,ou=scopes,o=gluu', inum='10B2', displayName='null', id='user_name', iconUrl='null', description='View your local username in the Gluu Server.', scopeType=openid, oxAuthClaims=[inum=42E0,ou=attributes,o=gluu], defaultScope=false, oxAuthGroupClaims=null, dynamicScopeScripts=null, umaAuthorizationPolicies=null, deletable=null, expirationDate=null, attributes=ScopeAttributes{spontaneousClientId=''spontaneousClientScopes='[]'showInConfigurationEndpoint='true'}}' 2021-06-21 16:16:36,229 TRACE [qtp222511810-19] [org.gluu.service.BaseCacheService] (BaseCacheService.java:37) - Request data, key 'inum=764C,ou=scopes,o=gluu' 2021-06-21 16:16:36,230 TRACE [qtp222511810-19] [org.gluu.service.BaseCacheService] (BaseCacheService.java:39) - Loaded data, key 'inum=764C,ou=scopes,o=gluu': 'Scope{dn='inum=764C,ou=scopes,o=gluu', inum='764C', displayName='null', id='email', iconUrl='null', description='View your email address.', scopeType=openid, oxAuthClaims=[inum=8F88,ou=attributes,o=gluu, inum=CAE3,ou=attributes,o=gluu], defaultScope=false, oxAuthGroupClaims=null, dynamicScopeScripts=null, umaAuthorizationPolicies=null, deletable=null, expirationDate=null, attributes=ScopeAttributes{spontaneousClientId=''spontaneousClientScopes='[]'showInConfigurationEndpoint='true'}}' 2021-06-21 16:16:36,231 TRACE [qtp222511810-19] [org.gluu.service.BaseCacheService] (BaseCacheService.java:58) - Loaded from cache, key: 'inum=764C,ou=scopes,o=gluu' 2021-06-21 16:16:36,231 TRACE [qtp222511810-19] [org.gluu.service.BaseCacheService] (BaseCacheService.java:84) - Put data, key 'email': 'Scope{dn='inum=764C,ou=scopes,o=gluu', inum='764C', displayName='null', id='email', iconUrl='null', description='View your email address.', scopeType=openid, oxAuthClaims=[inum=8F88,ou=attributes,o=gluu, inum=CAE3,ou=attributes,o=gluu], defaultScope=false, oxAuthGroupClaims=null, dynamicScopeScripts=null, umaAuthorizationPolicies=null, deletable=null, expirationDate=null, attributes=ScopeAttributes{spontaneousClientId=''spontaneousClientScopes='[]'showInConfigurationEndpoint='true'}}' 2021-06-21 16:16:36,231 TRACE [qtp222511810-19] [org.gluu.service.BaseCacheService] (BaseCacheService.java:37) - Request data, key 'inum=F0C4,ou=scopes,o=gluu' 2021-06-21 16:16:36,232 TRACE [qtp222511810-19] [org.gluu.service.BaseCacheService] (BaseCacheService.java:39) - Loaded data, key 'inum=F0C4,ou=scopes,o=gluu': 'Scope{dn='inum=F0C4,ou=scopes,o=gluu', inum='F0C4', displayName='null', id='openid', iconUrl='null', description='Authenticate using OpenID Connect.', scopeType=openid, oxAuthClaims=null, defaultScope=true, oxAuthGroupClaims=null, dynamicScopeScripts=null, umaAuthorizationPolicies=null, deletable=null, expirationDate=null, attributes=ScopeAttributes{spontaneousClientId=''spontaneousClientScopes='[]'showInConfigurationEndpoint='true'}}' 2021-06-21 16:16:36,232 TRACE [qtp222511810-19] [org.gluu.service.BaseCacheService] (BaseCacheService.java:58) - Loaded from cache, key: 'inum=F0C4,ou=scopes,o=gluu' 2021-06-21 16:16:36,232 TRACE [qtp222511810-19] [org.gluu.service.BaseCacheService] (BaseCacheService.java:84) - Put data, key 'openid': 'Scope{dn='inum=F0C4,ou=scopes,o=gluu', inum='F0C4', displayName='null', id='openid', iconUrl='null', description='Authenticate using OpenID Connect.', scopeType=openid, oxAuthClaims=null, defaultScope=true, oxAuthGroupClaims=null, dynamicScopeScripts=null, umaAuthorizationPolicies=null, deletable=null, expirationDate=null, attributes=ScopeAttributes{spontaneousClientId=''spontaneousClientScopes='[]'showInConfigurationEndpoint='true'}}' 2021-06-21 16:16:36,233 TRACE [qtp222511810-19] [org.gluu.service.BaseCacheService] (BaseCacheService.java:37) - Request data, key 'inum=10B2,ou=scopes,o=gluu' 2021-06-21 16:16:36,233 TRACE [qtp222511810-19] [org.gluu.service.BaseCacheService] (BaseCacheService.java:39) - Loaded data, key 'inum=10B2,ou=scopes,o=gluu': 'Scope{dn='inum=10B2,ou=scopes,o=gluu', inum='10B2', displayName='null', id='user_name', iconUrl='null', description='View your local username in the Gluu Server.', scopeType=openid, oxAuthClaims=[inum=42E0,ou=attributes,o=gluu], defaultScope=false, oxAuthGroupClaims=null, dynamicScopeScripts=null, umaAuthorizationPolicies=null, deletable=null, expirationDate=null, attributes=ScopeAttributes{spontaneousClientId=''spontaneousClientScopes='[]'showInConfigurationEndpoint='true'}}' 2021-06-21 16:16:36,233 TRACE [qtp222511810-19] [org.gluu.service.BaseCacheService] (BaseCacheService.java:58) - Loaded from cache, key: 'inum=10B2,ou=scopes,o=gluu' 2021-06-21 16:16:36,233 TRACE [qtp222511810-19] [org.gluu.service.BaseCacheService] (BaseCacheService.java:84) - Put data, key 'user_name': 'Scope{dn='inum=10B2,ou=scopes,o=gluu', inum='10B2', displayName='null', id='user_name', iconUrl='null', description='View your local username in the Gluu Server.', scopeType=openid, oxAuthClaims=[inum=42E0,ou=attributes,o=gluu], defaultScope=false, oxAuthGroupClaims=null, dynamicScopeScripts=null, umaAuthorizationPolicies=null, deletable=null, expirationDate=null, attributes=ScopeAttributes{spontaneousClientId=''spontaneousClientScopes='[]'showInConfigurationEndpoint='true'}}' 2021-06-21 16:16:36,234 TRACE [qtp222511810-19] [org.gluu.service.BaseCacheService] (BaseCacheService.java:37) - Request data, key 'inum=764C,ou=scopes,o=gluu' 2021-06-21 16:16:36,234 TRACE [qtp222511810-19] [org.gluu.service.BaseCacheService] (BaseCacheService.java:39) - Loaded data, key 'inum=764C,ou=scopes,o=gluu': 'Scope{dn='inum=764C,ou=scopes,o=gluu', inum='764C', displayName='null', id='email', iconUrl='null', description='View your email address.', scopeType=openid, oxAuthClaims=[inum=8F88,ou=attributes,o=gluu, inum=CAE3,ou=attributes,o=gluu], defaultScope=false, oxAuthGroupClaims=null, dynamicScopeScripts=null, umaAuthorizationPolicies=null, deletable=null, expirationDate=null, attributes=ScopeAttributes{spontaneousClientId=''spontaneousClientScopes='[]'showInConfigurationEndpoint='true'}}' 2021-06-21 16:16:36,234 TRACE [qtp222511810-19] [org.gluu.service.BaseCacheService] (BaseCacheService.java:58) - Loaded from cache, key: 'inum=764C,ou=scopes,o=gluu' 2021-06-21 16:16:36,234 TRACE [qtp222511810-19] [org.gluu.service.BaseCacheService] (BaseCacheService.java:84) - Put data, key 'email': 'Scope{dn='inum=764C,ou=scopes,o=gluu', inum='764C', displayName='null', id='email', iconUrl='null', description='View your email address.', scopeType=openid, oxAuthClaims=[inum=8F88,ou=attributes,o=gluu, inum=CAE3,ou=attributes,o=gluu], defaultScope=false, oxAuthGroupClaims=null, dynamicScopeScripts=null, umaAuthorizationPolicies=null, deletable=null, expirationDate=null, attributes=ScopeAttributes{spontaneousClientId=''spontaneousClientScopes='[]'showInConfigurationEndpoint='true'}}' 2021-06-21 16:16:36,235 TRACE [qtp222511810-19] [org.gluu.service.BaseCacheService] (BaseCacheService.java:37) - Request data, key 'inum=F0C4,ou=scopes,o=gluu' 2021-06-21 16:16:36,235 TRACE [qtp222511810-19] [org.gluu.service.BaseCacheService] (BaseCacheService.java:39) - Loaded data, key 'inum=F0C4,ou=scopes,o=gluu': 'Scope{dn='inum=F0C4,ou=scopes,o=gluu', inum='F0C4', displayName='null', id='openid', iconUrl='null', description='Authenticate using OpenID Connect.', scopeType=openid, oxAuthClaims=null, defaultScope=true, oxAuthGroupClaims=null, dynamicScopeScripts=null, umaAuthorizationPolicies=null, deletable=null, expirationDate=null, attributes=ScopeAttributes{spontaneousClientId=''spontaneousClientScopes='[]'showInConfigurationEndpoint='true'}}' 2021-06-21 16:16:36,235 TRACE [qtp222511810-19] [org.gluu.service.BaseCacheService] (BaseCacheService.java:58) - Loaded from cache, key: 'inum=F0C4,ou=scopes,o=gluu' 2021-06-21 16:16:36,235 TRACE [qtp222511810-19] [org.gluu.service.BaseCacheService] (BaseCacheService.java:84) - Put data, key 'openid': 'Scope{dn='inum=F0C4,ou=scopes,o=gluu', inum='F0C4', displayName='null', id='openid', iconUrl='null', description='Authenticate using OpenID Connect.', scopeType=openid, oxAuthClaims=null, defaultScope=true, oxAuthGroupClaims=null, dynamicScopeScripts=null, umaAuthorizationPolicies=null, deletable=null, expirationDate=null, attributes=ScopeAttributes{spontaneousClientId=''spontaneousClientScopes='[]'showInConfigurationEndpoint='true'}}' 2021-06-21 16:16:36,236 TRACE [qtp222511810-19] [org.gluu.service.BaseCacheService] (BaseCacheService.java:37) - Request data, key 'inum=10B2,ou=scopes,o=gluu' 2021-06-21 16:16:36,236 TRACE [qtp222511810-19] [org.gluu.service.BaseCacheService] (BaseCacheService.java:39) - Loaded data, key 'inum=10B2,ou=scopes,o=gluu': 'Scope{dn='inum=10B2,ou=scopes,o=gluu', inum='10B2', displayName='null', id='user_name', iconUrl='null', description='View your local username in the Gluu Server.', scopeType=openid, oxAuthClaims=[inum=42E0,ou=attributes,o=gluu], defaultScope=false, oxAuthGroupClaims=null, dynamicScopeScripts=null, umaAuthorizationPolicies=null, deletable=null, expirationDate=null, attributes=ScopeAttributes{spontaneousClientId=''spontaneousClientScopes='[]'showInConfigurationEndpoint='true'}}' 2021-06-21 16:16:36,236 TRACE [qtp222511810-19] [org.gluu.service.BaseCacheService] (BaseCacheService.java:58) - Loaded from cache, key: 'inum=10B2,ou=scopes,o=gluu' 2021-06-21 16:16:36,237 TRACE [qtp222511810-19] [org.gluu.service.BaseCacheService] (BaseCacheService.java:84) - Put data, key 'user_name': 'Scope{dn='inum=10B2,ou=scopes,o=gluu', inum='10B2', displayName='null', id='user_name', iconUrl='null', description='View your local username in the Gluu Server.', scopeType=openid, oxAuthClaims=[inum=42E0,ou=attributes,o=gluu], defaultScope=false, oxAuthGroupClaims=null, dynamicScopeScripts=null, umaAuthorizationPolicies=null, deletable=null, expirationDate=null, attributes=ScopeAttributes{spontaneousClientId=''spontaneousClientScopes='[]'showInConfigurationEndpoint='true'}}' 2021-06-21 16:16:36,237 TRACE [qtp222511810-19] [org.gluu.service.BaseCacheService] (BaseCacheService.java:37) - Request data, key 'inum=764C,ou=scopes,o=gluu' 2021-06-21 16:16:36,237 TRACE [qtp222511810-19] [org.gluu.service.BaseCacheService] (BaseCacheService.java:39) - Loaded data, key 'inum=764C,ou=scopes,o=gluu': 'Scope{dn='inum=764C,ou=scopes,o=gluu', inum='764C', displayName='null', id='email', iconUrl='null', description='View your email address.', scopeType=openid, oxAuthClaims=[inum=8F88,ou=attributes,o=gluu, inum=CAE3,ou=attributes,o=gluu], defaultScope=false, oxAuthGroupClaims=null, dynamicScopeScripts=null, umaAuthorizationPolicies=null, deletable=null, expirationDate=null, attributes=ScopeAttributes{spontaneousClientId=''spontaneousClientScopes='[]'showInConfigurationEndpoint='true'}}' 2021-06-21 16:16:36,237 TRACE [qtp222511810-19] [org.gluu.service.BaseCacheService] (BaseCacheService.java:58) - Loaded from cache, key: 'inum=764C,ou=scopes,o=gluu' 2021-06-21 16:16:36,238 TRACE [qtp222511810-19] [org.gluu.service.BaseCacheService] (BaseCacheService.java:84) - Put data, key 'email': 'Scope{dn='inum=764C,ou=scopes,o=gluu', inum='764C', displayName='null', id='email', iconUrl='null', description='View your email address.', scopeType=openid, oxAuthClaims=[inum=8F88,ou=attributes,o=gluu, inum=CAE3,ou=attributes,o=gluu], defaultScope=false, oxAuthGroupClaims=null, dynamicScopeScripts=null, umaAuthorizationPolicies=null, deletable=null, expirationDate=null, attributes=ScopeAttributes{spontaneousClientId=''spontaneousClientScopes='[]'showInConfigurationEndpoint='true'}}' 2021-06-21 16:16:36,238 TRACE [qtp222511810-19] [org.gluu.service.BaseCacheService] (BaseCacheService.java:37) - Request data, key 'inum=F0C4,ou=scopes,o=gluu' 2021-06-21 16:16:36,238 TRACE [qtp222511810-19] [org.gluu.service.BaseCacheService] (BaseCacheService.java:39) - Loaded data, key 'inum=F0C4,ou=scopes,o=gluu': 'Scope{dn='inum=F0C4,ou=scopes,o=gluu', inum='F0C4', displayName='null', id='openid', iconUrl='null', description='Authenticate using OpenID Connect.', scopeType=openid, oxAuthClaims=null, defaultScope=true, oxAuthGroupClaims=null, dynamicScopeScripts=null, umaAuthorizationPolicies=null, deletable=null, expirationDate=null, attributes=ScopeAttributes{spontaneousClientId=''spontaneousClientScopes='[]'showInConfigurationEndpoint='true'}}' 2021-06-21 16:16:36,238 TRACE [qtp222511810-19] [org.gluu.service.BaseCacheService] (BaseCacheService.java:58) - Loaded from cache, key: 'inum=F0C4,ou=scopes,o=gluu' 2021-06-21 16:16:36,238 TRACE [qtp222511810-19] [org.gluu.service.BaseCacheService] (BaseCacheService.java:84) - Put data, key 'openid': 'Scope{dn='inum=F0C4,ou=scopes,o=gluu', inum='F0C4', displayName='null', id='openid', iconUrl='null', description='Authenticate using OpenID Connect.', scopeType=openid, oxAuthClaims=null, defaultScope=true, oxAuthGroupClaims=null, dynamicScopeScripts=null, umaAuthorizationPolicies=null, deletable=null, expirationDate=null, attributes=ScopeAttributes{spontaneousClientId=''spontaneousClientScopes='[]'showInConfigurationEndpoint='true'}}' 2021-06-21 16:16:36,239 TRACE [qtp222511810-19] [org.gluu.service.BaseCacheService] (BaseCacheService.java:37) - Request data, key 'inum=10B2,ou=scopes,o=gluu' 2021-06-21 16:16:36,239 TRACE [qtp222511810-19] [org.gluu.service.BaseCacheService] (BaseCacheService.java:39) - Loaded data, key 'inum=10B2,ou=scopes,o=gluu': 'Scope{dn='inum=10B2,ou=scopes,o=gluu', inum='10B2', displayName='null', id='user_name', iconUrl='null', description='View your local username in the Gluu Server.', scopeType=openid, oxAuthClaims=[inum=42E0,ou=attributes,o=gluu], defaultScope=false, oxAuthGroupClaims=null, dynamicScopeScripts=null, umaAuthorizationPolicies=null, deletable=null, expirationDate=null, attributes=ScopeAttributes{spontaneousClientId=''spontaneousClientScopes='[]'showInConfigurationEndpoint='true'}}' 2021-06-21 16:16:36,239 TRACE [qtp222511810-19] [org.gluu.service.BaseCacheService] (BaseCacheService.java:58) - Loaded from cache, key: 'inum=10B2,ou=scopes,o=gluu' 2021-06-21 16:16:36,239 TRACE [qtp222511810-19] [org.gluu.service.BaseCacheService] (BaseCacheService.java:84) - Put data, key 'user_name': 'Scope{dn='inum=10B2,ou=scopes,o=gluu', inum='10B2', displayName='null', id='user_name', iconUrl='null', description='View your local username in the Gluu Server.', scopeType=openid, oxAuthClaims=[inum=42E0,ou=attributes,o=gluu], defaultScope=false, oxAuthGroupClaims=null, dynamicScopeScripts=null, umaAuthorizationPolicies=null, deletable=null, expirationDate=null, attributes=ScopeAttributes{spontaneousClientId=''spontaneousClientScopes='[]'showInConfigurationEndpoint='true'}}' 2021-06-21 16:16:36,239 TRACE [qtp222511810-19] [org.gluu.service.BaseCacheService] (BaseCacheService.java:37) - Request data, key 'inum=764C,ou=scopes,o=gluu' 2021-06-21 16:16:36,240 TRACE [qtp222511810-19] [org.gluu.service.BaseCacheService] (BaseCacheService.java:39) - Loaded data, key 'inum=764C,ou=scopes,o=gluu': 'Scope{dn='inum=764C,ou=scopes,o=gluu', inum='764C', displayName='null', id='email', iconUrl='null', description='View your email address.', scopeType=openid, oxAuthClaims=[inum=8F88,ou=attributes,o=gluu, inum=CAE3,ou=attributes,o=gluu], defaultScope=false, oxAuthGroupClaims=null, dynamicScopeScripts=null, umaAuthorizationPolicies=null, deletable=null, expirationDate=null, attributes=ScopeAttributes{spontaneousClientId=''spontaneousClientScopes='[]'showInConfigurationEndpoint='true'}}' 2021-06-21 16:16:36,240 TRACE [qtp222511810-19] [org.gluu.service.BaseCacheService] (BaseCacheService.java:58) - Loaded from cache, key: 'inum=764C,ou=scopes,o=gluu' 2021-06-21 16:16:36,240 TRACE [qtp222511810-19] [org.gluu.service.BaseCacheService] (BaseCacheService.java:84) - Put data, key 'email': 'Scope{dn='inum=764C,ou=scopes,o=gluu', inum='764C', displayName='null', id='email', iconUrl='null', description='View your email address.', scopeType=openid, oxAuthClaims=[inum=8F88,ou=attributes,o=gluu, inum=CAE3,ou=attributes,o=gluu], defaultScope=false, oxAuthGroupClaims=null, dynamicScopeScripts=null, umaAuthorizationPolicies=null, deletable=null, expirationDate=null, attributes=ScopeAttributes{spontaneousClientId=''spontaneousClientScopes='[]'showInConfigurationEndpoint='true'}}' 2021-06-21 16:16:36,241 DEBUG [qtp222511810-19] [org.gluu.oxauth.model.authorize.ScopeChecker] (ScopeChecker.java:90) - Granted scopes: [openid, user_name, email] 2021-06-21 16:16:36,242 DEBUG [qtp222511810-19] [org.gluu.oxauth.service.RedirectionUriService] (RedirectionUriService.java:107) - Validating redirection URI: clientIdentifier = 1001.fcfdac3c-87a3-4422-8159-b0610e207cdb, redirectionUri = https://gluu-vm.pre.whispeak.io/identity/authcode.htm, found = 3 2021-06-21 16:16:36,242 DEBUG [qtp222511810-19] [org.gluu.oxauth.service.RedirectionUriService] (RedirectionUriService.java:129) - Comparing https://gluu-vm.pre.whispeak.io/identity/scim/auth == https://gluu-vm.pre.whispeak.io/identity/authcode.htm 2021-06-21 16:16:36,242 DEBUG [qtp222511810-19] [org.gluu.oxauth.service.RedirectionUriService] (RedirectionUriService.java:129) - Comparing https://gluu-vm.pre.whispeak.io/identity/authcode.htm == https://gluu-vm.pre.whispeak.io/identity/authcode.htm 2021-06-21 16:16:36,246 TRACE [qtp222511810-19] [gluu.oxauth.authorize.ws.rs.AuthorizeAction] (AuthorizeAction.java:297) - Redirect to person authentication login page: /auth/passport/passportlogin.xhtml 2021-06-21 16:16:36,246 TRACE [qtp222511810-19] [org.gluu.oxauth.service.SessionIdService] (SessionIdService.java:487) - Generated new session, id = '35fa7d6e-7c14-414f-9249-7fcb574f85e7', state = 'unauthenticated', asJwt = 'false', persisted = 'false' 2021-06-21 16:16:36,247 TRACE [qtp222511810-19] [org.gluu.oxauth.service.SessionIdService] (SessionIdService.java:584) - sessionIdAttributes: SessionIdAccessMap{permissionGranted={1001.fcfdac3c-87a3-4422-8159-b0610e207cdb=false}} 2021-06-21 16:16:36,264 TRACE [qtp222511810-19] [org.gluu.service.BaseCacheService] (BaseCacheService.java:84) - Put data, key 'oxId=35fa7d6e-7c14-414f-9249-7fcb574f85e7,ou=sessions,o=gluu': 'SessionId {dn='oxId=35fa7d6e-7c14-414f-9249-7fcb574f85e7,ou=sessions,o=gluu', id='35fa7d6e-7c14-414f-9249-7fcb574f85e7', outsideSid='e5db70b9-53b4-4604-900d-4e9db8d7d65c', lastUsedAt=Mon Jun 21 16:16:36 UTC 2021, userDn='', authenticationTime=Mon Jun 21 16:16:36 UTC 2021, state=unauthenticated, expirationDate=Mon Jun 21 16:18:36 UTC 2021, sessionState='06e6e86cd932d76fb2c10885c7a23bbc97c1c2c6a730e4a84e35444aa93eb63a.5d1fc7db-2efd-47a9-b834-7703848b2c5b', permissionGranted=null, isJwt=false, jwt=null, permissionGrantedMap=SessionIdAccessMap{permissionGranted={1001.fcfdac3c-87a3-4422-8159-b0610e207cdb=false}}, sessionAttributes={auth_step=1, acr=passport_social, remote_ip=213.98.185.28, opbs=f5ad06e6-8057-4ec9-9008-1c0606132a79, scope=openid profile email user_name, acr_values=passport_social, response_type=code, redirect_uri=https://gluu-vm.pre.whispeak.io/identity/authcode.htm, state=c744712f-d534-4ccb-bfb5-a3cfee73e6fc, nonce=68583bd6-3843-4600-9828-d35fd48d2bfb, client_id=1001.fcfdac3c-87a3-4422-8159-b0610e207cdb}, persisted=true}' 2021-06-21 16:16:36,265 TRACE [qtp222511810-19] [gluu.oxauth.authorize.ws.rs.AuthorizeAction] (AuthorizeAction.java:332) - Session '35fa7d6e-7c14-414f-9249-7fcb574f85e7' persisted to LDAP 2021-06-21 16:16:36,281 TRACE [qtp222511810-19] [org.gluu.oxauth.service.AuthenticationService] (AuthenticationService.java:769) - Attempting to store extraParameters: [selectedProvider, externalProviders] 2021-06-21 16:16:36,281 TRACE [qtp222511810-19] [org.gluu.oxauth.service.AuthenticationService] (AuthenticationService.java:788) - Storing sessionIdAttributes: {auth_external_attributes=[{"externalProviders":"java.lang.String"}], opbs=f5ad06e6-8057-4ec9-9008-1c0606132a79, externalProviders={"Microsoft365": {"requestForEmail": false, "displayName": "Login with Microsoft", "emailLinkingSafe": false, "type": "openidconnect", "logo_img": null, "saml": false}}, response_type=code, nonce=68583bd6-3843-4600-9828-d35fd48d2bfb, client_id=1001.fcfdac3c-87a3-4422-8159-b0610e207cdb, auth_step=1, acr=passport_social, remote_ip=213.98.185.28, scope=openid profile email user_name, acr_values=passport_social, redirect_uri=https://gluu-vm.pre.whispeak.io/identity/authcode.htm, state=c744712f-d534-4ccb-bfb5-a3cfee73e6fc} 2021-06-21 16:16:36,281 TRACE [qtp222511810-19] [org.gluu.oxauth.service.AuthenticationService] (AuthenticationService.java:789) - Storing authExternalAttributes: {externalProviders=java.lang.String} 2021-06-21 16:16:36,294 TRACE [qtp222511810-19] [org.gluu.service.BaseCacheService] (BaseCacheService.java:84) - Put data, key 'oxId=35fa7d6e-7c14-414f-9249-7fcb574f85e7,ou=sessions,o=gluu': 'SessionId {dn='oxId=35fa7d6e-7c14-414f-9249-7fcb574f85e7,ou=sessions,o=gluu', id='35fa7d6e-7c14-414f-9249-7fcb574f85e7', outsideSid='e5db70b9-53b4-4604-900d-4e9db8d7d65c', lastUsedAt=Mon Jun 21 16:16:36 UTC 2021, userDn='', authenticationTime=Mon Jun 21 16:16:36 UTC 2021, state=unauthenticated, expirationDate=Mon Jun 21 16:18:36 UTC 2021, sessionState='06e6e86cd932d76fb2c10885c7a23bbc97c1c2c6a730e4a84e35444aa93eb63a.5d1fc7db-2efd-47a9-b834-7703848b2c5b', permissionGranted=null, isJwt=false, jwt=null, permissionGrantedMap=SessionIdAccessMap{permissionGranted={1001.fcfdac3c-87a3-4422-8159-b0610e207cdb=false}}, sessionAttributes={auth_external_attributes=[{"externalProviders":"java.lang.String"}], opbs=f5ad06e6-8057-4ec9-9008-1c0606132a79, externalProviders={"Microsoft365": {"requestForEmail": false, "displayName": "Login with Microsoft", "emailLinkingSafe": false, "type": "openidconnect", "logo_img": null, "saml": false}}, response_type=code, nonce=68583bd6-3843-4600-9828-d35fd48d2bfb, client_id=1001.fcfdac3c-87a3-4422-8159-b0610e207cdb, auth_step=1, acr=passport_social, remote_ip=213.98.185.28, scope=openid profile email user_name, acr_values=passport_social, redirect_uri=https://gluu-vm.pre.whispeak.io/identity/authcode.htm, state=c744712f-d534-4ccb-bfb5-a3cfee73e6fc}, persisted=true}' 2021-06-21 16:16:36,986 TRACE [qtp222511810-16] [org.gluu.service.BaseCacheService] (BaseCacheService.java:37) - Request data, key 'organization' 2021-06-21 16:16:36,987 TRACE [qtp222511810-16] [org.gluu.service.BaseCacheService] (BaseCacheService.java:39) - Loaded data, key 'organization': 'null' 2021-06-21 16:16:36,987 TRACE [qtp222511810-16] [org.gluu.service.BaseCacheService] (BaseCacheService.java:61) - Key not in cache. Searching value via load function, key: 'organization' 2021-06-21 16:16:37,001 TRACE [qtp222511810-16] [org.gluu.service.BaseCacheService] (BaseCacheService.java:84) - Put data, key 'organization': 'Entry [dn=o=gluu]' 2021-06-21 16:16:37,381 TRACE [qtp222511810-16] [org.gluu.service.BaseCacheService] (BaseCacheService.java:37) - Request data, key 'organization' 2021-06-21 16:16:37,381 TRACE [qtp222511810-16] [org.gluu.service.BaseCacheService] (BaseCacheService.java:39) - Loaded data, key 'organization': 'Entry [dn=o=gluu]' 2021-06-21 16:16:37,382 TRACE [qtp222511810-16] [org.gluu.service.BaseCacheService] (BaseCacheService.java:58) - Loaded from cache, key: 'organization' 2021-06-21 16:16:39,044 TRACE [qtp222511810-16] [org.gluu.oxauth.service.CookieService] (CookieService.java:156) - Found cookie: '35fa7d6e-7c14-414f-9249-7fcb574f85e7' 2021-06-21 16:16:39,045 TRACE [qtp222511810-16] [org.gluu.oxauth.service.SessionIdService] (SessionIdService.java:806) - SessionId from cookie: 35fa7d6e-7c14-414f-9249-7fcb574f85e7 2021-06-21 16:16:39,045 TRACE [qtp222511810-16] [org.gluu.service.BaseCacheService] (BaseCacheService.java:37) - Request data, key 'oxId=35fa7d6e-7c14-414f-9249-7fcb574f85e7,ou=sessions,o=gluu' 2021-06-21 16:16:39,045 TRACE [qtp222511810-16] [org.gluu.service.BaseCacheService] (BaseCacheService.java:39) - Loaded data, key 'oxId=35fa7d6e-7c14-414f-9249-7fcb574f85e7,ou=sessions,o=gluu': 'null' 2021-06-21 16:16:39,052 TRACE [qtp222511810-16] [org.gluu.service.BaseCacheService] (BaseCacheService.java:84) - Put data, key 'oxId=35fa7d6e-7c14-414f-9249-7fcb574f85e7,ou=sessions,o=gluu': 'SessionId {dn='oxId=35fa7d6e-7c14-414f-9249-7fcb574f85e7,ou=sessions,o=gluu', id='35fa7d6e-7c14-414f-9249-7fcb574f85e7', outsideSid='e5db70b9-53b4-4604-900d-4e9db8d7d65c', lastUsedAt=Mon Jun 21 16:16:36 UTC 2021, userDn='null', authenticationTime=Mon Jun 21 16:16:36 UTC 2021, state=unauthenticated, expirationDate=Mon Jun 21 16:18:36 UTC 2021, sessionState='06e6e86cd932d76fb2c10885c7a23bbc97c1c2c6a730e4a84e35444aa93eb63a.5d1fc7db-2efd-47a9-b834-7703848b2c5b', permissionGranted=null, isJwt=false, jwt=null, permissionGrantedMap=SessionIdAccessMap{permissionGranted={1001.fcfdac3c-87a3-4422-8159-b0610e207cdb=false}}, sessionAttributes={auth_external_attributes=[{"externalProviders":"java.lang.String"}], opbs=f5ad06e6-8057-4ec9-9008-1c0606132a79, externalProviders={"Microsoft365": {"requestForEmail": false, "displayName": "Login with Microsoft", "emailLinkingSafe": false, "type": "openidconnect", "logo_img": null, "saml": false}}, response_type=code, nonce=68583bd6-3843-4600-9828-d35fd48d2bfb, client_id=1001.fcfdac3c-87a3-4422-8159-b0610e207cdb, auth_step=1, acr=passport_social, remote_ip=213.98.185.28, scope=openid profile email user_name, acr_values=passport_social, redirect_uri=https://gluu-vm.pre.whispeak.io/identity/authcode.htm, state=c744712f-d534-4ccb-bfb5-a3cfee73e6fc}, persisted=false}' 2021-06-21 16:16:39,053 TRACE [qtp222511810-16] [org.gluu.oxauth.service.SessionIdService] (SessionIdService.java:821) - Try to get session by id: 35fa7d6e-7c14-414f-9249-7fcb574f85e7 ... 2021-06-21 16:16:39,053 TRACE [qtp222511810-16] [org.gluu.oxauth.service.SessionIdService] (SessionIdService.java:823) - Session dn: oxId=35fa7d6e-7c14-414f-9249-7fcb574f85e7,ou=sessions,o=gluu 2021-06-21 16:16:39,053 TRACE [qtp222511810-16] [org.gluu.oxauth.auth.Authenticator] (Authenticator.java:189) - Authenticating ... (interactive: true, skipPassword: false, credentials.username: ) 2021-06-21 16:16:39,056 DEBUG [qtp222511810-16] [org.gluu.oxauth.auth.Authenticator] (Authenticator.java:332) - Authentication result for user ''. auth_step: '1', result: 'true', credentials: '1058090780' 2021-06-21 16:16:39,056 TRACE [qtp222511810-16] [org.gluu.oxauth.auth.Authenticator] (Authenticator.java:339) - ######################################################################### 2021-06-21 16:16:39,056 TRACE [qtp222511810-16] [org.gluu.oxauth.auth.Authenticator] (Authenticator.java:340) - ++++++++++++++++++++++++++++++++++++++++++CURRENT ACR:passport_social 2021-06-21 16:16:39,056 TRACE [qtp222511810-16] [org.gluu.oxauth.auth.Authenticator] (Authenticator.java:341) - ++++++++++++++++++++++++++++++++++++++++++CURRENT STEP:1 2021-06-21 16:16:39,057 TRACE [qtp222511810-16] [org.gluu.oxauth.auth.Authenticator] (Authenticator.java:344) - According to API version script supports steps overriding 2021-06-21 16:16:39,057 DEBUG [qtp222511810-16] [org.gluu.oxauth.auth.Authenticator] (Authenticator.java:347) - Get next step from script: '1' 2021-06-21 16:16:39,070 TRACE [qtp222511810-16] [org.gluu.service.BaseCacheService] (BaseCacheService.java:84) - Put data, key 'oxId=35fa7d6e-7c14-414f-9249-7fcb574f85e7,ou=sessions,o=gluu': 'SessionId {dn='oxId=35fa7d6e-7c14-414f-9249-7fcb574f85e7,ou=sessions,o=gluu', id='35fa7d6e-7c14-414f-9249-7fcb574f85e7', outsideSid='e5db70b9-53b4-4604-900d-4e9db8d7d65c', lastUsedAt=Mon Jun 21 16:16:39 UTC 2021, userDn='null', authenticationTime=Mon Jun 21 16:16:36 UTC 2021, state=unauthenticated, expirationDate=Mon Jun 21 16:18:36 UTC 2021, sessionState='06e6e86cd932d76fb2c10885c7a23bbc97c1c2c6a730e4a84e35444aa93eb63a.5d1fc7db-2efd-47a9-b834-7703848b2c5b', permissionGranted=null, isJwt=false, jwt=null, permissionGrantedMap=SessionIdAccessMap{permissionGranted={1001.fcfdac3c-87a3-4422-8159-b0610e207cdb=false}}, sessionAttributes={auth_external_attributes=[{"externalProviders":"java.lang.String"}], opbs=f5ad06e6-8057-4ec9-9008-1c0606132a79, externalProviders={"Microsoft365": {"requestForEmail": false, "displayName": "Login with Microsoft", "emailLinkingSafe": false, "type": "openidconnect", "logo_img": null, "saml": false}}, response_type=code, nonce=68583bd6-3843-4600-9828-d35fd48d2bfb, client_id=1001.fcfdac3c-87a3-4422-8159-b0610e207cdb, auth_step=1, acr=passport_social, remote_ip=213.98.185.28, scope=openid profile email user_name, acr_values=passport_social, redirect_uri=https://gluu-vm.pre.whispeak.io/identity/authcode.htm, state=c744712f-d534-4ccb-bfb5-a3cfee73e6fc}, persisted=true}' 2021-06-21 16:16:39,070 INFO [qtp222511810-16] [org.gluu.oxauth.auth.Authenticator] (Authenticator.java:372) - Authentication reset to step : '1' 2021-06-21 16:16:39,071 TRACE [qtp222511810-16] [org.gluu.oxauth.service.AuthenticationService] (AuthenticationService.java:769) - Attempting to store extraParameters: [passport_user_profile] 2021-06-21 16:16:39,072 TRACE [qtp222511810-16] [org.gluu.oxauth.service.AuthenticationService] (AuthenticationService.java:788) - Storing sessionIdAttributes: {auth_external_attributes=[{"externalProviders":"java.lang.String"}], opbs=f5ad06e6-8057-4ec9-9008-1c0606132a79, externalProviders={"Microsoft365": {"requestForEmail": false, "displayName": "Login with Microsoft", "emailLinkingSafe": false, "type": "openidconnect", "logo_img": null, "saml": false}}, response_type=code, nonce=68583bd6-3843-4600-9828-d35fd48d2bfb, client_id=1001.fcfdac3c-87a3-4422-8159-b0610e207cdb, auth_step=1, acr=passport_social, remote_ip=213.98.185.28, scope=openid profile email user_name, acr_values=passport_social, redirect_uri=https://gluu-vm.pre.whispeak.io/identity/authcode.htm, state=c744712f-d534-4ccb-bfb5-a3cfee73e6fc} 2021-06-21 16:16:39,072 TRACE [qtp222511810-16] [org.gluu.oxauth.service.AuthenticationService] (AuthenticationService.java:789) - Storing authExternalAttributes: {externalProviders=java.lang.String} 2021-06-21 16:16:39,075 TRACE [qtp222511810-16] [org.gluu.oxauth.service.AuthenticationService] (AuthenticationService.java:769) - Attempting to store extraParameters: [selectedProvider, externalProviders] 2021-06-21 16:16:39,075 TRACE [qtp222511810-16] [org.gluu.oxauth.service.AuthenticationService] (AuthenticationService.java:788) - Storing sessionIdAttributes: {auth_external_attributes=[{"externalProviders":"java.lang.String"},{"selectedProvider":"java.lang.String"}], opbs=f5ad06e6-8057-4ec9-9008-1c0606132a79, externalProviders={"Microsoft365": {"requestForEmail": false, "displayName": "Login with Microsoft", "emailLinkingSafe": false, "type": "openidconnect", "logo_img": null, "saml": false}}, response_type=code, nonce=68583bd6-3843-4600-9828-d35fd48d2bfb, client_id=1001.fcfdac3c-87a3-4422-8159-b0610e207cdb, auth_step=1, acr=passport_social, remote_ip=213.98.185.28, scope=openid profile email user_name, acr_values=passport_social, redirect_uri=https://gluu-vm.pre.whispeak.io/identity/authcode.htm, state=c744712f-d534-4ccb-bfb5-a3cfee73e6fc, selectedProvider=Microsoft365} 2021-06-21 16:16:39,076 TRACE [qtp222511810-16] [org.gluu.oxauth.service.AuthenticationService] (AuthenticationService.java:789) - Storing authExternalAttributes: {externalProviders=java.lang.String, selectedProvider=java.lang.String} 2021-06-21 16:16:39,085 TRACE [qtp222511810-16] [org.gluu.service.BaseCacheService] (BaseCacheService.java:84) - Put data, key 'oxId=35fa7d6e-7c14-414f-9249-7fcb574f85e7,ou=sessions,o=gluu': 'SessionId {dn='oxId=35fa7d6e-7c14-414f-9249-7fcb574f85e7,ou=sessions,o=gluu', id='35fa7d6e-7c14-414f-9249-7fcb574f85e7', outsideSid='e5db70b9-53b4-4604-900d-4e9db8d7d65c', lastUsedAt=Mon Jun 21 16:16:39 UTC 2021, userDn='null', authenticationTime=Mon Jun 21 16:16:36 UTC 2021, state=unauthenticated, expirationDate=Mon Jun 21 16:18:36 UTC 2021, sessionState='06e6e86cd932d76fb2c10885c7a23bbc97c1c2c6a730e4a84e35444aa93eb63a.5d1fc7db-2efd-47a9-b834-7703848b2c5b', permissionGranted=null, isJwt=false, jwt=null, permissionGrantedMap=SessionIdAccessMap{permissionGranted={1001.fcfdac3c-87a3-4422-8159-b0610e207cdb=false}}, sessionAttributes={auth_external_attributes=[{"externalProviders":"java.lang.String"},{"selectedProvider":"java.lang.String"}], opbs=f5ad06e6-8057-4ec9-9008-1c0606132a79, externalProviders={"Microsoft365": {"requestForEmail": false, "displayName": "Login with Microsoft", "emailLinkingSafe": false, "type": "openidconnect", "logo_img": null, "saml": false}}, response_type=code, nonce=68583bd6-3843-4600-9828-d35fd48d2bfb, client_id=1001.fcfdac3c-87a3-4422-8159-b0610e207cdb, auth_step=1, acr=passport_social, remote_ip=213.98.185.28, scope=openid profile email user_name, acr_values=passport_social, redirect_uri=https://gluu-vm.pre.whispeak.io/identity/authcode.htm, state=c744712f-d534-4ccb-bfb5-a3cfee73e6fc, selectedProvider=Microsoft365}, persisted=true}' 2021-06-21 16:16:39,086 TRACE [qtp222511810-16] [org.gluu.oxauth.auth.Authenticator] (Authenticator.java:425) - Redirect to page: '/auth/passport/passportlogin.xhtml' 2021-06-21 16:16:39,087 TRACE [qtp222511810-16] [org.gluu.oxauth.auth.Authenticator] (Authenticator.java:222) - Authentication successfully for '' 2021-06-21 16:16:39,139 TRACE [qtp222511810-4501] [org.gluu.oxauth.service.CookieService] (CookieService.java:156) - Found cookie: '35fa7d6e-7c14-414f-9249-7fcb574f85e7' 2021-06-21 16:16:39,139 TRACE [qtp222511810-4501] [org.gluu.service.BaseCacheService] (BaseCacheService.java:37) - Request data, key 'oxId=35fa7d6e-7c14-414f-9249-7fcb574f85e7,ou=sessions,o=gluu' 2021-06-21 16:16:39,140 TRACE [qtp222511810-4501] [org.gluu.service.BaseCacheService] (BaseCacheService.java:39) - Loaded data, key 'oxId=35fa7d6e-7c14-414f-9249-7fcb574f85e7,ou=sessions,o=gluu': 'SessionId {dn='oxId=35fa7d6e-7c14-414f-9249-7fcb574f85e7,ou=sessions,o=gluu', id='35fa7d6e-7c14-414f-9249-7fcb574f85e7', outsideSid='e5db70b9-53b4-4604-900d-4e9db8d7d65c', lastUsedAt=Mon Jun 21 16:16:39 UTC 2021, userDn='null', authenticationTime=Mon Jun 21 16:16:36 UTC 2021, state=unauthenticated, expirationDate=Mon Jun 21 16:18:36 UTC 2021, sessionState='06e6e86cd932d76fb2c10885c7a23bbc97c1c2c6a730e4a84e35444aa93eb63a.5d1fc7db-2efd-47a9-b834-7703848b2c5b', permissionGranted=null, isJwt=false, jwt=null, permissionGrantedMap=SessionIdAccessMap{permissionGranted={1001.fcfdac3c-87a3-4422-8159-b0610e207cdb=false}}, sessionAttributes={auth_external_attributes=[{"externalProviders":"java.lang.String"},{"selectedProvider":"java.lang.String"}], opbs=f5ad06e6-8057-4ec9-9008-1c0606132a79, externalProviders={"Microsoft365": {"requestForEmail": false, "displayName": "Login with Microsoft", "emailLinkingSafe": false, "type": "openidconnect", "logo_img": null, "saml": false}}, response_type=code, nonce=68583bd6-3843-4600-9828-d35fd48d2bfb, client_id=1001.fcfdac3c-87a3-4422-8159-b0610e207cdb, auth_step=1, acr=passport_social, remote_ip=213.98.185.28, scope=openid profile email user_name, acr_values=passport_social, redirect_uri=https://gluu-vm.pre.whispeak.io/identity/authcode.htm, state=c744712f-d534-4ccb-bfb5-a3cfee73e6fc, selectedProvider=Microsoft365}, persisted=true}' 2021-06-21 16:16:39,140 TRACE [qtp222511810-4501] [org.gluu.oxauth.service.SessionIdService] (SessionIdService.java:821) - Try to get session by id: 35fa7d6e-7c14-414f-9249-7fcb574f85e7 ... 2021-06-21 16:16:39,141 TRACE [qtp222511810-4501] [org.gluu.oxauth.service.SessionIdService] (SessionIdService.java:823) - Session dn: oxId=35fa7d6e-7c14-414f-9249-7fcb574f85e7,ou=sessions,o=gluu 2021-06-21 16:16:39,171 DEBUG [qtp222511810-4501] [org.apache.http.impl.client.DefaultRequestDirector] (DefaultRequestDirector.java:682) - Attempt 1 to execute request 2021-06-21 16:16:39,183 DEBUG [qtp222511810-4501] [org.apache.http.impl.client.DefaultRequestDirector] (DefaultRequestDirector.java:509) - Connection can be kept alive for 5000 MILLISECONDS 2021-06-21 16:16:39,190 TRACE [qtp222511810-4501] [org.gluu.oxauth.service.AuthenticationService] (AuthenticationService.java:769) - Attempting to store extraParameters: [selectedProvider, externalProviders] 2021-06-21 16:16:39,190 TRACE [qtp222511810-4501] [org.gluu.oxauth.service.AuthenticationService] (AuthenticationService.java:788) - Storing sessionIdAttributes: {auth_external_attributes=[{"externalProviders":"java.lang.String"},{}], opbs=f5ad06e6-8057-4ec9-9008-1c0606132a79, externalProviders={"Microsoft365": {"requestForEmail": false, "displayName": "Login with Microsoft", "emailLinkingSafe": false, "type": "openidconnect", "logo_img": null, "saml": false}}, response_type=code, nonce=68583bd6-3843-4600-9828-d35fd48d2bfb, client_id=1001.fcfdac3c-87a3-4422-8159-b0610e207cdb, auth_step=1, acr=passport_social, remote_ip=213.98.185.28, scope=openid profile email user_name, acr_values=passport_social, redirect_uri=https://gluu-vm.pre.whispeak.io/identity/authcode.htm, state=c744712f-d534-4ccb-bfb5-a3cfee73e6fc, selectedProvider=null} 2021-06-21 16:16:39,190 TRACE [qtp222511810-4501] [org.gluu.oxauth.service.AuthenticationService] (AuthenticationService.java:789) - Storing authExternalAttributes: {externalProviders=java.lang.String, selectedProvider=null} 2021-06-21 16:16:39,199 TRACE [qtp222511810-4501] [org.gluu.service.BaseCacheService] (BaseCacheService.java:84) - Put data, key 'oxId=35fa7d6e-7c14-414f-9249-7fcb574f85e7,ou=sessions,o=gluu': 'SessionId {dn='oxId=35fa7d6e-7c14-414f-9249-7fcb574f85e7,ou=sessions,o=gluu', id='35fa7d6e-7c14-414f-9249-7fcb574f85e7', outsideSid='e5db70b9-53b4-4604-900d-4e9db8d7d65c', lastUsedAt=Mon Jun 21 16:16:39 UTC 2021, userDn='null', authenticationTime=Mon Jun 21 16:16:36 UTC 2021, state=unauthenticated, expirationDate=Mon Jun 21 16:18:36 UTC 2021, sessionState='06e6e86cd932d76fb2c10885c7a23bbc97c1c2c6a730e4a84e35444aa93eb63a.5d1fc7db-2efd-47a9-b834-7703848b2c5b', permissionGranted=null, isJwt=false, jwt=null, permissionGrantedMap=SessionIdAccessMap{permissionGranted={1001.fcfdac3c-87a3-4422-8159-b0610e207cdb=false}}, sessionAttributes={auth_external_attributes=[{"externalProviders":"java.lang.String"},{}], opbs=f5ad06e6-8057-4ec9-9008-1c0606132a79, externalProviders={"Microsoft365": {"requestForEmail": false, "displayName": "Login with Microsoft", "emailLinkingSafe": false, "type": "openidconnect", "logo_img": null, "saml": false}}, response_type=code, nonce=68583bd6-3843-4600-9828-d35fd48d2bfb, client_id=1001.fcfdac3c-87a3-4422-8159-b0610e207cdb, auth_step=1, acr=passport_social, remote_ip=213.98.185.28, scope=openid profile email user_name, acr_values=passport_social, redirect_uri=https://gluu-vm.pre.whispeak.io/identity/authcode.htm, state=c744712f-d534-4ccb-bfb5-a3cfee73e6fc, selectedProvider=null}, persisted=true}' 2021-06-21 16:16:42,504 DEBUG [oxAuthScheduler_Worker-3] [org.gluu.service.timer.RequestJobListener] (RequestJobListener.java:53) - Bound request started 2021-06-21 16:16:42,505 TRACE [oxAuthScheduler_Worker-3] [org.gluu.service.timer.TimerJob] (TimerJob.java:35) - Fire timer event [org.gluu.service.cdi.event.LoggerUpdateEvent] with qualifiers [@org.gluu.service.cdi.event.Scheduled()] from instance 1777378540 2021-06-21 16:16:42,505 DEBUG [oxAuthScheduler_Worker-3] [org.gluu.service.timer.RequestJobListener] (RequestJobListener.java:63) - Bound request ended 2021-06-21 16:16:42,548 INFO [ForkJoinPool.commonPool-worker-7] [org.gluu.service.logger.LoggerService] (LoggerService.java:205) - Updated log level of '141' loggers to TRACE 2021-06-21 16:16:48,361 DEBUG [oxAuthScheduler_Worker-2] [org.gluu.service.timer.RequestJobListener] (RequestJobListener.java:53) - Bound request started 2021-06-21 16:16:48,362 TRACE [oxAuthScheduler_Worker-2] [org.gluu.service.timer.TimerJob] (TimerJob.java:35) - Fire timer event [org.gluu.service.cdi.event.UpdateScriptEvent] with qualifiers [@org.gluu.service.cdi.event.Scheduled()] from instance 689387407 2021-06-21 16:16:48,397 DEBUG [oxAuthScheduler_Worker-2] [org.gluu.service.timer.RequestJobListener] (RequestJobListener.java:63) - Bound request ended 2021-06-21 16:16:49,960 TRACE [qtp222511810-4501] [org.gluu.oxauth.auth.AuthenticationFilter] (AuthenticationFilter.java:122) - Get request to: 'https://gluu-vm.pre.whispeak.io/oxauth/restv1/token' 2021-06-21 16:16:49,960 TRACE [qtp222511810-4501] [org.gluu.service.BaseCacheService] (BaseCacheService.java:37) - Request data, key 'inum=1501.c7b9c0ba-1e13-4a68-9d4c-f6e484f42df9,ou=clients,o=gluu' 2021-06-21 16:16:49,960 TRACE [qtp222511810-4501] [org.gluu.service.BaseCacheService] (BaseCacheService.java:39) - Loaded data, key 'inum=1501.c7b9c0ba-1e13-4a68-9d4c-f6e484f42df9,ou=clients,o=gluu': 'null' 2021-06-21 16:16:49,960 TRACE [qtp222511810-4501] [org.gluu.service.BaseCacheService] (BaseCacheService.java:61) - Key not in cache. Searching value via load function, key: 'inum=1501.c7b9c0ba-1e13-4a68-9d4c-f6e484f42df9,ou=clients,o=gluu' 2021-06-21 16:16:49,965 TRACE [qtp222511810-4501] [org.gluu.service.BaseCacheService] (BaseCacheService.java:84) - Put data, key 'inum=1501.c7b9c0ba-1e13-4a68-9d4c-f6e484f42df9,ou=clients,o=gluu': 'DeletableEntity{expirationDate=null, deletable=null} BaseEntry [dn=null]' 2021-06-21 16:16:49,965 DEBUG [qtp222511810-4501] [org.gluu.oxauth.service.ClientService] (ClientService.java:135) - Found 1 entries for client id = 1501.c7b9c0ba-1e13-4a68-9d4c-f6e484f42df9 2021-06-21 16:16:49,965 DEBUG [qtp222511810-4501] [org.gluu.oxauth.auth.AuthenticationFilter] (AuthenticationFilter.java:144) - Starting endpoint authentication https://gluu-vm.pre.whispeak.io/oxauth/restv1/token 2021-06-21 16:16:49,965 DEBUG [qtp222511810-4501] [org.gluu.oxauth.auth.AuthenticationFilter] (AuthenticationFilter.java:156) - Starting JWT token endpoint authentication 2021-06-21 16:16:49,966 TRACE [qtp222511810-4501] [org.gluu.service.BaseCacheService] (BaseCacheService.java:37) - Request data, key 'inum=1501.c7b9c0ba-1e13-4a68-9d4c-f6e484f42df9,ou=clients,o=gluu' 2021-06-21 16:16:49,966 TRACE [qtp222511810-4501] [org.gluu.service.BaseCacheService] (BaseCacheService.java:39) - Loaded data, key 'inum=1501.c7b9c0ba-1e13-4a68-9d4c-f6e484f42df9,ou=clients,o=gluu': 'DeletableEntity{expirationDate=null, deletable=null} BaseEntry [dn=null]' 2021-06-21 16:16:49,966 TRACE [qtp222511810-4501] [org.gluu.service.BaseCacheService] (BaseCacheService.java:58) - Loaded from cache, key: 'inum=1501.c7b9c0ba-1e13-4a68-9d4c-f6e484f42df9,ou=clients,o=gluu' 2021-06-21 16:16:49,966 DEBUG [qtp222511810-4501] [org.gluu.oxauth.service.ClientService] (ClientService.java:135) - Found 1 entries for client id = 1501.c7b9c0ba-1e13-4a68-9d4c-f6e484f42df9 2021-06-21 16:16:49,967 TRACE [qtp222511810-4501] [org.gluu.oxauth.auth.Authenticator] (Authenticator.java:189) - Authenticating ... (interactive: false, skipPassword: true, credentials.username: 1501.c7b9c0ba-1e13-4a68-9d4c-f6e484f42df9) 2021-06-21 16:16:49,967 DEBUG [qtp222511810-4501] [org.gluu.oxauth.service.AuthenticationService] (AuthenticationService.java:685) - ConfigureSessionClient: username: '1501.c7b9c0ba-1e13-4a68-9d4c-f6e484f42df9', credentials: '1058090780' 2021-06-21 16:16:49,967 TRACE [qtp222511810-4501] [org.gluu.service.BaseCacheService] (BaseCacheService.java:37) - Request data, key 'inum=1501.c7b9c0ba-1e13-4a68-9d4c-f6e484f42df9,ou=clients,o=gluu' 2021-06-21 16:16:49,968 TRACE [qtp222511810-4501] [org.gluu.service.BaseCacheService] (BaseCacheService.java:39) - Loaded data, key 'inum=1501.c7b9c0ba-1e13-4a68-9d4c-f6e484f42df9,ou=clients,o=gluu': 'DeletableEntity{expirationDate=null, deletable=null} BaseEntry [dn=null]' 2021-06-21 16:16:49,968 TRACE [qtp222511810-4501] [org.gluu.service.BaseCacheService] (BaseCacheService.java:58) - Loaded from cache, key: 'inum=1501.c7b9c0ba-1e13-4a68-9d4c-f6e484f42df9,ou=clients,o=gluu' 2021-06-21 16:16:49,968 DEBUG [qtp222511810-4501] [org.gluu.oxauth.service.ClientService] (ClientService.java:135) - Found 1 entries for client id = 1501.c7b9c0ba-1e13-4a68-9d4c-f6e484f42df9 2021-06-21 16:16:49,968 INFO [qtp222511810-4501] [org.gluu.oxauth.auth.Authenticator] (Authenticator.java:279) - Authentication success for Client: '1501.c7b9c0ba-1e13-4a68-9d4c-f6e484f42df9' 2021-06-21 16:16:49,968 TRACE [qtp222511810-4501] [org.gluu.oxauth.auth.Authenticator] (Authenticator.java:222) - Authentication successfully for '1501.c7b9c0ba-1e13-4a68-9d4c-f6e484f42df9' 2021-06-21 16:16:49,968 TRACE [qtp222511810-4501] [org.gluu.service.BaseCacheService] (BaseCacheService.java:37) - Request data, key 'inum=1501.c7b9c0ba-1e13-4a68-9d4c-f6e484f42df9,ou=clients,o=gluu' 2021-06-21 16:16:49,968 TRACE [qtp222511810-4501] [org.gluu.service.BaseCacheService] (BaseCacheService.java:39) - Loaded data, key 'inum=1501.c7b9c0ba-1e13-4a68-9d4c-f6e484f42df9,ou=clients,o=gluu': 'DeletableEntity{expirationDate=null, deletable=null} BaseEntry [dn=null]' 2021-06-21 16:16:49,968 TRACE [qtp222511810-4501] [org.gluu.service.BaseCacheService] (BaseCacheService.java:58) - Loaded from cache, key: 'inum=1501.c7b9c0ba-1e13-4a68-9d4c-f6e484f42df9,ou=clients,o=gluu' 2021-06-21 16:16:49,968 DEBUG [qtp222511810-4501] [org.gluu.oxauth.service.ClientService] (ClientService.java:135) - Found 1 entries for client id = 1501.c7b9c0ba-1e13-4a68-9d4c-f6e484f42df9 2021-06-21 16:16:49,970 DEBUG [qtp222511810-4501] [gluu.oxauth.token.ws.rs.TokenRestWebServiceImpl] (TokenRestWebServiceImpl.java:119) - Attempting to request access token: grantType = client_credentials, code = null, redirectUri = null, username = null, refreshToken = null, clientId = 1501.c7b9c0ba-1e13-4a68-9d4c-f6e484f42df9, ExtraParams = {client_assertion_type=[urn:ietf:params:oauth:client-assertion-type:jwt-bearer], client_assertion=[eyJraWQiOiJiZGY0NDIzZi1mNjM2LTQ4ZDYtYmE3Mi1kYTVhY2NlZDI3MGRfc2lnX3JzMjU2IiwidHlwIjoiSldUIiwiYWxnIjoiUlMyNTYifQ.eyJzdWIiOiIxNTAxLmM3YjljMGJhLTFlMTMtNGE2OC05ZDRjLWY2ZTQ4NGY0MmRmOSIsImF1ZCI6Imh0dHBzOi8vZ2x1dS12bS5wcmUud2hpc3BlYWsuaW8vb3hhdXRoL3Jlc3R2MS90b2tlbiIsImlzcyI6IjE1MDEuYzdiOWMwYmEtMWUxMy00YTY4LTlkNGMtZjZlNDg0ZjQyZGY5IiwiZXhwIjoxNjI0MjkyNTA5LCJpYXQiOjE2MjQyOTIyMDksImp0aSI6IjZjMGVjOWUxLWM0MzctNDlkNC1hZDY1LWFmNGUxNTFjZDQ0YyJ9.lHdiE0w-1F1c0aGYrdqXMuHS7PmO0aa-enhRWLWP9HGE2KGoOFLjMXEzy8ZqaFdAMFZynXmIQTjzY8TdOo6gZCu0PCv-tdan4YUFMQsxjbsYLSaaeYM7UGvC-rY9cAJUNmzCin50dMEtghSZzpXbkdyEPS6RE3Abu5JEe8IXpnmbILppGR0bOw9U90tkewZacApORz_jsB2P-u8jns_I-RYdLVUeaukmzjUjf2ovin3LlASASuB7TVmRdgulurO9dZrvaK2iPayD_EDoE4DKN8fqA17qkjThb7CfnyG7zv1zVUkI7GbJOPcTlaQU7AooUNaO6R9s2zVf1iabT23gkg], grant_type=[client_credentials], client_id=[1501.c7b9c0ba-1e13-4a68-9d4c-f6e484f42df9], scope=[uma_protection]}, isSecure = true, codeVerifier = null, ticket = null 2021-06-21 16:16:49,970 DEBUG [qtp222511810-4501] [gluu.oxauth.token.ws.rs.TokenRestWebServiceImpl] (TokenRestWebServiceImpl.java:141) - Starting to validate request parameters 2021-06-21 16:16:49,970 DEBUG [qtp222511810-4501] [gluu.oxauth.token.ws.rs.TokenRestWebServiceImpl] (TokenRestWebServiceImpl.java:149) - Grant type: 'client_credentials' 2021-06-21 16:16:49,971 DEBUG [qtp222511810-4501] [gluu.oxauth.token.ws.rs.TokenRestWebServiceImpl] (TokenRestWebServiceImpl.java:155) - Get sessionClient: 'org.gluu.oxauth.model.session.SessionClient@d50770a' 2021-06-21 16:16:49,971 DEBUG [qtp222511810-4501] [gluu.oxauth.token.ws.rs.TokenRestWebServiceImpl] (TokenRestWebServiceImpl.java:162) - Get client from session: '1501.c7b9c0ba-1e13-4a68-9d4c-f6e484f42df9' 2021-06-21 16:16:49,971 TRACE [qtp222511810-4501] [gluu.oxauth.model.crypto.binding.TokenBindingMessage] (TokenBindingMessage.java:57) - TokenBindingMessage present: false, rpCnfKey: null 2021-06-21 16:16:49,971 TRACE [qtp222511810-4501] [org.gluu.oxauth.service.SessionIdService] (SessionIdService.java:806) - SessionId from cookie: 2021-06-21 16:16:49,972 DEBUG [qtp222511810-4501] [org.gluu.oxauth.model.authorize.ScopeChecker] (ScopeChecker.java:58) - Checking scopes policy for: [uma_protection] 2021-06-21 16:16:49,972 TRACE [qtp222511810-4501] [org.gluu.service.BaseCacheService] (BaseCacheService.java:37) - Request data, key 'inum=6D99,ou=scopes,o=gluu' 2021-06-21 16:16:49,972 TRACE [qtp222511810-4501] [org.gluu.service.BaseCacheService] (BaseCacheService.java:39) - Loaded data, key 'inum=6D99,ou=scopes,o=gluu': 'null' 2021-06-21 16:16:49,972 TRACE [qtp222511810-4501] [org.gluu.service.BaseCacheService] (BaseCacheService.java:61) - Key not in cache. Searching value via load function, key: 'inum=6D99,ou=scopes,o=gluu' 2021-06-21 16:16:49,976 TRACE [qtp222511810-4501] [org.gluu.service.BaseCacheService] (BaseCacheService.java:84) - Put data, key 'inum=6D99,ou=scopes,o=gluu': 'Scope{dn='inum=6D99,ou=scopes,o=gluu', inum='6D99', displayName='UMA Protection', id='uma_protection', iconUrl='null', description='Obtain UMA PAT.', scopeType=openid, oxAuthClaims=null, defaultScope=true, oxAuthGroupClaims=null, dynamicScopeScripts=null, umaAuthorizationPolicies=null, deletable=null, expirationDate=null, attributes=ScopeAttributes{spontaneousClientId=''spontaneousClientScopes='[]'showInConfigurationEndpoint='true'}}' 2021-06-21 16:16:49,976 TRACE [qtp222511810-4501] [org.gluu.service.BaseCacheService] (BaseCacheService.java:84) - Put data, key 'uma_protection': 'Scope{dn='inum=6D99,ou=scopes,o=gluu', inum='6D99', displayName='UMA Protection', id='uma_protection', iconUrl='null', description='Obtain UMA PAT.', scopeType=openid, oxAuthClaims=null, defaultScope=true, oxAuthGroupClaims=null, dynamicScopeScripts=null, umaAuthorizationPolicies=null, deletable=null, expirationDate=null, attributes=ScopeAttributes{spontaneousClientId=''spontaneousClientScopes='[]'showInConfigurationEndpoint='true'}}' 2021-06-21 16:16:49,977 DEBUG [qtp222511810-4501] [org.gluu.oxauth.model.authorize.ScopeChecker] (ScopeChecker.java:90) - Granted scopes: [uma_protection] 2021-06-21 16:16:50,012 TRACE [qtp222511810-16] [org.gluu.oxauth.uma.service.UmaValidationService] (UmaValidationService.java:110) - Validate authorization: Bearer 28e64efd-d497-475b-a819-3b6ca9c70615 2021-06-21 16:16:50,012 TRACE [qtp222511810-16] [org.gluu.service.BaseCacheService] (BaseCacheService.java:37) - Request data, key '37c97708104d6c164397f415937111085eef7be73f67566039f432a7d84b7a1e' 2021-06-21 16:16:50,015 TRACE [qtp222511810-16] [org.gluu.service.BaseCacheService] (BaseCacheService.java:39) - Loaded data, key '37c97708104d6c164397f415937111085eef7be73f67566039f432a7d84b7a1e': 'null' 2021-06-21 16:16:50,021 DEBUG [qtp222511810-16] [org.gluu.oxauth.service.common.UserService] (UserService.java:77) - Getting user information from LDAP: userId = null 2021-06-21 16:16:50,022 TRACE [qtp222511810-16] [org.gluu.service.BaseCacheService] (BaseCacheService.java:37) - Request data, key 'inum=1501.c7b9c0ba-1e13-4a68-9d4c-f6e484f42df9,ou=clients,o=gluu' 2021-06-21 16:16:50,023 TRACE [qtp222511810-16] [org.gluu.service.BaseCacheService] (BaseCacheService.java:39) - Loaded data, key 'inum=1501.c7b9c0ba-1e13-4a68-9d4c-f6e484f42df9,ou=clients,o=gluu': 'DeletableEntity{expirationDate=null, deletable=null} BaseEntry [dn=null]' 2021-06-21 16:16:50,023 TRACE [qtp222511810-16] [org.gluu.service.BaseCacheService] (BaseCacheService.java:58) - Loaded from cache, key: 'inum=1501.c7b9c0ba-1e13-4a68-9d4c-f6e484f42df9,ou=clients,o=gluu' 2021-06-21 16:16:50,024 DEBUG [qtp222511810-16] [org.gluu.oxauth.service.ClientService] (ClientService.java:135) - Found 1 entries for client id = 1501.c7b9c0ba-1e13-4a68-9d4c-f6e484f42df9 2021-06-21 16:16:50,053 TRACE [qtp222511810-16] [org.gluu.service.BaseCacheService] (BaseCacheService.java:37) - Request data, key 'inum=1502.a0f040c5-668e-4809-a659-f5ae69aed919,ou=clients,o=gluu' 2021-06-21 16:16:50,053 TRACE [qtp222511810-16] [org.gluu.service.BaseCacheService] (BaseCacheService.java:39) - Loaded data, key 'inum=1502.a0f040c5-668e-4809-a659-f5ae69aed919,ou=clients,o=gluu': 'null' 2021-06-21 16:16:50,054 TRACE [qtp222511810-16] [org.gluu.service.BaseCacheService] (BaseCacheService.java:61) - Key not in cache. Searching value via load function, key: 'inum=1502.a0f040c5-668e-4809-a659-f5ae69aed919,ou=clients,o=gluu' 2021-06-21 16:16:50,060 TRACE [qtp222511810-16] [org.gluu.service.BaseCacheService] (BaseCacheService.java:84) - Put data, key 'inum=1502.a0f040c5-668e-4809-a659-f5ae69aed919,ou=clients,o=gluu': 'DeletableEntity{expirationDate=null, deletable=null} BaseEntry [dn=null]' 2021-06-21 16:16:50,060 DEBUG [qtp222511810-16] [org.gluu.oxauth.service.ClientService] (ClientService.java:135) - Found 1 entries for client id = 1502.a0f040c5-668e-4809-a659-f5ae69aed919 2021-06-21 16:16:50,061 TRACE [qtp222511810-16] [gluu.oxauth.uma.ws.rs.UmaRptIntrospectionWS] (UmaRptIntrospectionWS.java:133) - Canceled changes made by external RPT Claims script since method returned `false`. 2021-06-21 16:16:50,245 TRACE [qtp222511810-21] [org.gluu.oxauth.service.CookieService] (CookieService.java:156) - Found cookie: '35fa7d6e-7c14-414f-9249-7fcb574f85e7' 2021-06-21 16:16:50,246 TRACE [qtp222511810-21] [org.gluu.service.BaseCacheService] (BaseCacheService.java:37) - Request data, key 'oxId=35fa7d6e-7c14-414f-9249-7fcb574f85e7,ou=sessions,o=gluu' 2021-06-21 16:16:50,246 TRACE [qtp222511810-21] [org.gluu.service.BaseCacheService] (BaseCacheService.java:39) - Loaded data, key 'oxId=35fa7d6e-7c14-414f-9249-7fcb574f85e7,ou=sessions,o=gluu': 'null' 2021-06-21 16:16:50,252 TRACE [qtp222511810-21] [org.gluu.service.BaseCacheService] (BaseCacheService.java:84) - Put data, key 'oxId=35fa7d6e-7c14-414f-9249-7fcb574f85e7,ou=sessions,o=gluu': 'SessionId {dn='oxId=35fa7d6e-7c14-414f-9249-7fcb574f85e7,ou=sessions,o=gluu', id='35fa7d6e-7c14-414f-9249-7fcb574f85e7', outsideSid='e5db70b9-53b4-4604-900d-4e9db8d7d65c', lastUsedAt=Mon Jun 21 16:16:39 UTC 2021, userDn='null', authenticationTime=Mon Jun 21 16:16:36 UTC 2021, state=unauthenticated, expirationDate=Mon Jun 21 16:18:36 UTC 2021, sessionState='06e6e86cd932d76fb2c10885c7a23bbc97c1c2c6a730e4a84e35444aa93eb63a.5d1fc7db-2efd-47a9-b834-7703848b2c5b', permissionGranted=null, isJwt=false, jwt=null, permissionGrantedMap=SessionIdAccessMap{permissionGranted={1001.fcfdac3c-87a3-4422-8159-b0610e207cdb=false}}, sessionAttributes={auth_external_attributes=[{"externalProviders":"java.lang.String"},{}], opbs=f5ad06e6-8057-4ec9-9008-1c0606132a79, externalProviders={"Microsoft365": {"requestForEmail": false, "displayName": "Login with Microsoft", "emailLinkingSafe": false, "type": "openidconnect", "logo_img": null, "saml": false}}, response_type=code, nonce=68583bd6-3843-4600-9828-d35fd48d2bfb, client_id=1001.fcfdac3c-87a3-4422-8159-b0610e207cdb, auth_step=1, acr=passport_social, remote_ip=213.98.185.28, scope=openid profile email user_name, acr_values=passport_social, redirect_uri=https://gluu-vm.pre.whispeak.io/identity/authcode.htm, state=c744712f-d534-4ccb-bfb5-a3cfee73e6fc, selectedProvider=null}, persisted=false}' 2021-06-21 16:16:50,253 TRACE [qtp222511810-21] [org.gluu.oxauth.service.SessionIdService] (SessionIdService.java:821) - Try to get session by id: 35fa7d6e-7c14-414f-9249-7fcb574f85e7 ... 2021-06-21 16:16:50,253 TRACE [qtp222511810-21] [org.gluu.oxauth.service.SessionIdService] (SessionIdService.java:823) - Session dn: oxId=35fa7d6e-7c14-414f-9249-7fcb574f85e7,ou=sessions,o=gluu 2021-06-21 16:16:50,265 TRACE [qtp222511810-21] [org.gluu.oxauth.service.AuthenticationService] (AuthenticationService.java:769) - Attempting to store extraParameters: [selectedProvider, externalProviders] 2021-06-21 16:16:50,265 TRACE [qtp222511810-21] [org.gluu.oxauth.service.AuthenticationService] (AuthenticationService.java:788) - Storing sessionIdAttributes: {auth_external_attributes=[{"externalProviders":"java.lang.String"}], opbs=f5ad06e6-8057-4ec9-9008-1c0606132a79, externalProviders={"Microsoft365": {"requestForEmail": false, "displayName": "Login with Microsoft", "emailLinkingSafe": false, "type": "openidconnect", "logo_img": null, "saml": false}}, response_type=code, nonce=68583bd6-3843-4600-9828-d35fd48d2bfb, client_id=1001.fcfdac3c-87a3-4422-8159-b0610e207cdb, auth_step=1, acr=passport_social, remote_ip=213.98.185.28, scope=openid profile email user_name, acr_values=passport_social, redirect_uri=https://gluu-vm.pre.whispeak.io/identity/authcode.htm, state=c744712f-d534-4ccb-bfb5-a3cfee73e6fc, selectedProvider=null} 2021-06-21 16:16:50,266 TRACE [qtp222511810-21] [org.gluu.oxauth.service.AuthenticationService] (AuthenticationService.java:789) - Storing authExternalAttributes: {externalProviders=java.lang.String} 2021-06-21 16:16:50,275 TRACE [qtp222511810-21] [org.gluu.service.BaseCacheService] (BaseCacheService.java:84) - Put data, key 'oxId=35fa7d6e-7c14-414f-9249-7fcb574f85e7,ou=sessions,o=gluu': 'SessionId {dn='oxId=35fa7d6e-7c14-414f-9249-7fcb574f85e7,ou=sessions,o=gluu', id='35fa7d6e-7c14-414f-9249-7fcb574f85e7', outsideSid='e5db70b9-53b4-4604-900d-4e9db8d7d65c', lastUsedAt=Mon Jun 21 16:16:50 UTC 2021, userDn='null', authenticationTime=Mon Jun 21 16:16:36 UTC 2021, state=unauthenticated, expirationDate=Mon Jun 21 16:18:36 UTC 2021, sessionState='06e6e86cd932d76fb2c10885c7a23bbc97c1c2c6a730e4a84e35444aa93eb63a.5d1fc7db-2efd-47a9-b834-7703848b2c5b', permissionGranted=null, isJwt=false, jwt=null, permissionGrantedMap=SessionIdAccessMap{permissionGranted={1001.fcfdac3c-87a3-4422-8159-b0610e207cdb=false}}, sessionAttributes={auth_external_attributes=[{"externalProviders":"java.lang.String"}], opbs=f5ad06e6-8057-4ec9-9008-1c0606132a79, externalProviders={"Microsoft365": {"requestForEmail": false, "displayName": "Login with Microsoft", "emailLinkingSafe": false, "type": "openidconnect", "logo_img": null, "saml": false}}, response_type=code, nonce=68583bd6-3843-4600-9828-d35fd48d2bfb, client_id=1001.fcfdac3c-87a3-4422-8159-b0610e207cdb, auth_step=1, acr=passport_social, remote_ip=213.98.185.28, scope=openid profile email user_name, acr_values=passport_social, redirect_uri=https://gluu-vm.pre.whispeak.io/identity/authcode.htm, state=c744712f-d534-4ccb-bfb5-a3cfee73e6fc, selectedProvider=null}, persisted=true}' ``` from oxauth_script ``` 2021-06-20T17:42:36.850Z [DEBUG] doRequest. options = { "simple": false, "resolveWithFullResponse": true, "uri": "https://gluu-vm.pre.whispeak.io/identity/restv1/passport/config", "headers": { "authorization": "Bearer 3be075a4-9b6e-4493-87fd-230ded8e0b62_334D.699C.4986.5994.A25F.7C6D.4D27.C92B", "pct": "57cf8e4a-6ab7-4b8b-b860-955fc24f7170_6983.8562.1953.B277.8A59.5F85.D87D.A4EC" } } 2021-06-20T17:42:36.926Z [DEBUG] doRequest. response is: { "statusCode": 200, "body": "{\n \"conf\" : {\n \"serverURI\" : \"https://gluu-vm.pre.whispeak.io\",\n \"serverWebPort\" : 8090,\n \"postProfileEndpoint\" : \"https://gluu-vm.pre.whispeak.io/oxauth/postlogin.htm\",\n \"spTLSCert\" : \"/etc/certs/passport-sp.crt\",\n \"spTLSKey\" : \"/etc/certs/passport-sp.key\",\n \"logging\" : {\n \"level\" : \"debug\",\n \"consoleLogOnly\" : true,\n \"activeMQConf\" : {\n \"enabled\" : false,\n \"host\" : \"\",\n \"username\" : \"\",\n \"password\" : \"\",\n \"port\" : 0\n }\n }\n },\n \"idpInitiated\" : {\n \"openidclient\" : {\n \"authorizationEndpoint\" : \"https://gluu-vm.pre.whispeak.io/oxauth/restv1/authorize\",\n \"clientId\" : \"1503.f48d8d09-7922-423e-85f0-eeb107211c6d\",\n \"acrValues\" : \"passport_saml\"\n },\n \"authorizationParams\" : [ ]\n },\n \"providers\" : [ {\n \"id\" : \"Microsoft365\",\n \"displayName\" : \"Login with Microsoft\",\n \"type\" : \"openidconnect\",\n \"mapping\" : \"openidconnect-default\",\n \"passportStrategyId\" : \"passport-windowslive\",\n \"enabled\" : true,\n \"callbackUrl\" : \"https://gluu-vm.pre.whispeak.io/passport/auth/Microsoft365/callback\",\n \"requestForEmail\" : true,\n \"emailLinkingSafe\" : true,\n \"options\" : {\n \"userInfoURL\" : \"https://graph.microsoft.com/oidc/userinfo\",\n \"clientID\" : \"32543e85-6e3c-4959-ae57-9682fa294c3a\",\n \"tokenURL\" : \"https://login.microsoftonline.com/common/oauth2/v2.0/token\",\n \"authorizationURL\" : \"https://login.microsoftonline.com/common/oauth2/v2.0/authorize\",\n \"scope\" : \"profile openid permission phone address email user_name\",\n \"clientSecret\" : \"AVotE2121JqpZ_8-_O74li_SW0vwb~gq1q\",\n \"issuer\" : \"https://login.microsoftonline.com\"\n }\n } ]\n}", "headers": { "date": "Sun, 20 Jun 2021 17:42:36 GMT", "server": "Apache/2.4.41 (Ubuntu)", "x-xss-protection": "1; mode=block", "x-content-type-options": "nosniff", "strict-transport-security": "max-age=31536000; includeSubDomains", "content-type": "application/json", "content-length": "1696", "connection": "close" }, "request": { "uri": { "protocol": "https:", "slashes": true, "auth": null, "host": "gluu-vm.pre.whispeak.io", "port": 443, "hostname": "gluu-vm.pre.whispeak.io", "hash": null, "search": null, "query": null, "pathname": "/identity/restv1/passport/config", "path": "/identity/restv1/passport/config", "href": "https://gluu-vm.pre.whispeak.io/identity/restv1/passport/config" }, "method": "GET", "headers": { "authorization": "Bearer 3be075a4-9b6e-4493-87fd-230ded8e0b62_334D.699C.4986.5994.A25F.7C6D.4D27.C92B", "pct": "57cf8e4a-6ab7-4b8b-b860-955fc24f7170_6983.8562.1953.B277.8A59.5F85.D87D.A4EC" } } } 2021-06-20T17:42:36.926Z [INFO] getConfiguration. Passport configs received 2021-06-20T17:42:36.926Z [DEBUG] getConfiguration. Passport configs are: { "conf" : { "serverURI" : "https://gluu-vm.pre.whispeak.io", "serverWebPort" : 8090, "postProfileEndpoint" : "https://gluu-vm.pre.whispeak.io/oxauth/postlogin.htm", "spTLSCert" : "/etc/certs/passport-sp.crt", "spTLSKey" : "/etc/certs/passport-sp.key", "logging" : { "level" : "debug", "consoleLogOnly" : true, "activeMQConf" : { "enabled" : false, "host" : "", "username" : "", "password" : "", "port" : 0 } } }, "idpInitiated" : { "openidclient" : { "authorizationEndpoint" : "https://gluu-vm.pre.whispeak.io/oxauth/restv1/authorize", "clientId" : "1503.f48d8d09-7922-423e-85f0-eeb107211c6d", "acrValues" : "passport_saml" }, "authorizationParams" : [ ] }, "providers" : [ { "id" : "Microsoft365", "displayName" : "Login with Microsoft", "type" : "openidconnect", "mapping" : "openidconnect-default", "passportStrategyId" : "passport-windowslive", "enabled" : true, "callbackUrl" : "https://gluu-vm.pre.whispeak.io/passport/auth/Microsoft365/callback", "requestForEmail" : true, "emailLinkingSafe" : true, "options" : { "userInfoURL" : "https://graph.microsoft.com/oidc/userinfo", "clientID" : "32543e85-6e3c-4959-ae57-9682fa294c3a", "tokenURL" : "https://login.microsoftonline.com/common/oauth2/v2.0/token", "authorizationURL" : "https://login.microsoftonline.com/common/oauth2/v2.0/authorize", "scope" : "profile openid permission phone address email user_name", "clientSecret" : "AVotE2121JqpZ_8-_O74li_SW0vwb~gq1q", "issuer" : "https://login.microsoftonline.com" } } ] } 2021-06-20T17:42:36.926Z [INFO] Response received 2021-06-20T17:42:36.926Z [INFO] Configuration data has been parsed ``` from passport ``` 2021-06-20T17:42:36.926Z [INFO] getConfiguration. Passport configs received 2021-06-20T17:42:36.926Z [DEBUG] getConfiguration. Passport configs are: { "conf" : { "serverURI" : "https://gluu-vm.pre.whispeak.io", "serverWebPort" : 8090, "postProfileEndpoint" : "https://gluu-vm.pre.whispeak.io/oxauth/postlogin.htm", "spTLSCert" : "/etc/certs/passport-sp.crt", "spTLSKey" : "/etc/certs/passport-sp.key", "logging" : { "level" : "debug", "consoleLogOnly" : true, "activeMQConf" : { "enabled" : false, "host" : "", "username" : "", "password" : "", "port" : 0 } } }, "idpInitiated" : { "openidclient" : { "authorizationEndpoint" : "https://gluu-vm.pre.whispeak.io/oxauth/restv1/authorize", "clientId" : "1503.f48d8d09-7922-423e-85f0-eeb107211c6d", "acrValues" : "passport_saml" }, "authorizationParams" : [ ] }, "providers" : [ { "id" : "Microsoft365", "displayName" : "Login with Microsoft", "type" : "openidconnect", "mapping" : "openidconnect-default", "passportStrategyId" : "passport-windowslive", "enabled" : true, "callbackUrl" : "https://gluu-vm.pre.whispeak.io/passport/auth/Microsoft365/callback", "requestForEmail" : true, "emailLinkingSafe" : true, "options" : { "userInfoURL" : "https://graph.microsoft.com/oidc/userinfo", "clientID" : "32543e85-6e3c-4959-ae57-9682fa294c3a", "tokenURL" : "https://login.microsoftonline.com/common/oauth2/v2.0/token", "authorizationURL" : "https://login.microsoftonline.com/common/oauth2/v2.0/authorize", "scope" : "profile openid permission phone address email user_name", "clientSecret" : "XXXXXXXXXXXXXXXXXXX", "issuer" : "https://login.microsoftonline.com" } } ] } 2021-06-20T17:42:36.926Z [INFO] Response received 2021-06-20T17:42:36.926Z [INFO] Configuration data has been parsed ```

By Mobarak Hosen Shakil staff 21 Jun 2021 at 11:38 a.m. CDT

Mobarak Hosen Shakil gravatar
thanks, I will check them.

By Mobarak Hosen Shakil staff 05 Jul 2021 at 7:48 a.m. CDT

Mobarak Hosen Shakil gravatar
Can you please remove `scope: email` from the provider options of your setup here: https://www.dropbox.com/s/n2e94r1rrbutjhi/Capture%20d%E2%80%99%C3%A9cran%20de%202021-06-20%2020-07-19.png?dl=0 please let me know if it works.

By Mobarak Hosen Shakil staff 14 Jul 2021 at 6:42 a.m. CDT

Mobarak Hosen Shakil gravatar
Please reopen the ticket if required. Thanks ~ Shakil